Marcus Schull
2009-Apr-02 02:21 UTC
[Lustre-discuss] Lustre 1.6.7 kernel panics when umounting MDTs
Lustre Admins,
We have recently had 2 odd events I am keen to get some feedback on.
1) We recently had a filesystem go read-only (noticed on the client)
due to an "inode out of bounds" error as reported in the server logs.
Please see below for log and fsck details.
2) In order to correct the issue (ie remount the device read-write), I
attempted to umount that device (intending to do a quick fsck as the
device was the filesystem''s MDT, and then remounting) - however this
action caused a kernel panic.
I have experienced these kernel panics quite a few times in the past
when umounting MDTs and OSTs in similar situations - when one or more
have gone read-only, but this is the first with the 1.6.7 kernel.
The resulting panic required a reboot and fsck on all mounted LUNs -
which at present is about 15 TB (in a few separate filesystems).
The server is currently acting has the MGS, MDT and OST partitions for
all lustre filesystems. Unfortunately we have still not had the
chance to separate those roles onto different servers.
The server is running 64 bit RHEL 5.2 with the latest lustre kernel
(1.6.7) and associated packages. It runs on a SUN blade with 4 AMD
cores and 16 GB RAM.
[ kernel version: 2.6.18-92.1.17.el5_lustre.1.6.7smp #1 SMP Mon Feb 9
19:56:55 MST 2009 x86_64 x86_64 x86_64 GNU/Linux ]
All clients are also running RHEL 5.2/5.3 with unpatched kernels and
the latest lustre packages (1.6.7).
[ client kernel: 2.6.18-92.1.17.el5 #1 SMP Wed Oct 22 04:19:38 EDT
2008 x86_64 x86_64 x86_64 GNU/Linux ]
I look forward to any advice regarding the unusual error (1) or any
procedures to follow in order to prevent the kernel panics.
Thanks in advance.
Marcus Schull,
Systems Administrator
IMB, University of Queensland
Lustre server /var/log/messages:
Apr 1 19:03:04 lustre1 kernel: LDISKFS-fs error (device dm-37):
ldiskfs_add_entry: bad entry in directory #12686675: inode out of
bounds - offset=0, inode=2807365078, rec_len=4096, name_len=36
Apr 1 19:03:04 lustre1 kernel: Remounting filesystem read-only
Apr 1 19:03:04 lustre1 kernel: LDISKFS-fs error (device dm-37) in
start_transaction: Readonly filesystem
Apr 1 19:03:04 lustre1 kernel: LustreError: 8059:0:(fsfilt-ldiskfs.c:
1231:fsfilt_ldiskfs_write_record()) can''t start transaction for 18
blocks (128 bytes)
Apr 1 19:03:04 lustre1 kernel: LustreError: 8059:0:(mds_reint.c:
230:mds_finish_transno()) @@@ wrote trans #0 rc -5 client
5142a23c-5adc-d4e8-4375-1b1028fe8e7d at idx 0: err = -30
req at ffff8101771ba000 x28445861/t0 o101->51
42a23c-5adc-d4e8-4375-1b1028fe8e7d at NET_0x200008266732c_UUID:0/0 lens
512/568 e 0 to 0 dl 1238576684 ref 1 fl Interpret:/0/0 rc 0/0
Apr 1 19:03:04 lustre1 kernel: LustreError: 8059:0:(mds_reint.c:
238:mds_finish_transno()) wrote objids: err = 0
Apr 1 19:03:04 lustre1 kernel: LustreError: 11330:0:(fsfilt-ldiskfs.c:
280:fsfilt_ldiskfs_start()) error starting handle for op 8 (33
credits): rc -30
Apr 1 19:03:04 lustre1 kernel: LustreError: 11330:0:(fsfilt-ldiskfs.c:
280:fsfilt_ldiskfs_start()) error starting handle for op 8 (33
credits): rc -30
Apr 1 19:03:04 lustre1 kernel: LustreError: 11330:0:(mds_reint.c:
154:mds_finish_transno()) fsfilt_start: -30
Apr 1 19:03:04 lustre1 kernel: LustreError: 11337:0:(mds_reint.c:
154:mds_finish_transno()) fsfilt_start: -30
fsck output of filesystem with error reported above:
[root at lustre1 ~]# e2fsck /dev/mapper/mpath11p1
e2fsck 1.40.11.sun1 (17-June-2008)
qfab-MDT0000: recovering journal
qfab-MDT0000 contains a file system with errors, check forced.
Pass 1: Checking inodes, blocks, and sizes
Inode 12686675, i_size is 28672, should be 65536. Fix<y>? yes
Pass 2: Checking directory structure
Problem in HTREE directory inode 12686675: node (0) has an unordered
hash table
Clear HTree index<y>? yes
Entry ''(=fM-''^\^@
^@M-~^JM-XM-''p^H$^@:{M-XM-''^H^G$^@TM-O^IM-(x^L(^@t^W
$M-('' in /ROOT/data1/offindex (12686675) has invalid inode #:
2807365078.
Clear<y>? yes
Pass 3: Checking directory connectivity
Pass 3A: Optimizing directories
Pass 4: Checking reference counts
Unattached inode 12681396
Connect to /lost+found<y>? yes
Inode 12681396 ref count is 2, should be 1. Fix<y>? yes
Unattached inode 12681397
Connect to /lost+found<y>? yes
... etc
-------
Out of interest, we are also getting occasional "soft CPU lockups",
although these don''t appear to be causing problems at present . . .
Mar 31 08:57:36 lustre1 kernel: BUG: soft lockup - CPU#0 stuck for
10s! [ll_mdt_rdpg_11:11332]
Mar 31 08:57:36 lustre1 kernel: CPU 0:
Mar 31 08:57:36 lustre1 kernel: Modules linked in: obdfilter(U) ost(U)
mds(U) fsfilt_ldiskfs(U) mgs(U) mgc(U) ldiskfs(U) crc16(U) lustre(U)
lov(U) mdc(U) lquota(U) osc(U) ksocklnd(U) ptlrpc(U) obdclass(U)
lnet(U) lvfs(U) li
bcfs(U) ip_conntrack_netbios_ns(U) ipt_REJECT(U) xt_tcpudp(U)
xt_state(U) ip_conntrack(U) nfnetlink(U) iptable_filter(U)
ip_tables(U) x_tables(U) cpufreq_ondemand(U) dm_round_robin(U)
dm_multipath(U) video(U) sbs(U) backlig
ht(U) i2c_ec(U) button(U) battery(U) asus_acpi(U) acpi_memhotplug(U)
ac(U) parport_pc(U) lp(U) parport(U) sr_mod(U) joydev(U) cdrom(U)
pata_acpi(U) libata(U) i2c_nforce2(U) k8temp(U) shpchp(U) pcspkr(U)
i2c_core(U) hwmon(U)
k8_edac(U) sg(U) forcedeth(U) edac_mc(U) serio_raw(U) e1000e(U)
dm_snapshot(U) dm_zero(U) dm_mirror(U) dm_mod(U) usb_storage(U)
qla2xxx(U) scsi_transport_fc(U) mptsas(U) mptscsih(U) mptbase(U)
scsi_transport_sas(U) sd_mod(
U) scsi_mod(U) ext3(U) jbd(U) uhci_hcd(U) ohci_hcd(U) ehci_hcd(U)
Mar 31 08:57:36 lustre1 kernel: Pid: 11332, comm: ll_mdt_rdpg_11
Tainted: G 2.6.18-92.1.17.el5_lustre.1.6.7smp #1
Mar 31 08:57:36 lustre1 kernel: RIP: 0010:[<ffffffff800649e6>]
[<ffffffff800649e6>] _write_lock+0x7/0xf
Mar 31 08:57:36 lustre1 kernel: RSP: 0018:ffff81024f0e3928 EFLAGS:
00000246
Mar 31 08:57:36 lustre1 kernel: RAX: ffff81005ab05600 RBX:
0000000000002b10 RCX: 00000000000053b7
Mar 31 08:57:36 lustre1 kernel: RDX: fffffffffffff5e8 RSI:
ffffffff802f0d80 RDI: ffffc20000d1810c
Mar 31 08:57:36 lustre1 kernel: RBP: 0000000000000286 R08:
ffff810001006360 R09: ffff8100610996c0
Mar 31 08:57:36 lustre1 kernel: R10: 5a5a5a5a5a5a5a5a R11:
5a5a5a5a5a5a5a5a R12: 0000000000000286
Mar 31 08:57:36 lustre1 kernel: R13: ffff81024f0e38d0 R14:
ffff810061099718 R15: ffff8100610996c0
Mar 31 08:57:36 lustre1 kernel: FS: 00002b6a51d6d220(0000)
GS:ffffffff803ea000(0000) knlGS:00000000f7f326d0
Mar 31 08:57:36 lustre1 kernel: CS: 0010 DS: 0000 ES: 0000 CR0:
000000008005003b
Mar 31 08:57:36 lustre1 kernel: CR2: 00002b5047841000 CR3:
0000000000201000 CR4: 00000000000006e0
Mar 31 08:57:36 lustre1 kernel:
Mar 31 08:57:36 lustre1 kernel: Call Trace:
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff885893fe>] :obdclass:lustre_hash_for_each_empty+0x20e/0x290
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff8858fbf8>] :obdclass:class_disconnect+0x378/0x400
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff886055b0>] :ptlrpc:ldlm_cancel_locks_for_export_cb+0x0/0xc0
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff888fc05b>] :mds:mds_disconnect+0x11b/0x310
Mar 31 08:57:36 lustre1 kernel: [<ffffffff8003d514>] lock_timer_base
+0x1b/0x3c
Mar 31 08:57:36 lustre1 kernel: [<ffffffff8004a824>]
try_to_del_timer_sync+0x51/0x5a
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff8858bce4>] :obdclass:class_fail_export+0x384/0x4c0
Mar 31 08:57:36 lustre1 kernel: [<ffffffff888f4751>] :mds:mds_readpage
+0x1571/0x18a0
Mar 31 08:57:36 lustre1 kernel: [<ffffffff8853a5f0>] :lnet:LNetMDBind
+0x2c0/0x420
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff8863ef33>] :ptlrpc:ptl_send_buf+0x3f3/0x5b0
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff88645004>] :ptlrpc:lustre_msg_set_timeout+0x34/0x110
Mar 31 08:57:36 lustre1 kernel: [<ffffffff8008abb9>]
default_wake_function+0x0/0xe
Mar 31 08:57:36 lustre1 kernel: [<ffffffff888f870b>] :mds:mds_handle
+0x216b/0x4d30
Mar 31 08:57:36 lustre1 kernel: [<ffffffff800d3fc7>] free_block+0x11c/
0x13b
Mar 31 08:57:36 lustre1 kernel: [<ffffffff80143809>] __next_cpu
+0x19/0x28
Mar 31 08:57:36 lustre1 kernel: [<ffffffff80143809>] __next_cpu
+0x19/0x28
Mar 31 08:57:36 lustre1 kernel: [<ffffffff800898e3>]
find_busiest_group+0x20d/0x621
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff886435a5>] :ptlrpc:lustre_msg_get_conn_cnt+0x35/0xf0
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff8864bcfa>] :ptlrpc:ptlrpc_server_request_get+0x6a/0x150
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff8864db7d>] :ptlrpc:ptlrpc_check_req+0x1d/0x110
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff88650103>] :ptlrpc:ptlrpc_server_handle_request+0xa93/0x1150
Mar 31 08:57:36 lustre1 kernel: [<ffffffff80062f4b>] thread_return
+0x0/0xdf
Mar 31 08:57:36 lustre1 kernel: [<ffffffff8006d8a2>] do_gettimeofday
+0x40/0x8f
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff884f37c6>] :libcfs:lcw_update_time+0x16/0x100
Mar 31 08:57:36 lustre1 kernel: [<ffffffff800891f6>] __wake_up_common
+0x3e/0x68
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff886535f8>] :ptlrpc:ptlrpc_main+0x1218/0x13e0
Mar 31 08:57:36 lustre1 kernel: [<ffffffff8008abb9>]
default_wake_function+0x0/0xe
Mar 31 08:57:36 lustre1 kernel: [<ffffffff8005dfb1>] child_rip+0xa/0x11
Mar 31 08:57:36 lustre1 kernel:
[<ffffffff886523e0>] :ptlrpc:ptlrpc_main+0x0/0x13e0
Mar 31 08:57:37 lustre1 kernel: [<ffffffff8005dfa7>] child_rip+0x0/0x11
Mar 31 08:57:37 lustre1 kernel:
Mar 31 08:57:46 lustre1 kernel: BUG: soft lockup - CPU#0 stuck for
10s! [ll_mdt_rdpg_11:11332]
Mar 31 08:57:46 lustre1 kernel: CPU 0:
Jason Rappleye
2009-Apr-02 05:58 UTC
[Lustre-discuss] Lustre 1.6.7 kernel panics when umounting MDTs
Hi, On Apr 1, 2009, at 7:21 PM, Marcus Schull wrote:> Lustre Admins, > > > We have recently had 2 odd events I am keen to get some feedback on. > > 1) We recently had a filesystem go read-only (noticed on the client) > due to an "inode out of bounds" error as reported in the server logs. > Please see below for log and fsck details.It looks like you''re experiencing corruption described in bz 18695, which was also reported by us in bz 18889 and by TACC in bz 19029. At this point in time, Sun hasn''t made any official recommendations regarding this problem. If you can stomach it, I''m certain that Sun (and other sites experiencing this problem) would appreciate feedback on what the user whose data was corrupted was doing at the time. If you can reproduce the problem, even better. Unfortunately, by the time ldiskfs detects the corruption, it''s already happened - it is detecting corrupted metadata that has already been written to disk, not the instant at which the corruption is occurring. When we first discovered the corruption at our site, we had a user report errors when trying to perform ls and rm commands in a corrupted directory. ldiskfs did not report any errors. unmounting the MDT and running e2fsck on it produced the same type of errors you saw during your fsck. We remounted the MDT and later that day ldiskfs did produce the "inode out of bounds" error that you saw. So, either the corruption occurred again, or e2fsck didn''t fix the problem. This happened a day after upgrading to Lustre 1.6.7. We have since downgraded our servers to 1.6.6. We''re running SLES10 SP2 with kernel 2.6.16.60-0.35 + a few site specific patches for OOM handling (developed in house in conjunction with SGI) and one for improved SCSI error handling that came from Novell, through SGI. So, this problem doesn''t appear to be specific to the RHEL or SLES kernel, or to our patched kernel. It''s worth noting that we only saw this on the MDTs on a pair of filesystems. We ran e2fsck against all of the OSTs (a total of 90) and all came back clean. Is there anyone else out there running 1.6.7 that is seeing this problem as well? It might be a good idea to unmount your MDTs and run e2fsck against them, and report the results back to the mailing list. j> > > 2) In order to correct the issue (ie remount the device read-write), I > attempted to umount that device (intending to do a quick fsck as the > device was the filesystem''s MDT, and then remounting) - however this > action caused a kernel panic. > > I have experienced these kernel panics quite a few times in the past > when umounting MDTs and OSTs in similar situations - when one or more > have gone read-only, but this is the first with the 1.6.7 kernel. > The resulting panic required a reboot and fsck on all mounted LUNs - > which at present is about 15 TB (in a few separate filesystems). > > The server is currently acting has the MGS, MDT and OST partitions for > all lustre filesystems. Unfortunately we have still not had the > chance to separate those roles onto different servers. > The server is running 64 bit RHEL 5.2 with the latest lustre kernel > (1.6.7) and associated packages. It runs on a SUN blade with 4 AMD > cores and 16 GB RAM. > [ kernel version: 2.6.18-92.1.17.el5_lustre.1.6.7smp #1 SMP Mon Feb 9 > 19:56:55 MST 2009 x86_64 x86_64 x86_64 GNU/Linux ] > > All clients are also running RHEL 5.2/5.3 with unpatched kernels and > the latest lustre packages (1.6.7). > [ client kernel: 2.6.18-92.1.17.el5 #1 SMP Wed Oct 22 04:19:38 EDT > 2008 x86_64 x86_64 x86_64 GNU/Linux ] > > > I look forward to any advice regarding the unusual error (1) or any > procedures to follow in order to prevent the kernel panics. > > > Thanks in advance. > > Marcus Schull, > Systems Administrator > IMB, University of Queensland > > > > > > > Lustre server /var/log/messages: > > Apr 1 19:03:04 lustre1 kernel: LDISKFS-fs error (device dm-37): > ldiskfs_add_entry: bad entry in directory #12686675: inode out of > bounds - offset=0, inode=2807365078, rec_len=4096, name_len=36 > Apr 1 19:03:04 lustre1 kernel: Remounting filesystem read-only > Apr 1 19:03:04 lustre1 kernel: LDISKFS-fs error (device dm-37) in > start_transaction: Readonly filesystem > Apr 1 19:03:04 lustre1 kernel: LustreError: 8059:0:(fsfilt-ldiskfs.c: > 1231:fsfilt_ldiskfs_write_record()) can''t start transaction for 18 > blocks (128 bytes) > Apr 1 19:03:04 lustre1 kernel: LustreError: 8059:0:(mds_reint.c: > 230:mds_finish_transno()) @@@ wrote trans #0 rc -5 client > 5142a23c-5adc-d4e8-4375-1b1028fe8e7d at idx 0: err = -30 > req at ffff8101771ba000 x28445861/t0 o101->51 > 42a23c-5adc-d4e8-4375-1b1028fe8e7d at NET_0x200008266732c_UUID:0/0 lens > 512/568 e 0 to 0 dl 1238576684 ref 1 fl Interpret:/0/0 rc 0/0 > Apr 1 19:03:04 lustre1 kernel: LustreError: 8059:0:(mds_reint.c: > 238:mds_finish_transno()) wrote objids: err = 0 > Apr 1 19:03:04 lustre1 kernel: LustreError: 11330:0:(fsfilt- > ldiskfs.c: > 280:fsfilt_ldiskfs_start()) error starting handle for op 8 (33 > credits): rc -30 > Apr 1 19:03:04 lustre1 kernel: LustreError: 11330:0:(fsfilt- > ldiskfs.c: > 280:fsfilt_ldiskfs_start()) error starting handle for op 8 (33 > credits): rc -30 > Apr 1 19:03:04 lustre1 kernel: LustreError: 11330:0:(mds_reint.c: > 154:mds_finish_transno()) fsfilt_start: -30 > Apr 1 19:03:04 lustre1 kernel: LustreError: 11337:0:(mds_reint.c: > 154:mds_finish_transno()) fsfilt_start: -30 > > > > fsck output of filesystem with error reported above: > > [root at lustre1 ~]# e2fsck /dev/mapper/mpath11p1 > e2fsck 1.40.11.sun1 (17-June-2008) > qfab-MDT0000: recovering journal > qfab-MDT0000 contains a file system with errors, check forced. > Pass 1: Checking inodes, blocks, and sizes > Inode 12686675, i_size is 28672, should be 65536. Fix<y>? yes > > Pass 2: Checking directory structure > Problem in HTREE directory inode 12686675: node (0) has an unordered > hash table > Clear HTree index<y>? yes > > Entry ''(=fM-''^\^@ ^@M-~^JM-XM-''p^H$^@:{M-XM-''^H^G$^@TM-O^IM-(x^L(^@t^W > $M-('' in /ROOT/data1/offindex (12686675) has invalid inode #: > 2807365078. > Clear<y>? yes > > Pass 3: Checking directory connectivity > Pass 3A: Optimizing directories > Pass 4: Checking reference counts > Unattached inode 12681396 > Connect to /lost+found<y>? yes > > Inode 12681396 ref count is 2, should be 1. Fix<y>? yes > > Unattached inode 12681397 > Connect to /lost+found<y>? yes > > ... etc > > > > > ------- > > Out of interest, we are also getting occasional "soft CPU lockups", > although these don''t appear to be causing problems at present . . . > > Mar 31 08:57:36 lustre1 kernel: BUG: soft lockup - CPU#0 stuck for > 10s! [ll_mdt_rdpg_11:11332] > Mar 31 08:57:36 lustre1 kernel: CPU 0: > Mar 31 08:57:36 lustre1 kernel: Modules linked in: obdfilter(U) ost(U) > mds(U) fsfilt_ldiskfs(U) mgs(U) mgc(U) ldiskfs(U) crc16(U) lustre(U) > lov(U) mdc(U) lquota(U) osc(U) ksocklnd(U) ptlrpc(U) obdclass(U) > lnet(U) lvfs(U) li > bcfs(U) ip_conntrack_netbios_ns(U) ipt_REJECT(U) xt_tcpudp(U) > xt_state(U) ip_conntrack(U) nfnetlink(U) iptable_filter(U) > ip_tables(U) x_tables(U) cpufreq_ondemand(U) dm_round_robin(U) > dm_multipath(U) video(U) sbs(U) backlig > ht(U) i2c_ec(U) button(U) battery(U) asus_acpi(U) acpi_memhotplug(U) > ac(U) parport_pc(U) lp(U) parport(U) sr_mod(U) joydev(U) cdrom(U) > pata_acpi(U) libata(U) i2c_nforce2(U) k8temp(U) shpchp(U) pcspkr(U) > i2c_core(U) hwmon(U) > k8_edac(U) sg(U) forcedeth(U) edac_mc(U) serio_raw(U) e1000e(U) > dm_snapshot(U) dm_zero(U) dm_mirror(U) dm_mod(U) usb_storage(U) > qla2xxx(U) scsi_transport_fc(U) mptsas(U) mptscsih(U) mptbase(U) > scsi_transport_sas(U) sd_mod( > U) scsi_mod(U) ext3(U) jbd(U) uhci_hcd(U) ohci_hcd(U) ehci_hcd(U) > Mar 31 08:57:36 lustre1 kernel: Pid: 11332, comm: ll_mdt_rdpg_11 > Tainted: G 2.6.18-92.1.17.el5_lustre.1.6.7smp #1 > Mar 31 08:57:36 lustre1 kernel: RIP: 0010:[<ffffffff800649e6>] > [<ffffffff800649e6>] _write_lock+0x7/0xf > Mar 31 08:57:36 lustre1 kernel: RSP: 0018:ffff81024f0e3928 EFLAGS: > 00000246 > Mar 31 08:57:36 lustre1 kernel: RAX: ffff81005ab05600 RBX: > 0000000000002b10 RCX: 00000000000053b7 > Mar 31 08:57:36 lustre1 kernel: RDX: fffffffffffff5e8 RSI: > ffffffff802f0d80 RDI: ffffc20000d1810c > Mar 31 08:57:36 lustre1 kernel: RBP: 0000000000000286 R08: > ffff810001006360 R09: ffff8100610996c0 > Mar 31 08:57:36 lustre1 kernel: R10: 5a5a5a5a5a5a5a5a R11: > 5a5a5a5a5a5a5a5a R12: 0000000000000286 > Mar 31 08:57:36 lustre1 kernel: R13: ffff81024f0e38d0 R14: > ffff810061099718 R15: ffff8100610996c0 > Mar 31 08:57:36 lustre1 kernel: FS: 00002b6a51d6d220(0000) > GS:ffffffff803ea000(0000) knlGS:00000000f7f326d0 > Mar 31 08:57:36 lustre1 kernel: CS: 0010 DS: 0000 ES: 0000 CR0: > 000000008005003b > Mar 31 08:57:36 lustre1 kernel: CR2: 00002b5047841000 CR3: > 0000000000201000 CR4: 00000000000006e0 > Mar 31 08:57:36 lustre1 kernel: > Mar 31 08:57:36 lustre1 kernel: Call Trace: > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff885893fe>] :obdclass:lustre_hash_for_each_empty+0x20e/0x290 > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff8858fbf8>] :obdclass:class_disconnect+0x378/0x400 > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff886055b0>] :ptlrpc:ldlm_cancel_locks_for_export_cb+0x0/0xc0 > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff888fc05b>] :mds:mds_disconnect+0x11b/0x310 > Mar 31 08:57:36 lustre1 kernel: [<ffffffff8003d514>] lock_timer_base > +0x1b/0x3c > Mar 31 08:57:36 lustre1 kernel: [<ffffffff8004a824>] > try_to_del_timer_sync+0x51/0x5a > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff8858bce4>] :obdclass:class_fail_export+0x384/0x4c0 > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff888f4751>] :mds:mds_readpage > +0x1571/0x18a0 > Mar 31 08:57:36 lustre1 kernel: [<ffffffff8853a5f0>] :lnet:LNetMDBind > +0x2c0/0x420 > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff8863ef33>] :ptlrpc:ptl_send_buf+0x3f3/0x5b0 > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff88645004>] :ptlrpc:lustre_msg_set_timeout+0x34/0x110 > Mar 31 08:57:36 lustre1 kernel: [<ffffffff8008abb9>] > default_wake_function+0x0/0xe > Mar 31 08:57:36 lustre1 kernel: [<ffffffff888f870b>] :mds:mds_handle > +0x216b/0x4d30 > Mar 31 08:57:36 lustre1 kernel: [<ffffffff800d3fc7>] free_block > +0x11c/ > 0x13b > Mar 31 08:57:36 lustre1 kernel: [<ffffffff80143809>] __next_cpu > +0x19/0x28 > Mar 31 08:57:36 lustre1 kernel: [<ffffffff80143809>] __next_cpu > +0x19/0x28 > Mar 31 08:57:36 lustre1 kernel: [<ffffffff800898e3>] > find_busiest_group+0x20d/0x621 > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff886435a5>] :ptlrpc:lustre_msg_get_conn_cnt+0x35/0xf0 > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff8864bcfa>] :ptlrpc:ptlrpc_server_request_get+0x6a/0x150 > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff8864db7d>] :ptlrpc:ptlrpc_check_req+0x1d/0x110 > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff88650103>] :ptlrpc:ptlrpc_server_handle_request+0xa93/0x1150 > Mar 31 08:57:36 lustre1 kernel: [<ffffffff80062f4b>] thread_return > +0x0/0xdf > Mar 31 08:57:36 lustre1 kernel: [<ffffffff8006d8a2>] do_gettimeofday > +0x40/0x8f > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff884f37c6>] :libcfs:lcw_update_time+0x16/0x100 > Mar 31 08:57:36 lustre1 kernel: [<ffffffff800891f6>] __wake_up_common > +0x3e/0x68 > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff886535f8>] :ptlrpc:ptlrpc_main+0x1218/0x13e0 > Mar 31 08:57:36 lustre1 kernel: [<ffffffff8008abb9>] > default_wake_function+0x0/0xe > Mar 31 08:57:36 lustre1 kernel: [<ffffffff8005dfb1>] child_rip+0xa/ > 0x11 > Mar 31 08:57:36 lustre1 kernel: > [<ffffffff886523e0>] :ptlrpc:ptlrpc_main+0x0/0x13e0 > Mar 31 08:57:37 lustre1 kernel: [<ffffffff8005dfa7>] child_rip > +0x0/0x11 > Mar 31 08:57:37 lustre1 kernel: > Mar 31 08:57:46 lustre1 kernel: BUG: soft lockup - CPU#0 stuck for > 10s! [ll_mdt_rdpg_11:11332] > Mar 31 08:57:46 lustre1 kernel: CPU 0: > > > _______________________________________________ > Lustre-discuss mailing list > Lustre-discuss at lists.lustre.org > http://lists.lustre.org/mailman/listinfo/lustre-discuss
Johann Lombardi
2009-Apr-02 09:29 UTC
[Lustre-discuss] Lustre 1.6.7 kernel panics when umounting MDTs
Hi, On Wed, Apr 01, 2009 at 10:58:23PM -0700, Jason Rappleye wrote:> Is there anyone else out there running 1.6.7 that is seeing this > problem as well? It might be a good idea to unmount your MDTs and run > e2fsck against them, and report the results back to the mailing list.Actually, what would really help us is to have a reproducer (we are still not able to reproduce the problem on our side). We also lack a corrupted MDT image (taken with e2image). So, if someone hits the same problem, please take an image of the MDT with e2image before running e2fsck, it would really help us. Thanks in advance. Cheers, Johann
Lundgren, Andrew
2009-Apr-02 14:49 UTC
[Lustre-discuss] Lustre 1.6.7 kernel panics when umounting MDTs
Has this problem only been seen in 1.6.7? We are currently running on 1.6.4.3.> -----Original Message----- > This happened a day after upgrading to Lustre 1.6.7. We have since > downgraded our servers to 1.6.6.
Johann Lombardi
2009-Apr-02 15:06 UTC
[Lustre-discuss] Lustre 1.6.7 kernel panics when umounting MDTs
On Thu, Apr 02, 2009 at 08:49:15AM -0600, Lundgren, Andrew wrote:> Has this problem only been seen in 1.6.7? We are currently running on 1.6.4.3.yes. Johann
Johann Lombardi
2009-Apr-02 21:12 UTC
[Lustre-discuss] inode out of bounds issue in 1.6.7 (bug 18695)
Hi all, On Thu, Apr 02, 2009 at 11:29:47AM +0200, Johann Lombardi wrote:> Actually, what would really help us is to have a reproducer (we are still > not able to reproduce the problem on our side). We also lack a corrupted > MDT image (taken with e2image). So, if someone hits the same problem, > please take an image of the MDT with e2image before running e2fsck, it > would really help us. Thanks in advance.FYI, i think we have worked out the problem. A patch is attached to bug 18695. We are now working on a regression test for this issue. Cheers, Johann
Lundgren, Andrew
2009-Apr-02 21:28 UTC
[Lustre-discuss] inode out of bounds issue in 1.6.7 (bug 18695)
Will this be dropped as a 1.6.7.1 release or a later 1.6.8 release?> -----Original Message----- > From: lustre-discuss-bounces at lists.lustre.org [mailto:lustre-discuss- > bounces at lists.lustre.org] On Behalf Of Johann Lombardi > Sent: Thursday, April 02, 2009 3:13 PM > To: lustre-discuss at lists.lustre.org; Marcus Schull > Subject: [Lustre-discuss] inode out of bounds issue in 1.6.7 (bug > 18695) > > Hi all, > > On Thu, Apr 02, 2009 at 11:29:47AM +0200, Johann Lombardi wrote: > > Actually, what would really help us is to have a reproducer (we are > still > > not able to reproduce the problem on our side). We also lack a > corrupted > > MDT image (taken with e2image). So, if someone hits the same problem, > > please take an image of the MDT with e2image before running e2fsck, > it > > would really help us. Thanks in advance. > > FYI, i think we have worked out the problem. A patch is attached to > bug 18695. We are now working on a regression test for this issue. > > Cheers, > Johann > _______________________________________________ > Lustre-discuss mailing list > Lustre-discuss at lists.lustre.org > http://lists.lustre.org/mailman/listinfo/lustre-discuss
Johann Lombardi
2009-Apr-02 21:45 UTC
[Lustre-discuss] inode out of bounds issue in 1.6.7 (bug 18695)
On Thu, Apr 02, 2009 at 03:28:19PM -0600, Lundgren, Andrew wrote:> Will this be dropped as a 1.6.7.1 release or a later 1.6.8 release?I don''t know yet. The release management group will probably make a decision very soon. Cheers, Johann
IMB Mail
2009-Apr-07 02:17 UTC
[Lustre-discuss] Lustre 1.6.7 kernel panics when umounting MDTs
Thank you all for the feedback regarding the "inode out of bounds" issue, and I look forward to the upcoming binary patch / release. We have found some other interesting filesystem issues (probably related to the bug under discussion) whereby we have some directories full of files that have no inodes associated. There are no recent logs indicating problems so I assume that they are a result of the previous "inode out of bounds" issue and were not fixed correctly with the fsck that was subsequently done.>From ls -l:?--------- ? ? ? ? ? uniprot_trembl_SwissGeneSynonym_99.lc ?--------- ? ? ? ? ? uniprot_trembl_typ__168.inx ?--------- ? ? ? ? ? uniprot_trembl_typ__171.inx ?--------- ? ? ? ? ? uniprot_trembl_typ__173.inx ?--------- ? ? ? ? ? uniref100_cks.inx # rm uniref100_cks.inx rm: cannot lstat `uniref100_cks.inx'': No such file or directory ** The other issue I was wondering about in my initial post was whether a kernel panic was expected if I simply umount an MDT on the lustre server (whether or not clients have the file system mounted). If not what, what steps should I take to prevent this from occurring in the future? Thanks again for the advice and responses received. Marcus. Marcus Schull, Systems Administrator IMB, University of Queensland On 2/04/09 3:58 PM, "Jason Rappleye" <jason.rappleye at nasa.gov> wrote:> > Hi, > > On Apr 1, 2009, at 7:21 PM, Marcus Schull wrote: > >> Lustre Admins, >> >> >> We have recently had 2 odd events I am keen to get some feedback on. >> >> 1) We recently had a filesystem go read-only (noticed on the client) >> due to an "inode out of bounds" error as reported in the server logs. >> Please see below for log and fsck details. > > It looks like you''re experiencing corruption described in bz 18695, > which was also reported by us in bz 18889 and by TACC in bz 19029. > > At this point in time, Sun hasn''t made any official recommendations > regarding this problem. If you can stomach it, I''m certain that Sun > (and other sites experiencing this problem) would appreciate feedback > on what the user whose data was corrupted was doing at the time. If > you can reproduce the problem, even better. > > Unfortunately, by the time ldiskfs detects the corruption, it''s > already happened - it is detecting corrupted metadata that has already > been written to disk, not the instant at which the corruption is > occurring. When we first discovered the corruption at our site, we had > a user report errors when trying to perform ls and rm commands in a > corrupted directory. ldiskfs did not report any errors. unmounting the > MDT and running e2fsck on it produced the same type of errors you saw > during your fsck. We remounted the MDT and later that day ldiskfs did > produce the "inode out of bounds" error that you saw. So, either the > corruption occurred again, or e2fsck didn''t fix the problem. > > This happened a day after upgrading to Lustre 1.6.7. We have since > downgraded our servers to 1.6.6. We''re running SLES10 SP2 with kernel > 2.6.16.60-0.35 + a few site specific patches for OOM handling > (developed in house in conjunction with SGI) and one for improved SCSI > error handling that came from Novell, through SGI. So, this problem > doesn''t appear to be specific to the RHEL or SLES kernel, or to our > patched kernel. > > It''s worth noting that we only saw this on the MDTs on a pair of > filesystems. We ran e2fsck against all of the OSTs (a total of 90) and > all came back clean. > > Is there anyone else out there running 1.6.7 that is seeing this > problem as well? It might be a good idea to unmount your MDTs and run > e2fsck against them, and report the results back to the mailing list. > > j > >> >> >> 2) In order to correct the issue (ie remount the device read-write), I >> attempted to umount that device (intending to do a quick fsck as the >> device was the filesystem''s MDT, and then remounting) - however this >> action caused a kernel panic. >> >> I have experienced these kernel panics quite a few times in the past >> when umounting MDTs and OSTs in similar situations - when one or more >> have gone read-only, but this is the first with the 1.6.7 kernel. >> The resulting panic required a reboot and fsck on all mounted LUNs - >> which at present is about 15 TB (in a few separate filesystems). >> >> The server is currently acting has the MGS, MDT and OST partitions for >> all lustre filesystems. Unfortunately we have still not had the >> chance to separate those roles onto different servers. >> The server is running 64 bit RHEL 5.2 with the latest lustre kernel >> (1.6.7) and associated packages. It runs on a SUN blade with 4 AMD >> cores and 16 GB RAM. >> [ kernel version: 2.6.18-92.1.17.el5_lustre.1.6.7smp #1 SMP Mon Feb 9 >> 19:56:55 MST 2009 x86_64 x86_64 x86_64 GNU/Linux ] >> >> All clients are also running RHEL 5.2/5.3 with unpatched kernels and >> the latest lustre packages (1.6.7). >> [ client kernel: 2.6.18-92.1.17.el5 #1 SMP Wed Oct 22 04:19:38 EDT >> 2008 x86_64 x86_64 x86_64 GNU/Linux ] >> >> >> I look forward to any advice regarding the unusual error (1) or any >> procedures to follow in order to prevent the kernel panics. >> >> >> Thanks in advance. >> >> Marcus Schull, >> Systems Administrator >> IMB, University of Queensland >> >> >> >> >> >> >> Lustre server /var/log/messages: >> >> Apr 1 19:03:04 lustre1 kernel: LDISKFS-fs error (device dm-37): >> ldiskfs_add_entry: bad entry in directory #12686675: inode out of >> bounds - offset=0, inode=2807365078, rec_len=4096, name_len=36 >> Apr 1 19:03:04 lustre1 kernel: Remounting filesystem read-only >> Apr 1 19:03:04 lustre1 kernel: LDISKFS-fs error (device dm-37) in >> start_transaction: Readonly filesystem >> Apr 1 19:03:04 lustre1 kernel: LustreError: 8059:0:(fsfilt-ldiskfs.c: >> 1231:fsfilt_ldiskfs_write_record()) can''t start transaction for 18 >> blocks (128 bytes) >> Apr 1 19:03:04 lustre1 kernel: LustreError: 8059:0:(mds_reint.c: >> 230:mds_finish_transno()) @@@ wrote trans #0 rc -5 client >> 5142a23c-5adc-d4e8-4375-1b1028fe8e7d at idx 0: err = -30 >> req at ffff8101771ba000 x28445861/t0 o101->51 >> 42a23c-5adc-d4e8-4375-1b1028fe8e7d at NET_0x200008266732c_UUID:0/0 lens >> 512/568 e 0 to 0 dl 1238576684 ref 1 fl Interpret:/0/0 rc 0/0 >> Apr 1 19:03:04 lustre1 kernel: LustreError: 8059:0:(mds_reint.c: >> 238:mds_finish_transno()) wrote objids: err = 0 >> Apr 1 19:03:04 lustre1 kernel: LustreError: 11330:0:(fsfilt- >> ldiskfs.c: >> 280:fsfilt_ldiskfs_start()) error starting handle for op 8 (33 >> credits): rc -30 >> Apr 1 19:03:04 lustre1 kernel: LustreError: 11330:0:(fsfilt- >> ldiskfs.c: >> 280:fsfilt_ldiskfs_start()) error starting handle for op 8 (33 >> credits): rc -30 >> Apr 1 19:03:04 lustre1 kernel: LustreError: 11330:0:(mds_reint.c: >> 154:mds_finish_transno()) fsfilt_start: -30 >> Apr 1 19:03:04 lustre1 kernel: LustreError: 11337:0:(mds_reint.c: >> 154:mds_finish_transno()) fsfilt_start: -30 >> >> >> >> fsck output of filesystem with error reported above: >> >> [root at lustre1 ~]# e2fsck /dev/mapper/mpath11p1 >> e2fsck 1.40.11.sun1 (17-June-2008) >> qfab-MDT0000: recovering journal >> qfab-MDT0000 contains a file system with errors, check forced. >> Pass 1: Checking inodes, blocks, and sizes >> Inode 12686675, i_size is 28672, should be 65536. Fix<y>? yes >> >> Pass 2: Checking directory structure >> Problem in HTREE directory inode 12686675: node (0) has an unordered >> hash table >> Clear HTree index<y>? yes >> >> Entry ''(=fM-''^\^@ ^@M-~^JM-XM-''p^H$^@:{M-XM-''^H^G$^@TM-O^IM-(x^L(^@t^W >> $M-('' in /ROOT/data1/offindex (12686675) has invalid inode #: >> 2807365078. >> Clear<y>? yes >> >> Pass 3: Checking directory connectivity >> Pass 3A: Optimizing directories >> Pass 4: Checking reference counts >> Unattached inode 12681396 >> Connect to /lost+found<y>? yes >> >> Inode 12681396 ref count is 2, should be 1. Fix<y>? yes >> >> Unattached inode 12681397 >> Connect to /lost+found<y>? yes >> >> ... etc >> >> >> >> >> ------- >> >> _______________________________________________ >> Lustre-discuss mailing list >> Lustre-discuss at lists.lustre.org >> http://lists.lustre.org/mailman/listinfo/lustre-discuss >