Actions
Support #40303
closedAverage latency output in rados bench seems incorrect
Status:
Closed
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
% Done:
0%
Tags:
Reviewed:
Affected Versions:
Pull request ID:
Description
Seen on ceph version 14.2.1 (d555a9489eb35f84f2e1ef49b77e19da9d113972) nautilus (stable)
# /usr/bin/rados bench -c /etc/ceph/fast.conf -p pool 60 write -t 2 -b 65536 --no-cleanup
hints = 1
Maintaining 2 concurrent writes of 65536 bytes to objects of size 65536 for up to 60 seconds or 0 objects
Object prefix: benchmark_data_bn336.convoke.cloud_16758
sec Cur ops started finished avg MB/s cur MB/s last lat(s) avg lat(s)
0 0 0 0 0 0 - 0
1 2 501 499 31.182 31.1875 0.00156332 0.00372242
2 2 992 990 30.9324 30.6875 0.0014457 0.00403083
3 1 1638 1637 34.0986 40.4375 0.00119016 0.00359742
4 2 2323 2321 36.2598 42.75 0.00161445 0.00344049
5 2 2861 2859 35.7317 33.625 0.00126015 0.00348331
6 2 3414 3412 35.5359 34.5625 0.00168682 0.00349687
7 2 3922 3920 34.9943 31.75 0.00189924 0.00356997
8 2 4495 4493 35.0959 35.8125 0.00114464 0.00355285
9 1 4875 4874 33.8417 23.8125 0.00170197 0.00368152
10 2 5421 5419 33.8632 34.0625 0.00152365 0.00368276
11 2 5924 5922 33.6422 31.4375 0.00116316 0.00371197
12 2 6370 6368 33.1613 27.875 0.00131946 0.00374918
13 2 6834 6832 32.8409 29 0.00101812 0.00379321
14 2 7363 7361 32.8565 33.0625 0.00154718 0.00379322
15 2 7759 7757 32.3159 24.75 0.00139544 0.00386386
16 2 8243 8241 32.1865 30.25 0.00127026 0.00387422
17 2 8910 8908 32.7451 41.6875 0.00135777 0.00380918
18 2 9386 9384 32.5785 29.75 0.00114425 0.00382886
19 2 10055 10053 33.0642 41.8125 0.0014974 0.00377908
2019-06-12 10:40:28.220542 min lat: 0.000867134 max lat: 0.282099 avg lat: 0.00371032
sec Cur ops started finished avg MB/s cur MB/s last lat(s) avg lat(s)
20 2 10780 10778 33.6763 45.3125 0.00148318 0.00371032
21 2 11221 11219 33.385 27.5625 0.0013521 0.00371883
22 2 11839 11837 33.623 38.625 0.00109343 0.00371319
23 2 12464 12462 33.8592 39.0625 0.00105072 0.00369039
24 2 12928 12926 33.6566 29 0.00113544 0.00370982
25 2 13485 13483 33.7026 34.8125 0.00134962 0.00370475
26 2 14034 14032 33.7259 34.3125 0.00182426 0.00369088
27 2 14560 14558 33.6942 32.875 0.00115982 0.00370405
28 2 15307 15305 34.1581 46.6875 0.00139306 0.00365811
29 2 15893 15891 34.243 36.625 0.00133283 0.00364906
30 2 16608 16606 34.5909 44.6875 0.00113804 0.00361237
31 2 17359 17357 34.989 46.9375 0.00113668 0.00356149
32 2 18059 18057 35.2626 43.75 0.00138045 0.00354355
33 2 18808 18806 35.6124 46.8125 0.00121765 0.00350637
34 2 19530 19528 35.892 45.125 0.00127839 0.00347845
35 1 20106 20105 35.8968 36.0625 0.0015811 0.00347737
36 2 20742 20740 36.0019 39.6875 0.00138548 0.00346994
37 2 21319 21317 36.0034 36.0625 0.00117204 0.00347066
38 2 21961 21959 36.1118 40.125 0.00155697 0.0034602
39 2 22628 22626 36.2546 41.6875 0.00124545 0.00344635
2019-06-12 10:40:48.223129 min lat: 0.000769916 max lat: 0.282099 avg lat: 0.00341283
sec Cur ops started finished avg MB/s cur MB/s last lat(s) avg lat(s)
40 2 23434 23432 36.6075 50.375 0.00134771 0.00341283
41 2 24074 24072 36.69 40 0.00154871 0.00339875
42 2 24676 24674 36.7122 37.625 0.00158016 0.0034028
43 2 25329 25327 36.8074 40.8125 0.00195395 0.00339488
44 1 25974 25973 36.8884 40.375 0.00165454 0.0033867
45 2 26760 26758 37.1587 49.0625 0.00173819 0.00336172
46 2 27643 27641 37.5505 55.1875 0.00150727 0.00332601
47 2 28436 28434 37.8059 49.5625 0.00122901 0.00330491
48 2 29227 29225 38.0481 49.4375 0.00158476 0.00328129
49 2 29782 29780 37.9795 34.6875 0.00148581 0.00329006
50 2 30578 30576 38.2147 49.75 0.00122827 0.00326905
51 1 31278 31277 38.3244 43.8125 0.00137523 0.00326043
52 2 32067 32065 38.5344 49.25 0.00173384 0.00324264
53 2 32810 32808 38.6834 46.4375 0.00104165 0.0032298
54 2 33632 33630 38.9183 51.375 0.0012043 0.00320996
55 2 34362 34360 39.0402 45.625 0.00199642 0.00320062
56 2 35204 35202 39.2827 52.625 0.00123679 0.00317964
57 2 36163 36161 39.6449 59.9375 0.00149645 0.00314994
58 2 36972 36970 39.833 50.5625 0.00136391 0.00313687
59 2 37863 37861 40.1016 55.6875 0.00189514 0.00311385
2019-06-12 10:41:08.225652 min lat: 0.000769916 max lat: 0.282099 avg lat: 0.00310966
sec Cur ops started finished avg MB/s cur MB/s last lat(s) avg lat(s)
60 2 38561 38559 40.1602 43.625 0.00159082 0.00310966
Total time run: 60.0687
Total writes made: 38562
Write size: 65536
Object size: 65536
Bandwidth (MB/sec): 40.1228
Stddev Bandwidth: 8.31216
Max bandwidth (MB/sec): 59.9375
Min bandwidth (MB/sec): 23.8125
Average IOPS: 641
Stddev IOPS: 132.995
Max IOPS: 959
Min IOPS: 381
Average Latency(s): 0.00311428
Stddev Latency(s): 0.01138
Max latency(s): 0.282099
Min latency(s): 0.000769916
I would expect Avg Latency to be much less based on the last latency readings.
Actions