#!/bin/bash

##################################################
# Author: QAD Inc. (pao@qad.com)
# Date: Nov-27-2011
#
# Script to analyse a FINANCIAL Appserver server logfile to
# statistically analyse all PROCEDURES running on the server.
#
# Please use at own risk.
#
# Usage
# -----
# For usage message run the script without any arguments
#
# Possible Extentions & Limitations:
# ----------------------------------
# 1.
# 2.
#   
#
#
# Modification History
# --------------------
# 0. Nov 27 2010 pao:  Created
#
# 1. 
#
# 2.
#
##################################################


AS_logfile=$1
date=$2
CO_time=$3
TIMES_file="FIN-TIMES-"$date
HISTO_file="FIN-HISTO-"$date

dir=PROCEDURES

echo "1 - mkdir $dir"
[[ ! -d $dir ]] && mkdir $dir 

echo "2 - cd $dir"
echo "3 - Extracting and writing individual PIDs from FIN AS"

cd $dir


awk 'BEGIN{msgs=" (5497) (5498) (5499) (8396) (8397) (8398) "}
    { 
      if (match(msgs,$NF)){ pid[$2]++;
       print $0 >> "FIN-"$2
      }
    }' ../$AS_logfile


echo "4 - Processing and writing times for each PID to $TIMES_file"
no_files=$(ls FIN-P-*[0-9] | wc -l)
no=0
[[ -f $TIMES_file ]] && rm -f $TIMES_file

for i in $(ls FIN-P-*[0-9]); do 
 no=$(echo "$no + 1" | bc -l);
 echo "Processing file (PID) $no of $no_files"

more $i | awk ' BEGIN{ action[1]="(5497)";
action[2]="(5498)";
action[3]="(5499)";
action[4]="(8396)";
action[5]="(8397)";
action[6]="(8398)";
no_actions=6;   #This is the total number of transition states for procedures
open_actions=3; #This is the number of OPEN/START calls
line=0;
}

{
for (i=1;i<=no_actions;i++){
 if ($NF==action[i]){
  line++;                            
  count[i]++; 
  record[1,i,count[i]]=line;         #record[1,...] = The actual line number
  record[2,i,count[i]]=runtime($1);  #record[2,...] = The timestamp (seconds) for the OE Timestamp of line
  record[6,i,count[i]]=$0;           #record[6,...] = The full AS lofgile entry
  record[7,i,count[i]]=$1;
  
  if (i<=open_actions) {             #ENTER HERE ONLY for START CALLS
   record[3,i,count[i]]=0;           #record[3,...] = Just a flag to idenfiy START calls [0 until assigned]
  }

  if (i>open_actions) {              #ENTER HERE ONLY FOR END CALLS              
# print i, "END", $NF, action[i];
   for (j=count[i-open_actions];j>=1;j--){
     if (record[3,i-open_actions,j]==0){
         record[3,i-open_actions,j]=1;   #have found the START corresponding to current END call
         record[4,i,count[i]]= \
         record[2,i-open_actions,j]; #record[4,...] = ONLY FOR END, the time of the corresponding START call
         record[5,i,count[i]]=j;     #record[5,...] = ONLY FOR END, the OCCURRANCE of the corresponding START call                      
         break;
     }    #END --> if (record[3,i-open_actions,j]==0)
   }      #END --> for (j=count[i-open_actions];....)
  }       #END --> if (i>open_actions)
 break; 
 }        #END --> if ($NF==action[i])
}         #END --> for (i=1;i<=no_actions;i++)       
}

END {

  for (j=open_actions+1;j<=no_actions;j++){   #Loop through all entry types (only by the END entry type)
    for(i=1;i<=count[j];i++){                 #Loop through all OCCURRANCES of the entry type (by first END first) 
      t_idx_1=j-open_actions;
      t_idx_2=record[5,j,i];
      separation=record[1,j,i]-record[1,t_idx_1,t_idx_2];
      if(separation==1){ print j,i,separation,record[2,j,i]-record[4,j,i],record[7,t_idx_1,t_idx_2],record[6,t_idx_1,t_idx_2]};
  }
  } 
}
function runtime(st) { # Break progress timestamp to calc. Browse runtime
           split(st,a,"[");s=a[2];split(s,a,"-");s=a[1];split(s,a,"@");s=a[1]":"a[2];gsub("/",":",s);gsub("\\.",":",s);split(s,a,":");
           start1="20"a[1]; for (ctr=2;ctr<=6;ctr++){start1=start1" "a[ctr]}; m1=a[7]; #print "start1 ", st, start1, m1;
return mktime(start1)+m1*0.001;
exit
}
' >> $TIMES_file
done 

echo "5 - Creating Global Histogram Timings: $HISTO_file"

awk -vdt=$date 'BEGIN{
   # Array "l" contains the limit boundaries (in seconds)
   # Array "c" contains the count of browses within the limits
   l[11]=90000;
   l[10]=300;
   l[9]=180;
   l[8]=120;
   l[7]=60;
   l[6]=50;
   l[5]=40;
   l[4]=30;
   l[3]=20;
   l[2]=10;
   l[1]=1;
   l[0]=0;
   len=11;
   for(j=0;j<=len;j++){c[j]=0;time[j]=0} #initiate histogram bins to zero
   }
   {
    if(NF>6){
        t=$4; # Get Procedure runtime
        for(i=0;i<len;i++){             # Populate both histograms
            if (t>l[i]&&t<=l[i+1]){
                 c[i]++;                # Histogram for No. of occurrances 
                 time[i]+=t;            # Histogram for procedure runtimes
            }
        }
    }
   }
   END{
    print "Date No_Procedures_(secs) <1_sec <10 <20 <30 <40 <50 <1_min <2_mins <3_mins <5_mins >5_min";
    str="";tot=0;
    for (j=0;j<len;j++){str=str" "c[j];tot=tot+c[j]};
    print dat" "tot" "str;
    print "Date Cumulative_Runtime_(secs) <1_sec <10 <20 <30 <40 <50 1_min <2_mins <3_mins <5_mins >5_mins";
    str="";tot=0;
    for (j=0;j<len;j++){str=str" "time[j];tot=tot+time[j]};
    print dat" "tot" "str;
   }' $TIMES_file > $HISTO_file

echo "6 - Creating summary TIMING DETAILS files"
RESTR_file=FIN-PROCEDURE-TIMES-INDIVIDUAL-OVER-$CO_time-SECS-ALL-$date".txt"
sort -k4 -nr $TIMES_file | awk -vco=$CO_time '{if($4>=co){print $0}}' > $RESTR_file
RESTR_file_2=FIN-PROCEDURE-TIMES-INDIVIDUAL-OVER-5-MINS-$date".txt"
TMP_co=300
sort -k4 -nr $TIMES_file | awk -vco=$TMP_co '{if($4>=co){print $0}}' > $RESTR_file_2
RESTR_file_3=FIN-PROCEDURE-TIMES-INDIVIDUAL-OVER-$CO_time-SECS-UNDER-$TMP_co-SECS-$date".txt"
TMP_co=300
sort -k4 -nr $TIMES_file | awk -vco=$CO_time -vmax=$TMP_co '{if($4>=co&&$4<max){print $0}}' > $RESTR_file_3
#rm -f $TIMES_file

echo "7 - Creating summary HISTOGRAM files"

#RESTR_file=$(echo $RESTR_file | awk '{gsub("HISTOGRAM","INDIVIDUAL");gsub("csv","txt");print $0)
RESTR_file_=$(echo $RESTR_file | awk '{gsub("INDIVIDUAL","HISTOGRAM-DETAIL");gsub("txt","");print $0}')
RESTR_file_a=$(echo $RESTR_file | awk '{gsub("INDIVIDUAL","HISTOGRAM-SHORT");gsub("txt","");print $0}')
RESTR_file__2=$(echo $RESTR_file_2 | awk '{gsub("INDIVIDUAL","HISTOGRAM-DETAIL");gsub("txt","");print $0}')
RESTR_file__2a=$(echo $RESTR_file_2 | awk '{gsub("INDIVIDUAL","HISTOGRAM-SHORT");gsub("txt","");print $0}')
RESTR_file__3=$(echo $RESTR_file_3 | awk '{gsub("INDIVIDUAL","HISTOGRAM-DETAIL");gsub("txt","");print $0}')
RESTR_file__3a=$(echo $RESTR_file_3 | awk '{gsub("INDIVIDUAL","HISTOGRAM-SHORT");gsub("txt","");print $0}')

for i in 1 2; do

if [ $i -eq 1 ]; then
f1=$RESTR_file_2
f2=$RESTR_file__2
f3=$RESTR_file__2a
else
f1=$RESTR_file_3
f2=$RESTR_file__3
f3=$RESTR_file__3a
fi

[[ -f $f2 ]] && rm $f2
[[ -f $f3 ]] && rm $f3
touch $f2 $f3

awk -vf2=$f2 -vf3=$f3 '{action[1]="(5497)";
action[2]="(5498)";
action[3]="(5499)"}
 {
   if (match($NF,action[1])){
    cnt[$14"::"$16]++;
    tm[$14"::"$16]+=$4;
    cnt1[$16]++;
    tm1[$16]+=$4;
   }
   else if (match($NF,action[2])){
    cnt[$14"::"$16]++;
    tm[$14"::"$16]+=$4;
    cnt1[$16]++;
    tm1[$16]+=$4;
   }
   else if (match($NF,action[3])){
    cnt[$14"-"$15"::"$16"-"$17"-"$18]++;
    tm[$14"-"$15"::"$16"-"$17"-"$18]+=$4;
    cnt1[$16]++;
    tm1[$16]+=$4;
   }
 }
 END{
   for (i in cnt) {print i, cnt[i], tm[i], tm[i]/cnt[i] >> f2}
   for (i in cnt1) {print i, cnt1[i], tm1[i],tm1[i]/cnt1[i]  >> f3}
 }' $f1

sort -k2 -nr $f2 > $f2"csv"
sort -k2 -nr $f3 >  $f3"csv"

rm -f $f2 $f3
done
exit


awk '{action[1]="(5497)";
action[2]="(5498)";
action[3]="(5499)"}
 {
   if ($NF==action[1]){
    cnt[$9"::"$11]++;
    tm[$9"::"$11]+=$4;
   } 
   else if ($NF==action[2]){
    cnt[$9"-"$10"::"$11"-"$12"-"$13]++;
    tm[$9"-"$10"::"$11"-"$12"-"$13]+=$4;
   }
   else if ($NF==action[3]){
    cnt[$9"::"$11]++;
    tm[$9"::"$11]+=$4; 
   }
 }
 END{
   for (i in cnt) {print i, cnt[i], tm[i]}
 }' $RESTR_file_3 > TEST