[LU-347] Failure on test suite conf-sanity.sh test_48

• Status: Resolved
• Project: Lustre
• Affects Version/s: Lustre 2.1.0
• Fix Version/s: Lustre 2.1.0
• Type: Bug
• Priority: Minor
• Reporter: Maloo
• Assignee: Zhenyu Xu
• Resolution: Duplicate
• Severity: 3

Description

This issue was created by maloo for sarah <[e-mail]>

This issue relates to the following test suite run: https://maloo.whamcloud.com/test_sets/e5b0eb78-8228-11e0-b4df-52540025f9af.

09:18:42:Lustre: DEBUG MARKER: == conf-sanity test 48: too many acls on file ======================================================== 02:18:41 (1305796721)
09:18:45:LDISKFS-fs (sdb): warning: maximal mount count reached, running e2fsck is recommended
09:18:50:Lustre: lustre-MDT0000: new disk, initializing
09:18:51:LustreError: 11651:0:(ldlm_lib.c:2118:target_send_reply_msg()) @@@ processing error (11) req@ffff81040cfb4800 x1369227103567881/t0(0) o-1><?>@<?>:0/0 lens 368/0 e 0 to 0 dl 1305796751 ref 1 fl Interpret:/ffffffff/ffffffff rc -11/-1
09:18:51:LustreError: 11651:0:(ldlm_lib.c:2118:target_send_reply_msg()) Skipped 25 previous similar messages
09:18:58:Lustre: 11831:0:(quota_master.c:793:close_quota_files()) quota[0] is off already
09:18:58:Lustre: 11831:0:(quota_master.c:793:close_quota_files()) Skipped 35 previous similar messages
09:18:59:Unable to handle kernel paging request at 0000000000100100 RIP:
09:18:59: [<ffffffff889ae134>] :ptlrpc:ptlrpc_unregister_service+0x1e4/0xbd0
09:18:59:PGD 0
09:18:59:Oops: 0000 [1] SMP
09:18:59:last sysfs file: /block/sdb/queue/max_sectors_kb
09:18:59:CPU 3
09:18:59:Modules linked in: nfs(U) fscache(U) nfs_acl(U) cmm(U) osd_ldiskfs(U) mdt(U) mdd(U) mds(U) fsfilt_ldiskfs(U) exportfs(U) mgs(U) mgc(U) lustre(U) lov(U) osc(U) lquota(U) mdc(U) fid(U) fld(U) ko2iblnd(U) ptlrpc(U) obdclass(U) lnet(U) lvfs(U) libcfs(U) ldiskfs(U) jbd2(U) crc16(U) autofs4(U) hidp(U) rfcomm(U) l2cap(U) bluetooth(U) lockd(U) sunrpc(U) cpufreq_ondemand(U) powernow_k8(U) freq_table(U) be2iscsi(U) iscsi_tcp(U) bnx2i(U) cnic(U) uio(U) cxgb3i(U) iw_cxgb3(U) cxgb3(U) libiscsi_tcp(U) ib_iser(U) libiscsi2(U) scsi_transport_iscsi2(U) scsi_transport_iscsi(U) ib_srp(U) rds(U) ib_sdp(U) ib_ipoib(U) ipoib_helper(U) ipv6(U) xfrm_nalgo(U) crypto_api(U) rdma_ucm(U) rdma_cm(U) ib_ucm(U) ib_uverbs(U) ib_umad(U) ib_cm(U) iw_cm(U) ib_addr(U) ib_sa(U) loop(U) dm_mirror(U) dm_multipath(U) scsi_dh(U) video(U) backlight(U) sbs(U) power_meter(U) hwmon(U) i2c_ec(U) dell_wmi(U) wmi(U) button(U) battery(U) asus_acpi(U) acpi_memhotplug(U) ac(U) parport_pc(U) lp(U) parport(U) mlx4_ib(U) ib_mad(U) ib_core(U) mlx4_en(U) shpchp(U) igb(U) 8021q(U) sg(U) mlx4_core(U) dca(U) i2c_piix4(U) i2c_core(U) amd64_edac_mod(U) edac_mc(U) pcspkr(U) serio_raw(U) dm_raid45(U) dm_message(U) dm_region_hash(U) dm_log(U) dm_mod(U) dm_mem_cache(U) ahci(U) libata(U) sd_mod(U) scsi_mod(U) ext3(U) jbd(U) uhci_hcd(U) ohci_hcd(U) ehci_hcd(U)
09:18:59:Pid: 5695, comm: obd_zombid Tainted: G 2.6.18-194.17.1.el5_lustre.gce09fce #1
09:18:59:RIP: 0010:[<ffffffff889ae134>] [<ffffffff889ae134>] :ptlrpc:ptlrpc_unregister_service+0x1e4/0xbd0
09:18:59:RSP: 0018:ffff81021eb6dcd0 EFLAGS: 00010246
09:18:59:RAX: 00000000fffffffe RBX: 0000000000100100 RCX: ffff8100765189d0
09:18:59:RDX: ffff81031e11d250 RSI: 0000000000000001 RDI: 0000000001406495
09:18:59:RBP: ffff810078fe0c00 R08: 0000000000000001 R09: 0000000000000001
09:18:59:R10: 00000000ffffffff R11: 00000000000000d0 R12: ffff81010a4266a8
09:18:59:R13: 0000000000000000 R14: 0000000000000000 R15: ffff810078fe0ca8
09:18:59:FS: 00002b36a618f6e0(0000) GS:ffff8102239255c0(0000) knlGS:0000000000000000
09:18:59:CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
09:18:59:CR2: 0000000000100100 CR3: 0000000000201000 CR4: 00000000000006e0
09:18:59:Process obd_zombid (pid: 5695, threadinfo ffff81021eb6c000, task ffff81010537c080)
09:18:59:Stack: 0000000000000000 0000000000000000 ffffffff88a04a34 ffffffff88ccc670
09:18:59: ffffffff88a6bbd0 0000000000000000 ffff810078fe0dd8 ffff810078fe0ce0
09:18:59: ffff810078fe0db8 ffffffff88a6bbd0 0000000000000000 0000000000000001
09:18:59:Call Trace:
09:18:59: [<ffffffff8002e244>] __wake_up+0x38/0x4f
09:18:59: [<ffffffff88ca70bb>] :mgs:mgs_cleanup+0xeb/0x220
09:18:59: [<ffffffff888b82cf>] :obdclass:class_decref+0x43f/0x5b0
09:18:59: [<ffffffff88ca72d6>] :mgs:mgs_destroy_export+0xe6/0xf0
09:18:59: [<ffffffff8889e302>] :obdclass:obd_zombie_impexp_cull+0x402/0x4f0
09:18:59: [<ffffffff888a5847>] :obdclass:obd_zombie_impexp_thread+0x1f7/0x2a0
09:18:59: [<ffffffff8008cf99>] default_wake_function+0x0/0xe
09:18:59: [<ffffffff8005dfb1>] child_rip+0xa/0x11
09:18:59: [<ffffffff888a5650>] :obdclass:obd_zombie_impexp_thread+0x0/0x2a0
09:18:59: [<ffffffff8005dfa7>] child_rip+0x0/0x11
09:18:59:
09:18:59:
09:18:59:Code: 48 8b 03 0f 18 08 48 39 5c 24 38 75 bf 4c 8d bd a8 00 00 00
09:18:59:RIP [<ffffffff889ae134>] :ptlrpc:ptlrpc_unregister_service+0x1e4/0xbd0
09:18:59: RSP <ffff81021eb6dcd0>
09:18:59:CR2: 0000000000100100
09:18:59: <0>Kernel panic - not syncing: Fatal exception

Comments

[Peter Jones]

Bobijam

Could you please look into this one? It is showing up regularly during testing

Thanks

Peter

[Zhenyu Xu]

from https://maloo.whamcloud.com/test_sets/9b40afc6-871c-11e0-b4df-52540025f9af

17:25:56: [] :ptlrpc:ptlrpc_unregister_service+0x580/0xbd0
17:25:56: [] __wake_up+0x38/0x4f
17:25:56: [] :mgs:mgs_cleanup+0xeb/0x220
17:25:56: [] :obdclass:class_decref+0x43f/0x5b0
17:25:56: [] :obdclass:class_incref+0x7a/0x90
17:25:56: [] :obdclass:obd_devlist_next+0x65/0x80

and my local test ran similar panic

crash> bt
PID: 17830 TASK: ffff81000d61f790 CPU: 1 COMMAND: "lctl"
#0 [ffff810015fa1a20] crash_kexec at ffffffff800af38f
#1 [ffff810015fa1ae0] __die at ffffffff80065117
#2 [ffff810015fa1b20] do_page_fault at ffffffff8006748d
#3 [ffff810015fa1c10] error_exit at ffffffff8005dde9
[exception RIP: ptlrpc_unregister_service+115]
RIP: ffffffff88646ff3 RSP: ffff810015fa1cc8 RFLAGS: 00010296
RAX: 0000000000000001 RBX: ffff81000a55e700 RCX: 0000000000000001
RDX: 0000000000000d32 RSI: ffffffff8868595a RDI: ffff810016ed8080
RBP: 0000000000000000 R8: 0000000000000000 R9: 0000000000000a34
R10: 00000000ffffffff R11: 0000000000000000 R12: ffff81000a55e1b8
R13: 0000000000000000 R14: 0000000000000000 R15: 00002b0b5e5b4000
ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018
#4 [ffff810015fa1cc0] ptlrpc_unregister_service at ffffffff88646ff3
#5 [ffff810015fa1d80] ost_cleanup at ffffffff88a88caf
#6 [ffff810015fa1dd0] class_decref at ffffffff8855425f
#7 [ffff810015fa1e70] obd_devlist_next at ffffffff8853b1a5
#8 [ffff810015fa1e90] obd_device_list_seq_next at ffffffff885230c7

Looks like obd device is accessed during its cleanup. Lai Siyao's patch in http://review.whamcloud.com/#patch,sidebyside,326,13,lustre/obdclass/genops.c will handle it (it's patch for LU-106)

[Zhenyu Xu]

LU-106's patch can fix this error, resolve it as dup of LU-106, and feel free to reopen it if the issue reoccurs after LU-106's patch got landed.

root cause:
mgs was in clean up phase, while conf-sanity.sh was checking /proc/fs/lustre/devices and find the mgs device, obd_devlist_next() class_incref() it, afterward class_decref() it which called obd_cleanup() again, causing invalid memory access violation.