Hi Igor In ceph.conf: [osd] debug bluestore = 10/30 systemctl start ceph-osd@2 ~# ls -alh /var/log/ceph/ceph-osd.2.log -rw-r--r-- 1 ceph ceph 416M paź 25 21:08 /var/log/ceph/ceph-osd.2.log /var/log/ceph/ceph-osd.2.log | gzip > ceph-osd.2.log.gz Full compressed log on gdrive: https://drive.google.com/file/d/1Z3Yh92RQBgE1IGRsLdJrgM8qvLHXotBw/view?usp=sharing ~# tail -n 700 /var/log/ceph/ceph-osd.2.log -540> 2021-10-25T20:52:24.141+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.a_head oid #25:50000000::::head# = 0 -539> 2021-10-25T20:52:24.141+0200 7f0c27906f00 20 _unpin0x55655e742800 #25:50000000::::head# unpinned -538> 2021-10-25T20:52:24.141+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.a_head oid #25:50000000::::head# -537> 2021-10-25T20:52:24.141+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002320 in 0x55655e742800) lookup -536> 2021-10-25T20:52:24.141+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002320 in 0x55655e742800) lookup #25:50000000::::head# hit 0x556564efea00 1 1 0 -535> 2021-10-25T20:52:24.141+0200 7f0c27906f00 20 _pin0x55655e742800 #25:50000000::::head# pinned -534> 2021-10-25T20:52:24.141+0200 7f0c27906f00 20 bluestore.onode(0x556564efea00).flush flush done -533> 2021-10-25T20:52:24.141+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830DB'._epoch' -> _epoch -532> 2021-10-25T20:52:24.141+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830DB'._infover' -> _infover -531> 2021-10-25T20:52:24.141+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.a_head oid #25:50000000::::head# = 0 -530> 2021-10-25T20:52:24.141+0200 7f0c27906f00 20 _unpin0x55655e742800 #25:50000000::::head# unpinned -529> 2021-10-25T20:52:24.189+0200 7f0c1adc4700 20 bluestore.MempoolThread(0x55655d98eb90) _resize_shards cache_size: 733714456 kv_alloc: 318767104 kv_used: 61399496 kv_onode_alloc: 42949672 kv_onode_used: -22 meta_alloc: 293601280 meta_used: 26058 data_alloc: 100663296 data_used: 40960 -528> 2021-10-25T20:52:24.189+0200 7f0c1adc4700 30 bluestore.MempoolThread(0x55655d98eb90) _resize_shards max_shard_onodes: 2816 max_shard_buffer: 3145728 -527> 2021-10-25T20:52:24.237+0200 7f0c27906f00 5 osd.2 pg_epoch: 23167 pg[25.a(unlocked)] enter Initial -526> 2021-10-25T20:52:24.237+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_apply_kv onode 0x556564efe500 had 1 -525> 2021-10-25T20:52:24.237+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.a_head oid #25:50000000::::head# -524> 2021-10-25T20:52:24.237+0200 7f0c165bb700 10 HybridAllocator allocate want 0x10000 unit 0x10000 max_alloc_size 0x10000 hint 0x0 -523> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002320 in 0x55655e742800) lookup -522> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002320 in 0x55655e742800) lookup #25:50000000::::head# hit 0x556564efea00 1 1 0 -521> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 _pin0x55655e742800 #25:50000000::::head# pinned -520> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore.onode(0x556564efea00).flush flush done -519> 2021-10-25T20:52:24.237+0200 7f0c165bb700 20 AvlAllocator _allocate first fit=5111808 size=65536 -518> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830DB'._biginfo' -> _biginfo -517> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830DB'._info' -> _info -516> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830DB'._infover' -> _infover -515> 2021-10-25T20:52:24.237+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.a_head oid #25:50000000::::head# = 0 -514> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 _unpin0x55655e742800 #25:50000000::::head# unpinned -513> 2021-10-25T20:52:24.237+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) stat 25.a_head #25:50000000::::head# -512> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002320 in 0x55655e742800) lookup -511> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002320 in 0x55655e742800) lookup #25:50000000::::head# hit 0x556564efea00 1 1 0 -510> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 _pin0x55655e742800 #25:50000000::::head# pinned -509> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 _unpin0x55655e742800 #25:50000000::::head# unpinned -508> 2021-10-25T20:52:24.237+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator 25.a_head #25:50000000::::head# -507> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002320 in 0x55655e742800) lookup -506> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002320 in 0x55655e742800) lookup #25:50000000::::head# hit 0x556564efea00 1 1 0 -505> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 _pin0x55655e742800 #25:50000000::::head# pinned -504> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore.onode(0x556564efea00).flush flush done -503> 2021-10-25T20:52:24.237+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator has_omap = 1 -502> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x55656e4c5340) valid is at 0x0000000004F830DB'._biginfo' -501> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x55656e4c5340) valid is at 0x0000000004F830DB'._epoch' -500> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x55656e4c5340) valid is at 0x0000000004F830DB'._info' -499> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x55656e4c5340) valid is at 0x0000000004F830DB'._infover' -498> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x55656e4c5340) valid is at 0x0000000004F830DB'.may_include_deletes_in_missing' -497> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x55656e4c5340) valid is at 0x0000000004F830DB7E -496> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 _unpin0x55655e742800 #25:50000000::::head# unpinned -495> 2021-10-25T20:52:24.237+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) set_collection_opts 25.a_head options pg_num_min 1 -494> 2021-10-25T20:52:24.237+0200 7f0c27906f00 5 osd.2 pg_epoch: 23167 pg[25.a( empty local-lis/les=11033/11034 n=0 ec=10991/10977 lis/c=11033/11033 les/c/f=11034/11034/0 sis=11033) [8,2,4] r=1 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.000461 0 0.000000 -493> 2021-10-25T20:52:24.237+0200 7f0c27906f00 5 osd.2 pg_epoch: 23167 pg[25.a( empty local-lis/les=11033/11034 n=0 ec=10991/10977 lis/c=11033/11033 les/c/f=11034/11034/0 sis=11033) [8,2,4] r=1 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] enter Reset -492> 2021-10-25T20:52:24.237+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) queue_transactions ch 0x5565670021e0 25.a_head -491> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_create osr 0x556564d96580 = 0x55655d98b180 seq 1 -490> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 _dump_transaction transaction dump: { "ops": [ { "op_num": 0, "op_name": "touch", "collection": "25.a_head", "oid": "#25:50000000::::head#" } ] } -489> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002320 in 0x55655e742800) lookup -488> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002320 in 0x55655e742800) lookup #25:50000000::::head# hit 0x556564efea00 1 1 0 -487> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 _pin0x55655e742800 #25:50000000::::head# pinned -486> 2021-10-25T20:52:24.237+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.a_head #25:50000000::::head# -485> 2021-10-25T20:52:24.237+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.a_head #25:50000000::::head# = 0 -484> 2021-10-25T20:52:24.237+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_calc_cost 0x55655d98b180 cost 670195 (1 ios * 670000 + 195 bytes) -483> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_write_nodes txc 0x55655d98b180 onodes 0x556564efea00 shared_blobs -482> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore.extentmap(0x556564efeb50) update #25:50000000::::head# -481> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _record_onode onode #25:50000000::::head# is 31 (23 bytes onode + 2 bytes spanning blobs + 6 bytes inline extents) -480> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finalize_kv txc 0x55655d98b180 allocated 0x[] released 0x[] -479> 2021-10-25T20:52:24.237+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655d98b180 prepare -478> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish_io 0x55655d98b180 -477> 2021-10-25T20:52:24.237+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655d98b180 io_done -476> 2021-10-25T20:52:24.237+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.9_head oid #25:90000000::::head# -475> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002140 in 0x55655e740000) lookup -474> 2021-10-25T20:52:24.237+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002140 in 0x55655e740000) lookup #25:90000000::::head# miss -473> 2021-10-25T20:52:24.237+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(25.9_head 0x556567002000) get_onode oid #25:90000000::::head# key 0x7F800000000000001990000000'!!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F -472> 2021-10-25T20:52:24.241+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(25.9_head 0x556567002000) r 0 v.len 31 -471> 2021-10-25T20:52:24.241+0200 7f0c27906f00 20 bluestore.OnodeSpace(0x556567002140 in 0x55655e740000) add #25:90000000::::head# 0x556564efec80 -470> 2021-10-25T20:52:24.241+0200 7f0c27906f00 20 _add 0x55655e740000 #25:90000000::::head# added, num=1 -469> 2021-10-25T20:52:24.241+0200 7f0c27906f00 20 bluestore.onode(0x556564efec80).flush flush done -468> 2021-10-25T20:52:24.241+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.9_head oid #25:90000000::::head# = 0 -467> 2021-10-25T20:52:24.241+0200 7f0c27906f00 20 _unpin0x55655e740000 #25:90000000::::head# unpinned -466> 2021-10-25T20:52:24.241+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.9_head oid #25:90000000::::head# -465> 2021-10-25T20:52:24.241+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002140 in 0x55655e740000) lookup -464> 2021-10-25T20:52:24.241+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002140 in 0x55655e740000) lookup #25:90000000::::head# hit 0x556564efec80 1 1 0 -463> 2021-10-25T20:52:24.241+0200 7f0c27906f00 20 _pin0x55655e740000 #25:90000000::::head# pinned -462> 2021-10-25T20:52:24.241+0200 7f0c27906f00 20 bluestore.onode(0x556564efec80).flush flush done -461> 2021-10-25T20:52:24.241+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830E6'._epoch' -> _epoch -460> 2021-10-25T20:52:24.241+0200 7f0c1adc4700 20 bluestore.MempoolThread(0x55655d98eb90) _resize_shards cache_size: 733714456 kv_alloc: 318767104 kv_used: 61399496 kv_onode_alloc: 42949672 kv_onode_used: -22 meta_alloc: 293601280 meta_used: 26980 data_alloc: 100663296 data_used: 40960 -459> 2021-10-25T20:52:24.241+0200 7f0c1adc4700 30 bluestore.MempoolThread(0x55655d98eb90) _resize_shards max_shard_onodes: 3060 max_shard_buffer: 3145728 -458> 2021-10-25T20:52:24.253+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830E6'._infover' -> _infover -457> 2021-10-25T20:52:24.253+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.9_head oid #25:90000000::::head# = 0 -456> 2021-10-25T20:52:24.253+0200 7f0c27906f00 20 _unpin0x55655e740000 #25:90000000::::head# unpinned -455> 2021-10-25T20:52:24.253+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) read meta #-1:9325dd72:::osdmap.23155:0# 0x0~0 -454> 2021-10-25T20:52:24.253+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x5565670026e0 in 0x55655e648000) lookup -453> 2021-10-25T20:52:24.253+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x5565670026e0 in 0x55655e648000) lookup #-1:9325dd72:::osdmap.23155:0# miss -452> 2021-10-25T20:52:24.253+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x5565670025a0) get_onode oid #-1:9325dd72:::osdmap.23155:0# key 0x7F7FFFFFFFFFFFFFFF9325DD'r!osdmap.23155!='0x0000000000000000FFFFFFFFFFFFFFFF6F -451> 2021-10-25T20:52:24.265+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x5565670025a0) r 0 v.len 112 -450> 2021-10-25T20:52:24.265+0200 7f0c27906f00 20 bluestore.blob(0x55656e4c5650) get_ref 0x0~3fd7 Blob(0x55656e4c5650 blob([0x51ba0000~10000] csum+has_unused crc32c/0x1000 unused=0xfff0) use_tracker(0x0 0x0) SharedBlob(0x55656e4c56c0 sbid 0x0)) -449> 2021-10-25T20:52:24.265+0200 7f0c27906f00 20 bluestore.blob(0x55656e4c5650) get_ref init 0x10000, 10000 -448> 2021-10-25T20:52:24.265+0200 7f0c27906f00 20 bluestore.OnodeSpace(0x5565670026e0 in 0x55655e648000) add #-1:9325dd72:::osdmap.23155:0# 0x556564efef00 -447> 2021-10-25T20:52:24.265+0200 7f0c27906f00 20 _add 0x55655e648000 #-1:9325dd72:::osdmap.23155:0# added, num=7 -446> 2021-10-25T20:52:24.265+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _do_read 0x0~3fd7 size 0x3fd7 (16343) -445> 2021-10-25T20:52:24.265+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _do_read will do buffered read -444> 2021-10-25T20:52:24.265+0200 7f0c27906f00 30 bluestore.extentmap(0x556564eff050) fault_range 0x0~3fd7 -443> 2021-10-25T20:52:24.265+0200 7f0c27906f00 30 _dump_onode 0x556564efef00 #-1:9325dd72:::osdmap.23155:0# nid 83552689 size 0x3fd7 (16343) expected_object_size 0 expected_write_size 0 in 0 shards, 0 spanning blobs -442> 2021-10-25T20:52:24.265+0200 7f0c27906f00 30 _dump_extent_map 0x0~3fd7: 0x0~3fd7 Blob(0x55656e4c5650 blob([0x51ba0000~10000] csum+has_unused crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) SharedBlob(0x55656e4c56c0 sbid 0x0)) -441> 2021-10-25T20:52:24.265+0200 7f0c27906f00 30 _dump_extent_map csum: [6483e9d4,bf9ed52,e111b5d9,7baa3b0c,0,0,0,0,0,0,0,0,0,0,0,0] -440> 2021-10-25T20:52:24.265+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _read_cache blob Blob(0x55656e4c5650 blob([0x51ba0000~10000] csum+has_unused crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) SharedBlob(0x55656e4c56c0 sbid 0x0)) need 0x0~3fd7 cache has 0x[] -439> 2021-10-25T20:52:24.265+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) _read_cache will read 0x0: 0x0~3fd7 -438> 2021-10-25T20:52:24.265+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc blob Blob(0x55656e4c5650 blob([0x51ba0000~10000] csum+has_unused crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) SharedBlob(0x55656e4c56c0 sbid 0x0)) need {<0x0, 0x4000> : [0x0:0~3fd7]} -437> 2021-10-25T20:52:24.265+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc region 0x0: 0x0 reading 0x0~4000 -436> 2021-10-25T20:52:24.265+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _do_read waiting for aio -435> 2021-10-25T20:52:24.273+0200 7f0c165bb700 10 AvlAllocator _release offset 0x480000 length 0x20000 -434> 2021-10-25T20:52:24.273+0200 7f0c165bb700 10 AvlAllocator _release offset 0xb20000 length 0x10000 -433> 2021-10-25T20:52:24.273+0200 7f0c165bb700 10 AvlAllocator _release offset 0xbb0000 length 0x20000 -432> 2021-10-25T20:52:24.273+0200 7f0c165bb700 10 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread nid_max now 83562945 -431> 2021-10-25T20:52:24.273+0200 7f0c165bb700 10 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread blobid_max now 2304895 -430> 2021-10-25T20:52:24.273+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread wake -429> 2021-10-25T20:52:24.273+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committed 1 cleaned 0 in 0.132197276s (0.000000137s flush + 0.132197142s kv commit) -428> 2021-10-25T20:52:24.273+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread kv_committed <0x55655eee1c00> -427> 2021-10-25T20:52:24.273+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread deferred_stable <> -426> 2021-10-25T20:52:24.273+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655eee1c00 kv_submitted -425> 2021-10-25T20:52:24.273+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_committed_kv txc 0x55655eee1c00 -424> 2021-10-25T20:52:24.273+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committing 1 submitting 1 deferred done 0 stable 0 -423> 2021-10-25T20:52:24.273+0200 7f0c165bb700 30 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committing <0x55655d98b180> -422> 2021-10-25T20:52:24.273+0200 7f0c165bb700 30 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread submitting <0x55655d98b180> -421> 2021-10-25T20:52:24.273+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655eee1c00 finishing -420> 2021-10-25T20:52:24.273+0200 7f0c165bb700 30 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread deferred_done <> -419> 2021-10-25T20:52:24.273+0200 7f0c165bb700 30 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread deferred_stable <> -418> 2021-10-25T20:52:24.273+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish 0x55655eee1c00 onodes 0x556564efe500 -417> 2021-10-25T20:52:24.273+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish txc 0x55655eee1c00 done -416> 2021-10-25T20:52:24.273+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish osr 0x556564d966e0 q now empty -415> 2021-10-25T20:52:24.273+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_release_alloc(sync) 0x55655eee1c00 [] -414> 2021-10-25T20:52:24.273+0200 7f0c1b5c5700 20 _unpin0x55655e745000 #25:d0000000::::head# unpinned -413> 2021-10-25T20:52:24.273+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread sleep -412> 2021-10-25T20:52:24.273+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_apply_kv onode 0x556564efea00 had 1 -411> 2021-10-25T20:52:24.289+0200 7f0c1adc4700 20 bluestore.MempoolThread(0x55655d98eb90) _resize_shards cache_size: 733714456 kv_alloc: 318767104 kv_used: 61407880 kv_onode_alloc: 42949672 kv_onode_used: -22 meta_alloc: 293601280 meta_used: 28154 data_alloc: 100663296 data_used: 40960 -410> 2021-10-25T20:52:24.289+0200 7f0c1adc4700 30 bluestore.MempoolThread(0x55655d98eb90) _resize_shards max_shard_onodes: 3258 max_shard_buffer: 3145728 -409> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _generate_read_result_bl blob Blob(0x55656e4c5650 blob([0x51ba0000~10000] csum+has_unused crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) SharedBlob(0x55656e4c56c0 sbid 0x0)) need 0x{<0x0, 0x4000> : [0x0:0~3fd7]} -408> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore.BufferSpace(0x55656e4c56d8 in 0x55655d92ef70) _discard 0x0~4000 -407> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 _add level 1 near 0 on buffer(0x556567e984e0 space 0x55656e4c56d8 0x0~4000 clean) which has cache_private 0 -406> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) _generate_read_result_bl assemble 0x0: data from 0x0~3fd7 -405> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 _unpin0x55655e648000 #-1:9325dd72:::osdmap.23155:0# unpinned -404> 2021-10-25T20:52:24.289+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) read meta #-1:9325dd72:::osdmap.23155:0# 0x0~3fd7 = 16343 -403> 2021-10-25T20:52:24.289+0200 7f0c27906f00 5 osd.2 pg_epoch: 23155 pg[25.9(unlocked)] enter Initial -402> 2021-10-25T20:52:24.289+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.9_head oid #25:90000000::::head# -401> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002140 in 0x55655e740000) lookup -400> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002140 in 0x55655e740000) lookup #25:90000000::::head# hit 0x556564efec80 1 1 0 -399> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 _pin0x55655e740000 #25:90000000::::head# pinned -398> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore.onode(0x556564efec80).flush flush done -397> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830E6'._biginfo' -> _biginfo -396> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830E6'._info' -> _info -395> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830E6'._infover' -> _infover -394> 2021-10-25T20:52:24.289+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.9_head oid #25:90000000::::head# = 0 -393> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 _unpin0x55655e740000 #25:90000000::::head# unpinned -392> 2021-10-25T20:52:24.289+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) stat 25.9_head #25:90000000::::head# -391> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002140 in 0x55655e740000) lookup -390> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002140 in 0x55655e740000) lookup #25:90000000::::head# hit 0x556564efec80 1 1 0 -389> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 _pin0x55655e740000 #25:90000000::::head# pinned -388> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 _unpin0x55655e740000 #25:90000000::::head# unpinned -387> 2021-10-25T20:52:24.289+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator 25.9_head #25:90000000::::head# -386> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002140 in 0x55655e740000) lookup -385> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002140 in 0x55655e740000) lookup #25:90000000::::head# hit 0x556564efec80 1 1 0 -384> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 _pin0x55655e740000 #25:90000000::::head# pinned -383> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore.onode(0x556564efec80).flush flush done -382> 2021-10-25T20:52:24.289+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator has_omap = 1 -381> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x55656e4c5c00) valid is at 0x0000000004F830E6'._biginfo' -380> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x55656e4c5c00) valid is at 0x0000000004F830E6'._epoch' -379> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x55656e4c5c00) valid is at 0x0000000004F830E6'._info' -378> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x55656e4c5c00) valid is at 0x0000000004F830E6'._infover' -377> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x55656e4c5c00) valid is at 0x0000000004F830E6'.may_include_deletes_in_missing' -376> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x55656e4c5c00) valid is at 0x0000000004F830E67E -375> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 _unpin0x55655e740000 #25:90000000::::head# unpinned -374> 2021-10-25T20:52:24.289+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) set_collection_opts 25.9_head options pg_num_min 1 -373> 2021-10-25T20:52:24.289+0200 7f0c27906f00 5 osd.2 pg_epoch: 23155 pg[25.9( empty local-lis/les=12563/12564 n=0 ec=10991/10977 lis/c=12563/12563 les/c/f=12564/12564/0 sis=12563) [2,9,0] r=0 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.000402 0 0.000000 -372> 2021-10-25T20:52:24.289+0200 7f0c27906f00 5 osd.2 pg_epoch: 23155 pg[25.9( empty local-lis/les=12563/12564 n=0 ec=10991/10977 lis/c=12563/12563 les/c/f=12564/12564/0 sis=12563) [2,9,0] r=0 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] enter Reset -371> 2021-10-25T20:52:24.289+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) queue_transactions ch 0x556567002000 25.9_head -370> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_create osr 0x556564d96420 = 0x55655d98aa80 seq 1 -369> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 _dump_transaction transaction dump: { "ops": [ { "op_num": 0, "op_name": "touch", "collection": "25.9_head", "oid": "#25:90000000::::head#" } ] } -368> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002140 in 0x55655e740000) lookup -367> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556567002140 in 0x55655e740000) lookup #25:90000000::::head# hit 0x556564efec80 1 1 0 -366> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 _pin0x55655e740000 #25:90000000::::head# pinned -365> 2021-10-25T20:52:24.289+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.9_head #25:90000000::::head# -364> 2021-10-25T20:52:24.289+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.9_head #25:90000000::::head# = 0 -363> 2021-10-25T20:52:24.289+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_calc_cost 0x55655d98aa80 cost 670195 (1 ios * 670000 + 195 bytes) -362> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_write_nodes txc 0x55655d98aa80 onodes 0x556564efec80 shared_blobs -361> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore.extentmap(0x556564efedd0) update #25:90000000::::head# -360> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _record_onode onode #25:90000000::::head# is 31 (23 bytes onode + 2 bytes spanning blobs + 6 bytes inline extents) -359> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finalize_kv txc 0x55655d98aa80 allocated 0x[] released 0x[] -358> 2021-10-25T20:52:24.289+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655d98aa80 prepare -357> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish_io 0x55655d98aa80 -356> 2021-10-25T20:52:24.289+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655d98aa80 io_done -355> 2021-10-25T20:52:24.289+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.18_head oid #25:18000000::::head# -354> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95d60 in 0x55655e768000) lookup -353> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95d60 in 0x55655e768000) lookup #25:18000000::::head# miss -352> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(25.18_head 0x556564d95c20) get_onode oid #25:18000000::::head# key 0x7F800000000000001918000000'!!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F -351> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(25.18_head 0x556564d95c20) r 0 v.len 31 -350> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore.OnodeSpace(0x556564d95d60 in 0x55655e768000) add #25:18000000::::head# 0x556564eff180 -349> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 _add 0x55655e768000 #25:18000000::::head# added, num=1 -348> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore.onode(0x556564eff180).flush flush done -347> 2021-10-25T20:52:24.289+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.18_head oid #25:18000000::::head# = 0 -346> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 _unpin0x55655e768000 #25:18000000::::head# unpinned -345> 2021-10-25T20:52:24.289+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.18_head oid #25:18000000::::head# -344> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95d60 in 0x55655e768000) lookup -343> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95d60 in 0x55655e768000) lookup #25:18000000::::head# hit 0x556564eff180 1 1 0 -342> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 _pin0x55655e768000 #25:18000000::::head# pinned -341> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore.onode(0x556564eff180).flush flush done -340> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830E4'._epoch' -> _epoch -339> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830E4'._infover' -> _infover -338> 2021-10-25T20:52:24.289+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.18_head oid #25:18000000::::head# = 0 -337> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 _unpin0x55655e768000 #25:18000000::::head# unpinned -336> 2021-10-25T20:52:24.289+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) read meta #-1:987ddd72:::osdmap.23163:0# 0x0~0 -335> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x5565670026e0 in 0x55655e648000) lookup -334> 2021-10-25T20:52:24.289+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x5565670026e0 in 0x55655e648000) lookup #-1:987ddd72:::osdmap.23163:0# miss -333> 2021-10-25T20:52:24.289+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x5565670025a0) get_onode oid #-1:987ddd72:::osdmap.23163:0# key 0x7F7FFFFFFFFFFFFFFF987DDD'r!osdmap.23163!='0x0000000000000000FFFFFFFFFFFFFFFF6F -332> 2021-10-25T20:52:24.301+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x5565670025a0) r 0 v.len 112 -331> 2021-10-25T20:52:24.301+0200 7f0c27906f00 20 bluestore.blob(0x55656e4c5f10) get_ref 0x0~3fd7 Blob(0x55656e4c5f10 blob([0x53bc0000~10000] csum+has_unused crc32c/0x1000 unused=0xfff0) use_tracker(0x0 0x0) SharedBlob(0x55656e4c5f80 sbid 0x0)) -330> 2021-10-25T20:52:24.301+0200 7f0c27906f00 20 bluestore.blob(0x55656e4c5f10) get_ref init 0x10000, 10000 -329> 2021-10-25T20:52:24.301+0200 7f0c27906f00 20 bluestore.OnodeSpace(0x5565670026e0 in 0x55655e648000) add #-1:987ddd72:::osdmap.23163:0# 0x556564eff400 -328> 2021-10-25T20:52:24.301+0200 7f0c27906f00 20 _add 0x55655e648000 #-1:987ddd72:::osdmap.23163:0# added, num=8 -327> 2021-10-25T20:52:24.301+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _do_read 0x0~3fd7 size 0x3fd7 (16343) -326> 2021-10-25T20:52:24.301+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _do_read will do buffered read -325> 2021-10-25T20:52:24.301+0200 7f0c27906f00 30 bluestore.extentmap(0x556564eff550) fault_range 0x0~3fd7 -324> 2021-10-25T20:52:24.301+0200 7f0c27906f00 30 _dump_onode 0x556564eff400 #-1:987ddd72:::osdmap.23163:0# nid 83552705 size 0x3fd7 (16343) expected_object_size 0 expected_write_size 0 in 0 shards, 0 spanning blobs -323> 2021-10-25T20:52:24.301+0200 7f0c27906f00 30 _dump_extent_map 0x0~3fd7: 0x0~3fd7 Blob(0x55656e4c5f10 blob([0x53bc0000~10000] csum+has_unused crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) SharedBlob(0x55656e4c5f80 sbid 0x0)) -322> 2021-10-25T20:52:24.301+0200 7f0c27906f00 30 _dump_extent_map csum: [cc222d0e,bf9ed52,e111b5d9,9e1c4300,0,0,0,0,0,0,0,0,0,0,0,0] -321> 2021-10-25T20:52:24.301+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _read_cache blob Blob(0x55656e4c5f10 blob([0x53bc0000~10000] csum+has_unused crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) SharedBlob(0x55656e4c5f80 sbid 0x0)) need 0x0~3fd7 cache has 0x[] -320> 2021-10-25T20:52:24.301+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) _read_cache will read 0x0: 0x0~3fd7 -319> 2021-10-25T20:52:24.301+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc blob Blob(0x55656e4c5f10 blob([0x53bc0000~10000] csum+has_unused crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) SharedBlob(0x55656e4c5f80 sbid 0x0)) need {<0x0, 0x4000> : [0x0:0~3fd7]} -318> 2021-10-25T20:52:24.301+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc region 0x0: 0x0 reading 0x0~4000 -317> 2021-10-25T20:52:24.301+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _do_read waiting for aio -316> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _generate_read_result_bl blob Blob(0x55656e4c5f10 blob([0x53bc0000~10000] csum+has_unused crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) SharedBlob(0x55656e4c5f80 sbid 0x0)) need 0x{<0x0, 0x4000> : [0x0:0~3fd7]} -315> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore.BufferSpace(0x55656e4c5f98 in 0x55655d92ef70) _discard 0x0~4000 -314> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 _add level 1 near 0 on buffer(0x5565716a8420 space 0x55656e4c5f98 0x0~4000 clean) which has cache_private 0 -313> 2021-10-25T20:52:24.309+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) _generate_read_result_bl assemble 0x0: data from 0x0~3fd7 -312> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 _unpin0x55655e648000 #-1:987ddd72:::osdmap.23163:0# unpinned -311> 2021-10-25T20:52:24.309+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) read meta #-1:987ddd72:::osdmap.23163:0# 0x0~3fd7 = 16343 -310> 2021-10-25T20:52:24.309+0200 7f0c27906f00 5 osd.2 pg_epoch: 23163 pg[25.18(unlocked)] enter Initial -309> 2021-10-25T20:52:24.309+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.18_head oid #25:18000000::::head# -308> 2021-10-25T20:52:24.309+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95d60 in 0x55655e768000) lookup -307> 2021-10-25T20:52:24.309+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95d60 in 0x55655e768000) lookup #25:18000000::::head# hit 0x556564eff180 1 1 0 -306> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 _pin0x55655e768000 #25:18000000::::head# pinned -305> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore.onode(0x556564eff180).flush flush done -304> 2021-10-25T20:52:24.309+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830E4'._biginfo' -> _biginfo -303> 2021-10-25T20:52:24.309+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830E4'._info' -> _info -302> 2021-10-25T20:52:24.309+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830E4'._infover' -> _infover -301> 2021-10-25T20:52:24.309+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.18_head oid #25:18000000::::head# = 0 -300> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 _unpin0x55655e768000 #25:18000000::::head# unpinned -299> 2021-10-25T20:52:24.309+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) stat 25.18_head #25:18000000::::head# -298> 2021-10-25T20:52:24.309+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95d60 in 0x55655e768000) lookup -297> 2021-10-25T20:52:24.309+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95d60 in 0x55655e768000) lookup #25:18000000::::head# hit 0x556564eff180 1 1 0 -296> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 _pin0x55655e768000 #25:18000000::::head# pinned -295> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 _unpin0x55655e768000 #25:18000000::::head# unpinned -294> 2021-10-25T20:52:24.309+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator 25.18_head #25:18000000::::head# -293> 2021-10-25T20:52:24.309+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95d60 in 0x55655e768000) lookup -292> 2021-10-25T20:52:24.309+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95d60 in 0x55655e768000) lookup #25:18000000::::head# hit 0x556564eff180 1 1 0 -291> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 _pin0x55655e768000 #25:18000000::::head# pinned -290> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore.onode(0x556564eff180).flush flush done -289> 2021-10-25T20:52:24.309+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator has_omap = 1 -288> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d244d0) valid is at 0x0000000004F830E4'._biginfo' -287> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d244d0) valid is at 0x0000000004F830E4'._epoch' -286> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d244d0) valid is at 0x0000000004F830E4'._info' -285> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d244d0) valid is at 0x0000000004F830E4'._infover' -284> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d244d0) valid is at 0x0000000004F830E4'.may_include_deletes_in_missing' -283> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d244d0) valid is at 0x0000000004F830E47E -282> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 _unpin0x55655e768000 #25:18000000::::head# unpinned -281> 2021-10-25T20:52:24.309+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) set_collection_opts 25.18_head options pg_num_min 1 -280> 2021-10-25T20:52:24.309+0200 7f0c27906f00 5 osd.2 pg_epoch: 23163 pg[25.18( empty local-lis/les=12563/12564 n=0 ec=10991/10977 lis/c=12563/12563 les/c/f=12564/12564/0 sis=12563) [0,2,12] r=1 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.000404 0 0.000000 -279> 2021-10-25T20:52:24.309+0200 7f0c27906f00 5 osd.2 pg_epoch: 23163 pg[25.18( empty local-lis/les=12563/12564 n=0 ec=10991/10977 lis/c=12563/12563 les/c/f=12564/12564/0 sis=12563) [0,2,12] r=1 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] enter Reset -278> 2021-10-25T20:52:24.309+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) queue_transactions ch 0x556564d95c20 25.18_head -277> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_create osr 0x556564d96160 = 0x55655e642380 seq 1 -276> 2021-10-25T20:52:24.309+0200 7f0c27906f00 30 _dump_transaction transaction dump: { "ops": [ { "op_num": 0, "op_name": "touch", "collection": "25.18_head", "oid": "#25:18000000::::head#" } ] } -275> 2021-10-25T20:52:24.309+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95d60 in 0x55655e768000) lookup -274> 2021-10-25T20:52:24.309+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95d60 in 0x55655e768000) lookup #25:18000000::::head# hit 0x556564eff180 1 1 0 -273> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 _pin0x55655e768000 #25:18000000::::head# pinned -272> 2021-10-25T20:52:24.309+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.18_head #25:18000000::::head# -271> 2021-10-25T20:52:24.309+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.18_head #25:18000000::::head# = 0 -270> 2021-10-25T20:52:24.309+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_calc_cost 0x55655e642380 cost 670195 (1 ios * 670000 + 195 bytes) -269> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_write_nodes txc 0x55655e642380 onodes 0x556564eff180 shared_blobs -268> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore.extentmap(0x556564eff2d0) update #25:18000000::::head# -267> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _record_onode onode #25:18000000::::head# is 31 (23 bytes onode + 2 bytes spanning blobs + 6 bytes inline extents) -266> 2021-10-25T20:52:24.309+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finalize_kv txc 0x55655e642380 allocated 0x[] released 0x[] -265> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655e642380 prepare -264> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish_io 0x55655e642380 -263> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655e642380 io_done -262> 2021-10-25T20:52:24.313+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.15_head oid #25:a8000000::::head# -261> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95b80 in 0x55655e760000) lookup -260> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95b80 in 0x55655e760000) lookup #25:a8000000::::head# miss -259> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(25.15_head 0x556564d95a40) get_onode oid #25:a8000000::::head# key 0x7F8000000000000019A8000000'!!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F -258> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(25.15_head 0x556564d95a40) r 0 v.len 31 -257> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.OnodeSpace(0x556564d95b80 in 0x55655e760000) add #25:a8000000::::head# 0x556564eff680 -256> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _add 0x55655e760000 #25:a8000000::::head# added, num=1 -255> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.onode(0x556564eff680).flush flush done -254> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.15_head oid #25:a8000000::::head# = 0 -253> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _unpin0x55655e760000 #25:a8000000::::head# unpinned -252> 2021-10-25T20:52:24.313+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.15_head oid #25:a8000000::::head# -251> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95b80 in 0x55655e760000) lookup -250> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95b80 in 0x55655e760000) lookup #25:a8000000::::head# hit 0x556564eff680 1 1 0 -249> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _pin0x55655e760000 #25:a8000000::::head# pinned -248> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.onode(0x556564eff680).flush flush done -247> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830DF'._epoch' -> _epoch -246> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830DF'._infover' -> _infover -245> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.15_head oid #25:a8000000::::head# = 0 -244> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _unpin0x55655e760000 #25:a8000000::::head# unpinned -243> 2021-10-25T20:52:24.313+0200 7f0c27906f00 5 osd.2 pg_epoch: 23163 pg[25.15(unlocked)] enter Initial -242> 2021-10-25T20:52:24.313+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.15_head oid #25:a8000000::::head# -241> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95b80 in 0x55655e760000) lookup -240> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95b80 in 0x55655e760000) lookup #25:a8000000::::head# hit 0x556564eff680 1 1 0 -239> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _pin0x55655e760000 #25:a8000000::::head# pinned -238> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.onode(0x556564eff680).flush flush done -237> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830DF'._biginfo' -> _biginfo -236> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830DF'._info' -> _info -235> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830DF'._infover' -> _infover -234> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.15_head oid #25:a8000000::::head# = 0 -233> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _unpin0x55655e760000 #25:a8000000::::head# unpinned -232> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) stat 25.15_head #25:a8000000::::head# -231> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95b80 in 0x55655e760000) lookup -230> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95b80 in 0x55655e760000) lookup #25:a8000000::::head# hit 0x556564eff680 1 1 0 -229> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _pin0x55655e760000 #25:a8000000::::head# pinned -228> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _unpin0x55655e760000 #25:a8000000::::head# unpinned -227> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator 25.15_head #25:a8000000::::head# -226> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95b80 in 0x55655e760000) lookup -225> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95b80 in 0x55655e760000) lookup #25:a8000000::::head# hit 0x556564eff680 1 1 0 -224> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _pin0x55655e760000 #25:a8000000::::head# pinned -223> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.onode(0x556564eff680).flush flush done -222> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator has_omap = 1 -221> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d24770) valid is at 0x0000000004F830DF'._biginfo' -220> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d24770) valid is at 0x0000000004F830DF'._epoch' -219> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d24770) valid is at 0x0000000004F830DF'._info' -218> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d24770) valid is at 0x0000000004F830DF'._infover' -217> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d24770) valid is at 0x0000000004F830DF'.may_include_deletes_in_missing' -216> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d24770) valid is at 0x0000000004F830DF7E -215> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _unpin0x55655e760000 #25:a8000000::::head# unpinned -214> 2021-10-25T20:52:24.313+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) set_collection_opts 25.15_head options pg_num_min 1 -213> 2021-10-25T20:52:24.313+0200 7f0c27906f00 5 osd.2 pg_epoch: 23163 pg[25.15( empty local-lis/les=12563/12564 n=0 ec=10991/10977 lis/c=12563/12563 les/c/f=12564/12564/0 sis=12563) [0,5,2] r=2 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.000307 0 0.000000 -212> 2021-10-25T20:52:24.313+0200 7f0c27906f00 5 osd.2 pg_epoch: 23163 pg[25.15( empty local-lis/les=12563/12564 n=0 ec=10991/10977 lis/c=12563/12563 les/c/f=12564/12564/0 sis=12563) [0,5,2] r=2 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] enter Reset -211> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) queue_transactions ch 0x556564d95a40 25.15_head -210> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_create osr 0x556564d96000 = 0x55655eee1500 seq 1 -209> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 _dump_transaction transaction dump: { "ops": [ { "op_num": 0, "op_name": "touch", "collection": "25.15_head", "oid": "#25:a8000000::::head#" } ] } -208> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95b80 in 0x55655e760000) lookup -207> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d95b80 in 0x55655e760000) lookup #25:a8000000::::head# hit 0x556564eff680 1 1 0 -206> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _pin0x55655e760000 #25:a8000000::::head# pinned -205> 2021-10-25T20:52:24.313+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.15_head #25:a8000000::::head# -204> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.15_head #25:a8000000::::head# = 0 -203> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_calc_cost 0x55655eee1500 cost 670195 (1 ios * 670000 + 195 bytes) -202> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_write_nodes txc 0x55655eee1500 onodes 0x556564eff680 shared_blobs -201> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.extentmap(0x556564eff7d0) update #25:a8000000::::head# -200> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _record_onode onode #25:a8000000::::head# is 31 (23 bytes onode + 2 bytes spanning blobs + 6 bytes inline extents) -199> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finalize_kv txc 0x55655eee1500 allocated 0x[] released 0x[] -198> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655eee1500 prepare -197> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish_io 0x55655eee1500 -196> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655eee1500 io_done -195> 2021-10-25T20:52:24.313+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.0_head oid #25:00000000::::head# -194> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d959a0 in 0x55655e648000) lookup -193> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d959a0 in 0x55655e648000) lookup #25:00000000::::head# miss -192> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(25.0_head 0x556564d95860) get_onode oid #25:00000000::::head# key 0x7F800000000000001900000000'!!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F -191> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(25.0_head 0x556564d95860) r 0 v.len 31 -190> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.OnodeSpace(0x556564d959a0 in 0x55655e648000) add #25:00000000::::head# 0x556564eff900 -189> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _add 0x55655e648000 #25:00000000::::head# added, num=9 -188> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.onode(0x556564eff900).flush flush done -187> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.0_head oid #25:00000000::::head# = 0 -186> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _unpin0x55655e648000 #25:00000000::::head# unpinned -185> 2021-10-25T20:52:24.313+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.0_head oid #25:00000000::::head# -184> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d959a0 in 0x55655e648000) lookup -183> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d959a0 in 0x55655e648000) lookup #25:00000000::::head# hit 0x556564eff900 1 1 0 -182> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _pin0x55655e648000 #25:00000000::::head# pinned -181> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore.onode(0x556564eff900).flush flush done -180> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830EC'._epoch' -> _epoch -179> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830EC'._infover' -> _infover -178> 2021-10-25T20:52:24.313+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.0_head oid #25:00000000::::head# = 0 -177> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 _unpin0x55655e648000 #25:00000000::::head# unpinned -176> 2021-10-25T20:52:24.313+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) read meta #-1:9829dd72:::osdmap.23134:0# 0x0~0 -175> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x5565670026e0 in 0x55655e648000) lookup -174> 2021-10-25T20:52:24.313+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x5565670026e0 in 0x55655e648000) lookup #-1:9829dd72:::osdmap.23134:0# miss -173> 2021-10-25T20:52:24.313+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x5565670025a0) get_onode oid #-1:9829dd72:::osdmap.23134:0# key 0x7F7FFFFFFFFFFFFFFF9829DD'r!osdmap.23134!='0x0000000000000000FFFFFFFFFFFFFFFF6F -172> 2021-10-25T20:52:24.333+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread wake -171> 2021-10-25T20:52:24.333+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread kv_committed <0x55655d98b180> -170> 2021-10-25T20:52:24.333+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread deferred_stable <> -169> 2021-10-25T20:52:24.333+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655d98b180 kv_submitted -168> 2021-10-25T20:52:24.333+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_committed_kv txc 0x55655d98b180 -167> 2021-10-25T20:52:24.333+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655d98b180 finishing -166> 2021-10-25T20:52:24.333+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committed 1 cleaned 0 in 0.060099199s (0.000000128s flush + 0.060099073s kv commit) -165> 2021-10-25T20:52:24.333+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish 0x55655d98b180 onodes 0x556564efea00 -164> 2021-10-25T20:52:24.333+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish txc 0x55655d98b180 done -163> 2021-10-25T20:52:24.333+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish osr 0x556564d96580 q now empty -162> 2021-10-25T20:52:24.333+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_release_alloc(sync) 0x55655d98b180 [] -161> 2021-10-25T20:52:24.333+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committing 3 submitting 3 deferred done 0 stable 0 -160> 2021-10-25T20:52:24.333+0200 7f0c165bb700 30 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committing <0x55655d98aa80,0x55655e642380,0x55655eee1500> -159> 2021-10-25T20:52:24.333+0200 7f0c165bb700 30 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread submitting <0x55655d98aa80,0x55655e642380,0x55655eee1500> -158> 2021-10-25T20:52:24.333+0200 7f0c165bb700 30 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread deferred_done <> -157> 2021-10-25T20:52:24.333+0200 7f0c165bb700 30 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread deferred_stable <> -156> 2021-10-25T20:52:24.333+0200 7f0c1b5c5700 20 _unpin0x55655e742800 #25:50000000::::head# unpinned -155> 2021-10-25T20:52:24.333+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread sleep -154> 2021-10-25T20:52:24.333+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_apply_kv onode 0x556564efec80 had 1 -153> 2021-10-25T20:52:24.333+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_apply_kv onode 0x556564eff180 had 1 -152> 2021-10-25T20:52:24.333+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_apply_kv onode 0x556564eff680 had 1 -151> 2021-10-25T20:52:24.333+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x5565670025a0) r 0 v.len 113 -150> 2021-10-25T20:52:24.333+0200 7f0c27906f00 20 bluestore.blob(0x556571d24a10) get_ref 0x0~4083 Blob(0x556571d24a10 blob([0x49800000~10000] csum+has_unused crc32c/0x1000 unused=0xffe0) use_tracker(0x0 0x0) SharedBlob(0x556571d24a80 sbid 0x0)) -149> 2021-10-25T20:52:24.333+0200 7f0c27906f00 20 bluestore.blob(0x556571d24a10) get_ref init 0x10000, 10000 -148> 2021-10-25T20:52:24.333+0200 7f0c27906f00 20 bluestore.OnodeSpace(0x5565670026e0 in 0x55655e648000) add #-1:9829dd72:::osdmap.23134:0# 0x556564effb80 -147> 2021-10-25T20:52:24.333+0200 7f0c27906f00 20 _add 0x55655e648000 #-1:9829dd72:::osdmap.23134:0# added, num=10 -146> 2021-10-25T20:52:24.333+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _do_read 0x0~4083 size 0x4083 (16515) -145> 2021-10-25T20:52:24.333+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _do_read will do buffered read -144> 2021-10-25T20:52:24.333+0200 7f0c27906f00 30 bluestore.extentmap(0x556564effcd0) fault_range 0x0~4083 -143> 2021-10-25T20:52:24.333+0200 7f0c27906f00 30 _dump_onode 0x556564effb80 #-1:9829dd72:::osdmap.23134:0# nid 83552647 size 0x4083 (16515) expected_object_size 0 expected_write_size 0 in 0 shards, 0 spanning blobs -142> 2021-10-25T20:52:24.333+0200 7f0c27906f00 30 _dump_extent_map 0x0~4083: 0x0~4083 Blob(0x556571d24a10 blob([0x49800000~10000] csum+has_unused crc32c/0x1000 unused=0xffe0) use_tracker(0x10000 0x4083) SharedBlob(0x556571d24a80 sbid 0x0)) -141> 2021-10-25T20:52:24.333+0200 7f0c27906f00 30 _dump_extent_map csum: [74f8a3b3,bf9ed52,b32f206d,14d80ddc,4f188bfb,0,0,0,0,0,0,0,0,0,0,0] -140> 2021-10-25T20:52:24.333+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _read_cache blob Blob(0x556571d24a10 blob([0x49800000~10000] csum+has_unused crc32c/0x1000 unused=0xffe0) use_tracker(0x10000 0x4083) SharedBlob(0x556571d24a80 sbid 0x0)) need 0x0~4083 cache has 0x[] -139> 2021-10-25T20:52:24.333+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) _read_cache will read 0x0: 0x0~4083 -138> 2021-10-25T20:52:24.333+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc blob Blob(0x556571d24a10 blob([0x49800000~10000] csum+has_unused crc32c/0x1000 unused=0xffe0) use_tracker(0x10000 0x4083) SharedBlob(0x556571d24a80 sbid 0x0)) need {<0x0, 0x5000> : [0x0:0~4083]} -137> 2021-10-25T20:52:24.333+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc region 0x0: 0x0 reading 0x0~5000 -136> 2021-10-25T20:52:24.333+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _do_read waiting for aio -135> 2021-10-25T20:52:24.341+0200 7f0c1adc4700 20 bluestore.MempoolThread(0x55655d98eb90) _resize_shards cache_size: 733714456 kv_alloc: 318767104 kv_used: 61416264 kv_onode_alloc: 42949672 kv_onode_used: -22 meta_alloc: 293601280 meta_used: 33556 data_alloc: 100663296 data_used: 73728 -134> 2021-10-25T20:52:24.341+0200 7f0c1adc4700 30 bluestore.MempoolThread(0x55655d98eb90) _resize_shards max_shard_onodes: 4101 max_shard_buffer: 3145728 -133> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _generate_read_result_bl blob Blob(0x556571d24a10 blob([0x49800000~10000] csum+has_unused crc32c/0x1000 unused=0xffe0) use_tracker(0x10000 0x4083) SharedBlob(0x556571d24a80 sbid 0x0)) need 0x{<0x0, 0x5000> : [0x0:0~4083]} -132> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore.BufferSpace(0x556571d24a98 in 0x55655d92ef70) _discard 0x0~5000 -131> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 _add level 1 near 0 on buffer(0x5565615a3680 space 0x556571d24a98 0x0~5000 clean) which has cache_private 0 -130> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) _generate_read_result_bl assemble 0x0: data from 0x0~4083 -129> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 _unpin0x55655e648000 #-1:9829dd72:::osdmap.23134:0# unpinned -128> 2021-10-25T20:52:24.349+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) read meta #-1:9829dd72:::osdmap.23134:0# 0x0~4083 = 16515 -127> 2021-10-25T20:52:24.349+0200 7f0c27906f00 5 osd.2 pg_epoch: 23134 pg[25.0(unlocked)] enter Initial -126> 2021-10-25T20:52:24.349+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.0_head oid #25:00000000::::head# -125> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d959a0 in 0x55655e648000) lookup -124> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d959a0 in 0x55655e648000) lookup #25:00000000::::head# hit 0x556564eff900 1 1 0 -123> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 _pin0x55655e648000 #25:00000000::::head# pinned -122> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore.onode(0x556564eff900).flush flush done -121> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830EC'._biginfo' -> _biginfo -120> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830EC'._info' -> _info -119> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values got 0x0000000004F830EC'._infover' -> _infover -118> 2021-10-25T20:52:24.349+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.0_head oid #25:00000000::::head# = 0 -117> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 _unpin0x55655e648000 #25:00000000::::head# unpinned -116> 2021-10-25T20:52:24.349+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) stat 25.0_head #25:00000000::::head# -115> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d959a0 in 0x55655e648000) lookup -114> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d959a0 in 0x55655e648000) lookup #25:00000000::::head# hit 0x556564eff900 1 1 0 -113> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 _pin0x55655e648000 #25:00000000::::head# pinned -112> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 _unpin0x55655e648000 #25:00000000::::head# unpinned -111> 2021-10-25T20:52:24.349+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator 25.0_head #25:00000000::::head# -110> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d959a0 in 0x55655e648000) lookup -109> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d959a0 in 0x55655e648000) lookup #25:00000000::::head# hit 0x556564eff900 1 1 0 -108> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 _pin0x55655e648000 #25:00000000::::head# pinned -107> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore.onode(0x556564eff900).flush flush done -106> 2021-10-25T20:52:24.349+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator has_omap = 1 -105> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d25030) valid is at 0x0000000004F830EC'._biginfo' -104> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d25030) valid is at 0x0000000004F830EC'._epoch' -103> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d25030) valid is at 0x0000000004F830EC'._info' -102> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d25030) valid is at 0x0000000004F830EC'._infover' -101> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d25030) valid is at 0x0000000004F830EC'.may_include_deletes_in_missing' -100> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore.OmapIteratorImpl(0x556571d25030) valid is at 0x0000000004F830EC7E -99> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 _unpin0x55655e648000 #25:00000000::::head# unpinned -98> 2021-10-25T20:52:24.349+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) set_collection_opts 25.0_head options pg_num_min 1 -97> 2021-10-25T20:52:24.349+0200 7f0c27906f00 5 osd.2 pg_epoch: 23134 pg[25.0( empty local-lis/les=11017/11018 n=0 ec=10977/10977 lis/c=11017/11017 les/c/f=11018/11018/0 sis=11017) [6,2,12] r=1 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.000437 0 0.000000 -96> 2021-10-25T20:52:24.349+0200 7f0c27906f00 5 osd.2 pg_epoch: 23134 pg[25.0( empty local-lis/les=11017/11018 n=0 ec=10977/10977 lis/c=11017/11017 les/c/f=11018/11018/0 sis=11017) [6,2,12] r=1 lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] enter Reset -95> 2021-10-25T20:52:24.349+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) queue_transactions ch 0x556564d95860 25.0_head -94> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_create osr 0x55656531fe40 = 0x55655eee1880 seq 1 -93> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 _dump_transaction transaction dump: { "ops": [ { "op_num": 0, "op_name": "touch", "collection": "25.0_head", "oid": "#25:00000000::::head#" } ] } -92> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d959a0 in 0x55655e648000) lookup -91> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x556564d959a0 in 0x55655e648000) lookup #25:00000000::::head# hit 0x556564eff900 1 1 0 -90> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 _pin0x55655e648000 #25:00000000::::head# pinned -89> 2021-10-25T20:52:24.349+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.0_head #25:00000000::::head# -88> 2021-10-25T20:52:24.349+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.0_head #25:00000000::::head# = 0 -87> 2021-10-25T20:52:24.349+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_calc_cost 0x55655eee1880 cost 670195 (1 ios * 670000 + 195 bytes) -86> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_write_nodes txc 0x55655eee1880 onodes 0x556564eff900 shared_blobs -85> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore.extentmap(0x556564effa50) update #25:00000000::::head# -84> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _record_onode onode #25:00000000::::head# is 31 (23 bytes onode + 2 bytes spanning blobs + 6 bytes inline extents) -83> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finalize_kv txc 0x55655eee1880 allocated 0x[] released 0x[] -82> 2021-10-25T20:52:24.349+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655eee1880 prepare -81> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish_io 0x55655eee1880 -80> 2021-10-25T20:52:24.349+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655eee1880 io_done -79> 2021-10-25T20:52:24.349+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 23.4s3_head oid 3#23:20000000::::head# -78> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x55655f5c39a0 in 0x55655e732800) lookup -77> 2021-10-25T20:52:24.349+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x55655f5c39a0 in 0x55655e732800) lookup 3#23:20000000::::head# miss -76> 2021-10-25T20:52:24.349+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(23.4s3_head 0x55655f5c3860) get_onode oid 3#23:20000000::::head# key 0x83800000000000001720000000'!!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F -75> 2021-10-25T20:52:24.369+0200 7f0c27906f00 20 bluestore(/var/lib/ceph/osd/ceph-2).collection(23.4s3_head 0x55655f5c3860) r 0 v.len 31 -74> 2021-10-25T20:52:24.369+0200 7f0c27906f00 20 bluestore.OnodeSpace(0x55655f5c39a0 in 0x55655e732800) add 3#23:20000000::::head# 0x556566dad680 -73> 2021-10-25T20:52:24.369+0200 7f0c27906f00 20 _add 0x55655e732800 3#23:20000000::::head# added, num=1 -72> 2021-10-25T20:52:24.369+0200 7f0c27906f00 20 bluestore.onode(0x556566dad680).flush flush done -71> 2021-10-25T20:52:24.381+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committed 3 cleaned 0 in 0.050149284s (0.000000097s flush + 0.050149184s kv commit) -70> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread wake -69> 2021-10-25T20:52:24.381+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committing 1 submitting 1 deferred done 0 stable 0 -68> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread kv_committed <0x55655d98aa80,0x55655e642380,0x55655eee1500> -67> 2021-10-25T20:52:24.381+0200 7f0c165bb700 30 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committing <0x55655eee1880> -66> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread deferred_stable <> -65> 2021-10-25T20:52:24.381+0200 7f0c165bb700 30 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread submitting <0x55655eee1880> -64> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655d98aa80 kv_submitted -63> 2021-10-25T20:52:24.381+0200 7f0c165bb700 30 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread deferred_done <> -62> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_committed_kv txc 0x55655d98aa80 -61> 2021-10-25T20:52:24.381+0200 7f0c165bb700 30 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread deferred_stable <> -60> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655d98aa80 finishing -59> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish 0x55655d98aa80 onodes 0x556564efec80 -58> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish txc 0x55655d98aa80 done -57> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish osr 0x556564d96420 q now empty -56> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_release_alloc(sync) 0x55655d98aa80 [] -55> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 _unpin0x55655e740000 #25:90000000::::head# unpinned -54> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655e642380 kv_submitted -53> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_committed_kv txc 0x55655e642380 -52> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655e642380 finishing -51> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish 0x55655e642380 onodes 0x556564eff180 -50> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish txc 0x55655e642380 done -49> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish osr 0x556564d96160 q now empty -48> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_release_alloc(sync) 0x55655e642380 [] -47> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 _unpin0x55655e768000 #25:18000000::::head# unpinned -46> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655eee1500 kv_submitted -45> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_committed_kv txc 0x55655eee1500 -44> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655eee1500 finishing -43> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish 0x55655eee1500 onodes 0x556564eff680 -42> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish txc 0x55655eee1500 done -41> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish osr 0x556564d96000 q now empty -40> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_release_alloc(sync) 0x55655eee1500 [] -39> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 _unpin0x55655e760000 #25:a8000000::::head# unpinned -38> 2021-10-25T20:52:24.381+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_apply_kv onode 0x556564eff900 had 1 -37> 2021-10-25T20:52:24.381+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread sleep -36> 2021-10-25T20:52:24.389+0200 7f0c1adc4700 20 bluestore.MempoolThread(0x55655d98eb90) _resize_shards cache_size: 733714456 kv_alloc: 318767104 kv_used: 61563760 kv_onode_alloc: 42949672 kv_onode_used: -22 meta_alloc: 293601280 meta_used: 34622 data_alloc: 100663296 data_used: 94208 -35> 2021-10-25T20:52:24.389+0200 7f0c1adc4700 30 bluestore.MempoolThread(0x55655d98eb90) _resize_shards max_shard_onodes: 4240 max_shard_buffer: 3145728 -34> 2021-10-25T20:52:24.401+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 23.4s3_head oid 3#23:20000000::::head# = 0 -33> 2021-10-25T20:52:24.401+0200 7f0c27906f00 20 _unpin0x55655e732800 3#23:20000000::::head# unpinned -32> 2021-10-25T20:52:24.401+0200 7f0c27906f00 15 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 23.4s3_head oid 3#23:20000000::::head# -31> 2021-10-25T20:52:24.401+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x55655f5c39a0 in 0x55655e732800) lookup -30> 2021-10-25T20:52:24.401+0200 7f0c27906f00 30 bluestore.OnodeSpace(0x55655f5c39a0 in 0x55655e732800) lookup 3#23:20000000::::head# hit 0x556566dad680 1 1 0 -29> 2021-10-25T20:52:24.401+0200 7f0c27906f00 20 _pin0x55655e732800 3#23:20000000::::head# pinned -28> 2021-10-25T20:52:24.401+0200 7f0c27906f00 20 bluestore.onode(0x556566dad680).flush flush done -27> 2021-10-25T20:52:24.401+0200 7f0c27906f00 10 bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 23.4s3_head oid 3#23:20000000::::head# = 0 -26> 2021-10-25T20:52:24.401+0200 7f0c27906f00 20 _unpin0x55655e732800 3#23:20000000::::head# unpinned -25> 2021-10-25T20:52:24.429+0200 7f0c27906f00 -1 /build/ceph-16.2.6/src/osd/PG.cc: In function 'static int PG::peek_map_epoch(ObjectStore*, spg_t, epoch_t*)' thread 7f0c27906f00 time 2021-10-25T20:52:24.406635+0200 /build/ceph-16.2.6/src/osd/PG.cc: 1009: FAILED ceph_assert(values.size() == 2) ceph version 16.2.6 (ee28fb57e47e9f88813e24bbf4c14496ca299d31) pacific (stable) 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x152) [0x5565530c8e61] 2: /usr/bin/ceph-osd(+0xac6069) [0x5565530c9069] 3: (PG::peek_map_epoch(ObjectStore*, spg_t, unsigned int*)+0xa17) [0x556553253057] 4: (OSD::load_pgs()+0x6b4) [0x5565531c3ec4] 5: (OSD::init()+0x2b4e) [0x5565531d0a6e] 6: main() 7: __libc_start_main() 8: _start() -24> 2021-10-25T20:52:24.441+0200 7f0c1adc4700 20 bluestore.MempoolThread(0x55655d98eb90) _resize_shards cache_size: 733714456 kv_alloc: 318767104 kv_used: 62317464 kv_onode_alloc: 42949672 kv_onode_used: -22 meta_alloc: 293601280 meta_used: 34622 data_alloc: 100663296 data_used: 94208 -23> 2021-10-25T20:52:24.441+0200 7f0c1adc4700 30 bluestore.MempoolThread(0x55655d98eb90) _resize_shards max_shard_onodes: 4240 max_shard_buffer: 3145728 -22> 2021-10-25T20:52:24.441+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread wake -21> 2021-10-25T20:52:24.441+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committed 1 cleaned 0 in 0.060038690s (0.000000186s flush + 0.060038500s kv commit) -20> 2021-10-25T20:52:24.441+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread kv_committed <0x55655eee1880> -19> 2021-10-25T20:52:24.441+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread deferred_stable <> -18> 2021-10-25T20:52:24.441+0200 7f0c165bb700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread sleep -17> 2021-10-25T20:52:24.441+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655eee1880 kv_submitted -16> 2021-10-25T20:52:24.441+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_committed_kv txc 0x55655eee1880 -15> 2021-10-25T20:52:24.441+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 0x55655eee1880 finishing -14> 2021-10-25T20:52:24.441+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish 0x55655eee1880 onodes 0x556564eff900 -13> 2021-10-25T20:52:24.441+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish txc 0x55655eee1880 done -12> 2021-10-25T20:52:24.441+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish osr 0x55656531fe40 q now empty -11> 2021-10-25T20:52:24.441+0200 7f0c1b5c5700 10 bluestore(/var/lib/ceph/osd/ceph-2) _txc_release_alloc(sync) 0x55655eee1880 [] -10> 2021-10-25T20:52:24.441+0200 7f0c1b5c5700 20 _unpin0x55655e648000 #25:00000000::::head# unpinned -9> 2021-10-25T20:52:24.441+0200 7f0c1b5c5700 20 bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread sleep -8> 2021-10-25T20:52:24.489+0200 7f0c1adc4700 20 bluestore.MempoolThread(0x55655d98eb90) _resize_shards cache_size: 733714456 kv_alloc: 318767104 kv_used: 62317464 kv_onode_alloc: 42949672 kv_onode_used: -22 meta_alloc: 293601280 meta_used: 34622 data_alloc: 100663296 data_used: 94208 -7> 2021-10-25T20:52:24.489+0200 7f0c1adc4700 30 bluestore.MempoolThread(0x55655d98eb90) _resize_shards max_shard_onodes: 4240 max_shard_buffer: 3145728 -6> 2021-10-25T20:52:24.541+0200 7f0c1adc4700 20 bluestore.MempoolThread(0x55655d98eb90) _resize_shards cache_size: 733714456 kv_alloc: 318767104 kv_used: 62317464 kv_onode_alloc: 42949672 kv_onode_used: -22 meta_alloc: 293601280 meta_used: 34622 data_alloc: 100663296 data_used: 94208 -5> 2021-10-25T20:52:24.541+0200 7f0c1adc4700 30 bluestore.MempoolThread(0x55655d98eb90) _resize_shards max_shard_onodes: 4240 max_shard_buffer: 3145728 -4> 2021-10-25T20:52:24.589+0200 7f0c1adc4700 20 bluestore.MempoolThread(0x55655d98eb90) _resize_shards cache_size: 733714456 kv_alloc: 318767104 kv_used: 62317464 kv_onode_alloc: 42949672 kv_onode_used: -22 meta_alloc: 293601280 meta_used: 34622 data_alloc: 100663296 data_used: 94208 -3> 2021-10-25T20:52:24.589+0200 7f0c1adc4700 30 bluestore.MempoolThread(0x55655d98eb90) _resize_shards max_shard_onodes: 4240 max_shard_buffer: 3145728 -2> 2021-10-25T20:52:24.641+0200 7f0c1adc4700 20 bluestore.MempoolThread(0x55655d98eb90) _resize_shards cache_size: 733714456 kv_alloc: 318767104 kv_used: 62317464 kv_onode_alloc: 42949672 kv_onode_used: -22 meta_alloc: 293601280 meta_used: 34622 data_alloc: 100663296 data_used: 94208 -1> 2021-10-25T20:52:24.641+0200 7f0c1adc4700 30 bluestore.MempoolThread(0x55655d98eb90) _resize_shards max_shard_onodes: 4240 max_shard_buffer: 3145728 0> 2021-10-25T20:52:24.677+0200 7f0c27906f00 -1 *** Caught signal (Aborted) ** in thread 7f0c27906f00 thread_name:ceph-osd ceph version 16.2.6 (ee28fb57e47e9f88813e24bbf4c14496ca299d31) pacific (stable) 1: /lib/x86_64-linux-gnu/libpthread.so.0(+0x153c0) [0x7f0c27fb03c0] 2: gsignal() 3: abort() 4: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x1ad) [0x5565530c8ebc] 5: /usr/bin/ceph-osd(+0xac6069) [0x5565530c9069] 6: (PG::peek_map_epoch(ObjectStore*, spg_t, unsigned int*)+0xa17) [0x556553253057] 7: (OSD::load_pgs()+0x6b4) [0x5565531c3ec4] 8: (OSD::init()+0x2b4e) [0x5565531d0a6e] 9: main() 10: __libc_start_main() 11: _start() NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. --- logging levels --- 0/ 5 none 0/ 1 lockdep 0/ 1 context 1/ 1 crush 1/ 5 mds 1/ 5 mds_balancer 1/ 5 mds_locker 1/ 5 mds_log 1/ 5 mds_log_expire 1/ 5 mds_migrator 0/ 1 buffer 0/ 1 timer 0/ 1 filer 0/ 1 striper 0/ 1 objecter 0/ 5 rados 0/ 5 rbd 0/ 5 rbd_mirror 0/ 5 rbd_replay 0/ 5 rbd_pwl 0/ 5 journaler 0/ 5 objectcacher 0/ 5 immutable_obj_cache 0/ 5 client 1/ 5 osd 0/ 5 optracker 0/ 5 objclass 1/ 3 filestore 1/ 3 journal 0/ 0 ms 1/ 5 mon 0/10 monc 1/ 5 paxos 0/ 5 tp 1/ 5 auth 1/ 5 crypto 1/ 1 finisher 1/ 1 reserver 1/ 5 heartbeatmap 1/ 5 perfcounter 1/ 5 rgw 1/ 5 rgw_sync 1/10 civetweb 1/ 5 javaclient 1/ 5 asok 1/ 1 throttle 0/ 0 refs 1/ 5 compressor 10/30 bluestore 1/ 5 bluefs 1/ 3 bdev 1/ 5 kstore 4/ 5 rocksdb 4/ 5 leveldb 4/ 5 memdb 1/ 5 fuse 2/ 5 mgr 1/ 5 mgrc 1/ 5 dpdk 1/ 5 eventtrace 1/ 5 prioritycache 0/ 5 test 0/ 5 cephfs_mirror 0/ 5 cephsqlite -2/-2 (syslog threshold) -1/-1 (stderr threshold) --- pthread ID / name mapping for recent threads --- 139689891444480 / bstore_kv_sync 139689966978816 / bstore_mempool 139689975371520 / bstore_kv_final 139690180112128 / ceph-osd max_recent 10000 max_new 10000 log_file /var/log/ceph/ceph-osd.2.log --- end dump of recent events --- _______________________________________________ ceph-users mailing list -- ceph-users@xxxxxxx To unsubscribe send an email to ceph-users-leave@xxxxxxx
 |