EM9190 randomly dial fail
dailijin
dailijin126 at 126.com
Mon Apr 26 10:10:03 UTC 2021
When the issue happen, I checked system log and can see below error log related to cdc_mbim.ko. not sure whether this cause the issue.
Apr 26 09:53:33 user.info kernel: [ 169.732503] NETDEV WATCHDOG: wwan0 (cdc_mbim): transmit queue 0 timed out,trans_start:[4294932908,4294932908,4294932908],jiffies:4294934744,timeo:1250
Apr 26 09:53:33 user.warn kernel: [ 169.732543] ------------[ cut here ]------------
Apr 26 09:53:33 user.warn kernel: [ 169.732549] WARNING: at /data/jack_amb/2_h2_sdk_svn/h2_sdk/ambarella/kernel/linux-4.4/net/sched/sch_generic.c:308
Apr 26 09:53:33 user.warn kernel: [ 169.732553] Modules linked in: cdc_mbim cdc_ncm cdc_wdm(O) qcserial usb_wwan(O) usbserial cdc_acm evdev 8812au(O) ambarella_adc industrialio_triggered_buffer ir_xmp_decoder kfifo_buf ir_
Apr 26 09:53:33 user.warn kernel: [ 169.732699]
Apr 26 09:53:33 user.warn kernel: [ 169.732709] CPU: 3 PID: 0 Comm: swapper/3 Tainted: P O 4.4.13 #1
Apr 26 09:53:33 user.warn kernel: [ 169.732714] Hardware name: Ambarella H2BUB Board (DT)
Apr 26 09:53:33 user.warn kernel: [ 169.732720] task: ffffffc019ed0000 ti: ffffffc019ed8000 task.ti: ffffffc019ed8000
Apr 26 09:53:33 user.warn kernel: [ 169.732733] PC is at dev_watchdog+0x2f8/0x308
Apr 26 09:53:33 user.warn kernel: [ 169.732739] LR is at dev_watchdog+0x2f8/0x308
Apr 26 09:53:33 user.warn kernel: [ 169.732744] pc : [<ffffffc0003fb688>] lr : [<ffffffc0003fb688>] pstate: 00000145
Apr 26 09:53:33 user.warn kernel: [ 169.732748] sp : ffffffc019edbc30
Apr 26 09:53:33 user.warn kernel: [ 169.732752] x29: ffffffc019edbc40 x28: 0000000000000005
Apr 26 09:53:33 user.warn kernel: [ 169.732759] x27: ffffffc013a07000 x26: ffffffc00073a000
Apr 26 09:53:33 user.warn kernel: [ 169.732766] x25: ffffffc0006f2300 x24: ffffffc0006f2000
Apr 26 09:53:33 user.warn kernel: [ 169.732772] x23: 00000000ffff79ac x22: ffffffc013a073a0
Apr 26 09:53:33 user.warn kernel: [ 169.732778] x21: 0000000000000000 x20: ffffffc013a07000
Apr 26 09:53:33 user.warn kernel: [ 169.732785] x19: ffffffc018c30c00 x18: 0000000000000010
Apr 26 09:53:33 user.warn kernel: [ 169.732791] x17: 00000000e5b906e6 x16: 0000000000000005
Apr 26 09:53:33 user.warn kernel: [ 169.732797] x15: ffffffc08074d62f x14: 2c34343734333934
Apr 26 09:53:33 user.warn kernel: [ 169.732804] x13: 3932343a73656966 x12: 66696a2c5d383039
Apr 26 09:53:33 user.warn kernel: [ 169.732810] x11: 323339343932342c x10: 3830393233393439
Apr 26 09:53:33 user.warn kernel: [ 169.732816] x9 : 32342c3830393233 x8 : 39343932345b3a74
Apr 26 09:53:33 user.warn kernel: [ 169.732823] x7 : ffffffc0006f3cc8 x6 : ffffffc00036bab8
Apr 26 09:53:33 user.warn kernel: [ 169.732829] x5 : 0000000000000000 x4 : 0000000000000000
Apr 26 09:53:33 user.warn kernel: [ 169.732835] x3 : 0000000000000000 x2 : ffffffc0207c6fd8
Apr 26 09:53:33 user.warn kernel: [ 169.732841] x1 : ffffffc019ed8000 x0 : 000000000000008a
Apr 26 09:53:33 user.warn kernel: [ 169.732847]
Apr 26 09:53:33 user.warn kernel: [ 169.732851] ---[ end trace dd3fe369f385dfc1 ]---
Apr 26 09:53:33 user.emerg kernel: [ 169.732856] Call trace:
Apr 26 09:53:33 user.warn kernel: [ 169.732863] [<ffffffc0003fb688>] dev_watchdog+0x2f8/0x308
Apr 26 09:53:33 user.warn kernel: [ 169.732874] [<ffffffc0000e89cc>] call_timer_fn.isra.8+0x24/0x88
Apr 26 09:53:33 user.warn kernel: [ 169.732880] [<ffffffc0000e8bb0>] run_timer_softirq+0x180/0x200
Apr 26 09:53:33 user.warn kernel: [ 169.732889] [<ffffffc00009b4c8>] __do_softirq+0x110/0x228
Apr 26 09:53:33 user.warn kernel: [ 169.732896] [<ffffffc00009b864>] irq_exit+0x84/0xd8
Apr 26 09:53:33 user.warn kernel: [ 169.732905] [<ffffffc0000d78f8>] __handle_domain_irq+0x60/0xb0
Apr 26 09:53:33 user.warn kernel: [ 169.732912] [<ffffffc000080d0c>] gic_handle_irq+0x54/0xa8
Apr 26 09:53:33 user.warn kernel: [ 169.732918] Exception stack(0xffffffc019edbe10 to 0xffffffc019edbf30)
Apr 26 09:53:33 user.warn kernel: [ 169.732925] be00: ffffffc0006f3cc8 ffffffc0006dc940
Apr 26 09:53:33 user.warn kernel: [ 169.732932] be20: ffffffc019edbf60 ffffffc000084d80 0000000040000145 ffffffc0000ee63c
Apr 26 09:53:33 user.warn kernel: [ 169.732939] be40: 0000000000000000 ffffffc0207c5984 0000000000000000 ffffffc00070b000
Apr 26 09:53:33 user.warn kernel: [ 169.732946] be60: 00000000200e9000 00000000000001c0 ffffffc0006f3cc8 00000000000001c0
Apr 26 09:53:33 user.warn kernel: [ 169.732952] be80: ffffffc019ed06c0 ffffffc019edbef0 0000000000000660 00000000afb50401
Apr 26 09:53:33 user.warn kernel: [ 169.732959] bea0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
Apr 26 09:53:33 user.warn kernel: [ 169.732966] bec0: 0000000000000005 00000000e5b906e6 0000000000000000 ffffffc0006f3cc8
Apr 26 09:53:33 user.warn kernel: [ 169.732973] bee0: ffffffc0006dc940 0000000000000001 ffffffc0006dc000 ffffffc000509000
Apr 26 09:53:33 user.warn kernel: [ 169.732979] bf00: ffffffc00073a000 ffffffc0006f3d48 0000000000984000 ffffffc000081040
Apr 26 09:53:33 user.warn kernel: [ 169.732985] bf20: 100cb653e83ac04b ffffffc019edbf60
Apr 26 09:53:33 user.warn kernel: [ 169.732992] [<ffffffc000083da8>] el1_irq+0x68/0xd8
Apr 26 09:53:33 user.warn kernel: [ 169.733000] [<ffffffc0000cddd0>] default_idle_call+0x20/0x38
Apr 26 09:53:33 user.warn kernel: [ 169.733008] [<ffffffc0000cdea0>] cpu_startup_entry+0xb8/0x1b8
Apr 26 09:53:33 user.warn kernel: [ 169.733015] [<ffffffc00008b680>] secondary_start_kernel+0x130/0x158
Apr 26 09:53:33 user.warn kernel: [ 169.733021] [<000000000028102c>] 0x28102c
--
Best Regards,
Dai,Lijin
At 2021-04-26 16:56:13, "dailijin" <dailijin126 at 126.com> wrote:
Hi Aleksander,
Thanks your response. see below updates.
Are you running that command as part of a script or something? If you run mbimcli without using the --no-close and --no-open options; carefully, I assume you could get in such a situation quickly.
My test unit can install two EM9190 modems, and my dial command steps for each EM9190 as below.
# PROXY=yes mbim-network /dev/cdc-wdmx start
# busybox udhcpc -i wwanx
If I reboot system, the two modems sometimes can work, or one can work or both can't work. see below.
# PROXY=yes mbim-network /dev/cdc-wdm1 start
APN:
APN user:
APN password:
APN user:
mbim-proxy: yes
Profile at '/etc/mbim-network.conf' not found...
Querying subscriber ready status 'mbimcli -d /dev/cdc-wdm1 --query-subscriber-ready-status --no-close --device-open-proxy'...
error: couldn't open the MbimDevice: Transaction timed out
Querying registration state 'mbimcli -d /dev/cdc-wdm1 --query-registration-state --no-open= --no-close --device-open-proxy'...
error: invalid transaction ID specified:
Attaching to packet service with 'mbimcli -d /dev/cdc-wdm1 --attach-packet-service --no-open= --no-close --device-open-proxy'...
error: invalid transaction ID specified:
Starting network with 'mbimcli -d /dev/cdc-wdm1 --connect=apn='' --no-open= --no-close --device-open-proxy'...
error: invalid transaction ID specified:
Network start failed
# PROXY=yes mbim-network /dev/cdc-wdm0 start
APN:
APN user:
APN password:
APN user:
mbim-proxy: yes
Profile at '/etc/mbim-network.conf' not found...
Querying subscriber ready status 'mbimcli -d /dev/cdc-wdm0 --query-subscriber-ready-status --no-close --device-open-proxy'...
[/dev/cdc-wdm0] Subscriber ready status retrieved: Ready state: 'initialized' Subscriber ID: '460042240808109' SIM ICCID: '89860402101703508108' Ready info: 'none' Telephone numbers: (0) 'unknown' [/dev/cdc-wdm0] Session not closed: TRID: '4'
Saving state at /tmp/mbim-network-state-cdc-wdm0... (TRID: 4)
Querying registration state 'mbimcli -d /dev/cdc-wdm0 --query-registration-state --no-open=4 --no-close --device-open-proxy'...
[/dev/cdc-wdm0] Registration status: Network error: 'unknown' Register state: 'home' Register mode: 'automatic' Available data classes: 'lte' Current cellular class: 'gsm' Provider ID: '46000' Provider name: 'CMCC' Roaming text: 'unknown' Registration flags: 'packet-service-automatic-attach' [/dev/cdc-wdm0] Session not closed: TRID: '6'
Saving state at /tmp/mbim-network-state-cdc-wdm0... (TRID: 6)
Attaching to packet service with 'mbimcli -d /dev/cdc-wdm0 --attach-packet-service --no-open=6 --no-close --device-open-proxy'...
Saving state at /tmp/mbim-network-state-cdc-wdm0... (TRID: 8)
Starting network with 'mbimcli -d /dev/cdc-wdm0 --connect=apn='' --no-open=8 --no-close --device-open-proxy'...
Network started successfully
Saving state at /tmp/mbim-network-state-cdc-wdm0... (TRID: 11)
if I continue to run command manually without "--no-close --device-open-proxy", also encounter the same error log. see below.
# mbimcli -d /dev/cdc-wdm1 --query-subscriber-ready-status
error: couldn't open the MbimDevice: Failure
# mbimcli -d /dev/cdc-wdm0 --query-subscriber-ready-status
error: operation failed: Transaction timed out
error: couldn't close device: Transaction timed out
the result of command "lsof" as below.
[10.12.32.138]# lsof | grep cdc
2353 /usr/lib64/mbim-proxy /dev/cdc-wdm0
Have you tried to run ALL your mbimcli commands with the '-p' option (to run through the proxy). When running with the proxy, it's the proxy itself the one who keeps track of the open/closed MBIM session
Yes, I run all mbim commands with "-p"
And another question, when you reboot your system, is the EM9190 also power cycled? or is it kept powered? Maybe the MBIM session is kept open in the device while the host thinks it should be closed?
when reboot system, the mother board and hub both power off ,then power on
--
Best Regards,
Dai,Lijin
At 2021-04-26 16:24:54, "dailijin" <dailijin126 at 126.com> wrote:
>Hi Aleksander,<br/><br/>Thanks your response. see below updates.<br/><br/>> Are you running that command as part of a script or something? If you<br/>> run mbimcli without using the --no-close and --no-open options<br/>> carefully, I assume you could get in such a situation quickly.<br/>My test unit can install two EM9190 modems, and my dial command steps for each EM9190 as below.<br/><br/># PROXY=yes mbim-network /dev/cdc-wdmx start<br/># busybox udhcpc -i wwanx<br/><br/>If I reboot system, the two modems sometimes can work, or one can work or both can't work. see below.<br/><br/># PROXY=yes mbim-network /dev/cdc-wdm1 start <br/> APN: <br/> APN user: <br/> APN password: <br/> APN user: <br/> mbim-proxy: yes<br/>Profile at '/etc/mbim-network.conf' not found...<br/>Querying subscriber ready status 'mbimcli -d /dev/cdc-wdm1 --query-subscriber-ready-status --no-close --device-open-proxy'...<br/>error: couldn't open the MbimDevice: Transaction timed out<br/><br/>Querying registration state 'mbimcli -d /dev/cdc-wdm1 --query-registration-state --no-open= --no-close --device-open-proxy'...<br/>error: invalid transaction ID specified: <br/><br/>Attaching to packet service with 'mbimcli -d /dev/cdc-wdm1 --attach-packet-service --no-open= --no-close --device-open-proxy'...<br/>error: invalid transaction ID specified: <br/>Starting network with 'mbimcli -d /dev/cdc-wdm1 --connect=apn='' --no-open= --no-close --device-open-proxy'...<br/>error: invalid transaction ID specified: <br/>Network start failed<br/><br/># PROXY=yes mbim-network /dev/cdc-wdm0 start <br/> APN: <br/> APN user: <br/> APN password: <br/> APN user: <br/> mbim-proxy: yes<br/>Profile at '/etc/mbim-network.conf' not found...<br/>Querying subscriber ready status 'mbimcli -d /dev/cdc-wdm0 --query-subscriber-ready-status --no-close --device-open-proxy'...<br/>[/dev/cdc-wdm0] Subscriber ready status retrieved: Ready state: 'initialized' Subscriber ID: '460042240808109' SIM ICCID: '89860402101703508108' Ready info: 'none' Telephone numbers: (0) 'unknown' [/dev/cdc-wdm0] Session not closed: TRID: '4'<br/>Saving state at /tmp/mbim-network-state-cdc-wdm0... (TRID: 4)<br/>Querying registration state 'mbimcli -d /dev/cdc-wdm0 --query-registration-state --no-open=4 --no-close --device-open-proxy'...<br/>[/dev/cdc-wdm0] Registration status: Network error: 'unknown' Register state: 'home' Register mode: 'automatic' Available data classes: 'lte' Current cellular class: 'gsm' Provider ID: '46000' Provider name: 'CMCC' Roaming text: 'unknown' Registration flags: 'packet-service-automatic-attach' [/dev/cdc-wdm0] Session not closed: TRID: '6'<br/>Saving state at /tmp/mbim-network-state-cdc-wdm0... (TRID: 6)<br/>Attaching to packet service with 'mbimcli -d /dev/cdc-wdm0 --attach-packet-service --no-open=6 --no-close --device-open-proxy'...<br/>Saving state at /tmp/mbim-network-state-cdc-wdm0... (TRID: 8)<br/>Starting network with 'mbimcli -d /dev/cdc-wdm0 --connect=apn='' --no-open=8 --no-close --device-open-proxy'...<br/>Network started successfully<br/>Saving state at /tmp/mbim-network-state-cdc-wdm0... (TRID: 11)<br/><br/>if I continue to run command manually without "--no-close --device-open-proxy", also encounter the same error log. see below.<br/># mbimcli -d /dev/cdc-wdm1 --query-subscriber-ready-status <br/>error: couldn't open the MbimDevice: Failure<br/># mbimcli -d /dev/cdc-wdm0 --query-subscriber-ready-status <br/>error: operation failed: Transaction timed out<br/><br/>the result of command "lsof" as below.<br/># lsof | grep cdc-wdm <br/>2353 /usr/lib64/mbim-proxy /dev/cdc-wdm0<br/><br/><br/>>Have you tried to run ALL your mbimcli commands with the '-p' option<br/>>(to run through the proxy). When running with the proxy, it's the<br/>>proxy itself the one who keeps track of the open/closed MBIM session<br/>Yes, I run all mbim commands with "-p"<br/><br/>>And another question, when you reboot your system, is the EM9190 also<br/>>power cycled? or is it kept powered? Maybe the MBIM session is kept<br/>>open in the device while the host thinks it should be closed?<br/>when reboot system, the mother board and hub both power off ,then power on
>At 2021-04-26 15:48:48, "Aleksander Morgado" <aleksander at aleksander.es> wrote:
>>Hey,
>>
>>> I am testing Sierra 5G modem EM9190. my kernel version is V4.4.13 and use the default driver cdc_mbim.ko. the modem randomly can't dial success after I reboot system.
>>>
>>> I checked AT command 'AT!GSTATUS' and confirm the modem can connect cell station successfully, but mbim-network always execute fail. the error log is "error: couldn't open the MbimDevice: Failure".
>>>
>>> I am using libmbim version 1.14.0. do you any guys encounter the same issue?
>>>
>>> [10.12.32.138]# mbimcli -d /dev/cdc-wdm3 --query-connection-state -v
>>> [22 Apr 2021, 08:41:38] [Debug] opening device...
>>> [22 Apr 2021, 08:41:38] [Debug] [/dev/cdc-wdm3] Queried max control message size: 4096
>>> [22 Apr 2021, 08:41:38] [Debug] [/dev/cdc-wdm3] Sent message...
>>> <<<<<< RAW:
>>> <<<<<< length = 16
>>> <<<<<< data = 01:00:00:00:10:00:00:00:01:00:00:00:00:10:00:00
>>>
>>> [22 Apr 2021, 08:41:38] [Debug] [/dev/cdc-wdm3] Sent message (translated)...
>>> <<<<<< Header:
>>> <<<<<< length = 16
>>> <<<<<< type = open (0x00000001)
>>> <<<<<< transaction = 1
>>> <<<<<< Contents:
>>> <<<<<< max control transfer = 4096
>>>
>>> [22 Apr 2021, 08:41:40] [Debug] [/dev/cdc-wdm3] Received message...
>>> >>>>>> RAW:
>>> >>>>>> length = 16
>>> >>>>>> data = 01:00:00:80:10:00:00:00:01:00:00:00:02:00:00:00
>>>
>>> [22 Apr 2021, 08:41:40] [Debug] getting open done result failed: closed
>>> error: couldn't open the MbimDevice: Failure
>>>
>>
>>Are you running that command as part of a script or something? If you
>>run mbimcli without using the --no-close and --no-open options
>>carefully, I assume you could get in such a situation quickly.
>>
>>Have you tried to run ALL your mbimcli commands with the '-p' option
>>(to run through the proxy). When running with the proxy, it's the
>>proxy itself the one who keeps track of the open/closed MBIM session.
>>
>>And another question, when you reboot your system, is the EM9190 also
>>power cycled? or is it kept powered? Maybe the MBIM session is kept
>>open in the device while the host thinks it should be closed?
>>
>>You'll need to investigate a bit more following those hints :) Please
>>let us know what you discover.
>>
>>--
>>Aleksander
>>https://aleksander.es
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/libmbim-devel/attachments/20210426/6d4fcb83/attachment-0001.htm>
More information about the libmbim-devel
mailing list