Ceph » RADOS

Igor Fedotov wrote:

I believe this isn't ceph-deploy issue...

Probably not indeed, my bad

Just to mention - telemetry reports show multiple crashes inside HeartbeatMap::_check for different clusters.
Hence this might worth a priority raise.

Igor Fedotov wrote:

Just to mention - telemetry reports show multiple crashes inside HeartbeatMap::_check for different clusters.
Hence this might worth a priority raise.

Alright, thanks for mentioning it. I'm raising the issue.

little update, I've tried with v15.2.8. Sadly same behaviour.

Hi Sage,

Hum I've finally managed to recover my cluster after an uncounted osd restart procedures until they started up successfully somehow.
The issue occured after a pool's PG number modification leading osd to crash and letting some of them unable to restart properly.
I'm currently unable to reproduce the issue but I'll for sure keep you up to date along the way if it occurs again.
Thanks a lot !

Hi I'm having the same problem.

-7> 2021-12-25T12:05:37.491+0100 7fd15c920640  1 heartbeat_map reset_timeout 'OSD::osd_op_tp thread 0x7fd15c920640' had suicide timed out after 1500.000000000s
    -6> 2021-12-25T12:05:37.683+0100 7fd167936640 10 monclient: tick
    -5> 2021-12-25T12:05:37.683+0100 7fd167936640 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2021-12-25T12:05:07.685922+0100)
    -4> 2021-12-25T12:05:37.719+0100 7fd167936640 10 monclient: _send_mon_message to mon.blue-compute at v2:172.16.0.119:3300/0
    -3> 2021-12-25T12:05:38.719+0100 7fd167936640 10 monclient: tick
    -2> 2021-12-25T12:05:38.719+0100 7fd167936640 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2021-12-25T12:05:08.720135+0100)
    -1> 2021-12-25T12:05:38.719+0100 7fd167936640 10 monclient: _send_mon_message to mon.blue-compute at v2:172.16.0.119:3300/0
     0> 2021-12-25T12:05:39.295+0100 7fd15c920640 -1 ** Caught signal (Aborted) *
 in thread 7fd15c920640 thread_name:tp_osd_tp

ceph version 16.2.6 (ee28fb57e47e9f88813e24bbf4c14496ca299d31) pacific (stable)
 1: /lib/x86_64-linux-gnu/libc.so.6(+0x46520) [0x7fd1c4b56520]
 2: pthread_kill()
 3: (ceph::HeartbeatMap::_check(ceph::heartbeat_handle_d const*, char const*, std::chrono::time_point<ceph::coarse_mono_clock, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> > >)+0x485) [0x559eb61883b5]
 4: (ceph::HeartbeatMap::reset_timeout(ceph::heartbeat_handle_d*, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> >, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> >)+0x74) [0x559eb6188c04]
 5: (OSD::advance_pg(unsigned int, PG*, ThreadPool::TPHandle&, PeeringCtx&)+0x706) [0x559eb5b32586]
 6: (OSD::dequeue_peering_evt(OSDShard*, PG*, std::shared_ptr<PGPeeringEvent>, ThreadPool::TPHandle&)+0xca) [0x559eb5b3447a]
 7: (ceph::osd::scheduler::PGPeeringItem::run(OSD*, OSDShard*, boost::intrusive_ptr<PG>&, ThreadPool::TPHandle&)+0x5b) [0x559eb5d7bb9b]
 8: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0x9c3) [0x559eb5b25f73]
 9: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x434) [0x559eb61aa284]
 10: (ShardedThreadPool::WorkThreadSharded::entry()+0x14) [0x559eb61ac5b4]
 11: /lib/x86_64-linux-gnu/libc.so.6(+0x98927) [0x7fd1c4ba8927]
 12: clone()
 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/ 1 osd
0/ 5 optracker
0/ 5 objclass
10/10 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
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 ---
140537102464576 / tp_osd_tp
140537169573440 / tp_osd_tp
140537177966144 / tp_osd_tp
140537186358848 / tp_osd_tp
140537194751552 / tp_osd_tp
140537362605632 / safe_timer
140537379391040 / ms_dispatch
140538376353344 / tp_fstore_op
140538458064448 / fn_jrn_objstore
140538483242560 / filestore_sync
140538741188160 / msgr-worker-2
140538779006528 / io_context_pool
140538858620480 / io_context_pool
140538875405888 / admin_socket
140538883798592 / msgr-worker-1
140538892191296 / msgr-worker-0
140538922681024 / ceph-osd
max_recent 10000
max_new 10000
log_file /var/log/ceph/ceph-osd.9.log
--- end dump of recent events ---

But this is:

ceph version 16.2.6 (ee28fb57e47e9f88813e24bbf4c14496ca299d31) pacific (stable)

Clément Hampaï wrote:

Hi Sage,

Hum I've finally managed to recover my cluster after an uncounted osd restart procedures until they started up successfully somehow.
The issue occured after a pool's PG number modification leading osd to crash and letting some of them unable to restart properly.
I'm currently unable to reproduce the issue but I'll for sure keep you up to date along the way if it occurs again.
Thanks a lot !

Can you explain how did you resolved it?

Hey Gonzalo,

It was some times ago but from my memories I've created a hudge swapfile ~50G and I restarted the osd's multiple times one after the other when they finally crashed.
After some restarts one failed osd was able to boot properly again. Then a second one and a third one. At this point my unknown PGs where online again.
I hope it might help you to fix your cluster too. Keep me up to date if you want to.

KR,

Clément

Gonzalo Aguilar Delgado wrote:

Clément Hampaï wrote:

Hi Sage,

Hum I've finally managed to recover my cluster after an uncounted osd restart procedures until they started up successfully somehow.
The issue occured after a pool's PG number modification leading osd to crash and letting some of them unable to restart properly.
I'm currently unable to reproduce the issue but I'll for sure keep you up to date along the way if it occurs again.
Thanks a lot !

Can you explain how did you resolved it?

Gonzalo Aguilar Delgado wrote:

Hi I'm having the same problem.

-7> 2021-12-25T12:05:37.491+0100 7fd15c920640 1 heartbeat_map reset_timeout 'OSD::osd_op_tp thread 0x7fd15c920640' had suicide timed out after 1500.000000000s
-6> 2021-12-25T12:05:37.683+0100 7fd167936640 10 monclient: tick
-5> 2021-12-25T12:05:37.683+0100 7fd167936640 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2021-12-25T12:05:07.685922+0100)
-4> 2021-12-25T12:05:37.719+0100 7fd167936640 10 monclient: _send_mon_message to mon.blue-compute at v2:172.16.0.119:3300/0
-3> 2021-12-25T12:05:38.719+0100 7fd167936640 10 monclient: tick
-2> 2021-12-25T12:05:38.719+0100 7fd167936640 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2021-12-25T12:05:08.720135+0100)
-1> 2021-12-25T12:05:38.719+0100 7fd167936640 10 monclient: _send_mon_message to mon.blue-compute at v2:172.16.0.119:3300/0
0> 2021-12-25T12:05:39.295+0100 7fd15c920640 -1 ** Caught signal (Aborted) *
in thread 7fd15c920640 thread_name:tp_osd_tp

ceph version 16.2.6 (ee28fb57e47e9f88813e24bbf4c14496ca299d31) pacific (stable)
1: /lib/x86_64-linux-gnu/libc.so.6(+0x46520) [0x7fd1c4b56520]
2: pthread_kill()
3: (ceph::HeartbeatMap::_check(ceph::heartbeat_handle_d const*, char const*, std::chrono::time_point<ceph::coarse_mono_clock, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> > >)+0x485) [0x559eb61883b5]
4: (ceph::HeartbeatMap::reset_timeout(ceph::heartbeat_handle_d*, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> >, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> >)+0x74) [0x559eb6188c04]
5: (OSD::advance_pg(unsigned int, PG*, ThreadPool::TPHandle&, PeeringCtx&)+0x706) [0x559eb5b32586]
6: (OSD::dequeue_peering_evt(OSDShard*, PG*, std::shared_ptr<PGPeeringEvent>, ThreadPool::TPHandle&)+0xca) [0x559eb5b3447a]
7: (ceph::osd::scheduler::PGPeeringItem::run(OSD*, OSDShard*, boost::intrusive_ptr<PG>&, ThreadPool::TPHandle&)+0x5b) [0x559eb5d7bb9b]
8: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0x9c3) [0x559eb5b25f73]
9: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x434) [0x559eb61aa284]
10: (ShardedThreadPool::WorkThreadSharded::entry()+0x14) [0x559eb61ac5b4]
11: /lib/x86_64-linux-gnu/libc.so.6(+0x98927) [0x7fd1c4ba8927]
12: clone()
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/ 1 osd
0/ 5 optracker
0/ 5 objclass
10/10 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
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 ---
140537102464576 / tp_osd_tp
140537169573440 / tp_osd_tp
140537177966144 / tp_osd_tp
140537186358848 / tp_osd_tp
140537194751552 / tp_osd_tp
140537362605632 / safe_timer
140537379391040 / ms_dispatch
140538376353344 / tp_fstore_op
140538458064448 / fn_jrn_objstore
140538483242560 / filestore_sync
140538741188160 / msgr-worker-2
140538779006528 / io_context_pool
140538858620480 / io_context_pool
140538875405888 / admin_socket
140538883798592 / msgr-worker-1
140538892191296 / msgr-worker-0
140538922681024 / ceph-osd
max_recent 10000
max_new 10000
log_file /var/log/ceph/ceph-osd.9.log
--- end dump of recent events ---

But this is:

ceph version 16.2.6 (ee28fb57e47e9f88813e24bbf4c14496ca299d31) pacific (stable)

Can you provide the info sage asked in https://tracker.ceph.com/issues/48468#note-9 and also the output of "ceph daemon osd.X dump_mempools" for the problematic osd?

@Neha ., @Gonsalo - to avoid the mess let's use https://tracker.ceph.com/issues/53729 for further communication on the issue.

Igor Fedotov wrote:

@Neha ., @Gonsalo - to avoid the mess let's use https://tracker.ceph.com/issues/53729 for further communication on the issue.

sounds good