FM / doc

/usr/share/doc/bpfcc-tools/examples/doc/

/usr/share/doc/bpfcc-tools/examples/doc

Name	Size	Mode	Actions
lib/	-	0755	rm
argdist_example.txt	23029	0644	edit dl rm
bashreadline_example.txt	882	0644	edit dl rm
bindsnoop_example.txt	4530	0644	edit dl rm
biolatency_example.txt	24021	0644	edit dl rm
biolatpcts_example.txt	3040	0644	edit dl rm
biopattern_example.txt	1406	0644	edit dl rm
biosnoop_example.txt	3549	0644	edit dl rm
biotop_example.txt	9326	0644	edit dl rm
bitesize_example.txt	5100	0644	edit dl rm
bpflist_example.txt	2179	0644	edit dl rm
btrfsdist_example.txt	9545	0644	edit dl rm
btrfsslower_example.txt	6812	0644	edit dl rm
cachestat_example.txt	4012	0644	edit dl rm
cachetop_example.txt	3918	0644	edit dl rm
capable_example.txt	6655	0644	edit dl rm
cobjnew_example.txt	3044	0644	edit dl rm
compactsnoop_example.txt	10160	0644	edit dl rm
cpudist_example.txt	16876	0644	edit dl rm
cpuunclaimed_example.txt	15568	0644	edit dl rm
criticalstat_example.txt	4926	0644	edit dl rm
cthreads_example.txt	2132	0644	edit dl rm
dbslower_example.txt	3981	0644	edit dl rm
dbstat_example.txt	6656	0644	edit dl rm
dcsnoop_example.txt	4371	0644	edit dl rm
dcstat_example.txt	3343	0644	edit dl rm
deadlock_example.txt	16643	0644	edit dl rm
dirtop_example.txt	5097	0644	edit dl rm
drsnoop_example.txt	5120	0644	edit dl rm
execsnoop_example.txt	6795	0644	edit dl rm
exitsnoop_example.txt	6373	0644	edit dl rm
ext4dist_example.txt	8991	0644	edit dl rm
ext4slower_example.txt	11335	0644	edit dl rm
filegone_example.txt	743	0644	edit dl rm
filelife_example.txt	2092	0644	edit dl rm
fileslower_example.txt	5711	0644	edit dl rm
filetop_example.txt	6968	0644	edit dl rm
funccount_example.txt	13605	0644	edit dl rm
funcinterval_example.txt	15646	0644	edit dl rm
funclatency_example.txt	21485	0644	edit dl rm
funcslower_example.txt	6786	0644	edit dl rm
gethostlatency_example.txt	1317	0644	edit dl rm
hardirqs_example.txt	37936	0644	edit dl rm
inject_example.txt	6832	0644	edit dl rm
javacalls_example.txt	4000	0644	edit dl rm
javaflow_example.txt	6017	0644	edit dl rm
javagc_example.txt	3867	0644	edit dl rm
javaobjnew_example.txt	3044	0644	edit dl rm
javastat_example.txt	3052	0644	edit dl rm
javathreads_example.txt	2132	0644	edit dl rm
killsnoop_example.txt	1339	0644	edit dl rm
klockstat_example.txt	8536	0644	edit dl rm
kvmexit_example.txt	11909	0644	edit dl rm
llcstat_example.txt	3315	0644	edit dl rm
mdflush_example.txt	1780	0644	edit dl rm
memleak_example.txt	10263	0644	edit dl rm
mountsnoop_example.txt	1481	0644	edit dl rm
mysqld_qslower_example.txt	2351	0644	edit dl rm
netqtop_example.txt	12497	0644	edit dl rm
nfsdist_example.txt	8508	0644	edit dl rm
nfsslower_example.txt	7867	0644	edit dl rm
nodegc_example.txt	3867	0644	edit dl rm
nodestat_example.txt	3052	0644	edit dl rm
offcputime_example.txt	19662	0644	edit dl rm
offwaketime_example.txt	38258	0644	edit dl rm
oomkill_example.txt	1925	0644	edit dl rm
opensnoop_example.txt	10573	0644	edit dl rm
perlcalls_example.txt	4000	0644	edit dl rm
perlflow_example.txt	6017	0644	edit dl rm
perlstat_example.txt	3052	0644	edit dl rm
phpcalls_example.txt	4000	0644	edit dl rm
phpflow_example.txt	6017	0644	edit dl rm
phpstat_example.txt	3052	0644	edit dl rm
pidpersec_example.txt	677	0644	edit dl rm
ppchcalls_example.txt	7097	0644	edit dl rm
profile_example.txt	31826	0644	edit dl rm
pythoncalls_example.txt	4000	0644	edit dl rm
pythonflow_example.txt	6017	0644	edit dl rm
pythongc_example.txt	3867	0644	edit dl rm
pythonstat_example.txt	3052	0644	edit dl rm
rdmaucma_example.txt	1983	0644	edit dl rm
readahead_example.txt	3248	0644	edit dl rm
reset-trace_example.txt	9365	0644	edit dl rm
rubycalls_example.txt	4000	0644	edit dl rm
rubyflow_example.txt	6017	0644	edit dl rm
rubygc_example.txt	3867	0644	edit dl rm
rubyobjnew_example.txt	3044	0644	edit dl rm
rubystat_example.txt	3052	0644	edit dl rm
runqlat_example.txt	32051	0644	edit dl rm
runqlen_example.txt	12136	0644	edit dl rm
runqslower_example.txt	2184	0644	edit dl rm
shmsnoop_example.txt	2798	0644	edit dl rm
slabratetop_example.txt	5347	0644	edit dl rm
sofdsnoop_example.txt	3211	0644	edit dl rm
softirqs_example.txt	11286	0644	edit dl rm
solisten_example.txt	2355	0644	edit dl rm
sslsniff_example.txt	6902	0644	edit dl rm
stackcount_example.txt	21965	0644	edit dl rm
statsnoop_example.txt	3091	0644	edit dl rm
swapin.txt	2632	0644	edit dl rm
swapin_example.txt	1421	0644	edit dl rm
syncsnoop_example.txt	387	0644	edit dl rm
syscount_example.txt	6419	0644	edit dl rm
tclcalls_example.txt	4000	0644	edit dl rm
tclflow_example.txt	6017	0644	edit dl rm
tclobjnew_example.txt	3044	0644	edit dl rm
tclstat_example.txt	3052	0644	edit dl rm
tcpaccept_example.txt	2822	0644	edit dl rm
tcpcong_example.txt	34106	0644	edit dl rm
tcpconnect_example.txt	6420	0644	edit dl rm
tcpconnlat_example.txt	2616	0644	edit dl rm
tcpdrop_example.txt	2001	0644	edit dl rm
tcplife_example.txt	6995	0644	edit dl rm
tcpretrans_example.txt	3938	0644	edit dl rm
tcprtt_example.txt	10070	0644	edit dl rm
tcpstates_example.txt	2908	0644	edit dl rm
tcpsubnet_example.txt	5503	0644	edit dl rm
tcpsynbl_example.txt	1179	0644	edit dl rm
tcptop_example.txt	5890	0644	edit dl rm
tcptracer_example.txt	2029	0644	edit dl rm
threadsnoop_example.txt	1094	0644	edit dl rm
tplist_example.txt	4507	0644	edit dl rm
trace_example.txt	22136	0644	edit dl rm
ttysnoop_example.txt	3315	0644	edit dl rm
vfscount_example.txt	2221	0644	edit dl rm
vfsstat_example.txt	1696	0644	edit dl rm
virtiostat_example.txt	2678	0644	edit dl rm
wakeuptime_example.txt	34048	0644	edit dl rm
xfsdist_example.txt	6928	0644	edit dl rm
xfsslower_example.txt	7080	0644	edit dl rm
zfsdist_example.txt	9753	0644	edit dl rm
zfsslower_example.txt	7551	0644	edit dl rm

Edit: /usr/share/doc/bpfcc-tools/examples/doc/biolatency_example.txt (24021B)

Demonstrations of biolatency, the Linux eBPF/bcc version.

biolatency traces block device I/O (disk I/O), and records the distribution
of I/O latency (time), printing this as a histogram when Ctrl-C is hit.
For example:

# ./biolatency
Tracing block device I/O... Hit Ctrl-C to end.
^C
     usecs           : count     distribution
       0 -> 1        : 0        |                                      |
       2 -> 3        : 0        |                                      |
       4 -> 7        : 0        |                                      |
       8 -> 15       : 0        |                                      |
      16 -> 31       : 0        |                                      |
      32 -> 63       : 0        |                                      |
      64 -> 127      : 1        |                                      |
     128 -> 255      : 12       |********                              |
     256 -> 511      : 15       |**********                            |
     512 -> 1023     : 43       |*******************************       |
    1024 -> 2047     : 52       |**************************************|
    2048 -> 4095     : 47       |**********************************    |
    4096 -> 8191     : 52       |**************************************|
    8192 -> 16383    : 36       |**************************            |
   16384 -> 32767    : 15       |**********                            |
   32768 -> 65535    : 2        |*                                     |
   65536 -> 131071   : 2        |*                                     |

The latency of the disk I/O is measured from the issue to the device to its
completion. A -Q option can be used to include time queued in the kernel.

This example output shows a large mode of latency from about 128 microseconds
to about 32767 microseconds (33 milliseconds). The bulk of the I/O was
between 1 and 8 ms, which is the expected block device latency for
rotational storage devices.

The highest latency seen while tracing was between 65 and 131 milliseconds:
the last row printed, for which there were 2 I/O.

For efficiency, biolatency uses an in-kernel eBPF map to store timestamps
with requests, and another in-kernel map to store the histogram (the "count")
column, which is copied to user-space only when output is printed. These
methods lower the performance overhead when tracing is performed.

In the following example, the -m option is used to print a histogram using
milliseconds as the units (which eliminates the first several rows), -T to
print timestamps with the output, and to print 1 second summaries 5 times:

# ./biolatency -mT 1 5
Tracing block device I/O... Hit Ctrl-C to end.

06:20:16
     msecs           : count     distribution
       0 -> 1        : 36       |**************************************|
       2 -> 3        : 1        |*                                     |
       4 -> 7        : 3        |***                                   |
       8 -> 15       : 17       |*****************                     |
      16 -> 31       : 33       |**********************************    |
      32 -> 63       : 7        |*******                               |
      64 -> 127      : 6        |******                                |

06:20:17
     msecs           : count     distribution
       0 -> 1        : 96       |************************************  |
       2 -> 3        : 25       |*********                             |
       4 -> 7        : 29       |***********                           |
       8 -> 15       : 62       |***********************               |
      16 -> 31       : 100      |**************************************|
      32 -> 63       : 62       |***********************               |
      64 -> 127      : 18       |******                                |

06:20:18
     msecs           : count     distribution
       0 -> 1        : 68       |*************************             |
       2 -> 3        : 76       |****************************          |
       4 -> 7        : 20       |*******                               |
       8 -> 15       : 48       |*****************                     |
      16 -> 31       : 103      |**************************************|
      32 -> 63       : 49       |******************                    |
      64 -> 127      : 17       |******                                |

06:20:19
     msecs           : count     distribution
       0 -> 1        : 522      |*************************************+|
       2 -> 3        : 225      |****************                      |
       4 -> 7        : 38       |**                                    |
       8 -> 15       : 8        |                                      |
      16 -> 31       : 1        |                                      |

06:20:20
     msecs           : count     distribution
       0 -> 1        : 436      |**************************************|
       2 -> 3        : 106      |*********                             |
       4 -> 7        : 34       |**                                    |
       8 -> 15       : 19       |*                                     |
      16 -> 31       : 1        |                                      |

How the I/O latency distribution changes over time can be seen.

The -Q option begins measuring I/O latency from when the request was first
queued in the kernel, and includes queuing latency:

# ./biolatency -Q
Tracing block device I/O... Hit Ctrl-C to end.
^C
     usecs           : count     distribution
       0 -> 1        : 0        |                                      |
       2 -> 3        : 0        |                                      |
       4 -> 7        : 0        |                                      |
       8 -> 15       : 0        |                                      |
      16 -> 31       : 0        |                                      |
      32 -> 63       : 0        |                                      |
      64 -> 127      : 0        |                                      |
     128 -> 255      : 3        |*                                     |
     256 -> 511      : 37       |**************                        |
     512 -> 1023     : 30       |***********                           |
    1024 -> 2047     : 18       |*******                               |
    2048 -> 4095     : 22       |********                              |
    4096 -> 8191     : 14       |*****                                 |
    8192 -> 16383    : 48       |*******************                   |
   16384 -> 32767    : 96       |**************************************|
   32768 -> 65535    : 31       |************                          |
   65536 -> 131071   : 26       |**********                            |
  131072 -> 262143   : 12       |****                                  |

This better reflects the latency suffered by the application (if it is
synchronous I/O), whereas the default mode without kernel queueing better
reflects the performance of the device.

Note that the storage device (and storage device controller) usually have
queues of their own, which are always included in the latency, with or
without -Q.

The -D option will print a histogram per disk. Eg:

# ./biolatency -D
Tracing block device I/O... Hit Ctrl-C to end.
^C

Bucket disk = 'xvdb'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 1        |                                        |
       256 -> 511        : 33       |**********************                  |
       512 -> 1023       : 36       |************************                |
      1024 -> 2047       : 58       |****************************************|
      2048 -> 4095       : 51       |***********************************     |
      4096 -> 8191       : 21       |**************                          |
      8192 -> 16383      : 2        |*                                       |

Bucket disk = 'xvdc'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 1        |                                        |
       256 -> 511        : 38       |***********************                 |
       512 -> 1023       : 42       |*************************               |
      1024 -> 2047       : 66       |****************************************|
      2048 -> 4095       : 40       |************************                |
      4096 -> 8191       : 14       |********                                |

Bucket disk = 'xvda1'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 18       |**********                              |
       512 -> 1023       : 67       |*************************************   |
      1024 -> 2047       : 35       |*******************                     |
      2048 -> 4095       : 71       |****************************************|
      4096 -> 8191       : 65       |************************************    |
      8192 -> 16383      : 65       |************************************    |
     16384 -> 32767      : 20       |***********                             |
     32768 -> 65535      : 7        |***                                     |

This output sows that xvda1 has much higher latency, usually between 0.5 ms
and 32 ms, whereas xvdc is usually between 0.2 ms and 4 ms.

The -F option prints a separate histogram for each unique set of request
flags. For example:

./biolatency.py -Fm
Tracing block device I/O... Hit Ctrl-C to end.
^C

flags = Read
     msecs               : count     distribution
         0 -> 1          : 180      |*************                           |
         2 -> 3          : 519      |****************************************|
         4 -> 7          : 60       |****                                    |
         8 -> 15         : 123      |*********                               |
        16 -> 31         : 68       |*****                                   |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 2        |                                        |
       128 -> 255        : 12       |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 1        |                                        |

flags = Sync-Write
     msecs               : count     distribution
         0 -> 1          : 5        |****************************************|

flags = Flush
     msecs               : count     distribution
         0 -> 1          : 2        |****************************************|

flags = Metadata-Read
     msecs               : count     distribution
         0 -> 1          : 3        |****************************************|
         2 -> 3          : 2        |**************************              |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 1        |*************                           |
        16 -> 31         : 1        |*************                           |

flags = Write
     msecs               : count     distribution
         0 -> 1          : 103      |*******************************         |
         2 -> 3          : 106      |********************************        |
         4 -> 7          : 130      |****************************************|
         8 -> 15         : 79       |************************                |
        16 -> 31         : 5        |*                                       |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 1        |                                        |

flags = NoMerge-Read
     msecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 5        |****************************************|
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 1        |********                                |

flags = NoMerge-Write
     msecs               : count     distribution
         0 -> 1          : 30       |**                                      |
         2 -> 3          : 293      |********************                    |
         4 -> 7          : 564      |****************************************|
         8 -> 15         : 463      |********************************        |
        16 -> 31         : 21       |*                                       |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 5        |                                        |

flags = Priority-Metadata-Read
     msecs               : count     distribution
         0 -> 1          : 1        |****************************************|
         2 -> 3          : 0        |                                        |
         4 -> 7          : 1        |****************************************|
         8 -> 15         : 1        |****************************************|

flags = ForcedUnitAccess-Metadata-Sync-Write
     msecs               : count     distribution
         0 -> 1          : 2        |****************************************|

flags = ReadAhead-Read
     msecs               : count     distribution
         0 -> 1          : 15       |***************************             |
         2 -> 3          : 22       |****************************************|
         4 -> 7          : 14       |*************************               |
         8 -> 15         : 8        |**************                          |
        16 -> 31         : 1        |*                                       |

flags = Priority-Metadata-Write
     msecs               : count     distribution
         0 -> 1          : 9        |****************************************|

These can be handled differently by the storage device, and this mode lets us
examine their performance in isolation.

The -e option shows extension summary(total, average)
For example:
# ./biolatency.py -e
^C
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 4        |***********                             |
       128 -> 255        : 2        |*****                                   |
       256 -> 511        : 4        |***********                             |
       512 -> 1023       : 14       |****************************************|
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 1        |**                                      |

avg = 663 usecs, total: 16575 usecs, count: 25

Sometimes 512 -> 1023 usecs is not enough for throughput tuning.
Especially a little difference in performance downgrade.
By this extension, we know the value in log2 range is about 663 usecs.

The -j option prints a dictionary of the histogram.
For example:

# ./biolatency.py -j
^C
{'ts': '2020-12-30 14:33:03', 'val_type': 'usecs', 'data': [{'interval-start': 0, 'interval-end': 1, 'count': 0}, {'interval-start': 2, 'interval-end': 3, 'count': 0}, {'interval-start': 4, 'interval-end': 7, 'count': 0}, {'interval-start': 8, 'interval-end': 15, 'count': 0}, {'interval-start': 16, 'interval-end': 31, 'count': 0}, {'interval-start': 32, 'interval-end': 63, 'count': 2}, {'interval-start': 64, 'interval-end': 127, 'count': 75}, {'interval-start': 128, 'interval-end': 255, 'count': 7}, {'interval-start': 256, 'interval-end': 511, 'count': 0}, {'interval-start': 512, 'interval-end': 1023, 'count': 6}, {'interval-start': 1024, 'interval-end': 2047, 'count': 3}, {'interval-start': 2048, 'interval-end': 4095, 'count': 31}]}

the key `data` is the list of the log2 histogram intervals. The `interval-start` and `interval-end` define the
latency bucket and `count` is the number of I/O's that lie in that latency range.

# ./biolatency.py -jF
^C
{'ts': '2020-12-30 14:37:59', 'val_type': 'usecs', 'data': [{'interval-start': 0, 'interval-end': 1, 'count': 0}, {'interval-start': 2, 'interval-end': 3, 'count': 0}, {'interval-start': 4, 'interval-end': 7, 'count': 0}, {'interval-start': 8, 'interval-end': 15, 'count': 0}, {'interval-start': 16, 'interval-end': 31, 'count': 1}, {'interval-start': 32, 'interval-end': 63, 'count': 1}, {'interval-start': 64, 'interval-end': 127, 'count': 0}, {'interval-start': 128, 'interval-end': 255, 'count': 0}, {'interval-start': 256, 'interval-end': 511, 'count': 0}, {'interval-start': 512, 'interval-end': 1023, 'count': 0}, {'interval-start': 1024, 'interval-end': 2047, 'count': 2}], 'flags': 'Sync-Write'}
{'ts': '2020-12-30 14:37:59', 'val_type': 'usecs', 'data': [{'interval-start': 0, 'interval-end': 1, 'count': 0}, {'interval-start': 2, 'interval-end': 3, 'count': 0}, {'interval-start': 4, 'interval-end': 7, 'count': 0}, {'interval-start': 8, 'interval-end': 15, 'count': 0}, {'interval-start': 16, 'interval-end': 31, 'count': 0}, {'interval-start': 32, 'interval-end': 63, 'count': 0}, {'interval-start': 64, 'interval-end': 127, 'count': 0}, {'interval-start': 128, 'interval-end': 255, 'count': 2}, {'interval-start': 256, 'interval-end': 511, 'count': 0}, {'interval-start': 512, 'interval-end': 1023, 'count': 2}, {'interval-start': 1024, 'interval-end': 2047, 'count': 1}], 'flags': 'Unknown'}
{'ts': '2020-12-30 14:37:59', 'val_type': 'usecs', 'data': [{'interval-start': 0, 'interval-end': 1, 'count': 0}, {'interval-start': 2, 'interval-end': 3, 'count': 0}, {'interval-start': 4, 'interval-end': 7, 'count': 0}, {'interval-start': 8, 'interval-end': 15, 'count': 0}, {'interval-start': 16, 'interval-end': 31, 'count': 0}, {'interval-start': 32, 'interval-end': 63, 'count': 0}, {'interval-start': 64, 'interval-end': 127, 'count': 0}, {'interval-start': 128, 'interval-end': 255, 'count': 0}, {'interval-start': 256, 'interval-end': 511, 'count': 0}, {'interval-start': 512, 'interval-end': 1023, 'count': 0}, {'interval-start': 1024, 'interval-end': 2047, 'count': 1}], 'flags': 'Write'}
{'ts': '2020-12-30 14:37:59', 'val_type': 'usecs', 'data': [{'interval-start': 0, 'interval-end': 1, 'count': 0}, {'interval-start': 2, 'interval-end': 3, 'count': 0}, {'interval-start': 4, 'interval-end': 7, 'count': 0}, {'interval-start': 8, 'interval-end': 15, 'count': 0}, {'interval-start': 16, 'interval-end': 31, 'count': 0}, {'interval-start': 32, 'interval-end': 63, 'count': 0}, {'interval-start': 64, 'interval-end': 127, 'count': 0}, {'interval-start': 128, 'interval-end': 255, 'count': 0}, {'interval-start': 256, 'interval-end': 511, 'count': 0}, {'interval-start': 512, 'interval-end': 1023, 'count': 4}], 'flags': 'Flush'}

The -j option used with -F prints a histogram dictionary per set of I/O flags.

# ./biolatency.py -jD
^C
{'ts': '2020-12-30 14:40:00', 'val_type': 'usecs', 'data': [{'interval-start': 0, 'interval-end': 1, 'count': 0}, {'interval-start': 2, 'interval-end': 3, 'count': 0}, {'interval-start': 4, 'interval-end': 7, 'count': 0}, {'interval-start': 8, 'interval-end': 15, 'count': 0}, {'interval-start': 16, 'interval-end': 31, 'count': 0}, {'interval-start': 32, 'interval-end': 63, 'count': 1}, {'interval-start': 64, 'interval-end': 127, 'count': 1}, {'interval-start': 128, 'interval-end': 255, 'count': 1}, {'interval-start': 256, 'interval-end': 511, 'count': 1}, {'interval-start': 512, 'interval-end': 1023, 'count': 6}, {'interval-start': 1024, 'interval-end': 2047, 'count': 1}, {'interval-start': 2048, 'interval-end': 4095, 'count': 3}], 'Bucket ptr': b'sda'}

The -j option used with -D prints a histogram dictionary per disk device.

# ./biolatency.py -jm
^C
{'ts': '2020-12-30 14:42:03', 'val_type': 'msecs', 'data': [{'interval-start': 0, 'interval-end': 1, 'count': 11}, {'interval-start': 2, 'interval-end': 3, 'count': 3}]}

The -j with -m prints a millisecond histogram dictionary. The `value_type` key is set to msecs.

USAGE message:

# ./biolatency -h
usage: biolatency.py [-h] [-T] [-Q] [-m] [-D] [-F] [-e] [-j] [-d DISK]
                     [interval] [count]

Summarize block device I/O latency as a histogram

positional arguments:
  interval              output interval, in seconds
  count                 number of outputs

optional arguments:
  -h, --help            show this help message and exit
  -T, --timestamp       include timestamp on output
  -Q, --queued          include OS queued time in I/O time
  -m, --milliseconds    millisecond histogram
  -D, --disks           print a histogram per disk device
  -F, --flags           print a histogram per set of I/O flags
  -e, --extension       summarize average/total value
  -j, --json            json output
  -d DISK, --disk DISK  Trace this disk only

examples:
    ./biolatency                    # summarize block I/O latency as a histogram
    ./biolatency 1 10               # print 1 second summaries, 10 times
    ./biolatency -mT 1              # 1s summaries, milliseconds, and timestamps
    ./biolatency -Q                 # include OS queued time in I/O time
    ./biolatency -D                 # show each disk device separately
    ./biolatency -F                 # show I/O flags separately
    ./biolatency -j                 # print a dictionary
    ./biolatency -e                 # show extension summary(total, average)
    ./biolatency -d sdc             # Trace sdc only

cmd: