[LU-4242] mdt_open.c:1685:mdt_reint_open()) LBUG

• Status: Resolved
• Project: Lustre
• Affects Version/s: Lustre 2.4.1
• Type: Bug
• Priority: Blocker
• Reporter: Frederik Ferner (Inactive)
• Assignee: Bob Glossman (Inactive)
• Resolution: Cannot Reproduce

Environment

file system upgraded from at least 1.8 to 2.3 and now 2.4.1, clients all running 1.8.9 currently, mostly Red Hat clients, Red Hat 6 servers

• Severity: 3

Description

After upgrading our test file system to 2.4.1 earlier (and at the same time moving the OSSes to a different network), the MDT crashes very frequently with and LBUG and reboots directly. I have managed to get the following stack trace from /var/crash.

<0>LustreError: 8518:0:(mdt_open.c:1685:mdt_reint_open()) LBUG
<6>Lustre: play01-MDT0000: Recovery over after 0:31, of 267 clients 267 recovered and 0 were evicted.
<4>Pid: 8518, comm: mdt01_005
<4>
<4>Call Trace:
<4> [<ffffffffa04ea895>] libcfs_debug_dumpstack+0x55/0x80 [libcfs]
<4> [<ffffffffa04eae97>] lbug_with_loc+0x47/0xb0 [libcfs]
<4> [<ffffffffa0e5a6b9>] mdt_reint_open+0x1989/0x20c0 [mdt]
<4> [<ffffffffa050782e>] ? upcall_cache_get_entry+0x28e/0x860 [libcfs]
<4> [<ffffffffa07d5dcc>] ? lustre_msg_add_version+0x6c/0xc0 [ptlrpc]
<4> [<ffffffffa0669f50>] ? lu_ucred+0x20/0x30 [obdclass]
<4> [<ffffffffa0e44911>] mdt_reint_rec+0x41/0xe0 [mdt]
<4> [<ffffffffa0e29ae3>] mdt_reint_internal+0x4c3/0x780 [mdt]
<4> [<ffffffffa0e2a06d>] mdt_intent_reint+0x1ed/0x520 [mdt]
<4> [<ffffffffa0e27f1e>] mdt_intent_policy+0x39e/0x720 [mdt]
<4> [<ffffffffa078d831>] ldlm_lock_enqueue+0x361/0x8d0 [ptlrpc]
<4> [<ffffffffa07b41ef>] ldlm_handle_enqueue0+0x4ef/0x10b0 [ptlrpc]
<4> [<ffffffffa0e283a6>] mdt_enqueue+0x46/0xe0 [mdt]
<4> [<ffffffffa0e2ea97>] mdt_handle_common+0x647/0x16d0 [mdt]
<4> [<ffffffffa07d6bac>] ? lustre_msg_get_transno+0x8c/0x100 [ptlrpc]
<4> [<ffffffffa0e683f5>] mds_regular_handle+0x15/0x20 [mdt]
<4> [<ffffffffa07e63c8>] ptlrpc_server_handle_request+0x398/0xc60 [ptlrpc]
<4> [<ffffffffa04eb5de>] ? cfs_timer_arm+0xe/0x10 [libcfs]
<4> [<ffffffffa04fcd9f>] ? lc_watchdog_touch+0x6f/0x170 [libcfs]
<4> [<ffffffffa07dd729>] ? ptlrpc_wait_event+0xa9/0x290 [ptlrpc]
<4> [<ffffffff81055ad3>] ? __wake_up+0x53/0x70
<4> [<ffffffffa07e775e>] ptlrpc_main+0xace/0x1700 [ptlrpc]
<4> [<ffffffffa07e6c90>] ? ptlrpc_main+0x0/0x1700 [ptlrpc]
<4> [<ffffffff8100c0ca>] child_rip+0xa/0x20
<4> [<ffffffffa07e6c90>] ? ptlrpc_main+0x0/0x1700 [ptlrpc]
<4> [<ffffffffa07e6c90>] ? ptlrpc_main+0x0/0x1700 [ptlrpc]
<4> [<ffffffff8100c0c0>] ? child_rip+0x0/0x20
<4>
<0>Kernel panic - not syncing: LBUG

I also have a vmcore file for this crash, though none of the files in /tmp that I remember from 1.8 times, not sure if this is a 2.4 thing or related to the reboots, which happen even though kernel.panic=0.

It doesn't make any difference if I mount with our without --abort-recovery, the LBUG happens within a minute of the file system coming back, every time.

This test file system has been upgrade from 1.8 to 2.3 previously and was running 2.3 for a while. It is also possible that this has been upgraded from 1.6 initially, though I'd have to check this.

It might be of note that even though we moved the OSSes to a different network, we did not manage to shutdown all clients before the migration, so quite a few clients are likely trying to communicate with the OSSes using the old IPs and will fail.

Issue Links

• is related to: LU-4282 some OSTs reported as inactive in lfs...

Comments

[Frederik Ferner (Inactive)]

attempting to downgrade the MDS to 2.3.0 which it was running previously, results in another LBUG when attempting to mount the MDT. This one looks a bit like LU-2888 or LU-3639:

LustreError: 8822:0:(osd_handler.c:2720:osd_index_try()) ASSERTION( dt_object_ex
LustreError: 8822:0:(osd_handler.c:2720:osd_index_try()) LBUG
Pid: 8822, comm: llog_process_th

Call Trace:
 [<ffffffffa0570905>] libcfs_debug_dumpstack+0x55/0x80 [libcfs]
 [<ffffffffa0570f17>] lbug_with_loc+0x47/0xb0 [libcfs]
 [<ffffffffa0f42735>] osd_index_try+0x175/0x620 [osd_ldiskfs]
 [<ffffffffa0a2dc08>] fld_index_init+0x88/0x4d0 [fld]
 [<ffffffffa0a2b13d>] ? fld_cache_init+0x14d/0x430 [fld]
 [<ffffffffa0a26a3e>] fld_server_init+0x29e/0x450 [fld]
 [<ffffffffa0e961b6>] mdt_fld_init+0x126/0x430 [mdt]
 [<ffffffffa0e9b326>] mdt_init0+0x8c6/0x23f0 [mdt]
 [<ffffffffa0571be0>] ? cfs_alloc+0x30/0x60 [libcfs]
 [<ffffffffa0e9cf43>] mdt_device_alloc+0xf3/0x220 [mdt]
 [<ffffffffa06b60d7>] obd_setup+0x1d7/0x2f0 [obdclass]
 [<ffffffffa06b63f8>] class_setup+0x208/0x890 [obdclass]
 [<ffffffffa06be08c>] class_process_config+0xc0c/0x1c30 [obdclass]
 [<ffffffffa0571be0>] ? cfs_alloc+0x30/0x60 [libcfs]
 [<ffffffffa06b7eb3>] ? lustre_cfg_new+0x353/0x7e0 [obdclass]
 [<ffffffffa06c015b>] class_config_llog_handler+0x9bb/0x1610 [obdclass]
 [<ffffffffa068e5f0>] ? llog_lvfs_next_block+0x2d0/0x650 [obdclass]
 [<ffffffffa0688970>] ? llog_process_thread+0x0/0xd00 [obdclass]
 [<ffffffffa06891f8>] llog_process_thread+0x888/0xd00 [obdclass]
 [<ffffffffa0688970>] ? llog_process_thread+0x0/0xd00 [obdclass]
 [<ffffffff8100c14a>] child_rip+0xa/0x20
 [<ffffffffa0688970>] ? llog_process_thread+0x0/0xd00 [obdclass]
 [<ffffffffa0688970>] ? llog_process_thread+0x0/0xd00 [obdclass]
 [<ffffffff8100c140>] ? child_rip+0x0/0x20

Kernel panic - not syncing: LBUG

and on a terminal:

essage from syslogd@cs04r-sc-mds02-03 at Nov 11 21:21:30 ...
 kernel:LustreError: 8822:0:(osd_handler.c:2720:osd_index_try()) ASSERTION( dt_object_exists(dt) ) failed: 

Message from syslogd@cs04r-sc-mds02-03 at Nov 11 21:21:30 ...
 kernel:LustreError: 8822:0:(osd_handler.c:2720:osd_index_try()) LBUG

Message from syslogd@cs04r-sc-mds02-03 at Nov 11 21:21:30 ...
 kernel:Kernel panic - not syncing: LBUG

[Bob Glossman (Inactive)]

I'm wondering if this is an instance of known bug LU-2842. I believe there is a fix already in the b2_4 branch, but it went in after the 2.4.1 release.

[Di Wang]

Are there any other error console message before LBUG, if the object triggered this LBUG is a IGIF object(i.e. created in <= 1.8), then it is probably LU-3934. http://review.whamcloud.com/#/c/7625/ should fix this problem.

[Frederik Ferner (Inactive)]

This is the full contents starting with the new mount found in /var/crash/ after one of the initial LBUGs, not this is after tunefs.lustre --writeconf on all clients.

<4>LDISKFS-fs warning (device dm-9): ldiskfs_multi_mount_protect: MMP interval 42 higher than expected, please wait.
<4>LDISKFS-fs (dm-10): warning: maximal mount count reached, running e2fsck is recommended
<6>LDISKFS-fs (dm-10): recovery complete
<6>LDISKFS-fs (dm-10): mounted filesystem with ordered data mode. quota=off. Opts: 
<4>
<3>LustreError: 137-5: play01-MDT0000_UUID: not available for connect from 172.23.132.8@tcp (no target)
<3>LustreError: 137-5: play01-MDT0000_UUID: not available for connect from 172.23.132.23@tcp (no target)
<3>LustreError: 137-5: play01-MDT0000_UUID: not available for connect from 172.23.140.11@tcp (no target)
<4>Lustre: 8320:0:(client.c:1868:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1384193891/real 1384193891]  req@ffff880237a6c800 x1451432468283396/t0(0) o250->MGC172.23.138.36@tcp@0@lo:26/25 lens 400/544 e 0 to 1 dl 1384193896 ref 1 fl Rpc:XN/0/ffffffff rc 0/-1
<3>LustreError: 137-5: play01-MDT0000_UUID: not available for connect from 172.23.138.78@tcp (no target)
<3>LustreError: Skipped 1 previous similar message
<3>LustreError: 137-5: play01-MDT0000_UUID: not available for connect from 172.23.146.12@tcp (no target)
<3>LustreError: Skipped 1 previous similar message
<3>LustreError: 8338:0:(client.c:1052:ptlrpc_import_delay_req()) @@@ send limit expired   req@ffff880237a6c000 x1451432468283400/t0(0) o253->MGC172.23.138.36@tcp@0@lo:26/25 lens 4768/4768 e 0 to 0 dl 0 ref 2 fl Rpc:W/0/ffffffff rc 0/-1
<3>LustreError: 8338:0:(obd_mount_server.c:1124:server_register_target()) play01-MDT0000: error registering with the MGS: rc = -5 (not fatal)
<3>LustreError: 8338:0:(client.c:1052:ptlrpc_import_delay_req()) @@@ send limit expired   req@ffff880237a6c000 x1451432468283404/t0(0) o101->MGC172.23.138.36@tcp@0@lo:26/25 lens 328/344 e 0 to 0 dl 0 ref 2 fl Rpc:W/0/ffffffff rc 0/-1
<3>LustreError: 8338:0:(client.c:1052:ptlrpc_import_delay_req()) @@@ send limit expired   req@ffff880237a6c000 x1451432468283408/t0(0) o101->MGC172.23.138.36@tcp@0@lo:26/25 lens 328/344 e 0 to 0 dl 0 ref 2 fl Rpc:W/0/ffffffff rc 0/-1
<4>Lustre: play01-MDT0000: used disk, loading
<3>LustreError: 8419:0:(sec_config.c:1115:sptlrpc_target_local_read_conf()) missing llog context
<4>Lustre: 8419:0:(mdt_handler.c:4948:mdt_process_config()) For interoperability, skip this mdt.quota_type. It is obsolete.
<4>Lustre: 8419:0:(mdt_handler.c:4948:mdt_process_config()) For interoperability, skip this mdt.group_upcall. It is obsolete.
<3>LustreError: 8338:0:(client.c:1052:ptlrpc_import_delay_req()) @@@ send limit expired   req@ffff880237a6c000 x1451432468283412/t0(0) o101->MGC172.23.138.36@tcp@0@lo:26/25 lens 328/344 e 0 to 0 dl 0 ref 2 fl Rpc:W/0/ffffffff rc 0/-1
<4>Lustre: 8320:0:(client.c:1868:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1384193916/real 1384193916]  req@ffff88042a57d000 x1451432468283416/t0(0) o250->MGC172.23.138.36@tcp@0@lo:26/25 lens 400/544 e 0 to 1 dl 1384193926 ref 1 fl Rpc:XN/0/ffffffff rc 0/-1
<3>LustreError: 8338:0:(client.c:1052:ptlrpc_import_delay_req()) @@@ send limit expired   req@ffff880237a6c000 x1451432468283420/t0(0) o101->MGC172.23.138.36@tcp@0@lo:26/25 lens 328/344 e 0 to 0 dl 0 ref 2 fl Rpc:W/0/ffffffff rc 0/-1
<4>Lustre: 8320:0:(client.c:1868:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1384193926/real 1384193926]  req@ffff88043bb77400 x1451432468283424/t0(0) o38->play01-MDT0000-lwp-MDT0000@172.23.138.19@tcp:12/10 lens 400/544 e 0 to 1 dl 1384193931 ref 1 fl Rpc:XN/0/ffffffff rc 0/-1
<4>LDISKFS-fs (dm-9): warning: maximal mount count reached, running e2fsck is recommended
<6>LDISKFS-fs (dm-9): recovery complete
<6>LDISKFS-fs (dm-9): mounted filesystem with ordered data mode. quota=off. Opts: 
<4>Lustre: play01-MDT0000: Will be in recovery for at least 5:00, or until 267 clients reconnect
<4>Lustre: MGS: Regenerating play01-OST0005 log by user request.
<6>Lustre: Setting parameter play01-OST0005.ost.quota_type in log play01-OST0005
<4>Lustre: MGS: Regenerating play01-OST0003 log by user request.
<6>Lustre: Setting parameter play01-OST0003.ost.quota_type in log play01-OST0003
<4>Lustre: MGS: Regenerating play01-OST0001 log by user request.
<6>Lustre: Setting parameter play01-OST0001.ost.quota_type in log play01-OST0001
<3>LustreError: 8446:0:(mdt_open.c:1497:mdt_reint_open()) @@@ OPEN & CREAT not in open replay/by_fid.  req@ffff88042a15c000 x1433645786902677/t0(167503724545) o101->9b75b3ec-58d8-9e5e-4031-acd3744332ea@172.23.142.163@tcp:0/0 lens 664/1272 e 0 to 0 dl 1384193985 ref 1 fl Complete:/4/0 rc 0/0
<3>LustreError: 8446:0:(mdt_open.c:1497:mdt_reint_open()) @@@ OPEN & CREAT not in open replay/by_fid.  req@ffff880429f09000 x1433645786902678/t0(167503724546) o101->9b75b3ec-58d8-9e5e-4031-acd3744332ea@172.23.142.163@tcp:0/0 lens 664/1272 e 0 to 0 dl 1384194007 ref 1 fl Complete:/4/0 rc 0/0
<0>LustreError: 8518:0:(mdt_open.c:1685:mdt_reint_open()) LBUG

[Bob Glossman (Inactive)]

Just to be sure I'm interpreting correctly, the log shown above is from the LBUG seen when you tried to upgrade. Not the one from when you tried to downgrade again from 2.4.1 to 2.3. Is that right?

Have you tried the patch that Di Wang suggested, or is this still without any patches?

[Frederik Ferner (Inactive)]

Bob,

you are correct, the additional errors from my previous comment were from the original LBUG running 2.4.1.

We've not had a chance to run with the patch, we've been very busy today with other work. We've not yet tried to bring the file system in question back today, though this will be a task for tomorrow.

Is there a link to RPMs containing that patch that I could try or do I need to build the server myself? The one linked to from the review page doesn't seem to exist anymore. Or should I just try a more recent build from b2_4 branch in jenkins?

[Bob Glossman (Inactive)]

Frederik,

If you use a more recent build from b2_4 it may already have the suggested patch in it. The most recent certainly does. However I can't recommend that as the best course. The latest prebuilt rpms may not be for your exact kernel version, they may be for a later version. Also the latest b2_4 has many patches in it on the way to our upcoming 2.4.2 release besides the one you want and hasn't yet been through a full and complete test cycle for release.

Your safest course is to pull the tagged 2.4.1 lustre source, install that, add just patch recommended by Di Wang, and build the server yourself against the kernel you are already running on your RedHat or Centos servers.

[Frederik Ferner (Inactive)]

Bob,

I've now reproduced this using the jenkins build #47 for be b2_4 branch (http://build.whamcloud.com/job/lustre-b2_4/47/arch=x86_64,build_type=server,distro=el6,ib_stack=inkernel/) as this is the first one with the patch included as far as I can see and my own build didn't even boot.

So with this build:

Lustre: Lustre: Build Version: jenkins-arch=x86_64,build_type=server,distro=el6,ib_stack=inkernel-47-g63f298d-PRISTINE-2.6.32-358.18.1.el6_lustre.g63f298d.x86_64

it still crashes as soon as recovery is complete with LBUG, (nearly) same LustreError:

LustreError: 6172:0:(mdt_open.c:1692:mdt_reint_open()) LBUG

[Frederik Ferner (Inactive)]

I have now managed to get the file system back using the latest jenkins build (#51) on the MDS. I'm currently running this following on the MDT and the LBUG directly after recovery has not happened.

[bnh65367@cs04r-sc-mds02-03 ~]$ cat /proc/fs/lustre/version 
lustre: 2.4.1
kernel: patchless_client
build:  jenkins-arch=x86_64,build_type=server,distro=el6,ib_stack=inkernel-51-g5ee03f6-PRISTINE-2.6.32-358.18.1.el6_lustre.gf81b846.x86_64
[bnh65367@cs04r-sc-mds02-03 ~]$ 

[Peter Jones]

Frederik

So are you comfortable that this seems likely to be a duplicate of LU-3934 and if you defer your upgrade until the upcoming 2.4.2 you will avoid this issue?

Peter

[Di Wang]

Frederik, Could you please provide us debug log for this LBUG. So you need
1. setup MDT, then

lctl set_param panic_on_lbug=0
lctl set_param debug_mb=30
lctl set_param debug=-1

Note: these should be done before LBUG happens.
2. When LBUG happens, it should dump some debug log somewhere(usually under /tmp), you can see this from console message. Could you please put this debug log somewhere(ftp.whamcloud.com)? Thanks!

[Frederik Ferner (Inactive)]

I've dropped our MDS in this file system back to 2.4.1 but can no longer reproduce the problem. Sorry I didn't collect debug logs earlier.

I'm not fully convinced it is a duplicate of LU-3934, as my initial attempt to run with the version that had the suggested patch included didn't fix the problem, but a later version did fix the problem. Before then it was happening on every attempt to mount the MDT.

Unfortunately now I have a different problem, somehow my clients don't succeed in connecting to all OSTs anymore (note that each client seems to be able to connect to at least one OST for each OSS in this file system but not all of them) I guess I'll open a separate ticket for that.

[John Fuchs-Chesney (Inactive)]

Customer cannot reproduce and has opened another ticket for a related problem.