Hi all, with the help of Croit we got back on our feet. I will post a detailed post-mortem later this month including information about how to check if a cluster is in the same situation. Long story short, we hit a deadlock due to competition between MDS cache trimming and purging stale strays. "Disabling" cache trimming by setting a ridiculously high mds_memory_limit on the bad rank did the trick. Purging 100Mio strays is actually no problem and doesn't require much if any RAM by itself (I mean here the purge that happens on MDS restart, I don't know if the forward-scrub purge behaves the same). Our cluster managed to purge about 10K items/s and after a few hours everything was cleaned out. While purging it was serving client IO, so the FS is up right away. A big thank you to everyone who helped with this case. Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 ________________________________________ From: Frank Schilder <frans@xxxxxx> Sent: Sunday, January 19, 2025 5:35 PM To: ceph-users@xxxxxxx Cc: Dan van der Ster; Patrick Donnelly; Bailey Allison; Spencer Macphee Subject: Re: Help needed, ceph fs down due to large stray dir Hi all, we took a log with setting debug_journaler=20 and managed to track the deadlock down to line https://github.com/ceph/ceph/blob/pacific/src/osdc/Journaler.cc#L583 in Journaler::append_entry(bufferlist& bl): // append size_t delta = bl.length() + journal_stream.get_envelope_size(); // write_buf space is nearly full if (!write_buf_throttle.get_or_fail(delta)) { l.unlock(); ldout(cct, 10) << "write_buf_throttle wait, delta " << delta << dendl; write_buf_throttle.get(delta); //<<<<<<<<< The MDS is stuck here <<<<<<<<< l.lock(); } ldout(cct, 20) << "write_buf_throttle get, delta " << delta << dendl; This is indicated by the last message in the log before the lock up, which reads mds.2.journaler.pq(rw) write_buf_throttle wait, delta 101 and is generated by the line above the call write_buf_throttle.get(delta). All log messages messages before start with "write_buf_throttle get, delta", which means these did not go into the if-statement. Obvious question is, which parameter influences the maximum capacity of Journaler::write_buffer (https://github.com/ceph/ceph/blob/pacific/src/osdc/Journaler.h#L306) in the class definition of class Journaler? Increasing this limit should get us past the deadlock. Note that all the relevant code is identical to branch main, which means that all versions since pacific are affected. Thanks for your help and best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 ________________________________________ From: Frank Schilder <frans@xxxxxx> Sent: Saturday, January 18, 2025 2:21 PM To: Frédéric Nass; ceph-users@xxxxxxx Cc: Dan van der Ster; Patrick Donnelly; Bailey Allison; Spencer Macphee Subject: Re: Help needed, ceph fs down due to large stray dir Hi all, looking at the log data (see snippet at end) we suspect a classic "producer–consumer" deadlock since it seems that the same thread that is filling the purge queue at PurgeQueue.cc:L335:journaler.append_entry(bl) in function PurgeQueue::push is also responsible for processing it but the call to scan_stray_dir() at the end of MDCache::populate_mydir() is atomic and blocks processing until it completes. I'm looking through the code right now to find what parameter is used in constructing this queue that allows adjusting its size. I need to triple it in size at least to get scan_stray_dir() to complete and see what happens then. This would, of course, go much faster if someone familiar with the code would tell me what that parameter is. Here the log snippet when the purge queue runs full: 2025-01-16T14:06:00.490+0100 7f25cfa31700 10 mds.2.cache.ino(0x20028c29e69) purge_stale_snap_data 2025-01-16T14:06:00.490+0100 7f25cfa31700 10 mds.2.cache.ino(0x20028c29e69) purging old_inode [c7d,dae] 2025-01-16T14:06:00.490+0100 7f25cfa31700 10 mds.2.cache clear_dirty_bits_for_stray [inode 0x20028c29e69 [...daf,head] ~mds2/stray7/20028c29e69/ auth v2199183125 snaprealm=0x562c9fb6e600 f(v0 m2024-12-28T20:17:59.487395+0100) n(v0 rc2024-12-28T20:17:59.487395+0100 1=0+1) (iversion lock) 0x562c9fb70b00] 2025-01-16T14:06:00.490+0100 7f25cfa31700 20 mds.2.cache.strays enqueue: purging dn: [dentry #0x102/stray7/20028c29e69 [daf,head] auth (dversion lock) pv=0 v=2199200546 ino=0x20028c29e69 state=1073741844 0x562c9fb6db80] 2025-01-16T14:06:00.490+0100 7f25cfa31700 10 mds.2.cache.dir(0x61b.000100011011*) auth_pin by 0x55e0f256ff80 on [dir 0x61b.000100011011* ~mds2/stray7/ [2,head] auth v=2199200547 cv=2199200546/2199200546 ap=1928+0 state=1610620929|complete|sticky f(v23 m2025-01-10T13:30:41.594215+0100 2568=0+2568)/f(v23 m2025-01-10T13:30:41.594215+0100 2569=1+2568) n(v2110 rc2025-01-10T13:30:41.594215+0100 2568=0+2568)/n(v2110 rc2025-01-10T13:30:41.594215+0100 b7068 2569=1+2568) hs=2568+0,ss=0+0 | child=1 sticky=1 dirty=1 waiter=0 authpin=1 0x562c98bf0880] count now 1928 2025-01-16T14:06:00.490+0100 7f25cfa31700 10 mds.2.cache.strays purge [dentry #0x102/stray7/20028c29e69 [daf,head] auth (dversion lock) pv=0 v=2199200546 ino=0x20028c29e69 state=1073741876 | purging=1 0x562c9fb6db80] [inode 0x20028c29e69 [...daf,head] ~mds2/stray7/20028c29e69/ auth v2199183125 snaprealm=0x562c9fb6e600 f(v0 m2024-12-28T20:17:59.487395+0100) n(v0 rc2024-12-28T20:17:59.487395+0100 1=0+1) (iversion lock) 0x562c9fb70b00] 2025-01-16T14:06:00.490+0100 7f25cfa31700 4 mds.2.purge_queue push: pushing inode 0x20028c29e69 2025-01-16T14:06:00.537+0100 7f25d7240700 20 -- [v2:192.168.32.85:6800/845135215,v1:192.168.32.85:6801/845135215] >> v1:192.168.48.132:0/2119497078 conn(0x55e0f3d3e400 legacy=0x55e0f3d34000 unknown :6801 s=STATE_CONNECTION_ESTABLISHED l=0).process 2025-01-16T14:06:00.537+0100 7f25d7240700 20 -- [v2:192.168.32.85:6800/845135215,v1:192.168.32.85:6801/845135215] >> v1:192.168.48.132:0/2119497078 conn(0x55e0f3d3e400 legacy=0x55e0f3d34000 unknown :6801 s=STATE_CONNECTION_ESTABLISHED l=0).read continue len=1 2025-01-16T14:06:00.537+0100 7f25d7240700 20 --1- [v2:192.168.32.85:6800/845135215,v1:192.168.32.85:6801/845135215] >> v1:192.168.48.132:0/2119497078 conn(0x55e0f3d3e400 0x55e0f3d34000 :6801 s=OPENED pgs=828965 cs=1 l=0).handle_message r=0 2025-01-16T14:06:00.537+0100 7f25d7240700 20 --1- [v2:192.168.32.85:6800/845135215,v1:192.168.32.85:6801/845135215] >> v1:192.168.48.132:0/2119497078 conn(0x55e0f3d3e400 0x55e0f3d34000 :6801 s=OPENED pgs=828965 cs=1 l=0).handle_message process tag 14 Best regards and have a good weekend. ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 _______________________________________________ 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 _______________________________________________ ceph-users mailing list -- ceph-users@xxxxxxx To unsubscribe send an email to ceph-users-leave@xxxxxxx
 |