NMI watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [kworker/1:1:29]

I got the following lockup on openSUSEs 4.4.0-rc5-2.g1e923a3-default kernel while unloading the lpfc module:

[  444.088002] NMI watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [kworker/1:1:29]
[  444.088002] Modules linked in: lpfc(-) qla2x00tgt(O) qla2xxx_scst(O) scst_vdisk(O) scsi_transport_fc libcrc32c scst(O) dlm configfs nfsd lockd grace nfs_acl auth_rpcgss sunrpc ed

d snd_pcm_oss snd_mixer_oss snd_seq snd_seq_device dm_mod iTCO_wdt snd_hda_codec_realtek snd_hda_codec_generic gpio_ich iTCO_vendor_support ppdev snd_hda_intel snd_hda_codec snd_hda _core snd_hwdep tg3 snd_pcm snd_timer libphy lpc_ich parport_pc ptp acpi_cpufreq snd pps_core fjes parport i2c_i801 ehci_pci tpm_tis tpm sr_mod cdrom soundcore floppy hwmon sg 8250_ fintek pcspkr i915 drm_kms_helper uhci_hcd ehci_hcd drm fb_sys_fops sysimgblt sysfillrect syscopyarea i2c_algo_bit usbcore button video usb_common fan ata_generic ata_piix libata th ermal

[  444.088002] CPU: 1 PID: 29 Comm: kworker/1:1 Tainted: G           O    4.4.0-rc5-2.g1e923a3-default #1
[  444.088002] Hardware name: FUJITSU SIEMENS ESPRIMO E           /D2164-A1, BIOS 5.00 R1.10.2164.A1               05/08/2006
[  444.088002] Workqueue: fc_wq_4 fc_rport_final_delete [scsi_transport_fc]
[  444.088002] task: f6266ec0 ti: f6268000 task.ti: f6268000
[  444.088002] EIP: 0060:[<c07e7044>] EFLAGS: 00000286 CPU: 1
[  444.088002] EIP is at _raw_spin_unlock_irqrestore+0x14/0x20
[  444.088002] EAX: 00000286 EBX: f20d3800 ECX: 00000002 EDX: 00000286
[  444.088002] ESI: f50ba800 EDI: f2146848 EBP: f6269ec8 ESP: f6269ec8
[  444.088002]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[  444.088002] CR0: 8005003b CR2: 08f96600 CR3: 363ae000 CR4: 000006d0
[  444.088002] Stack:
[  444.088002]  f6269eec c066b0f7 00000286 f2146848 f50ba808 f50ba800 f50ba800 f2146a90
[  444.088002]  f2146848 f6269f08 f8f0a4ed f3141000 f2146800 f2146a90 f619fa00 00000040
[  444.088002]  f6269f40 c026cb25 00000001 166c6392 00000061 f6757140 f6136340 00000004
[  444.088002] Call Trace:
[  444.088002]  [<c066b0f7>] scsi_remove_target+0x167/0x1c0
[  444.088002]  [<f8f0a4ed>] fc_rport_final_delete+0x9d/0x1e0 [scsi_transport_fc]
[  444.088002]  [<c026cb25>] process_one_work+0x155/0x3e0
[  444.088002]  [<c026cde7>] worker_thread+0x37/0x490
[  444.088002]  [<c027214b>] kthread+0x9b/0xb0
[  444.088002]  [<c07e72c1>] ret_from_kernel_thread+0x21/0x40
[  444.088002] DWARF2 unwinder stuck at ret_from_kernel_thread+0x21/0x40
[  444.088002]
[  444.088002] Leftover inexact backtrace:
[  444.088002]  [<c02720b0>] ? kthread_park+0x50/0x50
[  444.088002] Code: c8 e8 41 7f ab ff 89 d8 5b 5d c3 8d b6 00 00 00 00 8d bf 00 00 00 00 55 89 e5 3e 8d 74 26 00 0f ae f0 89 f6 c6 00 00 89 d0 50 9d <8d> 74 26 00 5d c3 8d b6 00 00 00 00 55 89 e5 3e 8d 74 26 00 0f
[  444.088002] Kernel panic - not syncing: softlockup: hung tasks
[  444.088002] CPU: 1 PID: 29 Comm: kworker/1:1 Tainted: G           O L  4.4.0-rc5-2.g1e923a3-default #1
[  444.088002] Hardware name: FUJITSU SIEMENS ESPRIMO E           /D2164-A1, BIOS 5.00 R1.10.2164.A1               05/08/2006
[  444.088002] Workqueue: fc_wq_4 fc_rport_final_delete [scsi_transport_fc]
[  444.088002]  00000000 00000000 f6269da4 c0518e08 00000016 f6269dbc c034faa0 f6266ec0
[  444.088002]  00000016 f6266ec0 00000000 f6269df0 c0303f54 c09a6589 00000001 00000016
[  444.088002]  f62672ac 0000001d f6269e8c 00000000 00000187 f67506c0 f6750700 f6750a60
[  444.088002] Call Trace:
[  444.088002]  [<c0206092>] try_stack_unwind+0x132/0x140
[  444.088002]  [<c02052a4>] dump_trace+0x54/0x200
[  444.088002]  [<c02060e6>] show_trace_log_lvl+0x46/0x50
[  444.088002]  [<c020551b>] show_stack_log_lvl+0xcb/0x110
[  444.088002]  [<c0206176>] show_stack+0x26/0x50
[  444.088002]  [<c0518e08>] dump_stack+0x41/0x59
[  444.088002]  [<c034faa0>] panic+0x81/0x1b4
[  444.088002]  [<c0303f54>] watchdog_timer_fn+0x1e4/0x1f0
[  444.088002]  [<c02bf3a0>] __hrtimer_run_queues+0xc0/0x240
[  444.088002]  [<c02bfc3a>] hrtimer_interrupt+0x8a/0x190
[  444.088002]  [<c0239a32>] local_apic_timer_interrupt+0x32/0x60
[  444.088002]  [<c07e8713>] smp_apic_timer_interrupt+0x33/0x50
[  444.088002]  [<c07e7e34>] apic_timer_interrupt+0x34/0x40
[  444.088002] DWARF2 unwinder stuck at apic_timer_interrupt+0x34/0x40
[  444.088002]
[  444.088002] Leftover inexact backtrace:
[  444.088002]  [<c06300e0>] ? mipi_dsi_host_register+0x30/0x1d0
[  444.088002]  [<c07e7044>] ? _raw_spin_unlock_irqrestore+0x14/0x20
[  444.088002]  [<c066b0f7>] scsi_remove_target+0x167/0x1c0
[  444.088002]  [<f8f0a4ed>] fc_rport_final_delete+0x9d/0x1e0 [scsi_transport_fc]
[  444.088002]  [<c026cb25>] process_one_work+0x155/0x3e0
[  444.088002]  [<c026cde7>] worker_thread+0x37/0x490
[  444.088002]  [<c026cdb0>] ? process_one_work+0x3e0/0x3e0
[  444.088002]  [<c027214b>] kthread+0x9b/0xb0
[  444.088002]  [<c07e72c1>] ret_from_kernel_thread+0x21/0x40
[  444.088002]  [<c02720b0>] ? kthread_park+0x50/0x50

Sebastian

I still get this on 4.4.0-rc7-1.g276c9f4-default. Since this did not happen on 4.3 I checked the scsi changes and found the following commit:

scsi: restart list search after unlock in scsi_remove_target

Christoph, can it cause this issue?

Sebastian

Apparently yes. Bad hard a patch to avoid this when he resubmitted my patch, which for some reason didn't get apply. Can you grab it from the list archives and give it a try?

Do you mean the following patch?

"[PATCH v2] Separate target visibility from reaped state information" [1]

I can give it a try but it will likely take a few days.

[1] http://marc.info/?l=linux-scsi&m=144771953020415&w=2

Sebastian

Bart's patch mentioned above seems to fix my issue.
The soft lockup is gone and now I am getting the following but that already happened on 4.3 too:

[  531.269588] ------------[ cut here ]------------
[  531.269609] WARNING: CPU: 0 PID: 3482 at fs/sysfs/group.c:237 sysfs_remove_group+0x8f/0xa0()
[  531.269616] sysfs group c0ad62c8 not found for kobject '4:0:0:0'
[  531.269620] Modules linked in: lpfc(-) qla2x00tgt(O) qla2xxx_scst(O) scst_vdisk(O) scst(O) dlm configfs libcrc32c scsi_transport_fc edd nfsd lockd grace nfs_acl snd_pcm_oss snd_mixer_oss snd_seq snd_seq_device auth_rpcgss sunrpc dm_mod snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_hda_codec snd_hda_core iTCO_wdt snd_hwdep ppdev parport_pc tg3 snd_pcm libphy gpio_ich acpi_cpufreq iTCO_vendor_support snd_timer parport fjes snd sr_mod ehci_pci ptp lpc_ich tpm_tis floppy 8250_fintek cdrom pps_core soundcore i2c_i801 tpm hwmon sg pcspkr i915 drm_kms_helper drm fb_sys_fops sysimgblt sysfillrect syscopyarea i2c_algo_bit uhci_hcd ehci_hcd usbcore button video usb_common fan ata_generic ata_piix ahci libahci libata thermal
[  531.269778] CPU: 0 PID: 3482 Comm: rmmod Tainted: G           O    4.4.0-rc8 #2
[  531.269785] Hardware name: FUJITSU SIEMENS ESPRIMO E           /D2164-A1, BIOS 5.00 R1.10.2164.A1               05/08/2006
[  531.269791]  00000000 00000000 f47cbd14 c051cfe0 000000ed c09d07e8 f47cbd44 c025aefe
[  531.269808]  c09c6620 f47cbd70 00000d9a c09d07e8 000000ed c041fbdf c041fbdf c0ad62c8
[  531.269824]  00000000 f4644408 f47cbd5c c025afe3 00000009 f47cbd54 c09c6620 f47cbd70
[  531.269841] Call Trace:
[  531.269852]  [<c051cfe0>] dump_stack+0x44/0x64
[  531.269859]  [<c025aefe>] warn_slowpath_common+0x8e/0xd0
[  531.269865]  [<c041fbdf>] ? sysfs_remove_group+0x8f/0xa0
[  531.269869]  [<c041fbdf>] ? sysfs_remove_group+0x8f/0xa0
[  531.269874]  [<c025afe3>] warn_slowpath_fmt+0x33/0x40
[  531.269879]  [<c041fbdf>] sysfs_remove_group+0x8f/0xa0
[  531.269885]  [<c064fea9>] dpm_sysfs_remove+0x49/0x60
[  531.269891]  [<c06445df>] device_del+0x3f/0x1d0
[  531.269897]  [<c064478e>] device_unregister+0x1e/0x60
[  531.269903]  [<c050ca04>] bsg_unregister_queue+0x54/0x90
[  531.269909]  [<c0679216>] __scsi_remove_device+0x96/0xc0
[  531.269913]  [<c06778b7>] scsi_forget_host+0x57/0x60
[  531.269919]  [<c066c1d8>] scsi_remove_host+0x68/0x100
[  531.269940]  [<f8b5c16a>] lpfc_pci_remove_one_s3+0xca/0x2b0 [lpfc]
[  531.269957]  [<f8b63cc5>] lpfc_pci_remove_one+0x65/0x80 [lpfc]
[  531.269963]  [<c0652aa6>] ? __pm_runtime_resume+0x46/0x60
[  531.269970]  [<c0566bc8>] pci_device_remove+0x38/0xc0
[  531.269975]  [<c06488c2>] __device_release_driver+0x72/0xf0
[  531.269979]  [<c0648aaf>] driver_detach+0x8f/0xa0
[  531.269984]  [<c0647bcc>] bus_remove_driver+0x4c/0xc0
[  531.269989]  [<c06491e8>] driver_unregister+0x28/0x60
[  531.269994]  [<c0644802>] ? device_destroy+0x32/0x40
[  531.269999]  [<c0643c20>] ? class_dir_child_ns_type+0x10/0x10
[  531.270004]  [<c05667d8>] pci_unregister_driver+0x18/0x70
[  531.270010]  [<c0622317>] ? misc_deregister+0x67/0x90
[  531.270024]  [<f8b8b6ef>] lpfc_exit+0x1a/0x92b [lpfc]
[  531.270031]  [<c02d603b>] ? find_module+0x1b/0x20
[  531.270035]  [<c02d9b56>] SyS_delete_module+0x176/0x1f0
[  531.270041]  [<c0380dfb>] ? do_munmap+0x22b/0x2c0
[  531.270046]  [<c0380ed6>] ? vm_munmap+0x46/0x60
[  531.270052]  [<c0201bd1>] do_fast_syscall_32+0x91/0x140
[  531.270059]  [<c07f9074>] sysenter_past_esp+0x3d/0x69
[  531.270064] ---[ end trace 6d7ac64edaa712d5 ]---
[  531.270160] ------------[ cut here ]------------

Sebastian

Bart, can you resend that patch with a a Reported-by and Tested-by for Sebastian?

This looks power management related. Might be worth to send a separate bug report to both linux-scsi and the people responsible for drivers/base/power/sysfs.c