modem is unusable when removing and putting back sim card

[Aleksander Morgado]

Hey

> I am working with ModemManager with qmi-proxy and I have a weird behavior when I am using ModemManager with the log-level set to DEBUG like this "ModemManager --log-level=DEBUG &"
> everything is working fine but when I use it normally or set the log-level to anything else except debug I have "modem is unusable"
> Here are the logs :
> <debug> [modem2] cleaning up port 'net/mhi_hwip0'...
> <debug> [modem2] cleaning up port 'unknown/wwan0qcdm0'...
> <debug> [modem2] cleaning up port 'tty/ttyUSB2'...
> <debug> [modem2] cleaning up port 'wwan/wwan0qmi0'...
> <debug> [modem2] cleaning up port 'unknown/wwan0mbim0'...
> <debug> [ttyUSB2/at] forced to close port
> <debug> [modem2] (quectel) check SIM swap completed
> <debug> [modem2] completely disposed
> <debug> [device SG520TM] Reprobing modem...
> <info>  [device SG520TM] creating modem with plugin 'quectel' and '5' ports
> <debug> [plugin/quectel] (quectel) QMI-powered Quectel modem found...
> <debug> [wwan0qmi0/qmi] timeout monitoring enabled in QMI port
> <debug> [modem3] port 'wwan/wwan0qmi0' grabbed
> <debug> [plugin/quectel] port wwan0qcdm0 is blacklisted
> <debug> [modem3] port 'wwan/wwan0qcdm0' grabbed
> <debug> [plugin/quectel] port wwan0mbim0 is blacklisted
> <debug> [modem3] port 'wwan/wwan0mbim0' grabbed
> <debug> [modem3] port 'net/mhi_hwip0' grabbed
> <debug> [ttyUSB2/at] timeout monitoring enabled in AT port
> <debug> [ttyUSB2/at] AT port flagged as primary
> <debug> [modem3] port 'tty/ttyUSB2' grabbed
> <debug> [modem3] tty/ttyUSB2 at (primary)
> <debug> [modem3] tty/ttyUSB2 at (data primary)
> <debug> [modem3] net/mhi_hwip0 net (data)
> <debug> [modem3] wwan/wwan0qmi0 qmi
> <debug> [modem3] at data ports available but ignored
> <debug> [wwan0qmi0/qmi] endpoint info updated: type 'pcie', interface number '0'
> <debug> [modem3] running QMI port 'wwan0qmi0' reset with data interface 'mhi_hwip0'
> <debug> [device SG520TM] modem recreated
> <debug> [wwan0qmi0/qmi] bringing down data interface 'mhi_hwip0'
> <debug> [modem3/mhi_hwip0/net] interface index: 2
> <debug> [wwan0qmi0/qmi] deleting all links in data interface 'mhi_hwip0'
> <debug> [wwan0qmi0/qmi] Opening QMI device...
> <debug> [wwan0qmi0/qmi] Checking if QMI device already opening...
> <debug> [wwan0qmi0/qmi] Checking if QMI device already open...
> <debug> [wwan0qmi0/qmi] Creating QMI device...
> <debug> [wwan0qmi0/qmi] Opening device with flags: version-info, proxy...
> <debug> [/dev/wwan0qmi0] opening device with flags 'version-info, proxy'...
> <debug> [/dev/wwan0qmi0] created endpoint
> <debug> [/dev/wwan0qmi0] sent message...
> <<<<<< RAW:
> <<<<<<   length = 29
> <<<<<<   data   = 01:1C:00:00:00:00:00:01:00:FF:11:00...
>
> <debug> [/dev/wwan0qmi0] sent generic request (translated)...
> <<<<<< QMUX:
> <<<<<<   length  = 28
> <<<<<<   flags   = 0x00
> <<<<<<   service = "ctl"
> <<<<<<   client  = 0
> <<<<<< QMI:
> <<<<<<   flags       = "none"
> <<<<<<   transaction = 1
> <<<<<<   tlv_length  = 17
> <<<<<<   message     = "Internal Proxy Open" (0xFF00)
> <<<<<< TLV:
> <<<<<<   type       = "Device Path" (0x01)
> <<<<<<   length     = 14
> <<<<<<   value      = 2F:64:65:76:2F:77:77:61:6E:30:71:6D:69:30
> <<<<<<   translated = /dev/wwan0qmi0
>
> <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 1
> <debug> [/dev/wwan0qmi0] transaction 0xf aborted, but message is not abortable
> <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 2
> <debug> [/dev/wwan0qmi0] transaction 0x10 aborted, but message is not abortable
> <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 3
> <debug> [/dev/wwan0qmi0] transaction 0x11 aborted, but message is not abortable
> <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 4
> <debug> [/dev/wwan0qmi0] transaction 0x12 aborted, but message is not abortable
> <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 5
> <debug> [/dev/wwan0qmi0] transaction 0x13 aborted, but message is not abortable
> <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 6
> <debug> [/dev/wwan0qmi0] transaction 0x14 aborted, but message is not abortable
> <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 7
> <debug> [/dev/wwan0qmi0] transaction 0x15 aborted, but message is not abortable
> <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 8
> <debug> [/dev/wwan0qmi0] transaction 0x16 aborted, but message is not abortable
> <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 9
> <debug> [/dev/wwan0qmi0] transaction 0x17 aborted, but message is not abortable
> <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 10
> <debug> [/dev/wwan0qmi0] transaction 0x18 aborted, but message is not abortable
> <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 1
> <debug> [/dev/wwan0qmi0] transaction 0x1 aborted, but message is not abortable
> <debug> [wwan0qmi0/qmi] QMI port open operation failed: Transaction timed out
> <debug> [modem3] couldn't open QMI port with data format update: Transaction timed out
> <debug> [wwan0qmi0/qmi] Opening QMI device...
> <debug> [wwan0qmi0/qmi] Checking if QMI device already opening...
> <debug> [wwan0qmi0/qmi] Checking if QMI device already open...
> <debug> [wwan0qmi0/qmi] Creating QMI device...
> <debug> [wwan0qmi0/qmi] Opening device with flags: version-info, proxy...
> <debug> [/dev/wwan0qmi0] opening device with flags 'version-info, proxy'...
> <debug> [/dev/wwan0qmi0] created endpoint
> <debug> [/dev/wwan0qmi0] sent message...
> <<<<<< RAW:
> <<<<<<   length = 29
> <<<<<<   data   = 01:1C:00:00:00:00:00:01:00:FF:11:00...
>
> <debug> [/dev/wwan0qmi0] sent generic request (translated)...
> <<<<<< QMUX:
> <<<<<<   length  = 28
> <<<<<<   flags   = 0x00
> <<<<<<   service = "ctl"
> <<<<<<   client  = 0
> <<<<<< QMI:
> <<<<<<   flags       = "none"
> <<<<<<   transaction = 1
> <<<<<<   tlv_length  = 17
> <<<<<<   message     = "Internal Proxy Open" (0xFF00)
> <<<<<< TLV:
> <<<<<<   type       = "Device Path" (0x01)
> <<<<<<   length     = 14
> <<<<<<   value      = 2F:64:65:76:2F:77:77:61:6E:30:71:6D:69:30
> <<<<<<   translated = /dev/wwan0qmi0
>
> <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 1
> <debug> [/dev/wwan0qmi0] transaction 0x1 aborted, but message is not abortable
> <debug> [wwan0qmi0/qmi] QMI port open operation failed: Transaction timed out
> <warn>  [modem3] couldn't start initialization: Transaction timed out
> <error> [modem3] fatal error initializing: Fatal error: modem is unusable
>


This is weird, as if the ModemManager process cannot talk to the
proxy. Are you running MM as root?


-- 
Aleksander