Project

General

Profile

Bug #56506

pacific: Test failure: test_rebuild_backtraceless (tasks.cephfs.test_data_scan.TestDataScan)

Added by Venky Shankar over 1 year ago. Updated 10 months ago.

Status:
Triaged
Priority:
Normal
Category:
Correctness/Safety
Target version:
-
% Done:

0%

Source:
Tags:
Backport:
quincy, pacific
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(FS):
MDS
Labels (FS):
crash
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

https://pulpito.ceph.com/yuriw-2022-07-06_13:57:53-fs-wip-yuri4-testing-2022-07-05-0719-pacific-distro-default-smithi/6917403/

Failure is due to an MDS crash with backtrace

    -6> 2022-07-06T14:25:24.738+0000 7f11abeb5700  1 mds.0.journalpointer Journal pointer '400.00000000' read failed: (2) No such file or directory
    -5> 2022-07-06T14:25:24.738+0000 7f11abeb5700  4 mds.0.journalpointer Writing pointer object '400.00000000': 0x0x200:0x0x0
    -4> 2022-07-06T14:25:24.738+0000 7f11abeb5700  1 -- [v2:172.21.15.112:6832/3392874805,v1:172.21.15.112:6833/3392874805] --> [v2:172.21.15.119:6800/28316,v1:172.21.15.119:6801/28316] -- osd_op(unknown.0.62:8 11.f 11:f1f69726:::400.00000000:head [writefull 0~22 in=22b] snapc 0=[] ondisk+write+known_if_redirected+full_force e86) v8 -- 0x563115521000 con 0x563115521800
    -3> 2022-07-06T14:25:24.746+0000 7f11b5ec9700  1 -- [v2:172.21.15.112:6832/3392874805,v1:172.21.15.112:6833/3392874805] <== osd.7 v2:172.21.15.119:6800/28316 2 ==== osd_op_reply(8 400.00000000 [writefull 0~22] v0'0 uv0 ondisk = -108 ((108) Cannot send after transport endpoint shutdown)) v8 ==== 156+0+0 (crc 0 0 0) 0x5631153d9b00 con 0x563115521800
    -2> 2022-07-06T14:25:24.746+0000 7f11abeb5700 -1 mds.0.journalpointer Error writing pointer object '400.00000000': (108) Cannot send after transport endpoint shutdown
    -1> 2022-07-06T14:25:24.746+0000 7f11abeb5700 -1 /build/ceph-16.2.9-446-g2103eaf0/src/mds/MDLog.cc: In function 'void MDLog::_recovery_thread(MDSContext*)' thread 7f11abeb5700 time 2022-07-06T14:25:24.750534+0000
/build/ceph-16.2.9-446-g2103eaf0/src/mds/MDLog.cc: 976: FAILED ceph_assert(write_result >= 0)

 ceph version 16.2.9-446-g2103eaf0 (2103eaf02dd3c9da5290a33a5b7ec7f42138d76a) pacific (stable)
 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x152) [0x7f11b7bd1d55]
 2: /usr/lib/ceph/libceph-common.so.2(+0x266f5d) [0x7f11b7bd1f5d]
 3: (MDLog::_recovery_thread(MDSContext*)+0x15f2) [0x5631138ba1a2]
 4: (MDLog::RecoveryThread::entry()+0x15) [0x56311355a615]
 5: /lib/x86_64-linux-gnu/libpthread.so.0(+0x8609) [0x7f11b7915609]
 6: clone()

Just before the crash, the MDS failed to read inode table object

   -32> 2022-07-06T14:25:24.734+0000 7f11ac6b6700 10 MDSIOContextBase::complete: 12C_IO_MT_Load
   -31> 2022-07-06T14:25:24.734+0000 7f11ac6b6700 10 MDSContext::complete: 12C_IO_MT_Load
   -30> 2022-07-06T14:25:24.734+0000 7f11ac6b6700 -1 mds.0.inotable: load_2 could not read table: -2
   -29> 2022-07-06T14:25:24.734+0000 7f11b5ec9700  1 -- [v2:172.21.15.112:6832/3392874805,v1:172.21.15.112:6833/3392874805] <== osd.5 v2:172.21.15.119:6803/28315 2 ==== osd_op_reply(4 mds0_openfiles.0 [omap-get-header,omap-get-vals] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 202+0+0 (crc 0 0 0) 0x5631153d9b00 con 0x56311472dc00
   -28> 2022-07-06T14:25:24.734+0000 7f11ac6b6700 -1 log_channel(cluster) log [ERR] : error reading table object 'mds0_inotable' -2 ((2) No such file or directory)
   -27> 2022-07-06T14:25:24.734+0000 7f11ac6b6700  5 mds.beacon.a set_want_state: up:replay -> down:damaged
   -26> 2022-07-06T14:25:24.734+0000 7f11ac6b6700 10 log_client  log_queue is 1 last_log 1 sent 0 num 1 unsent 1 sending 1
   -25> 2022-07-06T14:25:24.734+0000 7f11ac6b6700 10 log_client  will send 2022-07-06T14:25:24.737603+0000 mds.a (mds.0) 1 : cluster [ERR] error reading table object 'mds0_inotable' -2 ((2) No such file or directory)
   -24> 2022-07-06T14:25:24.734+0000 7f11ac6b6700 10 monclient: _send_mon_message to mon.a at v2:172.21.15.112:3300/0
   -23> 2022-07-06T14:25:24.734+0000 7f11b56c8700  1 -- [v2:172.21.15.112:6832/3392874805,v1:172.21.15.112:6833/3392874805] <== osd.3 v2:172.21.15.112:6824/28044 1 ==== osd_op_reply(2 mds0_sessionmap [omap-get-header,omap-get-vals] v0'0 uv0 ondisk = -2 ((2) No such file
or directory)) v8 ==== 201+0+0 (crc 0 0 0) 0x5631155446c0 con 0x563115520400
   -22> 2022-07-06T14:25:24.734+0000 7f11ac6b6700  1 -- [v2:172.21.15.112:6832/3392874805,v1:172.21.15.112:6833/3392874805] --> [v2:172.21.15.112:3300/0,v1:172.21.15.112:6789/0] -- log(1 entries from seq 1 at 2022-07-06T14:25:24.737603+0000) v1 -- 0x563114706000 con 0x56311472d000
   -21> 2022-07-06T14:25:24.734+0000 7f11ac6b6700  5 mds.beacon.a Sending beacon down:damaged seq 2

AFAICT, this is only seen in pacific.

History

#1 Updated by Venky Shankar over 1 year ago

  • Status changed from New to Triaged
  • Assignee set to Milind Changire

#2 Updated by Ilya Dryomov over 1 year ago

  • Target version changed from v16.2.10 to v16.2.11

#3 Updated by Venky Shankar over 1 year ago

  • Severity changed from 3 - minor to 2 - major

Milind, please RCA this.

#4 Updated by Milind Changire over 1 year ago

This seems to be a race between an mds respawn and the MDLog::_recovery_thread()
In Pacific, the MDLog::_recovery_thread() wins and leads to the assertion failure.
The race seems to be present in later versions as well, but somehow the respawn path wins and we don't see the assertion failure via the MDLog::_recovery_thread() path.

5 of 5 teuthology jobs for pacific passed, with a small patch (on top of yuri's testing branch) which sleeps for 10 seconds before the fateful assertion failure:

All the 5 jobs were executed on Ubuntu.

I also tried 3 job runs with Yuri's original branch (i.e. without my patch), but was unable to reproduce the problem.

NOTE:
I haven't yet checked code older than pacific as of filing this report.

#5 Updated by Venky Shankar over 1 year ago

Milind Changire wrote:

This seems to be a race between an mds respawn and the MDLog::_recovery_thread()
In Pacific, the MDLog::_recovery_thread() wins and leads to the assertion failure.

Do we know why the update operation (objecter write) fails? (in logs)? What is not 100% clear to me is how a racing respawn is causing the objecter write operation to fail.

The race seems to be present in later versions as well, but somehow the respawn path wins and we don't see the assertion failure via the MDLog::_recovery_thread() path.

5 of 5 teuthology jobs for pacific passed, with a small patch (on top of yuri's testing branch) which sleeps for 10 seconds before the fateful assertion failure:

All the 5 jobs were executed on Ubuntu.

I also tried 3 job runs with Yuri's original branch (i.e. without my patch), but was unable to reproduce the problem.

NOTE:
I haven't yet checked code older than pacific as of filing this report.

#6 Updated by Venky Shankar over 1 year ago

Never mind - I see the err coming from JournalPointer. If the MDS is respawning/shutting down could that condition additionally be a part of the assert?

#7 Updated by Milind Changire over 1 year ago

Adding any more condition to the assertion expression and passing the assertion is not going to do any good.
Since MDSTable::load_2() is hopefully going to set the MDS state as damaged and respawn immediately when loading fails, the idea for the MDLog::_recovery_thread() is to wait for the respawn as much as possible and eventually fail the assertion as there's no way to recover and make progress.

#8 Updated by Venky Shankar over 1 year ago

  • Severity changed from 2 - major to 3 - minor

Milind Changire wrote:

Adding any more condition to the assertion expression and passing the assertion is not going to do any good.
Since MDSTable::load_2() is hopefully going to set the MDS state as damaged and respawn immediately when loading fails, the idea for the MDLog::_recovery_thread() is to wait for the respawn as much as possible and eventually fail the assertion as there's no way to recover and make progress.

(adjusting severity since this happens only during MDS respawn)

Maybe we could terminate such threads before respawning?

#9 Updated by Ilya Dryomov about 1 year ago

  • Target version deleted (v16.2.11)

Also available in: Atom PDF