I am running an EM7565 running SWI9X50C_01.09.04.00 on OpenWrt with kernel 4.19.80 connected to an IPQ4019 on USB3 via mPCIe + adaptor. Getting the following crash. It seems to happen after an arbitrary amount of time, could be anywhere from a half an hour of use to a few days. I am just hoping for some suggestions on how to continue investigating, because I do not know the cause of this problem. Currently I am using ModemManager 10.8, libqmi 1.24.0 and libmbim 1.20, but I have tried various recent versions. I have also experimented with GobiSerial + libmbim but not GobiNet as of yet.
Is there some way to get the module to write it’s own logs to a file on the host?
My hunch is I think there is some miscommunication between the modules and the xhci-hcd driver. Also, I think it tends to happen when my signal is poor: for example RSRP less than -119dBm. Would using GobiSerial and GobiNet be a good start at trying to find a workaround? Any advice would be greatly appreciated
Here is a crash in QMI mode with qmi_wwan
Sun Oct 27 06:56:58 2019 kern.warn kernel: [ 4372.964719] xhci-hcd xhci-hcd.0.auto: ERROR unknown event type 37
Sun Oct 27 06:56:58 2019 kern.warn kernel: [ 4372.983113] xhci-hcd xhci-hcd.0.auto: ERROR unknown event type 37
Sun Oct 27 06:56:58 2019 kern.warn kernel: [ 4373.002448] xhci-hcd xhci-hcd.0.auto: ERROR unknown event type 37
Sun Oct 27 06:56:58 2019 kern.warn kernel: [ 4373.021859] xhci-hcd xhci-hcd.0.auto: ERROR unknown event type 37
Sun Oct 27 06:56:58 2019 kern.err kernel: [ 4373.024543] qmi_wwan 1-1:1.8: nonzero urb status received: -71
Sun Oct 27 06:56:58 2019 kern.err kernel: [ 4373.027175] qmi_wwan 1-1:1.8: wdm_int_callback - 0 bytes
Sun Oct 27 06:56:58 2019 kern.warn kernel: [ 4373.049578] xhci-hcd xhci-hcd.0.auto: ERROR unknown event type 37
Sun Oct 27 06:56:58 2019 kern.warn kernel: [ 4373.068801] xhci-hcd xhci-hcd.0.auto: ERROR unknown event type 37
Sun Oct 27 06:56:58 2019 kern.warn kernel: [ 4373.088147] xhci-hcd xhci-hcd.0.auto: ERROR unknown event type 37
Sun Oct 27 06:56:58 2019 kern.warn kernel: [ 4373.107536] xhci-hcd xhci-hcd.0.auto: ERROR unknown event type 37
and a crash in MBIM mode with cdc_mbim
[566389.792034] usb 1-1: USB disconnect, device number 2
[566394.603851] cdc_mbim 1-1:1.12: Tx URB error: -19
[566394.829730] xhci-hcd xhci-hcd.0.auto: xHCI host not responding to stop endpoint command.
[566394.846083] xhci-hcd xhci-hcd.0.auto: Host halt failed, -110
[566394.846315] xhci-hcd xhci-hcd.0.auto: xHCI host controller not responding, assume dead
[566394.851573] xhci-hcd xhci-hcd.0.auto: HC died; cleaning up
[566394.862108] qcserial ttyUSB0: Qualcomm USB modem converter now disconnected from ttyUSB0
[566394.865473] qcserial 1-1:1.0: device disconnected
[566394.880516] qcserial ttyUSB1: Qualcomm USB modem converter now disconnected from ttyUSB1
[566394.881892] qcserial 1-1:1.3: device disconnected
[566394.892850] cdc_mbim 1-1:1.12 wwan0: unregister 'cdc_mbim' usb-xhci-hcd.0.auto-1, CDC MBIM
[566394.897722] failed to kill vid 0081/0 for device wwan0
And an earlier crash
Sat Oct 26 11:06:20 2019 daemon.warn [8652]: <warn> Reloading stats failed: Transaction timed out
Sat Oct 26 11:06:20 2019 daemon.warn [8652]: <warn> Couldn't load extended signal information: Transaction timed out
Sat Oct 26 11:06:21 2019 kern.info kernel: [ 5402.778911] usb 1-1: USB disconnect, device number 2
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5402.832709] ------------[ cut here ]------------
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5402.832761] WARNING: CPU: 2 PID: 0 at net/sched/sch_generic.c:466 dev_watchdog+0x16c/0x248
Sat Oct 26 11:06:21 2019 kern.info kernel: [ 5402.836404] NETDEV WATCHDOG: wwan0 (cdc_mbim): transmit queue 0 timed out
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5402.844507] Modules linked in: xt_connlimit qcserial pppoe ppp_async option nf_conncount iptable_nat ipt_MASQUERADE cdc_mbim ath10k_pci ath10k_core ath xt_state xt_nat xt_helper xt_conntrack xt_connmark xt_connbytes xt_REDIRECT xt_FLOWOFFLOAD xt_CT usb_wwan usb_serial_simple sierra_net sierra qmi_wwan pppox ppp_generic nf_nat_ipv4 nf_nat nf_flow_table_hw nf_flow_table nf_conntrack_rtcache nf_conntrack mac80211 ipt_REJECT cfg80211 cdc_ncm cdc_ether xt_time xt_tcpudp xt_tcpmss xt_statistic xt_recent xt_multiport xt_mark xt_mac xt_limit xt_length xt_hl xt_ecn xt_dscp xt_comment xt_TCPMSS xt_LOG xt_HL xt_DSCP xt_CLASSIFY xr_usb_serial_common wireguard usbserial usbnet ums_usbat ums_sddr55 ums_sddr09 ums_karma ums_jumpshot ums_isd200 ums_freecom ums_datafab ums_cypress ums_alauda slhc nf_reject_ipv4 nf_log_ipv4
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5402.900486] nf_defrag_ipv6 nf_defrag_ipv4 iptable_raw iptable_mangle iptable_filter ipt_ECN ip_tables hwmon crc_ccitt compat cdc_wdm xt_set ip_set_list_set ip_set_hash_netportnet ip_set_hash_netport ip_set_hash_netnet ip_set_hash_netiface ip_set_hash_net ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac ip_set_bitmap_ip ip_set nfnetlink nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 ip6_udp_tunnel udp_tunnel usb_storage leds_gpio xhci_plat_hcd xhci_pci xhci_hcd dwc3 dwc3_qcom ehci_pci ehci_platform sd_mod scsi_mod ehci_hcd gpio_button_hotplug mii
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5402.962805] CPU: 2 PID: 0 Comm: swapper/2 Tainted: G W 4.19.79 #0
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5402.985014] Hardware name: Generic DT based system
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5402.992413] [<c030e310>] (unwind_backtrace) from [<c030ab70>] (show_stack+0x10/0x14)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5402.997006] [<c030ab70>] (show_stack) from [<c0783a5c>] (dump_stack+0x88/0x9c)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.004906] [<c0783a5c>] (dump_stack) from [<c031bad0>] (__warn+0xd4/0xf0)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.011934] [<c031bad0>] (__warn) from [<c031b778>] (warn_slowpath_fmt+0x38/0x48)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.018795] [<c031b778>] (warn_slowpath_fmt) from [<c06ac288>] (dev_watchdog+0x16c/0x248)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.026348] [<c06ac288>] (dev_watchdog) from [<c0371eb8>] (call_timer_fn+0x24/0x90)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.034506] [<c0371eb8>] (call_timer_fn) from [<c03725a4>] (run_timer_softirq+0x1ac/0x418)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.041972] [<c03725a4>] (run_timer_softirq) from [<c03021c8>] (__do_softirq+0xe0/0x25c)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.050302] [<c03021c8>] (__do_softirq) from [<c031f9c8>] (irq_exit+0x9c/0xfc)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.058550] [<c031f9c8>] (irq_exit) from [<c035f7a4>] (__handle_domain_irq+0x9c/0xac)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.065583] [<c035f7a4>] (__handle_domain_irq) from [<c0538ec0>] (gic_handle_irq+0x5c/0x90)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.073482] [<c0538ec0>] (gic_handle_irq) from [<c0301a0c>] (__irq_svc+0x6c/0x90)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.081631] Exception stack(0xdf473f68 to 0xdf473fb0)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.089271] 3f60: 00000000 001b3ea0 dfb532c4 c0313ac0 ffffe000 c0b04c6c
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.094310] 3f80: 00000004 c0b04cac c0a3bda8 00000000 00000000 00000000 c0b0d740 df473fb8
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.102465] 3fa0: c0308358 c030835c 60000013 ffffffff
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.110631] [<c0301a0c>] (__irq_svc) from [<c030835c>] (arch_cpu_idle+0x34/0x38)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.115672] [<c030835c>] (arch_cpu_idle) from [<c0341a20>] (do_idle+0xf0/0x200)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.123134] [<c0341a20>] (do_idle) from [<c0341d8c>] (cpu_startup_entry+0x18/0x1c)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.130161] [<c0341d8c>] (cpu_startup_entry) from [<803023ec>] (0x803023ec)
Sat Oct 26 11:06:21 2019 kern.warn kernel: [ 5403.137828] ---[ end trace 1916688659126e01 ]---
Sat Oct 26 11:06:23 2019 daemon.warn [8652]: <warn> Couldn't load extended signal information: Transaction timed out
Sat Oct 26 11:06:24 2019 kern.err kernel: [ 5405.878356] cdc_mbim 1-1:1.12: Tx URB error: -19
Sat Oct 26 11:06:26 2019 kern.warn kernel: [ 5407.782904] xhci-hcd xhci-hcd.0.auto: xHCI host not responding to stop endpoint command.
Sat Oct 26 11:06:26 2019 kern.warn kernel: [ 5407.799267] xhci-hcd xhci-hcd.0.auto: Host halt failed, -110
Sat Oct 26 11:06:26 2019 kern.err kernel: [ 5407.799498] xhci-hcd xhci-hcd.0.auto: xHCI host controller not responding, assume dead
Sat Oct 26 11:06:26 2019 kern.err kernel: [ 5407.804779] xhci-hcd xhci-hcd.0.auto: HC died; cleaning up
Sat Oct 26 11:06:26 2019 kern.info kernel: [ 5407.815149] qcserial ttyUSB0: Qualcomm USB modem converter now disconnected from ttyUSB0
Sat Oct 26 11:06:26 2019 kern.info kernel: [ 5407.818541] qcserial 1-1:1.0: device disconnected
Sat Oct 26 11:06:26 2019 kern.info kernel: [ 5407.831180] qcserial ttyUSB1: Qualcomm USB modem converter now disconnected from ttyUSB1
Sat Oct 26 11:06:26 2019 kern.info kernel: [ 5407.832591] qcserial 1-1:1.2: device disconnected
Sat Oct 26 11:06:26 2019 kern.info kernel: [ 5407.844663] qcserial ttyUSB2: Qualcomm USB modem converter now disconnected from ttyUSB2
Sat Oct 26 11:06:26 2019 kern.info kernel: [ 5407.846265] qcserial 1-1:1.3: device disconnected
Sat Oct 26 11:06:26 2019 kern.info kernel: [ 5407.855899] cdc_mbim 1-1:1.12 wwan0: unregister 'cdc_mbim' usb-xhci-hcd.0.auto-1, CDC MBIM
Sat Oct 26 11:06:26 2019 daemon.notice netifd: Network device 'wwan0' link is down
Sat Oct 26 11:06:26 2019 kern.warn kernel: [ 5407.866783] failed to kill vid 0081/0 for device wwan0
Sat Oct 26 11:06:26 2019 daemon.warn [8652]: <warn> Couldn't load extended signal information: Transaction timed out
Sat Oct 26 11:06:26 2019 user.notice ModemManager: hotplug: remove serial interface ttyUSB0: event processed
Sat Oct 26 11:06:26 2019 user.notice ModemManager: hotplug: event reported: action=remove, name=ttyUSB0, subsystem=tty
Sat Oct 26 11:06:26 2019 daemon.debug [8652]: [/dev/cdc-wdm0] unexpected port hangup!
Sat Oct 26 11:06:26 2019 daemon.debug [8652]: [/dev/cdc-wdm0] channel destroyed
Sat Oct 26 11:06:26 2019 daemon.info [8652]: <info> Connection to mbim-proxy for /dev/cdc-wdm0 lost, reprobing
Sat Oct 26 11:06:26 2019 daemon.info [8652]: <info> [device /sys/devices/platform/soc/8af8800.usb3/8a00000.dwc3/xhci-hcd.0.auto/usb1/1-1] creating modem with plugin 'Sierra' and '5' ports
Sat Oct 26 11:06:26 2019 daemon.warn [8652]: <warn> Could not grab port (tty/ttyUSB1): 'Cannot add port 'tty/ttyUSB1', unhandled serial type'
Sat Oct 26 11:06:26 2019 daemon.warn [8652]: <warn> Could not grab port (tty/ttyUSB0): 'Cannot add port 'tty/ttyUSB0', unhandled serial type'
Sat Oct 26 11:06:26 2019 daemon.debug [8652]: [/dev/cdc-wdm0] unexpected port hangup!
Sat Oct 26 11:06:26 2019 daemon.debug [8652]: [/dev/cdc-wdm0] channel destroyed
Sat Oct 26 11:06:26 2019 daemon.warn [8652]: [/dev/cdc-wdm0] QMI client for service 'pdc' with CID '3' wasn't released
Sat Oct 26 11:06:26 2019 daemon.warn [8652]: [/dev/cdc-wdm0] QMI client for service 'nas' with CID '4' wasn't released
Sat Oct 26 11:06:26 2019 daemon.warn [8652]: [/dev/cdc-wdm0] QMI client for service 'dms' with CID '3' wasn't released
Sat Oct 26 11:06:26 2019 daemon.warn [8652]: [/dev/cdc-wdm0] QMI client for service 'loc' with CID '3' wasn't released
Sat Oct 26 11:06:26 2019 daemon.warn [8652]: <warn> Couldn't start initialization: Couldn't query file info: Error when getting information for file “/dev/cdc-wdm0”: No such file or directory
Sat Oct 26 11:06:26 2019 daemon.warn [8652]: <warn> couldn't initialize the modem: 'Modem is unusable, cannot fully initialize'
Sat Oct 26 11:06:26 2019 user.notice ModemManager: hotplug: cleanup wait for modem at sysfs path /sys/devices/platform/soc/8af8800.usb3/8a00000.dwc3/xhci-hcd.0.auto/usb1
Sat Oct 26 11:06:26 2019 daemon.info [8652]: <info> (tty/ttyUSB0): released by device '/sys/devices/platform/soc/8af8800.usb3/8a00000.dwc3/xhci-hcd.0.auto/usb1/1-1'
Sat Oct 26 11:06:26 2019 user.notice ModemManager: hotplug: remove serial interface ttyUSB1: event processed
Sat Oct 26 11:06:26 2019 user.notice ModemManager: hotplug: event reported: action=remove, name=ttyUSB1, subsystem=tty
Sat Oct 26 11:06:26 2019 user.notice ModemManager: hotplug: cleanup wait for modem at sysfs path /sys/devices/platform/soc/8af8800.usb3/8a00000.dwc3/xhci-hcd.0.auto/usb1
Sat Oct 26 11:06:26 2019 daemon.info [8652]: <info> (tty/ttyUSB1): released by device '/sys/devices/platform/soc/8af8800.usb3/8a00000.dwc3/xhci-hcd.0.auto/usb1/1-1'
Sat Oct 26 11:06:27 2019 user.notice ModemManager: hotplug: remove serial interface ttyUSB2: event processed
Sat Oct 26 11:06:27 2019 user.notice ModemManager: hotplug: event reported: action=remove, name=ttyUSB2, subsystem=tty
Sat Oct 26 11:06:27 2019 user.notice ModemManager: hotplug: cleanup wait for modem at sysfs path /sys/devices/platform/soc/8af8800.usb3/8a00000.dwc3/xhci-hcd.0.auto/usb1
Sat Oct 26 11:06:27 2019 daemon.info [8652]: <info> (tty/ttyUSB2): released by device '/sys/devices/platform/soc/8af8800.usb3/8a00000.dwc3/xhci-hcd.0.auto/usb1/1-1'
Sat Oct 26 11:06:27 2019 user.notice ModemManager: hotplug: remove network interface wwan0: event processed
Sat Oct 26 11:06:27 2019 user.notice ModemManager: hotplug: event reported: action=remove, name=wwan0, subsystem=net
Sat Oct 26 11:06:27 2019 user.notice ModemManager: hotplug: cleanup wait for modem at sysfs path /sys/devices/platform/soc/8af8800.usb3/8a00000.dwc3/xhci-hcd.0.auto/usb1
Sat Oct 26 11:06:27 2019 daemon.info [8652]: <info> (net/wwan0): released by device '/sys/devices/platform/soc/8af8800.usb3/8a00000.dwc3/xhci-hcd.0.auto/usb1/1-1'
Sat Oct 26 11:06:27 2019 user.notice ModemManager: hotplug: remove cdc interface cdc-wdm0: custom event processed
Sat Oct 26 11:06:27 2019 user.notice ModemManager: hotplug: event reported: action=remove, name=cdc-wdm0, subsystem=usbmisc
Sat Oct 26 11:06:27 2019 user.notice ModemManager: hotplug: cleanup wait for modem at sysfs path /sys/devices/platform/soc/8af8800.usb3/8a00000.dwc3/xhci-hcd.0.auto/usb1
Sat Oct 26 11:06:27 2019 daemon.info [8652]: <info> (usbmisc/cdc-wdm0): released by device '/sys/devices/platform/soc/8af8800.usb3/8a00000.dwc3/xhci-hcd.0.auto/usb1/1-1'
Sat Oct 26 11:06:29 2019 daemon.warn [8652]: <warn> Couldn't load extended signal information: Transaction timed out