Re: kernel panic with USB3+DVB+ARM

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On 06.01.2015 22:00, JPT wrote:
> Am 06.01.2015 um 18:38 schrieb Greg KH:
>> On Tue, Jan 06, 2015 at 11:47:29AM +0100, JPT wrote:
>>> Hi Greg
>>>
>>> Am 06.01.2015 um 02:54 schrieb Greg KH:
>>>>
>>>> Is that where the kernel panics show the problem happens?  Without them,
>>>> there's nothing we can do to help out except randomly guess, sorry.
>>>
>>> well. at least xhci is contained in the call stack:
>>>
>>>> [<c02fc948>] (crc32_be) from [<bf01dbc8>] (dvb_dmx_crc32+0x10/0x18 [dvb_core])
>>>> [<bf01dbc8>] (dvb_dmx_crc32 [dvb_core]) from [<bf01c7ec>] (dvb_dmx_swfilter_section_copy_dump+0x254/0x268 [dvb_core])
>>>> [<bf01c7ec>] (dvb_dmx_swfilter_section_copy_dump [dvb_core]) from [<bf01cef4>] (dvb_dmx_swfilter_packet+0x45c/0x564 [dvb_core])
>>>> [<bf01cef4>] (dvb_dmx_swfilter_packet [dvb_core]) from [<bf01d14c>] (dvb_dmx_swfilter+0xf4/0x164 [dvb_core])
>>>> [<bf01d14c>] (dvb_dmx_swfilter [dvb_core]) from [<bf03bebc>] (usb_urb_complete+0xbc/0xe4 [dvb_usb])
>>>> [<bf03bebc>] (usb_urb_complete [dvb_usb]) from [<c0401e44>] (__usb_hcd_giveback_urb+0x5c/0xe8)
>>>> [<c0401e44>] (__usb_hcd_giveback_urb) from [<c042a8d0>] (xhci_irq+0x8d8/0x1e08)
>>>> [<c042a8d0>] (xhci_irq) from [<c0048f40>] (handle_irq_event_percpu+0x78/0x140)
>>>> [<c0048f40>] (handle_irq_event_percpu) from [<c0049030>] (handle_irq_event+0x28/0x38)
>>>> [<c0049030>] (handle_irq_event) from [<c004b1d8>] (handle_simple_irq+0x64/0xa8)
>>>> [<c004b1d8>] (handle_simple_irq) from [<c004886c>] (generic_handle_irq+0x2c/0x3c)
>>>> [<c004886c>] (generic_handle_irq) from [<c000f608>] (handle_IRQ+0x38/0x84)
>>>> [<c000f608>] (handle_IRQ) from [<c030bba0>] (armada_370_xp_handle_msi_irq+0x9c/0xa0)
>>>> [<c030bba0>] (armada_370_xp_handle_msi_irq) from [<c00084f0>] (armada_370_xp_handle_irq+0x5c/0x60)
>>>> [<c00084f0>] (armada_370_xp_handle_irq) from [<c00126c0>] (__irq_svc+0x40/0x54)
>>>
>>>
>>> It's always the same stack, but different errors:
>>>
>>> kernelpanic0.log: Unhandled prefetch abort: unknown 25 (0x409) at 0xc02fc948
>>> kernelpanic0.log: Internal error: : 409 [#1] ARM
>>>
>>> kernelpanic1.log: Unhandled prefetch abort: unknown 25 (0x409) at 0xc02fc948
>>> kernelpanic1.log: Internal error: : 409 [#1] ARM
>>>
>>> kernelpanic2.log: Internal error: Oops: 815 [#1] ARM
>>>
>>> kernelpanic3.log: Unhandled prefetch abort: unknown 25 (0x409) at 0xc0301228
>>> kernelpanic3.log: Internal error: : 409 [#1] ARM
>>>
>>> kernelpanic4.log: Unhandled prefetch abort: unknown 0 (0x000) at 0xc0301228
>>> kernelpanic4.log: Internal error: : 0 [#1] ARM
>>>
>>>
>>> I added a printk to dvb_dmx_crc32() (see dvb.log). This probably
>>> introduced more problems, because irq code has to be fast?
>>> During recording through USB2 this code made the system not crash but it
>>> wasn't able to answer any request (SSH, HTTP, login from serial console ...)
>>>
>>>
>>> Is this info useful?
>>> I attached only one of the kernel panic logs. If you would like to see
>>> the others, please tell me.
>>> I am not sure if the dvb.log tells something of worth at all.
>>>
>>>
>>> Jan
>>
>>> [   57.646235] dvb_dmx_crc32(dvb_demux_feed e0d4b13c, src: e0d4b154, len 18
>>> [   57.688218] dvb_dmx_crc32(dvb_demux_feed e0d4d3b4, src: e0d4d3cc, len 97
>>> [   57.695163] dvb_dmx_crc32(dvb_demux_feed e0d4a000, src: e0d4a018, len 28
>>> [   57.702105] xhci_hcd 0000:01:00.0: ERROR Unknown event condition, HC probably busted
>>> [   57.709920] xhci_hcd 0000:01:00.0: ERROR Unknown event condition, HC probably busted
>>> [   57.717924] xhci_hcd 0000:01:00.0: ERROR Unknown event condition, HC probably busted
>>> [   57.725728] xhci_hcd 0000:01:00.0: ERROR Unknown event condition, HC probably busted
>>
>> Those messages look kind of important, right?  :)
> 
> well yes. But I think I did not have them without the printk in
> dvb_dmx_crc32().
> 
>> Perhaps something is wrong with your hardware, you are using the 3.17
>> kernel release, does this also happen on 3.18?  
> 
> yes, the captured logs are from:
> kernelpanic0.log: 3.17.2-rn104-jpt9
> kernelpanic1.log: 3.17.2-rn104-jpt10
> kernelpanic2.log: 3.17.2-rn104-jpt10
> kernelpanic3.log: 3.18.1-rn104-jpt1
> kernelpanic4.log: 3.18.1-rn104-jpt1
> 
> 
>> Do you have any xhci
>> patches in your tree for this specific ARM hardware?
> 
> No. Not any.
> Only patch is
>     .isoc = {
> -           .framesperurb = 32,
> +           .framesperurb = 8,
>             .framesize = 2048,
>             .interval = 1,
>     }
> in drivers/media/usb/dvb-usb/technisat-usb2.c
> because else the driver would not have worked because of some
> out-of-memory problems. Did not really understand. (where are those
> buffers located?)
> 
>>> Unhandled prefetch abort: unknown 25 (0x409) at 0xc02fc948
>>> Internal error: : 409 [#1] ARM
>>
>> I don't know enough about arm, but this looks like some odd hardware
>> issue, and not a "normal" kernel oops report, right?
> 
> Well, I don't know. If you say so...
> My knowledge dates back to MSDOS and ralph brown's interrupt list ;)
> Haven't got any idea about how USB works, nor kernel panics/oops
> 
> 
> I don't expect this code to be thoroughly tested on an arm system.
> (especially DVB)
> 
> So the stack trace doesn't tell you anything useful?!
> Is there anything else I can do to find out more?

Do you see the same issues with a 3.19 rc kernel? 
There are some xhci patches in 3.19 that touches stopping transfers and cancelling urbs,
which helped some other dvb devices work better. See bug:

https://bugzilla.kernel.org/show_bug.cgi?id=75521

>From your xhci log I can see:

[   57.822902] xhci_hcd 0000:01:00.0: ERROR Unknown event condition, HC probably busted

- we get unknown transfer events, that we have no idea how to handle
(should add debugging to show event number)

[   57.839677] xhci_hcd 0000:01:00.0: ERROR Transfer event TRB DMA ptr not part of current TD ep_index 4 comp_code 13

- we get a short packet transfer event (comp_code 13) meaning we got less bytes from the device than we asked for.
  but the worrying thing is that this event was not part of a currently active transfer descriptor.

[   57.850079] xhci_hcd 0000:01:00.0: Looking for event-dma 000000001e5e2250 trb-start 000000001e5e22c0 trb-end 000000001e5e22c0 seg-start 000000001e5e2000 seg-end 000000001e5e23f0

- This tells that the event was for some old transfer, 1e5e2250, which we moved past, we are now handling transfers starting at 1e5e22c0.

Now its just a matter of figuring out why we get these events, and how to fix it :)

-Mathias


 
   
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html



[Index of Archives]     [Linux Media]     [Linux Input]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [Old Linux USB Devel Archive]

  Powered by Linux