>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
