Messages in this thread | | | From | Mark Einon <> | Date | Wed, 30 Jan 2013 23:43:26 +0000 | Subject | Re: [PATCH] firewire: Fix ohci free_irq() warning |
| |
On 29 January 2013 16:04, Stefan Richter <stefanr@s5r6.in-berlin.de> wrote: > Added Cc: linux-pm. > > On Jan 29 Mark Einon wrote: >> On 28 January 2013 23:01, Stefan Richter <stefanr@s5r6.in-berlin.de> wrote: >> > On Jan 28 Mark Einon wrote: >> >> This patch fixes the kernel warning generated when putting an MSI MS-1727 >> >> GT740 laptop into suspend mode. The call sequence in this case calls >> >> free_irq() twice, once in pci_remove() and once then in pci_suspend(). >> > >> > You mean /first/ in pci_suspend() and /then/ in pci_remove() on the >> > already suspended devices, right? >> >> Yes, I did. The call sequence is suspend then resume. My bad.
Correction above : s/resume/remove
>> >> > >> > Because the other way around, first pci_remove(), then pci_suspend(), >> > surely must not appen. And if it does, the bug is elsewhere but not in >> > firewire-ohci. >> > >> > On that note, is pci_suspend() -> pci_remove() actually a legal state >> > transition that must be handled by drivers? >> >> It's happening on the Ubuntu 12.10 distro which performs the suspend >> then remove sequence. I assumed that was normal. > > Maybe a parent device (PCI bridge or the likes) of the OHCI is > requested to be removed during suspend or is being removed during > resume, thereby causing a removal request to the OHCI? > > Or the suspend method of firewire-ohci exited with an error return code... > but then the suspend sequence would be rolled back, not the offending > device be removed, right? > > In any case, could you check the dmesg right before the warning which you > already posted --- and right after it too --- whether there is an > indication what else was going on?
It looks like the remove call actually happens on the wakeup sequence - although I've not yet found the time to investigate further. The lines preceding the crash are:
Jan 30 23:22:53 msilap kernel: [ 7682.288190] ACPI: Low-level resume complete Jan 30 23:22:53 msilap kernel: [ 7682.288228] PM: Restoring platform NVS memory Jan 30 23:22:53 msilap kernel: [ 7682.288644] Enabling non-boot CPUs ... Jan 30 23:22:53 msilap kernel: [ 7682.288713] smpboot: Booting Node 0 Processor 1 APIC 0x2 Jan 30 23:22:53 msilap kernel: [ 7682.301963] hpet: hpet3 irq 41 for MSI Jan 30 23:22:53 msilap kernel: [ 7682.301978] CPU1 is up Jan 30 23:22:53 msilap kernel: [ 7682.302040] smpboot: Booting Node 0 Processor 2 APIC 0x4 Jan 30 23:22:53 msilap kernel: [ 7682.315394] hpet: hpet4 irq 42 for MSI Jan 30 23:22:53 msilap kernel: [ 7682.315408] CPU2 is up Jan 30 23:22:53 msilap kernel: [ 7682.315470] smpboot: Booting Node 0 Processor 3 APIC 0x6 Jan 30 23:22:53 msilap kernel: [ 7682.328815] hpet: hpet5 irq 43 for MSI Jan 30 23:22:53 msilap kernel: [ 7682.328828] CPU3 is up Jan 30 23:22:53 msilap kernel: [ 7682.328882] smpboot: Booting Node 0 Processor 4 APIC 0x1 Jan 30 23:22:53 msilap kernel: [ 7682.342256] hpet: hpet6 irq 44 for MSI Jan 30 23:22:53 msilap kernel: [ 7682.342269] CPU4 is up Jan 30 23:22:53 msilap kernel: [ 7682.342327] smpboot: Booting Node 0 Processor 5 APIC 0x3 Jan 30 23:22:53 msilap kernel: [ 7682.355737] CPU5 is up Jan 30 23:22:53 msilap kernel: [ 7682.355797] smpboot: Booting Node 0 Processor 6 APIC 0x5 Jan 30 23:22:53 msilap kernel: [ 7682.369213] CPU6 is up Jan 30 23:22:53 msilap kernel: [ 7682.369272] smpboot: Booting Node 0 Processor 7 APIC 0x7 Jan 30 23:22:53 msilap kernel: [ 7682.382720] CPU7 is up Jan 30 23:22:53 msilap kernel: [ 7682.388801] ACPI: Waking up from system sleep state S3 Jan 30 23:22:53 msilap kernel: [ 7682.403997] ------------[ cut here ]------------ Jan 30 23:22:53 msilap kernel: [ 7682.404007] WARNING: at /home/mark/Source/linux/kernel/irq/manage.c:1248 __free_irq+0xa3/0x1e0() <snip>
then after the first crash trace:
Jan 30 23:22:53 msilap kernel: [ 7682.404181] ---[ end trace 1a4f0a37b1022aad ]--- Jan 30 23:22:53 msilap kernel: [ 7682.404211] firewire_ohci 0000:07:00.0: removed fw-ohci device Jan 30 23:22:53 msilap kernel: [ 7682.404327] ------------[ cut here ]------------ Jan 30 23:22:53 msilap kernel: [ 7682.404330] WARNING: at /home/mark/Source/linux/kernel/irq/manage.c:1248 __free_irq+0xa3/0x1e0() Jan 30 23:22:53 msilap kernel: [ 7682.404330] Hardware name: MS-1727 Jan 30 23:22:53 msilap kernel: [ 7682.404331] Trying to free already-free IRQ 16 Jan 30 23:22:53 msilap kernel: [ 7682.404363] Modules linked in: ip6table_filter ip6_tables ebtable_nat ebtables nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack ipt_REJECT xt_CHECKSUM iptable_mangle xt_tcpudp iptable_filter bnep rfcomm ip_tables bluetooth x_tables bridge stp llc parport_pc ppdev binfmt_misc arc4 nouveau iwldvm mac80211 snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_intel snd_hda_codec iwlwifi coretemp kvm_intel snd_hwdep kvm snd_pcm ttm cfg80211 snd_seq_midi snd_rawmidi drm_kms_helper snd_seq_midi_event drm snd_seq snd_timer snd_seq_device joydev snd microcode i7core_edac i2c_algo_bit psmouse soundcore edac_core jmb38x_ms msi_wmi serio_raw video memstick mxm_wmi lpc_ich sparse_keymap mac_hid wmi snd_page_alloc acpiphp lp parport r8169 firewire_ohci(O) sdhci_pci firewire_core(O) sdhci crc_itu_t Jan 30 23:22:53 msilap kernel: [ 7682.404365] Pid: 5968, comm: kworker/0:2 Tainted: G W O 3.8.0-rc5-next-20130128+ #6 Jan 30 23:22:53 msilap kernel: [ 7682.404366] Call Trace: Jan 30 23:22:53 msilap kernel: [ 7682.404369] [<ffffffff810589af>] warn_slowpath_common+0x7f/0xc0 Jan 30 23:22:53 msilap kernel: [ 7682.404371] [<ffffffff81058aa6>] warn_slowpath_fmt+0x46/0x50 Jan 30 23:22:53 msilap kernel: [ 7682.404374] [<ffffffff81044c69>] ? default_spin_lock_flags+0x9/0x10 Jan 30 23:22:53 msilap kernel: [ 7682.404376] [<ffffffff810eabc3>] __free_irq+0xa3/0x1e0 Jan 30 23:22:53 msilap kernel: [ 7682.404378] [<ffffffff810ead54>] free_irq+0x54/0xc0 Jan 30 23:22:53 msilap kernel: [ 7682.404384] [<ffffffffa000968a>] sdhci_remove_host+0x6a/0x190 [sdhci] Jan 30 23:22:53 msilap kernel: [ 7682.404389] [<ffffffffa002f3ff>] sdhci_pci_remove_slot+0x4f/0xc0 [sdhci_pci] Jan 30 23:22:53 msilap kernel: [ 7682.404394] [<ffffffffa002fa70>] sdhci_pci_remove+0x50/0xa0 [sdhci_pci] Jan 30 23:22:53 msilap kernel: [ 7682.404398] [<ffffffff8137ff26>] pci_device_remove+0x46/0xc0 Jan 30 23:22:53 msilap kernel: [ 7682.404402] [<ffffffff81456f3c>] __device_release_driver+0x7c/0xe0 Jan 30 23:22:53 msilap kernel: [ 7682.404404] [<ffffffff814571ac>] device_release_driver+0x2c/0x40 Jan 30 23:22:53 msilap kernel: [ 7682.404406] [<ffffffff814569b1>] bus_remove_device+0xe1/0x120 Jan 30 23:22:53 msilap kernel: [ 7682.404409] [<ffffffff8145403a>] device_del+0x11a/0x1b0 Jan 30 23:22:53 msilap kernel: [ 7682.404411] [<ffffffff81379d94>] pci_stop_bus_device+0x94/0xa0 Jan 30 23:22:53 msilap kernel: [ 7682.404414] [<ffffffff81379f36>] pci_stop_and_remove_bus_device+0x16/0x30 Jan 30 23:22:53 msilap kernel: [ 7682.404419] [<ffffffffa0028b36>] acpiphp_disable_slot+0xf6/0x1a0 [acpiphp] Jan 30 23:22:53 msilap kernel: [ 7682.404424] [<ffffffffa0027716>] ? get_slot_status+0x46/0xc0 [acpiphp] Jan 30 23:22:53 msilap kernel: [ 7682.404428] [<ffffffffa0028c0d>] acpiphp_check_bridge.isra.13+0x2d/0xf0 [acpiphp] Jan 30 23:22:53 msilap kernel: [ 7682.404433] [<ffffffffa0029247>] _handle_hotplug_event_bridge+0x2e7/0x410 [acpiphp] Jan 30 23:22:53 msilap kernel: [ 7682.404436] [<ffffffff813bdc64>] ? acpi_os_execute_deferred+0x2d/0x32 Jan 30 23:22:53 msilap kernel: [ 7682.404439] [<ffffffff8117df25>] ? kfree+0x105/0x140 Jan 30 23:22:53 msilap kernel: [ 7682.404441] [<ffffffff81077249>] process_one_work+0x159/0x4c0 Jan 30 23:22:53 msilap kernel: [ 7682.404444] [<ffffffff8107895e>] worker_thread+0x15e/0x4a0 Jan 30 23:22:53 msilap kernel: [ 7682.404446] [<ffffffff81078800>] ? manage_workers+0x2a0/0x2a0 Jan 30 23:22:53 msilap kernel: [ 7682.404448] [<ffffffff8107df60>] kthread+0xc0/0xd0 Jan 30 23:22:53 msilap kernel: [ 7682.404450] [<ffffffff8107dea0>] ? kthread_create_on_node+0x130/0x130 Jan 30 23:22:53 msilap kernel: [ 7682.404452] [<ffffffff816d756c>] ret_from_fork+0x7c/0xb0 Jan 30 23:22:53 msilap kernel: [ 7682.404454] [<ffffffff8107dea0>] ? kthread_create_on_node+0x130/0x130 Jan 30 23:22:53 msilap kernel: [ 7682.404456] ---[ end trace 1a4f0a37b1022aae ]---
> > Also, what are the parent devices of the OHCI according to "lspci -tv" (or > what else can show PCI topology)?
I ran 'lshw' on the machine, which may be of more use. The relevant output is (removing parts not associated with the firewire device):
msilap description: Notebook product: MS-1727 (To be filled by O.E.M.) vendor: MICRO-STAR INTERNATIONAL CO., LTD version: REV:1.0 serial: FFFFFFFF width: 64 bits capabilities: smbios-2.6 dmi-2.6 vsyscall32 configuration: boot=normal chassis=notebook family=To be filled by O.E.M. sku=To be filled by O.E.M. uuid=00020003-0004-0005-0006-000700080009 *-core description: Motherboard product: MS-1727 vendor: MICRO-STAR INTERNATIONAL CO., LTD physical id: 0 version: REV:1.0 serial: BSS-0123456789 slot: To be filled by O.E.M. *-pci:0 description: Host bridge product: Core Processor DMI vendor: Intel Corporation physical id: 100 bus info: pci@0000:00:00.0 version: 11 width: 32 bits clock: 33MHz *-pci:4 description: PCI bridge product: 5 Series/3400 Series Chipset PCI Express Root Port 5 vendor: Intel Corporation physical id: 1c.4 bus info: pci@0000:00:1c.4 version: 05 width: 32 bits clock: 33MHz capabilities: pci pciexpress msi pm normal_decode bus_master cap_list configuration: driver=pcieport resources: irq:16 ioport:9000(size=4096) memory:d4600000-d59fffff ioport:d9d00000(size=2097152) *-firewire description: FireWire (IEEE 1394) product: IEEE 1394 Host Controller vendor: JMicron Technology Corp. physical id: 0 bus info: pci@0000:07:00.0 version: 00 width: 32 bits clock: 33MHz capabilities: pm pciexpress msi ohci bus_master cap_list configuration: driver=firewire_ohci latency=0 resources: irq:16 memory:d4607000-d46077ff memory:d4606000-d460607f memory:d4605000-d460507f memory:d4604000-d460407f *-generic:0 description: System peripheral product: SD/MMC Host Controller vendor: JMicron Technology Corp. physical id: 0.1 bus info: pci@0000:07:00.1 version: 00 width: 32 bits clock: 33MHz capabilities: pm pciexpress msi bus_master cap_list configuration: driver=sdhci-pci latency=0 resources: irq:16 memory:d4603000-d46030ff *-generic:1 UNCLAIMED description: SD Host controller product: Standard SD Host Controller vendor: JMicron Technology Corp. physical id: 0.2 bus info: pci@0000:07:00.2 version: 00 width: 32 bits clock: 33MHz capabilities: pm pciexpress msi cap_list configuration: latency=0 resources: memory:d4602000-d46020ff *-generic:2 description: System peripheral product: MS Host Controller vendor: JMicron Technology Corp. physical id: 0.3 bus info: pci@0000:07:00.3 version: 00 width: 32 bits clock: 33MHz capabilities: pm pciexpress msi bus_master cap_list configuration: driver=jmb38x_ms latency=0 resources: irq:16 memory:d4601000-d46010ff *-generic:3 UNCLAIMED description: System peripheral product: xD Host Controller vendor: JMicron Technology Corp. physical id: 0.4 bus info: pci@0000:07:00.4 version: 00 width: 32 bits clock: 33MHz capabilities: pm pciexpress msi bus_master cap_list configuration: latency=0 resources: memory:d4600000-d46000ff
> >> > Another comment below. >> <snip> >> > >> > firewire-ohci's pci_resume() calls request_irq() a little bit before that, >> > in ohci_enable(). Is the sequence pci_probe/request_irq() -> >> > pci_suspend/disable_irq() -> pci_resume/request_irq() -> >> > pci_resume/enable_irq() legal? >> >> I missed the call to request_irq(). Perhaps the simplest way to handle >> the fix would be to use a flag that holds the irq state? I'm open to >> suggestions. > > Not sure what extent of state tracking the PCI core or driver core already > offer; I'll have to look. > -- > Stefan Richter > -=====-===-= ---= ===-= > http://arcgraph.de/sr/
| |