How to Graph HammerDB Response Times

The HammerDB workload derived from TPC-C contains a feature to record the response times for the stored procedures that are run in the logfile. This post shows how you can easily convert this data into spreadsheet format to view the response times you have captured over a run.

Firstly, to activate the time profile feature select Time Profile for the GUI or the set the equivalent parameter in the CLI to true.

Time Profile

You can note that when loaded the driver script is modified to report response times for the first active virtual user running the workload. (Only the first virtual user is tracked to minimise the impact on the workload). This data is reported every 10 seconds into the HammerDB log.  The output is in percentile format reporting the minimum, 50th percentile, 95th percentile, 99th percentile and maximum for each of the procedures during that 10 second interval with an extract shown below.

 |PERCENTILES 2019-08-23 04:54:21 to 2019-08-23 04:54:31
 |PERCENTILES 2019-08-23 04:54:31 to 2019-08-23 04:54:41

In text from this data can be useful, however often it is better to view this in graphical form. The simple script below can be run at the command line and provided with a logfile with the data for one run only. (Note that it is important that to convert you only provide a logfile for that to convert, otherwise all of the data will be combined).  When run on a logfile with data such as shown above this will output the data in tab delimited format that can be interpreted by a spreadsheet.

 set filename [lindex $argv 0]
 set fp [open "$filename" r]
 set file_data [ read $fp ]
 set data [split $file_data "\n"]
 foreach line $data {
 if {[ string match *PERCENTILES* $line ]} {
 set timeval "[ lindex [ split $line ] 3 ]"
 append xaxis "$timeval\t"
 puts "\t$xaxis"
 foreach storedproc {neword payment delivery slev ostat} {
 puts [ string toupper $storedproc ]
 foreach line $data {
 if {[ string match *PROCNAME* $line ]} { break }
 if {[ string match *$storedproc* $line ]} {
 regexp {MIN-[0-9.]+} $line min
 regsub {MIN-} $min "" min
 append minlist "$min\t"
 regexp {P50%-[0-9.]+} $line p50
 regsub {P50%-} $p50 "" p50
 append p50list "$p50\t"
 regexp {P95%-[0-9.]+} $line p95
 regsub {P95%-} $p95 "" p95
 append p95list "$p95\t"
 regexp {P99%-[0-9.]+} $line p99
 regsub {P99%-} $p99 "" p99
 append p99list "$p99\t"
 regexp {MAX-[0-9.]+} $line max
 regsub {MAX-} $max "" max
 append maxlist "$max\t"
 puts -nonewline "MIN\t"
 puts $minlist
 unset -nocomplain minlist
 puts -nonewline "P50\t"
 puts $p50list 
 unset -nocomplain p50list
 puts -nonewline "P95\t"
 puts $p95list 
 unset -nocomplain p95list
 puts -nonewline "P99\t"
 puts $p99list
 unset -nocomplain p99list
 puts -nonewline "MAX\t"
 puts $maxlist
 unset -nocomplain maxlist
 close $fp

In this example we run the script above, pass the name of the logfile for the run where response times were captured and output them to a file with a spreadsheet extension name.  Note that it is important to output the data to a file and not to a terminal with that data then cut and paste into a spreadsheet. If output to a terminal it may format the output by removing the tab characters which are essential to the formatting.

$ ./extracttp.tcl pgtp.log > pgtp.txt

If we look in this file we can see that it has extracted the data and output them into rows with the extracted values.

$ more pgtp.txt
     04:49:51    04:50:01    04:50:11    04:50:21    04:50:31    04:50:41    04:50:51    04:51:01    04:51:11    04:51:21    04:51:31    04:51:41    04:51:51    04:52:01    04:52:11    04:52:21    04:52:31    04:52:41    04:52:51    04:53:01    04:53:11    04:53:21    04:53:31    04:53:41    04:53:51    04:54:01    04:54:11    04:54:21    04:54:31    04:54:41    04:54:51    04:55:01    04:55:11    04:55:21    04:55:31    04:55:41    04:55:51    04:56:01    04:56:11    04:56:21    04:56:31    04:56:41    
 MIN    457 519 684 734 828 829 795 894 803 880 775 840 774 851 821 792 720 849 751 813 715 879 823 778 853 739 807 812 797 781 841 852 775 865 832 686 805 845 813 822 863 833 
 P50    866 1099    1455    1918.5  2318    2267    2271    2307    2315    2347    2299    2296    2301.5  2313    2314    2351    2324    2312    2284    2347    2344 ...

We now have an option.  In testing with Excel 2013 we can simply give this file a .xls extension and open it. If we do it will give the following warning, however if you click OK it will open with the correctly formatted data.

Excel extension

Alternatively if we open the file with the .txt extension it will show 3 steps for the Text Import Wizard.  Click through the Wizard until Finish.

Text Import 1
Text Import 2
Text Import 3

After clicking Finish the data has been imported into the spreadsheet without warnings.

Imported Data

As an example we will highlight the rows we want to graph by clicking on the row numbers.

Highlighted Spreadsheet

If we then click on Insert and Recommended Charts, the default graph produced by Excel is shown below with the addition of a vertical axis title and a chart header.

Finally make sure when saving the spreadsheet it is saved in Excel format rather than the imported Tab (Text Delimited).

With this approach it is straightforward to turn the captured response times into a visual representation to being further analysis to your workloads.