[LU-9142] (lib-lnet.h:293:lnet_msg_alloc()) LBUG Created: 22/Feb/17  Updated: 03/Mar/17  Resolved: 28/Feb/17

Status: Resolved
Project: Lustre
Component/s: None
Affects Version/s: Lustre 2.8.0
Fix Version/s: None

Type: Bug Priority: Major
Reporter: Ruth Klundt (Inactive) Assignee: Amir Shehata (Inactive)
Resolution: Not a Bug Votes: 0
Labels: None
Environment:

servers and clients:
lustre: 2.8.0_8.chaos
kernel: 3.10.0-514.6.1.1chaos.ch6.x86_64
RHEL 7.3


Severity: 3
Rank (Obsolete): 9223372036854775807

 Description   

sleeping in invalid context at ldiskfs/ext4_jbd2.c:259 followed by LBUG:

2017-02-21 17:51:20 [25522.565474] BUG: sleeping function called from invalid context at /builddir/build/BUILD/lustre-2.8.0_8.chaos/ldiskfs/ext4_jbd2.c:259
2017-02-21 17:51:20 [25522.577368] in_atomic(): 1, irqs_disabled(): 0, pid: 15066, name: mdt_rdpg00_003
2017-02-21 17:51:20 [25522.584754] CPU: 6 PID: 15066 Comm: mdt_rdpg00_003 Tainted: G IOE ------------ 3.10.0-514.6.1.1chaos.ch6.x86_64 #1
2017-02-21 17:51:20 [25522.596123] Hardware name: Dell Inc. PowerEdge R710/00NH4P, BIOS 3.0.0 01/31/2011
2017-02-21 17:51:20 [25522.603591] ffff88060710df70 00000000b9ff74be ffff880313ab3640 ffffffff8169c685
2017-02-21 17:51:20 [25522.611015] ffff880313ab3650 ffffffff810c0199 ffff880313ab36b0 ffffffffa0e5c048
2017-02-21 17:51:20 [25522.618435] 0000000000000002 0000000000000000 00000000b9ff74be ffff880313ab3698
2017-02-21 17:51:20 [25522.625855] Call Trace:
2017-02-21 17:51:20 [25522.628305] [<ffffffff8169c685>] dump_stack+0x19/0x1b
2017-02-21 17:51:20 [25522.633436] [<ffffffff810c0199>] __might_sleep+0xd9/0x100
2017-02-21 17:51:20 [25522.638922] [<ffffffffa0e5c048>] __ldiskfs_handle_dirty_metadata+0x38/0x230 [ldiskfs]
2017-02-21 17:51:20 [25522.646829] [<ffffffff810b4745>] ? wake_up_bit+0x25/0x30
2017-02-21 17:51:20 [25522.652228] [<ffffffffa0ea8bf2>] ldiskfs_getblk+0x142/0x210 [ldiskfs]
2017-02-21 17:51:20 [25522.658754] [<ffffffffa0ea8ce7>] ldiskfs_bread+0x27/0xe0 [ldiskfs]
2017-02-21 17:51:20 [25522.665025] [<ffffffffa0f3e6e9>] osd_ldiskfs_write_record+0x169/0x360 [osd_ldiskfs]
2017-02-21 17:51:20 [25522.672764] [<ffffffffa0f3ea22>] osd_write+0x142/0x570 [osd_ldiskfs]
2017-02-21 17:51:20 [25522.679206] [<ffffffffa11ac779>] lod_sub_object_write+0x1d9/0x420 [lod]
2017-02-21 17:51:20 [25522.685900] [<ffffffffa1194054>] lod_write+0x24/0x30 [lod]
2017-02-21 17:51:20 [25522.691493] [<ffffffffa0a47129>] dt_record_write+0x39/0x120 [obdclass]
2017-02-21 17:51:20 [25522.698150] [<ffffffffa0c92ee0>] tgt_add_reply_data+0x240/0x430 [ptlrpc]
2017-02-21 17:51:20 [25522.704964] [<ffffffffa0c950fc>] tgt_last_rcvd_update+0x77c/0xc80 [ptlrpc]
2017-02-21 17:51:20 [25522.711952] [<ffffffffa0c9914d>] tgt_txn_stop_cb+0x19d/0x490 [ptlrpc]
2017-02-21 17:51:20 [25522.718473] [<ffffffffa071b639>] ? start_this_handle+0x1a9/0x480 [jbd2]
2017-02-21 17:51:20 [25522.725182] [<ffffffffa0a4861e>] dt_txn_hook_stop+0x7e/0xd0 [obdclass]
2017-02-21 17:51:20 [25522.731793] [<ffffffffa0f27eb8>] osd_trans_stop+0x138/0x5a0 [osd_ldiskfs]
2017-02-21 17:51:20 [25522.738692] [<ffffffffa0cb4429>] top_trans_stop+0x99/0x970 [ptlrpc]
2017-02-21 17:51:20 [25522.745054] [<ffffffffa0a450d3>] ? lu_context_init+0xd3/0x200 [obdclass]
2017-02-21 17:51:20 [25522.751836] [<ffffffffa1180399>] lod_trans_stop+0x259/0x340 [lod]
2017-02-21 17:51:20 [25522.758041] [<ffffffffa0cb414f>] ? top_trans_start+0x70f/0x950 [ptlrpc]
2017-02-21 17:51:20 [25522.764738] [<ffffffffa0f1b2c5>] ? osd_trans_create+0x75/0x390 [osd_ldiskfs]
2017-02-21 17:51:20 [25522.771882] [<ffffffffa0a614ce>] ? lu_ucred+0x1e/0x30 [obdclass]
2017-02-21 17:51:20 [25522.777975] [<ffffffffa12043bf>] ? mdd_changelog_data_store+0x2f/0x330 [mdd]
2017-02-21 17:51:20 [25522.785135] [<ffffffffa0cb0ec7>] ? top_trans_create+0x87/0x200 [ptlrpc]
2017-02-21 17:51:20 [25522.791832] [<ffffffffa120eafd>] mdd_trans_stop+0x1d/0x25 [mdd]
2017-02-21 17:51:20 [25522.797834] [<ffffffffa1205327>] mdd_close+0x117/0xc90 [mdd]
2017-02-21 17:51:20 [25522.803588] [<ffffffffa10d5e29>] mdt_mfd_close+0x249/0x620 [mdt]
2017-02-21 17:51:20 [25522.809681] [<ffffffffa10db573>] mdt_close_internal+0x103/0x470 [mdt]
2017-02-21 17:51:20 [25522.816207] [<ffffffffa10dbb00>] mdt_close+0x220/0x780 [mdt]
2017-02-21 17:51:20 [25522.821982] [<ffffffffa0ca0445>] tgt_request_handle+0x915/0x1320 [ptlrpc]
2017-02-21 17:51:20 [25522.828876] [<ffffffffa0c4ce9b>] ptlrpc_server_handle_request+0x21b/0xa90 [ptlrpc]
2017-02-21 17:51:20 [25522.836534] [<ffffffffa0931748>] ? lc_watchdog_touch+0x68/0x180 [libcfs]
2017-02-21 17:51:20 [25522.843341] [<ffffffffa0c4aa6b>] ? ptlrpc_wait_event+0xab/0x350 [ptlrpc]
2017-02-21 17:51:20 [25522.850150] [<ffffffffa0c50f40>] ptlrpc_main+0xa90/0x1db0 [ptlrpc]
2017-02-21 17:51:20 [25522.856439] [<ffffffffa0c504b0>] ? ptlrpc_register_service+0xe40/0xe40 [ptlrpc]
2017-02-21 17:51:20 [25522.863823] [<ffffffff810b360f>] kthread+0xcf/0xe0
2017-02-21 17:51:20 [25522.868693] [<ffffffff810b3540>] ? kthread_create_on_node+0x140/0x140
2017-02-21 17:51:20 [25522.875212] [<ffffffff816ad498>] ret_from_fork+0x58/0x90
2017-02-21 17:51:20 [25522.880601] [<ffffffff810b3540>] ? kthread_create_on_node+0x140/0x140
2017-02-21 17:51:20 [25522.887133] LNetError: 15066:0:(lib-lnet.h:293:lnet_msg_alloc()) ASSERTION( !(((current_thread_info()->preempt_count) & ((((1UL << (10))-1) << ((0 + 8) + 8)) | (((1UL << (8))-1) << (0 + 8)) | (((1UL << (1))-1) << (((0 + 8) + 8) + 10))))) || (((sizeof(*msg))) <= (2 << 12) && (((((( gfp_t)0x10u) | (( gfp_t)0x40u)))) & ((( gfp_t)0x20u)))) != 0 ) failed:
2017-02-21 17:51:20 [25522.918175] LNetError: 15066:0:(lib-lnet.h:293:lnet_msg_alloc()) LBUG



 Comments   
Comment by Ruth Klundt (Inactive) [ 22/Feb/17 ]

The I/O load was IOR, on a smallish test cluster ~200 nodes total.

Comment by Peter Jones [ 22/Feb/17 ]

Amir

Could you please advise on this one?

Thanks

Peter

Comment by Amir Shehata (Inactive) [ 27/Feb/17 ]

Is this crash on the server or the client?

If the server, has the kernel been patched?

Comment by Ruth Klundt (Inactive) [ 27/Feb/17 ]

it's the MDS, and I'll check on the kernel. It is also from LLNL.

Comment by Ruth Klundt (Inactive) [ 27/Feb/17 ]

The kernel has the following patches in the src rpm:

ACPI-APEI-GHES-Further-instrumentation-refinements.patch
ACPI-APEI-GHES-GHES-platform-driver-instrumentation.patch
edac-Enable-MCE-and-amd64-error-injection.patch
Export-mutex-lockdep-symbols-to-non-GPL-modules.patch
Fix-missed-REQ_TYPE_SPECIAL-REQ_TYPE_DRV_PRIV-in-nbd-driver.patch
fs-drop_caches-report-amount-of-dropped-pagecache.patch
fs-Enhance-proc-sys-vm-drop_caches.patch
fs-nfs-support-16-groups-in-nfs.patch
IB-hfi1-Add-static-PCIe-Gen3-CTLE-tuning.patch
IB-rdmavt-Only-put-mmap_info-ref-if-it-exists.patch
ipmi-Disable-kipmid-by-default.patch
mlx4-Add-huge-TLB-support-for-CQs-and-QPs.patch
mm-Export-symbols-needed-by-DI-MMAP.patch
net-9p-add-privport-option-to-9p-tcp-transport.patch
net-9p-Initialize-opts-privport-as-it-should-be.patch
net-9p-Remove-ib_get_dma_mr-calls.patch
Revert-scsi-sas-provide-stub-implementation-for-scsi_is_sas_rphy.patch
Revert-scsi-sas-remove-is_sas_attached.patch
Revert-scsi-ses-use-scsi_is_sas_rphy-instead-of-is_sas_attached.patch

Comment by Amir Shehata (Inactive) [ 27/Feb/17 ]

This doesn't look like a lustre patched kernel. 

I would expect the following patches to be applied:
raid5-mmp-unplug-dev-3.7.patch
dev_read_only-3.7.patch
blkdev_tunables-3.8.patch
jbd2-fix-j_list_lock-unlock-3.10-rhel7.patch

According to Andreas LLNL doesn't patch the kernel for lustre anymore because they use ZFS.

Out of those patches jdb2-fix is the real bug fixer.

And according to the crash log you have listed in the ticket this could be your problem.

Please make sure to patch the kernel properly for the server nodes.

Comment by Ruth Klundt (Inactive) [ 28/Feb/17 ]

Thanks for the diagnosis, you can close this bug.

Comment by Amir Shehata (Inactive) [ 28/Feb/17 ]

Issue due to a non lustre patched kernel.

Comment by Ruth Klundt (Inactive) [ 01/Mar/17 ]

FYI, the jbd2 patch would appear to be obsolete for rhel7.3, it was generated against 3.10.0-327.36.1. The kernel I'm currently looking at is 3.10.0-514, and there is only one spin_lock before the if-else block, and one unlock after. The patch shows one spin_lock within each of the if-else branches.

I'm surprised if that patch is not failing, even against rhel stock kernels.

Comment by Ruth Klundt (Inactive) [ 01/Mar/17 ]

sorry ignore the last comment, I was not looking in a redhat kernel. 

Comment by Amir Shehata (Inactive) [ 03/Mar/17 ]

Also note that as far as I can tell 2.8 only supports the following RHEL 7.x:

3.10-rhel7.series       3.10.0-327.3.1.el7  (RHEL 7.2)

full list of kernel version support for 2.8.0

2.6-rhel6.series        2.6.32-431.29.2.el6 (RHEL 6.5)
2.6-rhel6.series        2.6.32-504.30.3.el6 (RHEL 6.6)
2.6-rhel6.series        2.6.32-573.12.1.el6 (RHEL 6.7)
3.10-rhel7.series       3.10.0-327.3.1.el7  (RHEL 7.2)
3.0-sles11sp3.series    3.0.101-0.47.71     (SLES11 SP3)
3.0-sles11sp3.series    3.0.101-68          (SLES11 SP4)
Generated at Sat Feb 10 02:23:36 UTC 2024 using Jira 9.4.14#940014-sha1:734e6822bbf0d45eff9af51f82432957f73aa32c.