tools/TTCN3Profiler/ttcn3prof_MergeResults.awk

#///////////////////////////////////////////////////////////////////////////////
#// Copyright (c) 2000-2019 Ericsson Telecom AB                               //
#//                                                                           //
#// All rights reserved. This program and the accompanying materials          //
#// are made available under the terms of the Eclipse Public License v2.0     //
#// which accompanies this distribution, and is available at                  //
#// https://www.eclipse.org/org/documents/epl-2.0/EPL-2.0.html                                 //
#///////////////////////////////////////////////////////////////////////////////
# This processes the output produced by the executable test suite.
# It merges them into a single aggregated output.

# example format of the input:
# 12345.0000:<TAB>filename:123
#  ^ executionTime in ^file ^line
#
# The code lines for a file:
#Code lines     in file EPTF_CLL_Variable_Functions.ttcn: 1541


BEGIN {
  FS=":[ \t]*|[ \t]+"
  executedLineCount=0
  codeLineCount=0
  totalCalls=0
  usedFnsCounter=0
  allFunctions=0
  totalFnCalls=0
  print "------------------------------"
  print "-   Code Lines in files      -"
  print "------------------------------"
}

#Example line:
#33:	EPTF_CLL_LoadRegulator_Functions.ttcn:102 f_EPTF_LoadRegulator_init_CT
#$1     $2                                     $3   $4
# $4 can be empty
/^[[:digit:]]+:/ {
  if (executed[$2":"$3]==0 && executedNum[$2":"$3]==0) {
    lineno = sprintf("%07d", $3); # this is the line number
    linesSort[++executedLineCount] = $2":"lineno  # executedLineCount: total number of executed code lines
    lines[$2":"lineno] =  $2":"$3
  }
  if (fns[$2":"$3]!="") {
    if (usedFns[$2":"$3]==0) {
      usedFns[$2":"$3]=1;         # marks the function as used
      usedFnsInFileCounter[$2]+=1 # number of functions used in a file
      usedFnsCounter++            # total number of functions used
    }
    fnCallNum[$2] += $1           # total function calls in a file
    totalFnCallNum += $1          # total function calls
  }
  executedNum[$2":"$3]+=$1 # how many times a code line is executed
  callNum[$2] += $1        # how many calls were executed in a file
  totalCallNum += $1       # total number of calls
  
  #for the top 10:
  executedNumSort[$2":"$3]=sprintf(" %12d: %s",executedNum[$2":"$3],$2":"$3" "fns[$2":"$3])
}

#Example line:
#33:	EPTF_CLL_LoadRegulator_Functions.ttcn:102 f_EPTF_LoadRegulator_init_CT
#$1     $2                                     $3   $4
# $4 can be empty
# $1 can be: 12.0212 or 12.235e-06
/^[[:digit:]]+\.[[:digit:]]+(|[eE][-+][[:digit:]]+):/ {
  if (executed[$2":"$3]==0 && executedNum[$2":"$3]==0) {
    lineno = sprintf("%07d", $3); # this is the line number
    linesSort[++executedLineCount] = $2":"lineno  # executedLineCount: total number of executed code lines
    lines[$2":"lineno] =  $2":"$3
  }
  if (fns[$2":"$3]!="") {
    if (usedFns[$2":"$3]==0) {
      usedFns[$2":"$3]=1;         # marks the function as used
      usedFnsInFileCounter[$2]+=1 # number of functions used in a file
      usedFnsCounter++            # total number of functions used
    }
    #fnCalls[$2] += $1           # total time of function calls in a file: same as total code line calls!
    #totalFnCalls += $1          # total time of function calls: same as totalCalls
  }
  executed[$2":"$3]+=$1 # how long times a code line is executed
  calls[$2] += $1       # how long calls were executed in a file
  totalCalls += $1      # total time of calls

  #for the top 10:
  executedSort[$2":"$3]=sprintf(" %12f: %s",executed[$2":"$3],$2":"$3" "fns[$2":"$3])
}

# Example line:
#Code lines in file EPTF_CLL_Variable_Functions.ttcn: 1541
#  $1  $2    $3  $4   $5                               $6  
/Code lines/ {
  if (CodeLines[$5]==0) {
    CodeLines[$5]=$6    # number of code lines in a file
    codeLineCount+=$6;  # total number of code lines
    print "Code lines in file "$5": " $6
  }
}

#function references from TTCN3Coverage.fns:
# Example line:
#f: f_EPTF_Var_getContent EPTF_CLL_Variable_Functions.ttcn:1828
#$1   $2                    $3                             $4
/^f:/ {
  #print "functions: " $2" at "$3":"$4
  if (fns[$3":"$4]==0) {
    fns[$3":"$4]=$2                     # maps code lines to functions names
    fnLocation[++allFunctions]=$3":"$4  # allFunctions: total number of functions
    allFnsInFileCounter[$3]+=1          # total number of functions in a file
  }
}

END {
  print "Total code lines: "codeLineCount
#  print "\nttcn3prof: warning: Warning messages should be here!"
  print ""
  print "------------------------------"
  print "-   Call times per lines     -"
  print "------------------------------"
  n=asort(linesSort)
  for(i = 1; i <= n; i++) {
    line = lines[linesSort[i]];
    printf ("%f:\t"line" "fns[line]"\n",executed[line]);
  }

  #calculate function call times:
  n=asort(linesSort)
  totalFnCalls = totalCalls;
  for(i = 1; i <= n; i++) {
    line = lines[linesSort[i]];
    
    #print "****",executed[line],line,fns[line]
    sum = 0;
    if (fns[line]!="") {
      sum += executed[line];
      # go ahead and sum the times:
      for (i++;i<=n;i++) {
        line2 = lines[linesSort[i]];
        if (fns[line2]=="") {
          #print "--->",executed[line2],line2,fns[line2]
          sum += executed[line2];
        } else {
          i--;
          break;
        }
      }
      #totalFnCalls += sum;
      executed[line] = sum;  # replaced with sum
      executedSort[line] = sprintf (" %12f: "line" "fns[line],executed[line]) #replaced with text containing the sum
    }
  }
  

  print ""
  print "--------------------------------"
  print "- Average time/calls per lines -"
  print "--------------------------------"
  n=asort(linesSort)
  for(i = 1; i <= n; i++) {
    line = lines[linesSort[i]];

    # calculate average call time of executed lines:
    if (executedNum[line]==0) {
      continue;
    }
    executedCallTimeSort[line]=sprintf(" %12f = %12f/%d sec/call: %s",executed[line]/executedNum[line],executed[line],executedNum[line],
      line" "fns[line])
    print "Avg time/calls "executedCallTimeSort[line];
  }

  print ""
  print "-------------------------------"
  print "- Call times per lines sorted -"
  print "-------------------------------"
  n=asort(executedSort);
  for(i=1; i<=n; i++) {
    print executedSort[i]
  }

  print ""
  print "---------------------------------------"
  print "- Average call times per lines sorted -"
  print "---------------------------------------"
  n=asort(executedCallTimeSort);
  for(i=1; i<=n; i++) {
    print executedCallTimeSort[i]
  }

  n=asort(executedSort);
  print ""
  print "------------------------------"
  print "- Top 10  function call time -"
  print "------------------------------"
  m=10;
  top10Fns=""
  for(i=0; i<n; i++) {
    split(executedSort[n-i],spl);
    #if function line:
    if (spl[5]!="") {
      top10Fns = spl[3]":"spl[4]":\t`"spl[5]"' call took "spl[2]" secs.\n"top10Fns
      if (prevCounter!=spl[2]) {
        m--
        prevCounter=spl[2]
      }
    }
    if (m==0) {
      break
    }
  }
  printf top10Fns;

  print ""
  print "------------------------------"
  print "- Top 10 code line call time -"
  print "------------------------------"
  m=10;
  top10CodeLines=""
  for(i=0; i<n; i++) {
    split(executedSort[n-i],spl);
    #if function line:
    if (spl[5]=="") {
      top10CodeLines = spl[3]":"spl[4]": call took "spl[2]" secs.\n"top10CodeLines
      if (prevCounter!=spl[2]) {
        m--
        prevCounter=spl[2]
      }
    }
    if (m==0) {
      break
    }
  }
  printf top10CodeLines;

  n=asort(executedCallTimeSort);
  print ""
  print "---------------------------------"
  print "- Top 10 avg function call time -"
  print "---------------------------------"
  m=10;
  top10Fns=""
  for(i=0; i<n; i++) {
    split(executedCallTimeSort[n-i],spl);
    #if function line:
    if (spl[8]!="") {
      top10Fns = spl[6]":"spl[7]":\t`"spl[8]"' call took "spl[2]" ("spl[4]") sec/call.\n"top10Fns
      if (prevCounter!=spl[2]) {
        m--
        prevCounter=spl[2]
      }
    }
    if (m==0) {
      break
    }
  }
  printf top10Fns;

  print ""
  print "----------------------------------"
  print "- Top 10 avg code line call time -"
  print "----------------------------------"
  m=10;
  top10CodeLines=""
  for(i=0; i<n; i++) {
    split(executedCallTimeSort[n-i],spl);
    #if function line:
    if (spl[8]=="") {
      top10CodeLines = spl[6]":"spl[7]": call took "spl[2]" ("spl[4]") sec/call.\n"top10CodeLines
      if (prevCounter!=spl[2]) {
        m--
        prevCounter=spl[2]
      }
    }
    if (m==0) {
      break
    }
  }
  printf top10CodeLines;

  #collect files and calculate ExecutedLines
  n=asort(linesSort)
  for(i = 1; i <= n; i++) {
    line = lines[linesSort[i]];
    split(line,lineSplit,":");
    fileName=lineSplit[1]
    ExecutedLines[fileName]++;
    if (fileList[fileName]=="") {
      fileList[fileName]=fileName;
    }
  }
  n=asort(fileList);

  print ""
  print "------------------------------"
  print "- Total call times per files -"
  print "------------------------------"
  for(i=1; i<=n; i++) {
    fileName=fileList[i];
    callsInFile[fileName] =  sprintf( "Total calls took: %12f secs in  "fileName, calls[fileName])
    callsPerExecuted = calls[fileName]/ExecutedLines[fileName];
    totalCallsPerExecuted[fileName] =  sprintf( "Total callTimePerExecuted: %10.2f =%12f/"ExecutedLines[fileName]" \tin  "fileName, callsPerExecuted,calls[fileName])
  }
  m=asort(callsInFile);
  for(i=1; i<=m; i++) {
    print callsInFile[i];
  }
  print ""
  print "---------------------------------"
  print "- Total call times in all files -"
  print "---------------------------------"
  printf( "All calls took: %f secs\n",totalCalls)

  print ""
  print "------------------------------"
  print "- Average call time in files -"
  print "------------------------------"
  for(i=1; i<=n; i++) {
    fileName=fileList[i];
    if (callNum[fileName]==0) {
      continue;
    }
    avgCallTimeInFile[fileName] =  sprintf( "Average call time: %6f (%6f/"callNum[fileName]") \tsec/call in  "fileName, calls[fileName]/callNum[fileName],calls[fileName])
  }
  m=asort(avgCallTimeInFile);
  for(i=1; i<=m; i++) {
    print avgCallTimeInFile[i];
  }
  print ""
  print "---------------------------------"
  print "- Average call time in all files -"
  print "---------------------------------"
  if (totalCallNum!=0) {
  printf( "Overall average call time: %f (%6f/"totalCallNum") sec/call\n",totalCalls/totalCallNum,totalCalls)
  }

#  print ""
#  print "------------------------------------"
#  print "- Total call time per executed lines -"
#  print "------------------------------------"
#  m=asort(totalCallsPerExecuted);
#  for(i=1; i<=m; i++) {
#    print totalCallsPerExecuted[i];
#  }
#  if(executedLineCount==0) {
#    cov=0
#  } else {
#    cov=totalCalls/executedLineCount
#  }
#  print ""
#  print "----------------------------------"
#  print "- Total call time per executed lines -"
#  print "----------------------------------"
#  print "Total callTimePerExecuted: "cov" ("totalCalls"/"executedLineCount")"
#
#  print ""
#  print "----------------------------------------------"
#  print "-  Code Coverage per files (alphabetic list) -"
#  print "----------------------------------------------"
#  for(i = 1; i <= n; i++) {
#    fileName=fileList[i];
#    #print "Total code lines     in "fileName": "CodeLines[fileName]
#    #print "Total executed lines in "fileName": "ExecutedLines[fileName]
#    if (CodeLines[fileName]=="") {
#      print "Invalid filename: "fileName
#      continue
#    }
#    if (CodeLines[fileName]==0) {
#      cov=0.0
#    } else {
#      cov=ExecutedLines[fileName]/CodeLines[fileName];
#    }
#    coverage[fileName] =  sprintf( "Code Coverage: %6f ("ExecutedLines[fileName]"/"CodeLines[fileName]") \tof "fileName, cov)
#    print coverage[fileName];
#  }  
#  print ""
#  print "------------------------------"
#  print "-  Code Coverage per files   -"
#  print "------------------------------"
#  #sort coverage by coverage size:
#  n=asort(coverage)
#  for(i = 1; i <= n; i++) {
#   print coverage[i];
#  }
#
#  print ""
#  print "------------------------------"
#  print "-     Total Code Coverage    -"
#  print "------------------------------"
#  if (codeLineCount==0) {
#    cov=0.0
#  } else {
#    cov=executedLineCount/codeLineCount
#  }
#  printf( "Total code coverage: %6f ("executedLineCount"/"codeLineCount")\n",cov)

  print ""
  print "-------------------------------"
  print "-  Functions called in files  -"
  print "-------------------------------"
  n=asort(fileList);
  for(i = 1; i <= n; i++) {
    fnsUsedInFile[i] = sprintf( "Functions called: %6d in file "fileList[i],usedFnsInFileCounter[fileList[i]]);
  }
  m=asort(fnsUsedInFile);
  for(i=1; i<=m; i++) {
    print fnsUsedInFile[i];
  }

#  print ""
#  print "---------------------------------"
#  print "- Total function call time in files -"
#  print "---------------------------------"
#  n=asort(fileList);
#  for(i = 1; i <= n; i++) {
#    fnCallsInFile[i] = sprintf( "Total function calls took: %12f secs in file "fileList[i],fnCalls[fileList[i]]);
#  }
#  m=asort(fnCallsInFile);
#  for(i=1; i<=m; i++) {
#    print fnCallsInFile[i];
#  }
#  print ""
#  print "-------------------------------------"
#  print "- Total function call time in all files -"
#  print "-------------------------------------"
#  print "All function calls took: "totalFnCalls" secs"

  print ""
  print "---------------------------------"
  print "- Average function call time in files -"
  print "---------------------------------"
  n=asort(fileList);
  for(i = 1; i <= n; i++) {
    if (fnCallNum[fileList[i]]==0) {
      continue;
    }
    avgFnCallsInFile[i] = sprintf( "Avg function call time: %6f (%6f/"fnCallNum[fileList[i]]") \tsec/call in file "fileList[i],calls[fileList[i]]/fnCallNum[fileList[i]],calls[fileList[i]]);
  }
  m=asort(avgFnCallsInFile);
  for(i=1; i<=m; i++) {
    print avgFnCallsInFile[i];
  }
  print ""
  print "-------------------------------------"
  print "- Average function call time in all files -"
  print "-------------------------------------"
  if (totalFnCallNum!=0) {
  printf( "Overall function call time: %f = %12f/"totalFnCallNum" sec/call\n",totalFnCalls/totalFnCallNum,totalFnCalls)
  }

  print ""
  print "-------------------------------"
  print "- Function Coverage per files -"
  print "-------------------------------"
  n=asort(fileList);
  for(i = 1; i <= n; i++) {
    fileName = fileList[i];
    if (allFnsInFileCounter[fileName]==0) {
      cov=0;
    } else {
      cov = usedFnsInFileCounter[fileName]/allFnsInFileCounter[fileName]
    }
    fnCovInFile[i] = sprintf( "Function Coverage: %6f ("usedFnsInFileCounter[fileName]"/"allFnsInFileCounter[fileName]") \tin "fileName, cov)
  }
  m=asort(fnCovInFile);
  for(i=1; i<=m; i++) {
    print fnCovInFile[i];
  }

  print ""
  print "------------------------------"
  print "-  Total Function Coverage   -"
  print "------------------------------"
  if (allFunctions==0) {
    cov=0.0
  } else {
    cov=usedFnsCounter/allFunctions
  }
  print "Total function coverage: "cov" (" usedFnsCounter "/" allFunctions ")"
}