Re: kern/53066: nearly reproducable softint panic on shutdown

[Jaromír Doleček <jaromir.dolecek%gmail.com@localhost>]

The following reply was made to PR kern/53066; it has been noted by GNATS.

From: =?UTF-8?B?SmFyb23DrXIgRG9sZcSNZWs=?= <jaromir.dolecek%gmail.com@localhost>
To: "gnats-bugs%NetBSD.org@localhost" <gnats-bugs%netbsd.org@localhost>
Cc: 
Subject: Re: kern/53066: nearly reproducable softint panic on shutdown
Date: Mon, 23 Apr 2018 20:23:11 +0200

 So it's apparently mishandled shared interrupt in your case. Checked
 xhci_intr1(), it simply does not check if it should handle the
 interrupt, and always triggers the usb callback.
 
 Looking at dmesg, I see pin 18 intr is shared with ohci0-3, and
 nouveau0. From the detach list before panic, I see strikingly missing
 e.g. usb7, to which uplcom0 is attached. So I guess something is still
 triggering interrupts for uplcom0/ohci3 during detach, which xhci0
 misinterprets as something for itself.
 
 Quick fix would be to check sc_child/sc_child2 and skip the
 usb_schedsoftintr() call. Correct fix would be to fix xhci_intr() to
 check if it should handle the interrupt.
 
 I'll see what can be done to improve this.
 
 Jaromir
 
 2018-04-23 13:53 GMT+02:00 Martin Husemann <martin%duskware.de@localhost>:
 > On Mon, Apr 23, 2018 at 11:35:00AM +0000, Jarom=C3=ADr Dole?ek wrote:
 >>  Can you please check backtrace for reboot command, to see what in
 >>  particular triggered the interrupt? It was waiting on xscmd for my
 >>  sd(4) case, might be something else for yours.
 >
 > Sure:
 >
 > db{0}> trace/a ffffe4042bba04e0
 > trace: pid 37 lid 1 at 0xffff800144becd70
 > sleepq_block() at netbsd:sleepq_block+0x91
 > cv_wait() at netbsd:cv_wait+0xfb
 > kthread_join() at netbsd:kthread_join+0x89
 > audiodetach() at netbsd:audiodetach+0xcd
 > config_detach() at netbsd:config_detach+0x121
 > config_detach_all() at netbsd:config_detach_all+0x97
 > cpu_reboot() at netbsd:cpu_reboot+0x19a
 > sys_reboot() at netbsd:sys_reboot+0x75
 > syscall() at netbsd:syscall+0x208
 >
 > Nothing related to USB or umass.
 >
 >>  It's very strange that interrupt for xhci() would be triggered when
 >>  both child busses are already detached.
 >
 > Yes, but that is what is happening:
 >
 > [   1.1321399] xhci0 at pci4 dev 0 function 0: vendor 1033 product 0194 (=
 rev. 0x03)
 > [   1.1321399] xhci0: interrupting at ioapic0 pin 18
 > [   1.1321399] usb0 at xhci0: USB revision 3.0
 > [   1.1321399] usb1 at xhci0: USB revision 2.0
 > ..
 > [   1.1321399] fwohci0: BUS reset
 > [   1.1321399] fwohci0: node_id=3D0xc800ffc0, gen=3D1, CYCLEMASTER mode
 > [   1.1321399] ieee1394if0: 1 nodes, maxhop <=3D 0 cable IRM irm(0) (me)
 > [   1.1321399] ieee1394if0: bus manager 0
 > [   2.0103103] uhub0 at usb0: NetBSD (0000) xHCI Root Hub (0000), class 9=
 /0, rev 3.00/1.00, addr 0
 > [   2.1127363] uhub1 at usb1: NetBSD (0000) xHCI Root Hub (0000), class 9=
 /0, rev 2.00/1.00, addr 0
 > [   2.8278330] uhub2 at usb3: NetBSD (0000) EHCI root hub (0000), class 9=
 /0, rev 2.00/1.00, addr 1
 > ..
 > # reboot
 > reboot: rebooted by root
 > [  44.5996539] syncing disks... done
 > [  44.6396593] uhub1: detached
 > [  44.6696670] uhub0: detached
 > [  44.6996751] atabus0: detached
 > [  44.7396859] cd0: detached
 > [  44.7696940] usb1: detached
 > [  44.7997124] usb0: detached
 > [  44.8297205] atabus1: detached
 > [  44.8697210] atapibus0: detached
 > [  44.9097317] wd0: detached
 > [  44.9397399] uhub6: detached
 > [  44.9697480] uhub5: detached
 > [  44.9997560] uhub4: detached
 > [  45.0397668] uhub3: detached
 > [  45.0697749] uhub2: detached
 > [  45.0997830] spkr1: detached
 > [  45.1397938] Skipping crash dump on recursive panic
 > [  45.1397938] panic: kernel diagnostic assertion "sc->sc_child || sc->sc=
 _child2" failed: file "../../../../dev/usb/xhci.c", line 1239
 > [  45.1397938] cpu0: Begin traceback...
 > [  45.1397938] vpanic() at netbsd:vpanic+0x16f
 > [  45.1397938] ch_voltag_convert_in() at netbsd:ch_voltag_convert_in
 > [  45.1397938] xhci_intr() at netbsd:xhci_intr+0xd4
 > [  45.1397938] intr_biglock_wrapper() at netbsd:intr_biglock_wrapper+0x36
 > [  45.1397938] Xhandle_ioapic_level1() at netbsd:Xhandle_ioapic_level1+0x=
 6a
 > [  45.1397938] --- interrupt ---
 > [  45.1397938] x86_pause() at netbsd:x86_pause
 > [  45.1397938] callout_softclock() at netbsd:callout_softclock+0x41a
 > [  45.1397938] softint_dispatch() at netbsd:softint_dispatch+0xee
 > [  45.1397938] DDB lost frame for netbsd:Xsoftintr+0x4f, trying 0xffff800=
 13d2db0f0
 > [  45.1397938] Xsoftintr() at netbsd:Xsoftintr+0x4f
 >
 >
 >
 > Martin