Re: [linux-usb-devel] dvb-core random crashes - Got it

So,

since yesterday I'm running this:

drivers/usb/host/ehci-hcd.c:611
    /* complete the unlinking of some qh [4.15.2.3] */
    if (status & STS_IAA) {
        if (ehci->reclaim) {
            COUNT (ehci->stats.reclaim);
            ehci->reclaim_ready = 1;
            bh = 1;
        } else {
            printk(KERN_ERR "AUA: ehci reclaim NULL status: %u\n", status);
        }
    }


and got (once so far):

Jul 11 16:19:03 denon kernel: [13475.940000] drivers/usb/input/hid-core.c: submitting ctrl urb: Get_Report wValue=0x0306 wIndex=0x0000 wLength=2
Jul 11 16:19:03 denon kernel: [13475.960000] drivers/usb/input/hid-core.c: submitting ctrl urb: Get_Report wValue=0x0336 wIndex=0x0000 wLength=2
Jul 11 16:19:22 denon kernel: [13495.008000] AUA: ehci reclaim NULL status: 32
Jul 11 16:19:22 denon kernel: [13495.364000]  usbdev4.4_ep81: ep_device_release called for usbdev4.4_ep81
Jul 11 16:19:22 denon kernel: [13495.364000]  usbdev4.4_ep82: ep_device_release called for usbdev4.4_ep82
Jul 11 16:19:22 denon kernel: [13495.368000]  usbdev4.4_ep84: ep_device_release called for usbdev4.4_ep84
Jul 11 16:20:03 denon kernel: [13535.964000] drivers/usb/input/hid-core.c: submitting ctrl urb: Get_Report wValue=0x0331 wIndex=0x0000 wLength=3
Jul 11 16:20:03 denon kernel: [13536.004000] drivers/usb/input/hid-core.c: submitting ctrl urb: Get_Report wValue=0x0326 wIndex=0x0000 wLength=3

no crash, all usb devices happy.

Conclusion:

- It's the bug. Anywhere else in the code reclaim_ready will only set if ehci->reclaim is valid.
- I spammed the wrong ML :)

I still have some questions to the usb ppl:
* what is on status STS_IAA supposed to do?
* should bh set anyway and call ehci_work?
* what is [4.15.2.3] referring to?

Markus Rechberger schrieb:
> Hi Christoph,
> 
> please keep the linux-usb-devel ML in CC :-)

I try to but I'm not subscribed. Mh, I'll check if I'm still subscribed at linux-kernel ;)
This bug exists in actual and older versions too.

> 
> thanks,
> Markus
> 

thank you!
chris

ps: some statistics
[chris@denon /sys/class/usb_host/usb_host4]$ cat registers
bus pci, device 0000:00:03.3 (driver 10 Dec 2004)
EHCI Host Controller
EHCI 1.00, hcd state 1
ownership 01000001 linux
SMI sts/enable 0xe0080000
structural params 0x00103308
capability params 0x00007070
status 4008 Periodic FLR
command 040011 (park)=0 ithresh=4 Periodic period=1024 RUN
intrenable 37 IAA FATAL PCD ERR INT
uframe 1832
port 1 status 003000 POWER OWNER sig=se0
port 2 status 003000 POWER OWNER sig=se0
port 3 status 001005 POWER sig=se0 PE CONNECT
port 4 status 001000 POWER sig=se0
port 5 status 001000 POWER sig=se0
port 6 status 001005 POWER sig=se0 PE CONNECT
port 7 status 001000 POWER sig=se0
port 8 status 001000 POWER sig=se0
irq normal 6466227 err 18 reclaim 486483 (lost 2167)
complete 6553575 unlink 660


> On 7/10/07, Christoph <[email protected]> wrote:
>>
>> Alan Stern schrieb:
>> > On Sun, 8 Jul 2007, Markus Rechberger wrote:
>> >
>> >> On 7/8/07, Christoph <[email protected]> wrote:
>> >>> Hallo Markus!
>> >>>
>> >>> I'm using a Pinnacle PCTV DVB-T for several months now without
>> serious
>> >>> problems.
>> >>> So far I used it only with my Notebook. Now I set up a Mini-ITX
>> Machine with
>> >>> MythTV running 24/24h.
>> >>>
>> >>> The machine freezes ~36h ... black screen, even no sysrq. (Debian
>> etch
>> >>> 2.6.18-4-k7).
>> >>> So I setup kexec, kernel 2.6.21, v4l 5877:e9a7be188b2b and now I
>> got a
>> >>> backtrace:
>> >>>
>> >>> <1>[16645.528000] BUG: unable to handle kernel NULL pointer
>> dereference at
>> >>> virtual address 0
>> >>> 0000068
>> >>> [...]
>> >>> [16645.528000] EIP is at end_unlink_async+0x1b/0xc5 [ehci_hcd]
>> >>> [16645.528000] eax: 00000060   ebx: de4f20dc   ecx: df912020  
>> edx: df8f0b57
>> >>> [16645.528000] esi: 00000000   edi: de4f20dc   ebp: c58a9d4c  
>> esp: c58a9d40
>> >>> [16645.528000] ds: 007b   es: 007b   fs: 00d8  gs: 0033  ss: 0068
>> >>> [16645.528000] Process mythbackend (pid: 12863, ti=c58a8000
>> task=dbb3d070
>> >>> task.ti=c58a8000)
>> >>> [16645.528000] Stack: 00000020 00000000 de4f20dc c58a9dbc df8ed7d6
>> d74ba800
>> >>> de4f20dc de4f20d
>> >>> c
>> >>> [16645.528000]        dd9bd080 c58a9d78 df8ed22a de4f20dc 00000000
>> de4f20dc
>> >>> c58a9de8 df8ed7d
>> >>> 6
>> >>> [16645.528000]        000000bc c58a9d9c 00000292 00000000 00000000
>> c56ce254
>> >>> de4f20dc 0000000
>> >>> 0
>> >>> [16645.528000] Call Trace:
>> >>> [16645.528000]  [<c0104a3e>] show_trace_log_lvl+0x1a/0x2f
>> >>> [16645.528000]  [<c0104aee>] show_stack_log_lvl+0x9b/0xa3
>> >>> [16645.528000]  [<c0104cac>] show_registers+0x1b6/0x288
>> >>> [16645.528000]  [<c0104e68>] die+0xea/0x1bd
>> >>> [16645.528000]  [<c0113bcf>] do_page_fault+0x435/0x506
>> >>> [16645.528000]  [<c0289cbc>] error_code+0x74/0x7c
>> >>> [16645.528000]  [<df8ed7d6>] ehci_work+0x22/0x64b [ehci_hcd]
>> >>> [16645.528000]  [<df8f21b5>] ehci_irq+0x234/0x254 [ehci_hcd]
>> >>> [16645.528000]  [<df8a83af>] usb_hcd_irq+0x24/0x51 [usbcore]
>> >>> [16645.528000]  [<c013b3e2>] handle_IRQ_event+0x21/0x48
>> >>> [16645.528000]  [<c013c515>] handle_level_irq+0x5f/0x96
>> >>> [16645.528000]  [<c0105f8a>] do_IRQ+0x5c/0x7a
>> >>> [16645.528000]  [<c010453f>] common_interrupt+0x23/0x28
>> >>> [16645.528000]  [<c0140892>] free_hot_page+0xa/0xc
>> >>> [16645.528000]  [<c01408ae>] __free_pages+0x1a/0x25
>> >>> [16645.528000]  [<c014c0bc>] __vunmap+0xa2/0xcb
>> >>> [16645.528000]  [<c014c16f>] vfree+0x25/0x27
>> >>> [16645.528000]  [<dfb1e77b>] dvb_dvr_release+0x5b/0xb4 [dvb_core]
>> >>> [16645.528000]  [<c0155973>] __fput+0xa9/0x153
>> >>> [16645.528000]  [<c0155a33>] fput+0x16/0x18
>> >>> [16645.528000]  [<c01535cf>] filp_close+0x54/0x5c
>> >>> [16645.528000]  [<c0154597>] sys_close+0x57/0x8d
>> >>> [16645.528000]  [<c0103b30>] sysenter_past_esp+0x5d/0x81
>> >>> [16645.528000]  =======================
>> >>> [16645.528000] Code: e0 89 f8 e8 4c 4c 86 e0 83 c4 2c 5b 5e 5f c9
>> c3 55 89
>> >>> e5 57 56 53 89 c3
>> >>>  8b 70 14 0f ba b0 bc 00 00 00 01 8d 46 60 ba 57 0b 8f df <c6> 46
>> 68 03 c7
>> >>> 46 48 00 00 00 00
>> >>>  e8 21 8d 8c e0 8b 7e 58 80 63
>> >>> [16645.528000] EIP: [<df8ed1da>] end_unlink_async+0x1b/0xc5
>> [ehci_hcd]
>> >
>> > For whatever it's worth, the crash occurred in end_async_unlink because
>> > ehci->reclaim was NULL.  This may imply that ehci->reclaim_ready was
>> > set when it shouldn't be.  Don't ask me how either of these could
>> > have happened.
>> >
>> > Alan Stern
>> >
>>
>> mh, how about this:
>> drivers/usb/host/ehci-hcd.c:640
>>
>>     /* complete the unlinking of some qh [4.15.2.3] */
>>     if (status & STS_IAA) {
>>         COUNT (ehci->stats.reclaim);
>>         ehci->reclaim_ready = 1;
>>         bh = 1;
>>     }
>> ...
>>     if (bh)
>>         ehci_work (ehci);
>>
>> bh was set to 1 ... possible there?!
>>
>> chris
>>
>>
>> ps: found the box this morning dead ... the kexec kernel also crashed,
>> same story.
>> dvb module was loaded, but mythtv not running.
>> (rc.S was run I messed with the boot options)
>>
>> psps: found the box dead again when I came back from work ...
>> no dvb stuff in the backtrace, same story.
>>
>>
>>
>>
>>
>>
>>
>>
>> _______________________________________________
>> Em28xx mailing list
>> [email protected]
>> http://mcentral.de/mailman/listinfo/em28xx
>>
> 
>