Page History

...

For a telecoms project, JMeter was used to test a new high-availability integration layer, exposed to a few internal clients (see also \[:../UserManual/BuildWSTest:BuildWSTest\]). Several instances of JMeter represented the different clients and varying load profiles. The default JMeter XML output is too verbose, and the files grew too enormous, so the *Simple Data Writer* was used to produce much friendlier CSV results files.  I wanted to show throughput & response times in blocks of 1 minute; JMeter's inbuilt Graph function was not sufficient to process the volume of data. An example of the type of graph required follows. The reader will see that the JMeter test plan produced variations in load (normal, high & spike), and the response times were quite well-behaved. If the integration layer was performing poorly, the graph would show inconsistent throughput and fluctuating response times.  [BR] attachment:throughput-graph.png [BR]

Simple Data Writer JTL files

JMeter's \[http://jakarta.apache.org/jmeter/usermanual/build-monitor-test-plan.html Simple Data Writer\] produces JTL output files which convey the same information as the default XML output, but the CSV format is much denser. Example: 

queryBalance.jtl

timeStamp,elapsed,label,responseCode,responseMessage,threadName,dataType,success,bytes,grpThreads,allThreads,URL
1158477785863,351,SL_queryBalance,200,,queryBalance 1-1,text,true,87,7,7,http://123.45.67.89:8080/WebService
1158477785953,291,SL_queryBalance,200,,queryBalance 1-4,text,true,87,7,7,http://123.45.67.89:8080/WebService
1158477785883,431,SL_queryBalance,200,,queryBalance 1-2,text,true,87,8,8,http://123.45.67.89:8080/WebService
1158477786013,301,SL_queryBalance,200,,queryBalance 1-5,text,true,87,8,8,http://123.45.67.89:8080/WebService
1158477785883,481,SL_queryBalance,200,,queryBalance 1-3,text,true,87,9,9,http://123.45.67.89:8080/WebService
1158477786113,331,SL_queryBalance,200,,queryBalance 1-6,text,true,87,10,10,http://123.45.67.89:8080/WebService
1158477786183,301,SL_queryBalance,200,,queryBalance 1-7,text,true,87,11,11,http://123.45.67.89:8080/WebService
1158477786404,120,SL_queryBalance,200,,queryBalance 1-10,text,true,87,11,11,http://123.45.67.89:8080/WebService
1158477786334,200,SL_queryBalance,200,,queryBalance 1-9,text,true,87,11,11,http://123.45.67.89:8080/WebService
1158477786254,290,SL_queryBalance,200,,queryBalance 1-8,text,true,87,11,11,http://123.45.67.89:8080/WebService
1158477786474,140,SL_queryBalance,200,,queryBalance 1-11,text,true,87,12,12,http://123.45.67.89:8080/WebService
...

Overview of Several Output files

Script: attachment:jtltotals.sh.txt [BR] After a test run, all the JTL output files were gathered together (20 or so files) in a bunch of subdirectories. The analysis was conducted on a Windows PC with MinGW/MinSYS and a few other tools (msys-dtk, gnu bc, gnu paste, gVim). For an overview of total vs. projected throughput, I used the shell script {{jtltotals.sh}} (a bit kludgy but hey I'm a tester not a developer!). It collates \[total throughput, start time, end time, time elapsed, average response time\] for each output file.  This script will produce a (comma-delimited) file 'jtl-file-totals.txt'.  A sample of output is shown below.

jtl-file-totals.txt

JMeter-Output-file,total-throughput,start,end,elapsed-sec,elapsed-hms,response-av
WebGUI/output.1/queryFCNs.jtl,33,20061103.105342 local,20061103.105830 local,288,00:04:48,225.59
WebGUI/output.1/queryPackages.jtl,55,20061103.105342 local,20061103.105555 local,133,00:02:13,234.06
WebGUI/output.2/queryFCNs.jtl,42,20061103.113435 local,20061103.114155 local,440,00:07:20,212.12
WebGUI/output.2/queryPackages.jtl,59,20061103.113435 local,20061103.113737 local,182,00:03:02,238.78
WebGUI/output.3/queryPackages.jtl,272,20061103.121135 local,20061103.122042 local,547,00:09:07,260.03
Myserver/output/applyDebit.jtl,22219,20060912.154822 local,20060912.162945 local,2483,00:41:23,1265.12
Myserver/output/queryBalance.jtl,360,20061009.134916 local,20061009.150914 local,4798,01:19:58,96.31
total,23040,,,,,

Conversion of JMeter timestamps

Script: attachment:utime2ymd.txt BR The first field of a JTL output file is a Unix timestamp extended to milliseconds. The above script jtltotals.sh calls another script utime2ymd to convert start & end times into year-month-day.hour-min-sec (yyyymmdd.HHMMss). Usually the JTL timestamps are adjusted for your local timezone (eg. GMT plus or minus a few hours). The utime2ymd script uses the local timezone by default, but can also provide GMT values – useful for converting x-thousand elapsed seconds into hhmmss. Example of usage:

$ utime2ymd
Usage: utime2ymd <timestamp> [local|gmt] 

Convert 10-digit Unix timestamp to yyyymmdd.hhmmss format 
 use local time zone (default) or UTC/GMT

$ utime2ymd  1158477785863 
20060917.192305 local

$ utime2ymd 3601 gmt
19700101.010001 gmt

Excel Throughput Graph

Script: attachment:jtlmin.sh.txt BR JMeter's output graph is too granular to depict throughput for extended test intervals (anything from 2 to 24 hours). An Excel constraint its maximum of 65536 rows. So to produce a throughput graph, JTL files of ~100k rows should be summarized into increments of 1 minute (or 2,5,n minutes depending on requirements).
BRFor each minute: throughput = count of transactions in that minute ; response time = average of 'elapsed' values in that minute. BRThe script jtlmin.sh summarizes large JTL files into 1 minute increments producing an OUT file that can be imported to Excel and a graph produced. The core functionality in jtlmin.sh is this piece of awk code:

    # scan a JTL file for records in a specified interval
    # and return record count & average response time.
    BEGIN { 
      avgresponse=0; sumresponse=0; trancount=0; 
    }
    { 
      if(($1 >= lastmin) && ($1 < thismin)) {
        trancount++
        sumresponse += $2
        avgresponse = sumresponse / trancount
      }
    }
    END { 
      printf("%d %d %d %d",lastmin,sumresponse,trancount,avgresponse);
      print " ",strftime("%Y.%b.%d %H:%M",lastmin)
      }

An example session, using jtlmin.sh to process a JTL file. The file produced, queryBalance.jtl.OUT (tab-delimited), can now be used to produce throughput graph. Response times can also be included on the secondary axis, as in the diagram above. These graphs were very good at showing when the integration layer was slow to respond and when throughput varied from the original JMeter plan.

$ jtlmin.sh
Usage: jtlmin.sh <filename> 
Summarizes JMeter JTL output into 1-minute blocks

$ jtlmin.sh queryBalance.jtl
Processing queryBalance.jtl

$ ls q*
queryBalance.jtl  queryBalance.jtl.OUT

$ head queryBalance.jtl.OUT
/c/jmeter/performance/Myserver/output/queryBalance.jtl
unixtime        date    time    thruput(tpm)    response(ms)
1160354940      2006.Oct.09     13:49   65      0
1160355000      2006.Oct.09     13:50   0       0
1160355060      2006.Oct.09     13:51   0       0
1160355120      2006.Oct.09     13:52   56      0
1160355180      2006.Oct.09     13:53   98      108
1160355240      2006.Oct.09     13:54   84      125
1160355300      2006.Oct.09     13:55   0       0
1160355360      2006.Oct.09     13:56   0       0

Extract from JMeter Test Plan (JMX file)

Script: attachment:jmxparse.sh.txt BR Another possibly useful tool which will give a text based summary of what's in your JMeter JMX script. Mainly uses grep and sed.

$ jmxparse.sh STEPTEST_Myserver.jmx
  TestPlan.enabled=true
  clientID   Myserver
  wsdl   http://12.34.56.78:8080/webservice.wsdl
  hostIP   12.34.56.78
  hostPort   8080
  serialFile   C:\jmeter\prioritisation\serial.txt
  rampupInterval   3600
  rampdownInterval   3600
  spikeInterval   300
testname= applyCredit  enabled=false
  num_threads   2
  rampup5_1   9
  rampup5_2   34
  rampdown5_1   34
  rampdown5_2   9
  spikeLoad5   33
testname= queryBalance  enabled=true
  num_threads   14
  rampup2_1   125
  rampup2_2   461
  rampdown2_1   461
  rampdown2_2   125
  spikeLoad2   497

I tried to extract this information using XPath but it's not really designed to report on numerous pieces of data. Anyway, here's the XPath expression, just FYI.

...

Excel Throughput Graph

Script: attachment:jtlmin.sh.txt BR JMeter's output graph is too granular to depict throughput for extended test intervals (anything from 2 to 24 hours). An Excel constraint its maximum of 65536 rows. So to produce a throughput graph, JTL files of ~100k rows should be summarized into increments of 1 minute (or 2,5,n minutes depending on requirements).
BRFor each minute: throughput = count of transactions in that minute ; response time = average of 'elapsed' values in that minute. BRThe script jtlmin.sh summarizes large JTL files into 1 minute increments producing an OUT file that can be imported to Excel and a graph produced. The core functionality in jtlmin.sh is this piece of awk code:

    # scan a JTL file for records in a specified interval
    # and return record count & average response time.
    BEGIN { 
      avgresponse=0; sumresponse=0; trancount=0; 
    }
    { 
      if(($1 >= lastmin) && ($1 < thismin)) {
        trancount++
        sumresponse += $2
        avgresponse = sumresponse / trancount
      }
    }
    END { 
      printf("%d %d %d %d",lastmin,sumresponse,trancount,avgresponse);
      print " ",strftime("%Y.%b.%d %H:%M",lastmin)
      }

An example session, using jtlmin.sh to process a JTL file. The file produced, queryBalance.jtl.OUT (tab-delimited), can now be used to produce throughput graph. Response times can also be included on the secondary axis, as in the diagram above. These graphs were very good at showing when the integration layer was slow to respond and when throughput varied from the original JMeter plan.

$ jtlmin.sh
Usage: jtlmin.sh <filename> 
Summarizes JMeter JTL output into 1-minute blocks

$ jtlmin.sh queryBalance.jtl
Processing queryBalance.jtl

$ ls q*
queryBalance.jtl  queryBalance.jtl.OUT

$ head queryBalance.jtl.OUT
/c/jmeter/performance/Myserver/output/queryBalance.jtl
unixtime        date    time    thruput(tpm)    response(ms)
1160354940      2006.Oct.09     13:49   65      0
1160355000      2006.Oct.09     13:50   0       0
1160355060      2006.Oct.09     13:51   0       0
1160355120      2006.Oct.09     13:52   56      0
1160355180      2006.Oct.09     13:53   98      108
1160355240      2006.Oct.09     13:54   84      125
1160355300      2006.Oct.09     13:55   0       0
1160355360      2006.Oct.09     13:56   0       0

Simple Data Writer JTL files

JMeter's \[http://jakarta.apache.org/jmeter/usermanual/build-monitor-test-plan.html Simple Data Writer\] produces JTL output files which convey the same information as the default XML output, but the CSV format is much denser. Example: 

queryBalance.jtl

timeStamp,elapsed,label,responseCode,responseMessage,threadName,dataType,success,bytes,grpThreads,allThreads,URL
1158477785863,351,SL_queryBalance,200,,queryBalance 1-1,text,true,87,7,7,http://123.45.67.89:8080/WebService
1158477785953,291,SL_queryBalance,200,,queryBalance 1-4,text,true,87,7,7,http://123.45.67.89:8080/WebService
1158477785883,431,SL_queryBalance,200,,queryBalance 1-2,text,true,87,8,8,http://123.45.67.89:8080/WebService
1158477786013,301,SL_queryBalance,200,,queryBalance 1-5,text,true,87,8,8,http://123.45.67.89:8080/WebService
1158477785883,481,SL_queryBalance,200,,queryBalance 1-3,text,true,87,9,9,http://123.45.67.89:8080/WebService
1158477786113,331,SL_queryBalance,200,,queryBalance 1-6,text,true,87,10,10,http://123.45.67.89:8080/WebService
1158477786183,301,SL_queryBalance,200,,queryBalance 1-7,text,true,87,11,11,http://123.45.67.89:8080/WebService
1158477786404,120,SL_queryBalance,200,,queryBalance 1-10,text,true,87,11,11,http://123.45.67.89:8080/WebService
1158477786334,200,SL_queryBalance,200,,queryBalance 1-9,text,true,87,11,11,http://123.45.67.89:8080/WebService
1158477786254,290,SL_queryBalance,200,,queryBalance 1-8,text,true,87,11,11,http://123.45.67.89:8080/WebService
1158477786474,140,SL_queryBalance,200,,queryBalance 1-11,text,true,87,12,12,http://123.45.67.89:8080/WebService
...

Conversion of JMeter timestamps

Script: attachment:utime2ymd.txt BR The first field of a JTL output file is a Unix timestamp extended to milliseconds. The above script jtltotals.sh calls another script utime2ymd to convert start & end times into year-month-day.hour-min-sec (yyyymmdd.HHMMss). Usually the JTL timestamps are adjusted for your local timezone (eg. GMT plus or minus a few hours). The utime2ymd script uses the local timezone by default, but can also provide GMT values – useful for converting x-thousand elapsed seconds into hhmmss. Example of usage:

$ utime2ymd
Usage: utime2ymd <timestamp> [local|gmt] 

Convert 10-digit Unix timestamp to yyyymmdd.hhmmss format 
 use local time zone (default) or UTC/GMT

$ utime2ymd  1158477785863 
20060917.192305 local

$ utime2ymd 3601 gmt
19700101.010001 gmt

Overview of Several Output files

Script: attachment:jtltotals.sh.txt [BR] After a test run, all the JTL output files were gathered together (20 or so files) in a bunch of subdirectories. The analysis was conducted on a Windows PC with MinGW/MinSYS and a few other tools (msys-dtk, gnu bc, gnu paste, gVim). For an overview of total vs. projected throughput, I used the shell script {{jtltotals.sh}} (a bit kludgy but hey I'm a tester not a developer!). It collates \[total throughput, start time, end time, time elapsed, average response time\] for each output file.  This script will produce a (comma-delimited) file 'jtl-file-totals.txt'.  A sample of output is shown below.

jtl-file-totals.txt

JMeter-Output-file,total-throughput,start,end,elapsed-sec,elapsed-hms,response-av
WebGUI/output.1/queryFCNs.jtl,33,20061103.105342 local,20061103.105830 local,288,00:04:48,225.59
WebGUI/output.1/queryPackages.jtl,55,20061103.105342 local,20061103.105555 local,133,00:02:13,234.06
WebGUI/output.2/queryFCNs.jtl,42,20061103.113435 local,20061103.114155 local,440,00:07:20,212.12
WebGUI/output.2/queryPackages.jtl,59,20061103.113435 local,20061103.113737 local,182,00:03:02,238.78
WebGUI/output.3/queryPackages.jtl,272,20061103.121135 local,20061103.122042 local,547,00:09:07,260.03
Myserver/output/applyDebit.jtl,22219,20060912.154822 local,20060912.162945 local,2483,00:41:23,1265.12
Myserver/output/queryBalance.jtl,360,20061009.134916 local,20061009.150914 local,4798,01:19:58,96.31
total,23040,,,,,

Extract from JMeter Test Plan (JMX file)

Script: attachment:jmxparse.sh.txt BR Another possibly useful tool which will give a text based summary of what's in your JMeter JMX script. Mainly uses grep and sed.

$ jmxparse.sh STEPTEST_Myserver.jmx
  TestPlan.enabled=true
  clientID   Myserver
  wsdl   http://12.34.56.78:8080/webservice.wsdl
  hostIP   12.34.56.78
  hostPort   8080
  serialFile   C:\jmeter\prioritisation\serial.txt
  rampupInterval   3600
  rampdownInterval   3600
  spikeInterval   300
testname= applyCredit  enabled=false
  num_threads   2
  rampup5_1   9
  rampup5_2   34
  rampdown5_1   34
  rampdown5_2   9
  spikeLoad5   33
testname= queryBalance  enabled=true
  num_threads   14
  rampup2_1   125
  rampup2_2   461
  rampdown2_1   461
  rampdown2_2   125
  spikeLoad2   497

I tried to extract this information using XPath but it's not really designed to report on numerous pieces of data. Anyway, here's the XPath expression, just FYI.

//@testname|
//elementProp/@name|
//elementProp/stringProp[@name="Argument.value"]/text()|
//ThreadGroup/@enabled|
//stringProp[@name="RunTime.seconds"]/text()|
//stringProp[@name="throughput"]/text()|
//stringProp[@name="filename"]/text()

About MinGW/MinSYS and supporting tools

\[http://www.mingw.org/download.shtml MinGW\] is a subset of Cygwin, but I prefer it because it's a lightweight install on Windows, and it has a nicer interface (rxvt), but it provides the familiar \*nix text processing tools. Recommended packages/versions are:

• Wiki Markup
  \[http://prdownloads.sourceforge.net/mingw/MinGW-3.1.0-1.exe?download MinGW-3.1.0-1.exe\] Minimalist Gnu for Windows

• Wiki Markup
  \[http://prdownloads.sourceforge.net/mingw/MSYS-1.0.10.exe?download MSYS-1.0.10.exe\] Minimal System

• Wiki Markup
  \[http://prdownloads.sourceforge.net/mingw/msysDTK-1.0.1.exe?download msysDTK-1.0.1.exe\] Developer tool kit

• Wiki Markup
  \[http://sourceforge.net/project/showfiles.php?group_id=23617&package_id=26968 bc-1.06-2.exe\] Gnu bc "binary calculator"

• Wiki Markup
  \[http://prdownloads.sourceforge.net/mingw/join_paste_textutils-2.1-MSYS.tar.bz2?download join_paste_textutils-2.1\] (you'll need \[http://www.bzip.org/1.0.3/bzip2-103-x86-linux26 bzip2\] to extract it)

• Wiki Markup
  \[ftp://ftp.vim.org/pub/vim/pc/gvim70.exe gVim 7.0\] highly recommended for editing scripts \\

Windows alternatives (with large footprint) are \[http://www.cygwin.com Cygwin\] or \[http://www.microsoft.com/technet/interopmigration/unix/sfu/default.mspx WSU\], or even ubuntu linux on a Virtual PC.