Project

General

Profile

Bug #39156 » ceph-osd.2.log

'osd.2' logs from node 'osd1' - Guillaume Abrioux, 04/09/2019 12:26 PM

 
2019-04-09 08:41:40.749 7f16195b1f00 0 set uid:gid to 64045:64045 (ceph:ceph)
2019-04-09 08:41:40.749 7f16195b1f00 0 ceph version 14.2.0 (3a54b2b6d167d4a2a19e003a705696d4fe619afc) nautilus (stable), process ceph-osd, pid 122294
2019-04-09 08:41:40.753 7f16195b1f00 0 pidfile_write: ignore empty --pid-file
2019-04-09 08:41:40.753 7f16195b1f00 1 bluestore(/var/lib/ceph/osd/ceph-2/) mkfs path /var/lib/ceph/osd/ceph-2/
2019-04-09 08:41:40.753 7f16195b1f00 -1 bluestore(/var/lib/ceph/osd/ceph-2/) _read_fsid unparsable uuid
2019-04-09 08:41:40.753 7f16195b1f00 1 bluestore(/var/lib/ceph/osd/ceph-2/) mkfs using provided fsid 4069624b-c8ef-4bab-bf60-41b0424fc98f
2019-04-09 08:41:40.753 7f16195b1f00 1 bdev create path /var/lib/ceph/osd/ceph-2//block type kernel
2019-04-09 08:41:40.753 7f16195b1f00 1 bdev(0x555c2d15e380 /var/lib/ceph/osd/ceph-2//block) open path /var/lib/ceph/osd/ceph-2//block
2019-04-09 08:41:40.757 7f16195b1f00 1 bdev(0x555c2d15e380 /var/lib/ceph/osd/ceph-2//block) open size 13421772800 (0x320000000, 12 GiB) block_size 4096 (4 KiB) rotational discard supported
2019-04-09 08:41:40.781 7f16195b1f00 1 bluestore(/var/lib/ceph/osd/ceph-2/) _set_cache_sizes cache_size 1073741824 meta 0.4 kv 0.4 data 0.2
2019-04-09 08:41:40.781 7f16195b1f00 1 bdev create path /var/lib/ceph/osd/ceph-2//block.db type kernel
2019-04-09 08:41:40.781 7f16195b1f00 1 bdev(0x555c2d15ea80 /var/lib/ceph/osd/ceph-2//block.db) open path /var/lib/ceph/osd/ceph-2//block.db
2019-04-09 08:41:40.781 7f16195b1f00 1 bdev(0x555c2d15ea80 /var/lib/ceph/osd/ceph-2//block.db) open size 26839351296 (0x63fc00000, 25 GiB) block_size 4096 (4 KiB) rotational discard supported
2019-04-09 08:41:40.781 7f16195b1f00 1 bluefs add_block_device bdev 1 path /var/lib/ceph/osd/ceph-2//block.db size 25 GiB
2019-04-09 08:41:40.797 7f16195b1f00 1 bluefs _add_block_extent bdev 1 0x2000~63fbfe000
2019-04-09 08:41:40.797 7f16195b1f00 1 bdev create path /var/lib/ceph/osd/ceph-2//block type kernel
2019-04-09 08:41:40.797 7f16195b1f00 1 bdev(0x555c2d15ee00 /var/lib/ceph/osd/ceph-2//block) open path /var/lib/ceph/osd/ceph-2//block
2019-04-09 08:41:40.797 7f16195b1f00 1 bdev(0x555c2d15ee00 /var/lib/ceph/osd/ceph-2//block) open size 13421772800 (0x320000000, 12 GiB) block_size 4096 (4 KiB) rotational discard supported
2019-04-09 08:41:40.797 7f16195b1f00 1 bluefs add_block_device bdev 2 path /var/lib/ceph/osd/ceph-2//block size 12 GiB
2019-04-09 08:41:40.797 7f16195b1f00 1 bluefs _add_block_extent bdev 2 0x170000000~40000000
2019-04-09 08:41:40.797 7f16195b1f00 1 bluefs mkfs osd_uuid 4069624b-c8ef-4bab-bf60-41b0424fc98f
2019-04-09 08:41:40.797 7f16195b1f00 1 bluefs mkfs uuid 4ed428e9-068e-424b-9a77-b135a93ac4d8
2019-04-09 08:41:40.821 7f16195b1f00 1 fbmap_alloc 0x555c2c31e300 shutdown
2019-04-09 08:41:40.821 7f16195b1f00 1 fbmap_alloc 0x555c2c31e400 shutdown
2019-04-09 08:41:40.821 7f16195b1f00 1 bluefs mount
2019-04-09 08:41:40.825 7f16195b1f00 -1 /build/ceph-14.2.0/src/os/bluestore/fastbmap_allocator_impl.h: In function 'void AllocatorLevel02<T>::_mark_allocated(uint64_t, uint64_t) [with L1 = AllocatorLevel01Loose; uint64_t = long unsigned int]' thread 7f16195b1f00 time 2019-04-09 08:41:40.828356
/build/ceph-14.2.0/src/os/bluestore/fastbmap_allocator_impl.h: 731: FAILED ceph_assert(available >= allocated)

ceph version 14.2.0 (3a54b2b6d167d4a2a19e003a705696d4fe619afc) nautilus (stable)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x152) [0x555c21cde7e0]
2: (ceph::__ceph_assertf_fail(char const*, char const*, int, char const*, char const*, ...)+0) [0x555c21cde9bb]
3: (BitmapAllocator::init_rm_free(unsigned long, unsigned long)+0x6fc) [0x555c223e1b8c]
4: (BlueFS::mount()+0x2a0) [0x555c223ad630]
5: (BlueStore::_open_bluefs(bool)+0x8c) [0x555c22288a0c]
6: (BlueStore::_open_db(bool, bool, bool)+0xa5c) [0x555c22289d8c]
7: (BlueStore::mkfs()+0x11d1) [0x555c222ef351]
8: (OSD::mkfs(CephContext*, ObjectStore*, uuid_d, int)+0xd5) [0x555c21decc35]
9: (main()+0x1979) [0x555c21ce3849]
10: (__libc_start_main()+0xe7) [0x7f1615a6eb97]
11: (_start()+0x2a) [0x555c21dcb12a]

2019-04-09 08:41:40.829 7f16195b1f00 -1 *** Caught signal (Aborted) **
in thread 7f16195b1f00 thread_name:ceph-osd

ceph version 14.2.0 (3a54b2b6d167d4a2a19e003a705696d4fe619afc) nautilus (stable)
1: (()+0x12890) [0x7f1616dd9890]
2: (gsignal()+0xc7) [0x7f1615a8be97]
3: (abort()+0x141) [0x7f1615a8d801]
4: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x1a3) [0x555c21cde831]
5: (ceph::__ceph_assertf_fail(char const*, char const*, int, char const*, char const*, ...)+0) [0x555c21cde9bb]
6: (BitmapAllocator::init_rm_free(unsigned long, unsigned long)+0x6fc) [0x555c223e1b8c]
7: (BlueFS::mount()+0x2a0) [0x555c223ad630]
8: (BlueStore::_open_bluefs(bool)+0x8c) [0x555c22288a0c]
9: (BlueStore::_open_db(bool, bool, bool)+0xa5c) [0x555c22289d8c]
10: (BlueStore::mkfs()+0x11d1) [0x555c222ef351]
11: (OSD::mkfs(CephContext*, ObjectStore*, uuid_d, int)+0xd5) [0x555c21decc35]
12: (main()+0x1979) [0x555c21ce3849]
13: (__libc_start_main()+0xe7) [0x7f1615a6eb97]
14: (_start()+0x2a) [0x555c21dcb12a]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
-190> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command assert hook 0x555c2c2a4270
-189> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command abort hook 0x555c2c2a4270
-188> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command perfcounters_dump hook 0x555c2c2a4270
-187> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command 1 hook 0x555c2c2a4270
-186> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command perf dump hook 0x555c2c2a4270
-185> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command perfcounters_schema hook 0x555c2c2a4270
-184> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command perf histogram dump hook 0x555c2c2a4270
-183> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command 2 hook 0x555c2c2a4270
-182> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command perf schema hook 0x555c2c2a4270
-181> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command perf histogram schema hook 0x555c2c2a4270
-180> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command perf reset hook 0x555c2c2a4270
-179> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command config show hook 0x555c2c2a4270
-178> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command config help hook 0x555c2c2a4270
-177> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command config set hook 0x555c2c2a4270
-176> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command config unset hook 0x555c2c2a4270
-175> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command config get hook 0x555c2c2a4270
-174> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command config diff hook 0x555c2c2a4270
-173> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command config diff get hook 0x555c2c2a4270
-172> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command log flush hook 0x555c2c2a4270
-171> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command log dump hook 0x555c2c2a4270
-170> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command log reopen hook 0x555c2c2a4270
-169> 2019-04-09 08:41:40.737 7f16195b1f00 5 asok(0x555c2c63e000) register_command dump_mempools hook 0x555c2d12a068
-168> 2019-04-09 08:41:40.745 7f16195b1f00 10 monclient: get_monmap_and_config
-167> 2019-04-09 08:41:40.745 7f16195b1f00 10 monclient: build_initial_monmap
-166> 2019-04-09 08:41:40.745 7f16195b1f00 10 monclient: monmap:
epoch 1
fsid ccdbb3cb-ce97-42b1-9d2b-bdf46e7cca3b
last_changed 2019-04-09 08:35:02.607844
created 2019-04-09 08:35:02.607844
min_mon_release 14 (nautilus)
0: [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] mon.mon0
1: [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0] mon.mon1
2: [v2:192.168.1.12:3300/0,v1:192.168.1.12:6789/0] mon.mon2

-165> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x555c2c67e140) adding auth protocol: cephx
-164> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x555c2c67e140) adding auth protocol: cephx
-163> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x555c2c67e140) adding auth protocol: cephx
-162> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x555c2c67e140) adding auth protocol: none
-161> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x555c2c67e140) adding con mode: crc
-160> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x555c2c67e140) adding con mode: crc
-159> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x555c2c67e140) adding con mode: crc
-158> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x555c2c67e140) adding con mode: crc
-157> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x555c2c67e140) adding con mode: crc
-156> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x555c2c67e140) adding con mode: crc
-155> 2019-04-09 08:41:40.745 7f16195b1f00 2 auth: KeyRing::load: loaded key file /var/lib/ceph/osd/ceph-2//keyring
-154> 2019-04-09 08:41:40.745 7f1613742700 2 Event(0x555c2c2a6bc0 nevent=5000 time_id=1).set_owner idx=0 owner=139732792387328
-153> 2019-04-09 08:41:40.745 7f1612f41700 2 Event(0x555c2c2a7280 nevent=5000 time_id=1).set_owner idx=1 owner=139732783994624
-152> 2019-04-09 08:41:40.745 7f1612740700 2 Event(0x555c2c2a74c0 nevent=5000 time_id=1).set_owner idx=2 owner=139732775601920
-151> 2019-04-09 08:41:40.745 7f16195b1f00 1 Processor -- start
-150> 2019-04-09 08:41:40.745 7f16195b1f00 1 -- start start
-149> 2019-04-09 08:41:40.745 7f16195b1f00 10 monclient: init
-148> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x7ffc9b2da9d8) adding auth protocol: cephx
-147> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x7ffc9b2da9d8) adding auth protocol: cephx
-146> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x7ffc9b2da9d8) adding auth protocol: cephx
-145> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x7ffc9b2da9d8) adding auth protocol: none
-144> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x7ffc9b2da9d8) adding con mode: crc
-143> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x7ffc9b2da9d8) adding con mode: crc
-142> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x7ffc9b2da9d8) adding con mode: crc
-141> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x7ffc9b2da9d8) adding con mode: crc
-140> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x7ffc9b2da9d8) adding con mode: crc
-139> 2019-04-09 08:41:40.745 7f16195b1f00 5 AuthRegistry(0x7ffc9b2da9d8) adding con mode: crc
-138> 2019-04-09 08:41:40.745 7f16195b1f00 2 auth: KeyRing::load: loaded key file /var/lib/ceph/osd/ceph-2//keyring
-137> 2019-04-09 08:41:40.745 7f16195b1f00 2 auth: KeyRing::load: loaded key file /var/lib/ceph/osd/ceph-2//keyring
-136> 2019-04-09 08:41:40.745 7f16195b1f00 10 monclient: _reopen_session rank -1
-135> 2019-04-09 08:41:40.745 7f16195b1f00 1 --2- >> [v2:192.168.1.12:3300/0,v1:192.168.1.12:6789/0] conn(0x555c2c543a80 0x555c2d162580 unknown :-1 s=NONE pgs=0 cs=0 l=0 rx=0 tx=0).connect
-134> 2019-04-09 08:41:40.745 7f16195b1f00 10 monclient(hunting): picked mon.mon2 con 0x555c2c543a80 addr [v2:192.168.1.12:3300/0,v1:192.168.1.12:6789/0]
-133> 2019-04-09 08:41:40.745 7f16195b1f00 1 --2- >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 unknown :-1 s=NONE pgs=0 cs=0 l=0 rx=0 tx=0).connect
-132> 2019-04-09 08:41:40.745 7f16195b1f00 10 monclient(hunting): picked mon.mon0 con 0x555c2d20e000 addr [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0]
-131> 2019-04-09 08:41:40.745 7f16195b1f00 1 --2- >> [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0] conn(0x555c2d20e480 0x555c2d163080 unknown :-1 s=NONE pgs=0 cs=0 l=0 rx=0 tx=0).connect
-130> 2019-04-09 08:41:40.745 7f16195b1f00 10 monclient(hunting): picked mon.mon1 con 0x555c2d20e480 addr [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0]
-129> 2019-04-09 08:41:40.745 7f16195b1f00 10 monclient(hunting): start opening mon connection
-128> 2019-04-09 08:41:40.745 7f16195b1f00 1 -- --> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] -- mon_getmap magic: 0 v1 -- 0x555c2c34ae00 con 0x555c2d20e000
-127> 2019-04-09 08:41:40.745 7f16195b1f00 5 --2- >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 unknown :-1 s=START_CONNECT pgs=0 cs=0 l=0 rx=0 tx=0).send_message enqueueing message m=0x555c2c34ae00 type=5 mon_getmap magic: 0 v1
-126> 2019-04-09 08:41:40.745 7f16195b1f00 10 monclient(hunting): start opening mon connection
-125> 2019-04-09 08:41:40.745 7f16195b1f00 1 -- --> [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0] -- mon_getmap magic: 0 v1 -- 0x555c2c34ac40 con 0x555c2d20e480
-124> 2019-04-09 08:41:40.745 7f16195b1f00 5 --2- >> [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0] conn(0x555c2d20e480 0x555c2d163080 unknown :-1 s=START_CONNECT pgs=0 cs=0 l=0 rx=0 tx=0).send_message enqueueing message m=0x555c2c34ac40 type=5 mon_getmap magic: 0 v1
-123> 2019-04-09 08:41:40.745 7f16195b1f00 10 monclient(hunting): start opening mon connection
-122> 2019-04-09 08:41:40.745 7f16195b1f00 1 -- --> [v2:192.168.1.12:3300/0,v1:192.168.1.12:6789/0] -- mon_getmap magic: 0 v1 -- 0x555c2c34a700 con 0x555c2c543a80
-121> 2019-04-09 08:41:40.745 7f16195b1f00 5 --2- >> [v2:192.168.1.12:3300/0,v1:192.168.1.12:6789/0] conn(0x555c2c543a80 0x555c2d162580 unknown :-1 s=START_CONNECT pgs=0 cs=0 l=0 rx=0 tx=0).send_message enqueueing message m=0x555c2c34a700 type=5 mon_getmap magic: 0 v1
-120> 2019-04-09 08:41:40.745 7f16195b1f00 10 monclient(hunting): _renew_subs
-119> 2019-04-09 08:41:40.745 7f16195b1f00 10 monclient(hunting): authenticate will time out at 2019-04-09 08:46:40.751844
-118> 2019-04-09 08:41:40.745 7f1613742700 1 --2- >> [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0] conn(0x555c2d20e480 0x555c2d163080 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0)._handle_peer_banner_payload supported=0 required=0
-117> 2019-04-09 08:41:40.745 7f1612740700 1 --2- >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0)._handle_peer_banner_payload supported=0 required=0
-116> 2019-04-09 08:41:40.745 7f1613742700 5 --2- >> [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0] conn(0x555c2d20e480 0x555c2d163080 unknown :-1 s=HELLO_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_hello received hello: peer_type=1 peer_addr_for_me=v2:192.168.1.101:44744/0
-115> 2019-04-09 08:41:40.745 7f1613742700 10 monclient(hunting): get_auth_request con 0x555c2d20e480 auth_method 0
-114> 2019-04-09 08:41:40.745 7f1613742700 10 monclient(hunting): get_auth_request method 2 preferred_modes [1]
-113> 2019-04-09 08:41:40.745 7f1613742700 10 monclient(hunting): _init_auth method 2
-112> 2019-04-09 08:41:40.745 7f1612740700 5 --2- >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 unknown :-1 s=HELLO_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_hello received hello: peer_type=1 peer_addr_for_me=v2:192.168.1.101:40200/0
-111> 2019-04-09 08:41:40.745 7f1612740700 10 monclient(hunting): get_auth_request con 0x555c2d20e000 auth_method 0
-110> 2019-04-09 08:41:40.745 7f1612740700 10 monclient(hunting): get_auth_request method 2 preferred_modes [1]
-109> 2019-04-09 08:41:40.745 7f1612740700 10 monclient(hunting): _init_auth method 2
-108> 2019-04-09 08:41:40.749 7f1612f41700 1 --2- >> [v2:192.168.1.12:3300/0,v1:192.168.1.12:6789/0] conn(0x555c2c543a80 0x555c2d162580 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0)._handle_peer_banner_payload supported=0 required=0
-107> 2019-04-09 08:41:40.749 7f1612f41700 5 --2- >> [v2:192.168.1.12:3300/0,v1:192.168.1.12:6789/0] conn(0x555c2c543a80 0x555c2d162580 unknown :-1 s=HELLO_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_hello received hello: peer_type=1 peer_addr_for_me=v2:192.168.1.101:49340/0
-106> 2019-04-09 08:41:40.749 7f1612f41700 10 monclient(hunting): get_auth_request con 0x555c2c543a80 auth_method 0
-105> 2019-04-09 08:41:40.749 7f1612f41700 10 monclient(hunting): get_auth_request method 2 preferred_modes [1]
-104> 2019-04-09 08:41:40.749 7f1612f41700 10 monclient(hunting): _init_auth method 2
-103> 2019-04-09 08:41:40.749 7f1612740700 5 --2- >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 unknown :-1 s=AUTH_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_auth_reply_more auth reply more len=9
-102> 2019-04-09 08:41:40.749 7f1612740700 10 monclient(hunting): handle_auth_reply_more payload 9
-101> 2019-04-09 08:41:40.749 7f1613742700 5 --2- >> [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0] conn(0x555c2d20e480 0x555c2d163080 unknown :-1 s=AUTH_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_auth_reply_more auth reply more len=9
-100> 2019-04-09 08:41:40.749 7f1612740700 10 monclient(hunting): handle_auth_reply_more payload_len 9
-99> 2019-04-09 08:41:40.749 7f1612740700 10 monclient(hunting): handle_auth_reply_more responding with 36 bytes
-98> 2019-04-09 08:41:40.749 7f1613742700 10 monclient(hunting): handle_auth_reply_more payload 9
-97> 2019-04-09 08:41:40.749 7f1613742700 10 monclient(hunting): handle_auth_reply_more payload_len 9
-96> 2019-04-09 08:41:40.749 7f1613742700 10 monclient(hunting): handle_auth_reply_more responding with 36 bytes
-95> 2019-04-09 08:41:40.749 7f1612740700 10 monclient(hunting): handle_auth_done global_id 4353 payload 386
-94> 2019-04-09 08:41:40.749 7f1612740700 1 -- >> [v2:192.168.1.12:3300/0,v1:192.168.1.12:6789/0] conn(0x555c2c543a80 msgr2=0x555c2d162580 unknown :-1 s=STATE_CONNECTION_ESTABLISHED l=0).mark_down
-93> 2019-04-09 08:41:40.749 7f1612740700 1 --2- >> [v2:192.168.1.12:3300/0,v1:192.168.1.12:6789/0] conn(0x555c2c543a80 0x555c2d162580 unknown :-1 s=AUTH_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0).stop
-92> 2019-04-09 08:41:40.749 7f1612740700 1 -- >> [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0] conn(0x555c2d20e480 msgr2=0x555c2d163080 unknown :-1 s=STATE_CONNECTION_ESTABLISHED l=0).mark_down
-91> 2019-04-09 08:41:40.749 7f1612740700 1 --2- >> [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0] conn(0x555c2d20e480 0x555c2d163080 unknown :-1 s=AUTH_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0).stop
-90> 2019-04-09 08:41:40.749 7f1612740700 10 monclient: _finish_hunting 0
-89> 2019-04-09 08:41:40.749 7f1612740700 1 monclient: found mon.mon0
-88> 2019-04-09 08:41:40.749 7f1612740700 10 monclient: _send_mon_message to mon.mon0 at v2:192.168.1.10:3300/0
-87> 2019-04-09 08:41:40.749 7f1612740700 1 -- --> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] -- mon_subscribe({config=0+,monmap=2+}) v3 -- 0x555c2c2c8600 con 0x555c2d20e000
-86> 2019-04-09 08:41:40.749 7f1612740700 5 --2- >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 unknown :-1 s=AUTH_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0).send_message enqueueing message m=0x555c2c2c8600 type=15 mon_subscribe({config=0+,monmap=2+}) v3
-85> 2019-04-09 08:41:40.749 7f1612740700 10 monclient: _finish_auth 0
-84> 2019-04-09 08:41:40.749 7f1612740700 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2019-04-09 08:41:10.753206)
-83> 2019-04-09 08:41:40.749 7f1612740700 10 monclient: _send_mon_message to mon.mon0 at v2:192.168.1.10:3300/0
-82> 2019-04-09 08:41:40.749 7f1612740700 1 -- --> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] -- auth(proto 2 2 bytes epoch 0) v1 -- 0x555c2c2a7b00 con 0x555c2d20e000
-81> 2019-04-09 08:41:40.749 7f1612740700 5 --2- >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 unknown :-1 s=AUTH_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0).send_message enqueueing message m=0x555c2c2a7b00 type=17 auth(proto 2 2 bytes epoch 0) v1
-80> 2019-04-09 08:41:40.749 7f1613742700 1 --2- >> [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0] conn(0x555c2d20e480 0x555c2d163080 unknown :-1 s=CLOSED pgs=0 cs=0 l=0 rx=0 tx=0).handle_auth_done state changed!
-79> 2019-04-09 08:41:40.749 7f1612740700 1 --2- >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=SESSION_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0).send_client_ident getsockname reveals I am 192.168.1.101:40200 when talking to v2:192.168.1.10:3300/0
-78> 2019-04-09 08:41:40.749 7f1612740700 1 -- 192.168.1.101:0/1262403769 learned_addr learned my addr 192.168.1.101:0/1262403769 (peer_addr_for_me v2:192.168.1.101:0/0)
-77> 2019-04-09 08:41:40.749 7f1612740700 5 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=SESSION_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0).send_client_ident sending identification: addrs=192.168.1.101:0/1262403769 target=v2:192.168.1.10:3300/0 gid=-1 global_seq=3 features_supported=3ffddff8ffacffff features_required=800000000000000 flags=0 cookie=dc76e0bf8f62aa22
-76> 2019-04-09 08:41:40.749 7f16195b1f00 5 monclient: authenticate success, global_id 4353
-75> 2019-04-09 08:41:40.749 7f1612740700 5 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=SESSION_CONNECTING pgs=0 cs=0 l=0 rx=0 tx=0).handle_server_ident received server identification: addrs=[v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] gid=0 global_seq=105 features_supported=3ffddff8ffacffff features_required=c01020002040000 flags=1 cookie=0
-74> 2019-04-09 08:41:40.749 7f1612740700 1 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=READY pgs=105 cs=0 l=1 rx=0 tx=0).ready entity=mon.0 client_cookie=dc76e0bf8f62aa22 server_cookie=0 in_seq=0 out_seq=0
-73> 2019-04-09 08:41:40.749 7f1612740700 5 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=READY pgs=105 cs=0 l=1 rx=0 tx=0).write_message sending message m=0x555c2c34ae00 seq=1 mon_getmap magic: 0 v1
-72> 2019-04-09 08:41:40.749 7f1612740700 5 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=READY pgs=105 cs=0 l=1 rx=0 tx=0).write_message sending message m=0x555c2c2c8600 seq=2 mon_subscribe({config=0+,monmap=2+}) v3
-71> 2019-04-09 08:41:40.749 7f1612740700 5 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=READY pgs=105 cs=0 l=1 rx=0 tx=0).write_message sending message m=0x555c2c2a7b00 seq=3 auth(proto 2 2 bytes epoch 0) v1
-70> 2019-04-09 08:41:40.749 7f1612740700 5 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=THROTTLE_DONE pgs=105 cs=0 l=1 rx=0 tx=0).handle_message got 404 + 0 + 0 byte message. envelope type=4 src mon.0 off 0
-69> 2019-04-09 08:41:40.749 7f1612740700 5 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=READ_MESSAGE_COMPLETE pgs=105 cs=0 l=1 rx=0 tx=0).handle_message received message m=0x555c2c2c8600 seq=1 from=mon.0 type=4 mon_map magic: 0 v1
-68> 2019-04-09 08:41:40.749 7f1612740700 5 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=THROTTLE_DONE pgs=105 cs=0 l=1 rx=0 tx=0).handle_message got 4 + 0 + 0 byte message. envelope type=62 src mon.0 off 0
-67> 2019-04-09 08:41:40.749 7f1612740700 5 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=READ_MESSAGE_COMPLETE pgs=105 cs=0 l=1 rx=0 tx=0).handle_message received message m=0x555c2c316b40 seq=2 from=mon.0 type=62 config(0 keys) v1
-66> 2019-04-09 08:41:40.749 7f1612740700 5 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=THROTTLE_DONE pgs=105 cs=0 l=1 rx=0 tx=0).handle_message got 194 + 0 + 0 byte message. envelope type=18 src mon.0 off 0
-65> 2019-04-09 08:41:40.749 7f1611f3f700 1 -- 192.168.1.101:0/1262403769 <== mon.0 v2:192.168.1.10:3300/0 1 ==== mon_map magic: 0 v1 ==== 404+0+0 (crc 0 0 0) 0x555c2c2c8600 con 0x555c2d20e000
-64> 2019-04-09 08:41:40.749 7f1611f3f700 10 monclient: handle_monmap mon_map magic: 0 v1
-63> 2019-04-09 08:41:40.749 7f1611f3f700 10 monclient: got monmap 1 from mon.mon0 (according to old e1)
-62> 2019-04-09 08:41:40.749 7f1612740700 5 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=READ_MESSAGE_COMPLETE pgs=105 cs=0 l=1 rx=0 tx=0).handle_message received message m=0x555c2c2a7b00 seq=3 from=mon.0 type=18 auth_reply(proto 2 0 (0) Success) v1
-61> 2019-04-09 08:41:40.749 7f1611f3f700 10 monclient: dump:
epoch 1
fsid ccdbb3cb-ce97-42b1-9d2b-bdf46e7cca3b
last_changed 2019-04-09 08:35:02.607844
created 2019-04-09 08:35:02.607844
min_mon_release 14 (nautilus)
0: [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] mon.mon0
1: [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0] mon.mon1
2: [v2:192.168.1.12:3300/0,v1:192.168.1.12:6789/0] mon.mon2

-60> 2019-04-09 08:41:40.749 7f1611f3f700 1 -- 192.168.1.101:0/1262403769 <== mon.0 v2:192.168.1.10:3300/0 2 ==== config(0 keys) v1 ==== 4+0+0 (crc 0 0 0) 0x555c2c316b40 con 0x555c2d20e000
-59> 2019-04-09 08:41:40.749 7f1611f3f700 10 monclient: handle_config config(0 keys) v1
-58> 2019-04-09 08:41:40.749 7f16195b1f00 10 monclient: get_monmap_and_config success
-57> 2019-04-09 08:41:40.749 7f16195b1f00 10 monclient: shutdown
-56> 2019-04-09 08:41:40.749 7f1611f3f700 1 -- 192.168.1.101:0/1262403769 <== mon.0 v2:192.168.1.10:3300/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 194+0+0 (crc 0 0 0) 0x555c2c2a7b00 con 0x555c2d20e000
-55> 2019-04-09 08:41:40.749 7f16195b1f00 1 -- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 msgr2=0x555c2d162b00 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
-54> 2019-04-09 08:41:40.749 7f16195b1f00 1 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 crc :-1 s=READY pgs=105 cs=0 l=1 rx=0 tx=0).stop
-53> 2019-04-09 08:41:40.749 7f1611f3f700 10 monclient: discarding stray monitor message auth_reply(proto 2 0 (0) Success) v1
-52> 2019-04-09 08:41:40.749 7f161073c700 4 set_mon_vals no callback set
-51> 2019-04-09 08:41:40.749 7f16195b1f00 1 -- 192.168.1.101:0/1262403769 shutdown_connections
-50> 2019-04-09 08:41:40.749 7f16195b1f00 5 -- 192.168.1.101:0/1262403769 shutdown_connections mark down [v2:192.168.1.12:3300/0,v1:192.168.1.12:6789/0] 0x555c2c543a80
-49> 2019-04-09 08:41:40.749 7f16195b1f00 1 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.12:3300/0,v1:192.168.1.12:6789/0] conn(0x555c2c543a80 0x555c2d162580 unknown :-1 s=CLOSED pgs=0 cs=0 l=0 rx=0 tx=0).stop
-48> 2019-04-09 08:41:40.749 7f16195b1f00 5 -- 192.168.1.101:0/1262403769 shutdown_connections mark down [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0] 0x555c2d20e480
-47> 2019-04-09 08:41:40.749 7f16195b1f00 1 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.11:3300/0,v1:192.168.1.11:6789/0] conn(0x555c2d20e480 0x555c2d163080 unknown :-1 s=CLOSED pgs=0 cs=0 l=0 rx=0 tx=0).stop
-46> 2019-04-09 08:41:40.749 7f16195b1f00 5 -- 192.168.1.101:0/1262403769 shutdown_connections mark down [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] 0x555c2d20e000
-45> 2019-04-09 08:41:40.749 7f16195b1f00 1 --2- 192.168.1.101:0/1262403769 >> [v2:192.168.1.10:3300/0,v1:192.168.1.10:6789/0] conn(0x555c2d20e000 0x555c2d162b00 unknown :-1 s=CLOSED pgs=105 cs=0 l=1 rx=0 tx=0).stop
-44> 2019-04-09 08:41:40.749 7f16195b1f00 5 -- 192.168.1.101:0/1262403769 shutdown_connections delete 0x555c2c543a80
-43> 2019-04-09 08:41:40.749 7f16195b1f00 5 -- 192.168.1.101:0/1262403769 shutdown_connections delete 0x555c2d20e000
-42> 2019-04-09 08:41:40.749 7f16195b1f00 5 -- 192.168.1.101:0/1262403769 shutdown_connections delete 0x555c2d20e480
-41> 2019-04-09 08:41:40.749 7f16195b1f00 1 -- 192.168.1.101:0/1262403769 shutdown_connections
-40> 2019-04-09 08:41:40.749 7f16195b1f00 1 -- 192.168.1.101:0/1262403769 wait complete.
-39> 2019-04-09 08:41:40.749 7f16195b1f00 1 -- 192.168.1.101:0/1262403769 >> 192.168.1.101:0/1262403769 conn(0x555c2c543600 msgr2=0x555c2d16c000 unknown :-1 s=STATE_NONE l=0).mark_down
-38> 2019-04-09 08:41:40.749 7f16195b1f00 2 --1- 192.168.1.101:0/1262403769 >> 192.168.1.101:0/1262403769 conn(0x555c2c543600 0x555c2d16c000 :-1 s=NONE pgs=0 cs=0 l=0).stop
-37> 2019-04-09 08:41:40.749 7f16195b1f00 0 set uid:gid to 64045:64045 (ceph:ceph)
-36> 2019-04-09 08:41:40.749 7f16195b1f00 0 ceph version 14.2.0 (3a54b2b6d167d4a2a19e003a705696d4fe619afc) nautilus (stable), process ceph-osd, pid 122294
-35> 2019-04-09 08:41:40.753 7f16195b1f00 0 pidfile_write: ignore empty --pid-file
-34> 2019-04-09 08:41:40.753 7f16195b1f00 5 asok(0x555c2c63e000) init /var/run/ceph/ceph-osd.2.asok
-33> 2019-04-09 08:41:40.753 7f16195b1f00 5 asok(0x555c2c63e000) bind_and_listen /var/run/ceph/ceph-osd.2.asok
-32> 2019-04-09 08:41:40.753 7f16195b1f00 5 asok(0x555c2c63e000) register_command 0 hook 0x555c2c2a33d8
-31> 2019-04-09 08:41:40.753 7f16195b1f00 5 asok(0x555c2c63e000) register_command version hook 0x555c2c2a33d8
-30> 2019-04-09 08:41:40.753 7f16195b1f00 5 asok(0x555c2c63e000) register_command git_version hook 0x555c2c2a33d8
-29> 2019-04-09 08:41:40.753 7f16195b1f00 5 asok(0x555c2c63e000) register_command help hook 0x555c2c2a4520
-28> 2019-04-09 08:41:40.753 7f16195b1f00 5 asok(0x555c2c63e000) register_command get_command_descriptions hook 0x555c2c2a4530
-27> 2019-04-09 08:41:40.753 7f1612f41700 5 asok(0x555c2c63e000) entry start
-26> 2019-04-09 08:41:40.753 7f16195b1f00 1 bluestore(/var/lib/ceph/osd/ceph-2/) mkfs path /var/lib/ceph/osd/ceph-2/
-25> 2019-04-09 08:41:40.753 7f16195b1f00 2 bluestore(/var/lib/ceph/osd/ceph-2//block) _read_bdev_label unable to decode label at offset 102: buffer::malformed_input: void bluestore_bdev_label_t::decode(ceph::buffer::v14_2_0::list::const_iterator&) decode past end of struct encoding
-24> 2019-04-09 08:41:40.753 7f16195b1f00 2 bluestore(/var/lib/ceph/osd/ceph-2//block) _read_bdev_label unable to decode label at offset 102: buffer::malformed_input: void bluestore_bdev_label_t::decode(ceph::buffer::v14_2_0::list::const_iterator&) decode past end of struct encoding
-23> 2019-04-09 08:41:40.753 7f16195b1f00 2 bluestore(/var/lib/ceph/osd/ceph-2//block) _read_bdev_label unable to decode label at offset 102: buffer::malformed_input: void bluestore_bdev_label_t::decode(ceph::buffer::v14_2_0::list::const_iterator&) decode past end of struct encoding
-22> 2019-04-09 08:41:40.753 7f16195b1f00 -1 bluestore(/var/lib/ceph/osd/ceph-2/) _read_fsid unparsable uuid
-21> 2019-04-09 08:41:40.753 7f16195b1f00 1 bluestore(/var/lib/ceph/osd/ceph-2/) mkfs using provided fsid 4069624b-c8ef-4bab-bf60-41b0424fc98f
-20> 2019-04-09 08:41:40.753 7f16195b1f00 1 bdev create path /var/lib/ceph/osd/ceph-2//block type kernel
-19> 2019-04-09 08:41:40.753 7f16195b1f00 1 bdev(0x555c2d15e380 /var/lib/ceph/osd/ceph-2//block) open path /var/lib/ceph/osd/ceph-2//block
-18> 2019-04-09 08:41:40.757 7f16195b1f00 1 bdev(0x555c2d15e380 /var/lib/ceph/osd/ceph-2//block) open size 13421772800 (0x320000000, 12 GiB) block_size 4096 (4 KiB) rotational discard supported
-17> 2019-04-09 08:41:40.781 7f16195b1f00 1 bluestore(/var/lib/ceph/osd/ceph-2/) _set_cache_sizes cache_size 1073741824 meta 0.4 kv 0.4 data 0.2
-16> 2019-04-09 08:41:40.781 7f16195b1f00 1 bdev create path /var/lib/ceph/osd/ceph-2//block.db type kernel
-15> 2019-04-09 08:41:40.781 7f16195b1f00 1 bdev(0x555c2d15ea80 /var/lib/ceph/osd/ceph-2//block.db) open path /var/lib/ceph/osd/ceph-2//block.db
-14> 2019-04-09 08:41:40.781 7f16195b1f00 1 bdev(0x555c2d15ea80 /var/lib/ceph/osd/ceph-2//block.db) open size 26839351296 (0x63fc00000, 25 GiB) block_size 4096 (4 KiB) rotational discard supported
-13> 2019-04-09 08:41:40.781 7f16195b1f00 1 bluefs add_block_device bdev 1 path /var/lib/ceph/osd/ceph-2//block.db size 25 GiB
-12> 2019-04-09 08:41:40.797 7f16195b1f00 1 bluefs _add_block_extent bdev 1 0x2000~63fbfe000
-11> 2019-04-09 08:41:40.797 7f16195b1f00 1 bdev create path /var/lib/ceph/osd/ceph-2//block type kernel
-10> 2019-04-09 08:41:40.797 7f16195b1f00 1 bdev(0x555c2d15ee00 /var/lib/ceph/osd/ceph-2//block) open path /var/lib/ceph/osd/ceph-2//block
-9> 2019-04-09 08:41:40.797 7f16195b1f00 1 bdev(0x555c2d15ee00 /var/lib/ceph/osd/ceph-2//block) open size 13421772800 (0x320000000, 12 GiB) block_size 4096 (4 KiB) rotational discard supported
-8> 2019-04-09 08:41:40.797 7f16195b1f00 1 bluefs add_block_device bdev 2 path /var/lib/ceph/osd/ceph-2//block size 12 GiB
-7> 2019-04-09 08:41:40.797 7f16195b1f00 1 bluefs _add_block_extent bdev 2 0x170000000~40000000
-6> 2019-04-09 08:41:40.797 7f16195b1f00 1 bluefs mkfs osd_uuid 4069624b-c8ef-4bab-bf60-41b0424fc98f
-5> 2019-04-09 08:41:40.797 7f16195b1f00 1 bluefs mkfs uuid 4ed428e9-068e-424b-9a77-b135a93ac4d8
-4> 2019-04-09 08:41:40.821 7f16195b1f00 1 fbmap_alloc 0x555c2c31e300 shutdown
-3> 2019-04-09 08:41:40.821 7f16195b1f00 1 fbmap_alloc 0x555c2c31e400 shutdown
-2> 2019-04-09 08:41:40.821 7f16195b1f00 1 bluefs mount
-1> 2019-04-09 08:41:40.825 7f16195b1f00 -1 /build/ceph-14.2.0/src/os/bluestore/fastbmap_allocator_impl.h: In function 'void AllocatorLevel02<T>::_mark_allocated(uint64_t, uint64_t) [with L1 = AllocatorLevel01Loose; uint64_t = long unsigned int]' thread 7f16195b1f00 time 2019-04-09 08:41:40.828356
/build/ceph-14.2.0/src/os/bluestore/fastbmap_allocator_impl.h: 731: FAILED ceph_assert(available >= allocated)

ceph version 14.2.0 (3a54b2b6d167d4a2a19e003a705696d4fe619afc) nautilus (stable)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x152) [0x555c21cde7e0]
2: (ceph::__ceph_assertf_fail(char const*, char const*, int, char const*, char const*, ...)+0) [0x555c21cde9bb]
3: (BitmapAllocator::init_rm_free(unsigned long, unsigned long)+0x6fc) [0x555c223e1b8c]
4: (BlueFS::mount()+0x2a0) [0x555c223ad630]
5: (BlueStore::_open_bluefs(bool)+0x8c) [0x555c22288a0c]
6: (BlueStore::_open_db(bool, bool, bool)+0xa5c) [0x555c22289d8c]
7: (BlueStore::mkfs()+0x11d1) [0x555c222ef351]
8: (OSD::mkfs(CephContext*, ObjectStore*, uuid_d, int)+0xd5) [0x555c21decc35]
9: (main()+0x1979) [0x555c21ce3849]
10: (__libc_start_main()+0xe7) [0x7f1615a6eb97]
11: (_start()+0x2a) [0x555c21dcb12a]

0> 2019-04-09 08:41:40.829 7f16195b1f00 -1 *** Caught signal (Aborted) **
in thread 7f16195b1f00 thread_name:ceph-osd

ceph version 14.2.0 (3a54b2b6d167d4a2a19e003a705696d4fe619afc) nautilus (stable)
1: (()+0x12890) [0x7f1616dd9890]
2: (gsignal()+0xc7) [0x7f1615a8be97]
3: (abort()+0x141) [0x7f1615a8d801]
4: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x1a3) [0x555c21cde831]
5: (ceph::__ceph_assertf_fail(char const*, char const*, int, char const*, char const*, ...)+0) [0x555c21cde9bb]
6: (BitmapAllocator::init_rm_free(unsigned long, unsigned long)+0x6fc) [0x555c223e1b8c]
7: (BlueFS::mount()+0x2a0) [0x555c223ad630]
8: (BlueStore::_open_bluefs(bool)+0x8c) [0x555c22288a0c]
9: (BlueStore::_open_db(bool, bool, bool)+0xa5c) [0x555c22289d8c]
10: (BlueStore::mkfs()+0x11d1) [0x555c222ef351]
11: (OSD::mkfs(CephContext*, ObjectStore*, uuid_d, int)+0xd5) [0x555c21decc35]
12: (main()+0x1979) [0x555c21ce3849]
13: (__libc_start_main()+0xe7) [0x7f1615a6eb97]
14: (_start()+0x2a) [0x555c21dcb12a]
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 journaler
0/ 5 objectcacher
0/ 5 client
1/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
0/ 5 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 xio
1/ 5 compressor
1/ 5 bluestore
1/ 5 bluefs
1/ 3 bdev
1/ 5 kstore
4/ 5 rocksdb
4/ 5 leveldb
4/ 5 memdb
1/ 5 kinetic
1/ 5 fuse
1/ 5 mgr
1/ 5 mgrc
1/ 5 dpdk
1/ 5 eventtrace
-2/-2 (syslog threshold)
-1/-1 (stderr threshold)
max_recent 10000
max_new 1000
log_file /var/log/ceph/ceph-osd.2.log
--- end dump of recent events ---
(1-1/2)