Ceph » rgw

Strong possibility this is related to 22963, but I've got some solid debug logs here. This ALSO triggers issue 22050 as a side-effect, and can make OSDs unbootable.

$ sudo rados -p .usage  ls
usage.29
usage.16
usage.14
usage.3
usage.11
usage.7
usage.21
usage.27
usage.13
usage.10
usage.4
usage.17

$ sudo rados -p .usage  listomapkeys usage.3
01519916400_justin-benjamin_
01519916400_justin-west-1-staging_
justin-benjamin_01519916400_
justin-west-1-staging_01519916400_

$ sudo ceph osd map .usage usage.3
osdmap e157811 pool '.usage' (38) object 'usage.3' -> pg 38.eb5f8acc (38.c) -> up ([2,14,24], p2) acting ([2,14,24], p2)

# debug-ms=1 log from radosgw-admin usage trim shows unended calls to the same object:
2018-03-05 20:17:46.615032 7ffbaaa6db80  1 -- [XXXX::7930]:0/51387864 --> [XXXX::7108]:6806/48758 -- osd_op(unknown.0.0:71 38.c 38:3351fad7:::usage.3:head [call rgw.user_usage_log_trim] snapc 0=[] ondisk+write+known_if_redirected e157808) v8 -- 0x55c304c4f9e0 con 0
2018-03-05 20:17:46.966249 7ffb991e2700  1 -- [XXXX::7930]:0/51387864 <== osd.2 [XXXX::7108]:6806/48758 1 ==== osd_op_reply(71 usage.3 [call] v157808'772973 uv263780 ondisk = 0) v8 ==== 151+0+0 (1031674036 0 0) 0x7ffb88013f50 con 0x55c304c4b3c0
2018-03-05 20:17:46.966380 7ffbaaa6db80  1 -- [XXXX::7930]:0/51387864 --> [XXXX::7108]:6806/48758 -- osd_op(unknown.0.0:72 38.c 38:3351fad7:::usage.3:head [call rgw.user_usage_log_trim] snapc 0=[] ondisk+write+known_if_redirected e157808) v8 -- 0x55c304be7360 con 0
2018-03-05 20:17:47.246213 7ffb991e2700  1 -- [XXXX::7930]:0/51387864 <== osd.2 [XXXX::7108]:6806/48758 2 ==== osd_op_reply(72 usage.3 [call] v157808'772974 uv263780 ondisk = 0) v8 ==== 151+0+0 (2395895143 0 0) 0x7ffb88024590 con 0x55c304c4b3c0
2018-03-05 20:17:47.246342 7ffbaaa6db80  1 -- [XXXX::7930]:0/51387864 --> [XXXX::7108]:6806/48758 -- osd_op(unknown.0.0:73 38.c 38:3351fad7:::usage.3:head [call rgw.user_usage_log_trim] snapc 0=[] ondisk+write+known_if_redirected e157808) v8 -- 0x55c304be7360 con 0
2018-03-05 20:17:47.455677 7ffb991e2700  1 -- [XXXX::7930]:0/51387864 <== osd.2 [XXXX::7108]:6806/48758 3 ==== osd_op_reply(73 usage.3 [call] v157808'772975 uv263780 ondisk = 0) v8 ==== 151+0+0 (3764277718 0 0) 0x7ffb88025750 con 0x55c304c4b3c0
2018-03-05 20:17:47.455814 7ffbaaa6db80  1 -- [XXXX::7930]:0/51387864 --> [XXXX::7108]:6806/48758 -- osd_op(unknown.0.0:74 38.c 38:3351fad7:::usage.3:head [call rgw.user_usage_log_trim] snapc 0=[] ondisk+write+known_if_redirected e157808) v8 -- 0x55c304be7360 con 0
2018-03-05 20:17:47.463463 7ffb991e2700  1 -- [XXXX::7930]:0/51387864 <== osd.2 [XXXX::7108]:6806/48758 4 ==== osd_op_reply(74 usage.3 [call] v157808'772976 uv263780 ondisk = 0) v8 ==== 151+0+0 (1671175069 0 0) 0x7ffb88027dc0 con 0x55c304c4b3c0

I'm going to attach the OSD debug*=20 log from one of the rgw.user_usage_log_trim processing runs