Unable to attach to Telit LM940 after modem reset
I'm currently testing a few different mini-PCIe modems, and ran into an unexpected behaviour when testing a Telit LM940 modem.
The modem is initially probed fine by ModemManager, but after the modem has been reset with mmcli -m 0 -r
ModemManager can't attach, saying only Feb 13 12:52:39 hostname daemon.warn ModemManager[632]: <warn> Could not grab port (usbmisc/cdc-wdm0): 'Cannot add port 'usbmisc/cdc-wdm0', unsupported'
Log extract showing the relevant probing:
Feb 13 12:51:42 hostname daemon.info ModemManager[632]: <info> ModemManager (version 1.10.1) starting in system bus...
Feb 13 12:51:44 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Opening device with flags 'version-info, proxy'...
Feb 13 12:51:44 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] loaded driver of cdc-wdm port: qmi_wwan
Feb 13 12:51:44 hostname daemon.debug ModemManager[632]: cannot connect to proxy: Could not connect: Connection refused
Feb 13 12:51:44 hostname daemon.debug ModemManager[632]: spawning new qmi-proxy (try 1)...
Feb 13 12:51:44 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Checking version info (10 retries)...
Feb 13 12:51:45 hostname daemon.info ModemManager[632]: <info> Couldn't check support for device '/sys/devices/soc0/soc/2100000.aips-bus/2188000.ethernet': not supported by any plugin
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] QMI Device supports 32 services:
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] ctl (1.5)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] wds (1.67)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] dms (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] nas (1.25)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] qos (1.12)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] wms (1.10)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] auth (1.3)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] at (1.2)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] voice (2.1)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] cat2 (2.24)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] uim (1.62)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] pbm (1.4)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] test (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] loc (2.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] sar (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] ts (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] tmd (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] wda (1.16)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] csvt (1.1)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] coex (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] pdc (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] rfrpe (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] dsd (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] ssctl (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0x2d] (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0x30] (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0x31] (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0x36] (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0x44] (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0xe6] (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0xe7] (1.0)
Feb 13 12:51:45 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0xe8] (1.0)
Feb 13 12:51:45 hostname daemon.info ModemManager[632]: <info> [device /sys/devices/soc0/soc/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb2/2-1/2-1.6] creating modem with plugin 'Telit' and '2' ports
Feb 13 12:51:46 hostname daemon.info ModemManager[632]: <info> Modem for device '/sys/devices/soc0/soc/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb2/2-1/2-1.6' successfully created
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Opening device with flags 'version-info, proxy'...
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] loaded driver of cdc-wdm port: qmi_wwan
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Checking version info (10 retries)...
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] QMI Device supports 32 services:
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] ctl (1.5)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] wds (1.67)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] dms (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] nas (1.25)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] qos (1.12)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] wms (1.10)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] auth (1.3)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] at (1.2)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] voice (2.1)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] cat2 (2.24)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] uim (1.62)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] pbm (1.4)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] test (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] loc (2.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] sar (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] ts (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] tmd (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] wda (1.16)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] csvt (1.1)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] coex (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] pdc (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] rfrpe (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] dsd (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] ssctl (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0x2d] (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0x30] (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0x31] (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0x36] (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0x44] (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0xe6] (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0xe7] (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] unknown [0xe8] (1.0)
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Reading expected data format from: /sys/class/net/wwan0/qmi/raw_ip
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Allocating new client ID...
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Registered 'wda' (version 1.16) client with ID '1'
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Writing expected data format to: /sys/class/net/wwan0/qmi/raw_ip
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Reading expected data format from: /sys/class/net/wwan0/qmi/raw_ip
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Allocating new client ID...
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Releasing 'wda' client with flags 'release-cid'...
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Unregistered 'wda' client with ID '1'
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Registered 'dms' (version 1.0) client with ID '1'
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Allocating new client ID...
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Registered 'nas' (version 1.25) client with ID '3'
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Allocating new client ID...
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Registered 'wms' (version 1.10) client with ID '3'
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Allocating new client ID...
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Registered 'uim' (version 1.62) client with ID '2'
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Allocating new client ID...
Feb 13 12:51:46 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Registered 'loc' (version 2.0) client with ID '1'
Feb 13 12:51:47 hostname daemon.warn ModemManager[632]: <warn> couldn't load list of Own Numbers: 'Couldn't get MSISDN: QMI protocol error (16): 'NotProvisioned''
Feb 13 12:51:48 hostname daemon.warn ModemManager[632]: <warn> couldn't load UE mode of operation for EPS: 'No AT port available to run command'
Feb 13 12:51:58 hostname daemon.warn ModemManager[632]: <warn> couldn't load SUPL server: 'Failed to receive indication with the current server settings'
Feb 13 12:52:08 hostname daemon.warn ModemManager[632]: <warn> couldn't load supported assistance data types: 'Failed to receive indication with the predicted orbits data source'
Feb 13 12:52:08 hostname daemon.info ModemManager[632]: <info> Modem: state changed (unknown -> disabled)
An mmcli -m 0 -r
is issued:
Feb 13 12:52:09 hostname daemon.info ModemManager[632]: <info> Modem is being rebooted now
Feb 13 12:52:15 hostname daemon.info ModemManager[632]: <info> (net/wwan0): released by device '/sys/devices/soc0/soc/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb2/2-1/2-1.6'
Feb 13 12:52:15 hostname daemon.info ModemManager[632]: <info> (usbmisc/cdc-wdm0): released by device '/sys/devices/soc0/soc/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb2/2-1/2-1.6'
Feb 13 12:52:15 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Releasing 'loc' client with flags 'release-cid'...
Feb 13 12:52:15 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Unregistered 'loc' client with ID '1'
Feb 13 12:52:15 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Releasing 'uim' client with flags 'release-cid'...
Feb 13 12:52:15 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Unregistered 'uim' client with ID '2'
Feb 13 12:52:15 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Releasing 'wms' client with flags 'release-cid'...
Feb 13 12:52:15 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Unregistered 'wms' client with ID '3'
Feb 13 12:52:15 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Releasing 'nas' client with flags 'release-cid'...
Feb 13 12:52:15 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Unregistered 'nas' client with ID '3'
Feb 13 12:52:15 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Releasing 'dms' client with flags 'release-cid'...
Feb 13 12:52:15 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Unregistered 'dms' client with ID '1'
The modem restarts, and eventually shows back up on the USB bus:
Feb 13 12:52:30 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Opening device with flags 'version-info, proxy'...
Feb 13 12:52:30 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] loaded driver of cdc-wdm port: qmi_wwan
Feb 13 12:52:30 hostname daemon.debug ModemManager[632]: [/dev/cdc-wdm0] Checking version info (10 retries)...
Feb 13 12:52:39 hostname daemon.info ModemManager[632]: <info> [device internal] creating modem with plugin 'Telit' and '2' ports
Feb 13 12:52:39 hostname daemon.warn ModemManager[632]: <warn> Could not grab port (usbmisc/cdc-wdm0): 'Cannot add port 'usbmisc/cdc-wdm0', unsupported'
Feb 13 12:52:39 hostname daemon.warn ModemManager[632]: <warn> Couldn't create modem for device 'internal': Failed to find primary AT port
...and everything is unhappy.
Restarting the ModemManager makes it probe the modem correctly, and mmcli -S
can also find it (but doesn't then pick up the UID of the modem, which I guess is understandable). It's almost as if udev notifications don't work for this modem?