In this blog post, I will demonstrate how to run and use sysbench histograms.
One of the features of sysbench that I often I see overlooked (and rarely used) is its ability to produce detailed query response time histograms in addition to computing percentile numbers. Looking at histograms together with throughput or latency over time provides many additional insights into query performance.
Here is how you get detailed sysbench histograms and performance over time:
sysbench --rand-type=uniform --report-interval=1 --percentile=99 --time=300 --histogram --mysql-password=sbtest oltp_point_select --table_size=400000000 run
There are a few command line options to consider:
- report-interval=1 – prints out the current performance measurements every second, which helps see if performance is uniform, if you have stalls or otherwise high variance
- percentile=99 – computes 99 percentile response time, rather than 95 percentile (the default); I like looking at 99 percentile stats as it is a better measure of performance
- histogram=on – produces a histogram at the end of the run (as shown below)
The first thing to note about this histogram is that it is exponential. This means the width of the buckets changes with higher values. It starts with 0.001 ms (one microsecond) and gradually grows. This design is used so that sysbench can deal with workloads with requests that take small fractions of milliseconds, as well as accommodate requests that take many seconds (or minutes).
Next, we learn some us very interesting things about typical request response time distribution for databases. You might think that this distribution would be close to some to some “academic” distributions, such as normal distribution. In reality, we often observe is something of a “camelback” distribution (not a real term) – and our “camel” can have more than two humps (especially for simple requests such as the single primary key lookup shown here).
Why do request response times tend to have this distribution? It is because requests can take multiple paths inside the database. For example, certain requests might get responses from the MySQL Query Cache (which will result in the first hump). A second hump might come from resolving lookups using the InnoDB Adaptive Hash Index. A third hump might come from finding all the data in memory (rather than the Adaptive Hash Index). Finally, another hump might coalesce around the time (or times) it takes to execute on requests that require disk IO.
You also will likely see some long-tail data that highlights the fact that MySQL and Linux are not hard, real-time systems. As an example, this very simple run with a single thread (and thus no contention) has an outlier at around 18ms. Most of the requests are served within 0.2ms or less.
As you add contention, row-level locking, group commit and other issues, you are likely to see even more complicated diagrams – which can often show you something unexpected:
Latency histogram (values are in milliseconds) value ------------- distribution ------------- count 0.050 | 1 0.051 | 2 0.052 | 2 0.053 | 54 0.053 | 79 0.054 | 164 0.055 | 883 0.056 |* 1963 0.057 |* 2691 0.059 |** 4047 0.060 |**** 9480 0.061 |****** 15234 0.062 |******** 20723 0.063 |******** 20708 0.064 |********** 26770 0.065 |************* 35928 0.066 |************* 34520 0.068 |************ 32247 0.069 |************ 31693 0.070 |*************** 41682 0.071 |************** 37862 0.073 |******** 22691 0.074 |****** 15907 0.075 |**** 10509 0.077 |*** 7853 0.078 |**** 9880 0.079 |**** 10853 0.081 |*** 9243 0.082 |*** 9280 0.084 |*** 8947 0.085 |*** 7869 0.087 |*** 8129 0.089 |*** 9073 0.090 |*** 8364 0.092 |*** 6781 0.093 |** 4672 0.095 |* 3356 0.097 |* 2512 0.099 |* 2177 0.100 |* 1784 0.102 |* 1398 0.104 | 1082 0.106 | 810 0.108 | 742 0.110 | 511 0.112 | 422 0.114 | 330 0.116 | 259 0.118 | 203 0.120 | 165 0.122 | 126 0.125 | 108 0.127 | 87 0.129 | 83 0.132 | 55 0.134 | 42 0.136 | 45 0.139 | 41 0.141 | 149 0.144 | 456 0.147 | 848 0.149 |* 2128 0.152 |** 4586 0.155 |*** 7592 0.158 |***** 13685 0.160 |********* 24958 0.163 |***************** 44558 0.166 |***************************** 78332 0.169 |************************************* 98616 0.172 |**************************************** 107664 0.176 |**************************************** 107154 0.179 |**************************** 75272 0.182 |****************** 49645 0.185 |**************** 42793 0.189 |***************** 44649 0.192 |**************** 44329 0.196 |****************** 48460 0.199 |***************** 44769 0.203 |********************** 58578 0.206 |*********************** 61373 0.210 |********************** 58758 0.214 |****************** 48012 0.218 |************* 34533 0.222 |************** 36517 0.226 |************* 34645 0.230 |*********** 28694 0.234 |******* 17560 0.238 |***** 12920 0.243 |**** 10911 0.247 |*** 9208 0.252 |**** 10556 0.256 |*** 7561 0.261 |** 5047 0.266 |* 3757 0.270 |* 3584 0.275 |* 2951 0.280 |* 2078 0.285 |* 2161 0.291 |* 1747 0.296 |* 1954 0.301 |* 2878 0.307 |* 2810 0.312 |* 1967 0.318 |* 1619 0.324 |* 1409 0.330 | 1205 0.336 | 1193 0.342 | 1151 0.348 | 989 0.354 | 985 0.361 | 799 0.367 | 671 0.374 | 566 0.381 | 537 0.388 | 351 0.395 | 276 0.402 | 214 0.409 | 143 0.417 | 80 0.424 | 85 0.432 | 54 0.440 | 41 0.448 | 29 0.456 | 16 0.464 | 15 0.473 | 11 0.481 | 4 0.490 | 9 0.499 | 4 0.508 | 3 0.517 | 4 0.527 | 4 0.536 | 2 0.546 | 4 0.556 | 4 0.566 | 4 0.587 | 1 0.597 | 1 0.608 | 5 0.619 | 3 0.630 | 2 0.654 | 2 0.665 | 5 0.677 | 26 0.690 | 298 0.702 | 924 0.715 |* 1493 0.728 | 1027 0.741 | 1112 0.755 | 1127 0.768 | 796 0.782 | 574 0.797 | 445 0.811 | 415 0.826 | 296 0.841 | 245 0.856 | 202 0.872 | 210 0.888 | 168 0.904 | 217 0.920 | 163 0.937 | 157 0.954 | 204 0.971 | 155 0.989 | 158 1.007 | 137 1.025 | 94 1.044 | 79 1.063 | 52 1.082 | 36 1.102 | 25 1.122 | 25 1.142 | 16 1.163 | 8 1.184 | 5 1.205 | 7 1.227 | 2 1.250 | 4 1.272 | 3 1.295 | 3 1.319 | 2 1.343 | 2 1.367 | 1 1.417 | 2 1.791 | 1 1.996 | 2 2.106 | 2 2.184 | 1 2.264 | 1 2.347 | 2 2.389 | 1 2.433 | 1 2.477 | 1 2.568 | 2 2.615 | 1 2.710 | 1 2.810 | 1 2.861 | 1 3.187 | 1 3.488 | 1 3.816 | 1 4.028 | 1 6.913 | 1 7.565 | 1 8.130 | 1 17.954 | 1
I hope you give sysbench histograms a try, and see what you can discover!