#!/bin/bash

##################################################
# Author: QAD Inc. (pao@qad.com)
# Date: Jun-24-2010
#
# Script to analyse an Appserver server logfile to 
# statistically analyse all Browses running on the server. 
# [Get Browse runtime, starttime, endtime, user etc. etc.]
# - Created in response to an escalation -
#
# Please use at own risk.
#
# Usage
# -----
# For usage message run the script without any arguments 
#
# Possible Extentions & Limitations:
# ----------------------------------
# 1. This script really gets all runtime-related browse info.
#    Should output all statistics in a single csv output file
#    (rather than 6) to facilitate quicker analysis.  
# 2. Tidy up script internals - make it shorter, it's a bit 
#    messy
# 
#
# Modification History
# --------------------
# 
# Mar 07 2012 eos: Updated User If Statement
#
# Jun 24 2010 pao:  Created
#
# 1. Jan-25-2011 pao: 
#    Re-named output files and added an optional second argument
#    to facilitate extracting threshold runtimes
# 
##################################################


#useage message
if [[ $# -lt 1 || $# -gt 2 ]]; then
echo -e "

DESCRIPTION

  This command analyses an Appserver \"server\" logfile to determine
  information about Browses being run on the system

  It requires one comulsory argument, and there is one optional argument

USAGE

  browse-check <filename> [ <time_limit> ]

  where:
  <filename> - Compulsory
	     - Is the name of the UI Appserver log file
             - Remember that the Appserver _server_ logfile must 
             - have appropriate logging levels set:
             - Logginglevel 3 or 4 
             - LogEntryTypes ASPlumbing,DB.Connects
  <time_limit> - Optional
	     - An integer (specifies a user-controlled time limit in seconds)
             - This effects the contents of only two output file
             - (the \"chronoligical\" file and \"main-targets-summary\" file). 
             - By default these 2 files list only browses which take over 30 seconds to run.
             - Specifying this argument allows a summary of bowses which 
             - took over <time_limit> (seconds) to run 


EXAMPLES
./browse-check uiserver.log 

OUTPUT
 6 output file will be created (5 csv files, one text file):
 - <uiserver.log>-browses-summary-main-targets.csv
 - <uiserver.log>-browses-definition.txt
 - <uiserver.log>-browses-summary-system.csv
 - <uiserver.log>-browses-longest.csv
 - <uiserver.log>-browses-chronological.csv
 - <uiserver.log>-browses-simultaneous.csv

DETAILS:
 - uiserver.log-browses-summary-main-targets.csv
   -- *Summary* of longest running browses BY SYSTEM LOAD and who ran them
   -- By default lists only browses with a runtime over _30_seconds_
      (or over <time_limit> seconds, if <time_limit> set on command line)
   -- Organised by browse runtime (minutes) in descending order (longest first)
   -- THIS SUMMARISES THE KEY INEFFICIENT BROWSES
 - uiserver.log-browses-definition.txt
   -- Contains full browse definition of ALL browses run on the server
   -- Organised by browse runtime (seconds) in descending order (longest first)
 - uiserver.log-browses-summary-system.csv
   -- Does not mention individual browses
   -- Gives a histogram summary of all browses run on server, by runtimes
   -- Useful to see overall browse demand - how many 'quick/'slow' browses etc.
 - uiserver.log-browses-longest.csv
   -- *Details* of  ALL browses run, runtime, starttime and users 
   -- Organised by browse runtime (minutes) in descending order (excludes definition)
 - uiserver.log-browses-chronological.csv
   -- List of ALL browse run with runtime over _30_seconds_
      (or over <time_limit> seconds, if <time_limit> set on command line)
   -- Organised by browse starttime [i.e. chronoligical order]
 - uiserver.log-browses-simultaneous.csv
   -- Lists the number of simultaneous browses running on the server 
   -- Histogram bins are in 20 second intervals (Useful to plot)


DEPENDENCIES
 The Appserver logging needs to have enabled:
   * logginglevel 3 [or 4]
   * logentrytypes DB.Connects, ASPlumbing

"

exit
fi

##################
# Set up variables 
##################

uiserverlog=$1        #INPUT - The ui server logfile
if [ $# -eq 2 ]; then
 interval=$2          #INPUT - Optional <time_limit> 
fi

	              #OUTPUT - File to write browse detail to
basefile=$(echo $uiserverlog"-browses")
outnow=$(echo $basefile"-definition.txt")
outnow_tmp=$(echo $basefile"_tmp")
outnow_procesids=$(echo $basefile"-PIDs")
op_summary=$basefile"-summary-system.csv"

##################
# Error checks ...
##################

if [ ! -e $uiserverlog ]; then 
 echo -e "
	NOTE -
	Input file $uiserverlog does not exist, exiting
  "
 exit 
fi

if [  -e $outnow_tmp ]; then
 rm $outnow_tmp
fi


##################
# Get all unique process ID's (PID's) running on the UI Appserver
# (UI Appserver runs the Browses)
# 1. This has to be run each time to check for new Agent PIDs
#    spawned by the Broker
##################

echo -e " \n \n  Step 1 - Checking for Unique Agents "
pids=$(awk '$2 ~ /^P-[0-9]*$/ {pid[$2]++}END{for (i in pid){print i}}' $uiserverlog)
tot_pids=$(echo $pids |wc -w)  #check how many PIDs we have
echo "  ...done"

#################
# Main Loop -
# Loop through Appserver file and pids and quantify the Browses 
#################

echo "  Step 2 - Analysing system Browses ($tot_pids past Agents) "
count=1 #Loop counter
for i in $pids; do 
echo "Processing PID $i ( $((count++)) of $tot_pids)"
grep $i $uiserverlog | awk 'BEGIN{flag=0;line=0;running=0;seconds[1]=0;seconds[2]=0;user="unknown"}{
   line++;
   # Get user that is running the Browses
   if (match($7,"User")){user=$8};
   if (flag==1){ # We knoe Browse is running => check for more entries
        if (match ($0,"processQuery com/qad/shell/interface/GetBrowseData")){ #multi-line Browse definition
           br=br" +++ "$0;
	   running=1;
           }
        else if (match($0,"TRACE: Non-PERSISTENT Procedure END SUCCESS")) { #browse has finished
           flag=0;running=0;
           finish=$1;
	   comment="";  #Browse finished without issue
	   time=runtime(start,finish,seconds);
	   print br1,user,seconds[1],seconds[2],time,start,finish,seconds[1],br,comment;
           }
	else if (match($0,"Disconnecting from database")){ #Get finish time ( #Finished or PID Disconnected b4 browse finished
	   flag=0;running=0;
           finish=$1;
	   comment="*** DISCONNECTED ***";
	   time=runtime(start,finish,seconds); #runtime of browse
	   print br1,user,seconds[1],seconds[2],time,start,finish,seconds[1],br,comment;
           }
        if (match($0,"Connection failure for host localhost")){ #Possible connection failure (Rare but need it here)
	   flag=0;running=0;
           finish=$1;
	   comment="*** CONNECTION FAILURE ***";
	   time=runtime(start,finish,seconds); #runtime of browse
	   print br1,user,seconds[1],seconds[2],time,start,finish,seconds[1],br,comment;		
           }
   }
   # Check for Browse start time, definition etc.
#   if (flag==0&&match($9,"interface/GetBrowseData")&&match($11,".p")){
   if (flag==0&&match($9,"interface/GetBrowseData")&&match($13,"Query")&&match($14,"string")){ 
      flag=1;
      start=$1;
      br1=$11;
      pid=$2;
      br=$0;  #Records the Appserver Log entry for the Browse (first line if multi-line entry)
      z++}
    }
    END{
	if (running==1){ # Last option, Browse is still running (past last timestamp in logfile => may not be sensible to include....)
	  initial=start;
	  comment="*** BROWSE STILL RUNNING ***";	  
	  f=systime();now=strftime("%F:%H:%M:%S",f);
          split(start,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 (i=2;i<=6;i++){start1=start1" "a[i]}; m1=a[7];m2=0;if(m2>=m1){ms=m2-m1}else{ms=1000-m1+m2};
          start1=mktime(start1);
	  time=f-start1+ms*0.001; 
	  print br1,user,start1,f,time,start,now,start1,br,comment}}

    function runtime(st,fi,seconds,beg,fin) { # 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 (i=2;i<=6;i++){start1=start1" "a[i]}; m1=a[7]; #print "start1 ", st, start1, m1; 
           split(fi,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,":");
           finish1="20"a[1]; for (i=2;i<=6;i++){finish1=finish1" "a[i]}; m2=a[7]; #print "finish1 ", fi,finish1, m2;
           if(m2>=m1){ms=m2-m1}else{ms=1000-m1+m2};seconds[1]=mktime(start1);seconds[2]=mktime(finish1);
	   return mktime(finish1)-seconds[1]+ms*0.001;
	   exit;
	   }' >> $outnow_tmp
done
grep -v RUNNING $outnow_tmp | sort -k5 -gr > $outnow
echo "  ...done"

################
# NOW Process the output file
################
echo -e "\n  Step 3. - Creating csv Browse Statistics "
file_op=$basefile"-simultaneous.csv"
file_browses=$basefile"-longest.csv"
file_browses2=$basefile"-chronological.csv"

# Organise by RUNTIME && include ALL Browses 
echo "NOTE1:_ALL_browses_listed_from_longest_to_shortest_runtime" >  $file_browses
echo "NOTE2:_See_file_\""$outnow"\"_for_full_browse_definition" >>  $file_browses
echo "Browse Runtime_(min) User StartTime PID" >>  $file_browses
more $outnow | awk '{if(NF>6){print $1,$5/60,$2,$6,$10}}' | sort -k2 -gr >> $file_browses #Runtime ($2) is in MINUTES now

# Organise by START TIME && Only include browses with runtimes > ( <time_limit>||20 seconds )
if [ -z "$interval" ]; then
 interval=30
 echo "    interval unset - setting to $interval seconds"
fi

echo "NOTE1:_ONLY_Runtimes>$interval""_Seconds_Listed_Here" >  $file_browses2
echo "NOTE2:_List_is_in_chronoligical_order_by_browse_start_time" >>  $file_browses2
echo "Browse Runtime_(mins) User [StartTime] PID"  >>  $file_browses2
more $outnow | awk -vinter=$interval '{if(NF>6&&$5>=inter){print $1,$5/60,$2,$6,$10}}' | sort -k4  >> $file_browses2

# Only browses that were > 3 seconds
more $outnow | awk '{if($9>3){for (i=$3;i<=$4;i++){a[i]++}}}END{for (j in a){print j, a[j]}}' | sort -k1 -n > $outnow_tmp


start=$(head -1 $outnow_tmp | awk '{print $1}') # The earliest timestamp
echo "TIMESTAMP Simultaneous_Browses Date Time" > $file_op
 
# Organise timestamps to create the "simultaneous" browse timeline 
cat $outnow_tmp | awk -v st=$start 'BEGIN{last=st-1;format = "%a_%b_%e_%Z_%Y %H:%M:%S"}{
     nxt=last+1;
     cur=$1;
     if (nxt<cur){
        for (i=last+1;i<cur;i++){
          print i, 0, strftime(format,i)};
        print $0,strftime(format,i);
        last=cur}
     else
     {print $0,strftime(format,$1);last=cur}
     } ' | awk 'BEGIN{c=0}{c++;if(c%20==0){print $0}}' >> $file_op

echo -e "  ...done \n"
rm $outnow_tmp

###############
# Createa binned histogram summary of Browse runtimes
###############

echo -e "\n  Step 4. - Creating csv Browse Summary file "
echo "NOTE1:_This_summary_includes_every_system_browse_run" > $op_summary
echo "NOTE2:_The_'<1_sec'_column_records_all_browses_taking_less_than_1_second_to_run" >> $op_summary
echo "NOTE2:_The_'<10'_column_records_all_browses_taking_from_1_second_to_under_10_seconds_to_run_etc" >> $op_summary
echo "" >> $op_summary
echo "Date Total_Browses_Running <1_sec <10 <20 <30 <1_min <2.5_mins <5 <10 <20 <30 <40 <50 <60 <90 >90" >> $op_summary

dat=$(more $outnow | awk '{ if(NF>6){split($6,a,"@");gsub("\\[","",a[1]);print a[1];exit}}') #Extract at least start date
more $outnow | awk -vdt=$dat 'BEGIN{
   l[15]=90000
   l[14]=5400
   l[13]=3600; # Array "l" contains the limit boundaries (in seconds)
   l[12]=3000; # Array "c" contains the count of browses within the limits
   l[11]=2400;
   l[10]=1800;
   l[9]=1200;
   l[8]=600;
   l[7]=300;
   l[6]=150;
   l[5]=60;
   l[4]=30;
   l[3]=20;
   l[2]=10;
   l[1]=1;
   l[0]=0;
   len=15;
   for(j=0;j<=len;j++){c[j]=0;time[j]=0} #initiate histogram bins to zero
   }
   {
    if(NF>6){
        t=$5; # Get browse runtime
        for(i=0;i<len;i++){                        # Histogram of all other browses by bin [i.e. Runtime]
	    if (t>l[i]&&t<=l[i+1]){
		 c[i]++;
	         time[i]+=t;
            }
        }
    }
   } 
   END{
    for (j=0;j<len;j++){str=str" "c[j];tot=tot+c[j]};
    print dt" "tot" "str;
    print "Date Cumulative_Runtime_(secs) <1_sec <10 <20 <30 <1_min <2.5_mins <5 <10 <20 <30 <40 <50 <60 >60 >90";
    str="";tot=0;
    for (j=0;j<len;j++){str=str" "time[j];tot=tot+time[j]};
    print dt" "tot" "str;
   }' >> $op_summary

##############
# Focus on long-running browses and user usage patterns
# Record only browses that run for > $interval seconds (30 sec's by default)
##############
file_users=$basefile"-summary-main-targets.csv"
echo "NOTE1:_Summary_is_for_browses_with_Runtimes>$interval""_Seconds" >  $file_users
echo "NOTE2:_Occurrances_is_the_number_of_instances_of_the_browse_run" >> $file_users
echo "NOTE3:_%_Daily_is_the_percentage_of_daily_browse_CPU_runtime_consumed" >>  $file_users
echo "" >> $file_users

tot_time=$(cat $file_browses | awk '{sum+=$2}END{print sum}')
more $file_browses | sort -k4 | \
 awk -vtot=$tot_time -vinter=$interval '{if($2*60>inter){a[$1]++;s[$1]+=$2;u[$1]=u[$1]" "$3}}END{for (i in a){print i,a[i], s[i],s[i]*100.0/tot,u[i]}}' | \
 sort -k3 -gr | \
 awk 'BEGIN{print "Browse Occurrances Cumulative_Runtime_(min) Users %_Daily Users"} \
    {s="";
       users=0;
       delete c;
       for(i=5;i<=NF;i++){c[$i]++};
       s1=$1" "$2" "$3;
       j=1;
       for (i in c){
         u[j]=i;
         n[j]=c[i];
         users++;j++}
       j=j-1;
       for (k=j-1;k>=1;k--){
         for (m=1;m<=k;m++){
           if (n[m]>n[m+1]){
              t=n[m];
              n[m]=n[m+1];
              n[m+1]=t
              t=u[m];
              u[m]=u[m+1];
              u[m+1]=t
           }
         }
       }
      s="";
      for (k=j;k>0;k--){s=s" "u[k]"("n[k]")"};
      print s1" "users" "$4" "s;
      }' >> $file_users
echo "  ...done"

echo "Browse User Runtime_(seconds) Full_Browse_Definition_from_UI_Appserver_Logfile" > $outnow_tmp
more $outnow | cut -d " " -f 3,4,6,7,8 --complement >> $outnow_tmp
cp $outnow_tmp $outnow
rm $outnow_tmp

echo -e "

SUMMARY: 

THE FOLLOWING 6 FILES HAVE BEEN CREATED:

$outnow 
$file_users
$op_summary
$file_browses
$file_browses2
$file_op

"

exit