MC7455 periodic resets

IoT Modules MC/EM Series
1

This issue may be the same as this issue we saw in Februrary 2020. The symptoms are very similar but I have additional clues as to what happens when it resets, so I’ve opted to create a new thread.

We’re using an MC7455 mounted to an i.MX 6 board (the Digi ConnectCore 6UL SBC Pro), running Digi Embedded Yocto 4.14.170.

The modem has the following (Generic) firmware version:
SWI9X30C_02.33.03.00 r8209 CARMD-EV-FRMWR2 2019/08/28 20:59:30

ModemManager version:
1.10.8

In the past, we have had some issues where we would see the modem seemingly reset, and ModemManager would go through the process of re-connecting to the modem. Upgrading from Linux 4.14.141 to 4.14.170 seems to have fixed the issue last time, however in my desk unit (for testing) we’re seeing similar behaviour again, and since we’re already using 4.14.170 with the latest firmware on the modem, we’re wondering if perhaps the original cause of the issue from February was several things and not just one, or if we’re introducing a very similar issue with something new we’re doing.

The log file below comes from /var/log/messages. The first line of the log seems to be where it first goes wrong. Based on my understanding, it looks like ModemManager is having trouble communicating with the modem through the QMI driver, and subsequently releases the connection, causing it to be re-established. Of course, this is more than a minute of re-initialisation before cellular communication resumes. I’m not clear on where exactly it goes wrong or how to go about troubleshooting this.

Larger log file included as attachment. Log has been lightly sanitised, with a domain being changed to foo.com

Oct 19 17:03:49 0004f31dbf78 daemon.warn ModemManager[663]: Cannot read from istream: connection broken
Oct 19 17:03:49 0004f31dbf78 daemon.info ModemManager[663]: <info>  Connection to qmi-proxy for /dev/cdc-wdm0 lost, reprobing
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Releasing 'wds' client with flags 'release-cid'...
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Unregistered 'wds' client with ID '36'
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Releasing 'wds' client with flags 'release-cid'...
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Unregistered 'wds' client with ID '35'
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Releasing 'pdc' client with flags 'release-cid'...
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Unregistered 'pdc' client with ID '1'
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Releasing 'loc' client with flags 'release-cid'...
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Unregistered 'loc' client with ID '1'
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Releasing 'uim' client with flags 'release-cid'...
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Unregistered 'uim' client with ID '2'
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Releasing 'wms' client with flags 'release-cid'...
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Unregistered 'wms' client with ID '2'
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Releasing 'nas' client with flags 'release-cid'...
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Unregistered 'nas' client with ID '3'
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Releasing 'dms' client with flags 'release-cid'...
Oct 19 17:03:49 0004f31dbf78 daemon.debug ModemManager[663]: [/dev/cdc-wdm0] Unregistered 'dms' client with ID '2'
Oct 19 17:03:49 0004f31dbf78 daemon.info ModemManager[663]: <info>  [device /sys/devices/soc0/soc/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb1/1-1/1-1.3] creating modem with plugin 'Sierra' and '7' ports
Oct 19 17:03:49 0004f31dbf78 daemon.info ModemManager[663]: <info>  (tty/ttyUSB0): released by device '/sys/devices/soc0/soc/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb1/1-1/1-1.3'
Oct 19 17:03:49 0004f31dbf78 daemon.info ModemManager[663]: <info>  (tty/ttyUSB2): released by device '/sys/devices/soc0/soc/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb1/1-1/1-1.3'
Oct 19 17:03:49 0004f31dbf78 daemon.info ModemManager[663]: <info>  (tty/ttyUSB3): released by device '/sys/devices/soc0/soc/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb1/1-1/1-1.3'
Oct 19 17:03:49 0004f31dbf78 daemon.warn ModemManager[663]: <warn>  Couldn't start initialization: Couldn't query file info: Error when getting information for file “/dev/cdc-wdm0”: No such file or directory
Oct 19 17:03:49 0004f31dbf78 daemon.warn ModemManager[663]: <warn>  couldn't initialize the modem: 'Modem is unusable, cannot fully initialize'
Oct 19 17:03:49 0004f31dbf78 daemon.info ModemManager[663]: <info>  (usbmisc/cdc-wdm0): released by device '/sys/devices/soc0/soc/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb1/1-1/1-1.3'
Oct 19 17:03:49 0004f31dbf78 daemon.info ModemManager[663]: <info>  (usbmisc/cdc-wdm1): released by device '/sys/devices/soc0/soc/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb1/1-1/1-1.3'
Oct 19 17:03:49 0004f31dbf78 daemon.info dnsmasq[822]: setting upstream servers from DBus
Oct 19 17:03:49 0004f31dbf78 daemon.info dnsmasq[822]: using nameserver 172.16.1.10#53(via eth1)
Oct 19 17:03:49 0004f31dbf78 daemon.info dnsmasq[822]: using nameserver 172.16.1.10#53 for domain foo.com
Oct 19 17:03:49 0004f31dbf78 daemon.info dnsmasq[822]: using nameserver 172.16.1.10#53 for domain 1.16.172.in-addr.arpa
Oct 19 17:03:49 0004f31dbf78 daemon.info dnsmasq[822]: using nameserver 8.8.8.8#53(via eth1)
Oct 19 17:03:49 0004f31dbf78 daemon.info dnsmasq[822]: using nameserver 8.8.8.8#53 for domain foo.com
Oct 19 17:03:49 0004f31dbf78 daemon.info dnsmasq[822]: using nameserver 8.8.8.8#53 for domain 1.16.172.in-addr.arpa
Oct 19 17:03:49 0004f31dbf78 daemon.info dnsmasq[822]: using nameserver fd00:976a::9#53
Oct 19 17:03:49 0004f31dbf78 daemon.info dnsmasq[822]: using nameserver 172.16.2.14#53 for domain EAP900H
Oct 19 17:03:49 0004f31dbf78 daemon.info dnsmasq[822]: using nameserver 172.16.2.14#53 for domain 2.16.172.in-addr.arpa
Oct 19 17:03:49 0004f31dbf78 daemon.info dnsmasq[822]: using nameserver fd00:976a::10#53
Oct 19 17:03:49 0004f31dbf78 daemon.info dnsmasq[822]: using nameserver 172.16.2.14#53(via wlan0)
Oct 19 17:03:49 0004f31dbf78 daemon.info dnsmasq[822]: cleared cache
Oct 19 17:03:50 0004f31dbf78 daemon.info dnsmasq[822]: setting upstream servers from DBus
Oct 19 17:03:50 0004f31dbf78 daemon.info dnsmasq[822]: using nameserver 172.16.1.10#53(via eth1)
Oct 19 17:03:50 0004f31dbf78 daemon.info dnsmasq[822]: using nameserver 172.16.1.10#53 for domain foo.com

mc7455_modemmanager_disconnect.txt (36.2 KB)

2

We’re not seeing this issue since resolving a seemingly unrelated issue that caused a huge number of sockets to be opened and not closed. It looks like this was causing some system instability, one of the symptoms of which was this issue with ModemManager losing connection to the hardware/driver. While we’re not certain this is the cause, we’re not seeing the issue since fixing this other issue so we’ll go with this hypothesis for now.

I will consider this issue closed.

3

That assumption is correct I think; if you had a system-level problem with sockets opened and never properly closed, that issue would have affected the ModemManager<->qmi-proxy communication and that would have been reported as broken connection with the proxy, as in your logs. Those logs don’t show the modem reseting itself (we would see indications of all ports, including the network port, going away in that case), those logs show broken communication with the proxy.

1 Like