Re: Upgrade to 16.2.6 and osd+mds crash after bluestore_fsck_quick_fix_on_mount true

Igor Fedotov <igor.fedotov@xxxxxxxx> · Tue, 26 Oct 2021 01:36:09 +0300

Hey Marek,

looks like BlueStore is unable to get omap values for pgmeta onode for 
pg 23.4s3.

Apparently they haven't been properly converted or aren't present in the 
DB... My hypothesis is that this pgmeta onode had been created in 
Luminous or before and has got no PGMETA_OMAP flag which resulted in 
invalid conversion - will try to verify/repro that tomorrow...

Meanwhile Could you please run the following command and share the output:

1) ceph-kvstore-tool bluestore-kv <path-to-osd> list M 2>/dev/null

This lists all the omap in the initial (pre-octopus format. Should be empty.

2) ceph-kvstore-tool bluestore-kv <path-to-osd> list m 2>/dev/null

This lists all the omap in the per-pool (pre-pacific)format. Should be 
empty as well.

3) ceph-kvstore-tool bluestore-kv <path-to-osd> list P 2>/dev/null

This would list pgmeta onodes for all the pgs created in post Luminous 
era, e.g. I expect pool 25 PGs to be there...

4) ceph-kvstore-tool bluestore-kv <path-to-osd> list p 2>/dev/null | 
grep "_infover"

This lists all the omaps containing "_infover" substring in their keys.

I expect that lost pgmeta onodes's omaps to be there...

Thanks,

Igor

On 10/25/2021 11:37 PM, mgrzybowski wrote:

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 ---

On 24.10.2021 22:41, Igor Fedotov wrote:
Hey Marek,

one more attempt, please:
set debug_bluestore to 10/30 and and share osd startup  the log.

Thanks,
Igor.

On 10/22/2021 10:41 PM, mgrzybowski wrote:
Hi Igor

In ceph.conf i added:

[osd]
debug bluestore = 20

next: systemctl start ceph-osd@2

Log is large :

# ls -alh  /var/log/ceph/ceph-osd.2.log
-rw-r--r-- 1 ceph ceph 1,5G paź 22 21:14 /var/log/ceph/ceph-osd.2.log

Entire file: 
https://drive.google.com/file/d/1PqTQCVuFlgAYirtAYGcu3YN1j0BCuriE/view?usp=sharing

~# tail -n 700   /var/log/ceph/ceph-osd.2.log
  -578> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401af2d:::1000425e348.00000014:head# end GHMAX
  -577> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401b880:::1000425bf50.00000000:head# end GHMAX
  -576> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401bc06:::100005acc48.00000037:head# end GHMAX
  -575> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401c2e1:::10004f5879e.00000005:head# end GHMAX
  -574> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401c2f2:::1000022be2d.0000001b:head# end GHMAX
  -573> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401c84d:::1000352e0f4.0000000e:head# end GHMAX
  -572> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401cb11:::10000231f34.00000036:head# end GHMAX
  -571> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401d016:::100005d5971.00000029:head# end GHMAX
  -570> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401d855:::100042bed1e.00000000:head# end GHMAX
  -569> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401dbcc:::10004263aa2.00000000:head# end GHMAX
  -568> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401de32:::10003ff6114.0000003a:head# end GHMAX
  -567> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401deef:::10004681051.00000064:head# end GHMAX
  -566> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401e467:::10001907a42.00000036:head# end GHMAX
  -565> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401e8e4:::100046815bb.0000001d:head# end GHMAX
  -564> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6401f618:::1000001543b.00000224:head# end GHMAX
  -563> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6402218b:::100000fdd77.00000007:head# end GHMAX
  -562> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:64022348:::1000022da8b.0000000a:head# end GHMAX
  -561> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:64022520:::100000feae3.0000000d:head# end GHMAX
  -560> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:640239bf:::10005803551.0000000e:head# end GHMAX
  -559> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:64024882:::1000022d905.0000004c:head# end GHMAX
  -558> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:64024a5d:::100024e90a5.00000026:head# end GHMAX
  -557> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:6402533a:::100025b195c.0000001b:head# end GHMAX
  -556> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:64025c50:::1000111c11b.00000018:head# end GHMAX
  -555> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:640260e9:::1000426445a.0000022c:head# end GHMAX
  -554> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:64026115:::1000426686b.00000011:head# end GHMAX
  -553> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:64027c28:::1000001543d.000001ab:head# end GHMAX
  -552> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list reached max 64
  -551> 2021-10-22T21:14:52.418+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) collection_list 24.26s0_head 
start 0#24:64027c28:::1000001543d.000001ab:head# end GHMAX max 64 = 
0, ls.size() = 64, next = 0#24:64027c28:::1000001543d.000001ab:head#
  -550> 2021-10-22T21:14:52.418+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) collection_list 24.as0_head 
start GHMIN end GHMAX max 64
  -549> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list range 
0#-26:50000000::::0#0 to 0#-26:54000000::::0#0 and 
0#24:50000000::::0#0 to 0#24:54000000::::0#0 start GHMIN
  -548> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list pend 
0#-26:54000000::::0#0
  -547> 2021-10-22T21:14:52.418+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#22:a0000000::::head# >= 0#-26:54000000::::0#0
  -546> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50000000::::head# end GHMAX
  -545> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000002e:::1000022fa47.00000023:head# end GHMAX
  -544> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50000725:::10004279a70.00000067:head# end GHMAX
  -543> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50000828:::100042b7d79.00008b1f:head# end GHMAX
  -542> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50000b57:::10003ff5bbf.0000002c:head# end GHMAX
  -541> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50001c58:::100000fe001.00000062:head# end GHMAX
  -540> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50001c85:::10000015416.00000037:head# end GHMAX
  -539> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:500030bf:::100000154c3.00000431:head# end GHMAX
  -538> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000516b:::100007f4dde.00000073:head# end GHMAX
  -537> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50005904:::100000154c2.00000253:head# end GHMAX
  -536> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50005b85:::1000001529e.000002df:head# end GHMAX
  -535> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:500065af:::10000015490.0000039f:head# end GHMAX
  -534> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:500069ab:::10004258f26.00000002:head# end GHMAX
  -533> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:500073f9:::1000016dd1b.00000013:head# end GHMAX
  -532> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:500076f8:::10000015405.000002c1:head# end GHMAX
  -531> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50008c49:::100002301d0.00000021:head# end GHMAX
  -530> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000903f:::100000152ab.000000df:head# end GHMAX
  -529> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:500093b2:::10002e6d31e.00000030:head# end GHMAX
  -528> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50009d24:::10004ee2d66.00000021:head# end GHMAX
  -527> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000a35a:::10003c73247.00000016:head# end GHMAX
  -526> 2021-10-22T21:14:52.438+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000a83c:::10000015506.0000042e:head# end GHMAX
  -525> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000c303:::100049a5025.0000003a:head# end GHMAX
  -524> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000cd88:::10001530bbe.00000048:head# end GHMAX
  -523> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000d0e6:::100042c3ce6.00000000:head# end GHMAX
  -522> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000daa0:::10000015427.0000001e:head# end GHMAX
  -521> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000daa0:::10001a605a8.00000035:head# end GHMAX
  -520> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000db3c:::10002f1fc8e.00000004:head# end GHMAX
  -519> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000e1e8:::100001143bf.00000181:head# end GHMAX
  -518> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000e328:::10002bc2cb7.0000001a:head# end GHMAX
  -517> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5000ee71:::1000022ff03.00000039:head# end GHMAX
  -516> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50012333:::100019912ce.0000002e:head# end GHMAX
  -515> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50013cf7:::10000375b8d.00000025:head# end GHMAX
  -514> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50014b8f:::1000069f0f4.0000002a:head# end GHMAX
  -513> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:500159c5:::100000f8eb0.00000044:head# end GHMAX
  -512> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50016ad9:::1000172e3f2.00000020:head# end GHMAX
  -511> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50016f85:::100000fec3a.00000016:head# end GHMAX
  -510> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:500178cd:::1000425e34a.00000021:head# end GHMAX
  -509> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50017b25:::1000043176c.00000034:head# end GHMAX
  -508> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50017b32:::100000f96e8.00000002:head# end GHMAX
  -507> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5001863e:::1000022bd5f.00000006:head# end GHMAX
  -506> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5001890b:::10000bd2eb5.00000007:head# end GHMAX
  -505> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:500195eb:::100011d38fd.00000004:head# end GHMAX
  -504> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5001994b:::100000f8458.00000020:head# end GHMAX
  -503> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5001c006:::100000ee73b.00000000:head# end GHMAX
  -502> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5001e841:::10001e55dba.00000013:head# end GHMAX
  -501> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50020f90:::1000001542b.0000040d:head# end GHMAX
  -500> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:500214d2:::100035cefca.0000001f:head# end GHMAX
  -499> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50022899:::100000f8d6f.00000000:head# end GHMAX
  -498> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50022aa4:::100000f87d9.00000001:head# end GHMAX
  -497> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50022d00:::1000022c8f2.00000018:head# end GHMAX
  -496> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50022d36:::100026cf859.0000002a:head# end GHMAX
  -495> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50023eb5:::10000015466.00000123:head# end GHMAX
  -494> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50023f61:::1000307394a.00000009:head# end GHMAX
  -493> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50024809:::10000bc89a9.00000006:head# end GHMAX
  -492> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5002720a:::100047e53b8.00000031:head# end GHMAX
  -491> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50027681:::100000154ab.0000015c:head# end GHMAX
  -490> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:500278bd:::10000015427.000000a9:head# end GHMAX
  -489> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:50027f63:::10000a3f514.0000002c:head# end GHMAX
  -488> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5002810b:::100001913b7.00000015:head# end GHMAX
  -487> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5002828c:::10000015465.000002e7:head# end GHMAX
  -486> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:500285e9:::100002301d9.0000003b:head# end GHMAX
  -485> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5002a575:::10001c33f37.00000000:head# end GHMAX
  -484> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5002a871:::100042b7d79.00001e1b:head# end GHMAX
  -483> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5002b5d4:::100000154fc.00000075:head# end GHMAX
  -482> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list oid 
0#24:5002bbf3:::100005acc50.00000004:head# end GHMAX
  -481> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _collection_list reached max 64
  -480> 2021-10-22T21:14:52.442+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) collection_list 24.as0_head 
start 0#24:5002bbf3:::100005acc50.00000004:head# end GHMAX max 64 = 
0, ls.size() = 64, next = 0#24:5002bbf3:::100005acc50.00000004:head#
  -479> 2021-10-22T21:14:52.442+0200 7fb023c77f00  0 osd.2 23169 
load_pgs
  -478> 2021-10-22T21:14:52.442+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) read meta 
#-1:46e858f0:::pg_num_history:head# 0x0~0
  -477> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x55f8c87d2960) 
get_onode oid #-1:46e858f0:::pg_num_history:head# key 
0x7F7FFFFFFFFFFFFFFF46E858F0'!pg_num_history!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F
  -476> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x55f8c87d2960)  
r 0 v.len 110
  -475> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore.blob(0x55f8cddb0a10) get_ref 0x0~2e Blob(0x55f8cddb0a10 
blob([0x4090000~10000] csum+has_unused crc32c/0x1000 unused=0xfffe) 
use_tracker(0x0 0x0) SharedBlob(0x55f8cddb0a80 sbid 0x0))
  -474> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore.blob(0x55f8cddb0a10) get_ref init 0x10000, 10000
  -473> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore.OnodeSpace(0x55f8c87d2aa0 in 0x55f8c802c000) add 
#-1:46e858f0:::pg_num_history:head# 0x55f8d0387b80
  -472> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 _add 
0x55f8c802c000 #-1:46e858f0:::pg_num_history:head# added, num=5
  -471> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read 0x0~2e size 0x2e (46)
  -470> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read defaulting to buffered 
read
  -469> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _read_cache  blob 
Blob(0x55f8cddb0a10 blob([0x4090000~10000] csum+has_unused 
crc32c/0x1000 unused=0xfffe) use_tracker(0x10000 0x2e) 
SharedBlob(0x55f8cddb0a80 sbid 0x0)) need 0x0~2e cache has 0x[]
  -468> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc  blob 
Blob(0x55f8cddb0a10 blob([0x4090000~10000] csum+has_unused 
crc32c/0x1000 unused=0xfffe) use_tracker(0x10000 0x2e) 
SharedBlob(0x55f8cddb0a80 sbid 0x0)) need {<0x0, 0x1000> : [0x0:0~2e]}
  -467> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc region 0x0: 
0x0 reading 0x0~1000
  -466> 2021-10-22T21:14:52.442+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read waiting for aio
  -465> 2021-10-22T21:14:52.446+0200 7fb017135700 20 
bluestore.MempoolThread(0x55f8c7380b90) _resize_shards cache_size: 
733711452 kv_alloc: 285212672 kv_used: 56349448 kv_onode_alloc: 
42949672 kv_onode_used: -22 meta_alloc: 281018368 meta_used: 22752 
data_alloc: 96468992 data_used: 20480
  -464> 2021-10-22T21:14:52.454+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _generate_read_result_bl blob 
Blob(0x55f8cddb0a10 blob([0x4090000~10000] csum+has_unused 
crc32c/0x1000 unused=0xfffe) use_tracker(0x10000 0x2e) 
SharedBlob(0x55f8cddb0a80 sbid 0x0)) need 0x{<0x0, 0x1000> : 
[0x0:0~2e]}
  -463> 2021-10-22T21:14:52.454+0200 7fb023c77f00 20 
bluestore.BufferSpace(0x55f8cddb0a98 in 0x55f8c7320f70) _discard 
0x0~1000
  -462> 2021-10-22T21:14:52.454+0200 7fb023c77f00 20 _add level 1 
near 0 on buffer(0x55f8cf1bc900 space 0x55f8cddb0a98 0x0~1000 clean) 
which has cache_private 0
  -461> 2021-10-22T21:14:52.454+0200 7fb023c77f00 20 
_unpin0x55f8c802c000   #-1:46e858f0:::pg_num_history:head# unpinned
  -460> 2021-10-22T21:14:52.454+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) read meta 
#-1:46e858f0:::pg_num_history:head# 0x0~2e = 46
  -459> 2021-10-22T21:14:52.454+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.b_head oid 
#25:d0000000::::head#
  -458> 2021-10-22T21:14:52.454+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(25.b_head 
0x55f8c87d2780) get_onode oid #25:d0000000::::head# key 
0x7F8000000000000019D0000000'!!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F
  -457> 2021-10-22T21:14:52.454+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(25.b_head 
0x55f8c87d2780)  r 0 v.len 31
  -456> 2021-10-22T21:14:52.454+0200 7fb023c77f00 20 
bluestore.OnodeSpace(0x55f8c87d28c0 in 0x55f8c813f000) add 
#25:d0000000::::head# 0x55f8d7058000
  -455> 2021-10-22T21:14:52.454+0200 7fb023c77f00 20 _add 
0x55f8c813f000 #25:d0000000::::head# added, num=1
  -454> 2021-10-22T21:14:52.454+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058000).flush flush done
  -453> 2021-10-22T21:14:52.494+0200 7fb017135700 20 
bluestore.MempoolThread(0x55f8c7380b90) _resize_shards cache_size: 
733711452 kv_alloc: 285212672 kv_used: 56349448 kv_onode_alloc: 
42949672 kv_onode_used: -22 meta_alloc: 281018368 meta_used: 23818 
data_alloc: 96468992 data_used: 24576
  -452> 2021-10-22T21:14:52.506+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.b_head oid 
#25:d0000000::::head# = 0
  -451> 2021-10-22T21:14:52.506+0200 7fb023c77f00 20 
_unpin0x55f8c813f000   #25:d0000000::::head# unpinned
  -450> 2021-10-22T21:14:52.506+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.b_head oid 
#25:d0000000::::head#
  -449> 2021-10-22T21:14:52.506+0200 7fb023c77f00 20 
_pin0x55f8c813f000   #25:d0000000::::head# pinned
  -448> 2021-10-22T21:14:52.506+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058000).flush flush done
  -447> 2021-10-22T21:14:52.538+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.b_head oid 
#25:d0000000::::head# = 0
  -446> 2021-10-22T21:14:52.538+0200 7fb023c77f00 20 
_unpin0x55f8c813f000   #25:d0000000::::head# unpinned
  -445> 2021-10-22T21:14:52.538+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) read meta 
#-1:9bbddd72:::osdmap.23167:0# 0x0~0
  -444> 2021-10-22T21:14:52.538+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x55f8c87d2960) 
get_onode oid #-1:9bbddd72:::osdmap.23167:0# key 
0x7F7FFFFFFFFFFFFFFF9BBDDD'r!osdmap.23167!='0x0000000000000000FFFFFFFFFFFFFFFF6F
  -443> 2021-10-22T21:14:52.546+0200 7fb017135700 20 
bluestore.MempoolThread(0x55f8c7380b90) _resize_shards cache_size: 
733711452 kv_alloc: 285212672 kv_used: 61396560 kv_onode_alloc: 
42949672 kv_onode_used: -22 meta_alloc: 281018368 meta_used: 23818 
data_alloc: 96468992 data_used: 24576
  -442> 2021-10-22T21:14:52.558+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x55f8c87d2960)  
r 0 v.len 112
  -441> 2021-10-22T21:14:52.562+0200 7fb023c77f00 20 
bluestore.blob(0x55f8cddb0bd0) get_ref 0x0~3fd7 Blob(0x55f8cddb0bd0 
blob([0x545c0000~10000] csum+has_unused crc32c/0x1000 unused=0xfff0) 
use_tracker(0x0 0x0) SharedBlob(0x55f8cddb0c40 sbid 0x0))
  -440> 2021-10-22T21:14:52.562+0200 7fb023c77f00 20 
bluestore.blob(0x55f8cddb0bd0) get_ref init 0x10000, 10000
  -439> 2021-10-22T21:14:52.562+0200 7fb023c77f00 20 
bluestore.OnodeSpace(0x55f8c87d2aa0 in 0x55f8c802c000) add 
#-1:9bbddd72:::osdmap.23167:0# 0x55f8d7058280
  -438> 2021-10-22T21:14:52.562+0200 7fb023c77f00 20 _add 
0x55f8c802c000 #-1:9bbddd72:::osdmap.23167:0# added, num=6
  -437> 2021-10-22T21:14:52.562+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read 0x0~3fd7 size 0x3fd7 
(16343)
  -436> 2021-10-22T21:14:52.562+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read will do buffered read
  -435> 2021-10-22T21:14:52.562+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _read_cache  blob 
Blob(0x55f8cddb0bd0 blob([0x545c0000~10000] csum+has_unused 
crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) 
SharedBlob(0x55f8cddb0c40 sbid 0x0)) need 0x0~3fd7 cache has 0x[]
  -434> 2021-10-22T21:14:52.562+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc  blob 
Blob(0x55f8cddb0bd0 blob([0x545c0000~10000] csum+has_unused 
crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) 
SharedBlob(0x55f8cddb0c40 sbid 0x0)) need {<0x0, 0x4000> : 
[0x0:0~3fd7]}
  -433> 2021-10-22T21:14:52.562+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc region 0x0: 
0x0 reading 0x0~4000
  -432> 2021-10-22T21:14:52.562+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read waiting for aio
  -431> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _generate_read_result_bl blob 
Blob(0x55f8cddb0bd0 blob([0x545c0000~10000] csum+has_unused 
crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) 
SharedBlob(0x55f8cddb0c40 sbid 0x0)) need 0x{<0x0, 0x4000> : 
[0x0:0~3fd7]}
  -430> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.BufferSpace(0x55f8cddb0c58 in 0x55f8c7320f70) _discard 
0x0~4000
  -429> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 _add level 1 
near 0 on buffer(0x55f8d99f9d40 space 0x55f8cddb0c58 0x0~4000 clean) 
which has cache_private 0
  -428> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_unpin0x55f8c802c000   #-1:9bbddd72:::osdmap.23167:0# unpinned
  -427> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) read meta 
#-1:9bbddd72:::osdmap.23167:0# 0x0~3fd7 = 16343
  -426> 2021-10-22T21:14:52.578+0200 7fb023c77f00  5 osd.2 pg_epoch: 
23167 pg[25.b(unlocked)] enter Initial
  -425> 2021-10-22T21:14:52.578+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.b_head oid 
#25:d0000000::::head#
  -424> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_pin0x55f8c813f000   #25:d0000000::::head# pinned
  -423> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058000).flush flush done
  -422> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.b_head oid 
#25:d0000000::::head# = 0
  -421> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_unpin0x55f8c813f000   #25:d0000000::::head# unpinned
  -420> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) stat 25.b_head 
#25:d0000000::::head#
  -419> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_pin0x55f8c813f000   #25:d0000000::::head# pinned
  -418> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_unpin0x55f8c813f000   #25:d0000000::::head# unpinned
  -417> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator 25.b_head 
#25:d0000000::::head#
  -416> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_pin0x55f8c813f000   #25:d0000000::::head# pinned
  -415> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058000).flush flush done
  -414> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator has_omap = 1
  -413> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1180) valid is at 
0x0000000004F830E1'._biginfo'
  -412> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1180) valid is at 
0x0000000004F830E1'._epoch'
  -411> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1180) valid is at 
0x0000000004F830E1'._info'
  -410> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1180) valid is at 
0x0000000004F830E1'._infover'
  -409> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1180) valid is at 
0x0000000004F830E1'.may_include_deletes_in_missing'
  -408> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1180) valid is at 
0x0000000004F830E17E
  -407> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_unpin0x55f8c813f000   #25:d0000000::::head# unpinned
  -406> 2021-10-22T21:14:52.578+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) set_collection_opts 25.b_head 
options  pg_num_min 1
  -405> 2021-10-22T21:14:52.578+0200 7fb023c77f00  5 osd.2 pg_epoch: 
23167 pg[25.b( empty local-lis/les=12563/12564 n=0 ec=10991/10977 
lis/c=12563/12563 les/c/f=12564/12564/0 sis=12563) [2,12,0] r=0 
lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] exit Initial 0.000387 0 
0.000000
  -404> 2021-10-22T21:14:52.578+0200 7fb023c77f00  5 osd.2 pg_epoch: 
23167 pg[25.b( empty local-lis/les=12563/12564 n=0 ec=10991/10977 
lis/c=12563/12563 les/c/f=12564/12564/0 sis=12563) [2,12,0] r=0 
lpr=0 crt=0'0 mlcod 0'0 unknown mbc={}] enter Reset
  -403> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) queue_transactions ch 
0x55f8c87d2780 25.b_head
  -402> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_create osr 0x55f8c87d4580 = 
0x55f8c88dbc00 seq 1
  -401> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_pin0x55f8c813f000   #25:d0000000::::head# pinned
  -400> 2021-10-22T21:14:52.578+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.b_head 
#25:d0000000::::head#
  -399> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.b_head 
#25:d0000000::::head# = 0
  -398> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_calc_cost 0x55f8c88dbc00 
cost 670195 (1 ios * 670000 + 195 bytes)
  -397> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_write_nodes txc 
0x55f8c88dbc00 onodes 0x55f8d7058000 shared_blobs
  -396> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.extentmap(0x55f8d7058150) update #25:d0000000::::head#
  -395> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _record_onode onode 
#25:d0000000::::head# is 31 (23 bytes onode + 2 bytes spanning blobs 
+ 6 bytes inline extents)
  -394> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finalize_kv txc 
0x55f8c88dbc00 allocated 0x[] released 0x[]
  -393> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c88dbc00 prepare
  -392> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish_io 0x55f8c88dbc00
  -391> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c88dbc00 io_done
  -390> 2021-10-22T21:14:52.578+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.a_head oid 
#25:50000000::::head#
  -389> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(25.a_head 
0x55f8c87d25a0) get_onode oid #25:50000000::::head# key 
0x7F800000000000001950000000'!!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F
  -388> 2021-10-22T21:14:52.578+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread wake
  -387> 2021-10-22T21:14:52.578+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committing 1 
submitting 1 deferred done 0 stable 0
  -386> 2021-10-22T21:14:52.578+0200 7fb01292c700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread new_nid_max 
83561921
  -385> 2021-10-22T21:14:52.578+0200 7fb01292c700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread new_blobid_max 
2294655
  -384> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(25.a_head 
0x55f8c87d25a0)  r 0 v.len 31
  -383> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OnodeSpace(0x55f8c87d26e0 in 0x55f8c813c800) add 
#25:50000000::::head# 0x55f8d7058500
  -382> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 _add 
0x55f8c813c800 #25:50000000::::head# added, num=1
  -381> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058500).flush flush done
  -380> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.a_head oid 
#25:50000000::::head# = 0
  -379> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_unpin0x55f8c813c800   #25:50000000::::head# unpinned
  -378> 2021-10-22T21:14:52.578+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.a_head oid 
#25:50000000::::head#
  -377> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_pin0x55f8c813c800   #25:50000000::::head# pinned
  -376> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058500).flush flush done
  -375> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.a_head oid 
#25:50000000::::head# = 0
  -374> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_unpin0x55f8c813c800   #25:50000000::::head# unpinned
  -373> 2021-10-22T21:14:52.578+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_apply_kv onode 
0x55f8d7058000 had 1
  -372> 2021-10-22T21:14:52.578+0200 7fb01292c700 10 HybridAllocator 
allocate want 0x10000 unit 0x10000 max_alloc_size 0x10000 hint 0x0
  -371> 2021-10-22T21:14:52.578+0200 7fb023c77f00  5 osd.2 pg_epoch: 
23167 pg[25.a(unlocked)] enter Initial
  -370> 2021-10-22T21:14:52.578+0200 7fb01292c700 20 AvlAllocator 
_allocate first fit=12582912 size=65536
  -369> 2021-10-22T21:14:52.578+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.a_head oid 
#25:50000000::::head#
  -368> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_pin0x55f8c813c800   #25:50000000::::head# pinned
  -367> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058500).flush flush done
  -366> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.a_head oid 
#25:50000000::::head# = 0
  -365> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_unpin0x55f8c813c800   #25:50000000::::head# unpinned
  -364> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) stat 25.a_head 
#25:50000000::::head#
  -363> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_pin0x55f8c813c800   #25:50000000::::head# pinned
  -362> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_unpin0x55f8c813c800   #25:50000000::::head# unpinned
  -361> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator 25.a_head 
#25:50000000::::head#
  -360> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_pin0x55f8c813c800   #25:50000000::::head# pinned
  -359> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058500).flush flush done
  -358> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator has_omap = 1
  -357> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1490) valid is at 
0x0000000004F830DB'._biginfo'
  -356> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1490) valid is at 
0x0000000004F830DB'._epoch'
  -355> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1490) valid is at 
0x0000000004F830DB'._info'
  -354> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1490) valid is at 
0x0000000004F830DB'._infover'
  -353> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1490) valid is at 
0x0000000004F830DB'.may_include_deletes_in_missing'
  -352> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1490) valid is at 
0x0000000004F830DB7E
  -351> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_unpin0x55f8c813c800   #25:50000000::::head# unpinned
  -350> 2021-10-22T21:14:52.578+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) set_collection_opts 25.a_head 
options  pg_num_min 1
  -349> 2021-10-22T21:14:52.578+0200 7fb023c77f00  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.000327 0 0.000000
  -348> 2021-10-22T21:14:52.578+0200 7fb023c77f00  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
  -347> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) queue_transactions ch 
0x55f8c87d25a0 25.a_head
  -346> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_create osr 0x55f8c87d4420 = 
0x55f8c737d180 seq 1
  -345> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_pin0x55f8c813c800   #25:50000000::::head# pinned
  -344> 2021-10-22T21:14:52.578+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.a_head 
#25:50000000::::head#
  -343> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.a_head 
#25:50000000::::head# = 0
  -342> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_calc_cost 0x55f8c737d180 
cost 670195 (1 ios * 670000 + 195 bytes)
  -341> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_write_nodes txc 
0x55f8c737d180 onodes 0x55f8d7058500 shared_blobs
  -340> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.extentmap(0x55f8d7058650) update #25:50000000::::head#
  -339> 2021-10-22T21:14:52.578+0200 7fb023c77f00 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)
  -338> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finalize_kv txc 
0x55f8c737d180 allocated 0x[] released 0x[]
  -337> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c737d180 prepare
  -336> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish_io 0x55f8c737d180
  -335> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c737d180 io_done
  -334> 2021-10-22T21:14:52.578+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.9_head oid 
#25:90000000::::head#
  -333> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(25.9_head 
0x55f8c87d23c0) get_onode oid #25:90000000::::head# key 
0x7F800000000000001990000000'!!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F
  -332> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(25.9_head 
0x55f8c87d23c0)  r 0 v.len 31
  -331> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.OnodeSpace(0x55f8c87d2500 in 0x55f8c813a000) add 
#25:90000000::::head# 0x55f8d7058780
  -330> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 _add 
0x55f8c813a000 #25:90000000::::head# added, num=1
  -329> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058780).flush flush done
  -328> 2021-10-22T21:14:52.578+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.9_head oid 
#25:90000000::::head# = 0
  -327> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_unpin0x55f8c813a000   #25:90000000::::head# unpinned
  -326> 2021-10-22T21:14:52.578+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.9_head oid 
#25:90000000::::head#
  -325> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
_pin0x55f8c813a000   #25:90000000::::head# pinned
  -324> 2021-10-22T21:14:52.578+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058780).flush flush done
  -323> 2021-10-22T21:14:52.594+0200 7fb017135700 20 
bluestore.MempoolThread(0x55f8c7380b90) _resize_shards cache_size: 
733711452 kv_alloc: 285212672 kv_used: 61400752 kv_onode_alloc: 
42949672 kv_onode_used: -22 meta_alloc: 281018368 meta_used: 26980 
data_alloc: 96468992 data_used: 40960
  -322> 2021-10-22T21:14:52.598+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.9_head oid 
#25:90000000::::head# = 0
  -321> 2021-10-22T21:14:52.598+0200 7fb023c77f00 20 
_unpin0x55f8c813a000   #25:90000000::::head# unpinned
  -320> 2021-10-22T21:14:52.598+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) read meta 
#-1:9325dd72:::osdmap.23155:0# 0x0~0
  -319> 2021-10-22T21:14:52.598+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x55f8c87d2960) 
get_onode oid #-1:9325dd72:::osdmap.23155:0# key 
0x7F7FFFFFFFFFFFFFFF9325DD'r!osdmap.23155!='0x0000000000000000FFFFFFFFFFFFFFFF6F
  -318> 2021-10-22T21:14:52.618+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x55f8c87d2960)  
r 0 v.len 112
  -317> 2021-10-22T21:14:52.618+0200 7fb023c77f00 20 
bluestore.blob(0x55f8cddb17a0) get_ref 0x0~3fd7 Blob(0x55f8cddb17a0 
blob([0x51ba0000~10000] csum+has_unused crc32c/0x1000 unused=0xfff0) 
use_tracker(0x0 0x0) SharedBlob(0x55f8cddb1810 sbid 0x0))
  -316> 2021-10-22T21:14:52.618+0200 7fb023c77f00 20 
bluestore.blob(0x55f8cddb17a0) get_ref init 0x10000, 10000
  -315> 2021-10-22T21:14:52.618+0200 7fb023c77f00 20 
bluestore.OnodeSpace(0x55f8c87d2aa0 in 0x55f8c802c000) add 
#-1:9325dd72:::osdmap.23155:0# 0x55f8d7058a00
  -314> 2021-10-22T21:14:52.618+0200 7fb023c77f00 20 _add 
0x55f8c802c000 #-1:9325dd72:::osdmap.23155:0# added, num=7
  -313> 2021-10-22T21:14:52.618+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read 0x0~3fd7 size 0x3fd7 
(16343)
  -312> 2021-10-22T21:14:52.618+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read will do buffered read
  -311> 2021-10-22T21:14:52.618+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _read_cache  blob 
Blob(0x55f8cddb17a0 blob([0x51ba0000~10000] csum+has_unused 
crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) 
SharedBlob(0x55f8cddb1810 sbid 0x0)) need 0x0~3fd7 cache has 0x[]
  -310> 2021-10-22T21:14:52.618+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc  blob 
Blob(0x55f8cddb17a0 blob([0x51ba0000~10000] csum+has_unused 
crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) 
SharedBlob(0x55f8cddb1810 sbid 0x0)) need {<0x0, 0x4000> : 
[0x0:0~3fd7]}
  -309> 2021-10-22T21:14:52.618+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc region 0x0: 
0x0 reading 0x0~4000
  -308> 2021-10-22T21:14:52.618+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read waiting for aio
  -307> 2021-10-22T21:14:52.622+0200 7fb01292c700 10 AvlAllocator 
_release offset 0x4e0000 length 0x10000
  -306> 2021-10-22T21:14:52.622+0200 7fb01292c700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread nid_max now 
83561921
  -305> 2021-10-22T21:14:52.622+0200 7fb01292c700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread blobid_max now 
2294655
  -304> 2021-10-22T21:14:52.622+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committed 1 
cleaned 0 in 0.045136102s (0.000000199s flush + 0.045135900s kv commit)
  -303> 2021-10-22T21:14:52.622+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread wake
  -302> 2021-10-22T21:14:52.622+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread kv_committed 
<0x55f8c88dbc00>
  -301> 2021-10-22T21:14:52.622+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread 
deferred_stable <>
  -300> 2021-10-22T21:14:52.622+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committing 1 
submitting 1 deferred done 0 stable 0
  -299> 2021-10-22T21:14:52.622+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c88dbc00 kv_submitted
  -298> 2021-10-22T21:14:52.622+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_committed_kv txc 
0x55f8c88dbc00
  -297> 2021-10-22T21:14:52.622+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c88dbc00 finishing
  -296> 2021-10-22T21:14:52.622+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish 0x55f8c88dbc00 
onodes 0x55f8d7058000
  -295> 2021-10-22T21:14:52.622+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish  txc 0x55f8c88dbc00 
done
  -294> 2021-10-22T21:14:52.622+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish osr 0x55f8c87d4580 q 
now empty
  -293> 2021-10-22T21:14:52.622+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_release_alloc(sync) 
0x55f8c88dbc00 []
  -292> 2021-10-22T21:14:52.622+0200 7fb017936700 20 
_unpin0x55f8c813f000   #25:d0000000::::head# unpinned
  -291> 2021-10-22T21:14:52.622+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread sleep
  -290> 2021-10-22T21:14:52.622+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_apply_kv onode 
0x55f8d7058500 had 1
  -289> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _generate_read_result_bl blob 
Blob(0x55f8cddb17a0 blob([0x51ba0000~10000] csum+has_unused 
crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) 
SharedBlob(0x55f8cddb1810 sbid 0x0)) need 0x{<0x0, 0x4000> : 
[0x0:0~3fd7]}
  -288> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore.BufferSpace(0x55f8cddb1828 in 0x55f8c7320f70) _discard 
0x0~4000
  -287> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 _add level 1 
near 0 on buffer(0x55f8cda0c840 space 0x55f8cddb1828 0x0~4000 clean) 
which has cache_private 0
  -286> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
_unpin0x55f8c802c000   #-1:9325dd72:::osdmap.23155:0# unpinned
  -285> 2021-10-22T21:14:52.642+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) read meta 
#-1:9325dd72:::osdmap.23155:0# 0x0~3fd7 = 16343
  -284> 2021-10-22T21:14:52.642+0200 7fb023c77f00  5 osd.2 pg_epoch: 
23155 pg[25.9(unlocked)] enter Initial
  -283> 2021-10-22T21:14:52.642+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.9_head oid 
#25:90000000::::head#
  -282> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
_pin0x55f8c813a000   #25:90000000::::head# pinned
  -281> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058780).flush flush done
  -280> 2021-10-22T21:14:52.642+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.9_head oid 
#25:90000000::::head# = 0
  -279> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
_unpin0x55f8c813a000   #25:90000000::::head# unpinned
  -278> 2021-10-22T21:14:52.642+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) stat 25.9_head 
#25:90000000::::head#
  -277> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
_pin0x55f8c813a000   #25:90000000::::head# pinned
  -276> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
_unpin0x55f8c813a000   #25:90000000::::head# unpinned
  -275> 2021-10-22T21:14:52.642+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator 25.9_head 
#25:90000000::::head#
  -274> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
_pin0x55f8c813a000   #25:90000000::::head# pinned
  -273> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058780).flush flush done
  -272> 2021-10-22T21:14:52.642+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator has_omap = 1
  -271> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1d50) valid is at 
0x0000000004F830E6'._biginfo'
  -270> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1d50) valid is at 
0x0000000004F830E6'._epoch'
  -269> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1d50) valid is at 
0x0000000004F830E6'._info'
  -268> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1d50) valid is at 
0x0000000004F830E6'._infover'
  -267> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1d50) valid is at 
0x0000000004F830E6'.may_include_deletes_in_missing'
  -266> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8cddb1d50) valid is at 
0x0000000004F830E67E
  -265> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
_unpin0x55f8c813a000   #25:90000000::::head# unpinned
  -264> 2021-10-22T21:14:52.642+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) set_collection_opts 25.9_head 
options  pg_num_min 1
  -263> 2021-10-22T21:14:52.642+0200 7fb023c77f00  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.000326 0 0.000000
  -262> 2021-10-22T21:14:52.642+0200 7fb023c77f00  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
  -261> 2021-10-22T21:14:52.642+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) queue_transactions ch 
0x55f8c87d23c0 25.9_head
  -260> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_create osr 0x55f8c87d42c0 = 
0x55f8c737ca80 seq 1
  -259> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
_pin0x55f8c813a000   #25:90000000::::head# pinned
  -258> 2021-10-22T21:14:52.642+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.9_head 
#25:90000000::::head#
  -257> 2021-10-22T21:14:52.642+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.9_head 
#25:90000000::::head# = 0
  -256> 2021-10-22T21:14:52.642+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_calc_cost 0x55f8c737ca80 
cost 670195 (1 ios * 670000 + 195 bytes)
  -255> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_write_nodes txc 
0x55f8c737ca80 onodes 0x55f8d7058780 shared_blobs
  -254> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore.extentmap(0x55f8d70588d0) update #25:90000000::::head#
  -253> 2021-10-22T21:14:52.642+0200 7fb023c77f00 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)
  -252> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finalize_kv txc 
0x55f8c737ca80 allocated 0x[] released 0x[]
  -251> 2021-10-22T21:14:52.642+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c737ca80 prepare
  -250> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish_io 0x55f8c737ca80
  -249> 2021-10-22T21:14:52.642+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c737ca80 io_done
  -248> 2021-10-22T21:14:52.642+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.18_head oid 
#25:18000000::::head#
  -247> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(25.18_head 
0x55f8c87d2000) get_onode oid #25:18000000::::head# key 
0x7F800000000000001918000000'!!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F
  -246> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(25.18_head 
0x55f8c87d2000)  r 0 v.len 31
  -245> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore.OnodeSpace(0x55f8c87d2140 in 0x55f8c8162000) add 
#25:18000000::::head# 0x55f8d7058c80
  -244> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 _add 
0x55f8c8162000 #25:18000000::::head# added, num=1
  -243> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058c80).flush flush done
  -242> 2021-10-22T21:14:52.642+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.18_head oid 
#25:18000000::::head# = 0
  -241> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
_unpin0x55f8c8162000   #25:18000000::::head# unpinned
  -240> 2021-10-22T21:14:52.642+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.18_head oid 
#25:18000000::::head#
  -239> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
_pin0x55f8c8162000   #25:18000000::::head# pinned
  -238> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058c80).flush flush done
  -237> 2021-10-22T21:14:52.642+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.18_head oid 
#25:18000000::::head# = 0
  -236> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
_unpin0x55f8c8162000   #25:18000000::::head# unpinned
  -235> 2021-10-22T21:14:52.642+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) read meta 
#-1:987ddd72:::osdmap.23163:0# 0x0~0
  -234> 2021-10-22T21:14:52.642+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x55f8c87d2960) 
get_onode oid #-1:987ddd72:::osdmap.23163:0# key 
0x7F7FFFFFFFFFFFFFFF987DDD'r!osdmap.23163!='0x0000000000000000FFFFFFFFFFFFFFFF6F
  -233> 2021-10-22T21:14:52.646+0200 7fb017135700 20 
bluestore.MempoolThread(0x55f8c7380b90) _resize_shards cache_size: 
733711452 kv_alloc: 285212672 kv_used: 61409136 kv_onode_alloc: 
42949672 kv_onode_used: -22 meta_alloc: 281018368 meta_used: 29220 
data_alloc: 96468992 data_used: 57344
  -232> 2021-10-22T21:14:52.650+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x55f8c87d2960)  
r 0 v.len 112
  -231> 2021-10-22T21:14:52.650+0200 7fb023c77f00 20 
bluestore.blob(0x55f8d6cfe070) get_ref 0x0~3fd7 Blob(0x55f8d6cfe070 
blob([0x53bc0000~10000] csum+has_unused crc32c/0x1000 unused=0xfff0) 
use_tracker(0x0 0x0) SharedBlob(0x55f8d6cfe0e0 sbid 0x0))
  -230> 2021-10-22T21:14:52.650+0200 7fb023c77f00 20 
bluestore.blob(0x55f8d6cfe070) get_ref init 0x10000, 10000
  -229> 2021-10-22T21:14:52.650+0200 7fb023c77f00 20 
bluestore.OnodeSpace(0x55f8c87d2aa0 in 0x55f8c802c000) add 
#-1:987ddd72:::osdmap.23163:0# 0x55f8d7058f00
  -228> 2021-10-22T21:14:52.650+0200 7fb023c77f00 20 _add 
0x55f8c802c000 #-1:987ddd72:::osdmap.23163:0# added, num=8
  -227> 2021-10-22T21:14:52.650+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read 0x0~3fd7 size 0x3fd7 
(16343)
  -226> 2021-10-22T21:14:52.650+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read will do buffered read
  -225> 2021-10-22T21:14:52.650+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _read_cache  blob 
Blob(0x55f8d6cfe070 blob([0x53bc0000~10000] csum+has_unused 
crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) 
SharedBlob(0x55f8d6cfe0e0 sbid 0x0)) need 0x0~3fd7 cache has 0x[]
  -224> 2021-10-22T21:14:52.650+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc  blob 
Blob(0x55f8d6cfe070 blob([0x53bc0000~10000] csum+has_unused 
crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) 
SharedBlob(0x55f8d6cfe0e0 sbid 0x0)) need {<0x0, 0x4000> : 
[0x0:0~3fd7]}
  -223> 2021-10-22T21:14:52.650+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc region 0x0: 
0x0 reading 0x0~4000
  -222> 2021-10-22T21:14:52.650+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read waiting for aio
  -221> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _generate_read_result_bl blob 
Blob(0x55f8d6cfe070 blob([0x53bc0000~10000] csum+has_unused 
crc32c/0x1000 unused=0xfff0) use_tracker(0x10000 0x3fd7) 
SharedBlob(0x55f8d6cfe0e0 sbid 0x0)) need 0x{<0x0, 0x4000> : 
[0x0:0~3fd7]}
  -220> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.BufferSpace(0x55f8d6cfe0f8 in 0x55f8c7320f70) _discard 
0x0~4000
  -219> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 _add level 1 
near 0 on buffer(0x55f8cbdaf740 space 0x55f8d6cfe0f8 0x0~4000 clean) 
which has cache_private 0
  -218> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_unpin0x55f8c802c000   #-1:987ddd72:::osdmap.23163:0# unpinned
  -217> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) read meta 
#-1:987ddd72:::osdmap.23163:0# 0x0~3fd7 = 16343
  -216> 2021-10-22T21:14:52.654+0200 7fb023c77f00  5 osd.2 pg_epoch: 
23163 pg[25.18(unlocked)] enter Initial
  -215> 2021-10-22T21:14:52.654+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.18_head oid 
#25:18000000::::head#
  -214> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_pin0x55f8c8162000   #25:18000000::::head# pinned
  -213> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058c80).flush flush done
  -212> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.18_head oid 
#25:18000000::::head# = 0
  -211> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_unpin0x55f8c8162000   #25:18000000::::head# unpinned
  -210> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) stat 25.18_head 
#25:18000000::::head#
  -209> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_pin0x55f8c8162000   #25:18000000::::head# pinned
  -208> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_unpin0x55f8c8162000   #25:18000000::::head# unpinned
  -207> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator 25.18_head 
#25:18000000::::head#
  -206> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_pin0x55f8c8162000   #25:18000000::::head# pinned
  -205> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7058c80).flush flush done
  -204> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator has_omap = 1
  -203> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cfe620) valid is at 
0x0000000004F830E4'._biginfo'
  -202> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cfe620) valid is at 
0x0000000004F830E4'._epoch'
  -201> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cfe620) valid is at 
0x0000000004F830E4'._info'
  -200> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cfe620) valid is at 
0x0000000004F830E4'._infover'
  -199> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cfe620) valid is at 
0x0000000004F830E4'.may_include_deletes_in_missing'
  -198> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cfe620) valid is at 
0x0000000004F830E47E
  -197> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_unpin0x55f8c8162000   #25:18000000::::head# unpinned
  -196> 2021-10-22T21:14:52.654+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) set_collection_opts 25.18_head 
options  pg_num_min 1
  -195> 2021-10-22T21:14:52.654+0200 7fb023c77f00  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.000562 0 
0.000000
  -194> 2021-10-22T21:14:52.654+0200 7fb023c77f00  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
  -193> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) queue_transactions ch 
0x55f8c87d2000 25.18_head
  -192> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_create osr 0x55f8c87d4000 = 
0x55f8c8034380 seq 1
  -191> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_pin0x55f8c8162000   #25:18000000::::head# pinned
  -190> 2021-10-22T21:14:52.654+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.18_head 
#25:18000000::::head#
  -189> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.18_head 
#25:18000000::::head# = 0
  -188> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_calc_cost 0x55f8c8034380 
cost 670195 (1 ios * 670000 + 195 bytes)
  -187> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_write_nodes txc 
0x55f8c8034380 onodes 0x55f8d7058c80 shared_blobs
  -186> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.extentmap(0x55f8d7058dd0) update #25:18000000::::head#
  -185> 2021-10-22T21:14:52.654+0200 7fb023c77f00 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)
  -184> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finalize_kv txc 
0x55f8c8034380 allocated 0x[] released 0x[]
  -183> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c8034380 prepare
  -182> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish_io 0x55f8c8034380
  -181> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c8034380 io_done
  -180> 2021-10-22T21:14:52.654+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.15_head oid 
#25:a8000000::::head#
  -179> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(25.15_head 
0x55f8d3e33e00) get_onode oid #25:a8000000::::head# key 
0x7F8000000000000019A8000000'!!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F
  -178> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(25.15_head 
0x55f8d3e33e00)  r 0 v.len 31
  -177> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OnodeSpace(0x55f8d3e33f40 in 0x55f8c815a000) add 
#25:a8000000::::head# 0x55f8d7059180
  -176> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 _add 
0x55f8c815a000 #25:a8000000::::head# added, num=1
  -175> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7059180).flush flush done
  -174> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.15_head oid 
#25:a8000000::::head# = 0
  -173> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_unpin0x55f8c815a000   #25:a8000000::::head# unpinned
  -172> 2021-10-22T21:14:52.654+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.15_head oid 
#25:a8000000::::head#
  -171> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_pin0x55f8c815a000   #25:a8000000::::head# pinned
  -170> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7059180).flush flush done
  -169> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.15_head oid 
#25:a8000000::::head# = 0
  -168> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_unpin0x55f8c815a000   #25:a8000000::::head# unpinned
  -167> 2021-10-22T21:14:52.654+0200 7fb023c77f00  5 osd.2 pg_epoch: 
23163 pg[25.15(unlocked)] enter Initial
  -166> 2021-10-22T21:14:52.654+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.15_head oid 
#25:a8000000::::head#
  -165> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_pin0x55f8c815a000   #25:a8000000::::head# pinned
  -164> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7059180).flush flush done
  -163> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.15_head oid 
#25:a8000000::::head# = 0
  -162> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_unpin0x55f8c815a000   #25:a8000000::::head# unpinned
  -161> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) stat 25.15_head 
#25:a8000000::::head#
  -160> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_pin0x55f8c815a000   #25:a8000000::::head# pinned
  -159> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_unpin0x55f8c815a000   #25:a8000000::::head# unpinned
  -158> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator 25.15_head 
#25:a8000000::::head#
  -157> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_pin0x55f8c815a000   #25:a8000000::::head# pinned
  -156> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7059180).flush flush done
  -155> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator has_omap = 1
  -154> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cfe8c0) valid is at 
0x0000000004F830DF'._biginfo'
  -153> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cfe8c0) valid is at 
0x0000000004F830DF'._epoch'
  -152> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cfe8c0) valid is at 
0x0000000004F830DF'._info'
  -151> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cfe8c0) valid is at 
0x0000000004F830DF'._infover'
  -150> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cfe8c0) valid is at 
0x0000000004F830DF'.may_include_deletes_in_missing'
  -149> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cfe8c0) valid is at 
0x0000000004F830DF7E
  -148> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_unpin0x55f8c815a000   #25:a8000000::::head# unpinned
  -147> 2021-10-22T21:14:52.654+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) set_collection_opts 25.15_head 
options  pg_num_min 1
  -146> 2021-10-22T21:14:52.654+0200 7fb023c77f00  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.000517 0 0.000000
  -145> 2021-10-22T21:14:52.654+0200 7fb023c77f00  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
  -144> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) queue_transactions ch 
0x55f8d3e33e00 25.15_head
  -143> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_create osr 0x55f8d3e31e40 = 
0x55f8c88db500 seq 1
  -142> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_pin0x55f8c815a000   #25:a8000000::::head# pinned
  -141> 2021-10-22T21:14:52.654+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.15_head 
#25:a8000000::::head#
  -140> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.15_head 
#25:a8000000::::head# = 0
  -139> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_calc_cost 0x55f8c88db500 
cost 670195 (1 ios * 670000 + 195 bytes)
  -138> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_write_nodes txc 
0x55f8c88db500 onodes 0x55f8d7059180 shared_blobs
  -137> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.extentmap(0x55f8d70592d0) update #25:a8000000::::head#
  -136> 2021-10-22T21:14:52.654+0200 7fb023c77f00 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)
  -135> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finalize_kv txc 
0x55f8c88db500 allocated 0x[] released 0x[]
  -134> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c88db500 prepare
  -133> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish_io 0x55f8c88db500
  -132> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c88db500 io_done
  -131> 2021-10-22T21:14:52.654+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.0_head oid 
#25:00000000::::head#
  -130> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(25.0_head 
0x55f8d3e33c20) get_onode oid #25:00000000::::head# key 
0x7F800000000000001900000000'!!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F
  -129> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(25.0_head 
0x55f8d3e33c20)  r 0 v.len 31
  -128> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.OnodeSpace(0x55f8d3e33d60 in 0x55f8c802c000) add 
#25:00000000::::head# 0x55f8d7059400
  -127> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 _add 
0x55f8c802c000 #25:00000000::::head# added, num=9
  -126> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7059400).flush flush done
  -125> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.0_head oid 
#25:00000000::::head# = 0
  -124> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_unpin0x55f8c802c000   #25:00000000::::head# unpinned
  -123> 2021-10-22T21:14:52.654+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.0_head oid 
#25:00000000::::head#
  -122> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_pin0x55f8c802c000   #25:00000000::::head# pinned
  -121> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7059400).flush flush done
  -120> 2021-10-22T21:14:52.654+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.0_head oid 
#25:00000000::::head# = 0
  -119> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
_unpin0x55f8c802c000   #25:00000000::::head# unpinned
  -118> 2021-10-22T21:14:52.654+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) read meta 
#-1:9829dd72:::osdmap.23134:0# 0x0~0
  -117> 2021-10-22T21:14:52.654+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x55f8c87d2960) 
get_onode oid #-1:9829dd72:::osdmap.23134:0# key 
0x7F7FFFFFFFFFFFFFFF9829DD'r!osdmap.23134!='0x0000000000000000FFFFFFFFFFFFFFFF6F
  -116> 2021-10-22T21:14:52.674+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committed 1 
cleaned 0 in 0.050118767s (0.000000073s flush + 0.050118696s kv commit)
  -115> 2021-10-22T21:14:52.674+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committing 3 
submitting 3 deferred done 0 stable 0
  -114> 2021-10-22T21:14:52.674+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread wake
  -113> 2021-10-22T21:14:52.674+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread kv_committed 
<0x55f8c737d180>
  -112> 2021-10-22T21:14:52.674+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread 
deferred_stable <>
  -111> 2021-10-22T21:14:52.674+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_apply_kv onode 
0x55f8d7058780 had 1
  -110> 2021-10-22T21:14:52.674+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c737d180 kv_submitted
  -109> 2021-10-22T21:14:52.674+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_committed_kv txc 
0x55f8c737d180
  -108> 2021-10-22T21:14:52.674+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c737d180 finishing
  -107> 2021-10-22T21:14:52.674+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish 0x55f8c737d180 
onodes 0x55f8d7058500
  -106> 2021-10-22T21:14:52.674+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish  txc 0x55f8c737d180 
done
  -105> 2021-10-22T21:14:52.674+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish osr 0x55f8c87d4420 q 
now empty
  -104> 2021-10-22T21:14:52.674+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_release_alloc(sync) 
0x55f8c737d180 []
  -103> 2021-10-22T21:14:52.674+0200 7fb017936700 20 
_unpin0x55f8c813c800   #25:50000000::::head# unpinned
  -102> 2021-10-22T21:14:52.674+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread sleep
  -101> 2021-10-22T21:14:52.674+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_apply_kv onode 
0x55f8d7058c80 had 1
  -100> 2021-10-22T21:14:52.674+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_apply_kv onode 
0x55f8d7059180 had 1
   -99> 2021-10-22T21:14:52.674+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(meta 0x55f8c87d2960)  
r 0 v.len 113
   -98> 2021-10-22T21:14:52.674+0200 7fb023c77f00 20 
bluestore.blob(0x55f8d6cfeb60) get_ref 0x0~4083 Blob(0x55f8d6cfeb60 
blob([0x49800000~10000] csum+has_unused crc32c/0x1000 unused=0xffe0) 
use_tracker(0x0 0x0) SharedBlob(0x55f8d6cfebd0 sbid 0x0))
   -97> 2021-10-22T21:14:52.674+0200 7fb023c77f00 20 
bluestore.blob(0x55f8d6cfeb60) get_ref init 0x10000, 10000
   -96> 2021-10-22T21:14:52.674+0200 7fb023c77f00 20 
bluestore.OnodeSpace(0x55f8c87d2aa0 in 0x55f8c802c000) add 
#-1:9829dd72:::osdmap.23134:0# 0x55f8d7059680
   -95> 2021-10-22T21:14:52.674+0200 7fb023c77f00 20 _add 
0x55f8c802c000 #-1:9829dd72:::osdmap.23134:0# added, num=10
   -94> 2021-10-22T21:14:52.674+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read 0x0~4083 size 0x4083 
(16515)
   -93> 2021-10-22T21:14:52.674+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read will do buffered read
   -92> 2021-10-22T21:14:52.674+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _read_cache  blob 
Blob(0x55f8d6cfeb60 blob([0x49800000~10000] csum+has_unused 
crc32c/0x1000 unused=0xffe0) use_tracker(0x10000 0x4083) 
SharedBlob(0x55f8d6cfebd0 sbid 0x0)) need 0x0~4083 cache has 0x[]
   -91> 2021-10-22T21:14:52.674+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc  blob 
Blob(0x55f8d6cfeb60 blob([0x49800000~10000] csum+has_unused 
crc32c/0x1000 unused=0xffe0) use_tracker(0x10000 0x4083) 
SharedBlob(0x55f8d6cfebd0 sbid 0x0)) need {<0x0, 0x5000> : 
[0x0:0~4083]}
   -90> 2021-10-22T21:14:52.674+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _prepare_read_ioc region 0x0: 
0x0 reading 0x0~5000
   -89> 2021-10-22T21:14:52.674+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _do_read waiting for aio
   -88> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _generate_read_result_bl blob 
Blob(0x55f8d6cfeb60 blob([0x49800000~10000] csum+has_unused 
crc32c/0x1000 unused=0xffe0) use_tracker(0x10000 0x4083) 
SharedBlob(0x55f8d6cfebd0 sbid 0x0)) need 0x{<0x0, 0x5000> : 
[0x0:0~4083]}
   -87> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore.BufferSpace(0x55f8d6cfebe8 in 0x55f8c7320f70) _discard 
0x0~5000
   -86> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 _add level 1 
near 0 on buffer(0x55f8ceb0e0c0 space 0x55f8d6cfebe8 0x0~5000 clean) 
which has cache_private 0
   -85> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
_unpin0x55f8c802c000   #-1:9829dd72:::osdmap.23134:0# unpinned
   -84> 2021-10-22T21:14:52.690+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) read meta 
#-1:9829dd72:::osdmap.23134:0# 0x0~4083 = 16515
   -83> 2021-10-22T21:14:52.690+0200 7fb023c77f00  5 osd.2 pg_epoch: 
23134 pg[25.0(unlocked)] enter Initial
   -82> 2021-10-22T21:14:52.690+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.0_head oid 
#25:00000000::::head#
   -81> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
_pin0x55f8c802c000   #25:00000000::::head# pinned
   -80> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7059400).flush flush done
   -79> 2021-10-22T21:14:52.690+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 25.0_head oid 
#25:00000000::::head# = 0
   -78> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
_unpin0x55f8c802c000   #25:00000000::::head# unpinned
   -77> 2021-10-22T21:14:52.690+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) stat 25.0_head 
#25:00000000::::head#
   -76> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
_pin0x55f8c802c000   #25:00000000::::head# pinned
   -75> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
_unpin0x55f8c802c000   #25:00000000::::head# unpinned
   -74> 2021-10-22T21:14:52.690+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator 25.0_head 
#25:00000000::::head#
   -73> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
_pin0x55f8c802c000   #25:00000000::::head# pinned
   -72> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7059400).flush flush done
   -71> 2021-10-22T21:14:52.690+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) get_omap_iterator has_omap = 1
   -70> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cff180) valid is at 
0x0000000004F830EC'._biginfo'
   -69> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cff180) valid is at 
0x0000000004F830EC'._epoch'
   -68> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cff180) valid is at 
0x0000000004F830EC'._info'
   -67> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cff180) valid is at 
0x0000000004F830EC'._infover'
   -66> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cff180) valid is at 
0x0000000004F830EC'.may_include_deletes_in_missing'
   -65> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore.OmapIteratorImpl(0x55f8d6cff180) valid is at 
0x0000000004F830EC7E
   -64> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
_unpin0x55f8c802c000   #25:00000000::::head# unpinned
   -63> 2021-10-22T21:14:52.690+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) set_collection_opts 25.0_head 
options  pg_num_min 1
   -62> 2021-10-22T21:14:52.690+0200 7fb023c77f00  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.000704 0 
0.000000
   -61> 2021-10-22T21:14:52.690+0200 7fb023c77f00  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
   -60> 2021-10-22T21:14:52.690+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) queue_transactions ch 
0x55f8d3e33c20 25.0_head
   -59> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_create osr 0x55f8d3e31ce0 = 
0x55f8c88db880 seq 1
   -58> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
_pin0x55f8c802c000   #25:00000000::::head# pinned
   -57> 2021-10-22T21:14:52.690+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.0_head 
#25:00000000::::head#
   -56> 2021-10-22T21:14:52.690+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _touch 25.0_head 
#25:00000000::::head# = 0
   -55> 2021-10-22T21:14:52.690+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_calc_cost 0x55f8c88db880 
cost 670195 (1 ios * 670000 + 195 bytes)
   -54> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_write_nodes txc 
0x55f8c88db880 onodes 0x55f8d7059400 shared_blobs
   -53> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore.extentmap(0x55f8d7059550) update #25:00000000::::head#
   -52> 2021-10-22T21:14:52.690+0200 7fb023c77f00 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)
   -51> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finalize_kv txc 
0x55f8c88db880 allocated 0x[] released 0x[]
   -50> 2021-10-22T21:14:52.690+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c88db880 prepare
   -49> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish_io 0x55f8c88db880
   -48> 2021-10-22T21:14:52.690+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c88db880 io_done
   -47> 2021-10-22T21:14:52.690+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 23.4s3_head oid 
3#23:20000000::::head#
   -46> 2021-10-22T21:14:52.690+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(23.4s3_head 
0x55f8d19f1c20) get_onode oid 3#23:20000000::::head# key 
0x83800000000000001720000000'!!='0xFFFFFFFFFFFFFFFEFFFFFFFFFFFFFFFF6F
   -45> 2021-10-22T21:14:52.694+0200 7fb017135700 20 
bluestore.MempoolThread(0x55f8c7380b90) _resize_shards cache_size: 
733711452 kv_alloc: 285212672 kv_used: 61417520 kv_onode_alloc: 
42949672 kv_onode_used: -22 meta_alloc: 281018368 meta_used: 33700 
data_alloc: 96468992 data_used: 94208
   -44> 2021-10-22T21:14:52.718+0200 7fb023c77f00 20 
bluestore(/var/lib/ceph/osd/ceph-2).collection(23.4s3_head 
0x55f8d19f1c20)  r 0 v.len 31
   -43> 2021-10-22T21:14:52.718+0200 7fb023c77f00 20 
bluestore.OnodeSpace(0x55f8d19f1d60 in 0x55f8c812c800) add 
3#23:20000000::::head# 0x55f8d7059900
   -42> 2021-10-22T21:14:52.718+0200 7fb023c77f00 20 _add 
0x55f8c812c800 3#23:20000000::::head# added, num=1
   -41> 2021-10-22T21:14:52.718+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7059900).flush flush done
   -40> 2021-10-22T21:14:52.734+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committed 3 
cleaned 0 in 0.060137559s (0.000000088s flush + 0.060137473s kv commit)
   -39> 2021-10-22T21:14:52.734+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committing 1 
submitting 1 deferred done 0 stable 0
   -38> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread wake
   -37> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread kv_committed 
<0x55f8c737ca80,0x55f8c8034380,0x55f8c88db500>
   -36> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread 
deferred_stable <>
   -35> 2021-10-22T21:14:52.734+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c737ca80 kv_submitted
   -34> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_committed_kv txc 
0x55f8c737ca80
   -33> 2021-10-22T21:14:52.734+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c737ca80 finishing
   -32> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish 0x55f8c737ca80 
onodes 0x55f8d7058780
   -31> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish  txc 0x55f8c737ca80 
done
   -30> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish osr 0x55f8c87d42c0 q 
now empty
   -29> 2021-10-22T21:14:52.734+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_release_alloc(sync) 
0x55f8c737ca80 []
   -28> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
_unpin0x55f8c813a000   #25:90000000::::head# unpinned
   -27> 2021-10-22T21:14:52.734+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c8034380 kv_submitted
   -26> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_committed_kv txc 
0x55f8c8034380
   -25> 2021-10-22T21:14:52.734+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c8034380 finishing
   -24> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish 0x55f8c8034380 
onodes 0x55f8d7058c80
   -23> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish  txc 0x55f8c8034380 
done
   -22> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish osr 0x55f8c87d4000 q 
now empty
   -21> 2021-10-22T21:14:52.734+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_release_alloc(sync) 
0x55f8c8034380 []
   -20> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
_unpin0x55f8c8162000   #25:18000000::::head# unpinned
   -19> 2021-10-22T21:14:52.734+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c88db500 kv_submitted
   -18> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_committed_kv txc 
0x55f8c88db500
   -17> 2021-10-22T21:14:52.734+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_apply_kv onode 
0x55f8d7059400 had 1
   -16> 2021-10-22T21:14:52.734+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c88db500 finishing
   -15> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish 0x55f8c88db500 
onodes 0x55f8d7059180
   -14> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish  txc 0x55f8c88db500 
done
   -13> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish osr 0x55f8d3e31e40 q 
now empty
   -12> 2021-10-22T21:14:52.734+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_release_alloc(sync) 
0x55f8c88db500 []
   -11> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
_unpin0x55f8c815a000   #25:a8000000::::head# unpinned
   -10> 2021-10-22T21:14:52.734+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread sleep
    -9> 2021-10-22T21:14:52.746+0200 7fb017135700 20 
bluestore.MempoolThread(0x55f8c7380b90) _resize_shards cache_size: 
733711452 kv_alloc: 285212672 kv_used: 61565016 kv_onode_alloc: 
42949672 kv_onode_used: -22 meta_alloc: 281018368 meta_used: 34622 
data_alloc: 96468992 data_used: 94208
    -8> 2021-10-22T21:14:52.754+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 23.4s3_head oid 
3#23:20000000::::head# = 0
    -7> 2021-10-22T21:14:52.754+0200 7fb023c77f00 20 
_unpin0x55f8c812c800   3#23:20000000::::head# unpinned
    -6> 2021-10-22T21:14:52.754+0200 7fb023c77f00 15 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 23.4s3_head oid 
3#23:20000000::::head#
    -5> 2021-10-22T21:14:52.754+0200 7fb023c77f00 20 
_pin0x55f8c812c800   3#23:20000000::::head# pinned
    -4> 2021-10-22T21:14:52.754+0200 7fb023c77f00 20 
bluestore.onode(0x55f8d7059900).flush flush done
    -3> 2021-10-22T21:14:52.754+0200 7fb023c77f00 10 
bluestore(/var/lib/ceph/osd/ceph-2) omap_get_values 23.4s3_head oid 
3#23:20000000::::head# = 0
    -2> 2021-10-22T21:14:52.754+0200 7fb023c77f00 20 
_unpin0x55f8c812c800   3#23:20000000::::head# unpinned
    -1> 2021-10-22T21:14:52.758+0200 7fb023c77f00 -1 
/build/ceph-16.2.6/src/osd/PG.cc: In function 'static int 
PG::peek_map_epoch(ObjectStore*, spg_t, epoch_t*)' thread 
7fb023c77f00 time 2021-10-22T21:14:52.757014+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) [0x55f8bc092e61]
 2: /usr/bin/ceph-osd(+0xac6069) [0x55f8bc093069]
 3: (PG::peek_map_epoch(ObjectStore*, spg_t, unsigned int*)+0xa17) 
[0x55f8bc21d057]
 4: (OSD::load_pgs()+0x6b4) [0x55f8bc18dec4]
 5: (OSD::init()+0x2b4e) [0x55f8bc19aa6e]
 6: main()
 7: __libc_start_main()
 8: _start()

     0> 2021-10-22T21:14:52.762+0200 7fb023c77f00 -1 *** Caught 
signal (Aborted) **
 in thread 7fb023c77f00 thread_name:ceph-osd

 ceph version 16.2.6 (ee28fb57e47e9f88813e24bbf4c14496ca299d31) 
pacific (stable)
 1: /lib/x86_64-linux-gnu/libpthread.so.0(+0x153c0) [0x7fb0243213c0]
 2: gsignal()
 3: abort()
 4: (ceph::__ceph_assert_fail(char const*, char const*, int, char 
const*)+0x1ad) [0x55f8bc092ebc]
 5: /usr/bin/ceph-osd(+0xac6069) [0x55f8bc093069]
 6: (PG::peek_map_epoch(ObjectStore*, spg_t, unsigned int*)+0xa17) 
[0x55f8bc21d057]
 7: (OSD::load_pgs()+0x6b4) [0x55f8bc18dec4]
 8: (OSD::init()+0x2b4e) [0x55f8bc19aa6e]
 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
  20/20 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 ---
  140394177402624 / rocksdb:dump_st
  140394202580736 / bstore_kv_sync
  140394278115072 / bstore_mempool
  140394286507776 / bstore_kv_final
  140394491248384 / ceph-osd
  max_recent     10000
  max_new        10000
  log_file /var/log/ceph/ceph-osd.2.log
--- end dump of recent events ---
2021-10-22T21:14:52.786+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread committed 1 
cleaned 0 in 0.050166298s (0.000000118s flush + 0.050166178s kv commit)
2021-10-22T21:14:52.786+0200 7fb01292c700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_sync_thread sleep
2021-10-22T21:14:52.786+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread wake
2021-10-22T21:14:52.786+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread kv_committed 
<0x55f8c88db880>
2021-10-22T21:14:52.786+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread 
deferred_stable <>
2021-10-22T21:14:52.786+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c88db880 kv_submitted
2021-10-22T21:14:52.786+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_committed_kv txc 
0x55f8c88db880
2021-10-22T21:14:52.786+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_state_proc txc 
0x55f8c88db880 finishing
2021-10-22T21:14:52.786+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish 0x55f8c88db880 
onodes 0x55f8d7059400
2021-10-22T21:14:52.786+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish  txc 0x55f8c88db880 
done
2021-10-22T21:14:52.786+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_finish osr 0x55f8d3e31ce0 q 
now empty
2021-10-22T21:14:52.786+0200 7fb017936700 10 
bluestore(/var/lib/ceph/osd/ceph-2) _txc_release_alloc(sync) 
0x55f8c88db880 []
2021-10-22T21:14:52.786+0200 7fb017936700 20 _unpin0x55f8c802c000 
#25:00000000::::head# unpinned
2021-10-22T21:14:52.786+0200 7fb017936700 20 
bluestore(/var/lib/ceph/osd/ceph-2) _kv_finalize_thread sleep
2021-10-22T21:14:52.794+0200 7fb017135700 20 
bluestore.MempoolThread(0x55f8c7380b90) _resize_shards cache_size: 
733711452 kv_alloc: 285212672 kv_used: 62318720 kv_onode_alloc: 
42949672 kv_onode_used: -22 meta_alloc: 281018368 meta_used: 34622 
data_alloc: 96468992 data_used: 94208
2021-10-22T21:14:52.846+0200 7fb017135700 20 
bluestore.MempoolThread(0x55f8c7380b90) _resize_shards cache_size: 
733714101 kv_alloc: 285212672 kv_used: 62318720 kv_onode_alloc: 
42949672 kv_onode_used: -22 meta_alloc: 281018368 meta_used: 34622 
data_alloc: 96468992 data_used: 94208

On 21.10.2021 00:19, Igor Fedotov wrote:
Hey mgrzybowski!

Never seen that before but perhaps some omaps have been improperly 
converted to new format and aren't read any more...

I'll take a more detailed look at what's happening during that 
load_pgs call and what exact information is missing.

Meanwhile could you please set debug-bluestore to 20 and collect 
OSD startup log?

Thanks,

Igor

On 10/21/2021 12:56 AM, mgrzybowski wrote:
Hi
  Recently I did perform upgrades on single node cephfs server i 
have.

# ceph fs ls
name: cephfs, metadata pool: cephfs_metadata, data pools: 
[cephfs_data ecpoolk3m1osd ecpoolk5m1osd ecpoolk4m2osd
~# ceph osd pool ls detail
pool 20 'cephfs_data' replicated size 3 min_size 2 crush_rule 0 
object_hash rjenkins pg_num 32 pgp_num 32 autoscale_mode warn 
last_change 10674 lfor 0/0/5088 flags hashpspool stripe_width 0 
application cephfs
pool 21 'cephfs_metadata' replicated size 3 min_size 2 crush_rule 
0 object_hash rjenkins pg_num 32 pgp_num 32 autoscale_mode warn 
last_change 10674 lfor 0/0/5179 flags hashpspool stripe_width 0 
application cephfs
pool 22 'ecpoolk3m1osd' erasure profile myprofilek3m1osd size 4 
min_size 3 crush_rule 3 object_hash rjenkins pg_num 16 pgp_num 16 
autoscale_mode warn last_change 10674 lfor 0/0/1442 flags 
hashpspool,ec_overwrites stripe_width 12288 compression_algorithm 
zstd compression_mode aggressive application cephfs
pool 23 'ecpoolk5m1osd' erasure profile myprofilek5m1osd size 6 
min_size 5 crush_rule 5 object_hash rjenkins pg_num 128 pgp_num 
128 autoscale_mode warn last_change 12517 lfor 0/0/7892 flags 
hashpspool,ec_overwrites stripe_width 20480 compression_algorithm 
zstd compression_mode aggressive application cephfs
pool 24 'ecpoolk4m2osd' erasure profile myprofilek4m2osd size 6 
min_size 5 crush_rule 6 object_hash rjenkins pg_num 64 pgp_num 64 
autoscale_mode warn last_change 10674 flags 
hashpspool,ec_overwrites stripe_width 16384 compression_algorithm 
zstd compression_mode aggressive application cephfs
pool 25 'device_health_metrics' replicated size 3 min_size 2 
crush_rule 0 object_hash rjenkins pg_num 32 pgp_num 32 
autoscale_mode on last_change 11033 lfor 0/0/10991 flags 
hashpspool stripe_width 0 pg_num_min 1 application mgr_devicehealth

I started this upgrade from ubuntu 16.04 and luminous ( there were 
upgrades in the past and some osd's could be started in Kraken ) ):
- first i upgraded ceph to Nautilus,  all seems to went well and 
accoording to the docs, no warning in status
- then i did "do-release-upgrade" to ubuntu to 18.04 ( ceph 
packaged were not touch by that upgrade )
- then i did "do-release-upgrade" to ubuntu to 20.04 ( this 
upgrade bumped ceph
  packages to 15.2.1-0ubuntu1, before each do-release-upgrade i 
removed /etc/ceph/ceph.conf,
  so at least mon deamon was down. osd should not start ( siple 
volumes are encrypted )
- next i upgraded ceph packages to  16.2.6-1focal m started deamons .

All seems to work well, only what left was warning:

10 OSD(s) reporting legacy (not per-pool) BlueStore omap usage stats

I found on the list that it is recommend to set:

ceph config set osd bluestore_fsck_quick_fix_on_mount true

and rolling restart OSDs. After first restart+fsck i got crash on 
OSD ( and on MDS to) :

    -1> 2021-10-14T22:02:45.877+0200 7f7f080a4f00 -1 
/build/ceph-16.2.6/src/osd/PG.cc: In function 'static int 
PG::peek_map_epoch(ObjectStore*, spg_t, epoch_t*)' thread 
7f7f080a4f00 time 2021-10-14T22:02:45.878154+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) [0x55e29cd0ce61]
 2: /usr/bin/ceph-osd(+0xac6069) [0x55e29cd0d069]
 3: (PG::peek_map_epoch(ObjectStore*, spg_t, unsigned int*)+0xa17) 
[0x55e29ce97057]
 4: (OSD::load_pgs()+0x6b4) [0x55e29ce07ec4]
 5: (OSD::init()+0x2b4e) [0x55e29ce14a6e]
 6: main()
 7: __libc_start_main()
 8: _start()

The same went on next restart+fsck  osd:

    -1> 2021-10-17T22:47:49.291+0200 7f98877bff00 -1 
/build/ceph-16.2.6/src/osd/PG.cc: In function 'static int 
PG::peek_map_epoch(ObjectStore*, spg_t, epoch_t*)' thread 
7f98877bff00 time 2021-10-17T22:47:49.292912+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) [0x560e09af7e61]
 2: /usr/bin/ceph-osd(+0xac6069) [0x560e09af8069]
 3: (PG::peek_map_epoch(ObjectStore*, spg_t, unsigned int*)+0xa17) 
[0x560e09c82057]
 4: (OSD::load_pgs()+0x6b4) [0x560e09bf2ec4]
 5: (OSD::init()+0x2b4e) [0x560e09bffa6e]
 6: main()
 7: __libc_start_main()
 8: _start()

Once crashed OSDs could not be bring back online, they will crash 
again if i try start them.
Deep fsck did not found anything:

~# ceph-bluestore-tool --command fsck  --deep yes --path 
/var/lib/ceph/osd/ceph-2
fsck success

Any ideas what could cause this crashes and is it possible to 
bring online crashed osd this way  ?

_______________________________________________
ceph-users mailing list -- ceph-users@xxxxxxx
To unsubscribe send an email to ceph-users-leave@xxxxxxx

_______________________________________________
ceph-users mailing list -- ceph-users@xxxxxxx
To unsubscribe send an email to ceph-users-leave@xxxxxxx

--
Igor Fedotov
Ceph Lead Developer

Looking for help with your Ceph cluster? Contact us at https://croit.io

croit GmbH, Freseniusstr. 31h, 81247 Munich
CEO: Martin Verges - VAT-ID: DE310638492
Com. register: Amtsgericht Munich HRB 231263
Web: https://croit.io | YouTube: https://goo.gl/PGE1Bx

_______________________________________________
ceph-users mailing list -- ceph-users@xxxxxxx
To unsubscribe send an email to ceph-users-leave@xxxxxxx