ModemManager using QMI doesnt always work in the first attemp.

José Joseddg92 at gmail.com
Thu Nov 12 04:15:16 PST 2015 

I am working with two different QMI modems (Telit LE910 and Sierra MC7710
in QMI mode) and experimenting one issue with both of them.

After boot I try to establish the connection:

ModemManager &
(wait for the modem to be detected)
mmcli -m 0 --simple-connect="apn=.."

This somtimes works, but most of the time fails. However, when it fails,
issuing
mmcli -m 0 --simple-connect="apn=.."
always works.

I don't think it is related to the enviroment, because other modems (or
even the same Sierra MC7710 using MBIM or Direct IP) work fine.

The common error is this (complete logs at the end)

ModemManager[684]: [/dev/cdc-wdm0] No transaction matched in received message


What could be causing that?




Sierra log (QMI)


root at ccimx6sbc:~# ModemManager[684]: <info>  Simple connect started...

ModemManager[684]: <info>  Simple connect state (1/8): Unlock check

ModemManager[684]: <info>  Simple connect state (2/8): Wait to get
fully initialized

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (locked ->
initializing)

ModemManager[684]: <warn>  (ttyUSB2): port attributes not fully set

ModemManager[684]: <warn>  couldn't load list of Own Numbers:
'Couldn't get MSISDN: QMI protocol error (16): 'NotProvisioned''

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (initializing ->
disabled)

ModemManager[684]: <info>  Simple connect state (3/8): Enable

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (disabled ->
enabling)

ModemManager[684]: <warn>  (ttyUSB2): port attributes not fully set

ModemManager[684]: Couldn't read SMS messages: QMI protocol error
(52): 'DeviceNotReady'

ModemManager[684]: Couldn't read SMS messages: QMI protocol error
(48): 'InvalidArgument'

ModemManager[684]: Couldn't read SMS messages: QMI protocol error
(52): 'DeviceNotReady'

ModemManager[684]: Couldn't read SMS messages: QMI protocol error
(48): 'InvalidArgument'

ModemManager[684]: Couldn't read SMS messages: QMI protocol error
(48): 'InvalidArgument'

ModemManager[684]: Couldn't read SMS messages: QMI protocol error
(52): 'DeviceNotReady'

ModemManager[684]: Couldn't read SMS messages: QMI protocol error
(52): 'DeviceNotReady'

ModemManager[684]: Couldn't read SMS messages: QMI protocol error
(52): 'DeviceNotReady'

ModemManager[684]: Couldn't read SMS messages: QMI protocol error
(48): 'InvalidArgument'

ModemManager[684]: Couldn't read SMS messages: QMI protocol error
(48): 'InvalidArgument'

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (enabling ->
enabled)

ModemManager[684]: <info>  Simple connect state (4/8): Wait to get fully enabled

ModemManager[684]: <info>  Simple connect state (5/8): Register

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (unknown -> searching)

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (enabled ->
searching)

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (searching -> idle)

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (idle -> registering)

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (registering -> home)

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (searching ->
registered)

ModemManager[684]: <info>  Simple connect state (6/8): Bearer

ModemManager[684]: <info>  Simple connect state (7/8): Connect

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (registered ->
connecting)

ModemManager[684]: [/dev/cdc-wdm0] Allocating new client ID...

ModemManager[684]: [/dev/cdc-wdm0] Registered 'wds' (version 1.12)
client with ID '1'

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (home -> idle)

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (connecting ->
disconnecting)

ModemManager[684]: [/dev/cdc-wdm0] No transaction matched in received message

ModemManager[684]: <warn>  Error disconnecting bearer
'/org/freedesktop/ModemManager1/Bearer/0': 'Couldn't disconnect QMI
bearer: this bearer is not connected'. Will assume disconnected
anyway.

ModemManager[684]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (disconnecting
-> enabled)

error: couldn't connect the modem:
'GDBus.Error:org.freedesktop.ModemManager1.Error.Core.Cancelled:
Connection setup operation has been cancelled'


Telit LE910 (QMI) log:


root at imx6qsabresd:~# mmcli -m 0 --simple-connect=apn=ac.vodafone.es,pin=1234

ModemManager[960]: <info>  Simple connect started...

ModemManager[960]: <info>  Simple connect state (1/8): Unlock check

ModemManager[960]: <info>  Simple connect state (2/8): Wait to get
fully initialized

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (locked ->
initializing)

ModemManager[960]: <warn>  (ttyUSB2): port attributes not fully set

ModemManager[960]: <warn>  couldn't load list of Own Numbers:
'Couldn't get MSISDN: QMI protocol error (16): 'NotProvisioned''

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (initializing ->
disabled)

ModemManager[960]: <info>  Simple connect state (3/8): Enable

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (disabled ->
enabling)

ModemManager[960]: <warn>  (ttyUSB2): port attributes not fully set

ModemManager[960]: <warn>  (ttyUSB3): port attributes not fully set

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (unknown -> searching)

ModemManager[960]: Couldn't read SMS messages: QMI protocol error
(17): 'MissingArgument'

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (searching -> unknown)

ModemManager[960]: Couldn't read SMS messages: QMI protocol error
(52): 'DeviceNotReady'

ModemManager[960]: Couldn't read SMS messages: QMI protocol error
(48): 'InvalidArgument'

ModemManager[960]: Couldn't read SMS messages: QMI protocol error
(48): 'InvalidArgument'

ModemManager[960]: Couldn't read SMS messages: QMI protocol error
(17): 'MissingArgument'

ModemManager[960]: Couldn't read SMS messages: QMI protocol error
(52): 'DeviceNotReady'

ModemManager[960]: Couldn't read SMS messages: QMI protocol error
(48): 'InvalidArgument'

ModemManager[960]: Couldn't read SMS messages: QMI protocol error
(48): 'InvalidArgument'

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (enabling ->
enabled)

ModemManager[960]: <info>  Simple connect state (4/8): Wait to get fully enabled

ModemManager[960]: <info>  Simple connect state (5/8): Register

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (unknown -> idle)

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (idle -> registering)

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (registering -> home)

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (enabled ->
registered)

ModemManager[960]: <info>  Simple connect state (6/8): Bearer

ModemManager[960]: <info>  Simple connect state (7/8): Connect

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (registered ->
connecting)

ModemManager[960]: [/dev/cdc-wdm0] Allocating new client ID...

ModemManager[960]: [/dev/cdc-wdm0] Registered 'wds' (version 1.36)
client with ID '10'

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (home -> searching)

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (searching -> idle)

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (connecting ->
disconnecting)

ModemManager[960]: <warn>  Error disconnecting bearer
'/org/freedesktop/ModemManager1/Bearer/0': 'Couldn't disconnect QMI
bearer: this bearer is not connected'. Will assume disconnected
anyway.

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (disconnecting
-> enabled)

error: couldn't connect the modem:
'GDBus.Error:org.freedesktop.ModemManager1.Error.Core.Cancelled:
Connection setup operation has been cancelled'

ModemManager[960]: [/dev/cdc-wdm0] No transaction matched in received message

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (idle -> registering)



(ModemManager:960): GLib-CRITICAL **: g_variant_new_string: assertion
'g_utf8_validate (string, -1, NULL)' failed



(ModemManager:960): GLib-CRITICAL **: g_variant_ref_sink: assertion
'value != NULL' failed

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
changed (registering -> home)

ModemManager[960]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (enabled ->
registered)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freedesktop.org/archives/modemmanager-devel/attachments/20151112/7d64c4ea/attachment-0001.html>

More information about the ModemManager-devel mailing list