ALSA driver crash on USB sound card

[ddv2005]

Hello,

I have external USB sound card connected to the board.
But on "aplay -D plughw:0,0 -v ./beep.wav" I got an error:
76.571730 ------------ cut here ------------
76.576553 WARNING: at lib/kref.c:34 kref_get+0x40/0x48()
76.582179 Modules linked in: evdev snd_usb_audio snd_seq snd_pcm snd_timer snd_page_alloc snd_hwdep snd_usbmidi_lib snd_rawmidi snd_seq_device snd ipv6 last unloaded: scsi_wait_scan
76.599419 c00153d4 (unwind_backtrace+0x0/0xfc) from c03fba1c (dump_stack+0x20/0x24)
76.608193 c03fba1c (dump_stack+0x20/0x24) from c002d4b0 (warn_slowpath_common+0x5c/0x74)
76.617402 c002d4b0 (warn_slowpath_common+0x5c/0x74) from c002d4f4 (warn_slowpath_null+0x2c/0x34)
76.627329 c002d4f4 (warn_slowpath_null+0x2c/0x34) from c0251530 (kref_get+0x40/0x48)
76.636183 c0251530 (kref_get+0x40/0x48) from c02daafc (usb_get_urb+0x20/0x28)
76.644417 c02daafc (usb_get_urb+0x20/0x28) from c02d9cec (usb_hcd_flush_endpoint+0x110/0x160)
76.654064 c02d9cec (usb_hcd_flush_endpoint+0x110/0x160) from c02dc6ec (usb_disable_endpoint+0x60/0x90)
76.664514 c02dc6ec (usb_disable_endpoint+0x60/0x90) from c02dc768 (usb_disable_interface+0x4c/0x64)
76.674705 c02dc768 (usb_disable_interface+0x4c/0x64) from c02dcdac (usb_set_interface+0x168/0x244)
76.684934 c02dcdac (usb_set_interface+0x168/0x244) from bf0e16b8 (snd_usb_pcm_close.clone.2+0x48/0x74 snd_usb_audio)
76.696960 bf0e16b8 (snd_usb_pcm_close.clone.2+0x48/0x74 snd_usb_audio) from bf0e1728 (snd_usb_playback_close+0x20/0x24 snd_usb_audio)
76.710698 bf0e1728 (snd_usb_playback_close+0x20/0x24 snd_usb_audio) from bf0a6bc0 (snd_pcm_release_substream+0x64/0xb8 snd_pcm)
76.723831 bf0a6bc0 (snd_pcm_release_substream+0x64/0xb8 snd_pcm) from bf0a6c4c (snd_pcm_release+0x38/0x7c snd_pcm)
76.735788 bf0a6c4c (snd_pcm_release+0x38/0x7c snd_pcm) from c00f7f74 (fput+0xc0/0x218)
76.753002 c00f7f74 (fput+0xc0/0x218) from c00f43b4 (filp_close+0x78/0x90)
76.768920 c00f43b4 (filp_close+0x78/0x90) from c00f4488 (sys_close+0xbc/0x118)
76.785391 c00f4488 (sys_close+0xbc/0x118) from c000e140 (ret_fast_syscall+0x0/0x48)
76.802331 --- end trace b01813e49adb0423 ---

[fsonnlei]

Same here with USB Audio (with or without snd_bcm2835 loaded):

------------[ cut here ]------------
WARNING: at lib/kref.c:34 kref_get+0x40/0x48()
Modules linked in: snd_bcm2835 ipv6 jfs snd_usb_audio snd_usbmidi_lib snd_hwdep snd_seq_midi snd_seq_midi_event snd_rawmidi snd_pcm snd_page_alloc snd_seq snd_seq_device snd_timer snd evdev
c00153d4 (unwind_backtrace+0x0/0xfc) from
c03fba1c (dump_stack+0x20/0x24) from
c002d4b0 (warn_slowpath_common+0x5c/0x74) from
c002d4f4 (warn_slowpath_null+0x2c/0x34) from
c0251530 (kref_get+0x40/0x48) from
c02daafc (usb_get_urb+0x20/0x28) from
c02d9cec (usb_hcd_flush_endpoint+0x110/0x160) from
c02dc6ec (usb_disable_endpoint+0x60/0x90) from
c02dc768 (usb_disable_interface+0x4c/0x64) from
c02dcdac (usb_set_interface+0x168/0x244) from [](snd_usb_pcm_close.clone.2+0x48/0x74 [snd_usb_audio])
bf0986b8 (snd_usb_pcm_close.clone.2+0x48/0x74 [snd_usb_audio]) from [](snd_usb_playback_close+0x20/0x24 [snd_usb_audio])
bf098728 (snd_usb_playback_close+0x20/0x24 [snd_usb_audio]) from [](snd_pcm_release_substream+0x64/0xb8 [snd_pcm])
bf04fbc0 (snd_pcm_release_substream+0x64/0xb8 [snd_pcm]) from [](snd_pcm_release+0x38/0x7c [snd_pcm])
bf04fc4c (snd_pcm_release+0x38/0x7c [snd_pcm]) from
c00f7f74 (fput+0xc0/0x218) from
c00f43b4 (filp_close+0x78/0x90) from
c00f4488 (sys_close+0xbc/0x118) from
---[ end trace 2a4143d5dbc21058 ]---

[ddv2005]

I just got a kernel crash report that happened in 6 seconds after the WARNING:

---

kernel BUG at mm/slab.c:3114!
Unable to handle kernel NULL pointer dereference at virtual adress 00000
pgd = ccc2c000
*pgd=0db36831, *pte = 0, *ppte = 0

Internal error: Oops: 817 [#1] PREEMPT

[ddv2005]

it is look like problem in dwc_otg driver. I put some debug messages in kernel and found that URB double freed on IRQ

120.248276 usb_disable_endpoint dev CD9FF800, epaddr 1
120.254104 urb_free_urb kref CDB62C80, urb CDB62C80
120.259221 ------------ cut here ------------
120.263996 WARNING: at drivers/usb/core/urb.c:99 usb_free_urb+0x6c/0x80()
120.271039 Modules linked in: ipv6 snd_usb_audio snd_pcm snd_page_alloc snd_hwdep snd_usbmidi_lib snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq snd_timer snd_seq_device snd evdev
120.288311 c0014ee4 (unwind_backtrace+0x0/0xfc) from c03f5628 (dump_stack+0x20/0x24)
120.297078 c03f5628 (dump_stack+0x20/0x24) from c002e548 (warn_slowpath_common+0x5c/0x74)
120.306281 c002e548 (warn_slowpath_common+0x5c/0x74) from c002e58c (warn_slowpath_null+0x2c/0x34)
120.316198 c002e58c (warn_slowpath_null+0x2c/0x34) from c02d0f1c (usb_free_urb+0x6c/0x80)
120.325408 c02d0f1c (usb_free_urb+0x6c/0x80) from c02cdfe0 (usb_hcd_giveback_urb+0xa0/0x108)
120.334907 c02cdfe0 (usb_hcd_giveback_urb+0xa0/0x108) from c02f565c (_complete+0x14c/0x2b4)
120.344298 c02f565c (_complete+0x14c/0x2b4) from c02f6cfc (update_isoc_urb_state+0x118/0x270)
120.353855 c02f6cfc (update_isoc_urb_state+0x118/0x270) from c02f80e4 (handle_hc_xfercomp_intr+0x40c/0x4bc)
120.364663 c02f80e4 (handle_hc_xfercomp_intr+0x40c/0x4bc) from c02f8cc8 (dwc_otg_hcd_handle_hc_n_intr+0x67c/0x9f8)
120.376085 c02f8cc8 (dwc_otg_hcd_handle_hc_n_intr+0x67c/0x9f8) from c02f90c0 (dwc_otg_hcd_handle_hc_intr+0x7c/0xa0)
120.387594 c02f90c0 (dwc_otg_hcd_handle_hc_intr+0x7c/0xa0) from c02f9238 (dwc_otg_hcd_handle_intr+0x154/0x230)
120.398672 c02f9238 (dwc_otg_hcd_handle_intr+0x154/0x230) from c02f5f48 (dwc_otg_hcd_irq+0x1c/0x28)
120.408791 c02f5f48 (dwc_otg_hcd_irq+0x1c/0x28) from c02cd670 (usb_hcd_irq+0x48/0xc0)
120.417663 c02cd670 (usb_hcd_irq+0x48/0xc0) from c0089654 (handle_irq_event_percpu+0x80/0x2f4)
120.427313 c0089654 (handle_irq_event_percpu+0x80/0x2f4) from c0089928 (handle_irq_event+0x60/0x88)
120.437415 c0089928 (handle_irq_event+0x60/0x88) from c008b7a4 (handle_level_irq+0x98/0x134)
120.446888 c008b7a4 (handle_level_irq+0x98/0x134) from c0088f2c (generic_handle_irq+0x3c/0x50)
120.456545 c0088f2c (generic_handle_irq+0x3c/0x50) from c000ed4c (handle_IRQ+0x40/0x94)
120.465568 c000ed4c (handle_IRQ+0x40/0x94) from c0008490 (asm_do_IRQ+0x18/0x1c)
120.473888 c0008490 (asm_do_IRQ+0x18/0x1c) from c03fbb80 (__irq_usr+0x40/0xc0)
120.482094 Exception stack(0xcda57fb0 to 0xcda57ff8)
120.487285 7fa0: 400112e7 400112e7 017d0a58 00000000
120.495672 7fc0: 400112e7 017d1128 400112e7 00000004 00000000 400102bc 40010154 400102e4
120.504055 7fe0: 40010068 41ce1ca0 00023be8 00010c90 60000010 ffffffff
120.510839 --- end trace ce15b91c2ced1937 ---
120.517349 usb_hcd_flush_endpoint udev CD9FF800, ep CDA6F360
120.523745 usb_set_interface i 2, a 0
120.528022 usb_disable_endpoint dev CD9FF800, epaddr 130
120.533746 usb_hcd_flush_endpoint udev CD9FF800, ep CDA6F420

[ddv2005]

I did some patch ( https://gist.github.com/2973955 ) that work but I still see some possible problem in code:

usb_hcd_check_unlink_urb use ep->urb_list that must be synchronized via hcd_urb_list_lock. But usb_hcd_check_unlink_urb does not use it and no way to do it outside hcd.c . I looked to another drivers and found that they just use private locks before calliing usb_hcd_check_unlink_urb. I did it but it is still wrong way because usb_hcd_flush_endpoint use SAME list at SAME time and they don't lock private locks because it called by usb core.

[bryankemp]

Very glad to see that someone had found and fixed the issue. How does your patch get into the firmware updates? I have been using the rpi-update method, but if there is something else I need to do, that would be ok as well. I am working on a project that uses an external DAC via USB and it crashes on me a nearly 100% of the time.

[tclaesson]

Second bryankemp, thanks a lot for helping solve this! Getting crashes after a few seconds of playing with a cambridge dac magic.

[bryankemp]

ddv2005, this is so much better the e17 DAC is very happy now. Are you planning on submitting a pull request to have this added to the rpi/linux tree? I don't mind doing it if needed.

[arj03]

+1 :)

[bryankemp]

Well, I am happy to report that I tested by playing more than 12 hours of audio through the system. Using various formats, bit/sample rates, and it worked without a problem. There are some additional things to be done, but this is a great great start. I have not a response from ddv2005 and while I certainly do not want to take any credit for his efforts at debugging the issue and building a patch for it, the patch is now a little out of synch from the module code. I will post a more updated patch later today and I think I will go ahead and submit a pull request for the patch. ddv2005, if you would prefer I do not do that, please let me know and I will be more than glad to defer.

[bryankemp]

Here is the patch for the latest dwc_otg code: https://gist.github.com/3068136

[popcornmix]

Thanks for patch. The pull request has been applied and pushed to rpi-update repo.
Please update and confirm the problem is fixed in official firmware.

[bryankemp]

Really, all the credit should go to DDV2005. He did the tough part.

[splinedrive]

good job! It made my day.

[tclaesson]

Works here too, thanks a lot mates!