Hello Genodians
I have a SIMCOM 7600G mPCI modem, which I have configured to use MBIM mode. The device is recognized by `usb_drv` as follows: ``` <device label="usb-1-4" vendor_id="0x1e0e" product_id="0x9003" bus="0x1" dev="0x4" class="0xff"> <interface class="0xff" protocol="0xff"/> <interface class="0xff" protocol="0x0"/> <interface class="0xff" protocol="0x0"/> <interface class="0xff" protocol="0x0"/> <interface class="0xff" protocol="0x0"/> <interface class="0x2" protocol="0x0"/> <interface class="0xa" protocol="0x2"/> </device> ```
As described in the README of the driver I added a configuration to `usb_modem_drv.
Most of the times when I execute mbimcli.run (with or without a SIM card inserted) I get the following error: ``` Error: couldn't open the MbimDevice: Operation timed out: device is closed ``` On a low fraction of runs without SIM `mbimcli` reports that no sim is inserted.
Setting the `TRACE` enum in `construct.cc` of mbimcli to `TRUE`, I see the following debug output.
``` [13:44:42.820] [init -> mbimcli] <<<<<< RAW: [13:44:42.821] [init -> mbimcli] <<<<<< length = 16 [13:44:42.821] [init -> mbimcli] <<<<<< data = 01:00:00:00:10:00:00:00:01:00:00:00:00:10:00:00 [13:44:42.842] [init -> mbimcli] [13:44:42.842] [init -> mbimcli] [Debug] [/dev/cdc-wdm0] Sent message (translated)... [13:44:42.843] [init -> mbimcli] <<<<<< Header: [13:44:42.843] [init -> mbimcli] <<<<<< length = 16 [13:44:42.843] [init -> mbimcli] <<<<<< type = open (0x00000001) [13:44:42.855] [init -> mbimcli] <<<<<< transaction = 1 [13:44:42.856] [init -> mbimcli] <<<<<< Contents: [13:44:42.856] [init -> mbimcli] <<<<<< max control transfer = 4096 [13:44:42.856] [init -> mbimcli] [13:44:47.821] [init -> mbimcli] [Debug] [/dev/cdc-wdm0] Sent message... [13:44:47.822] [init -> mbimcli] <<<<<< RAW: [13:44:47.822] [init -> mbimcli] <<<<<< length = 16 [13:44:47.822] [init -> mbimcli] <<<<<< data = 01:00:00:00:10:00:00:00:02:00:00:00:00:10:00:00 [13:44:47.844] [init -> mbimcli] [13:44:47.844] [init -> mbimcli] [Debug] [/dev/cdc-wdm0] Sent message (translated)... [13:44:47.845] [init -> mbimcli] <<<<<< Header: [13:44:47.845] [init -> mbimcli] <<<<<< length = 16 [13:44:47.845] [init -> mbimcli] <<<<<< type = open (0x00000001) [13:44:47.857] [init -> mbimcli] <<<<<< transaction = 2 [13:44:47.857] [init -> mbimcli] <<<<<< Contents: [13:44:47.857] [init -> mbimcli] <<<<<< max control transfer = 4096 [13:44:47.858] [init -> mbimcli] [13:44:50.890] [init -> mbimcli] [Debug] [/dev/cdc-wdm0] Received message... [13:44:50.891] [init -> mbimcli] >>>>>> RAW: [13:44:50.891] [init -> mbimcli] >>>>>> length = 16 [13:44:50.891] [init -> mbimcli] >>>>>> data = 01:00:00:80:10:00:00:00:01:00:00:00:00:00:00:00 [13:44:50.898] [init -> mbimcli] [13:44:50.899] [init -> mbimcli] [Debug] [/dev/cdc-wdm0] No transaction matched in received message [13:44:50.921] [init -> mbimcli] [Debug] [/dev/cdc-wdm0] Received unexpected message (translated)... [13:44:50.921] [init -> mbimcli] >>>>>> Header: [13:44:50.921] [init -> mbimcli] >>>>>> length = 16 [13:44:50.921] [init -> mbimcli] >>>>>> type = open-done (0x80000001) [13:44:50.936] [init -> mbimcli] >>>>>> transaction = 1 [13:44:50.936] [init -> mbimcli] >>>>>> Contents: [13:44:50.936] [init -> mbimcli] >>>>>> status error = 'None' (0x00000000) [13:44:50.936] [init -> mbimcli] [13:44:52.824] [init -> mbimcli] [Debug] [/dev/cdc-wdm0] Sent message... [13:44:52.825] [init -> mbimcli] <<<<<< RAW: [13:44:52.825] [init -> mbimcli] <<<<<< length = 16 [13:44:52.825] [init -> mbimcli] <<<<<< data = 01:00:00:00:10:00:00:00:03:00:00:00:00:10:00:00 [13:44:52.846] [init -> mbimcli] [13:44:52.846] [init -> mbimcli] [Debug] [/dev/cdc-wdm0] Sent message (translated)... [13:44:52.847] [init -> mbimcli] <<<<<< Header: [13:44:52.847] [init -> mbimcli] <<<<<< length = 16 [13:44:52.847] [init -> mbimcli] <<<<<< type = open (0x00000001) [13:44:52.859] [init -> mbimcli] <<<<<< transaction = 3 [13:44:52.859] [init -> mbimcli] <<<<<< Contents: [13:44:52.860] [init -> mbimcli] <<<<<< max control transfer = 4096 [13:44:52.860] [init -> mbimcli] ... ``` This looks to me, as if the device is too slow in answering the first request. `mbimcli` will continue to send until transaction ID nine is reached and then stop with the error message from above. Only one response is ever received per test run on error.
When I insert a SIM card, then a second message is received directly after the first which looks as follows: ``` [15:24:15.668] [init -> mbimcli] [Debug] [/dev/cdc-wdm0] Received message... [15:24:15.668] [init -> mbimcli] >>>>>> RAW: [15:24:15.668] [init -> mbimcli] >>>>>> length = 92 [15:24:15.691] [init -> mbimcli] >>>>>> data = 07:00:00:80:5C:00:00:00:00:00:00:00:01:00:00:00:00:00:00:00:53:3F:BE:EB:14:FE:44:67:9F:90:33:A2:23:E5:6C:3F:01:00:00:00:30:00:00:00:01:00:00:00:00:00:00:00:35:00:00:00:00:00:00:00:18:00:00:00:18:00:00:00:2B:00:34: [15:24:15.691] [init -> mbimcli] 00:31:00:37:00:39:00:34:00:39:00:39:00:39:00:30:00:30:00:30:00 [15:24:15.691] [init -> mbimcli] [15:24:15.714] [init -> mbimcli] [Debug] [/dev/cdc-wdm0] Received message (translated)... [15:24:15.715] [init -> mbimcli] >>>>>> Header: [15:24:15.715] [init -> mbimcli] >>>>>> length = 92 [15:24:15.715] [init -> mbimcli] >>>>>> type = indicate-status (0x80000007) [15:24:15.736] [init -> mbimcli] >>>>>> transaction = 0 [15:24:15.736] [init -> mbimcli] >>>>>> Fragment header: [15:24:15.737] [init -> mbimcli] >>>>>> total = 1 [15:24:15.737] [init -> mbimcli] >>>>>> current = 0 [15:24:15.737] [init -> mbimcli] >>>>>> Contents: [15:24:15.753] [init -> mbimcli] >>>>>> service = 'sms' (533fbeeb-14fe-4467-9f90-33a223e56c3f) [15:24:15.753] [init -> mbimcli] >>>>>> cid = 'configuration' (0x00000001) [15:24:15.754] [init -> mbimcli] >>>>>> Fields: Unknown contents [15:24:15.754] [init -> mbimcli] ``` Still `mbimcli` will send further open requests. What I do not understand is that a service `sms` is reported, however the SIM in use doesn't support sending/receiving of SMS.
In rare cases the following message also appears in the output: ``` [init -> usb_modem_drv] dev_err: nonzero urb status received: -EPIPE ``` I'm not sure if it is related, but as the modem is connected via USB it could be.
The device is connected to a iMX8m mini, which uses the same `usb_host_drv` as the iMX6q sabrelite.
Has anybody an idea how I could narrow down the issue?
Best regards, Pirmin
Hello Pirmin,
we had an offline brainstorming in the Genode Labs team about the issue you raised. Unfortunately, we could not come up with a concrete suggestion how you could tackle the timeout. It seems timeouts happen sporadically during communication with the SIM card depending on the platform and modem device used. This hints that Linux tools may also face such issues and it may be worth to investigate the behavior when controlling the modem on a Linux host. Building and instrumenting the mbimcli tool for Linux should not be too hard.
On Mon, Oct 25, 2021 at 15:37:35 CEST, Duss Pirmin wrote:
In rare cases the following message also appears in the output:
[init -> usb_modem_drv] dev_err: nonzero urb status received: -EPIPEI'm not sure if it is related, but as the modem is connected via USB it could be.
The device is connected to a iMX8m mini, which uses the same `usb_host_drv` as the iMX6q sabrelite.
The message comes from cdc-wdm.c that also includes the following comment, which hints a temporary (?) USB stall.
* Avoid propagating -EPIPE (stall) to userspace since it is * better handled as an empty read
Regards
Hello Christian
Thanks for your teams brainstorming and sharing of information.
I will try to run mbimcli on linux, and debug on Genode once I have finished my current task.
Regards, Pirmin
On 11/3/21 09:08, Christian Helmuth wrote:
Hello Pirmin,
we had an offline brainstorming in the Genode Labs team about the issue you raised. Unfortunately, we could not come up with a concrete suggestion how you could tackle the timeout. It seems timeouts happen sporadically during communication with the SIM card depending on the platform and modem device used. This hints that Linux tools may also face such issues and it may be worth to investigate the behavior when controlling the modem on a Linux host. Building and instrumenting the mbimcli tool for Linux should not be too hard.
On Mon, Oct 25, 2021 at 15:37:35 CEST, Duss Pirmin wrote:
In rare cases the following message also appears in the output:
[init -> usb_modem_drv] dev_err: nonzero urb status received: -EPIPEI'm not sure if it is related, but as the modem is connected via USB it could be.
The device is connected to a iMX8m mini, which uses the same `usb_host_drv` as the iMX6q sabrelite.
The message comes from cdc-wdm.c that also includes the following comment, which hints a temporary (?) USB stall.
* Avoid propagating -EPIPE (stall) to userspace since it is * better handled as an empty readRegards
-
Christian Helmuth -
Duss Pirmin -
Pirmin Duss