Hi, Initial installation was 15.2.0 and we’ve upgraded to 15.2.1. I’ve verified and the RGWs and OSDs are running the same version - 15.2.1. I’ve created a bug report for this issue and uploaded the debug logs as requested: https://tracker.ceph.com/issues/45412 <https://tracker.ceph.com/issues/45412> Thanks, James. > On 6 May 2020, at 14:55, Pritha Srivastava <prsrivas@xxxxxxxxxx> wrote: > > From these: > crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 active+clean] do_osd_op > sync_read 4096~1024 > 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( > v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 > ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) > [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 > active+clean] read got 1024 / 1024 bytes from obj 5:9a6dd8c0:gc::gc.0:head > 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( > v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 > ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) > [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 > active+clean] method called response length=0 > 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( > v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 > ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) > [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 > active+clean] do_osd_ops error: (22) Invalid argument > > I suspect that there is an error while reading the queue head data, but to > debug that further, I need rgw logs and osd logs at debug level 20, > specifically debug_objclass=20 on osds. > > Although you have mentioned that you installed a new Ceph cluster with > Octopus v15.2.1, but just wanted to make sure that rgw, and osd versions > are the same - 15.2.1? > > Thanks, > Pritha > > On Wed, May 6, 2020 at 12:26 PM James, GleSYS <james.mcewan@xxxxxxxxx> > wrote: > >> Hi, >> >> Yes, it’s the same error with “—include-all”. I am currently awaiting >> confirmation of my account creation on the tracker site. >> >> In the meantime, here are some logs which I’ve obtained: >> >> radosgw-admin gc list --debug-rgw=10 --debug-ms=10: >> 2020-05-06T06:06:33.922+0000 7ff4ccffb700 1 -- >> [2a00:X:X:6::4]:0/232669402 <== osd.2 v2:[2a00:X:X:6::15]:6804/216047 2 >> ==== osd_op_reply(32 gc.31 [create,call,call,call] v5395'1345263 uv1345179 >> ondisk = -125 ((125) Operation canceled)) v8 ==== 275+0+0 (crc 0 0 0) >> 0x7ff4c4076af0 con 0x55ca738cd010 >> 2020-05-06T06:06:33.922+0000 7ff4ccffb700 10 -- >> [2a00:X:X:6::4]:0/232669402 dispatch_throttle_release 275 to dispatch >> throttler 275/104857600 >> 2020-05-06T06:06:33.922+0000 7ff4e0111080 1 -- >> [2a00:X:X:6::4]:0/232669402 --> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] -- >> osd_op(unknown.0.0:33 5.9 5:9a6dd8c0:gc::gc.0:head [call rgw.gc_list >> in=25b] snapc 0=[] ondisk+read+known_if_redirected e5395) v8 -- >> 0x55ca73935790 con 0x55ca7389f680 >> 2020-05-06T06:06:33.922+0000 7ff4e0111080 5 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).send_message enqueueing message m=0x55ca73935790 type=42 >> osd_op(client.610887.0:33 5.9 5:9a6dd8c0:gc::gc.0:head [call rgw.gc_list >> in=25b] snapc 0=[] ondisk+read+known_if_redirected e5395) v8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 -- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 msgr2=0x55ca738a1ab0 crc :-1 >> s=STATE_CONNECTION_ESTABLISHED l=1).handle_write >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).write_event >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 5 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).write_message sending message m=0x55ca73935790 seq=4 >> osd_op(client.610887.0:33 5.9 5:9a6dd8c0:gc::gc.0:head [call rgw.gc_list >> in=25b] snapc 0=[] ondisk+read+known_if_redirected e5395) v8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 -- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 msgr2=0x55ca738a1ab0 crc :-1 >> s=STATE_CONNECTION_ESTABLISHED l=1)._try_send sent bytes 330 remaining >> bytes 0 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).write_message sending 0x55ca73935790 done. >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).handle_read_frame_preamble_main got new segment: len=41 align=8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).handle_read_frame_preamble_main got new segment: len=148 align=8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).handle_read_frame_preamble_main got new segment: len=0 align=8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).handle_read_frame_preamble_main got new segment: len=15 align=4096 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=THROTTLE_DONE pgs=23 cs=0 l=1 >> rx=0 tx=0).handle_read_frame_dispatch tag=17 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 5 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=THROTTLE_DONE pgs=23 cs=0 l=1 >> rx=0 tx=0).handle_message got 148 + 0 + 15 byte message. envelope type=43 >> src osd.15 off 0 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 5 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READ_MESSAGE_COMPLETE pgs=23 >> cs=0 l=1 rx=0 tx=0).handle_message received message m=0x7ff4c0007110 seq=4 >> from=osd.15 type=43 osd_op_reply(33 gc.0 [call out=15b] v0'0 uv481420 >> ondisk = 0) v8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 1 -- >> [2a00:X:X:6::4]:0/232669402 <== osd.15 v2:[2a00:X:X:6::18]:6800/383606 4 >> ==== osd_op_reply(33 gc.0 [call out=15b] v0'0 uv481420 ondisk = 0) v8 ==== >> 148+0+15 (crc 0 0 0) 0x7ff4c0007110 con 0x55ca7389f680 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 -- >> [2a00:X:X:6::4]:0/232669402 dispatch_throttle_release 163 to dispatch >> throttler 163/104857600 >> 2020-05-06T06:06:33.922+0000 7ff4e0111080 1 -- >> [2a00:X:X:6::4]:0/232669402 --> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] -- >> osd_op(unknown.0.0:34 5.9 5:9a6dd8c0:gc::gc.0:head [call version.read >> in=11b] snapc 0=[] ondisk+read+known_if_redirected e5395) v8 -- >> 0x55ca73934780 con 0x55ca7389f680 >> 2020-05-06T06:06:33.922+0000 7ff4e0111080 5 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).send_message enqueueing message m=0x55ca73934780 type=42 >> osd_op(client.610887.0:34 5.9 5:9a6dd8c0:gc::gc.0:head [call version.read >> in=11b] snapc 0=[] ondisk+read+known_if_redirected e5395) v8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 -- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 msgr2=0x55ca738a1ab0 crc :-1 >> s=STATE_CONNECTION_ESTABLISHED l=1).handle_write >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).write_event >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 5 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).write_message sending message m=0x55ca73934780 seq=5 >> osd_op(client.610887.0:34 5.9 5:9a6dd8c0:gc::gc.0:head [call version.read >> in=11b] snapc 0=[] ondisk+read+known_if_redirected e5395) v8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 -- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 msgr2=0x55ca738a1ab0 crc :-1 >> s=STATE_CONNECTION_ESTABLISHED l=1)._try_send sent bytes 316 remaining >> bytes 0 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).write_message sending 0x55ca73934780 done. >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).handle_read_frame_preamble_main got new segment: len=41 align=8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).handle_read_frame_preamble_main got new segment: len=148 align=8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).handle_read_frame_preamble_main got new segment: len=0 align=8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).handle_read_frame_preamble_main got new segment: len=24 align=4096 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=THROTTLE_DONE pgs=23 cs=0 l=1 >> rx=0 tx=0).handle_read_frame_dispatch tag=17 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 5 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=THROTTLE_DONE pgs=23 cs=0 l=1 >> rx=0 tx=0).handle_message got 148 + 0 + 24 byte message. envelope type=43 >> src osd.15 off 0 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 5 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READ_MESSAGE_COMPLETE pgs=23 >> cs=0 l=1 rx=0 tx=0).handle_message received message m=0x7ff4c0007110 seq=5 >> from=osd.15 type=43 osd_op_reply(34 gc.0 [call out=24b] v0'0 uv481420 >> ondisk = 0) v8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 1 -- >> [2a00:X:X:6::4]:0/232669402 <== osd.15 v2:[2a00:X:X:6::18]:6800/383606 5 >> ==== osd_op_reply(34 gc.0 [call out=24b] v0'0 uv481420 ondisk = 0) v8 ==== >> 148+0+24 (crc 0 0 0) 0x7ff4c0007110 con 0x55ca7389f680 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 -- >> [2a00:X:X:6::4]:0/232669402 dispatch_throttle_release 172 to dispatch >> throttler 172/104857600 >> 2020-05-06T06:06:33.922+0000 7ff4e0111080 1 -- >> [2a00:X:X:6::4]:0/232669402 --> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] -- >> osd_op(unknown.0.0:35 5.9 5:9a6dd8c0:gc::gc.0:head [call >> rgw_gc.rgw_gc_queue_list_entries in=46b] snapc 0=[] >> ondisk+read+known_if_redirected e5395) v8 -- 0x55ca73935790 con >> 0x55ca7389f680 >> 2020-05-06T06:06:33.922+0000 7ff4e0111080 5 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).send_message enqueueing message m=0x55ca73935790 type=42 >> osd_op(client.610887.0:35 5.9 5:9a6dd8c0:gc::gc.0:head [call >> rgw_gc.rgw_gc_queue_list_entries in=46b] snapc 0=[] >> ondisk+read+known_if_redirected e5395) v8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 -- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 msgr2=0x55ca738a1ab0 crc :-1 >> s=STATE_CONNECTION_ESTABLISHED l=1).handle_write >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).write_event >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 5 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).write_message sending message m=0x55ca73935790 seq=6 >> osd_op(client.610887.0:35 5.9 5:9a6dd8c0:gc::gc.0:head [call >> rgw_gc.rgw_gc_queue_list_entries in=46b] snapc 0=[] >> ondisk+read+known_if_redirected e5395) v8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 -- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 msgr2=0x55ca738a1ab0 crc :-1 >> s=STATE_CONNECTION_ESTABLISHED l=1)._try_send sent bytes 351 remaining >> bytes 0 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).write_message sending 0x55ca73935790 done. >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).handle_read_frame_preamble_main got new segment: len=41 align=8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READY pgs=23 cs=0 l=1 rx=0 >> tx=0).handle_read_frame_preamble_main got new segment: len=148 align=8 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=THROTTLE_DONE pgs=23 cs=0 l=1 >> rx=0 tx=0).handle_read_frame_dispatch tag=17 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 5 --2- >> [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=THROTTLE_DONE pgs=23 cs=0 l=1 >> rx=0 tx=0).handle_message got 148 + 0 + 0 byte message. envelope type=43 >> src osd.15 off 0 >> ERROR: failed to list objs: 2020-05-06T06:06:33.922+0000 7ff4cbff9700 5 >> --2- [2a00:X:X:6::4]:0/232669402 >> >> [v2:[2a00:X:X:6::18]:6800/383606,v1:[2a00:X:X:6::18]:6801/383606] >> conn(0x55ca7389f680 0x55ca738a1ab0 crc :-1 s=READ_MESSAGE_COMPLETE pgs=23 >> cs=0 l=1 rx=0 tx=0).handle_message received message m=0x7ff4c0007110 seq=6 >> from=osd.15 type=43 osd_op_reply(35 gc.0 [call] v0'0 uv0 ondisk = -22 ((22) >> Invalid argument)) v8 >> (22) Invalid argument >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 1 -- >> [2a00:X:X:6::4]:0/232669402 <== osd.15 v2:[2a00:X:X:6::18]:6800/383606 6 >> ==== osd_op_reply(35 gc.0 [call] v0'0 uv0 ondisk = -22 ((22) Invalid >> argument)) v8 ==== 148+0+0 (crc 0 0 0) 0x7ff4c0007110 con 0x55ca7389f680 >> 2020-05-06T06:06:33.922+0000 7ff4cbff9700 10 -- >> [2a00:X:X:6::4]:0/232669402 dispatch_throttle_release 148 to dispatch >> throttler 148/104857600 >> 2020-05-06T06:06:33.926+0000 7ff4a1fdb700 2 >> RGWDataChangesLog::ChangesRenewThread: start >> >> >> /var/log/ceph/ceph-osd.15.log >> >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 5395 dequeue_op >> 0x555f68a5a580 prio 63 cost 46 latency 0.000009 osd_op(client.610887.0:35 >> 5.9 5.31bb659 (undecoded) ondisk+read+known_if_redirected e5395) v8 pg >> pg[5.9( v 5395'481462 (5387'478000,5395'481462] local-lis >> /les=5394/5395 n=48 ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 >> pruub=12.023579210s) [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod >> 5395'481461 mlcod 5395'481461 active+clean] >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] _handle_message: 0x555f68a5a580 >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] do_op osd_op(client.610887.0:35 5.9 5:9a6dd8c0:gc::gc.0:head >> [call rgw_gc.rgw_gc_queue_list_entries in=46b] snapc 0=[] >> ondisk+read+known_if_redirected e5395) v8 may_read -> read-ordered flags >> ondisk+read+known_if_redirected >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] get_object_context: found obc in cache: 0x555f67056dc0 >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] get_object_context: 0x555f67056dc0 5:9a6dd8c0:gc::gc.0:head >> rwstate(none n=0 w=0) oi: 5:9a6dd8c0:gc::gc.0:head(5395'481420 >> client.325552.0:1326193 dirty s 732076 uv 481420 alloc_hint [0 0 0]) >> exists: 1 ssc: 0x555f671f51e0 snapset: 0=[]:{} >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] find_object_context 5:9a6dd8c0:gc::gc.0:head @head >> oi=5:9a6dd8c0:gc::gc.0:head(5395'481420 client.325552.0:1326193 dirty s >> 732076 uv 481420 alloc_hint [0 0 0]) >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] execute_ctx 0x555f68255200 >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] execute_ctx 5:9a6dd8c0:gc::gc.0:head [call >> rgw_gc.rgw_gc_queue_list_entries in=46b] ov 5395'481420 >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] do_osd_op 5:9a6dd8c0:gc::gc.0:head [call >> rgw_gc.rgw_gc_queue_list_entries in=46b] >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] do_osd_op call rgw_gc.rgw_gc_queue_list_entries in=46b >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] call method rgw_gc.rgw_gc_queue_list_entries >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] do_osd_op 5:9a6dd8c0:gc::gc.0:head [sync_read 0~1024] >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] do_osd_op sync_read 0~1024 >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] read got 1024 / 1024 bytes from obj 5:9a6dd8c0:gc::gc.0:head >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] do_osd_op 5:9a6dd8c0:gc::gc.0:head [sync_read 1024~3090 >> [fadvise_sequential]] >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] do_osd_op sync_read 1024~3090 [fadvise_sequential] >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] read got 3090 / 3090 bytes from obj 5:9a6dd8c0:gc::gc.0:head >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] do_osd_op 5:9a6dd8c0:gc::gc.0:head [sync_read 4096~1024] >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] do_osd_op sync_read 4096~1024 >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] read got 1024 / 1024 bytes from obj 5:9a6dd8c0:gc::gc.0:head >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] method called response length=0 >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 pg_epoch: 5395 pg[5.9( >> v 5395'481462 (5387'478000,5395'481462] local-lis/les=5394/5395 n=48 >> ec=67/67 lis/c=5394/5394 les/c/f=5395/5395/0 sis=5394 pruub=12.023579210s) >> [15,21,26] r=0 lpr=5394 crt=5395'481460 lcod 5395'481461 mlcod 5395'481461 >> active+clean] do_osd_ops error: (22) Invalid argument >> 2020-05-06T08:06:33.925+0200 7f73b554a700 10 osd.15 5395 dequeue_op >> 0x555f68a5a580 finish >> >> Can you draw any conclusions from these logs? >> >> Regards, >> James >> >>> On 6 May 2020, at 05:03, Pritha Srivastava <prsrivas@xxxxxxxxxx> wrote: >>> >>> Hi James, >>> >>> Does radosgw-admin gc list --include-all, give the same error? If yes, >> can >>> you please open a tracker issue and share rgw and osd logs? >>> >>> Thanks, >>> Pritha >>> >>> On Wed, May 6, 2020 at 12:22 AM James, GleSYS <james.mcewan@xxxxxxxxx> >>> wrote: >>> >>>> Hi, >>>> >>>> We’ve recently installed a new Ceph cluster running Octopus 15.2.1, and >>>> we’re using RGW with an erasure coded backed pool. >>>> >>>> I started to get a suspicion that deleted objects were not getting >> cleaned >>>> up properly, and I wanted to verify this by checking the garbage >> collector. >>>> >>>> That’s when I discovered that when I run “radosgw-admin gc list”, I get >>>> the following error: >>>> "ERROR: failed to list objs: (22) Invalid argument” >>>> >>>> When running the command with the debug-rgw=20 flag, I see a bit more >>>> information: >>>> 2020-05-05T18:39:19.455+0000 7f3312d82080 20 add_watcher() i=0 >>>> 2020-05-05T18:39:19.455+0000 7f3312d82080 20 add_watcher() i=1 >>>> 2020-05-05T18:39:19.455+0000 7f3312d82080 20 add_watcher() i=2 >>>> 2020-05-05T18:39:19.455+0000 7f3312d82080 20 add_watcher() i=3 >>>> 2020-05-05T18:39:19.455+0000 7f3312d82080 20 add_watcher() i=4 >>>> 2020-05-05T18:39:19.455+0000 7f3312d82080 20 add_watcher() i=5 >>>> 2020-05-05T18:39:19.455+0000 7f3312d82080 20 add_watcher() i=6 >>>> 2020-05-05T18:39:19.455+0000 7f3312d82080 20 add_watcher() i=7 >>>> 2020-05-05T18:39:19.455+0000 7f3312d82080 2 all 8 watchers are set, >>>> enabling cache >>>> 2020-05-05T18:39:19.455+0000 7f3312d82080 20 check_secure_mon_conn(): >> auth >>>> registy supported: methods=[2,1] modes=[2,1] >>>> 2020-05-05T18:39:19.455+0000 7f3312d82080 20 check_secure_mon_conn(): >>>> method 1 is insecure >>>> 2020-05-05T18:39:19.455+0000 7f32d4fd9700 2 >>>> RGWDataChangesLog::ChangesRenewThread: start >>>> 2020-05-05T18:39:19.519+0000 7f3246ffd700 20 reqs_thread_entry: start >>>> 2020-05-05T18:39:19.519+0000 7f3312d82080 20 init_complete bucket index >>>> max shards: 11 >>>> 2020-05-05T18:39:19.519+0000 7f3244ff9700 20 reqs_thread_entry: start >>>> 2020-05-05T18:39:19.519+0000 7f323affd700 20 reqs_thread_entry: start >>>> ERROR: failed to list objs: (22) Invalid argument >>>> 2020-05-05T18:39:19.523+0000 7f32d4fd9700 2 >>>> RGWDataChangesLog::ChangesRenewThread: start >>>> 2020-05-05T18:39:19.523+0000 7f3312d82080 20 remove_watcher() i=0 >>>> 2020-05-05T18:39:19.523+0000 7f3312d82080 2 removed watcher, disabling >>>> cache >>>> 2020-05-05T18:39:19.523+0000 7f3312d82080 20 remove_watcher() i=1 >>>> 2020-05-05T18:39:19.523+0000 7f3312d82080 20 remove_watcher() i=2 >>>> 2020-05-05T18:39:19.527+0000 7f3312d82080 20 remove_watcher() i=3 >>>> 2020-05-05T18:39:19.527+0000 7f3312d82080 20 remove_watcher() i=4 >>>> 2020-05-05T18:39:19.527+0000 7f3312d82080 20 remove_watcher() i=5 >>>> 2020-05-05T18:39:19.527+0000 7f3312d82080 20 remove_watcher() i=6 >>>> 2020-05-05T18:39:19.527+0000 7f3312d82080 20 remove_watcher() I=7 >>>> >>>> I find very little information regarding this error, so I wondered if >>>> someone here could help me troubleshoot the issue? >>>> >>>> Thanks, >>>> James. >>>> _______________________________________________ >>>> ceph-users mailing list -- ceph-users@xxxxxxx >>>> To unsubscribe send an email to ceph-users-leave@xxxxxxx >>>> >>> _______________________________________________ >>> ceph-users mailing list -- ceph-users@xxxxxxx >>> To unsubscribe send an email to ceph-users-leave@xxxxxxx >> >> > _______________________________________________ > ceph-users mailing list -- ceph-users@xxxxxxx > To unsubscribe send an email to ceph-users-leave@xxxxxxx _______________________________________________ ceph-users mailing list -- ceph-users@xxxxxxx To unsubscribe send an email to ceph-users-leave@xxxxxxx
 |