Bug #22408
Updated by Sage Weil over 6 years ago
<pre>
2017-12-04 21:46:49.492 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 47 ==== osd_op(client.4156.0:230 2.3c 2.f3bd5ebc (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 237+0+21 (1622976175 0 554963611) 0x5569a1eaad80 con 0x5569a29d7800
2017-12-04 21:46:49.492 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 48 ==== osd_op(client.4156.0:235 2.3e 2.950c2cfe (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 240+0+38 (814723537 0 1640650905) 0x5569a27829c0 con 0x5569a29d7800
2017-12-04 21:46:49.492 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 49 ==== osd_op(client.4156.0:240 2.2 2.5961bc42 (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 246+0+0 (3225606758 0 0) 0x5569a2c15400 con 0x5569a29d7800
2017-12-04 21:46:49.492 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 50 ==== osd_op(client.4156.0:241 2.3c 2.f3bd5ebc (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 237+0+44 (3035202442 0 373528411) 0x5569a2c15400 con 0x5569a29d7800
2017-12-04 21:46:49.492 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 51 ==== osd_op(client.4156.0:242 2.3e 2.950c2cfe (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 240+0+20 (443886151 0 500188455) 0x5569a27850c0 con 0x5569a29d7800
2017-12-04 21:46:49.496 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 52 ==== osd_op(client.4156.0:245 2.38 2.ea225af8 (undecoded) ondisk+write+known_if_redirected e32) v9 ==== 236+0+0 (1353743976 0 0) 0x5569a22129c0 con 0x5569a29d7800
2017-12-04 21:46:49.496 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 53 ==== osd_op(client.4156.0:251 2.38 2.ea225af8 (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 312+0+56 (629625142 0 1571237320) 0x55699f4f36c0 con 0x5569a29d7800
2017-12-04 21:46:49.500 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 54 ==== osd_op(client.4156.0:254 2.b 2.1aa4ad4b (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 246+0+0 (3418490765 0 0) 0x5569a2213d40 con 0x5569a29d7800
2017-12-04 21:46:49.500 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 55 ==== osd_op(client.4156.0:256 2.38 2.ea225af8 (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 274+0+43 (186144397 0 2537278725) 0x55699fa24a40 con 0x5569a29d7800
2017-12-04 21:46:49.500 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 1 ==== osd_op(client.4156.0:256 2.38 2.ea225af8 (undecoded) ondisk+retry+read+known_if_redirected e32) v9 ==== 274+0+43 (3458823427 0 2537278725) 0x5569a1ea9040 con 0x5569a1a76700
2017-12-04 21:46:49.500 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 2 ==== osd_op(client.4156.0:260 2.b 2.1aa4ad4b (undecoded) ondisk+retry+read+known_if_redirected e32) v9 ==== 246+0+0 (3414267323 0 0) 0x5569a1ea8d00 con 0x5569a1a76700
2017-12-04 21:46:49.500 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 3 ==== osd_op(client.4156.0:261 2.19 2.4178cd99 (undecoded) ondisk+write+known_if_redirected e32) v9 ==== 241+0+0 (1831279878 0 0) 0x5569a2214080 con 0x5569a1a76700
2017-12-04 21:46:49.500 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 4 ==== osd_op(client.4156.0:262 2.26 2.b74753e6 (undecoded) ondisk+write+known_if_redirected e32) v9 ==== 230+0+0 (1836394690 0 0) 0x5569a2214700 con 0x5569a1a76700
2017-12-04 21:46:49.500 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 5 ==== osd_op(client.4156.0:263 2.26 2.b74753e6 (undecoded) ondisk+write+known_if_redirected e32) v9 ==== 230+0+0 (3618589350 0 0) 0x5569a2215740 con 0x5569a1a76700
2017-12-04 21:46:49.500 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 6 ==== osd_op(client.4156.0:264 2.3e 2.950c2cfe (undecoded) ondisk+write+known_if_redirected e32) v9 ==== 240+0+0 (1522655644 0 0) 0x5569a2bea9c0 con 0x5569a1a76700
2017-12-04 21:46:49.500 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 7 ==== osd_op(client.4156.0:265 2.1c 2.54f4921c (undecoded) ondisk+write+known_if_redirected e32) v9 ==== 240+0+0 (3209458527 0 0) 0x5569a2bec080 con 0x5569a1a76700
2017-12-04 21:46:49.500 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 8 ==== osd_op(client.4156.0:266 2.38 2.ea225af8 (undecoded) ondisk+write+known_if_redirected e32) v9 ==== 236+0+0 (1464743724 0 0) 0x5569a2bed0c0 con 0x5569a1a76700
2017-12-04 21:46:49.500 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 9 ==== osd_op(client.4156.0:267 2.3c 2.f3bd5ebc (undecoded) ondisk+write+known_if_redirected e32) v9 ==== 237+0+0 (1296420686 0 0) 0x5569a2becd80 con 0x5569a1a76700
2017-12-04 21:46:49.504 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 10 ==== osd_op(client.4156.0:259 2.3c 2.f3bd5ebc (undecoded) ondisk+write+known_if_redirected e32) v9 ==== 237+0+0 (1296420686 0 0) 0x5569a2beba00 con 0x5569a1a76700
2017-12-04 21:46:49.504 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 11 ==== osd_op(client.4156.0:268 2.38 2.ea225af8 (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 236+0+30 (3377207136 0 1005607131) 0x55699f4f36c0 con 0x5569a1a76700
2017-12-04 21:46:49.504 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 12 ==== osd_op(client.4156.0:269 2.1c 2.54f4921c (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 240+0+38 (3019887187 0 2515421301) 0x5569a1ebba80 con 0x5569a1a76700
2017-12-04 21:46:49.504 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 13 ==== osd_op(client.4156.0:270 2.38 2.ea225af8 (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 236+0+44 (210015123 0 373528411) 0x5569a2c14080 con 0x5569a1a76700
2017-12-04 21:46:49.504 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 14 ==== osd_op(client.4156.0:271 2.1c 2.54f4921c (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 240+0+20 (3973591687 0 4236338658) 0x5569a2785a80 con 0x5569a1a76700
2017-12-04 21:46:49.508 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 15 ==== osd_op(client.4156.0:272 2.3c 2.f3bd5ebc (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 313+0+56 (2758970976 0 1571237320) 0x5569a22129c0 con 0x5569a1a76700
2017-12-04 21:46:49.508 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 16 ==== osd_op(client.4156.0:273 2.3b 2.53b8a87b (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 245+0+0 (2099043904 0 0) 0x55699fa24a40 con 0x5569a1a76700
2017-12-04 21:46:49.508 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 17 ==== osd_op(client.4156.0:274 2.11 2.cc915e51 (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 245+0+0 (1456165968 0 0) 0x5569a1ebba80 con 0x5569a1a76700
2017-12-04 21:46:49.508 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 18 ==== osd_op(client.4156.0:278 2.26 2.b74753e6 (undecoded) ondisk+write+known_if_redirected e32) v9 ==== 230+0+242 (1018421343 0 3626819466) 0x5569a253b0c0 con 0x5569a1a76700
2017-12-04 21:46:49.508 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 19 ==== osd_op(client.4156.0:280 2.3b 2.53b8a87b (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 245+0+0 (2099043904 0 0) 0x5569a2213d40 con 0x5569a1a76700
2017-12-04 21:46:49.508 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 20 ==== osd_op(client.4156.0:281 2.11 2.cc915e51 (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 245+0+0 (1456165968 0 0) 0x5569a2c15400 con 0x5569a1a76700
2017-12-04 21:46:49.512 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 21 ==== osd_op(client.4156.0:284 2.26 2.b74753e6 (undecoded) ondisk+write+known_if_redirected e32) v9 ==== 230+0+242 (2573483893 0 2785313313) 0x5569a2bec3c0 con 0x5569a1a76700
</pre>
note the ordering of op client.4156.0:259:
<pre>
...
2017-12-04 21:46:49.500 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 9 ==== osd_op(client.4156.0:267 2.3c 2.f3bd5ebc (undecoded) ondisk+write+known_if_redirected e32) v9 ==== 237+0+0 (1296420686 0 0) 0x5569a2becd80 con 0x5569a1a76700
2017-12-04 21:46:49.504 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 10 ==== osd_op(client.4156.0:259 2.3c 2.f3bd5ebc (undecoded) ondisk+write+known_if_redirected e32) v9 ==== 237+0+0 (1296420686 0 0) 0x5569a2beba00 con 0x5569a1a76700
2017-12-04 21:46:49.504 7f1ea7d53700 1 -- 172.21.15.30:6805/26859 <== client.4156 172.21.15.41:0/2837864525 11 ==== osd_op(client.4156.0:268 2.38 2.ea225af8 (undecoded) ondisk+read+known_if_redirected e32) v9 ==== 236+0+30 (3377207136 0 1005607131) 0x55699f4f36c0 con 0x5569a1a76700
...
</pre>
from grep 172.21.15.41:0/2837864525 remote/*/log/cluster1*osd.0* | grep '= osd_op'
/a/sage-2017-12-04_18:01:15-rbd-mimic-dev1-distro-basic-smithi/1927044
rbd/mirror-ha/{base/install.yaml cluster/{2-node.yaml openstack.yaml} msgr-failures/many.yaml objectstore/bluestore.yaml workloads/rbd-mirror-ha-workunit.yaml}