os/bluesore,kv/rocksdbstore: dump KV txc ops when slow
Depending on bluestore_log_op_verbose parameter one can see either
short:
2026-05-20T19:45:05.792+0300
7f60980006c0 0
bluestore(/home/if/ceph.2/build/dev/osd0) log_latency_fn slow operation
observed for _txc_committed_kv, latency = 0.004759922s, txc =
0x55c357bde900, txc bytes =
2756989, txc ios = 43, txc cost =
31566989,
txc onodes = 1, DB ops = ' p:P, p:P, p:O, p:O, p:O, p:O, p:O, p:O, p:O,
p:O, p:O, p:L, m:b, m:b, m:b, m:b, m:b, m:b, m:b, m:b, m:b, m:b, m:b,
m:b', DB updates = 24, DB bytes = 8937, cost max =
95489052 on
2026-05-20T18:38:20.749901+0300, txc max = 100 on
2026-05-20T18:38:21.215016+0300
or verbose:
2026-05-20T18:42:01.551+0300
7f60980006c0 0
bluestore(/home/if/ceph.2/build/dev/osd0) log_latency_fn slow operation
observed for _txc_committe
d_kv, latency = 0.003735413s, txc = 0x55c356a35500, txc bytes =
2757061,
txc ios = 44, txc cost =
32237061, txc onodes = 1, DB ops = '
PutCF( prefix = P key =
0x0000000000000499'.
0000000032.
00000000000000000005' value size = 185)
PutCF( prefix = P key = 0x0000000000000499'._fastinfo' value size = 194)
PutCF( prefix = O key =
0x7F8000000000000002DB7D25F2'!c!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F0000000078
value size = 453)
PutCF( prefix = O key =
0x7F8000000000000002DB7D25F2'!c!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F0006000078
value size = 455)
PutCF( prefix = O key =
0x7F8000000000000002DB7D25F2'!c!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F000C000078
value size = 455)
PutCF( prefix = O key =
0x7F8000000000000002DB7D25F2'!c!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F0012000078
value size = 455)
PutCF( prefix = O key =
0x7F8000000000000002DB7D25F2'!c!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F0018000078
value size = 455)
PutCF( prefix = O key =
0x7F8000000000000002DB7D25F2'!c!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F001E000078
value size = 455)
PutCF( prefix = O key =
0x7F8000000000000002DB7D25F2'!c!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F0024000078
value size = 455)
PutCF( prefix = O key =
0x7F8000000000000002DB7D25F2'!c!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F002A000078
value size = 21)
PutCF( prefix = O key =
0x7F8000000000000002DB7D25F2'!c!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F
value size = 388)
MergeCF( prefix = b key = 0x0000000019080000 value size = 16)
MergeCF( prefix = b key = 0x0000000019100000 value size = 16)
MergeCF( prefix = b key = 0x0000000019180000 value size = 16)
MergeCF( prefix = b key = 0x0000000019200000 value size = 16)
MergeCF( prefix = b key = 0x0000000019280000 value size = 16)
MergeCF( prefix = b key = 0x0000000019300000 value size = 16)
MergeCF( prefix = T key = 0x0000000000000002 value size = 40)', DB
updates = 18, DB bytes = 4668, cost max =
95489052 on
2026-05-20T18:38:20.74
9901+0300, txc max = 100 on 2026-05-20T18:38:21.215016+0300
operations list when BlueStore observes slow op on KV commit.
Signed-off-by: Igor Fedotov <igor.fedotov@croit.io>