[ltp] 2nd gen X1 carbon 3g/lte Sierra Wireless EM7345 4G LTE

morten linux-thinkpad@linux-thinkpad.org
Mon, 07 Apr 2014 13:04:30 +0200


Hello Bj=C3=B8rn

Thanks for you quick reply.

I have created a virtual machine for trying out different kernel=20
versions. My results are below.

On 04/02/2014 10:24 AM, Bj=C3=B8rn Mork wrote:
> morten <mortenlarsens@gmail.com> writes:
>
>> Hello
>>
>> I have tested libmbim (git-ref: b1ae81a75a1a68ea1c7316047528e79092bf0d=
37)
>> on Ubuntu 12.04 (Linux thinkpad 3.11.0-18-generic #32~precise1-Ubuntu
>> SMP Thu Feb 20 17:52:10 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux)
>> with the Sierra Wireless EM7345 modem module.
> Perfect!  Thanks.
>
> Looks like we still have a few things to sort out.  Might be better to
> move the discussion to the libmbim-devel, netdev, linux-usb or
> modemmanager-devel lists, but I don't know exactly which one.  The
> libmbim list is probably best until we've narrowed it down?:
> http://lists.freedesktop.org/mailman/listinfo/libmbim-devel
>
> Anyway, we can continue here for now if you like and noone protests.
>
>> I am capable of querying the device of various properties e.g.
>>
>> sudo mbimcli -d /dev/cdc-wdm0 --query-device-caps
>> [/dev/cdc-wdm0] Device capabilities retrieved:
>>            Device type: 'embedded'
>>         Cellular class: 'gsm'
>>            Voice class: 'no-voice'
>>              Sim class: 'removable'
>>             Data class: 'gprs, edge, umts, hsdpa, hsupa, lte'
>>               SMS caps: 'pdu-receive, pdu-send'
>>              Ctrl caps: 'reg-manual'
>>           Max sessions: '8'
> Yeeha!  8 sessions!  Let's hope that is for real.
>
> In theory this means that you can connect to 8 separate IP services,
> having separate sessions and IP interfaces for e.g Internet + Voice
> (over IP) + VPN +++
>
> Not that I know of any service provider offering that many different
> services.
>
> Hmm, doesn't seem like there is any way to use it from mbimcli yet
> either. The sessionid is hard coded to '0'. Well, let's worry about tha=
t
> when we have the basics working.
>
>
>>      Custom data class: 'unknown'
>>              Device ID: '013937000188621'
>>          Firmware info: 'FIH7160_V1.1_MODEM_01.1349.12'
>>          Hardware info: 'XMM7160_V1.1_MBIM_GNSS_NAND_RE'
>>
>> sudo mbimcli -d /dev/cdc-wdm0 --query-radio-state
>> [/dev/cdc-wdm0] Radio state retrieved:
>>           Hardware Radio State: 'on'
>>           Software Radio State: 'on'
>>
>> sudo mbimcli -d /dev/cdc-wdm0 --query-subscriber-ready-status
>> [/dev/cdc-wdm0] Subscriber ready status retrieved:
>>            Ready state: 'initialized'
>>          Subscriber ID: '=3D=3DREDACTED=3D=3D'
>>              SIM ICCID: '=3D=3DREDACTED=3D=3D'
>>             Ready info: 'unknown'
>>      Telephone numbers: (0) 'unknown'
>>
>> but the following command times-out at some point
>>
>> sudo mbimcli -d /dev/cdc-wdm0 --query-device-services
>> [/dev/cdc-wdm0] Device services retrieved:
>>      Max DSS sessions: '0'
> OK, no DSS.  Well, you probably don't need it.  But I was hoping to see=

> a MBIM device actually implementing it for something useful...
>
> (DSS =3D Device Service Stream - a way to multiplex non-IP transport
> streams over the MBIM data link.  We can imagine stuff like NMEA GPS
> data or AT command channels using it)
>
> [..]
>
>>                    Service: 'unknown'
>>                       UUID: [10e40d69-375a-42ce-a297-906164f2754c]:
>>                DSS payload: 0
>>          Max DSS instances: 0
>>                       CIDs: 1
> Lots of unknown services here.  Wouldn't it have been nice if other
> vendors than Microsoft actually *used* the registry at
> http://compliance.usb.org/mbim/ ?
>
>>                    Service: 'ms-host-shutdown'
>>                       UUID: [883b7c26-985f-43fa-9804-27d7fb80959c]:
>>                DSS payload: 0
>>          Max DSS instances: 0
>>                       CIDs: notify (1)
> Time to send a big thanks to Microsoft for documenting their stuff!
> That's why we know what this is, and we sort of know how to use it.
>
>>                    Service: 'unknown'
>>                       UUID: [5967bdcc-7fd2-49a2-9f5c-b2e70e527db3]:
>>                DSS payload: 0
>>          Max DSS instances: 0
>>                       CIDs: 2, 3, 1, 11, 4, 10, 9
> This is an AT&T specific service.  My MC7710 implements the exact samt
> serivice and set of CIDs:
>
>                            Service: 'unknown'
>                               UUID: [5967bdcc-7fd2-49a2-9f5c-b2e70e527d=
b3]:
>                        DSS payload: 0
>                  Max DSS instances: 0
>                               CIDs: 1, 2, 3, 4, 9, 10, 11
>
>
>>                    Service: 'unknown'
>>                       UUID: [0ed374cb-f835-4474-bc11-3b3fd76f5641]:
>>                DSS payload: 0
>>          Max DSS instances: 0
>>                       CIDs: 1
>>
>>                    Service: 'unknown'
>>                       UUID: [ed19555d-a6ac-4327-8eb1-fc022e5e2388]:
>>                DSS payload: 0
>>          Max DSS instances: 0
>>                       CIDs: 33554448
> We've seen this service and CID on an Ericsson H5321gw before.  The fac=
t
> that it is implemented by two different vendors indicates that this mos=
t
> likely is an operator specific service as well.
>
>
>>                    Service: 'unknown'
>>                       UUID: [fa142322-166b-4fd9-89f0-99be90ae8e3d]:
>>                DSS payload: 0
>>          Max DSS instances: 0
>>                       CIDs: 1
>>
>>                    Service: 'unknown'
>>                       UUID: [6a2a8150-abca-4b11-a4e2-f2fc879f5481]:
>>                DSS payload: 0
>>          Max DSS instances: 0
>>                       CIDs: 1
>> error: couldn't close device: Transaction timed out
>
> Is 'query-device-services' always the first command to fail?  I wonder
> if this might be related to how we handle fragmented replies.  That
> reply is one of the longer ones, and it might need fragmentation.
Yes it was, however the fail was also triggered when trying to use=20
mbim-network script.
>
> It would be good to have a test with a newer kernel.  v3.13.2 or
> newer will do.  If we have driver problems related to fragmented
> replies, then this commit which went into v3.13 is most likely
> necessary:
>
>    73e06865ead1 USB: cdc-wdm: support back-to-back USB_CDC_NOTIFY_RESPO=
NSE_AVAILABLE notifications
>
> Unfortunately, that commit is much too intrusive for stable.  And it
> also introduced new bugs as a result, which is why you need at least
> v3.13.2 for your test. This is still to be considered work-in-progress,=

> so there is a good chance we have some more issues to sort out before i=
t
> will work properly...
with uname -a
Linux ubuntuexp-VirtualBox 3.14.0-031400-generic #201403310035 SMP Mon=20
Mar 31 04:36:23 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

modinfo cdc_mbim
filename:=20
/lib/modules/3.14.0-031400-generic/kernel/drivers/net/usb/cdc_mbim.ko
license:        GPL
description:    USB CDC MBIM host driver
author:         Bj=C3=B8rn Mork <bjorn@mork.no>
author:         Greg Suarez <gsuarez@smithmicro.com>
srcversion:     FE916B594C0D87867310A9D
alias:          usb:v*p*d*dc*dsc*dp*ic02isc0Eip00in*
alias:          usb:v0BDBp*d*dc*dsc*dp*ic02isc0Eip00in*
alias:          usb:v*p*d*dc*dsc*dp*ic02isc0Dip00in*
depends:        usbnet,cdc_ncm,cdc-wdm
intree:         Y
vermagic:       3.14.0-031400-generic SMP mod_unload modversions
signer:         Magrathea: Glacier signing key
sig_key: 81:29:87:03:9D:4A:1E:B1:AC:7B:5D:2B:4E:CD:B3:BA:9E:78:5C:D3
sig_hashalgo:   sha512

It got much worse. Now most commands fail, or gets a reply after a few=20
tries.

sudo mbimcli -d /dev/cdc-wdm0 --query-radio-state -v
[07 Apr 2014, 12:39:55] [Debug] [/dev/cdc-wdm0] Queried max control=20
message size: 512
[07 Apr 2014, 12:39:55] [Debug] [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length =3D 16
<<<<<<   data   =3D 01:00:00:00:10:00:00:00:01:00:00:00:00:02:00:00

[07 Apr 2014, 12:39:55] [Debug] [/dev/cdc-wdm0] Sent message (translated)=
=2E..
<<<<<< Header:
<<<<<<   length      =3D 16
<<<<<<   type        =3D open (0x00000001)
<<<<<<   transaction =3D 1
<<<<<< Contents:
<<<<<<   max_control_transfer =3D 512

[07 Apr 2014, 12:39:55] [Debug] [/dev/cdc-wdm0] Received message...
 >>>>>> RAW:
 >>>>>>   length =3D 16
 >>>>>>   data   =3D 02:00:00:80:10:00:00:00:02:00:00:00:00:00:00:00

[07 Apr 2014, 12:39:55] [Debug] [/dev/cdc-wdm0] No transaction matched=20
in received message
[07 Apr 2014, 12:39:56] [Debug] [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length =3D 16
<<<<<<   data   =3D 01:00:00:00:10:00:00:00:02:00:00:00:00:02:00:00

[07 Apr 2014, 12:39:56] [Debug] [/dev/cdc-wdm0] Sent message (translated)=
=2E..
<<<<<< Header:
<<<<<<   length      =3D 16
<<<<<<   type        =3D open (0x00000001)
<<<<<<   transaction =3D 2
<<<<<< Contents:
<<<<<<   max_control_transfer =3D 512

[07 Apr 2014, 12:39:56] [Debug] [/dev/cdc-wdm0] Received message...
 >>>>>> RAW:
 >>>>>>   length =3D 16
 >>>>>>   data   =3D 02:00:00:80:10:00:00:00:02:00:00:00:00:00:00:00

[07 Apr 2014, 12:39:56] -Error ** mbim_message_open_done_get_result:=20
assertion 'MBIM_MESSAGE_GET_MESSAGE_TYPE (self) =3D=3D=20
MBIM_MESSAGE_TYPE_OPEN_DONE' failed

(mbimcli:6221): GLib-GIO-CRITICAL **: g_simple_async_result_take_error:=20
assertion 'error !=3D NULL' failed
[07 Apr 2014, 12:39:56] [Debug] MBIM Device at '/dev/cdc-wdm0' ready
[07 Apr 2014, 12:39:56] [Debug] Asynchronously querying radio state...
[07 Apr 2014, 12:39:56] [Debug] [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length =3D 48
<<<<<<   data   =3D=20
03:00:00:00:30:00:00:00:03:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:B=
C:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:03:00:00:00:00:00:00:00:00:00:00:00

[07 Apr 2014, 12:39:56] [Debug] [/dev/cdc-wdm0] Sent message (translated)=
=2E..
<<<<<< Header:
<<<<<<   length      =3D 48
<<<<<<   type        =3D command (0x00000003)
<<<<<<   transaction =3D 3
<<<<<< Fragment header:
<<<<<<   total   =3D 1
<<<<<<   current =3D 0
<<<<<< Contents:
<<<<<<   service =3D 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6d=
f)
<<<<<<   cid     =3D 'radio-state' (0x00000003)
<<<<<<   type    =3D 'query' (0x00000000)

[07 Apr 2014, 12:39:56] [Debug] [/dev/cdc-wdm0] Received message...
 >>>>>> RAW:
 >>>>>>   length =3D 16
 >>>>>>   data   =3D 02:00:00:80:10:00:00:00:02:00:00:00:00:00:00:00

[07 Apr 2014, 12:39:56] [Debug] [/dev/cdc-wdm0] No transaction matched=20
in received message
[07 Apr 2014, 12:39:57] [Debug] [/dev/cdc-wdm0] Received message...
 >>>>>> RAW:
 >>>>>>   length =3D 56
 >>>>>>   data   =3D=20
03:00:00:80:38:00:00:00:03:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:B=
C:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:03:00:00:00:00:00:00:00:08:00:00:00:01=
:00:00:00:01:00:00:00

[07 Apr 2014, 12:39:57] [Debug] [/dev/cdc-wdm0] Received message=20
(translated)...
 >>>>>> Header:
 >>>>>>   length      =3D 56
 >>>>>>   type        =3D command-done (0x80000003)
 >>>>>>   transaction =3D 3
 >>>>>> Fragment header:
 >>>>>>   total   =3D 1
 >>>>>>   current =3D 0
 >>>>>> Contents:
 >>>>>>   status error =3D 'None' (0x00000000)
 >>>>>>   service      =3D 'basic-connect'=20
(a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
 >>>>>>   cid          =3D 'radio-state' (0x00000003)

[/dev/cdc-wdm0] Radio state retrieved:
          Hardware Radio State: 'on'
          Software Radio State: 'on'
[07 Apr 2014, 12:39:57] [Debug] [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length =3D 12
<<<<<<   data   =3D 02:00:00:00:0C:00:00:00:04:00:00:00

[07 Apr 2014, 12:39:57] [Debug] [/dev/cdc-wdm0] Sent message (translated)=
=2E..
<<<<<< Header:
<<<<<<   length      =3D 12
<<<<<<   type        =3D close (0x00000002)
<<<<<<   transaction =3D 4

error: couldn't close device: Transaction timed out

So now all commands have issues, I have tried to reboot both virtual=20
machine and physical machine, but it does not seem
to change anything.

>
>> Furtermore when I try to connect using sudo mbim-network /dev/cdc-wdm0=
 start
>> it is unable to connect giving a timeout as a reason. It should be
>> noted, that after the first timeout occurs, all of the following query=

>> gives an error similar to this:
>>
>> [01 Apr 2014, 15:53:07] -Error ** mbim_message_open_done_get_result:
>> assertion `MBIM_MESSAGE_GET_MESSAGE_TYPE (self) =3D=3D
>> MBIM_MESSAGE_TYPE_OPEN_DONE' failed
>>
>> (mbimcli:3189): GLib-GIO-CRITICAL **:
>> g_simple_async_result_take_error: assertion `error !=3D NULL' failed
>>
>> A verbose example of the --query-device-services command
> Thanks!  I was just about to ask for that :-)
>
>
>> sudo mbimcli -d /dev/cdc-wdm0 --query-device-services -v
> [..]
>
>> [01 Apr 2014, 21:38:59] [Debug] [/dev/cdc-wdm0] Received
>> message... (partial fragment)
>>>>>>>> RAW:
>>>>>>>>    length =3D 512
>>>>>>>>    data   =3D
>> 03:00:00:80:00:02:00:00:02:00:00:00:02:00:00:00:00:00:00:00:A2:89:CC:3=
3:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:10:00:00:00:00:00:00:00:B4:02:00:00=
:0E:00:00:00:00:00:00:00:78:00:00:00:64:00:00:00:DC:00:00:00:30:00:00:00:=
0C:01:00:00:20:00:00:00:2C:01:00:00:2C:00:00:00:58:01:00:00:24:00:00:00:7=
C:01:00:00:20:00:00:00:9C:01:00:00:20:00:00:00:BC:01:00:00:20:00:00:00:DC=
:01:00:00:20:00:00:00:FC:01:00:00:38:00:00:00:34:02:00:00:20:00:00:00:54:=
02:00:00:20:00:00:00:74:02:00:00:20:00:00:00:94:02:00:00:20:00:00:00:A2:8=
9:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:00:00:00:00:00:00:00:00:12:00=
:00:00:01:00:00:00:02:00:00:00:03:00:00:00:04:00:00:00:05:00:00:00:09:00:=
00:00:06:00:00:00:0B:00:00:00:08:00:00:00:07:00:00:00:15:00:00:00:0A:00:0=
0:00:0F:00:00:00:0C:00:00:00:10:00:00:00:13:00:00:00:17:00:00:00:0D:00:00=
:00:53:3F:BE:EB:14:FE:44:67:9F:90:33:A2:23:E5:6C:3F:00:00:00:00:00:00:00:=
00:05:00:00:00:01:00:00:00:02:00:00:00:03:00:00:00:04:00:00:00:05:00:00:0=
0:E5:50:A0:C8:5E:82:47:9E:82:F7:10:AB:F4:C3:35:1F:00:00:00:00:00:00:00:00=
:01:00:00:00:01:00:00:00:4B:F3:84:76:1E:6A:41:DB:B1:D8:BE:D2:89:C2:5B:DB:=
00:00:00:00:00:00:00:00:04:00:00:00:01:00:00:00:02:00:00:00:03:00:00:00:0=
4:00:00:00:1D:2B:5F:F7:0A:A1:48:B2:AA:52:50:F1:57:67:17:4E:00:00:00:00:00=
:00:00:00:02:00:00:00:01:00:00:00:03:00:00:00:10:E4:0D:69:37:5A:42:CE:A2:=
97:90:61:64:F2:75:4C:00:00:00:00:00:00:00:00:01:00:00:00:01:00:00:00:59:A=
7:F3:23:FE:5A:43:01:B1:85:B8:EA:9E:61:67:B7:00:00:00:00:00:00:00:00:01:00=
:00:00:01:00:00:00:FD:C2:2A:F2:F4:41:4D:46:AF:8D:25:9F:CD:DE:46:35:00:00:=
00:00
>>
>> [01 Apr 2014, 21:38:59] [Debug] [/dev/cdc-wdm0] Received message
>> fragment (translated)...
>>>>>>>> Header:
>>>>>>>>    length      =3D 512
>>>>>>>>    type        =3D command-done (0x80000003)
>>>>>>>>    transaction =3D 2
>>>>>>>> Fragment header:
>>>>>>>>    total   =3D 2
>>>>>>>>    current =3D 0
> Yes, there we have it.  This reply consists of 2 fragments.  Which is
> fine, of course.  That's how it is supposed to look.
>
>> error: operation failed: Fragment timed out
> But we fail to receive the second part of the reply.
>
> It could be something else, but this looks exactly like symptoms of the=

> bug the "support back-to-back USB_CDC_NOTIFY_RESPONSE_AVAILABLE" commit=

> is fixing. The issue is that the modem sends a notification for the
> second part before the driver has read the first part, and the driver
> just isn't prepared for that.  The result is that the driver doesn't
> ever fetch the second part.  And from there we've lost...
>
> [..]
>
>> [01 Apr 2014, 21:39:09] [Debug] [/dev/cdc-wdm0] Received
>> message... (partial fragment)
>>>>>>>> RAW:
>>>>>>>>    length =3D 248
>>>>>>>>    data   =3D
>> 03:00:00:80:F8:00:00:00:02:00:00:00:02:00:00:00:01:00:00:00:00:00:00:0=
0:01:00:00:00:00:01:00:02:88:3B:7C:26:98:5F:43:FA:98:04:27:D7:FB:80:95:9C=
:00:00:00:00:00:00:00:00:01:00:00:00:01:00:00:00:59:67:BD:CC:7F:D2:49:A2:=
9F:5C:B2:E7:0E:52:7D:B3:00:00:00:00:00:00:00:00:07:00:00:00:02:00:00:00:0=
3:00:00:00:01:00:00:00:0B:00:00:00:04:00:00:00:0A:00:00:00:09:00:00:00:0E=
:D3:74:CB:F8:35:44:74:BC:11:3B:3F:D7:6F:56:41:00:00:00:00:00:00:00:00:01:=
00:00:00:01:00:00:00:ED:19:55:5D:A6:AC:43:27:8E:B1:FC:02:2E:5E:23:88:00:0=
0:00:00:00:00:00:00:01:00:00:00:10:00:00:02:FA:14:23:22:16:6B:4F:D9:89:F0=
:99:BE:90:AE:8E:3D:00:00:00:00:00:00:00:00:01:00:00:00:01:00:00:00:6A:2A:=
81:50:AB:CA:4B:11:A4:E2:F2:FC:87:9F:54:81:00:00:00:00:00:00:00:00:01:00:0=
0:00:01:00:00:00
>>
>> [01 Apr 2014, 21:39:09] [Debug] [/dev/cdc-wdm0] Received message
>> fragment (translated)...
>>>>>>>> Header:
>>>>>>>>    length      =3D 248
>>>>>>>>    type        =3D command-done (0x80000003)
>>>>>>>>    transaction =3D 2
>>>>>>>> Fragment header:
>>>>>>>>    total   =3D 2
>>>>>>>>    current =3D 1
>> [01 Apr 2014, 21:39:09] [Debug] [/dev/cdc-wdm0] No transaction matched=

>> in received message
> This is the missing fragment, which the driver finally reads here - muc=
h
> too late, while userspace was expecting a reply for a later command.
>
>
>> dmesg output at boot
>> [    8.530427] usbcore: registered new interface driver cdc_ncm
>> [    8.535195] usbcore: registered new interface driver cdc_wdm
>> [    8.549669] cdc_mbim 2-4:1.0: cdc-wdm0: USB WDM device
>> [    8.554268] cdc_mbim 2-4:1.0 wwan0: register 'cdc_mbim' at
>> usb-0000:00:14.0-4, CDC MBIM, c6:92:45:62:05:05
>> [    8.555083] usbcore: registered new interface driver cdc_mbim
>> [    8.555543] usbcore: registered new interface driver btusb
>> [    8.557955] cdc_acm 2-4:1.2: This device cannot do calls on its
>> own. It is not a modem.
>> [    8.558002] cdc_acm 2-4:1.2: ttyACM0: USB ACM device
>> [    8.560226] usbcore: registered new interface driver cdc_acm
>> [    8.560230] cdc_acm: USB Abstract Control Model driver for USB
>> modems and ISDN adapters
> Great!  So there is a serial port (AT command?) as well, and it is also=

> a proper CDC class function so we don't need any vendor specific stuff
> to support it. Thanks Intel.  It's good to see such things.
The /dev/ttyACM0 can be openend but it does not appear to accept AT=20
commands tried with  echo "AT\r\n" > /dev/ttyACM0
> Are the 4 USB interfaces use by the cdc_mbim and cdc_acm drivers the
> only ones on this modem, or are there other (possibly unsupported)
> functions as well?
Not sure how to figure out, can you provide help?
>
> Bj=C3=B8rn
Lastly, is there any way to use the built in modem using pppd +=20
chatscript ?