Sierra Wireless 340u - NotInitialized
Shawn J. Goff
shawn7400 at gmail.com
Thu May 30 08:42:19 PDT 2013
On Thu, May 30, 2013 at 10:47 AM, Aleksander Morgado
<aleksander at lanedo.com> wrote:
> On 30/05/13 16:43, Shawn J. Goff wrote:
>> On Thu, May 30, 2013 at 8:06 AM, Aleksander Morgado
>> <aleksander at lanedo.com> wrote:
>>> Hey,
>>>
>>>>
>>>>>
>>>>> error: operation failed: NotInitialized
>>>>>
>>>>>
>>>>> Testing with my primitive perl script support this assumption. If I
>>>>> send OPEN after initializing and attaching, then the next attach will
>>>>> fail with MBIM_STATUS_NOT_INITIALIZED.
>>>>>
>>>>> I believe the --no-close isn't enough. We also need a way to tell
>>>>> mbimcli that the device is already open, just like qmicli has both
>>>>> --client-cid=<x> and --client-no-release-cid.
>>>>>
>>>>
>>>> Gah, I really thought we wouldn't need it :)
>>>>
>>>> Opened a new bugreport for that:
>>>> https://bugs.freedesktop.org/show_bug.cgi?id=65165
>>>>
>>>>
>>>
>>> Can you guys take a look at the 'aleksander/session-support' branch? The
>>> changes in the branch allow to have MBIM 'sessions', using --no-close
>>> and --no-open, while keeping the transaction ID between mbimcli
>>> commands. I updated the mbim-network script accordingly as well.
>>>
>>> E.g.:
>>>
>>> Open device:
>>> $> sudo mbimcli -d /dev/cdc-wdm0 --noop --no-close
>>> [/dev/cdc-wdm1] Session not closed:
>>> TRID: '2'
>>>
>>> Run a command:
>>> $> sudo mbimcli -d /dev/cdc-wdm1 \
>>> --query-radio-state \
>>> --no-open=2 \
>>> --no-close
>>> [/dev/cdc-wdm1] Radio state retrieved:
>>> Hardware Radio State: 'on'
>>> Software Radio State: 'on'
>>> [/dev/cdc-wdm1] Session not closed:
>>> TRID: '3'
>>>
>>> Close device:
>>> $> sudo mbimcli -d /dev/cdc-wdm0 --noop --no-open=3
>>>
>>> --
>>> Aleksander
>>
>>
>> Here is a verbose run shoing the NotInitialized error.
>>
>>
>> # mbimcli -d /dev/cdc-wdm0 --no-close --noop -v
>> [01 Jan 1970, 00:02:41] [Debug] [/dev/cdc-wdm0] Couldn't query maximum
>> message size: IOCTL_WDM_MAX_COMMAND failed: Inappropriate ioctl for
>> device
>> [01 Jan 1970, 00:02:41] [Debug] [/dev/cdc-wdm0] Read max control
>> message size from descriptors file: 4096
>> [01 Jan 1970, 00:02:41] [Debug] [/dev/cdc-wdm0] Sent message...
>> <<<<<< RAW:
>> <<<<<< length = 16
>> <<<<<< data = 01:00:00:00:10:00:00:00:01:00:00:00:00:10:00:00
>>
>> [01 Jan 1970, 00:02:41] [Debug] [/dev/cdc-wdm0] Sent message (translated)...
>> <<<<<< Header:
>> <<<<<< length = 16
>> <<<<<< type = open (0x00000001)
>> <<<<<< transaction = 1
>> <<<<<< Contents:
>> <<<<<< max_control_transfer = 4096
>>
>> [01 Jan 1970, 00:02:42] [Debug] [/dev/cdc-wdm0] Received message...
>> >>>>>> RAW:
>> >>>>>> length = 16
>> >>>>>> data = 01:00:00:80:10:00:00:00:01:00:00:00:00:00:00:00
>>
>> [01 Jan 1970, 00:02:42] [Debug] [/dev/cdc-wdm0] Received message
>> (translated)...
>> >>>>>> Header:
>> >>>>>> length = 16
>> >>>>>> type = open-done (0x80000001)
>> >>>>>> transaction = 1
>> >>>>>> Contents:
>> >>>>>> status error = 'None' (0x00000000)
>>
>> [01 Jan 1970, 00:02:42] [Debug] MBIM Device at '/dev/cdc-wdm0' ready
>> [01 Jan 1970, 00:02:42] [Debug] Device closed
>> [/dev/cdc-wdm0] Session not closed:
>> TRID: '2'
>> #
>> # mbimcli -d /dev/cdc-wdm0 -v --no-close --no-open=2 --connect=broadband
>> [01 Jan 1970, 00:04:24] [Debug] [/dev/cdc-wdm0] Couldn't query maximum
>> message size: IOCTL_WDM_MAX_COMMAND failed: Inappropriate ioctl for
>> device
>> [01 Jan 1970, 00:04:24] [Debug] [/dev/cdc-wdm0] Read max control
>> message size from descriptors file: 4096
>> [01 Jan 1970, 00:04:24] [Debug] [/dev/cdc-wdm0] Received message...
>>>>>>>> RAW:
>>>>>>>> length = 92
>>>>>>>> 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:1D:01:00:00:00:00:00:00:18:00:00:00:18:00:00:00:2B:00:31:00:33:00:31:00:32:00:33:00:31:00:34:00:39:00:38:00:31:00:30:00
>>
>> [01 Jan 1970, 00:04:24] [Debug] [/dev/cdc-wdm0] Received message (translated)...
>>>>>>>> Header:
>>>>>>>> length = 92
>>>>>>>> type = indicate-status (0x80000007)
>>>>>>>> transaction = 0
>>>>>>>> Fragment header:
>>>>>>>> total = 1
>>>>>>>> current = 0
>>>>>>>> Contents:
>>>>>>>> service = 'sms' (533fbeeb-14fe-4467-9f90-33a223e56c3f)
>>>>>>>> cid = 'configuration' (0x00000001)
>>
>> [01 Jan 1970, 00:04:24] [Debug] [/dev/cdc-wdm0] Received message (translated)...
>>>>>>>> Header:
>>>>>>>> length = 92
>>>>>>>> type = indicate-status (0x80000007)
>>>>>>>> transaction = 0
>>>>>>>> Fragment header:
>>>>>>>> total = 1
>>>>>>>> current = 0
>>>>>>>> Contents:
>>>>>>>> service = 'sms' (533fbeeb-14fe-4467-9f90-33a223e56c3f)
>>>>>>>> cid = 'configuration' (0x00000001)
>>
>> [01 Jan 1970, 00:04:24] [Debug] MBIM Device at '/dev/cdc-wdm0' ready
>> [01 Jan 1970, 00:04:24] [Debug] [/dev/cdc-wdm0] Sent message...
>> <<<<<< RAW:
>> <<<<<< length = 126
>> <<<<<< data =
>> 03:00:00:00:7E:00:00:00:02:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:0C:00:00:00:01:00:00:00:4E:00:00:00:00:00:00:00:01:00:00:00:3C:00:00:00:12:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:7E:5E:2A:7E:4E:6F:72:72:73:6B:65:6E:7E:5E:2A:7E:62:00:72:00:6F:00:61:00:64:00:62:00:61:00:6E:00:64:00
>>
>> [01 Jan 1970, 00:04:24] [Debug] [/dev/cdc-wdm0] Sent message (translated)...
>> <<<<<< Header:
>> <<<<<< length = 126
>> <<<<<< type = command (0x00000003)
>> <<<<<< transaction = 2
>> <<<<<< Fragment header:
>> <<<<<< total = 1
>> <<<<<< current = 0
>> <<<<<< Contents:
>> <<<<<< service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>> <<<<<< cid = 'connect' (0x0000000c)
>> <<<<<< type = 'set' (0x00000001)
>>
>> [01 Jan 1970, 00:04:24] [Debug] [/dev/cdc-wdm0] Received message...
>>>>>>>> RAW:
>>>>>>>> length = 64
>>>>>>>> data = 07:00:00:80:40:00:00:00:00:00:00:00:01:00:00:00:00:00:00:00:4B:F3:84:76:1E:6A:41:DB:B1:D8:BE:D2:89:C2:5B:DB:01:00:00:00:14:00:00:00:01:00:00:00:FA:00:00:00:00:00:00:00:50:00:00:00:12:00:00:00
>>
>> [01 Jan 1970, 00:04:24] [Debug] [/dev/cdc-wdm0] Received message (translated)...
>>>>>>>> Header:
>>>>>>>> length = 64
>>>>>>>> type = indicate-status (0x80000007)
>>>>>>>> transaction = 0
>>>>>>>> Fragment header:
>>>>>>>> total = 1
>>>>>>>> current = 0
>>>>>>>> Contents:
>>>>>>>> service = 'phonebook' (4bf38476-1e6a-41db-b1d8-bed289c25bdb)
>>>>>>>> cid = 'configuration' (0x00000001)
>>
>> [01 Jan 1970, 00:04:24] [Debug] [/dev/cdc-wdm0] Received message (translated)...
>>>>>>>> Header:
>>>>>>>> length = 64
>>>>>>>> type = indicate-status (0x80000007)
>>>>>>>> transaction = 0
>>>>>>>> Fragment header:
>>>>>>>> total = 1
>>>>>>>> current = 0
>>>>>>>> Contents:
>>>>>>>> service = 'phonebook' (4bf38476-1e6a-41db-b1d8-bed289c25bdb)
>>>>>>>> cid = 'configuration' (0x00000001)
>>
>> [01 Jan 1970, 00:04:24] [Debug] [/dev/cdc-wdm0] Received message...
>>>>>>>> RAW:
>>>>>>>> length = 48
>>>>>>>> data = 03:00:00:80:30:00:00:00:02:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:0C:00:00:00:0E:00:00:00:00:00:00:00
>>
>> [01 Jan 1970, 00:04:24] [Debug] [/dev/cdc-wdm0] Received message (translated)...
>>>>>>>> Header:
>>>>>>>> length = 48
>>>>>>>> type = command-done (0x80000003)
>>>>>>>> transaction = 2
>>>>>>>> Fragment header:
>>>>>>>> total = 1
>>>>>>>> current = 0
>>>>>>>> Contents:
>>>>>>>> status error = 'NotInitialized' (0x0000000e)
>>>>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>>> cid = 'connect' (0x0000000c)
>>
>> [01 Jan 1970, 00:04:24] [Debug] [/dev/cdc-wdm0] Received message (translated)...
>>>>>>>> Header:
>>>>>>>> length = 48
>>>>>>>> type = command-done (0x80000003)
>>>>>>>> transaction = 2
>>>>>>>> Fragment header:
>>>>>>>> total = 1
>>>>>>>> current = 0
>>>>>>>> Contents:
>>>>>>>> status error = 'NotInitialized' (0x0000000e)
>>>>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>>> cid = 'connect' (0x0000000c)
>>
>> error: operation failed: NotInitialized
>> [01 Jan 1970, 00:04:24] [Debug] Device closed
>> [/dev/cdc-wdm0] Session not closed:
>> TRID: '3'
>> #
>>
>
> That's weird, probably our assumptions of re-opening causing the issue
> were not correct.
>
> Did you test this with ModemManager? Did you see such issue there?
>
> --
> Aleksander
I have NM 0.9.8 and MM 0.7.990 installed and mmcli -L doesn't list any modems.
Here is what I see in the journal:
May 30 11:33:01 shawntatious kernel: usb 1-1: new high-speed USB
device number 8 using xhci_hcd
May 30 11:33:01 shawntatious kernel: usb 1-1: config 1 has an invalid
interface number: 9 but max is 0
May 30 11:33:01 shawntatious kernel: usb 1-1: config 1 has no interface number 0
May 30 11:33:01 shawntatious kernel: usb 1-1: config 2 has an invalid
interface number: 12 but max is 1
May 30 11:33:01 shawntatious kernel: usb 1-1: config 2 has an invalid
interface number: 13 but max is 1
May 30 11:33:01 shawntatious kernel: usb 1-1: config 2 has an invalid
interface number: 13 but max is 1
May 30 11:33:01 shawntatious kernel: usb 1-1: config 2 has no interface number 0
May 30 11:33:01 shawntatious kernel: usb 1-1: config 2 has no interface number 1
May 30 11:33:01 shawntatious kernel: usb-storage: probe of 1-1:1.9
failed with error -5
May 30 11:33:05 shawntatious kernel: usb 1-1: USB disconnect, device number 8
May 30 11:33:05 shawntatious kernel: usb 1-1: new high-speed USB
device number 9 using xhci_hcd
May 30 11:33:05 shawntatious kernel: usb 1-1: config 1 has an invalid
interface number: 8 but max is 4
May 30 11:33:05 shawntatious kernel: usb 1-1: config 1 has an invalid
interface number: 9 but max is 4
May 30 11:33:05 shawntatious kernel: usb 1-1: config 1 has no interface number 1
May 30 11:33:05 shawntatious kernel: usb 1-1: config 1 has no interface number 4
May 30 11:33:05 shawntatious kernel: usb 1-1: config 2 has an invalid
interface number: 12 but max is 1
May 30 11:33:05 shawntatious kernel: usb 1-1: config 2 has an invalid
interface number: 13 but max is 1
May 30 11:33:05 shawntatious kernel: usb 1-1: config 2 has an invalid
interface number: 13 but max is 1
May 30 11:33:05 shawntatious kernel: usb 1-1: config 2 has no interface number 0
May 30 11:33:05 shawntatious kernel: usb 1-1: config 2 has no interface number 1
May 30 11:33:05 shawntatious kernel: cdc_mbim 1-1:2.12: cdc-wdm0: USB WDM device
May 30 11:33:05 shawntatious kernel: cdc_mbim 1-1:2.12 wwan0: register
'cdc_mbim' at usb-0000:06:00.0-1, CDC MBIM, 6a:30:d2:e7:b3:28
May 30 11:33:08 shawntatious ModemManager[9860]: <info> Creating
modem with plugin 'Generic' and '2' ports
May 30 11:33:08 shawntatious ModemManager[9860]: <warn> Could not
grab port (net/wwan0): 'ignoring MBIM net port'
May 30 11:33:08 shawntatious ModemManager[9860]: <warn> Could not
grab port (usbmisc/cdc-wdm0): 'Cannot add port 'usbmisc/cdc-wdm0',
unsupported'
May 30 11:33:08 shawntatious ModemManager[9860]: <warn> Couldn't
create modem for device at
'/sys/devices/pci0000:00/0000:00:1c.5/0000:06:00.0/usb1/1-1': Failed
to find primary AT port
More information about the libmbim-devel
mailing list