[LU-3102] kernel BUG at fs/jbd2/transaction.c:1033 Created: 03/Apr/13  Updated: 14/Dec/21  Resolved: 14/Dec/21

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

Type: Bug Priority: Major
Reporter: Minh Diep Assignee: Zhenyu Xu
Resolution: Cannot Reproduce Votes: 0
Labels: None
Environment:

wide striping

Issue Links:
Related
is related to LU-8527 Lustre 2.8 server crashed on bring up... Closed
Severity: 3
Rank (Obsolete): 7542

 Description   

While testing wide-striping by creating 200 osts per oss, 2 oss, I ran the following. Note that I see the stripe count to 500 which is more than 400 total osts.

while true; do
rm -rf /mnt/lustre/dir$(hostname)
for i in $(seq 1 500); do
DIR=/mnt/lustre/dir$(hostname)/dir$i
mkdir -p $DIR
lfs setstripe -c $i $DIR
touch $DIR/lustre
ls -l $DIR/lustre
lfs getstripe $DIR > /dev/null
done
done

-----------[ cut here ]-----------
kernel BUG at fs/jbd2/transaction.c:1033!
invalid opcode: 0000 1 SMP
last sysfs file: /sys/devices/pci0000:00/0000:00:1a.1/usb4/4-1/speed
CPU 1
Modules linked in: osp(U) lod(U) mdt(U) mgs(U) mgc(U) fsfilt_ldiskfs(U) osd_ldiskfs(U) lquota(U) mdd(U) lustre(U) lov(U) osc(U) mdc(U) fid(U) fld(U) ksocklnd(U) ptlrpc(U) obdclass(U) lnet(U) lvfs(U) sha512_generic sha256_generic libcfs(U) ldiskfs(U) jbd2 nfs fscache nfsd lockd nfs_acl auth_rpcgss exportfs autofs4 sunrpc cpufreq_ondemand acpi_cpufreq freq_table mperf ib_ipoib rdma_ucm ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm ib_addr ipv6 ib_sa igb mlx4_ib ib_mad ib_core mlx4_en mlx4_core microcode serio_raw i2c_i801 i2c_core sg iTCO_wdt iTCO_vendor_support ioatdma dca i7core_edac edac_core shpchp ext3 jbd mbcache sd_mod crc_t10dif ahci dm_mirror dm_region_hash dm_log dm_mod [last unloaded: scsi_wait_scan]

Pid: 2344, comm: mdt00_004 Not tainted 2.6.32-279.19.1.el6_lustre.gc4681d8.x86_64 #1 Supermicro X8DTT/X8DTT
RIP: 0010:[<ffffffffa040c86d>] [<ffffffffa040c86d>] jbd2_journal_dirty_metadata+0x10d/0x150 [jbd2]
RSP: 0018:ffff88020aad75c0 EFLAGS: 00010246
RAX: ffff8801be71ac80 RBX: ffff8801fab4b978 RCX: ffff88020c1e5610
RDX: 0000000000000000 RSI: ffff88020c1e5610 RDI: 0000000000000000
RBP: ffff88020aad75e0 R08: ffff88020c1e5610 R09: fdd5e22cf78d8402
R10: 0000000000000000 R11: 0000000000000000 R12: ffff880241019a58
R13: ffff88020c1e5610 R14: ffff880215f16800 R15: 0000000000000000
FS: 00007f0d793f1700(0000) GS:ffff880032e20000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 00007fff56043e40 CR3: 000000032e70c000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process mdt00_004 (pid: 2344, threadinfo ffff88020aad6000, task ffff88020aae5500)
Stack:
ffff8801fab4b978 ffffffffa0472a50 ffff88020c1e5610 0000000000000000
<d> ffff88020aad7620 ffffffffa04321bb ffffffffa0472a30 ffff8801fab4b978
<d> ffff88032b127000 ffff8801e9029c50 ffff8801e9029b80 ffff88020aad76a0
Call Trace:
[<ffffffffa04321bb>] __ldiskfs_handle_dirty_metadata+0x7b/0x100 [ldiskfs]
[<ffffffffa043cd22>] ldiskfs_mark_iloc_dirty+0x332/0x5b0 [ldiskfs]
[<ffffffffa043e4a3>] ldiskfs_mark_inode_dirty+0x83/0x1f0 [ldiskfs]
[<ffffffffa043fb90>] ldiskfs_dirty_inode+0x40/0x60 [ldiskfs]
[<ffffffffa0d153f7>] osd_ldiskfs_write_record+0x2d7/0x330 [osd_ldiskfs]
[<ffffffffa0d16058>] osd_write+0x148/0x2a0 [osd_ldiskfs]
[<ffffffffa0623eb5>] dt_record_write+0x45/0x130 [obdclass]
[<ffffffffa0c32cd0>] ? md_capainfo+0x20/0x30 [mdd]
[<ffffffffa05f088e>] llog_osd_write_blob+0x2fe/0x730 [obdclass]
[<ffffffffa05f42c1>] llog_osd_write_rec+0x821/0x1200 [obdclass]
[<ffffffffa0d0f9c5>] ? iam_path_fini+0x25/0x30 [osd_ldiskfs]
[<ffffffffa05c03b8>] llog_write_rec+0xc8/0x290 [obdclass]
[<ffffffffa05c857d>] llog_cat_add_rec+0xad/0x480 [obdclass]
[<ffffffffa05c01b1>] llog_add+0x91/0x1d0 [obdclass]
[<ffffffffa0f1fef7>] osp_sync_add_rec+0x247/0x8a0 [osp]
[<ffffffffa0d0d0cf>] ? osd_oi_delete+0x2af/0x4b0 [osd_ldiskfs]
[<ffffffffa0f205fb>] osp_sync_add+0x7b/0x80 [osp]
[<ffffffffa0f144e6>] osp_object_destroy+0x106/0x150 [osp]
[<ffffffffa0ed0347>] lod_object_destroy+0x1a7/0x350 [lod]
[<ffffffffa0c2ba19>] mdd_finish_unlink+0x229/0x380 [mdd]
[<ffffffffa0c2e748>] mdd_unlink+0x9c8/0xe20 [mdd]
[<ffffffffa0e19a18>] mdo_unlink+0x18/0x50 [mdt]
[<ffffffffa0e1ccd9>] mdt_reint_unlink+0x739/0xfd0 [mdt]
[<ffffffffa0e196d1>] mdt_reint_rec+0x41/0xe0 [mdt]
[<ffffffffa0e12d53>] mdt_reint_internal+0x4e3/0x7d0 [mdt]
[<ffffffffa0e13084>] mdt_reint+0x44/0xe0 [mdt]
[<ffffffffa0e01078>] mdt_handle_common+0x648/0x1660 [mdt]
[<ffffffffa0e3d125>] mds_regular_handle+0x15/0x20 [mdt]
[<ffffffffa07b51dc>] ptlrpc_server_handle_request+0x41c/0xdf0 [ptlrpc]
[<ffffffffa04b45de>] ? cfs_timer_arm+0xe/0x10 [libcfs]
[<ffffffffa04c5d8f>] ? lc_watchdog_touch+0x6f/0x170 [libcfs]
[<ffffffffa07ac819>] ? ptlrpc_wait_event+0xa9/0x290 [ptlrpc]
[<ffffffff81052223>] ? __wake_up+0x53/0x70
[<ffffffffa07b6725>] ptlrpc_main+0xb75/0x1870 [ptlrpc]
[<ffffffffa07b5bb0>] ? ptlrpc_main+0x0/0x1870 [ptlrpc]
[<ffffffff8100c0ca>] child_rip+0xa/0x20
[<ffffffffa07b5bb0>] ? ptlrpc_main+0x0/0x1870 [ptlrpc]
[<ffffffffa07b5bb0>] ? ptlrpc_main+0x0/0x1870 [ptlrpc]
[<ffffffff8100c0c0>] ? child_rip+0x0/0x20
Code: c6 9c 03 00 00 4c 89 f7 e8 a1 ff 0d e1 48 8b 33 ba 01 00 00 00 4c 89 e7 e8 11 ec ff ff 4c 89 f0 66 ff 00 66 66 90 e9 73 ff ff ff <0f> 0b eb fe 0f 0b eb fe 0f 0b 66 0f 1f 84 00 00 00 00 00 eb f5
RIP [<ffffffffa040c86d>] jbd2_journal_dirty_metadata+0x10d/0x150 [jbd2]
RSP <ffff88020aad75c0>
Initializing cgroup subsys cpuset
Initializing cgroup subsys cpu
Linux version 2.6.32-279.19.1.el6_lustre.gc4681d8.x86_64 (jenkins@builder-1-sde1-el6-x8664.lab.whamcloud.com) (gcc version 4.4.6 20120305 (Red Hat 4.4.6-4) (GCC) ) #1 SMP Wed Mar 6 18:02:10 PST 2013
Command line: ro root=UUID=7bb27ca3-4652-470c-b9ba-d628c22b7754 rd_NO_LUKS rd_NO_LVM LANG=en_US.UTF-8 rd_NO_MD console=ttyS0,115200 SYSFONT=latarcyrheb-sun16 KEYBOARDTYPE=pc KEYTABLE=us rd_NO_DM irqpoll nr_cpus=1 reset_devices cgroup_disable=memory mce=off memmap=exactmap memmap=563K@64K memmap=131513K@49715K elfcorehdr=181228K memmap=64K$0K memmap=13K$627K memmap=104K$920K memmap=8K$3136952K memmap=56K#3136960K memmap=328K#3137016K memmap=64K$3137344K memmap=8272K$3137456K memmap=262144K$3670016K memmap=4K$4175872K memmap=4096K$4190208K
KERNEL supported cpus:
Intel GenuineIntel
AMD AuthenticAMD

 Comments   
Comment by Minh Diep [ 03/Apr/13 ]

core dump available at /scratch/ftp/uploads/LU-3102

Comment by Oleg Drokin [ 04/Apr/13 ]

This issue seems to be resurrection of LU-601
Crash location is J_ASSERT_JH(jh, handle->h_buffer_credits > 0); in jbd2_journal_dirty_metadata

I see LU-601 landed in 2.1 and 2.2, so osd or recent llog changes potentially reintroduced the issue?

Comment by Oleg Drokin [ 04/Apr/13 ]

actually might not be exactly like lu-601, but certainly we have a case of underclaiming some transaction credits anyway

Comment by Peter Jones [ 04/Apr/13 ]

Bobijam

Does this seem to be related to LU-601?

Peter

Comment by Zhenyu Xu [ 07/Apr/13 ]

I think it's not related to LU-601.

Minh, when you say "Note that I see the stripe count to 500 which is more than 400 total osts.", what did you mean? the 'lfs getstripe' shows 500 in stripe count field?

Comment by Swapnil Pimpale (Inactive) [ 16/Apr/14 ]

I hit this when trying to preallocate a 20GB file using fallocate(2). I was trying the fallocate(2) code from this patch: http://review.whamcloud.com/#/c/9275/10
The setup had 4 OSTs.

  1. lfs getstripe /mnt/lustre/
    /mnt/lustre/
    stripe_count: 4 stripe_size: 1048576 stripe_offset: -1
  1. git describe
    2.5.57-68-g4b07229

The following is the stack-trace that I got.

<4>-----------[ cut here ]-----------
<2>kernel BUG at fs/jbd2/transaction.c:1033!
<4>invalid opcode: 0000 1 SMP
<4>last sysfs file: /sys/devices/pci0000:00/0000:00:09.0/0000:05:00.0/host24/scsi_host/host24/local_ib_port
<4>CPU 13
<4>Modules linked in: lustre(U) ofd(U) osp(U) lod(U) ost(U) mdt(U) mdd(U) mgs(U) nodemap(U) osd_ldiskfs(U) ldiskfs(U) exportfs lquota(U) lfsck(U) jbd obdecho(U) mgc(U) lov(U) osc(U) mdc(U) lmv(U) fid(U) fld(U) ptlrpc(U) obdclass(U) ksocklnd(U) lnet(U) sha512_generic sha256_generic crc32c_intel libcfs(U) autofs4 ib_srp(U) scsi_transport_srp scsi_tgt sunrpc dm_multipath rdma_ucm(U) ib_ucm(U) rdma_cm(U) iw_cm(U) ib_addr(U) ib_ipoib(U) ib_cm(U) ib_sa(U) ipv6 ib_uverbs(U) ib_umad(U) iw_nes(U) libcrc32c iw_cxgb3(U) cxgb3(U) mlx4_ib(U) ib_mthca(U) ib_mad(U) ib_core(U) ipmi_devintf power_meter dcdbas microcode serio_raw iTCO_wdt iTCO_vendor_support ses enclosure sg mlx4_en(U) mlx4_core(U) i7core_edac edac_core bnx2 ext4 jbd2 mbcache sr_mod cdrom sd_mod crc_t10dif pata_acpi ata_generic ata_piix megaraid_sas wmi dm_mirror dm_region_hash dm_log dm_mod [last unloaded: scsi_wait_scan]
<4>
<4>Pid: 21228, comm: ll_ost_io02_020 Not tainted 2.6.32-358.18.1.el6_lustre.es50.x86_64 #1 Dell Inc. PowerEdge R610/0F0XJ6
<4>RIP: 0010:[<ffffffffa008b8ad>] [<ffffffffa008b8ad>] jbd2_journal_dirty_metadata+0x10d/0x150 [jbd2]
<4>RSP: 0018:ffff88156b1596f0 EFLAGS: 00010246
<4>RAX: ffff880ed5be42c0 RBX: ffff880843671d38 RCX: ffff88181371f9b8
<4>RDX: 0000000000000000 RSI: ffff88181371f9b8 RDI: 0000000000000000
<4>RBP: ffff88156b159710 R08: 0000000000000000 R09: e7cea7e9177ef002
<4>R10: ffff8817fe82d000 R11: 0000000000000004 R12: ffff880c6fed90b8
<4>R13: ffff88181371f9b8 R14: ffff88184ae0b000 R15: ffff880843671d38
<4>FS: 0000000000000000(0000) GS:ffff8800282c0000(0000) knlGS:0000000000000000
<4>CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
<4>CR2: 00007f99eca16ee0 CR3: 0000003057f60000 CR4: 00000000000007e0
<4>DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
<4>DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
<4>Process ll_ost_io02_020 (pid: 21228, threadinfo ffff88156b158000, task ffff88156b157540)
<4>Stack:
<4> ffff880843671d38 ffffffffa0caf230 ffff88181371f9b8 0000000000000000
<4><d> ffff88156b159750 ffffffffa0c6f0eb ffff88156b159750 ffffffff8128cdb8
<4><d> ffff8818473ddf38 ffff8817fe82d400 ffff88181371f9b8 ffff8817fe82d000
<4>Call Trace:
<4> [<ffffffffa0c6f0eb>] __ldiskfs_handle_dirty_metadata+0x7b/0x100 [ldiskfs]
<4> [<ffffffff8128cdb8>] ? __percpu_counter_add+0x68/0x90
<4> [<ffffffffa0c84554>] ldiskfs_mb_mark_diskspace_used+0x2c4/0x300 [ldiskfs]
<4> [<ffffffffa0c8ba3f>] ldiskfs_mb_new_blocks+0x30f/0x620 [ldiskfs]
<4> [<ffffffffa0c712e1>] ? ldiskfs_ext_find_extent+0x141/0x330 [ldiskfs]
<4> [<ffffffffa0c736e1>] ldiskfs_ext_get_blocks+0x4f1/0x14b0 [ldiskfs]
<4> [<ffffffffa008c2c4>] ? do_get_write_access+0x3b4/0x520 [jbd2]
<4> [<ffffffff811b59d7>] ? __find_get_block+0x97/0xe0
<4> [<ffffffffa0c7a76d>] ? ldiskfs_mark_iloc_dirty+0x30d/0x630 [ldiskfs]
<4> [<ffffffffa0c7ca39>] ldiskfs_get_blocks+0xf9/0x2a0 [ldiskfs]
<4> [<ffffffffa0c7bf93>] ? ldiskfs_mark_inode_dirty+0x83/0x1f0 [ldiskfs]
<4> [<ffffffffa0c70d74>] ldiskfs_fallocate+0x204/0x3d0 [ldiskfs]
<4> [<ffffffffa0ca4578>] ? __ldiskfs_journal_stop+0x68/0xa0 [ldiskfs]
<4> [<ffffffffa0d1030d>] osd_prealloc+0x1bd/0x480 [osd_ldiskfs]
<4> [<ffffffffa0fe11ac>] ofd_object_prealloc+0x38c/0x580 [ofd]
<4> [<ffffffffa0fd0972>] ofd_prealloc_hdl+0x1b2/0x6d0 [ofd]
<4> [<ffffffffa07762ee>] ? lustre_pack_reply_flags+0xae/0x1f0 [ptlrpc]
<4> [<ffffffffa07d89ac>] tgt_request_handle+0x23c/0xac0 [ptlrpc]
<4> [<ffffffffa078798a>] ptlrpc_main+0xd1a/0x1980 [ptlrpc]
<4> [<ffffffffa0786c70>] ? ptlrpc_main+0x0/0x1980 [ptlrpc]
<4> [<ffffffff81096a36>] kthread+0x96/0xa0
<4> [<ffffffff8100c0ca>] child_rip+0xa/0x20
<4> [<ffffffff810969a0>] ? kthread+0x0/0xa0
<4> [<ffffffff8100c0c0>] ? child_rip+0x0/0x20
<4>Code: c6 9c 03 00 00 4c 89 f7 e8 b1 55 48 e1 48 8b 33 ba 01 00 00 00 4c 89 e7 e8 11 ec ff ff 4c 89 f0 66 ff 00 66 66 90 e9 73 ff ff ff <0f> 0b eb fe 0f 0b eb fe 0f 0b 66 0f 1f 84 00 00 00 00 00 eb f5
<1>RIP [<ffffffffa008b8ad>] jbd2_journal_dirty_metadata+0x10d/0x150 [jbd2]
<4> RSP <ffff88156b1596f0>

Generated at Sat Feb 10 06:23:00 UTC 2024 using Jira 9.4.14#940014-sha1:734e6822bbf0d45eff9af51f82432957f73aa32c.