Project

General

Profile

Bug #58190 ยป TextFile5.txt

very long running rgw_gc_queue_list_entries() (the beginning and a middle part) - Igor Fedotov, 12/06/2022 04:25 PM

 
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 37853 dequeue_op 0x5628a8582840 prio 63 cost 46 latency 13.122089 osd_op(client.41674241.0:5229631 3.1f 3:fde4dd55:gc::gc.26:head [call rgw_gc.rgw_gc_queue_list_entries in=46b] snapc 0=[] RETRY=146 ondisk+retry+read+known_if_redirected e37852) v8 pg pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}]
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] _handle_message: 0x5628a8582840
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_op osd_op(client.41674241.0:5229631 3.1f 3:fde4dd55:gc::gc.26:head [call rgw_gc.rgw_gc_queue_list_entries in=46b] snapc 0=[] RETRY=146 ondisk+retry+read+known_if_redirected e37852) v8 may_read -> read-ordered flags ondisk+retry+read+known_if_redirected
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] get_object_context: obc NOT found in cache: 3:fde4dd55:gc::gc.26:head
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 bluestore(/var/lib/ceph/osd/ceph-221) getattr 3.1f_head #3:fde4dd55:gc::gc.26:head# _ = 0
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 bluestore(/var/lib/ceph/osd/ceph-221) getattr 3.1f_head #3:fde4dd55:gc::gc.26:head# snapset = 0
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] populate_obc_watchers 3:fde4dd55:gc::gc.26:head
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] get_object_context: creating obc from disk: 0x562886f9ac00
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] get_object_context: 0x562886f9ac00 3:fde4dd55:gc::gc.26:head rwstate(none n=0 w=0) oi: 3:fde4dd55:gc::gc.26:head(37736'848600 client.41693195.0:6213653 dirty s 130370606 uv 848600 alloc_hint [0 0 0]) exists: 1 ssc: 0x5628b6835c80 snapset: 0=[]:{}
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] find_object_context 3:fde4dd55:gc::gc.26:head @head oi=3:fde4dd55:gc::gc.26:head(37736'848600 client.41693195.0:6213653 dirty s 130370606 uv 848600 alloc_hint [0 0 0])
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] execute_ctx 0x5628b10b1600
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] execute_ctx 3:fde4dd55:gc::gc.26:head [call rgw_gc.rgw_gc_queue_list_entries in=46b] ov 37736'848600
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op 3:fde4dd55:gc::gc.26:head [call rgw_gc.rgw_gc_queue_list_entries in=46b]
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op call rgw_gc.rgw_gc_queue_list_entries in=46b
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] call method rgw_gc.rgw_gc_queue_list_entries
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op 3:fde4dd55:gc::gc.26:head [sync_read 0~1024]
2022-12-06T15:18:45.585+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op sync_read 0~1024
2022-12-06T15:18:45.585+0000 7fe921550700 10 bluestore(/var/lib/ceph/osd/ceph-221) _txc_state_proc txc 0x5628b0132080 kv_submitted
2022-12-06T15:18:45.585+0000 7fe921550700 10 bluestore(/var/lib/ceph/osd/ceph-221) _txc_state_proc txc 0x5628b0132080 finishing
2022-12-06T15:18:45.585+0000 7fe921550700 10 bluestore(/var/lib/ceph/osd/ceph-221) _txc_release_alloc(sync) 0x5628b0132080 []
2022-12-06T15:18:45.597+0000 7fe90f91d700 10 bluestore(/var/lib/ceph/osd/ceph-221) read 3.1f_head #3:fde4dd55:gc::gc.26:head# 0x0~400 = 1024
2022-12-06T15:18:45.597+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] read got 1024 / 1024 bytes from obj 3:fde4dd55:gc::gc.26:head
2022-12-06T15:18:45.597+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:299: INFO: queue_list_entries(): front is: 2/20308704, tail is 2/81470662
2022-12-06T15:18:45.597+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:308: INFO: queue_list_entries(): start_offset is 20308704
2022-12-06T15:18:45.597+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:317: INFO: queue_list_entries(): size_to_read is 1024
2022-12-06T15:18:45.597+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op 3:fde4dd55:gc::gc.26:head [sync_read 20308704~1024]
2022-12-06T15:18:45.597+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op sync_read 20308704~1024
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 bluestore(/var/lib/ceph/osd/ceph-221) read 3.1f_head #3:fde4dd55:gc::gc.26:head# 0x135e2e0~400 = 1024
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] read got 1024 / 1024 bytes from obj 3:fde4dd55:gc::gc.26:head
2022-12-06T15:18:45.601+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:332: INFO: queue_list_entries(): Entry start offset accounting for leftover data is 20308704
2022-12-06T15:18:45.601+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:336: INFO: queue_list_entries(): size of chunk 1024
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:343: INFO: queue_list_entries(): index: 0, size_to_process: 1024
2022-12-06T15:18:45.601+0000 7fe90f91d700 5 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:353: INFO: queue_list_entries(): offset: 2/20308704
2022-12-06T15:18:45.601+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:387: INFO: queue_list_entries(): data size: 1175
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:401: INFO: queue_list_entries(): not enough data to read data, breaking out!
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:418: INFO: num_ops: 0 and op.max is 100
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:308: INFO: queue_list_entries(): start_offset is 20309728
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:317: INFO: queue_list_entries(): size_to_read is 1024
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op 3:fde4dd55:gc::gc.26:head [sync_read 20309728~1024]
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op sync_read 20309728~1024
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 bluestore(/var/lib/ceph/osd/ceph-221) read 3.1f_head #3:fde4dd55:gc::gc.26:head# 0x135e6e0~400 = 1024
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] read got 1024 / 1024 bytes from obj 3:fde4dd55:gc::gc.26:head
2022-12-06T15:18:45.601+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:332: INFO: queue_list_entries(): Entry start offset accounting for leftover data is 20308714
2022-12-06T15:18:45.601+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:336: INFO: queue_list_entries(): size of chunk 2038
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:343: INFO: queue_list_entries(): index: 0, size_to_process: 2038
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:343: INFO: queue_list_entries(): index: 1175, size_to_process: 863
2022-12-06T15:18:45.601+0000 7fe90f91d700 5 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:353: INFO: queue_list_entries(): offset: 2/20309889
2022-12-06T15:18:45.601+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:387: INFO: queue_list_entries(): data size: 4143
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:401: INFO: queue_list_entries(): not enough data to read data, breaking out!
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:418: INFO: num_ops: 1 and op.max is 100
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:308: INFO: queue_list_entries(): start_offset is 20310752
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:317: INFO: queue_list_entries(): size_to_read is 1024
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op 3:fde4dd55:gc::gc.26:head [sync_read 20310752~1024]
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op sync_read 20310752~1024
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 bluestore(/var/lib/ceph/osd/ceph-221) read 3.1f_head #3:fde4dd55:gc::gc.26:head# 0x135eae0~400 = 1024
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] read got 1024 / 1024 bytes from obj 3:fde4dd55:gc::gc.26:head
2022-12-06T15:18:45.601+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:332: INFO: queue_list_entries(): Entry start offset accounting for leftover data is 20309899
2022-12-06T15:18:45.601+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:336: INFO: queue_list_entries(): size of chunk 1877
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:343: INFO: queue_list_entries(): index: 0, size_to_process: 1877
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:401: INFO: queue_list_entries(): not enough data to read data, breaking out!
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:418: INFO: num_ops: 1 and op.max is 100
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:308: INFO: queue_list_entries(): start_offset is 20311776
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:317: INFO: queue_list_entries(): size_to_read is 1024
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op 3:fde4dd55:gc::gc.26:head [sync_read 20311776~1024]
2022-12-06T15:18:45.601+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op sync_read 20311776~1024
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 bluestore(/var/lib/ceph/osd/ceph-221) read 3.1f_head #3:fde4dd55:gc::gc.26:head# 0x135eee0~400 = 1024
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] read got 1024 / 1024 bytes from obj 3:fde4dd55:gc::gc.26:head
2022-12-06T15:18:45.605+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:332: INFO: queue_list_entries(): Entry start offset accounting for leftover data is 20309899
2022-12-06T15:18:45.605+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:336: INFO: queue_list_entries(): size of chunk 2901
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:343: INFO: queue_list_entries(): index: 0, size_to_process: 2901
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:401: INFO: queue_list_entries(): not enough data to read data, breaking out!
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:418: INFO: num_ops: 1 and op.max is 100
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:308: INFO: queue_list_entries(): start_offset is 20312800
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:317: INFO: queue_list_entries(): size_to_read is 1024
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op 3:fde4dd55:gc::gc.26:head [sync_read 20312800~1024]
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op sync_read 20312800~1024
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 bluestore(/var/lib/ceph/osd/ceph-221) read 3.1f_head #3:fde4dd55:gc::gc.26:head# 0x135f2e0~400 = 1024
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] read got 1024 / 1024 bytes from obj 3:fde4dd55:gc::gc.26:head
2022-12-06T15:18:45.605+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:332: INFO: queue_list_entries(): Entry start offset accounting for leftover data is 20309899
2022-12-06T15:18:45.605+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:336: INFO: queue_list_entries(): size of chunk 3925
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:343: INFO: queue_list_entries(): index: 0, size_to_process: 3925
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:401: INFO: queue_list_entries(): not enough data to read data, breaking out!
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:418: INFO: num_ops: 1 and op.max is 100
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:308: INFO: queue_list_entries(): start_offset is 20313824
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:317: INFO: queue_list_entries(): size_to_read is 1024
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op 3:fde4dd55:gc::gc.26:head [sync_read 20313824~1024]
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op sync_read 20313824~1024
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 bluestore(/var/lib/ceph/osd/ceph-221) read 3.1f_head #3:fde4dd55:gc::gc.26:head# 0x135f6e0~400 = 1024
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] read got 1024 / 1024 bytes from obj 3:fde4dd55:gc::gc.26:head
2022-12-06T15:18:45.605+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:332: INFO: queue_list_entries(): Entry start offset accounting for leftover data is 20309899
2022-12-06T15:18:45.605+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:336: INFO: queue_list_entries(): size of chunk 4949
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:343: INFO: queue_list_entries(): index: 0, size_to_process: 4949
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:343: INFO: queue_list_entries(): index: 4143, size_to_process: 806
2022-12-06T15:18:45.605+0000 7fe90f91d700 5 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:353: INFO: queue_list_entries(): offset: 2/20314042
2022-12-06T15:18:45.605+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:387: INFO: queue_list_entries(): data size: 1950
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:401: INFO: queue_list_entries(): not enough data to read data, breaking out!
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:418: INFO: num_ops: 2 and op.max is 100
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:308: INFO: queue_list_entries(): start_offset is 20314848
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:317: INFO: queue_list_entries(): size_to_read is 1024
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op 3:fde4dd55:gc::gc.26:head [sync_read 20314848~1024]
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op sync_read 20314848~1024
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 bluestore(/var/lib/ceph/osd/ceph-221) read 3.1f_head #3:fde4dd55:gc::gc.26:head# 0x135fae0~400 = 1024
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0 active+undersized+degraded mbc={}] read got 1024 / 1024 bytes from obj 3:fde4dd55:gc::gc.26:head
2022-12-06T15:18:45.605+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:332: INFO: queue_list_entries(): Entry start offset accounting for leftover data is 20314052
2022-12-06T15:18:45.605+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:336: INFO: queue_list_entries(): size of chunk 1820
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:343: INFO: queue_list_entries(): index: 0, size_to_process: 1820
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:401: INFO: queue_list_entries(): not enough data to read data, breaking out!
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:418: INFO: num_ops: 2 and op.max is 100
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:308: INFO: queue_list_entries(): start_offset is 20315872
2022-12-06T15:18:45.605+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:317: INFO: queue_list_entries(): size_to_read is 1024
...
2022-12-06T15:41:50.572+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0
active+undersized+degraded mbc={}] do_osd_op 3:fde4dd55:gc::gc.26:head [sync_read 70236896~1024]
2022-12-06T15:41:50.572+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0
active+undersized+degraded mbc={}] do_osd_op sync_read 70236896~1024
2022-12-06T15:41:50.572+0000 7fe90f91d700 10 bluestore(/var/lib/ceph/osd/ceph-221) read 3.1f_head #3:fde4dd55:gc::gc.26:head# 0x42fbae0~400 = 1024
2022-12-06T15:41:50.572+0000 7fe90f91d700 10 osd.221 pg_epoch: 37853 pg[3.1f( v 37756'848602 (37111'846423,37756'848602] local-lis/les=37852/37853 n=6 ec=13/13 lis/c=37852/37080 les/c/f=37853/37082/0 sis=37852) [221,49] r=0 lpr=37852 pi=[37080,37852)/2 crt=37756'848602 lcod 0'0 mlcod 0'0
active+undersized+degraded mbc={}] read got 1024 / 1024 bytes from obj 3:fde4dd55:gc::gc.26:head
2022-12-06T15:41:50.572+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:332: INFO: queue_list_entries(): Entry start offset accounting for leftover data is 20318720
2022-12-06T15:41:50.572+0000 7fe90f91d700 20 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:336: INFO: queue_list_entries(): size of chunk 49919200
2022-12-06T15:41:50.572+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:343: INFO: queue_list_entries(): index: 0, size_to_process: 49919200
2022-12-06T15:41:50.576+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:401: INFO: queue_list_entries(): not enough data to read data, breaking out!
2022-12-06T15:41:50.576+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:418: INFO: num_ops: 6 and op.max is 100
2022-12-06T15:41:50.576+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:308: INFO: queue_list_entries(): start_offset is 70237920
2022-12-06T15:41:50.576+0000 7fe90f91d700 10 <cls> /home/abuild/rpmbuild/BUILD/ceph-16.2.10/src/cls/queue/cls_queue_src.cc:317: INFO: queue_list_entries(): size_to_read is 1024
...
    (1-1/1)