- ceph-users - lists.ceph.io

Ceph 15.2.4 segfault, msgr-worker
by Ivan Kurnosov 14 Dec '20

14 Dec '20

Hi Team, this night I have caught the following segfault. Nothing else looks suspicious (but I'm a quite newbie in ceph management, so perhaps just don't know where to look at). I could not google any similar segfault from anybody else. Was it a known problem fixed in later versions? The cluster has been running for quite a while now (several months) and this has happened for the first time. ``` debug 0> 2020-12-02T10:31:09.295+0000 7f3e61943700 -1 *** Caught signal (Segmentation fault) ** in thread 7f3e61943700 thread_name:msgr-worker-1 ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable) 1: (()+0x12dd0) [0x7f3e65933dd0] 2: (std::_Rb_tree<boost::intrusive_ptr<AsyncConnection>, boost::intrusive_ptr<AsyncConnection>, std::_Identity<boost::intrusive_ptr<AsyncConnection> >, std::less<boost::intrusive_ptr<AsyncConnection> >, std::allocator<boost::intrusive_ptr<AsyncConnection> > >::find(boost::intrusive_ptr<AsyncConnection> const&) const+0x2c) [0x55cee407ca7c] 3: (AsyncConnection::_stop()+0xab) [0x55cee40767eb] 4: (ProtocolV2::stop()+0x8f) [0x55cee40a189f] 5: (ProtocolV2::_fault()+0x133) [0x55cee40a1b03] 6: (ProtocolV2::handle_read_frame_preamble_main(std::unique_ptr<ceph::buffer::v15_2_0::ptr_node, ceph::buffer::v15_2_0::ptr_node::disposer>&&, int)+0x551) [0x55cee40a63d1] 7: (ProtocolV2::run_continuation(Ct<ProtocolV2>&)+0x3c) [0x55cee40a273c] 8: (AsyncConnection::process()+0x8a9) [0x55cee4079ab9] 9: (EventCenter::process_events(unsigned int, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> >*)+0xcb7) [0x55cee3eceb67] 10: (()+0xdb914c) [0x55cee3ed414c] 11: (()+0xc2b73) [0x7f3e64f83b73] 12: (()+0x82de) [0x7f3e659292de] 13: (clone()+0x43) [0x7f3e64660e83] 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_rwl 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 1/ 5 bluestore 1/ 5 bluefs 1/ 3 bdev 1/ 5 kstore 4/ 5 rocksdb 4/ 5 leveldb 4/ 5 memdb 1/ 5 fuse 1/ 5 mgr 1/ 5 mgrc 1/ 5 dpdk 1/ 5 eventtrace 1/ 5 prioritycache 0/ 5 test -2/-2 (syslog threshold) 99/99 (stderr threshold) --- pthread ID / name mapping for recent threads --- 7f3e3d88b700 / osd_srv_heartbt 7f3e41893700 / tp_osd_tp 7f3e4589b700 / tp_osd_tp 7f3e4f8af700 / rocksdb:dump_st 7f3e52a8c700 / safe_timer 7f3e53a8e700 / ms_dispatch 7f3e566b7700 / bstore_mempool 7f3e5d0ca700 / safe_timer 7f3e61943700 / msgr-worker-1 7f3e62144700 / msgr-worker-0 max_recent 10000 max_new 1000 log_file /var/lib/ceph/crash/2020-12-02T10:31:09.301492Z_84e8430f-30fd-469f-8e22-c2e1ccc675da/log --- end dump of recent events --- reraise_fatal: default handler for signal 11 didn't terminate the process? ``` -- With best regards, Ivan Kurnosov

2 1

Removing an applied service set
by Michael Wodniok 14 Dec '20

14 Dec '20

Hi, we created multiple CephFS, this invloved deploying mutliple mds-services using `ceph orch apply mds [...]`. Worked like a charm. Now the filesystem has been removed and the leftovers of the filesystem should also be removed, but I can't delete the services as cephadm/orchestration module is recreating them. What is the "official" way to delete this applied service set? Setting placement size to 0 is not possible in Ceph 15. Kind regards, Michael

2 2

Re: pool nearfull, 300GB rbd image occupies 11TB!
by mk 13 Dec '20

13 Dec '20

In fact journaling was enabled, is it enough to disable feature and pool shrinks automatically again? Or still any additional actions are required? — Max > On 13. Dec 2020, at 15:53, Anthony D'Atri <anthony.datri(a)gmail.com> wrote: > > rbd status > rbd info > > If the ‘journaling’ flag is enabled, use ‘rbd feature’ to remove it from the image. > > > >> On Dec 13, 2020, at 6:22 AM, mk <mk(a)pop.de> wrote: >> >> Yes, few months ago I had enabled mirroring for few weeks and disabled again. Is there any additional actions has to be taken regarding journalling also ?? >> fyi. I also have copied rbd image into one newly created pool but after few weeks new pool grew up again to 11TB which is current state >> -- >> BR >> Max >> >>> On 13. Dec 2020, at 14:34, Jason Dillaman <jdillama(a)redhat.com> wrote: >>> >>>> On Sun, Dec 13, 2020 at 6:03 AM mk <mk(a)pop.de> wrote: >>>> >>>> rados ls -p ssdshop >>>> outputs 20MB of lines without any bench prefix >>>> ... >>>> rbd_data.d4993cc3c89825.00000000000074ec >>>> rbd_data.d4993cc3c89825.0000000000001634 >>>> journal_data.83.d4993cc3c89825.333485 >>>> journal_data.83.d4993cc3c89825.380648 >>>> journal_data.83.d4993cc3c89825.503838 >>>> ... >>> >>> If you have journal objects indexed at 333485 and 503838, that's >>> nearly 2TiBs of data right there. Sounds like you enabled journaling >>> and mirroring but perhaps never turned it off when you stopped using >>> it? >>> >>>>> On 13. Dec 2020, at 11:05, Anthony D'Atri <anthony.datri(a)gmail.com> wrote: >>>>> >>>>> Any chance you might have orphaned `rados bench` objects ? This happens more than one might think. >>>>> >>>>> `rados ls > /tmp/out` >>>>> >>>>> Inspect the result. You should see a few administrative objects, some header and data objects for the RBD volume. If you see a zillion with names like `bench*` there’s your culprit. Those can be cleaned up. >>>>> >>>>> >>>>> >>>>>> On Dec 12, 2020, at 11:42 PM, mk <mk(a)pop.de> wrote: >>>>>> >>>>>> Hi folks, >>>>>> my cluster shows strange behavior, the only ssd pool on cluster with repsize 3 and pg/pgp size 512 >>>>>> which contains 300GB rbd image and only one snapshot occupies 11TB space! >>>>>> >>>>>> I have tried objectmap check / rebuild, fstrim etc. which couldn’t solve that problem, any help would be appreciated. >>>>>> >>>>>> >>>>>> ceph version 14.2.7 nautilus (stable) >>>>>> >>>>>> >>>>>> ceph df >>>>>> ------- >>>>>> RAW STORAGE: >>>>>> CLASS SIZE AVAIL USED RAW USED %RAW USED >>>>>> hdd 107 TiB 68 TiB 39 TiB 39 TiB 36.45 >>>>>> ssd 21 TiB 11 TiB 11 TiB 11 TiB 50.78 >>>>>> TOTAL 128 TiB 78 TiB 50 TiB 50 TiB 38.84 >>>>>> >>>>>> POOLS: >>>>>> POOL ID STORED OBJECTS USED %USED MAX AVAIL >>>>>> ssdshop 83 3.5 TiB 517.72k 11 TiB 96.70 124 GiB >>>>>> >>>>>> >>>>>> rados df >>>>>> -------- >>>>>> POOL_NAME USED OBJECTS CLONES COPIES MISSING_ON_PRIMARY UNFOUND DEGRADED RD_OPS RD WR_OPS WR USED COMPR UNDER COMPR >>>>>> ssdshop 11 TiB 537040 28316 1611120 0 0 0 11482773 15 GiB 44189589 854 GiB 0 B 0 B >>>>>> >>>>>> >>>>>> >>>>>> rbd du -p ssdshop >>>>>> ----------------- >>>>>> NAME PROVISIONED USED >>>>>> shp-de-300gb.rbd@snap_2020-12-12_20:30:00 300 GiB 289 GiB >>>>>> shp-de-300gb.rbd 300 GiB 109 GiB >>>>>> <TOTAL> 300 GiB 398 GiB >>>>>> >>>>>> >>>>>> crush_rule >>>>>> ----------- >>>>>> rule ssd { >>>>>> id 3 >>>>>> type replicated >>>>>> min_size 1 >>>>>> max_size 10 >>>>>> step take dc1 class ssd >>>>>> step chooseleaf firstn 2 type rack >>>>>> step emit >>>>>> step take dc2 class ssd >>>>>> step chooseleaf firstn -1 type rack >>>>>> step emit >>>>>> } >>>>>> >>>>>> BR >>>>>> Max >>>>>> _______________________________________________ >>>>>> ceph-users mailing list -- ceph-users(a)ceph.io >>>>>> To unsubscribe send an email to ceph-users-leave(a)ceph.io >>>>> _______________________________________________ >>>>> ceph-users mailing list -- ceph-users(a)ceph.io >>>>> To unsubscribe send an email to ceph-users-leave(a)ceph.io >>>> _______________________________________________ >>>> ceph-users mailing list -- ceph-users(a)ceph.io >>>> To unsubscribe send an email to ceph-users-leave(a)ceph.io >>> >>> >>> >>> -- >>> Jason >>> _______________________________________________ >>> ceph-users mailing list -- ceph-users(a)ceph.io >>> To unsubscribe send an email to ceph-users-leave(a)ceph.io >>

2 2

pool nearfull, 300GB rbd image occupies 11TB!
by mk 13 Dec '20

13 Dec '20

Hi folks, my cluster shows strange behavior, the only ssd pool on cluster with repsize 3 and pg/pgp size 512 which contains 300GB rbd image and only one snapshot occupies 11TB space! I have tried objectmap check / rebuild, fstrim etc. which couldn’t solve that problem, any help would be appreciated. ceph version 14.2.7 nautilus (stable) ceph df ------- RAW STORAGE: CLASS SIZE AVAIL USED RAW USED %RAW USED hdd 107 TiB 68 TiB 39 TiB 39 TiB 36.45 ssd 21 TiB 11 TiB 11 TiB 11 TiB 50.78 TOTAL 128 TiB 78 TiB 50 TiB 50 TiB 38.84 POOLS: POOL ID STORED OBJECTS USED %USED MAX AVAIL ssdshop 83 3.5 TiB 517.72k 11 TiB 96.70 124 GiB rados df -------- POOL_NAME USED OBJECTS CLONES COPIES MISSING_ON_PRIMARY UNFOUND DEGRADED RD_OPS RD WR_OPS WR USED COMPR UNDER COMPR ssdshop 11 TiB 537040 28316 1611120 0 0 0 11482773 15 GiB 44189589 854 GiB 0 B 0 B rbd du -p ssdshop ----------------- NAME PROVISIONED USED shp-de-300gb.rbd@snap_2020-12-12_20:30:00 300 GiB 289 GiB shp-de-300gb.rbd 300 GiB 109 GiB <TOTAL> 300 GiB 398 GiB crush_rule ----------- rule ssd { id 3 type replicated min_size 1 max_size 10 step take dc1 class ssd step chooseleaf firstn 2 type rack step emit step take dc2 class ssd step chooseleaf firstn -1 type rack step emit } BR Max

3 4

pool nearfull, 300GB rbd image occupies 11TB!
by mk 13 Dec '20

13 Dec '20

Hi folks, my cluster shows strange behavior, the only ssd pool on cluster with repsize 3 and pg/pgp size 512 which contains 300GB rbd image and only one snapshot occupies 11TB space! I have tried objectmap check / rebuild, fstrim etc. which couldn’t solve that problem, any help would be appreciated. ceph version 14.2.7 nautilus (stable) ceph df ------- RAW STORAGE: CLASS SIZE AVAIL USED RAW USED %RAW USED hdd 107 TiB 68 TiB 39 TiB 39 TiB 36.45 ssd 21 TiB 11 TiB 11 TiB 11 TiB 50.78 TOTAL 128 TiB 78 TiB 50 TiB 50 TiB 38.84 POOLS: POOL ID STORED OBJECTS USED %USED MAX AVAIL ssdshop 83 3.5 TiB 517.72k 11 TiB 96.70 124 GiB rados df -------- POOL_NAME USED OBJECTS CLONES COPIES MISSING_ON_PRIMARY UNFOUND DEGRADED RD_OPS RD WR_OPS WR USED COMPR UNDER COMPR ssdshop 11 TiB 537040 28316 1611120 0 0 0 11482773 15 GiB 44189589 854 GiB 0 B 0 B rbd du -p ssdshop ----------------- NAME PROVISIONED USED shp-de-300gb.rbd@snap_2020-12-12_20:30:00 300 GiB 289 GiB shp-de-300gb.rbd 300 GiB 109 GiB <TOTAL> 300 GiB 398 GiB crush_rule ----------- rule ssd { id 3 type replicated min_size 1 max_size 10 step take dc1 class ssd step chooseleaf firstn 2 type rack step emit step take dc2 class ssd step chooseleaf firstn -1 type rack step emit } BR Max

1 0

Third nautilus OSD dead in 11 days - FAILED is_valid_io(off, len)
by Jonas Jelten 12 Dec '20

12 Dec '20

Hi! Yesterday a third OSD died with a failed assertion, and it can no longer boot. It's the third OSD within 11 days. There's already a tracker issue: https://tracker.ceph.com/issues/48276 2020-12-11 20:06:51.839 7fe2b5ffd700 -1 /build/ceph-14.2.13/src/os/bluestore/KernelDevice.cc: In function 'virtual int KernelDevice::aio_write(uint64_t, ceph::bufferlist&, IOContext*, bool, int)' thread 7fe2b5ffd /build/ceph-14.2.13/src/os/bluestore/KernelDevice.cc: 864: FAILED ceph_assert(is_valid_io(off, len)) ceph version 14.2.13 (1778d63e55dbff6cedb071ab7d367f8f52a8699f) nautilus (stable) 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x152) [0x55ff9fac9eea] 2: (ceph::__ceph_assertf_fail(char const*, char const*, int, char const*, char const*, ...)+0) [0x55ff9faca0c5] 3: (KernelDevice::aio_write(unsigned long, ceph::buffer::v14_2_0::list&, IOContext*, bool, int)+0x19e9) [0x55ffa01272a9] 4: (BlueStore::_deferred_submit_unlock(BlueStore::OpSequencer*)+0x621) [0x55ff9ffe87f1] 5: (BlueStore::deferred_try_submit()+0x3e0) [0x55ff9ffe9da0] 6: (BlueStore::_kv_finalize_thread()+0x6c6) [0x55ffa002fcc6] 7: (BlueStore::KVFinalizeThread::entry()+0xd) [0x55ffa006066d] 8: (()+0x76db) [0x7fe2c61456db] 9: (clone()+0x3f) [0x7fe2c4ee571f] When the OSD tries to boot (now with 14.2.15), it fails again: -4> 2020-12-11 20:07:05.160 7ff2d15e7c00 1 bluestore(/var/lib/ceph/osd/ceph-147) _open_db opened rocksdb path db options compression=kNoCompression,max_write_buffer_number=4,min_write_buffer_number_to_merge=1,recycle_log_file_num=4,write_buffer_size=268435456,writable_file_max_buffer_size=0,compaction_readahead_size=2097152,max_background_compactions=2 -3> 2020-12-11 20:07:05.160 7ff2d15e7c00 1 bluestore(/var/lib/ceph/osd/ceph-147) _upgrade_super from 2, latest 2 -2> 2020-12-11 20:07:05.160 7ff2d15e7c00 1 bluestore(/var/lib/ceph/osd/ceph-147) _upgrade_super done -1> 2020-12-11 20:07:05.184 7ff2d15e7c00 -1 /build/ceph-14.2.15/src/os/bluestore/KernelDevice.cc: In function 'virtual int KernelDevice::aio_write(uint64_t, ceph::bufferlist&, IOContext*, bool, int)' thread 7ff2d15e7c00 time 2020-12-11 20:07:05.186142 /build/ceph-14.2.15/src/os/bluestore/KernelDevice.cc: 888: FAILED ceph_assert(is_valid_io(off, len)) ceph version 14.2.15 (afdd217ae5fb1ed3f60e16bd62357ca58cc650e5) nautilus (stable) 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x152) [0x564ad1323fba] 2: (ceph::__ceph_assertf_fail(char const*, char const*, int, char const*, char const*, ...)+0) [0x564ad1324195] 3: (KernelDevice::aio_write(unsigned long, ceph::buffer::v14_2_0::list&, IOContext*, bool, int)+0x16da) [0x564ad198154a] 4: (BlueStore::_deferred_submit_unlock(BlueStore::OpSequencer*)+0x621) [0x564ad1842911] 5: (BlueStore::deferred_try_submit()+0x3e0) [0x564ad1843ec0] 6: (BlueStore::_osr_drain_all()+0x1a5) [0x564ad1845255] 7: (BlueStore::_deferred_replay()+0x1c7) [0x564ad188b297] 8: (BlueStore::_mount(bool, bool)+0x83e) [0x564ad1892e1e] 9: (OSD::init()+0x3f3) [0x564ad13d3db3] 10: (main()+0x5214) [0x564ad132ccf4] 11: (__libc_start_main()+0xe7) [0x7ff2cde60bf7] 12: (_start()+0x2a) [0x564ad135e72a] Anyone else with these symptoms? Any ideas how we can track it down? -- Jonas

2 2

Anonymous access to grafana
by Alessandro Piazza 12 Dec '20

12 Dec '20

Dear all, It seems that by default the grafana web page embedded inside the ceph dashboard is publicly available in read-only mode. More specifically the grafana configuration inside the docker running the grafana instance has the following configuration file (/usr/share/ceph/mgr/cephadm/templates/services/grafana/grafana.ini.j2) [auth.anonymous] enabled = true org_name = 'Main Org.' org_role = 'Viewer' Do you think that this might be a security concern? Is there a way to enforce authentication also for the read-only mode? I wasn't able to find any documentation on how to configure grafana. The only thing I found which might be related to this issue is the following: https://tracker.ceph.com/issues/45372. Regards, Alessandro Piazza

1 0

MON: global_init: error reading config file.
by Oscar Segarra 11 Dec '20

11 Dec '20

Hi, In my environment I have a single node and I'm trying to run a ceph monitor as a docker container using a kv store. Version: Octopus (stable-5.0) 2020-12-12 00:24:28 /opt/ceph-container/bin/entrypoint.sh: STAYALIVE: container will not die if a command fails., 2020-12-12 00:24:28 /opt/ceph-container/bin/entrypoint.sh: 'auth' key already exists, 2020-12-12 00:24:28 /opt/ceph-container/bin/entrypoint.sh: 'global' key already exists, 2020-12-12 00:24:28 /opt/ceph-container/bin/entrypoint.sh: 'mon' key already exists, 2020-12-12 00:24:28 /opt/ceph-container/bin/entrypoint.sh: 'mds' key already exists, 2020-12-12 00:24:28 /opt/ceph-container/bin/entrypoint.sh: 'osd' key already exists, 2020-12-12 00:24:28 /opt/ceph-container/bin/entrypoint.sh: 'client' key already exists, 2020-12-12 00:24:28 /opt/ceph-container/bin/entrypoint.sh: Adding Mon Host - vdicnode01., 0.0.0.0, vdicnode01, true, 2020-12-12 00:24:28 /opt/ceph-container/bin/entrypoint.sh: Configuration found for cluster ceph. Writing to disk., true, 2020-12-12T00:24:29+01:00 vdicnode01.local /tmp/gztmpGeLTQkuFB/confd[139]: INFO Backend set to etcd, 2020-12-12T00:24:29+01:00 vdicnode01.local /tmp/gztmpGeLTQkuFB/confd[139]: INFO Starting confd, 2020-12-12T00:24:29+01:00 vdicnode01.local /tmp/gztmpGeLTQkuFB/confd[139]: INFO Backend source(s) set to http://127.0.0.1:2379, 2020-12-12 00:24:29 /opt/ceph-container/bin/entrypoint.sh: Adding bootstrap keyrings., 2020-12-12 00:24:30 /opt/ceph-container/bin/entrypoint.sh: Adding mon/admin Keyrings., 2020-12-12 00:24:30 /opt/ceph-container/bin/entrypoint.sh: Trying to get the most recent monmap..., Error initializing cluster client: InvalidArgumentError('RADOS invalid argument (error calling conf_read_file)',), 2020-12-12 00:24:30 /opt/ceph-container/bin/entrypoint.sh: Peers not found, using initial monmap., 2020-12-12 00:24:30 /opt/ceph-container/bin/entrypoint.sh: Removing lock for vdicnode01., PrevNode.Value: vdicnode01, importing contents of /var/lib/ceph/bootstrap-osd/ceph.keyring into /etc/ceph/ceph.mon.keyring, importing contents of /var/lib/ceph/bootstrap-mds/ceph.keyring into /etc/ceph/ceph.mon.keyring, importing contents of /var/lib/ceph/bootstrap-rgw/ceph.keyring into /etc/ceph/ceph.mon.keyring, importing contents of /var/lib/ceph/bootstrap-rbd-mirror/ceph.keyring into /etc/ceph/ceph.mon.keyring, importing contents of /etc/ceph/ceph.client.admin.keyring into /etc/ceph/ceph.mon.keyring, global_init: error reading config file., And container dies (even the stayalive flag). docker service create -d --network=host \ --mount type=bind,source=/var/lib/ceph,destination=/var/lib/ceph \ --mount type=bind,source=/var/log/ceph,destination=/var/log/ceph \ --mount type=bind,source=/etc/localtime,destination=/etc/localtime,readonly \ -e KV_TYPE=etcd \ -e KV_IP=127.0.0.1 \ -e KV_PORT=2379 \ -e MON_IP=0.0.0.0 \ -e CEPH_PUBLIC_NETWORK=192.168.100.0/24 \ -e CEPH_CLUSTER_NETWORK=192.168.100.0/24 \ -e DEBUG=stayalive \ --name=vdicube_ceph_mon \ --mode=global \ --constraint node.labels.mon==1 \ ceph/daemon:v5.0.6-stable-5.0-octopus-centos-8 mon Anyone has experimented the same issue? Thanks a lot. Ó

1 0

Incomplete PG due to primary OSD crashing during EC backfill - get_hash_info: Mismatch of total_chunk_size 0
by Byrne, Thomas (STFC,RAL,SC) 11 Dec '20

11 Dec '20

Hi all, Got an odd issue that I'm not sure how to solve on our Nautilus 14.2.9 EC cluster. The primary OSD of an EC 8+3 PG died this morning with a very sad disk (thousands of pending sectors). After the down out interval a new 'up' primary was assigned and the backfill started. Twenty minutes later the acting primary (not the new 'up' primary) started crashing with a "get_hash_info: Mismatch of total_chunk_size 0" error (see log below) This crash always happens at the same object, with different acting primaries, and with a different new 'up' primary. I can't see anything in the logs that points to a particular OSD being the issue, so I suspect there is a corrupted object in the PG that is causing issues, but I'm not sure how to dig into this further. The PG is currently active (but degraded), but only whilst nobackfill or noout are set (+turning the new OSD off), and if the flags are unset the backfill will eventually crash enough OSDs to render the PG incomplete, which is not ideal. I would appreciate being able to resolve this so I can go back to letting Ceph deal with down OSDs itself :) Does anyone have some pointers on how to dig into or resolve this? Happy to create a tracker ticket and post more logs if this looks like a bug. Thanks, Tom OSD log with debug_osd=20 (preamble cut from subsequent lines in an attempt to improve readability...): 2020-12-10 15:14:16.130 7fc0a1575700 10 osd.1708 pg_epoch: 1162259 pg[11.214s1( v 1162255'714638 (1162110'711564,1162255'714638] local-lis/les=1162253/1162254 n=133385 ec=1069520/992 lis/c 1162253/1125301 les/c/f 1162254/1125302/257760 1162252/1162253/1162253) [2449,1708,2099,1346,4309,777,5098,4501,4134,217,4643]/[2147483647,1708,2099,1346,4309,777,5098,4501,4134,217,4643]p1708(1) backfill=[2449(0)] r=1 lpr=1162253 pi=[1125301,1162253)/3 rops=1 crt=1162255'714638 lcod 1162254'714637 mlcod 1162254'714637 active+undersized+degraded+remapped+backfilling mbc={}] run_recovery_op: starting RecoveryOp(hoid=11:28447b4a:::962de230-ed6c-44f2-ab02-788c52ea6a82.3210530112.122__multipart_201%2fin5%2fexp_4-05-737%2fprocessed%2fspe%2fsqw_187570.nxspe.2~bgZPo_rC64ZXJWKyTfdn4dIApqLNDPp.22:head v=1162125'713150 missing_on=2449(0) missing_on_shards=0 recovery_info=ObjectRecoveryInfo(11:28447b4a:::962de230-ed6c-44f2-ab02-788c52ea6a82.3210530112.122__multipart_201%2fin5%2fexp_4-05-737%2fprocessed%2fspe%2fsqw_187570.nxspe.2~bgZPo_rC64ZXJWKyTfdn4dIApqLNDPp.22:head@1162125'713150, size: 4194304, copy_subset: [], clone_subset: {}, snapset: 0=[]:{}) recovery_progress=ObjectRecoveryProgress(first, data_recovered_to:0, data_complete:false, omap_recovered_to:, omap_complete:true, error:false) obc refcount=3 state=IDLE waiting_on_pushes= extent_requested=0,0) continue_recovery_op: continuing RecoveryOp(hoid=11:28447b4a:::962de230-ed6c-44f2-ab02-788c52ea6a82.3210530112.122__multipart_201%2fin5%2fexp_4-05-737%2fprocessed%2fspe%2fsqw_187570.nxspe.2~bgZPo_rC64ZXJWKyTfdn4dIApqLNDPp.22:head v=1162125'713150 missing_on=2449(0) missing_on_shards=0 recovery_info=ObjectRecoveryInfo(11:28447b4a:::962de230-ed6c-44f2-ab02-788c52ea6a82.3210530112.122__multipart_201%2fin5%2fexp_4-05-737%2fprocessed%2fspe%2fsqw_187570.nxspe.2~bgZPo_rC64ZXJWKyTfdn4dIApqLNDPp.22:head@1162125'713150, size: 4194304, copy_subset: [], clone_subset: {}, snapset: 0=[]:{}) recovery_progress=ObjectRecoveryProgress(first, data_recovered_to:0, data_complete:false, omap_recovered_to:, omap_complete:true, error:false) obc refcount=4 state=IDLE waiting_on_pushes= extent_requested=0,0) get_hash_info: Getting attr on 11:28447b4a:::962de230-ed6c-44f2-ab02-788c52ea6a82.3210530112.122__multipart_201%2fin5%2fexp_4-05-737%2fprocessed%2fspe%2fsqw_187570.nxspe.2~bgZPo_rC64ZXJWKyTfdn4dIApqLNDPp.22:head get_hash_info: not in cache 11:28447b4a:::962de230-ed6c-44f2-ab02-788c52ea6a82.3210530112.122__multipart_201%2fin5%2fexp_4-05-737%2fprocessed%2fspe%2fsqw_187570.nxspe.2~bgZPo_rC64ZXJWKyTfdn4dIApqLNDPp.22:head get_hash_info: found on disk, size 524288 get_hash_info: Mismatch of total_chunk_size 0 2020-12-10 15:14:16.136 7fc0a1575700 -1 /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/gigantic/release/14.2.9/rpm/el7/BUILD/ceph-14.2.9/src/osd/ECBackend.cc: In function 'void ECBackend::continue_recovery_op(ECBackend::RecoveryOp&, RecoveryMessages*)' thread 7fc0a1575700 time 2020-12-10 15:14:16.132060 /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/gigantic/release/14.2.9/rpm/el7/BUILD/ceph-14.2.9/src/osd/ECBackend.cc: 585: FAILED ceph_assert(op.hinfo) ceph version 14.2.9 (581f22da52345dba46ee232b73b990f06029a2a0) nautilus (stable) 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x14a) [0x55e1569acf7d] 2: (()+0x4cb145) [0x55e1569ad145] 3: (ECBackend::continue_recovery_op(ECBackend::RecoveryOp&, RecoveryMessages*)+0x1764) [0x55e156da5834] 4: (ECBackend::run_recovery_op(PGBackend::RecoveryHandle*, int)+0x65b) [0x55e156da6c6b] 5: (PrimaryLogPG::recover_backfill(unsigned long, ThreadPool::TPHandle&, bool*)+0x1491) [0x55e156c26681] 6: (PrimaryLogPG::start_recovery_ops(unsigned long, ThreadPool::TPHandle&, unsigned long*)+0x114c) [0x55e156c29f7c] 7: (OSD::do_recovery(PG*, unsigned int, unsigned long, ThreadPool::TPHandle&)+0x2ff) [0x55e156a8b32f] 8: (PGRecovery::run(OSD*, OSDShard*, boost::intrusive_ptr<PG>&, ThreadPool::TPHandle&)+0x19) [0x55e156d1aa19] 9: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0x90f) [0x55e156aa6b4f] 10: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x5b6) [0x55e15704b216] 11: (ShardedThreadPool::WorkThreadSharded::entry()+0x10) [0x55e15704dd30] 12: (()+0x7ea5) [0x7fc0c2d5dea5] 13: (clone()+0x6d) [0x7fc0c1c208dd] 2020-12-10 15:14:16.143 7fc0a1575700 -1 *** Caught signal (Aborted) ** This email and any attachments are intended solely for the use of the named recipients. If you are not the intended recipient you must not use, disclose, copy or distribute this email or any of its attachments and should notify the sender immediately and delete this email from your system. UK Research and Innovation (UKRI) has taken every reasonable precaution to minimise risk of this email or any attachments containing viruses or malware but the recipient should carry out its own virus and malware checks before opening the attachments. UKRI does not accept any liability for any losses or damages which the recipient may sustain due to presence of any viruses. Opinions, conclusions or other information in this message and attachments that are not related directly to UKRI business are solely those of the author and do not represent the views of UKRI.

1 2

Scrubbing - osd down
by Miroslav Boháč 11 Dec '20

11 Dec '20

Hi, I have a problem with crashing OSD daemons in our Ceph 15.2.6 cluster . The problem was temporarily resolved by disabling scrub and deep-scrub. All PGs are active+clean. After a few days I tried to enable scrubbing again, but the problem persists. OSD with high latencies, PG laggy, osd not responding, OSD was marked down and the cluster is not usable. Problem appeared after failover when 10 OSD was marked as out. I will appreciate any help or advice, how to resolve this problem. Regards, Miroslav 2020-12-10T21:39:57.721883+0100 osd.1 (osd.1) 5 : cluster [DBG] 18.11 deep-scrub starts 2020-12-10T21:39:57.880861+0100 osd.1 (osd.1) 6 : cluster [DBG] 18.11 deep-scrub ok 2020-12-10T21:39:58.713422+0100 osd.1 (osd.1) 7 : cluster [DBG] 43.5 scrub starts 2020-12-10T21:39:58.719372+0100 osd.1 (osd.1) 8 : cluster [DBG] 43.5 scrub ok 2020-12-10T21:39:59.296962+0100 mgr.pve2-prg2a (mgr.91575377) 118746 : cluster [DBG] pgmap v119000: 1737 pgs: 3 active+clean+laggy, 3 active+clean+scrubbing+deep, 1731 active+clean; 3.3 TiB data, 7.8 TiB used, 21 TiB / 29 TiB avail; 117 KiB/s rd, 2.5 MiB/s wr, 269 op/s 2020-12-10T21:40:00.088421+0100 osd.29 (osd.29) 74 : cluster [DBG] 1.13b deep-scrub starts 2020-12-10T21:40:01.300373+0100 mgr.pve2-prg2a (mgr.91575377) 118747 : cluster [DBG] pgmap v119001: 1737 pgs: 3 active+clean+laggy, 3 active+clean+scrubbing+deep, 1731 active+clean; 3.3 TiB data, 7.8 TiB used, 21 TiB / 29 TiB avail; 101 KiB/s rd, 1.9 MiB/s wr, 202 op/s 2020-12-10T21:40:02.681058+0100 osd.34 (osd.34) 13 : cluster [DBG] 1.a2 deep-scrub ok 2020-12-10T21:40:03.304009+0100 mgr.pve2-prg2a (mgr.91575377) 118749 : cluster [DBG] pgmap v119002: 1737 pgs: 3 active+clean+laggy, 3 active+clean+scrubbing+deep, 1731 active+clean; 3.3 TiB data, 7.8 TiB used, 21 TiB / 29 TiB avail; 101 KiB/s rd, 1.9 MiB/s wr, 198 op/s 2020-12-10T21:40:05.316233+0100 mgr.pve2-prg2a (mgr.91575377) 118750 : cluster [DBG] pgmap v119003: 1737 pgs: 6 active+clean+laggy, 3 active+clean+scrubbing+deep, 1728 active+clean; 3.3 TiB data, 7.8 TiB used, 21 TiB / 29 TiB avail; 150 KiB/s rd, 3.0 MiB/s wr, 249 op/s 2020-12-10T21:40:07.319643+0100 mgr.pve2-prg2a (mgr.91575377) 118751 : cluster [DBG] pgmap v119004: 1737 pgs: 6 active+clean+laggy, 3 active+clean+scrubbing+deep, 1728 active+clean; 3.3 TiB data, 7.8 TiB used, 21 TiB / 29 TiB avail; 142 KiB/s rd, 2.3 MiB/s wr, 212 op/s 2020-12-10T21:40:15.523134+0100 mon.pve1-prg2a (mon.0) 125943 : cluster [DBG] osd.4 reported failed by osd.24 2020-12-10T21:40:15.523325+0100 mon.pve1-prg2a (mon.0) 125944 : cluster [DBG] osd.39 reported failed by osd.24 2020-12-10T21:40:16.112299+0100 mon.pve1-prg2a (mon.0) 125946 : cluster [WRN] Health check failed: 0 slow ops, oldest one blocked for 32 sec, osd.8 has slow ops (SLOW_OPS) 2020-12-10T21:40:16.202867+0100 mon.pve1-prg2a (mon.0) 125947 : cluster [DBG] osd.4 reported failed by osd.34 2020-12-10T21:40:16.202986+0100 mon.pve1-prg2a (mon.0) 125948 : cluster [INF] osd.4 failed (root=default,host=pve1-prg2a) (2 reporters from different host after 24.000267 >= grace 22.361677) 2020-12-10T21:40:16.373925+0100 mon.pve1-prg2a (mon.0) 125949 : cluster [DBG] osd.39 reported failed by osd.6 2020-12-10T21:40:16.865608+0100 mon.pve1-prg2a (mon.0) 125951 : cluster [DBG] osd.39 reported failed by osd.8 2020-12-10T21:40:17.125917+0100 mon.pve1-prg2a (mon.0) 125952 : cluster [WRN] Health check failed: 1 osds down (OSD_DOWN) 2020-12-10T21:40:17.139006+0100 mon.pve1-prg2a (mon.0) 125953 : cluster [DBG] osdmap e12819: 40 total, 39 up, 30 in 2020-12-10T21:40:17.140248+0100 mon.pve1-prg2a (mon.0) 125954 : cluster [DBG] osd.39 reported failed by osd.21 2020-12-10T21:40:17.344244+0100 mgr.pve2-prg2a (mgr.91575377) 118757 : cluster [DBG] pgmap v119012: 1737 pgs: 9 peering, 61 stale+active+clean, 1 active+clean+scrubbing+deep, 7 active+clean+laggy, 1659 active+clean; 3.3 TiB data, 7.8 TiB used, 14 TiB / 22 TiB avail; 44 KiB/s rd, 2.5 MiB/s wr, 107 op/s 2020-12-10T21:40:17.378069+0100 mon.pve1-prg2a (mon.0) 125955 : cluster [DBG] osd.39 reported failed by osd.26 2020-12-10T21:40:17.424429+0100 mon.pve1-prg2a (mon.0) 125956 : cluster [DBG] osd.39 reported failed by osd.18 2020-12-10T21:40:17.829447+0100 mon.pve1-prg2a (mon.0) 125957 : cluster [DBG] osd.39 reported failed by osd.36 2020-12-10T21:40:17.847373+0100 mon.pve1-prg2a (mon.0) 125958 : cluster [DBG] osd.39 reported failed by osd.1 2020-12-10T21:40:17.858371+0100 mon.pve1-prg2a (mon.0) 125959 : cluster [DBG] osd.39 reported failed by osd.17 2020-12-10T21:40:17.915755+0100 mon.pve1-prg2a (mon.0) 125960 : cluster [DBG] osd.39 reported failed by osd.28 2020-12-10T21:40:24.151192+0100 mon.pve1-prg2a (mon.0) 125986 : cluster [INF] Health check cleared: PG_AVAILABILITY (was: Reduced data availability: 1 pg peering) 2020-12-10T21:40:24.608038+0100 mon.pve1-prg2a (mon.0) 125987 : cluster [WRN] Health check update: 0 slow ops, oldest one blocked for 37 sec, osd.8 has slow ops (SLOW_OPS) 2020-12-10T21:40:25.375322+0100 mgr.pve2-prg2a (mgr.91575377) 118761 : cluster [DBG] pgmap v119017: 1737 pgs: 1 active+clean+scrubbing+deep, 6 active+undersized, 40 active+undersized+wait, 13 active+undersized+degraded, 101 active+undersized+degraded+wait, 3 stale+active+clean, 2 active+clean+laggy, 1571 active+clean; 3.3 TiB data, 7.8 TiB used, 21 TiB / 29 TiB avail; 4.0 MiB/s wr, 179 op/s; 74043/2676420 objects degraded (2.766%); 622 KiB/s, 0 objects/s recovering 2020-12-10T21:40:27.379311+0100 mgr.pve2-prg2a (mgr.91575377) 118762 : cluster [DBG] pgmap v119018: 1737 pgs: 1 active+clean+scrubbing+deep, 6 active+undersized, 40 active+undersized+wait, 13 active+undersized+degraded, 101 active+undersized+degraded+wait, 3 stale+active+clean, 2 active+clean+laggy, 1571 active+clean; 3.3 TiB data, 7.8 TiB used, 21 TiB / 29 TiB avail; 3.6 MiB/s wr, 154 op/s; 74043/2676420 objects degraded (2.766%); 510 KiB/s, 0 objects/s recovering 2020-12-10T21:40:29.391905+0100 mgr.pve2-prg2a (mgr.91575377) 118763 : cluster [DBG] pgmap v119019: 1737 pgs: 1 active+clean+scrubbing+deep, 11 active+undersized, 35 active+undersized+wait, 21 active+undersized+degraded, 93 active+undersized+degraded+wait, 3 stale+active+clean, 2 active+clean+laggy, 1571 active+clean; 3.3 TiB data, 7.8 TiB used, 21 TiB / 29 TiB avail; 3.9 MiB/s wr, 170 op/s; 74043/2676420 objects degraded (2.766%); 456 KiB/s, 0 objects/s recovering 2020-12-10T21:40:29.609801+0100 mon.pve1-prg2a (mon.0) 125991 : cluster [WRN] Health check update: Degraded data redundancy: 74043/2676420 objects degraded (2.766%), 114 pgs degraded (PG_DEGRADED) 2020-12-10T21:40:29.609845+0100 mon.pve1-prg2a (mon.0) 125992 : cluster [WRN] Health check update: 0 slow ops, oldest one blocked for 42 sec, osd.8 has slow ops (SLOW_OPS) 2020-12-10T21:40:31.395715+0100 mgr.pve2-prg2a (mgr.91575377) 118764 : cluster [DBG] pgmap v119020: 1737 pgs: 1 active+clean+scrubbing+deep, 11 active+undersized, 35 active+undersized+wait, 21 active+undersized+degraded, 93 active+undersized+degraded+wait, 3 stale+active+clean, 2 active+clean+laggy, 1571 active+clean; 3.3 TiB data, 7.8 TiB used, 21 TiB / 29 TiB avail; 154 KiB/s rd, 2.1 MiB/s wr, 151 op/s; 74043/2676420 objects degraded (2.766%); 425 KiB/s, 0 objects/s recovering 2020-12-10T21:40:32.797773+0100 osd.8 (osd.8) 19 : cluster [WRN] slow request osd_op(client.91721949.0:169935 1.3b 1:dc12cc94:::rbd_header.0373d6a5f7de48:head [watch ping cookie 139741691437056] snapc 0=[] ondisk+write+known_if_redirected e12816) initiated 2020-12-10T21:39:59.813054+0100 currently delayed 2020-12-10T21:40:33.399277+0100 mgr.pve2-prg2a (mgr.91575377) 118765 : cluster [DBG] pgmap v119021: 1737 pgs: 1 active+clean+scrubbing+deep, 13 active+undersized, 33 active+undersized+wait, 28 active+undersized+degraded, 86 active+undersized+degraded+wait, 3 stale+active+clean, 2 active+clean+laggy, 1571 active+clean; 3.3 TiB data, 7.8 TiB used, 21 TiB / 29 TiB avail; 156 KiB/s rd, 1.6 MiB/s wr, 144 op/s; 74043/2676420 objects degraded (2.766%) 2020-12-10T21:40:33.841597+0100 osd.8 (osd.8) 20 : cluster [WRN] slow request osd_op(client.91721949.0:169935 1.3b 1:dc12cc94:::rbd_header.0373d6a5f7de48:head [watch ping cookie 139741691437056] snapc 0=[] ondisk+write+known_if_redirected e12816) initiated 2020-12-10T21:39:59.813054+0100 currently delayed 2020-12-10T21:40:34.611650+0100 mon.pve1-prg2a (mon.0) 125996 : cluster [WRN] Health check update: 0 slow ops, oldest one blocked for 47 sec, daemons [osd.22,osd.8] have slow ops. (SLOW_OPS) 2020-12-10T21:40:34.612166+0100 mon.pve1-prg2a (mon.0) 125997 : cluster [INF] osd.39 failed (root=default,host=pve5-prg2a) (5 reporters from different host after 39.438374 >= grace 37.721344) 2020-12-10T21:40:34.615286+0100 mon.pve1-prg2a (mon.0) 125998 : cluster [WRN] Health check update: 2 osds down (OSD_DOWN) 2020-12-10T21:40:34.621801+0100 mon.pve1-prg2a (mon.0) 125999 : cluster [DBG] osdmap e12821: 40 total, 38 up, 30 in 2020-12-10T21:40:34.880626+0100 osd.8 (osd.8) 21 : cluster [WRN] slow request osd_op(client.91721949.0:169935 1.3b 1:dc12cc94:::rbd_header.0373d6a5f7de48:head [watch ping cookie 139741691437056] snapc 0=[] ondisk+write+known_if_redirected e12816) initiated 2020-12-10T21:39:59.813054+0100 currently delayed 8/0 sis=12819) [28,35] r=-1 lpr=12819 pi=[12507,12819)/1 crt=12818'17226265 lcod 12818'17226264 mlcod 0'0 unknown NOTIFY mbc={}] exit Start 0.000020 0 0.000000 -823> 2020-12-10T21:40:44.079+0100 7f5310751700 5 osd.4 pg_epoch: 12822 pg[1.cc( v 12818'17226265 (12812'17224439,12818'17226265] local-lis/les=12507/12508 n=1566 ec=171/171 lis/c=12507/12507 les/c/f=12508/12508/0 sis=12819) [28,35] r=-1 lpr=12819 pi=[12507,12819)/1 crt=12818'17226265 lcod 12818'17226264 mlcod 0'0 unknown NOTIFY mbc={}] enter Started/Stray -822> 2020-12-10T21:40:44.191+0100 7f5324f7a700 5 prioritycache tune_memory target: 4294967296 mapped: 3494428672 unmapped: 383787008 heap: 3878215680 old mem: 2845415832 new mem: 2845415832 -821> 2020-12-10T21:40:44.311+0100 7f532ca01700 1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7f530ef4e700' had timed out after 15 -820> 2020-12-10T21:40:44.311+0100 7f532ca01700 1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7f5312f56700' had timed out after 15 -819> 2020-12-10T21:40:44.311+0100 7f532ca01700 1 osd.4 12822 is_healthy false -- internal heartbeat failed -818> 2020-12-10T21:40:44.311+0100 7f532ca01700 1 osd.4 12822 not healthy; waiting to boot -817> 2020-12-10T21:40:44.311+0100 7f532ca01700 1 osd.4 12822 tick checking mon for new map -816> 2020-12-10T21:40:44.311+0100 7f530e74d700 5 osd.4 12822 heartbeat osd_stat(store_statfs(0x7c5f5b0000/0x2e36c0000/0xba40000000, data 0x3af1c2f453/0x3afd380000, compress 0x0/0x0/0x0, omap 0x30256c, meta 0x2e33bda94), peers [3,5,6,7,8,9,13,20,28,36] op hist [0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,22]) -815> 2020-12-10T21:40:44.403+0100 7f5323337700 10 monclient: tick -814> 2020-12-10T21:40:44.403+0100 7f5323337700 10 monclient: _check_auth_rotating have uptodate secrets (they expire after 2020-12-10T21:40:14.409098+0100) -813> 2020-12-10T21:40:44.403+0100 7f5323337700 10 log_client log_queue is 2 last_log 7 sent 5 num 2 unsent 2 sending 2 -812> 2020-12-10T21:40:44.403+0100 7f5323337700 10 log_client will send 2020-12-10T21:40:44.063147+0100 osd.4 (osd.4) 6 : cluster [WRN] Monitor daemon marked osd.4 down, but it is still running -811> 2020-12-10T21:40:44.403+0100 7f5323337700 10 log_client will send 2020-12-10T21:40:44.063157+0100 osd.4 (osd.4) 7 : cluster [DBG] map e12822 wrongly marked me down at e12819 -810> 2020-12-10T21:40:44.403+0100 7f5323337700 10 monclient: _send_mon_message to mon.pve1-prg2a at v2:10.104.200.11:3300/0 -809> 2020-12-10T21:40:45.191+0100 7f5324f7a700 5 prioritycache tune_memory target: 4294967296 mapped: 3494428672 unmapped: 383787008 heap: 3878215680 old mem: 2845415832 new mem: 2845415832 -808> 2020-12-10T21:40:45.351+0100 7f532ca01700 1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7f530ef4e700' had timed out after 15 -807> 2020-12-10T21:40:45.351+0100 7f532ca01700 1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7f5312f56700' had timed out after 15 -3> 2020-12-10T21:42:10.466+0100 7f5324f7a700 5 prioritycache tune_memory target: 4294967296 mapped: 3510689792 unmapped: 367525888 heap: 3878215680 old mem: 2845415832 new mem: 2845415832 -2> 2020-12-10T21:42:10.694+0100 7f532ca01700 1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7f530ef4e700' had timed out after 15 -1> 2020-12-10T21:42:10.694+0100 7f532ca01700 1 heartbeat_map is_healthy 'OSD::osd_op_tp thread 0x7f530ef4e700' had suicide timed out after 150

2 3