MDS "newly corrupt dentry" after patch version upgrade
Hi, After a patch version upgrade from 16.2.10 to 16.2.12, our rank 0 MDS fails start start. After replaying the journal, it just crashes with [ERR] : MDS abort because newly corrupt dentry to be committed: [dentry #0x1/storage [2,head] auth (dversion lock) Immediately after the upgrade, I had it running shortly, but then it decided to crash for unknown reasons and I cannot get it back up. We have five ranks in total, the other four seem to be fine. I backed up the journal and tried to run cephfs-journal-tool --rank=cephfs.storage:0 event recover_dentries summary, but it never finishes only eats up a lot of RAM. I stopped it after an hour and 50GB RAM. Resetting the journal makes the MDS crash with a missing inode error on another top-level directory, so I re-imported the backed-up journal. Is there any way to recover from this without rebuilding the whole file system? Thanks Janek Here's the full crash log: May 02 16:16:53 xxx077 ceph-mds[3047358]: -29> 2023-05-02T16:16:52.761+0200 7f51f878b700 1 mds.0.1711712 Finished replaying journal May 02 16:16:53 xxx077 ceph-mds[3047358]: -28> 2023-05-02T16:16:52.761+0200 7f51f878b700 1 mds.0.1711712 making mds journal writeable May 02 16:16:53 xxx077 ceph-mds[3047358]: -27> 2023-05-02T16:16:52.761+0200 7f51f878b700 1 mds.0.journaler.mdlog(ro) set_writeable May 02 16:16:53 xxx077 ceph-mds[3047358]: -26> 2023-05-02T16:16:52.761+0200 7f51f878b700 2 mds.0.1711712 i am not alone, moving to state resolve May 02 16:16:53 xxx077 ceph-mds[3047358]: -25> 2023-05-02T16:16:52.761+0200 7f51f878b700 3 mds.0.1711712 request_state up:resolve May 02 16:16:53 xxx077 ceph-mds[3047358]: -24> 2023-05-02T16:16:52.761+0200 7f51f878b700 5 mds.beacon.xxx077 set_want_state: up:replay -> up:resolve May 02 16:16:53 xxx077 ceph-mds[3047358]: -23> 2023-05-02T16:16:52.761+0200 7f51f878b700 5 mds.beacon.xxx077 Sending beacon up:resolve seq 15 May 02 16:16:53 xxx077 ceph-mds[3047358]: -22> 2023-05-02T16:16:52.761+0200 7f51f878b700 10 monclient: _send_mon_message to mon.xxx056 at v2:141.54.133.56:3300/0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -21> 2023-05-02T16:16:53.113+0200 7f51fef98700 10 monclient: tick May 02 16:16:53 xxx077 ceph-mds[3047358]: -20> 2023-05-02T16:16:53.113+0200 7f51fef98700 10 monclient: _check_auth_rotating have uptodate secrets (they expire after 2023-05-02T16:16:23.118186+0200) May 02 16:16:53 xxx077 ceph-mds[3047358]: -19> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.xxx077 Updating MDS map to version 1711713 from mon.1 May 02 16:16:53 xxx077 ceph-mds[3047358]: -18> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 handle_mds_map i am now mds.0.1711712 May 02 16:16:53 xxx077 ceph-mds[3047358]: -17> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 handle_mds_map state change up:replay --> up:resolve May 02 16:16:53 xxx077 ceph-mds[3047358]: -16> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 resolve_start May 02 16:16:53 xxx077 ceph-mds[3047358]: -15> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 reopen_log May 02 16:16:53 xxx077 ceph-mds[3047358]: -14> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 recovery set is 1,2,3,4 May 02 16:16:53 xxx077 ceph-mds[3047358]: -13> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 recovery set is 1,2,3,4 May 02 16:16:53 xxx077 ceph-mds[3047358]: -12> 2023-05-02T16:16:53.373+0200 7f5202fa0700 10 monclient: get_auth_request con 0x5574fe74c400 auth_method 0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -11> 2023-05-02T16:16:53.373+0200 7f52037a1700 10 monclient: get_auth_request con 0x5574fe40fc00 auth_method 0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -10> 2023-05-02T16:16:53.373+0200 7f520279f700 10 monclient: get_auth_request con 0x5574f932fc00 auth_method 0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -9> 2023-05-02T16:16:53.373+0200 7f520279f700 10 monclient: get_auth_request con 0x5574ffce2000 auth_method 0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -8> 2023-05-02T16:16:53.377+0200 7f5202fa0700 5 mds.beacon.xxx077 received beacon reply up:resolve seq 15 rtt 0.616008 May 02 16:16:53 xxx077 ceph-mds[3047358]: -7> 2023-05-02T16:16:53.393+0200 7f51fff9a700 5 mds.xxx077 handle_mds_map old map epoch 1711713 <= 1711713, discarding May 02 16:16:53 xxx077 ceph-mds[3047358]: -6> 2023-05-02T16:16:53.393+0200 7f51fff9a700 5 mds.xxx077 handle_mds_map old map epoch 1711713 <= 1711713, discarding May 02 16:16:53 xxx077 ceph-mds[3047358]: -5> 2023-05-02T16:16:53.393+0200 7f51fff9a700 5 mds.xxx077 handle_mds_map old map epoch 1711713 <= 1711713, discarding May 02 16:16:53 xxx077 ceph-mds[3047358]: -4> 2023-05-02T16:16:53.393+0200 7f51fff9a700 5 mds.xxx077 handle_mds_map old map epoch 1711713 <= 1711713, discarding May 02 16:16:53 xxx077 ceph-mds[3047358]: -3> 2023-05-02T16:16:53.545+0200 7f51fff9a700 -1 mds.0.cache.den(0x1 storage) newly corrupt dentry to be committed: [dentry #0x1/storage [2,head] auth (dversion lock) v=78956500 ino=0x10000000000 state=1610612736 | inodepin=1 dirty=1 0x5574f932db80] May 02 16:16:53 xxx077 ceph-mds[3047358]: -2> 2023-05-02T16:16:53.545+0200 7f51fff9a700 -1 log_channel(cluster) log [ERR] : MDS abort because newly corrupt dentry to be committed: [dentry #0x1/storage [2,head] auth (dversion lock) v=78956500 ino=0x10000000000 state=1610612736 | inodepin=1 dirty=1 0x5574f932db80] May 02 16:16:53 xxx077 ceph-mds[3047358]: -1> 2023-05-02T16:16:53.549+0200 7f51fff9a700 -1 /build/ceph-16.2.12/src/mds/CDentry.cc: In function 'bool CDentry::check_corruption(bool)' thread 7f51fff9a700 time 2023-05-02T16:16:53.549536+0200 /build/ceph-16.2.12/src/mds/CDentry.cc: 697: ceph_abort_msg("abort() called") ceph version 16.2.12 (5a2d516ce4b134bfafc80c4274532ac0d56fc1e2) pacific (stable) 1: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0xe0) [0x7f52054c3495] 2: (CDentry::check_corruption(bool)+0x86b) [0x5574f7e3a91b] 3: (EMetaBlob::add_dir_context(CDir*, int)+0x507) [0x5574f7f9f9d7] 4: (MDCache::create_subtree_map()+0x13e1) [0x5574f7d20dc1] 5: (MDLog::_journal_segment_subtree_map(MDSContext*)+0x4d) [0x5574f7f2949d] 6: (MDLog::_submit_entry(LogEvent*, MDSLogContextBase*)+0x206) [0x5574f7f29866] 7: (MDCache::log_leader_commit(metareqid_t)+0x277) [0x5574f7ccc3c7] 8: (MDCache::finish_committed_leaders()+0x87) [0x5574f7ccd0d7] 9: (MDCache::maybe_resolve_finish()+0x78) [0x5574f7d38358] 10: (MDCache::handle_resolve(boost::intrusive_ptr<MMDSResolve const> const&)+0x1e02) [0x5574f7d454c2] 11: (MDCache::dispatch(boost::intrusive_ptr<Message const> const&)+0x144) [0x5574f7d47bd4] 12: (MDSRank::handle_message(boost::intrusive_ptr<Message const> const&)+0x733) [0x5574f7bac793] 13: (MDSRank::_dispatch(boost::intrusive_ptr<Message const> const&, bool)+0x643) [0x5574f7bcacb3] 14: (MDSRankDispatcher::ms_dispatch(boost::intrusive_ptr<Message const> const&)+0x5c) [0x5574f7bcb34c] 15: (MDSDaemon::ms_dispatch2(boost::intrusive_ptr<Message> const&)+0x1d6) [0x5574f7b9f226] 16: (Messenger::ms_deliver_dispatch(boost::intrusive_ptr<Message> const&)+0x460) [0x7f5205714020] 17: (DispatchQueue::entry()+0x58f) [0x7f52057118bf] 18: (DispatchQueue::DispatchThread::entry()+0x11) [0x7f52057df261] 19: /lib/x86_64-linux-gnu/libpthread.so.0(+0x8609) [0x7f5205205609] 20: clone() May 02 16:16:53 xxx077 ceph-mds[3047358]: 0> 2023-05-02T16:16:53.553+0200 7f51fff9a700 -1 *** Caught signal (Aborted) ** in thread 7f51fff9a700 thread_name:ms_dispatch ceph version 16.2.12 (5a2d516ce4b134bfafc80c4274532ac0d56fc1e2) pacific (stable) 1: /lib/x86_64-linux-gnu/libpthread.so.0(+0x14420) [0x7f5205211420] 2: gsignal() 3: abort() 4: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0x1af) [0x7f52054c3564] 5: (CDentry::check_corruption(bool)+0x86b) [0x5574f7e3a91b] 6: (EMetaBlob::add_dir_context(CDir*, int)+0x507) [0x5574f7f9f9d7] 7: (MDCache::create_subtree_map()+0x13e1) [0x5574f7d20dc1] 8: (MDLog::_journal_segment_subtree_map(MDSContext*)+0x4d) [0x5574f7f2949d] 9: (MDLog::_submit_entry(LogEvent*, MDSLogContextBase*)+0x206) [0x5574f7f29866] 10: (MDCache::log_leader_commit(metareqid_t)+0x277) [0x5574f7ccc3c7] 11: (MDCache::finish_committed_leaders()+0x87) [0x5574f7ccd0d7] 12: (MDCache::maybe_resolve_finish()+0x78) [0x5574f7d38358] 13: (MDCache::handle_resolve(boost::intrusive_ptr<MMDSResolve const> const&)+0x1e02) [0x5574f7d454c2] 14: (MDCache::dispatch(boost::intrusive_ptr<Message const> const&)+0x144) [0x5574f7d47bd4] 15: (MDSRank::handle_message(boost::intrusive_ptr<Message const> const&)+0x733) [0x5574f7bac793] 16: (MDSRank::_dispatch(boost::intrusive_ptr<Message const> const&, bool)+0x643) [0x5574f7bcacb3] 17: (MDSRankDispatcher::ms_dispatch(boost::intrusive_ptr<Message const> const&)+0x5c) [0x5574f7bcb34c] 18: (MDSDaemon::ms_dispatch2(boost::intrusive_ptr<Message> const&)+0x1d6) [0x5574f7b9f226] 19: (Messenger::ms_deliver_dispatch(boost::intrusive_ptr<Message> const&)+0x460) [0x7f5205714020] 20: (DispatchQueue::entry()+0x58f) [0x7f52057118bf] 21: (DispatchQueue::DispatchThread::entry()+0x11) [0x7f52057df261] 22: /lib/x86_64-linux-gnu/libpthread.so.0(+0x8609) [0x7f5205205609] 23: clone() NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. May 02 16:16:53 xxx077 ceph-mds[3047358]: --- logging levels --- May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 none May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 lockdep May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 context May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 1 crush May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_balancer May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_locker May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_log May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_log_expire May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_migrator May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 buffer May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 timer May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 filer May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 striper May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 objecter May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rados May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rbd May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rbd_mirror May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rbd_replay May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rbd_pwl May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 journaler May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 objectcacher May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 immutable_obj_cache May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 client May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 osd May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 optracker May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 objclass May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 3 filestore May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 3 journal May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 0 ms May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mon May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/10 monc May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 paxos May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 tp May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 auth May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 crypto May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 1 finisher May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 1 reserver May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 heartbeatmap May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 perfcounter May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 rgw May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 rgw_sync May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/10 civetweb May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 javaclient May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 asok May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 1 throttle May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 0 refs May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 compressor May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 bluestore May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 bluefs May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 3 bdev May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 kstore May 02 16:16:53 xxx077 ceph-mds[3047358]: 4/ 5 rocksdb May 02 16:16:53 xxx077 ceph-mds[3047358]: 4/ 5 leveldb May 02 16:16:53 xxx077 ceph-mds[3047358]: 4/ 5 memdb May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 fuse May 02 16:16:53 xxx077 ceph-mds[3047358]: 2/ 5 mgr May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mgrc May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 dpdk May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 eventtrace May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 prioritycache May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 test May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 cephfs_mirror May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 cephsqlite May 02 16:16:53 xxx077 ceph-mds[3047358]: 99/99 (syslog threshold) May 02 16:16:53 xxx077 ceph-mds[3047358]: -2/-2 (stderr threshold) May 02 16:16:53 xxx077 ceph-mds[3047358]: --- pthread ID / name mapping for recent threads --- May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990037739264 / May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990054524672 / May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990062917376 / MR_Finisher May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990079702784 / PQ_Finisher May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990096488192 / ms_dispatch May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990130059008 / ceph-mds May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990146844416 / safe_timer May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990163629824 / ms_dispatch May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990180415232 / io_context_pool May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990197200640 / admin_socket May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990205593344 / msgr-worker-2 May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990213986048 / msgr-worker-1 May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990222378752 / msgr-worker-0 May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990239524736 / ceph-mds May 02 16:16:53 xxx077 ceph-mds[3047358]: max_recent 10000 May 02 16:16:53 xxx077 ceph-mds[3047358]: max_new 10000 May 02 16:16:53 xxx077 ceph-mds[3047358]: log_file /var/lib/ceph/crash/2023-05-02T14:16:53.555508Z_0b05f5cb-130c-4979-95ca-1ba7f31cf7e5/log May 02 16:16:53 xxx077 ceph-mds[3047358]: --- end dump of recent events --- -- Bauhaus-Universität Weimar Bauhausstr. 9a, R308 99423 Weimar, Germany Phone: +49 3643 58 3577 www.webis.de
Hi Janek, That assert is part of a new corruption check added in 16.2.12 -- see https://github.com/ceph/ceph/commit/1771aae8e79b577acde749a292d9965264f20202 The abort is controlled by a new option: + Option("mds_abort_on_newly_corrupt_dentry", Option::TYPE_BOOL, Option::LEVEL_ADVANCED) + .set_default(true) + .set_description("MDS will abort if dentry is detected newly corrupted."), So in theory you could switch that off, but it is concerning that the metadata is corrupted already. I'm cc'ing Patrick who has been working on this issue. Cheers, Dan ______________________________ Clyso GmbH | https://www.clyso.com On Tue, May 2, 2023 at 7:32 AM Janek Bevendorff <janek.bevendorff@uni-weimar.de> wrote:
Hi,
After a patch version upgrade from 16.2.10 to 16.2.12, our rank 0 MDS fails start start. After replaying the journal, it just crashes with
[ERR] : MDS abort because newly corrupt dentry to be committed: [dentry #0x1/storage [2,head] auth (dversion lock)
Immediately after the upgrade, I had it running shortly, but then it decided to crash for unknown reasons and I cannot get it back up.
We have five ranks in total, the other four seem to be fine. I backed up the journal and tried to run cephfs-journal-tool --rank=cephfs.storage:0 event recover_dentries summary, but it never finishes only eats up a lot of RAM. I stopped it after an hour and 50GB RAM.
Resetting the journal makes the MDS crash with a missing inode error on another top-level directory, so I re-imported the backed-up journal. Is there any way to recover from this without rebuilding the whole file system?
Thanks Janek
Here's the full crash log:
May 02 16:16:53 xxx077 ceph-mds[3047358]: -29> 2023-05-02T16:16:52.761+0200 7f51f878b700 1 mds.0.1711712 Finished replaying journal May 02 16:16:53 xxx077 ceph-mds[3047358]: -28> 2023-05-02T16:16:52.761+0200 7f51f878b700 1 mds.0.1711712 making mds journal writeable May 02 16:16:53 xxx077 ceph-mds[3047358]: -27> 2023-05-02T16:16:52.761+0200 7f51f878b700 1 mds.0.journaler.mdlog(ro) set_writeable May 02 16:16:53 xxx077 ceph-mds[3047358]: -26> 2023-05-02T16:16:52.761+0200 7f51f878b700 2 mds.0.1711712 i am not alone, moving to state resolve May 02 16:16:53 xxx077 ceph-mds[3047358]: -25> 2023-05-02T16:16:52.761+0200 7f51f878b700 3 mds.0.1711712 request_state up:resolve May 02 16:16:53 xxx077 ceph-mds[3047358]: -24> 2023-05-02T16:16:52.761+0200 7f51f878b700 5 mds.beacon.xxx077 set_want_state: up:replay -> up:resolve May 02 16:16:53 xxx077 ceph-mds[3047358]: -23> 2023-05-02T16:16:52.761+0200 7f51f878b700 5 mds.beacon.xxx077 Sending beacon up:resolve seq 15 May 02 16:16:53 xxx077 ceph-mds[3047358]: -22> 2023-05-02T16:16:52.761+0200 7f51f878b700 10 monclient: _send_mon_message to mon.xxx056 at v2:141.54.133.56:3300/0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -21> 2023-05-02T16:16:53.113+0200 7f51fef98700 10 monclient: tick May 02 16:16:53 xxx077 ceph-mds[3047358]: -20> 2023-05-02T16:16:53.113+0200 7f51fef98700 10 monclient: _check_auth_rotating have uptodate secrets (they expire after 2023-05-02T16:16:23.118186+0200) May 02 16:16:53 xxx077 ceph-mds[3047358]: -19> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.xxx077 Updating MDS map to version 1711713 from mon.1 May 02 16:16:53 xxx077 ceph-mds[3047358]: -18> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 handle_mds_map i am now mds.0.1711712 May 02 16:16:53 xxx077 ceph-mds[3047358]: -17> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 handle_mds_map state change up:replay --> up:resolve May 02 16:16:53 xxx077 ceph-mds[3047358]: -16> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 resolve_start May 02 16:16:53 xxx077 ceph-mds[3047358]: -15> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 reopen_log May 02 16:16:53 xxx077 ceph-mds[3047358]: -14> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 recovery set is 1,2,3,4 May 02 16:16:53 xxx077 ceph-mds[3047358]: -13> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 recovery set is 1,2,3,4 May 02 16:16:53 xxx077 ceph-mds[3047358]: -12> 2023-05-02T16:16:53.373+0200 7f5202fa0700 10 monclient: get_auth_request con 0x5574fe74c400 auth_method 0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -11> 2023-05-02T16:16:53.373+0200 7f52037a1700 10 monclient: get_auth_request con 0x5574fe40fc00 auth_method 0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -10> 2023-05-02T16:16:53.373+0200 7f520279f700 10 monclient: get_auth_request con 0x5574f932fc00 auth_method 0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -9> 2023-05-02T16:16:53.373+0200 7f520279f700 10 monclient: get_auth_request con 0x5574ffce2000 auth_method 0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -8> 2023-05-02T16:16:53.377+0200 7f5202fa0700 5 mds.beacon.xxx077 received beacon reply up:resolve seq 15 rtt 0.616008 May 02 16:16:53 xxx077 ceph-mds[3047358]: -7> 2023-05-02T16:16:53.393+0200 7f51fff9a700 5 mds.xxx077 handle_mds_map old map epoch 1711713 <= 1711713, discarding May 02 16:16:53 xxx077 ceph-mds[3047358]: -6> 2023-05-02T16:16:53.393+0200 7f51fff9a700 5 mds.xxx077 handle_mds_map old map epoch 1711713 <= 1711713, discarding May 02 16:16:53 xxx077 ceph-mds[3047358]: -5> 2023-05-02T16:16:53.393+0200 7f51fff9a700 5 mds.xxx077 handle_mds_map old map epoch 1711713 <= 1711713, discarding May 02 16:16:53 xxx077 ceph-mds[3047358]: -4> 2023-05-02T16:16:53.393+0200 7f51fff9a700 5 mds.xxx077 handle_mds_map old map epoch 1711713 <= 1711713, discarding May 02 16:16:53 xxx077 ceph-mds[3047358]: -3> 2023-05-02T16:16:53.545+0200 7f51fff9a700 -1 mds.0.cache.den(0x1 storage) newly corrupt dentry to be committed: [dentry #0x1/storage [2,head] auth (dversion lock) v=78956500 ino=0x10000000000 state=1610612736 | inodepin=1 dirty=1 0x5574f932db80] May 02 16:16:53 xxx077 ceph-mds[3047358]: -2> 2023-05-02T16:16:53.545+0200 7f51fff9a700 -1 log_channel(cluster) log [ERR] : MDS abort because newly corrupt dentry to be committed: [dentry #0x1/storage [2,head] auth (dversion lock) v=78956500 ino=0x10000000000 state=1610612736 | inodepin=1 dirty=1 0x5574f932db80] May 02 16:16:53 xxx077 ceph-mds[3047358]: -1> 2023-05-02T16:16:53.549+0200 7f51fff9a700 -1 /build/ceph-16.2.12/src/mds/CDentry.cc: In function 'bool CDentry::check_corruption(bool)' thread 7f51fff9a700 time 2023-05-02T16:16:53.549536+0200 /build/ceph-16.2.12/src/mds/CDentry.cc: 697: ceph_abort_msg("abort() called")
ceph version 16.2.12 (5a2d516ce4b134bfafc80c4274532ac0d56fc1e2) pacific (stable) 1: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0xe0) [0x7f52054c3495] 2: (CDentry::check_corruption(bool)+0x86b) [0x5574f7e3a91b] 3: (EMetaBlob::add_dir_context(CDir*, int)+0x507) [0x5574f7f9f9d7] 4: (MDCache::create_subtree_map()+0x13e1) [0x5574f7d20dc1] 5: (MDLog::_journal_segment_subtree_map(MDSContext*)+0x4d) [0x5574f7f2949d] 6: (MDLog::_submit_entry(LogEvent*, MDSLogContextBase*)+0x206) [0x5574f7f29866] 7: (MDCache::log_leader_commit(metareqid_t)+0x277) [0x5574f7ccc3c7] 8: (MDCache::finish_committed_leaders()+0x87) [0x5574f7ccd0d7] 9: (MDCache::maybe_resolve_finish()+0x78) [0x5574f7d38358] 10: (MDCache::handle_resolve(boost::intrusive_ptr<MMDSResolve const> const&)+0x1e02) [0x5574f7d454c2] 11: (MDCache::dispatch(boost::intrusive_ptr<Message const> const&)+0x144) [0x5574f7d47bd4] 12: (MDSRank::handle_message(boost::intrusive_ptr<Message const> const&)+0x733) [0x5574f7bac793] 13: (MDSRank::_dispatch(boost::intrusive_ptr<Message const> const&, bool)+0x643) [0x5574f7bcacb3] 14: (MDSRankDispatcher::ms_dispatch(boost::intrusive_ptr<Message const> const&)+0x5c) [0x5574f7bcb34c] 15: (MDSDaemon::ms_dispatch2(boost::intrusive_ptr<Message> const&)+0x1d6) [0x5574f7b9f226] 16: (Messenger::ms_deliver_dispatch(boost::intrusive_ptr<Message> const&)+0x460) [0x7f5205714020] 17: (DispatchQueue::entry()+0x58f) [0x7f52057118bf] 18: (DispatchQueue::DispatchThread::entry()+0x11) [0x7f52057df261] 19: /lib/x86_64-linux-gnu/libpthread.so.0(+0x8609) [0x7f5205205609] 20: clone() May 02 16:16:53 xxx077 ceph-mds[3047358]: 0> 2023-05-02T16:16:53.553+0200 7f51fff9a700 -1 *** Caught signal (Aborted) ** in thread 7f51fff9a700 thread_name:ms_dispatch
ceph version 16.2.12 (5a2d516ce4b134bfafc80c4274532ac0d56fc1e2) pacific (stable) 1: /lib/x86_64-linux-gnu/libpthread.so.0(+0x14420) [0x7f5205211420] 2: gsignal() 3: abort() 4: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0x1af) [0x7f52054c3564] 5: (CDentry::check_corruption(bool)+0x86b) [0x5574f7e3a91b] 6: (EMetaBlob::add_dir_context(CDir*, int)+0x507) [0x5574f7f9f9d7] 7: (MDCache::create_subtree_map()+0x13e1) [0x5574f7d20dc1] 8: (MDLog::_journal_segment_subtree_map(MDSContext*)+0x4d) [0x5574f7f2949d] 9: (MDLog::_submit_entry(LogEvent*, MDSLogContextBase*)+0x206) [0x5574f7f29866] 10: (MDCache::log_leader_commit(metareqid_t)+0x277) [0x5574f7ccc3c7] 11: (MDCache::finish_committed_leaders()+0x87) [0x5574f7ccd0d7] 12: (MDCache::maybe_resolve_finish()+0x78) [0x5574f7d38358] 13: (MDCache::handle_resolve(boost::intrusive_ptr<MMDSResolve const> const&)+0x1e02) [0x5574f7d454c2] 14: (MDCache::dispatch(boost::intrusive_ptr<Message const> const&)+0x144) [0x5574f7d47bd4] 15: (MDSRank::handle_message(boost::intrusive_ptr<Message const> const&)+0x733) [0x5574f7bac793] 16: (MDSRank::_dispatch(boost::intrusive_ptr<Message const> const&, bool)+0x643) [0x5574f7bcacb3] 17: (MDSRankDispatcher::ms_dispatch(boost::intrusive_ptr<Message const> const&)+0x5c) [0x5574f7bcb34c] 18: (MDSDaemon::ms_dispatch2(boost::intrusive_ptr<Message> const&)+0x1d6) [0x5574f7b9f226] 19: (Messenger::ms_deliver_dispatch(boost::intrusive_ptr<Message> const&)+0x460) [0x7f5205714020] 20: (DispatchQueue::entry()+0x58f) [0x7f52057118bf] 21: (DispatchQueue::DispatchThread::entry()+0x11) [0x7f52057df261] 22: /lib/x86_64-linux-gnu/libpthread.so.0(+0x8609) [0x7f5205205609] 23: clone() NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. May 02 16:16:53 xxx077 ceph-mds[3047358]: --- logging levels --- May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 none May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 lockdep May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 context May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 1 crush May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_balancer May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_locker May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_log May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_log_expire May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_migrator May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 buffer May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 timer May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 filer May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 striper May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 objecter May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rados May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rbd May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rbd_mirror May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rbd_replay May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rbd_pwl May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 journaler May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 objectcacher May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 immutable_obj_cache May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 client May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 osd May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 optracker May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 objclass May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 3 filestore May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 3 journal May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 0 ms May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mon May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/10 monc May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 paxos May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 tp May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 auth May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 crypto May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 1 finisher May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 1 reserver May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 heartbeatmap May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 perfcounter May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 rgw May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 rgw_sync May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/10 civetweb May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 javaclient May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 asok May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 1 throttle May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 0 refs May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 compressor May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 bluestore May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 bluefs May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 3 bdev May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 kstore May 02 16:16:53 xxx077 ceph-mds[3047358]: 4/ 5 rocksdb May 02 16:16:53 xxx077 ceph-mds[3047358]: 4/ 5 leveldb May 02 16:16:53 xxx077 ceph-mds[3047358]: 4/ 5 memdb May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 fuse May 02 16:16:53 xxx077 ceph-mds[3047358]: 2/ 5 mgr May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mgrc May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 dpdk May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 eventtrace May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 prioritycache May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 test May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 cephfs_mirror May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 cephsqlite May 02 16:16:53 xxx077 ceph-mds[3047358]: 99/99 (syslog threshold) May 02 16:16:53 xxx077 ceph-mds[3047358]: -2/-2 (stderr threshold) May 02 16:16:53 xxx077 ceph-mds[3047358]: --- pthread ID / name mapping for recent threads --- May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990037739264 / May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990054524672 / May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990062917376 / MR_Finisher May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990079702784 / PQ_Finisher May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990096488192 / ms_dispatch May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990130059008 / ceph-mds May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990146844416 / safe_timer May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990163629824 / ms_dispatch May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990180415232 / io_context_pool May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990197200640 / admin_socket May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990205593344 / msgr-worker-2 May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990213986048 / msgr-worker-1 May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990222378752 / msgr-worker-0 May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990239524736 / ceph-mds May 02 16:16:53 xxx077 ceph-mds[3047358]: max_recent 10000 May 02 16:16:53 xxx077 ceph-mds[3047358]: max_new 10000 May 02 16:16:53 xxx077 ceph-mds[3047358]: log_file /var/lib/ceph/crash/2023-05-02T14:16:53.555508Z_0b05f5cb-130c-4979-95ca-1ba7f31cf7e5/log May 02 16:16:53 xxx077 ceph-mds[3047358]: --- end dump of recent events ---
--
Bauhaus-Universität Weimar Bauhausstr. 9a, R308 99423 Weimar, Germany
Phone: +49 3643 58 3577 www.webis.de _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
Thanks! I tried downgrading to 16.2.10 and was able to get it running again, but after a reboot, got a warning that two of the OSDs on that host had broken Bluestore compression. Restarting the two OSDs again got rid of it, but that's still a bit concerning. On 02/05/2023 16:48, Dan van der Ster wrote:
Hi Janek,
That assert is part of a new corruption check added in 16.2.12 -- see https://github.com/ceph/ceph/commit/1771aae8e79b577acde749a292d9965264f20202
The abort is controlled by a new option:
+ Option("mds_abort_on_newly_corrupt_dentry", Option::TYPE_BOOL, Option::LEVEL_ADVANCED) + .set_default(true) + .set_description("MDS will abort if dentry is detected newly corrupted."),
So in theory you could switch that off, but it is concerning that the metadata is corrupted already. I'm cc'ing Patrick who has been working on this issue.
Cheers, Dan
______________________________ Clyso GmbH | https://www.clyso.com
On Tue, May 2, 2023 at 7:32 AM Janek Bevendorff <janek.bevendorff@uni-weimar.de> wrote:
Hi,
After a patch version upgrade from 16.2.10 to 16.2.12, our rank 0 MDS fails start start. After replaying the journal, it just crashes with
[ERR] : MDS abort because newly corrupt dentry to be committed: [dentry #0x1/storage [2,head] auth (dversion lock)
Immediately after the upgrade, I had it running shortly, but then it decided to crash for unknown reasons and I cannot get it back up.
We have five ranks in total, the other four seem to be fine. I backed up the journal and tried to run cephfs-journal-tool --rank=cephfs.storage:0 event recover_dentries summary, but it never finishes only eats up a lot of RAM. I stopped it after an hour and 50GB RAM.
Resetting the journal makes the MDS crash with a missing inode error on another top-level directory, so I re-imported the backed-up journal. Is there any way to recover from this without rebuilding the whole file system?
Thanks Janek
Here's the full crash log:
May 02 16:16:53 xxx077 ceph-mds[3047358]: -29> 2023-05-02T16:16:52.761+0200 7f51f878b700 1 mds.0.1711712 Finished replaying journal May 02 16:16:53 xxx077 ceph-mds[3047358]: -28> 2023-05-02T16:16:52.761+0200 7f51f878b700 1 mds.0.1711712 making mds journal writeable May 02 16:16:53 xxx077 ceph-mds[3047358]: -27> 2023-05-02T16:16:52.761+0200 7f51f878b700 1 mds.0.journaler.mdlog(ro) set_writeable May 02 16:16:53 xxx077 ceph-mds[3047358]: -26> 2023-05-02T16:16:52.761+0200 7f51f878b700 2 mds.0.1711712 i am not alone, moving to state resolve May 02 16:16:53 xxx077 ceph-mds[3047358]: -25> 2023-05-02T16:16:52.761+0200 7f51f878b700 3 mds.0.1711712 request_state up:resolve May 02 16:16:53 xxx077 ceph-mds[3047358]: -24> 2023-05-02T16:16:52.761+0200 7f51f878b700 5 mds.beacon.xxx077 set_want_state: up:replay -> up:resolve May 02 16:16:53 xxx077 ceph-mds[3047358]: -23> 2023-05-02T16:16:52.761+0200 7f51f878b700 5 mds.beacon.xxx077 Sending beacon up:resolve seq 15 May 02 16:16:53 xxx077 ceph-mds[3047358]: -22> 2023-05-02T16:16:52.761+0200 7f51f878b700 10 monclient: _send_mon_message to mon.xxx056 at v2:141.54.133.56:3300/0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -21> 2023-05-02T16:16:53.113+0200 7f51fef98700 10 monclient: tick May 02 16:16:53 xxx077 ceph-mds[3047358]: -20> 2023-05-02T16:16:53.113+0200 7f51fef98700 10 monclient: _check_auth_rotating have uptodate secrets (they expire after 2023-05-02T16:16:23.118186+0200) May 02 16:16:53 xxx077 ceph-mds[3047358]: -19> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.xxx077 Updating MDS map to version 1711713 from mon.1 May 02 16:16:53 xxx077 ceph-mds[3047358]: -18> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 handle_mds_map i am now mds.0.1711712 May 02 16:16:53 xxx077 ceph-mds[3047358]: -17> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 handle_mds_map state change up:replay --> up:resolve May 02 16:16:53 xxx077 ceph-mds[3047358]: -16> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 resolve_start May 02 16:16:53 xxx077 ceph-mds[3047358]: -15> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 reopen_log May 02 16:16:53 xxx077 ceph-mds[3047358]: -14> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 recovery set is 1,2,3,4 May 02 16:16:53 xxx077 ceph-mds[3047358]: -13> 2023-05-02T16:16:53.373+0200 7f51fff9a700 1 mds.0.1711712 recovery set is 1,2,3,4 May 02 16:16:53 xxx077 ceph-mds[3047358]: -12> 2023-05-02T16:16:53.373+0200 7f5202fa0700 10 monclient: get_auth_request con 0x5574fe74c400 auth_method 0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -11> 2023-05-02T16:16:53.373+0200 7f52037a1700 10 monclient: get_auth_request con 0x5574fe40fc00 auth_method 0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -10> 2023-05-02T16:16:53.373+0200 7f520279f700 10 monclient: get_auth_request con 0x5574f932fc00 auth_method 0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -9> 2023-05-02T16:16:53.373+0200 7f520279f700 10 monclient: get_auth_request con 0x5574ffce2000 auth_method 0 May 02 16:16:53 xxx077 ceph-mds[3047358]: -8> 2023-05-02T16:16:53.377+0200 7f5202fa0700 5 mds.beacon.xxx077 received beacon reply up:resolve seq 15 rtt 0.616008 May 02 16:16:53 xxx077 ceph-mds[3047358]: -7> 2023-05-02T16:16:53.393+0200 7f51fff9a700 5 mds.xxx077 handle_mds_map old map epoch 1711713 <= 1711713, discarding May 02 16:16:53 xxx077 ceph-mds[3047358]: -6> 2023-05-02T16:16:53.393+0200 7f51fff9a700 5 mds.xxx077 handle_mds_map old map epoch 1711713 <= 1711713, discarding May 02 16:16:53 xxx077 ceph-mds[3047358]: -5> 2023-05-02T16:16:53.393+0200 7f51fff9a700 5 mds.xxx077 handle_mds_map old map epoch 1711713 <= 1711713, discarding May 02 16:16:53 xxx077 ceph-mds[3047358]: -4> 2023-05-02T16:16:53.393+0200 7f51fff9a700 5 mds.xxx077 handle_mds_map old map epoch 1711713 <= 1711713, discarding May 02 16:16:53 xxx077 ceph-mds[3047358]: -3> 2023-05-02T16:16:53.545+0200 7f51fff9a700 -1 mds.0.cache.den(0x1 storage) newly corrupt dentry to be committed: [dentry #0x1/storage [2,head] auth (dversion lock) v=78956500 ino=0x10000000000 state=1610612736 | inodepin=1 dirty=1 0x5574f932db80] May 02 16:16:53 xxx077 ceph-mds[3047358]: -2> 2023-05-02T16:16:53.545+0200 7f51fff9a700 -1 log_channel(cluster) log [ERR] : MDS abort because newly corrupt dentry to be committed: [dentry #0x1/storage [2,head] auth (dversion lock) v=78956500 ino=0x10000000000 state=1610612736 | inodepin=1 dirty=1 0x5574f932db80] May 02 16:16:53 xxx077 ceph-mds[3047358]: -1> 2023-05-02T16:16:53.549+0200 7f51fff9a700 -1 /build/ceph-16.2.12/src/mds/CDentry.cc: In function 'bool CDentry::check_corruption(bool)' thread 7f51fff9a700 time 2023-05-02T16:16:53.549536+0200 /build/ceph-16.2.12/src/mds/CDentry.cc: 697: ceph_abort_msg("abort() called")
ceph version 16.2.12 (5a2d516ce4b134bfafc80c4274532ac0d56fc1e2) pacific (stable) 1: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0xe0) [0x7f52054c3495] 2: (CDentry::check_corruption(bool)+0x86b) [0x5574f7e3a91b] 3: (EMetaBlob::add_dir_context(CDir*, int)+0x507) [0x5574f7f9f9d7] 4: (MDCache::create_subtree_map()+0x13e1) [0x5574f7d20dc1] 5: (MDLog::_journal_segment_subtree_map(MDSContext*)+0x4d) [0x5574f7f2949d] 6: (MDLog::_submit_entry(LogEvent*, MDSLogContextBase*)+0x206) [0x5574f7f29866] 7: (MDCache::log_leader_commit(metareqid_t)+0x277) [0x5574f7ccc3c7] 8: (MDCache::finish_committed_leaders()+0x87) [0x5574f7ccd0d7] 9: (MDCache::maybe_resolve_finish()+0x78) [0x5574f7d38358] 10: (MDCache::handle_resolve(boost::intrusive_ptr<MMDSResolve const> const&)+0x1e02) [0x5574f7d454c2] 11: (MDCache::dispatch(boost::intrusive_ptr<Message const> const&)+0x144) [0x5574f7d47bd4] 12: (MDSRank::handle_message(boost::intrusive_ptr<Message const> const&)+0x733) [0x5574f7bac793] 13: (MDSRank::_dispatch(boost::intrusive_ptr<Message const> const&, bool)+0x643) [0x5574f7bcacb3] 14: (MDSRankDispatcher::ms_dispatch(boost::intrusive_ptr<Message const> const&)+0x5c) [0x5574f7bcb34c] 15: (MDSDaemon::ms_dispatch2(boost::intrusive_ptr<Message> const&)+0x1d6) [0x5574f7b9f226] 16: (Messenger::ms_deliver_dispatch(boost::intrusive_ptr<Message> const&)+0x460) [0x7f5205714020] 17: (DispatchQueue::entry()+0x58f) [0x7f52057118bf] 18: (DispatchQueue::DispatchThread::entry()+0x11) [0x7f52057df261] 19: /lib/x86_64-linux-gnu/libpthread.so.0(+0x8609) [0x7f5205205609] 20: clone() May 02 16:16:53 xxx077 ceph-mds[3047358]: 0> 2023-05-02T16:16:53.553+0200 7f51fff9a700 -1 *** Caught signal (Aborted) ** in thread 7f51fff9a700 thread_name:ms_dispatch
ceph version 16.2.12 (5a2d516ce4b134bfafc80c4274532ac0d56fc1e2) pacific (stable) 1: /lib/x86_64-linux-gnu/libpthread.so.0(+0x14420) [0x7f5205211420] 2: gsignal() 3: abort() 4: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0x1af) [0x7f52054c3564] 5: (CDentry::check_corruption(bool)+0x86b) [0x5574f7e3a91b] 6: (EMetaBlob::add_dir_context(CDir*, int)+0x507) [0x5574f7f9f9d7] 7: (MDCache::create_subtree_map()+0x13e1) [0x5574f7d20dc1] 8: (MDLog::_journal_segment_subtree_map(MDSContext*)+0x4d) [0x5574f7f2949d] 9: (MDLog::_submit_entry(LogEvent*, MDSLogContextBase*)+0x206) [0x5574f7f29866] 10: (MDCache::log_leader_commit(metareqid_t)+0x277) [0x5574f7ccc3c7] 11: (MDCache::finish_committed_leaders()+0x87) [0x5574f7ccd0d7] 12: (MDCache::maybe_resolve_finish()+0x78) [0x5574f7d38358] 13: (MDCache::handle_resolve(boost::intrusive_ptr<MMDSResolve const> const&)+0x1e02) [0x5574f7d454c2] 14: (MDCache::dispatch(boost::intrusive_ptr<Message const> const&)+0x144) [0x5574f7d47bd4] 15: (MDSRank::handle_message(boost::intrusive_ptr<Message const> const&)+0x733) [0x5574f7bac793] 16: (MDSRank::_dispatch(boost::intrusive_ptr<Message const> const&, bool)+0x643) [0x5574f7bcacb3] 17: (MDSRankDispatcher::ms_dispatch(boost::intrusive_ptr<Message const> const&)+0x5c) [0x5574f7bcb34c] 18: (MDSDaemon::ms_dispatch2(boost::intrusive_ptr<Message> const&)+0x1d6) [0x5574f7b9f226] 19: (Messenger::ms_deliver_dispatch(boost::intrusive_ptr<Message> const&)+0x460) [0x7f5205714020] 20: (DispatchQueue::entry()+0x58f) [0x7f52057118bf] 21: (DispatchQueue::DispatchThread::entry()+0x11) [0x7f52057df261] 22: /lib/x86_64-linux-gnu/libpthread.so.0(+0x8609) [0x7f5205205609] 23: clone() NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. May 02 16:16:53 xxx077 ceph-mds[3047358]: --- logging levels --- May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 none May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 lockdep May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 context May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 1 crush May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_balancer May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_locker May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_log May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_log_expire May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mds_migrator May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 buffer May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 timer May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 filer May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 striper May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 1 objecter May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rados May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rbd May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rbd_mirror May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rbd_replay May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 rbd_pwl May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 journaler May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 objectcacher May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 immutable_obj_cache May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 client May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 osd May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 optracker May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 objclass May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 3 filestore May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 3 journal May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 0 ms May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mon May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/10 monc May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 paxos May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 tp May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 auth May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 crypto May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 1 finisher May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 1 reserver May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 heartbeatmap May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 perfcounter May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 rgw May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 rgw_sync May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/10 civetweb May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 javaclient May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 asok May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 1 throttle May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 0 refs May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 compressor May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 bluestore May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 bluefs May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 3 bdev May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 kstore May 02 16:16:53 xxx077 ceph-mds[3047358]: 4/ 5 rocksdb May 02 16:16:53 xxx077 ceph-mds[3047358]: 4/ 5 leveldb May 02 16:16:53 xxx077 ceph-mds[3047358]: 4/ 5 memdb May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 fuse May 02 16:16:53 xxx077 ceph-mds[3047358]: 2/ 5 mgr May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 mgrc May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 dpdk May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 eventtrace May 02 16:16:53 xxx077 ceph-mds[3047358]: 1/ 5 prioritycache May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 test May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 cephfs_mirror May 02 16:16:53 xxx077 ceph-mds[3047358]: 0/ 5 cephsqlite May 02 16:16:53 xxx077 ceph-mds[3047358]: 99/99 (syslog threshold) May 02 16:16:53 xxx077 ceph-mds[3047358]: -2/-2 (stderr threshold) May 02 16:16:53 xxx077 ceph-mds[3047358]: --- pthread ID / name mapping for recent threads --- May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990037739264 / May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990054524672 / May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990062917376 / MR_Finisher May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990079702784 / PQ_Finisher May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990096488192 / ms_dispatch May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990130059008 / ceph-mds May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990146844416 / safe_timer May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990163629824 / ms_dispatch May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990180415232 / io_context_pool May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990197200640 / admin_socket May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990205593344 / msgr-worker-2 May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990213986048 / msgr-worker-1 May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990222378752 / msgr-worker-0 May 02 16:16:53 xxx077 ceph-mds[3047358]: 139990239524736 / ceph-mds May 02 16:16:53 xxx077 ceph-mds[3047358]: max_recent 10000 May 02 16:16:53 xxx077 ceph-mds[3047358]: max_new 10000 May 02 16:16:53 xxx077 ceph-mds[3047358]: log_file /var/lib/ceph/crash/2023-05-02T14:16:53.555508Z_0b05f5cb-130c-4979-95ca-1ba7f31cf7e5/log May 02 16:16:53 xxx077 ceph-mds[3047358]: --- end dump of recent events ---
--
Bauhaus-Universität Weimar Bauhausstr. 9a, R308 99423 Weimar, Germany
Phone: +49 3643 58 3577 www.webis.de _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
-- Bauhaus-Universität Weimar Bauhausstr. 9a, R308 99423 Weimar, Germany Phone: +49 3643 58 3577 www.webis.de
On Tue, May 2, 2023 at 10:31 AM Janek Bevendorff <janek.bevendorff@uni-weimar.de> wrote:
Hi,
After a patch version upgrade from 16.2.10 to 16.2.12, our rank 0 MDS fails start start. After replaying the journal, it just crashes with
[ERR] : MDS abort because newly corrupt dentry to be committed: [dentry #0x1/storage [2,head] auth (dversion lock)
Immediately after the upgrade, I had it running shortly, but then it decided to crash for unknown reasons and I cannot get it back up.
We have five ranks in total, the other four seem to be fine. I backed up the journal and tried to run cephfs-journal-tool --rank=cephfs.storage:0 event recover_dentries summary, but it never finishes only eats up a lot of RAM. I stopped it after an hour and 50GB RAM.
Resetting the journal makes the MDS crash with a missing inode error on another top-level directory, so I re-imported the backed-up journal. Is there any way to recover from this without rebuilding the whole file system?
Please be careful resetting the journal. It was not necessary. You can try to recover the missing inode using cephfs-data-scan [2]. Thanks for the report. Unfortunately this looks like a false positive. You're not using snapshots, right? In any case, if you can reproduce it again with:
ceph config mds debug_mds 20 ceph config mds debug_ms 1
and upload the logs using ceph-post-file [1], that would be helpful to understand what happened. After that you can disable the check as Dan pointed out: ceph config set mds mds_abort_on_newly_corrupt_dentry false ceph config set mds mds_go_bad_corrupt_dentry false NOTE FOR OTHER READERS OF THIS MAIL: it is not recommended to blindly set these configs as the MDS is trying to catch legitimate metadata corruption. [1] https://docs.ceph.com/en/quincy/man/8/ceph-post-file/ [2] https://docs.ceph.com/en/latest/cephfs/disaster-recovery-experts/ -- Patrick Donnelly, Ph.D. He / Him / His Red Hat Partner Engineer IBM, Inc. GPG: 19F28A586F808C2402351B93C3301A3E258DD79D
Hi Patrick,
Please be careful resetting the journal. It was not necessary. You can try to recover the missing inode using cephfs-data-scan [2].
Yes. I did that very reluctantly after trying everything else as a last resort. But since it only gave me another error, I restored the previous state. Downgrading to the previous version only came to mind minutes before Dan wrote that there's a new assertion in 16.2.12 (I didn't expect a corruption issue to be "fixable" like that).
Thanks for the report. Unfortunately this looks like a false positive. You're not using snapshots, right?
Or fortunately for me? We have an automated snapshot schedule which creates snapshots of certain top-level directories daily. Our main folder is /storage, which had this issue.
In any case, if you can reproduce it again with:
ceph config mds debug_mds 20 ceph config mds debug_ms 1
I'll try that tomorrow and let you know, thanks!
and upload the logs using ceph-post-file [1], that would be helpful to understand what happened.
After that you can disable the check as Dan pointed out:
ceph config set mds mds_abort_on_newly_corrupt_dentry false ceph config set mds mds_go_bad_corrupt_dentry false
NOTE FOR OTHER READERS OF THIS MAIL: it is not recommended to blindly set these configs as the MDS is trying to catch legitimate metadata corruption.
[1] https://docs.ceph.com/en/quincy/man/8/ceph-post-file/ [2] https://docs.ceph.com/en/latest/cephfs/disaster-recovery-experts/
-- Bauhaus-Universität Weimar Bauhausstr. 9a, R308 99423 Weimar, Germany Phone: +49 3643 58 3577 www.webis.de
Hi Patrick,
I'll try that tomorrow and let you know, thanks!
I was unable to reproduce the crash today. Even with mds_abort_on_newly_corrupt_dentry set to true, all MDS booted up correctly (though they took forever to rejoin with logs set to 20). To me it looks like the issue has resolved itself overnight. I had run a recursive scrub on the file system and another snapshot was taken, in case any of those might have had an effect on this. It could also be the case that the (supposedly) corrupt journal entry has simply been committed now and hence doesn't trigger the assertion any more. Is there any way I can verify this? Janek
On Wed, May 3, 2023 at 4:33 AM Janek Bevendorff <janek.bevendorff@uni-weimar.de> wrote:
Hi Patrick,
I'll try that tomorrow and let you know, thanks!
I was unable to reproduce the crash today. Even with mds_abort_on_newly_corrupt_dentry set to true, all MDS booted up correctly (though they took forever to rejoin with logs set to 20).
To me it looks like the issue has resolved itself overnight. I had run a recursive scrub on the file system and another snapshot was taken, in case any of those might have had an effect on this. It could also be the case that the (supposedly) corrupt journal entry has simply been committed now and hence doesn't trigger the assertion any more. Is there any way I can verify this?
You can run: https://github.com/ceph/ceph/blob/main/src/tools/cephfs/first-damage.py Just do: python3 first-damage.py --memo run.1 <meta pool> No need to do any of the other steps if you just want a read-only check. -- Patrick Donnelly, Ph.D. He / Him / His Red Hat Partner Engineer IBM, Inc. GPG: 19F28A586F808C2402351B93C3301A3E258DD79D
After running the tool for 11 hours straight, it exited with the following exception: Traceback (most recent call last): File "/home/webis/first-damage.py", line 156, in <module> traverse(f, ioctx) File "/home/webis/first-damage.py", line 84, in traverse for (dnk, val) in it: File "rados.pyx", line 1389, in rados.OmapIterator.__next__ File "rados.pyx", line 318, in rados.decode_cstr UnicodeDecodeError: 'utf-8' codec can't decode byte 0xff in position 8: invalid start byte Does that mean that the last inode listed in the output file is corrupt? Any way I can fix it? The output file has 14 million lines. We have about 24.5 million objects in the metadata pool. Janek On 03/05/2023 14:20, Patrick Donnelly wrote:
On Wed, May 3, 2023 at 4:33 AM Janek Bevendorff <janek.bevendorff@uni-weimar.de> wrote:
Hi Patrick,
I'll try that tomorrow and let you know, thanks! I was unable to reproduce the crash today. Even with mds_abort_on_newly_corrupt_dentry set to true, all MDS booted up correctly (though they took forever to rejoin with logs set to 20).
To me it looks like the issue has resolved itself overnight. I had run a recursive scrub on the file system and another snapshot was taken, in case any of those might have had an effect on this. It could also be the case that the (supposedly) corrupt journal entry has simply been committed now and hence doesn't trigger the assertion any more. Is there any way I can verify this? You can run:
https://github.com/ceph/ceph/blob/main/src/tools/cephfs/first-damage.py
Just do:
python3 first-damage.py --memo run.1 <meta pool>
No need to do any of the other steps if you just want a read-only check.
-- Bauhaus-Universität Weimar Bauhausstr. 9a, R308 99423 Weimar, Germany Phone: +49 3643 58 3577 www.webis.de
Hi Janek, All this indicates is that you have some files with binary keys that cannot be decoded as utf-8. Unfortunately, the rados python library assumes that omap keys can be decoded this way. I have a ticket here: https://tracker.ceph.com/issues/59716 I hope to have a fix soon. On Thu, May 4, 2023 at 3:15 AM Janek Bevendorff <janek.bevendorff@uni-weimar.de> wrote:
After running the tool for 11 hours straight, it exited with the following exception:
Traceback (most recent call last): File "/home/webis/first-damage.py", line 156, in <module> traverse(f, ioctx) File "/home/webis/first-damage.py", line 84, in traverse for (dnk, val) in it: File "rados.pyx", line 1389, in rados.OmapIterator.__next__ File "rados.pyx", line 318, in rados.decode_cstr UnicodeDecodeError: 'utf-8' codec can't decode byte 0xff in position 8: invalid start byte
Does that mean that the last inode listed in the output file is corrupt? Any way I can fix it?
The output file has 14 million lines. We have about 24.5 million objects in the metadata pool.
Janek
On 03/05/2023 14:20, Patrick Donnelly wrote:
On Wed, May 3, 2023 at 4:33 AM Janek Bevendorff <janek.bevendorff@uni-weimar.de> wrote:
Hi Patrick,
I'll try that tomorrow and let you know, thanks! I was unable to reproduce the crash today. Even with mds_abort_on_newly_corrupt_dentry set to true, all MDS booted up correctly (though they took forever to rejoin with logs set to 20).
To me it looks like the issue has resolved itself overnight. I had run a recursive scrub on the file system and another snapshot was taken, in case any of those might have had an effect on this. It could also be the case that the (supposedly) corrupt journal entry has simply been committed now and hence doesn't trigger the assertion any more. Is there any way I can verify this? You can run:
https://github.com/ceph/ceph/blob/main/src/tools/cephfs/first-damage.py
Just do:
python3 first-damage.py --memo run.1 <meta pool>
No need to do any of the other steps if you just want a read-only check.
--
Bauhaus-Universität Weimar Bauhausstr. 9a, R308 99423 Weimar, Germany
Phone: +49 3643 58 3577 www.webis.de
-- Patrick Donnelly, Ph.D. He / Him / His Red Hat Partner Engineer IBM, Inc. GPG: 19F28A586F808C2402351B93C3301A3E258DD79D
If is thrown while decoding the file name, then somebody probably managed to store files with non-UTF-8 characters in the name. Although I don't really know how this can happen. Perhaps some OS quirk. On 10/05/2023 22:33, Patrick Donnelly wrote:
Hi Janek,
All this indicates is that you have some files with binary keys that cannot be decoded as utf-8. Unfortunately, the rados python library assumes that omap keys can be decoded this way. I have a ticket here:
https://tracker.ceph.com/issues/59716
I hope to have a fix soon.
On Thu, May 4, 2023 at 3:15 AM Janek Bevendorff <janek.bevendorff@uni-weimar.de> wrote:
After running the tool for 11 hours straight, it exited with the following exception:
Traceback (most recent call last): File "/home/webis/first-damage.py", line 156, in <module> traverse(f, ioctx) File "/home/webis/first-damage.py", line 84, in traverse for (dnk, val) in it: File "rados.pyx", line 1389, in rados.OmapIterator.__next__ File "rados.pyx", line 318, in rados.decode_cstr UnicodeDecodeError: 'utf-8' codec can't decode byte 0xff in position 8: invalid start byte
Does that mean that the last inode listed in the output file is corrupt? Any way I can fix it?
The output file has 14 million lines. We have about 24.5 million objects in the metadata pool.
Janek
On 03/05/2023 14:20, Patrick Donnelly wrote:
On Wed, May 3, 2023 at 4:33 AM Janek Bevendorff <janek.bevendorff@uni-weimar.de> wrote:
Hi Patrick,
I'll try that tomorrow and let you know, thanks! I was unable to reproduce the crash today. Even with mds_abort_on_newly_corrupt_dentry set to true, all MDS booted up correctly (though they took forever to rejoin with logs set to 20).
To me it looks like the issue has resolved itself overnight. I had run a recursive scrub on the file system and another snapshot was taken, in case any of those might have had an effect on this. It could also be the case that the (supposedly) corrupt journal entry has simply been committed now and hence doesn't trigger the assertion any more. Is there any way I can verify this? You can run:
https://github.com/ceph/ceph/blob/main/src/tools/cephfs/first-damage.py
Just do:
python3 first-damage.py --memo run.1 <meta pool>
No need to do any of the other steps if you just want a read-only check.
--
Bauhaus-Universität Weimar Bauhausstr. 9a, R308 99423 Weimar, Germany
Phone: +49 3643 58 3577 www.webis.de
-- Bauhaus-Universität Weimar Bauhausstr. 9a, R308 99423 Weimar, Germany Phone: +49 3643 58 3577 www.webis.de
participants (3)
-
Dan van der Ster
-
Janek Bevendorff
-
Patrick Donnelly