Kernel panic on Intel NUC D34010WYKH and Ubuntu 14.04

[jelzinga]

Since the installation of the Sundtek device with the Net-Installer I have kernel-panics occasionally on my Intel NUC D34010WYKH (Intel i3).

I'm beginning to suspect there is something 'wrong' with the USB3-implementation on Linux on the device, since I would expect the Sundtek-drivers being userspace-drivers they alone can not cause kernel-panics... However, I must say that it only happened after I connected the Sundtek USB-stick and "the taint is on mediasrv" which is from the Sundtek-drivers.

I was wondering if any of you guys can shine some light on my issue, hence a copy/paste of the stack-trace after a recent kernel-panic:

Code: [Auswählen]

May  5 01:17:26 xbmc kernel: [31865.863680] ------------[ cut here ]------------
May  5 01:17:26 xbmc kernel: [31865.863691] WARNING: CPU: 1 PID: 2315 at /home/apw/COD/linux/drivers/usb/host/xhci-ring.c:569 xhci_find_new_dequeue_state+0x231/0x260()
May  5 01:17:26 xbmc kernel: [31865.863693] Modules linked in: ir_lirc_codec ir_mce_kbd_decoder ir_sanyo_decoder ir_sony_decoder ir_jvc_decoder ir_rc6_decoder ir_rc5_decoder ir_nec_decoder rc_rc6_mce nuvoton_cir des_generic md4 mceusb lirc_dev bnep rfcomm bluetooth 6lowpan_iphc snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic nls_utf8 cifs fscache joydev nls_iso8859_1 hid_sunplus usbhid intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel snd_hda_intel kvm snd_hda_codec snd_hwdep snd_pcm ftdi_sio usbserial crct10dif_pclmul crc32_pclmul i915 ghash_clmulni_intel snd_seq_midi snd_seq_midi_event aesni_intel rc_core aes_x86_64 snd_rawmidi lrw gf128mul snd_seq drm_kms_helper glue_helper i2c_hid ablk_helper snd_seq_device snd_timer parport_pc cryptd dw_dmac hid drm dw_dmac_core snd video ppdev 8250_dw i2c_designware_platform soundcore mei_me i2c_algo_bit spi_pxa2xx_platform lpc_ich mei i2c_designware_core lp microcode mac_hid parport e1000e ahci ptp libahci pps_core sdhci_acpi sdhci [last unloaded: nuvoton_cir]
May  5 01:17:26 xbmc kernel: [31865.863768] CPU: 1 PID: 2315 [b]Comm: mediasrv Tainted: G      D      3.14.1-031401-generic #201404141220[/b]
May  5 01:17:26 xbmc kernel: [31865.863770] Hardware name:                  /D34010WYK, BIOS WYLPT10H.86A.0025.2014.0303.1008 03/03/2014
May  5 01:17:26 xbmc kernel: [31865.863772]  0000000000000239 ffff8800a183dbf8 ffffffff8175bbf5 0000000000000007
May  5 01:17:26 xbmc kernel: [31865.863776]  0000000000000000 ffff8800a183dc38 ffffffff8106ac9c ffffffff81595770
May  5 01:17:26 xbmc kernel: [31865.863780]  ffff8800368aa000 ffff880036b545c0 ffff8800a183dcc0 ffff8800d6ed8000
May  5 01:17:26 xbmc kernel: [31865.863784] Call Trace:
May  5 01:17:26 xbmc kernel: [31865.863789]  [<ffffffff8175bbf5>] dump_stack+0x46/0x58
May  5 01:17:26 xbmc kernel: [31865.863794]  [<ffffffff8106ac9c>] warn_slowpath_common+0x8c/0xc0
May  5 01:17:26 xbmc kernel: [31865.863800]  [<ffffffff81595770>] ? trace_xhci_dbg_quirks+0x70/0x70
May  5 01:17:26 xbmc kernel: [31865.863803]  [<ffffffff8106acea>] warn_slowpath_null+0x1a/0x20
May  5 01:17:26 xbmc kernel: [31865.863807]  [<ffffffff815a3731>] xhci_find_new_dequeue_state+0x231/0x260
May  5 01:17:26 xbmc kernel: [31865.863810]  [<ffffffff81599e51>] xhci_cleanup_stalled_ring+0x71/0x100
May  5 01:17:26 xbmc kernel: [31865.863813]  [<ffffffff8159a016>] xhci_endpoint_reset+0x136/0x1a0
May  5 01:17:26 xbmc kernel: [31865.863817]  [<ffffffff81567b45>] usb_hcd_reset_endpoint+0x25/0x70
May  5 01:17:26 xbmc kernel: [31865.863821]  [<ffffffff8156ada8>] usb_enable_endpoint+0xa8/0xb0
May  5 01:17:26 xbmc kernel: [31865.863824]  [<ffffffff8156adf2>] usb_enable_interface+0x42/0x60
May  5 01:17:26 xbmc kernel: [31865.863828]  [<ffffffff8156b2e6>] usb_set_interface+0x1f6/0x340
May  5 01:17:26 xbmc kernel: [31865.863831]  [<ffffffff815756a9>] usbdev_do_ioctl+0x589/0xc50
May  5 01:17:26 xbmc kernel: [31865.863835]  [<ffffffff810a4fb9>] ? account_user_time+0x99/0xb0
May  5 01:17:26 xbmc kernel: [31865.863838]  [<ffffffff81575d9e>] usbdev_ioctl+0xe/0x20
May  5 01:17:26 xbmc kernel: [31865.863843]  [<ffffffff811e46e5>] do_vfs_ioctl+0x75/0x2c0
May  5 01:17:26 xbmc kernel: [31865.863846]  [<ffffffff81024195>] ? syscall_trace_enter+0x165/0x280
May  5 01:17:26 xbmc kernel: [31865.863850]  [<ffffffff811eea95>] ? __fget_light+0x25/0x70
May  5 01:17:26 xbmc kernel: [31865.863853]  [<ffffffff811e49c1>] SyS_ioctl+0x91/0xb0
May  5 01:17:26 xbmc kernel: [31865.863858]  [<ffffffff8177247f>] tracesys+0xe1/0xe6
May  5 01:17:26 xbmc kernel: [31865.863860] ---[ end trace f07cfa4073dc9914 ]---
May  5 01:17:26 xbmc kernel: [31865.863869] BUG: unable to handle kernel NULL pointer dereference at 0000000000000010
May  5 01:17:26 xbmc kernel: [31865.863910] IP: [<ffffffff815a37c5>] xhci_queue_new_dequeue_state+0x65/0xd0
May  5 01:17:26 xbmc kernel: [31865.863944] PGD 36ac3067 PUD d8b44067 PMD 0
May  5 01:17:26 xbmc kernel: [31865.863969] Oops: 0000 [#2] SMP
May  5 01:17:26 xbmc kernel: [31865.863987] Modules linked in: ir_lirc_codec ir_mce_kbd_decoder ir_sanyo_decoder ir_sony_decoder ir_jvc_decoder ir_rc6_decoder ir_rc5_decoder ir_nec_decoder rc_rc6_mce nuvoton_cir des_generic md4 mceusb lirc_dev bnep rfcomm bluetooth 6lowpan_iphc snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic nls_utf8 cifs fscache joydev nls_iso8859_1 hid_sunplus usbhid intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel snd_hda_intel kvm snd_hda_codec snd_hwdep snd_pcm ftdi_sio usbserial crct10dif_pclmul crc32_pclmul i915 ghash_clmulni_intel snd_seq_midi snd_seq_midi_event aesni_intel rc_core aes_x86_64 snd_rawmidi lrw gf128mul snd_seq drm_kms_helper glue_helper i2c_hid ablk_helper snd_seq_device snd_timer parport_pc cryptd dw_dmac hid drm dw_dmac_core snd video ppdev 8250_dw i2c_designware_platform soundcore mei_me i2c_algo_bit spi_pxa2xx_platform lpc_ich mei i2c_designware_core lp microcode mac_hid parport e1000e ahci ptp libahci pps_core sdhci_acpi sdhci [last unloaded: nuvoton_cir]
May  5 01:17:26 xbmc kernel: [31865.864495] CPU: 1 PID: 2315 Comm: mediasrv Tainted: G      D W    3.14.1-031401-generic #201404141220
May  5 01:17:26 xbmc kernel: [31865.864534] Hardware name:                  /D34010WYK, BIOS WYLPT10H.86A.0025.2014.0303.1008 03/03/2014
May  5 01:17:26 xbmc kernel: [31865.864574] task: ffff8800af0cb1e0 ti: ffff8800a183c000 task.ti: ffff8800a183c000
May  5 01:17:26 xbmc kernel: [31865.864606] RIP: 0010:[<ffffffff815a37c5>]  [<ffffffff815a37c5>] xhci_queue_new_dequeue_state+0x65/0xd0
May  5 01:17:26 xbmc kernel: [31865.864649] RSP: 0018:ffff8800a183dc48  EFLAGS: 00010046
May  5 01:17:26 xbmc kernel: [31865.864672] RAX: 0000000000000000 RBX: ffff8800a183dcc0 RCX: 0000000000000000
May  5 01:17:26 xbmc kernel: [31865.864702] RDX: 0000000000000000 RSI: ffff8800d6ed0000 RDI: 0000000000000000
May  5 01:17:26 xbmc kernel: [31865.864733] RBP: ffff8800a183dca8 R08: ffff8800a183dcc0 R09: ffff8800d6ed0000
May  5 01:17:26 xbmc kernel: [31865.864764] R10: 0000000000000003 R11: 0000000000000455 R12: ffff8800368aa000
May  5 01:17:26 xbmc kernel: [31865.864794] R13: ffff8800d6ed81f8 R14: 0000000000000000 R15: 0000000000000002
May  5 01:17:26 xbmc kernel: [31865.864826] FS:  00007fe7b2462700(0000) GS:ffff88011fa80000(0000) knlGS:0000000000000000
May  5 01:17:26 xbmc kernel: [31865.864861] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
May  5 01:17:26 xbmc kernel: [31865.864885] CR2: 0000000000000010 CR3: 00000000d6e71000 CR4: 00000000001407e0
May  5 01:17:26 xbmc kernel: [31865.864915] Stack:
May  5 01:17:26 xbmc kernel: [31865.864925]  ffff8800a183dcb8 ffff8800a183dc68 ffffffff81adc073 ffff8800d6ed0000
May  5 01:17:26 xbmc kernel: [31865.868359]  0000000200000003 00000000a183dcd0 ffff8800368aa000 ffff8800d6ed81f8
May  5 01:17:26 xbmc kernel: [31865.871788]  ffff8800368aa000 ffff8800d6ed0000 0000000000000002 ffff8800368aa048
May  5 01:17:26 xbmc kernel: [31865.875182] Call Trace:
May  5 01:17:26 xbmc kernel: [31865.878582]  [<ffffffff81599ed1>] xhci_cleanup_stalled_ring+0xf1/0x100
May  5 01:17:26 xbmc kernel: [31865.881853]  [<ffffffff8159a016>] xhci_endpoint_reset+0x136/0x1a0
May  5 01:17:26 xbmc kernel: [31865.885003]  [<ffffffff81567b45>] usb_hcd_reset_endpoint+0x25/0x70
May  5 01:17:26 xbmc kernel: [31865.888042]  [<ffffffff8156ada8>] usb_enable_endpoint+0xa8/0xb0
May  5 01:17:26 xbmc kernel: [31865.890984]  [<ffffffff8156adf2>] usb_enable_interface+0x42/0x60
May  5 01:17:26 xbmc kernel: [31865.893814]  [<ffffffff8156b2e6>] usb_set_interface+0x1f6/0x340
May  5 01:17:26 xbmc kernel: [31865.896600]  [<ffffffff815756a9>] usbdev_do_ioctl+0x589/0xc50
May  5 01:17:26 xbmc kernel: [31865.899361]  [<ffffffff810a4fb9>] ? account_user_time+0x99/0xb0
May  5 01:17:26 xbmc kernel: [31865.902094]  [<ffffffff81575d9e>] usbdev_ioctl+0xe/0x20
May  5 01:17:26 xbmc kernel: [31865.904796]  [<ffffffff811e46e5>] do_vfs_ioctl+0x75/0x2c0
May  5 01:17:26 xbmc kernel: [31865.907479]  [<ffffffff81024195>] ? syscall_trace_enter+0x165/0x280
May  5 01:17:26 xbmc kernel: [31865.910158]  [<ffffffff811eea95>] ? __fget_light+0x25/0x70
May  5 01:17:26 xbmc kernel: [31865.912839]  [<ffffffff811e49c1>] SyS_ioctl+0x91/0xb0
May  5 01:17:26 xbmc kernel: [31865.915514]  [<ffffffff8177247f>] tracesys+0xe1/0xe6
May  5 01:17:26 xbmc kernel: [31865.918191] Code: 10 01 00 00 4c 89 c3 4d 8b 48 08 49 89 fc 44 89 55 c0 89 4d cc 4c 89 f7 4c 89 ce 4c 8d 68 28 4c 89 4d b8 e8 ee ec ff ff 8b 53 10 <4d> 8b 46 10 4c 89 f1 4c 8b 4d b8 48 89 04 24 4c 89 e7 48 c7 c6
May  5 01:17:26 xbmc kernel: [31865.921175] RIP  [<ffffffff815a37c5>] xhci_queue_new_dequeue_state+0x65/0xd0
May  5 01:17:26 xbmc kernel: [31865.923962]  RSP <ffff8800a183dc48>
May  5 01:17:26 xbmc kernel: [31865.926748] CR2: 0000000000000010
May  5 01:17:26 xbmc kernel: [31865.946709] ---[ end trace f07cfa4073dc9915 ]---
This is taken on Ubuntu 14.04 - it happened on both the supplied 3.13 kernel as well on the 3.14.1 kernel which is installed right now.

Unfortunately the device has only USB3-ports connected on the outside and I can not seem to find a way to 'fall back' on EHCI rather than XCHI - but perhaps you can shine a light on this ?

To clarify, it is this device:
http://www.intel.nl/content/www/nl/nl/nuc/nuc-kit-d34010wykh.html

I have BIOS 0025 installed on it (latest stable) and Ubuntu 14.04 with kernel 3.14.1 (Linux 3.14.1-031401-generic #201404141220 SMP Mon Apr 14 16:21:48 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux)

[Sundtek]

I just created a bugreport on bugzilla.kernel.org; let's try to push this a little bit it's indeed a kernel bug - not related to our drivers at all but they are affected by this bug.

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

There are USB 3.0 issues known with various systems, however we are currently manufacturing new satellite devices and would only have time to dig closer into it once we're done with that process.

As a workaround you might try some older Linux kernel which only supports USB 2.0 (ehci driver)

[jelzinga]

Markus, thanks for the (almost) immediate update, much appreciated !

I figured the problem was indeed in the XHCI-implementation in the Linux kernel. Unfortunately, there are only USB3 headers connected to the outside of the small NUC-case, but I learned there is a USB2-connector on the inside. I have not checked if there is a possibility to use that header, but since the case is so compact I fear it requires a Dremel-tool, measures which I rather not take

In the meantime I have successfully installed the stick on my Synology DS211J and use a Network-connection to my i3. This seems to work, but I end up with interruptions on the stream, and TVHeadend then cuts off the stream.. So that is not ideal. I suspect the DS211J lacks the RAM/CPU to hold up - but I have not investigated fully.

Perhaps my Raspberry Pi would be better suited for this in the meantime until this kernel-issue gets resolved?

[Sundtek]

Are you using our Network Implementation?
If so be sure you enable PID Filtering on your client, we noticed passing the full transport stream from the NAS to various target systems might cause hickups (full TS = around 50-60mbit constantly!). But you should be rather safe when enabling the filter so it will decrease the network bandwidth to around 0.5-2mb/sec (depending if SD or HD)
The NAS shows up the current bandwidth utilization in the webinterface nicely.

[jelzinga]

Yeah I am using the PID-filtering. I can see the transfer in the web-interface to be 1-2 Mbyte/sec when streaming so it is definitely not sending the whole mux over the LAN.

It is not so much hickups or artifacts, the stream simply stops after a while (on XBMC with Tvheadend addon) or it repeats a small portion of the stream (VLC Media Player with HTSP plugin). Bit unsure what causes it, I have not seen this behavior when the stick was plugged in on the local TVheadend-machine.

I'm uncertain if dropping to a lower kernel without USB3-support will be a serious option, I don't know when xhci was added to the kernel but I'm worried such an old kernel will have other negative consequences (e.g. crappy video-performance on the Haswell onboard video).

[Sundtek]

http://support.sundtek.com/index.php/topic,179.0.html

http://support.sundtek.com/index.php/topic,841.0.html

We successfully used this one for live streaming, however filtering needs to be enabled.

[jelzinga]

Unfortunately, I can not *keep* it working with the Synology. Everything seems to work OK, but after ~5 till ~10 minutes I get a Transport Error in TVHeadend and I need to restart the stream. Obviously not a success watching TV like that. I am uncertain what causes this - I do not have any similar issues when I use the stick on the local tvheadend-server (but that is the kernel panic machine...)

Obviously it might also be a problem with TVheadend interpreting something wrong as a transport-error, I don't know. Right now I do not have a whole lot of other options to test, any recommendations on this problem ?

I've looked around a bit for 'an older kernel' but without USB3 you are looking at kernels >5 years old, which will have other issues (e.g. no TRIM, no decent video-performance, etc etc) so that is not a work-around which is possible.

[Sundtek]

Are you using our network driver implementation or do you use tvheadend only for streaming?

Which Synology NAS is that?
Our NAS is a Synology DS213J and we have no problem with it

[jelzinga]

The NAS is a Synology DS211J (ARMv5 / 128 Mb.)

I am using the Network driver implementation, because running Tvheadend on it will put an even bigger strain on the already poor CPU. Your DS213J has an ARMv7 if I recall correctly which is a lot more powerful - it might explain the difference. I did the driver-installation via the Synology web-interface after adding the Sundtek-repo to it. I also tried using PID-filter. The stream runs for about 5~ minutes and then it stops with a Transport-error in Tvheadend.



Nevertheless, I got a few more hardware-options available, so I am not giving up yet. Next project will be either trying to use internal USB2 headers on my Intel NUC or trying to run it on an old Atom-board I might still have lying around somewhere

[Sundtek]

Did you disable Full Mux Reception in your tvheadend configuration?

Because by default TVHeadend tries to read all the TS Datastream which would be 5 MB/Sec which makes TS filtering on the NAS obsolete.

/opt/bin/mediaclient --lc should show up a number of PIDs below the demux node (if it shows up 0x2000 then it means it will send out the entire TS stream).

[jelzinga]

I do not think there is "Full Mux Reception" anymore in TvHeadend 3.9.

I saw roughly 1.5-2.0 Megabyte/sec traffic outgoing on the Synology webinterface, I doubt that is a full mux (of 40-50 Mbit from my cable-provider). Nevertheless I can give that --lc command a go to see what I get.

But it all honesty, the DS211J with DSM5 already has a cpu-load when i simply click somewhere at the webinterface. I do not hold my breath if this can run it properly.

[jelzinga]

I´m trying to run TVheadend 3.9 now on the Synology DS211J. My CPU-load is roughly 100% when watching HD channels.

My output of --lc±

./mediaclient --lc
**** List of Media Clients ****
/dev/dvb/adapter0/frontend0:
  5495 ... tvheadend
/dev/dvb/adapter0/dvr0:
  5495 ... tvheadend
/dev/dvb/adapter0/demux0:
  5495 ... tvheadend (0000)
  5495 ... tvheadend (0001)
  5495 ... tvheadend (0010)
  5495 ... tvheadend (0011)
  5495 ... tvheadend (0012)
  5495 ... tvheadend (138f)
  5495 ... tvheadend (1838)
  5495 ... tvheadend (1839)
  5495 ... tvheadend (183a)
  5495 ... tvheadend (183b)
  5495 ... tvheadend (041c)
/dev/mediainput0:
  No client connected

Unfortunately this version of tvheadend has no option to turn off full mux-reception. You think I should make changes to /etc/sundtek.conf on the NAS to change this or...

[Sundtek]

The CPU Load of the NAS is 100% which processes use the CPU?

the PID filtering parts look okay.

[jelzinga]

tvheadend uses the largest part (up to 95%) - but with some smart 'tvheadend-tweaking' I managed to drop it to considerable less (45%) while watching a HD channel @ 12 Mbit as shown below:

Code: [Auswählen]

Mem: 98652K used, 19664K free, 0K shrd, 2864K buff, 22436K cached
CPU: [b]43.2%[/b] usr  1.3% sys  0.0% nic 55.1% idle  0.0% io  0.0% irq  0.1% sirq
Load average: 0.13 0.33 0.46 4/195 21429
  PID  PPID USER     STAT   VSZ %MEM %CPU COMMAND
 5495     1 tvheaden S     269m232.3 [b]43.7[/b] /usr/local/tvheadend-testing/bin/tvheadend
The biggest reason why TVHeadend uses so much CPU is mostly because my DVB-C is encrypted : TVHeadend has to use CSA (via Oscam) to decrypt the Irdeto-protection

Nevertheless, it seems to be working now, as long as I don't do anything else on the NAS obviously

Now all I need is a kernel-patch for the USB3 issues so I can move back to my i3 with the stick - but keeping my fingers crossed this will hold in the meantime

[eleete0712]

So are there any news about this issue (the USB kernel stuff)?
Is anybody working on it?

Because i'm also desperatly waiting for a solution.