Bug 728916 - Call Trace __report_bad_irq on irq 17 on Mac mini Core i5 EFI
Summary: Call Trace __report_bad_irq on irq 17 on Mac mini Core i5 EFI
Keywords:
Status: CLOSED WORKSFORME
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 16
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-08-08 11:41 UTC by Mads Kiilerich
Modified: 2012-09-19 19:05 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2012-09-19 19:05:38 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
dmesg (100.12 KB, text/plain)
2011-08-08 11:41 UTC, Mads Kiilerich
no flags Details
dmesg with 3.0.1-3.fc16.x86_64 (123.21 KB, text/plain)
2011-08-10 16:39 UTC, Mads Kiilerich
no flags Details
dmesg with irqpoll - doesn't make any difference (123.10 KB, text/plain)
2011-08-10 16:45 UTC, Mads Kiilerich
no flags Details
dmesg with pcie_ports=compat - as adviced by mjg59 (101.29 KB, text/plain)
2011-08-12 20:22 UTC, Mads Kiilerich
no flags Details

Description Mads Kiilerich 2011-08-08 11:41:12 UTC
Created attachment 517183 [details]
dmesg

I noticed this when booting 3.0.0-3.fc16.x86_64 from USB with EFI on a new Mac mini with Core i5. It looks like something that should be handled differently:

[    7.966658] irq 17: nobody cared (try booting with the "irqpoll" option)
[    7.966699] Pid: 151, comm: usb-storage Not tainted 3.0.0-3.fc16.x86_64 #1
[    7.966735] Call Trace:
[    7.966749]  <IRQ>  [<ffffffff810bef8a>] __report_bad_irq+0x37/0xc4
[    7.966790]  [<ffffffff810bf22d>] note_interrupt+0x179/0x1fc
[    7.966820]  [<ffffffff810bd736>] handle_irq_event_percpu+0x15d/0x1bc
[    7.966854]  [<ffffffff810bd7dc>] handle_irq_event+0x47/0x67
[    7.968321]  [<ffffffff814ddc74>] ? _raw_spin_lock+0x62/0x6a
[    7.969769]  [<ffffffff810bf9a3>] ? handle_fasteoi_irq+0x1e/0xad
[    7.971212]  [<ffffffff810bfa0c>] handle_fasteoi_irq+0x87/0xad
[    7.972651]  [<ffffffff8100ab60>] handle_irq+0x8b/0x91
[    7.974078]  [<ffffffff814e6b3d>] do_IRQ+0x4d/0xa5
[    7.975493]  [<ffffffff814de7d3>] common_interrupt+0x13/0x13
[    7.976897]  [<ffffffff81091106>] ? arch_local_irq_restore+0x6/0xd
[    7.978296]  [<ffffffff814de490>] ? _raw_spin_unlock_irqrestore+0x4d/0x52
[    7.979698]  [<ffffffff813222af>] ? scsi_run_queue+0x25d/0x274
[    7.981095]  [<ffffffff813233e5>] ? scsi_next_command+0x38/0x48
[    7.982473]  [<ffffffff813238a6>] ? scsi_io_completion+0x45d/0x4d7
[    7.983842]  [<ffffffff8131ba58>] ? scsi_finish_command+0xe4/0xed
[    7.985206]  [<ffffffff8132338d>] ? scsi_softirq_done+0x109/0x112
[    7.986566]  [<ffffffff8122be8f>] ? blk_done_softirq+0x79/0x8d
[    7.987915]  [<ffffffff8105f1a8>] ? __do_softirq+0xdb/0x1ec
[    7.989285]  [<ffffffff8108aafa>] ? lock_release+0x173/0x19c
[    7.989288]  [<ffffffff8100e9fd>] ? paravirt_read_tsc+0x9/0xd
[    7.989290]  [<ffffffff814e62dc>] ? call_softirq+0x1c/0x30
[    7.989292]  [<ffffffff8100abb1>] ? do_softirq+0x4b/0xa2
[    7.989305]  [<ffffffff8105f4c9>] ? irq_exit+0x5d/0xc0
[    7.989307]  [<ffffffff814e6b7e>] ? do_IRQ+0x8e/0xa5
[    7.989309]  [<ffffffff814de7d3>] ? common_interrupt+0x13/0x13
[    7.989310]  <EOI>  [<ffffffff81091122>] ? arch_local_irq_enable+0x8/0xd
[    7.989314]  [<ffffffff814de43f>] ? _raw_spin_unlock_irq+0x32/0x36
[    7.989320]  [<ffffffffa0052e96>] ? usb_stor_control_thread+0x1cd/0x237 [usb_storage]
[    7.989323]  [<ffffffffa0052cc9>] ? fill_inquiry_response+0xf3/0xf3 [usb_storage]
[    7.989326]  [<ffffffff81075e19>] ? kthread+0xa8/0xb0
[    7.989328]  [<ffffffff814e61e4>] ? kernel_thread_helper+0x4/0x10
[    7.989331]  [<ffffffff814de894>] ? retint_restore_args+0x13/0x13
[    7.989333]  [<ffffffff81075d71>] ? __init_kthread_worker+0x5a/0x5a
[    7.989335]  [<ffffffff814e61e0>] ? gs_change+0x13/0x13
[    7.989337] handlers:
[    7.989339] [<ffffffffa00ce036>] sdhci_irq
[    7.989341] Disabling IRQ #17

Comment 1 Mads Kiilerich 2011-08-10 16:39:14 UTC
Created attachment 517655 [details]
dmesg with 3.0.1-3.fc16.x86_64

Similar but different trace:
[    7.921910] irq 17: nobody cared (try booting with the "irqpoll" option)
[    7.921947] Pid: 0, comm: swapper Not tainted 3.0.1-3.fc16.x86_64 #1
[    7.921977] Call Trace:
[    7.921991]  <IRQ>  [<ffffffff810befa6>] __report_bad_irq+0x37/0xc4
[    7.922028]  [<ffffffff810bf249>] note_interrupt+0x179/0x1fc
[    7.922056]  [<ffffffff810bd752>] handle_irq_event_percpu+0x15d/0x1bc
[    7.922087]  [<ffffffff810bd7f8>] handle_irq_event+0x47/0x67
[    7.922116]  [<ffffffff814dcb24>] ? _raw_spin_lock+0x62/0x6a
[    7.923461]  [<ffffffff810bf9bf>] ? handle_fasteoi_irq+0x1e/0xad
[    7.924793]  [<ffffffff810bfa28>] handle_fasteoi_irq+0x87/0xad
[    7.926116]  [<ffffffff8100ab60>] handle_irq+0x8b/0x91
[    7.927429]  [<ffffffff814e59bd>] do_IRQ+0x4d/0xa5
[    7.928735]  [<ffffffff814dd653>] common_interrupt+0x13/0x13
[    7.930037]  <EOI>  [<ffffffff8100e9fd>] ? paravirt_read_tsc+0x9/0xd
[    7.931345]  [<ffffffff8128d245>] ? intel_idle+0xe5/0x10c
[    7.932640]  [<ffffffff8128d241>] ? intel_idle+0xe1/0x10c
[    7.933916]  [<ffffffff813c80a8>] cpuidle_idle_call+0xdb/0x175
[    7.935189]  [<ffffffff810082e9>] cpu_idle+0xaa/0xe4
[    7.936449]  [<ffffffff814ba743>] rest_init+0xb7/0xbe
[    7.937696]  [<ffffffff814ba68c>] ? csum_partial_copy_generic+0x16c/0x16c
[    7.938946]  [<ffffffff81d47bae>] start_kernel+0x3ed/0x3f8
[    7.940190]  [<ffffffff81d472c4>] x86_64_start_reservations+0xaf/0xb3
[    7.941429]  [<ffffffff81d47140>] ? early_idt_handlers+0x140/0x140
[    7.942658]  [<ffffffff81d473ca>] x86_64_start_kernel+0x102/0x111
[    7.943878] handlers:
[    7.945089] [<ffffffffa0062036>] sdhci_irq
[    7.946307] Disabling IRQ #17

This is http://www.smolts.org/client/show/pub_68a5a8ac-3cda-4919-b289-1a418ac80b7f

Comment 2 Mads Kiilerich 2011-08-10 16:45:51 UTC
Created attachment 517659 [details]
dmesg with irqpoll - doesn't make any difference

Comment 3 Mads Kiilerich 2011-08-12 20:22:27 UTC
Created attachment 518103 [details]
dmesg with pcie_ports=compat - as adviced by mjg59

Comment 4 Jurgen Kramer 2011-09-30 09:00:26 UTC
Seeing this on my 2011 mac mini as well, currently with kernel 3.1.0-0.rc8.git0.0.fc16.x86_64.

the SD card I/F does not work on this machine (sdhci/sdhci_pci). Not sure if the IRQ17 stuff causes the problem or the not working of the sdhci module cause the IRQ17 problem.


[   11.537508] irq 17: nobody cared (try booting with the "irqpoll" option)
[   11.537513] Pid: 0, comm: swapper Not tainted 3.1.0-0.rc8.git0.0.fc16.x86_64 #1
[   11.537515] Call Trace:
[   11.537516]  <IRQ>  [<ffffffff810b2312>] __report_bad_irq+0x38/0xc3
[   11.537525]  [<ffffffff810b25ac>] note_interrupt+0x176/0x1fa
[   11.537528]  [<ffffffff810b0aff>] handle_irq_event_percpu+0x15d/0x1a5
[   11.537530]  [<ffffffff810b0b82>] handle_irq_event+0x3b/0x59
[   11.537533]  [<ffffffff81078350>] ? sched_clock_cpu+0x42/0xc6
[   11.537536]  [<ffffffff810b2d6c>] handle_fasteoi_irq+0x80/0xa4
[   11.537540]  [<ffffffff81010af9>] handle_irq+0x88/0x8e
[   11.537543]  [<ffffffff814beb8d>] do_IRQ+0x4d/0xa5
[   11.537547]  [<ffffffff814b5cee>] common_interrupt+0x6e/0x6e
[   11.537548]  <EOI>  [<ffffffff813a46a2>] ? poll_idle+0x2f/0x65
[   11.537554]  [<ffffffff813a468e>] ? poll_idle+0x1b/0x65
[   11.537556]  [<ffffffff813a49be>] cpuidle_idle_call+0xe8/0x182
[   11.537559]  [<ffffffff8100e2e3>] cpu_idle+0xa4/0xe8
[   11.537563]  [<ffffffff81493283>] rest_init+0x77/0x79
[   11.537566]  [<ffffffff81b76b7d>] start_kernel+0x3ab/0x3b6
[   11.537569]  [<ffffffff81b762c4>] x86_64_start_reservations+0xaf/0xb3
[   11.537571]  [<ffffffff81b76140>] ? early_idt_handlers+0x140/0x140
[   11.537573]  [<ffffffff81b763ca>] x86_64_start_kernel+0x102/0x111
[   11.537575] handlers:
[   11.537582] [<ffffffffa00559f2>] sdhci_irq
[   11.537584] Disabling IRQ #17

After this the SD card I/F does not recognize card inserts/removals. Removing and reinserting the sdhci/sdhci_pci modules do not re-enable IRQ17.

Comment 5 Jurgen Kramer 2011-09-30 10:30:06 UTC
Above results (comment #4) were made with the kernel booted in EFI mode using current grub-0.97 (-79) which gave:

[    4.891179] sdhci: Secure Digital Host Controller Interface driver
[    4.891182] sdhci: Copyright(c) Pierre Ossman
[    4.891411] sdhci-pci 0000:02:00.1: SDHCI controller found [14e4:16bc] (rev 10)
[    4.891510] sdhci-pci 0000:02:00.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
[    4.891513] sdhci-pci 0000:02:00.1: Invalid iomem size. You may experience problems.
[    4.891617] sdhci-pci 0000:02:00.1: setting latency timer to 64
[    4.891866] Registered led device: mmc0::
[    4.892105] mmc0: SDHCI controller on PCI [0000:02:00.1] using ADMA

and above trace.

Now the same kernel booting through grub2-efi gives [slightly different]:

[    4.874845] sdhci: Secure Digital Host Controller Interface driver
[    4.874849] sdhci: Copyright(c) Pierre Ossman
[    4.875082] sdhci-pci 0000:02:00.1: SDHCI controller found [14e4:16bc] (rev 10)
[    4.875181] sdhci-pci 0000:02:00.1: enabling device (0000 -> 0002)
[    4.875192] sdhci-pci 0000:02:00.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
[    4.875196] sdhci-pci 0000:02:00.1: Invalid iomem size. You may experience problems.
[    4.875296] sdhci-pci 0000:02:00.1: setting latency timer to 64
[    4.875388] Registered led device: mmc0::
[    4.875475] mmc0: SDHCI controller on PCI [0000:02:00.1] using ADMA

and no trace from irq17 and when I insert and remove a SD card:

[  318.675142] mmc0: new high speed SDHC card at address d555
[  319.112369] mmcblk0: mmc0:d555 SD08G 7.60 GiB (ro)
[  319.113582]  mmcblk0: p1
[  319.320723] SELinux: initialized (dev mmcblk0p1, type vfat), uses genfs_contexts
[  352.262717] SELinux: initialized (dev mmcblk0p1, type vfat), uses genfs_contexts
[  356.642748] mmc0: card d555 removed

Seem to be working without problems. Odd (?)

Comment 6 Mads Kiilerich 2011-09-30 22:59:05 UTC
Strange. I have been using grub2-efi all the time.

Are you 200% sure that it works with grub2 and doesn't with grub2-efi?

I will not be able to test it for the next week.

Jurgen, what is your exact Mac version? Mine is Macmini5,1.

Comment 7 Jurgen Kramer 2011-10-01 07:59:00 UTC
No, it's the other way round. It works in EFI mode (either using the latest grub 1 efi or grub2-efi). I haven't tested it with regular grub2 or legacy grub.

I will do further testing once the F16 beta is out.

My mac details: Macmini5,1
with firmware: BIOS MM51.88Z.0077.B0A.1109091226 09/09/2011

Comment 8 Jurgen Kramer 2011-10-01 10:39:06 UTC
Checking your dmesg output files show you're using an older kernel and older firmware. Maybe you can retest with the latest F16 kernel to see if that fixes the problem. If that does not help I suggest you update the firmware.

Comment 9 Mads Kiilerich 2012-03-19 10:56:36 UTC
On a MacBookPro8,1 booted with grub2-efi-1.99-13.fc16.x86_64 and kernel-3.2.9-2.fc16.x86_64 I get

[    5.469614] firewire_core: created device fw0: GUID a4b197fffe7528d2, S800
[    5.469622] firewire_core: phy config: card 0, new root=ffc0, gap_count=63
[    5.672996] scsi 6:0:0:0: Direct-Access              USB Reader       0001 PQ: 0 ANSI: 0 CCS
[    5.673562] sd 6:0:0:0: Attached scsi generic sg2 type 0
[    5.718203] irq 17: nobody cared (try booting with the "irqpoll" option)
[    5.718207] Pid: 0, comm: swapper Not tainted 3.1.5-6.fc16.x86_64 #1
[    5.718208] Call Trace:
[    5.718210]  <IRQ>  [<ffffffff810dc87d>] __report_bad_irq+0x3d/0xe0
[    5.718216]  [<ffffffff810dcb3d>] note_interrupt+0x16d/0x220
[    5.718220]  [<ffffffff8101a569>] ? sched_clock+0x9/0x10
[    5.718223]  [<ffffffff810da8f9>] handle_irq_event_percpu+0xa9/0x220
[    5.718226]  [<ffffffff810daab4>] handle_irq_event+0x44/0x70
[    5.718228]  [<ffffffff810dd49f>] handle_fasteoi_irq+0x5f/0xf0
[    5.718230]  [<ffffffff810151e9>] handle_irq+0x49/0xa0
[    5.718233]  [<ffffffff815df2da>] do_IRQ+0x5a/0xe0
[    5.718236]  [<ffffffff815d4d6e>] common_interrupt+0x6e/0x6e
[    5.718237]  <EOI>  [<ffffffff8130539b>] ? intel_idle+0xcb/0x120
[    5.718242]  [<ffffffff8130537d>] ? intel_idle+0xad/0x120
[    5.718245]  [<ffffffff81483fc6>] cpuidle_idle_call+0xc6/0x280
[    5.718247]  [<ffffffff81012225>] cpu_idle+0xc5/0x120
[    5.718250]  [<ffffffff815aecee>] rest_init+0x72/0x74
[    5.718254]  [<ffffffff81b7ec0a>] start_kernel+0x3b5/0x3c0
[    5.718256]  [<ffffffff81b7e347>] x86_64_start_reservations+0x132/0x136
[    5.718258]  [<ffffffff81b7e140>] ? early_idt_handlers+0x140/0x140
[    5.718260]  [<ffffffff81b7e44d>] x86_64_start_kernel+0x102/0x111
[    5.718262] handlers:
[    5.718265] [<ffffffffa0137b70>] sdhci_irq
[    5.718266] Disabling IRQ #17

Comment 10 Josh Boyer 2012-03-19 13:27:13 UTC
(In reply to comment #9)
> On a MacBookPro8,1 booted with grub2-efi-1.99-13.fc16.x86_64 and
> kernel-3.2.9-2.fc16.x86_64 I get
> 
> [    5.469614] firewire_core: created device fw0: GUID a4b197fffe7528d2, S800
> [    5.469622] firewire_core: phy config: card 0, new root=ffc0, gap_count=63
> [    5.672996] scsi 6:0:0:0: Direct-Access              USB Reader       0001
> PQ: 0 ANSI: 0 CCS
> [    5.673562] sd 6:0:0:0: Attached scsi generic sg2 type 0
> [    5.718203] irq 17: nobody cared (try booting with the "irqpoll" option)
> [    5.718207] Pid: 0, comm: swapper Not tainted 3.1.5-6.fc16.x86_64 #1

3.2.9-2 huh?  Then why does this say 3.1.5-6?

Comment 11 Mads Kiilerich 2012-03-19 13:46:49 UTC
Sorry, you are right, I was cross checking with the old version and messed them up.

I no longer see the problem on the Macmini5,1 I originally reported it on. It now goes like this and automatically starts polling:

[    4.637860] sdhci: Secure Digital Host Controller Interface driver
[    4.637863] sdhci: Copyright(c) Pierre Ossman
[    4.638327] sdhci-pci 0000:02:00.1: SDHCI controller found [14e4:16bc] (rev 10)
[    4.638427] sdhci-pci 0000:02:00.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
[    4.638430] sdhci-pci 0000:02:00.1: Invalid iomem size. You may experience problems.
[    4.638528] sdhci-pci 0000:02:00.1: setting latency timer to 64
[    4.638590] Registered led device: mmc0::
[    4.638614] Disabling IRQ 17
[    4.640236] mmc0: SDHCI controller on PCI [0000:02:00.1] using ADMA
[    4.640336] firewire_ohci 0000:05:00.0: power state changed by ACPI to D0
[    4.640344] firewire_ohci 0000:05:00.0: power state changed by ACPI to D0
[    4.640357] firewire_ohci 0000:05:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[    4.648226] Polling IRQ 17
[    4.691364] firewire_ohci: Added fw-ohci device 0000:05:00.0, OHCI v1.10, 8 IR + 8 IT contexts, quirks 0x2

I don't have the MBP available for testing right now.

Comment 12 Mads Kiilerich 2012-03-19 13:57:10 UTC
No - now I got it again on Macmini5,1 :

[    5.619740] firewire_core: created device fw0: GUID c82a14fffeeb58e0, S800
[    5.812906] dracut: Scanning devices sda5  for LVM volume groups
[    5.823020] dracut: Reading all physical volumes. This may take a while...
[    5.912895] irq 17: nobody cared (try booting with the "irqpoll" option)
[    5.912898] Pid: 0, comm: swapper/0 Not tainted 3.2.10-3.fc16.x86_64 #1
[    5.912900] Call Trace:
[    5.912901]  <IRQ>  [<ffffffff810e115d>] __report_bad_irq+0x3d/0xe0
[    5.912909]  [<ffffffff810e141d>] note_interrupt+0x16d/0x220
[    5.912911]  [<ffffffff810deba9>] handle_irq_event_percpu+0xa9/0x220
[    5.912913]  [<ffffffff810ded64>] handle_irq_event+0x44/0x70
[    5.912916]  [<ffffffff810e1e8f>] handle_fasteoi_irq+0x5f/0xf0
[    5.912919]  [<ffffffff81016226>] handle_irq+0x46/0xb0
[    5.912922]  [<ffffffff815ef5da>] do_IRQ+0x5a/0xe0
[    5.912925]  [<ffffffff815e4f2e>] common_interrupt+0x6e/0x6e
[    5.912926]  <EOI>  [<ffffffff81494fd9>] ? poll_idle+0x49/0x90
[    5.912932]  [<ffffffff81494fac>] ? poll_idle+0x1c/0x90
[    5.912934]  [<ffffffff814953a1>] cpuidle_idle_call+0xc1/0x280
[    5.912937]  [<ffffffff8101322a>] cpu_idle+0xca/0x120
[    5.912940]  [<ffffffff815c1dde>] rest_init+0x72/0x74
[    5.912943]  [<ffffffff81aebbfe>] start_kernel+0x3ba/0x3c5
[    5.912945]  [<ffffffff81aeb347>] x86_64_start_reservations+0x132/0x136
[    5.912947]  [<ffffffff81aeb140>] ? early_idt_handlers+0x140/0x140
[    5.912949]  [<ffffffff81aeb44d>] x86_64_start_kernel+0x102/0x111
[    5.912951] handlers:
[    5.912953] [<ffffffffa0130080>] sdhci_irq
[    5.912955] Disabling IRQ #17

Comment 13 Dave Jones 2012-03-22 16:58:10 UTC
[mass update]
kernel-3.3.0-4.fc16 has been pushed to the Fedora 16 stable repository.
Please retest with this update.

Comment 14 Dave Jones 2012-03-22 17:02:28 UTC
[mass update]
kernel-3.3.0-4.fc16 has been pushed to the Fedora 16 stable repository.
Please retest with this update.

Comment 15 Dave Jones 2012-03-22 17:13:19 UTC
[mass update]
kernel-3.3.0-4.fc16 has been pushed to the Fedora 16 stable repository.
Please retest with this update.

Comment 16 Mads Kiilerich 2012-05-25 16:55:01 UTC
I no longer see any problem in dmesg with 3.3.5-2.fc16.x86_64 (and grub2beta5 efi), but immediately after boot I have

[root@fladmast ~]# cat /proc/interrupts 
           CPU0       CPU1       CPU2       CPU3       
  0:        165          0          0          0   IO-APIC-edge      timer
  8:          1          0          0          0   IO-APIC-edge      rtc0
  9:          3          0          0          0   IO-APIC-fasteoi   acpi
 17:    2606824          0          0          0   IO-APIC-fasteoi   mmc0
 18:          2          0          0          0   IO-APIC-fasteoi   firewire_ohci
 19:          0          0          0          0   IO-APIC-fasteoi   uhci_hcd:usb4
 21:          0          0          0          0   IO-APIC-fasteoi   uhci_hcd:usb3
 22:         63          0          0          0   IO-APIC-fasteoi   ehci_hcd:usb2
 23:        465          0          0          0   IO-APIC-fasteoi   ehci_hcd:usb1
...

That seems to be an unhelthy amount of interrupts ... and I guess it is the same 17 that still isn't behaving as it should?


Note You need to log in before you can comment on or make changes to this bug.