MC7700 sometimes fails with QMI error 'ClientIdsExhausted'
I hope to maybe get some ideas why my WWAN card sometimes fails to activate. I'm running on Ubuntu 22.04 and the WWAN card MC7700 is working out of the box with NetworkManager which is based on ModemManager. But sometimes when I start the computer NetworkManager just fails to connect over and over.
This is the output of journalctl when it fails:
$ journalctl -xe NM_CONNECTION=2e49886e-0f33-444c-b633-32312c1ca135 + NM_DEVICE=cdc-wdm0
Jun 28 15:49:01 ThinkPad-T500 NetworkManager[843]: <info> [1656424141.9967] device (cdc-wdm0): Activation: starting connection 'MedionMobile' (2e49886e-0f33-444c-b633-32312c1ca135)
Jun 28 15:49:01 ThinkPad-T500 NetworkManager[843]: <info> [1656424141.9980] device (cdc-wdm0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Jun 28 15:49:02 ThinkPad-T500 NetworkManager[843]: <info> [1656424142.0002] device (cdc-wdm0): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')
Jun 28 15:49:02 ThinkPad-T500 NetworkManager[843]: <info> [1656424142.0082] device (cdc-wdm0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Jun 28 15:49:02 ThinkPad-T500 NetworkManager[843]: <warn> [1656424142.0811] modem-broadband[cdc-wdm0]: failed to connect modem: Couldn't allocate IPv6 client in QMI port cdc-wdm0: Couldn't create client for service 'wds': QMI protocol error (5): 'ClientIdsExhausted'
Jun 28 15:49:02 ThinkPad-T500 NetworkManager[843]: <info> [1656424142.0811] device (cdc-wdm0): state change: prepare -> failed (reason 'unknown', sys-iface-state: 'managed')
Jun 28 15:49:02 ThinkPad-T500 NetworkManager[843]: <warn> [1656424142.0825] device (cdc-wdm0): Activation: failed for connection 'MedionMobile'
Jun 28 15:49:02 ThinkPad-T500 NetworkManager[843]: <info> [1656424142.0830] device (cdc-wdm0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Jun 28 15:49:02 ThinkPad-T500 NetworkManager[843]: <info> [1656424142.0851] device (cdc-wdm0): Activation: starting connection 'MedionMobile' (2e49886e-0f33-444c-b633-32312c1ca135)
Jun 28 15:49:02 ThinkPad-T500 NetworkManager[843]: <info> [1656424142.0853] device (cdc-wdm0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Jun 28 15:49:02 ThinkPad-T500 NetworkManager[843]: <info> [1656424142.0884] device (cdc-wdm0): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')
Jun 28 15:49:02 ThinkPad-T500 NetworkManager[843]: <info> [1656424142.0942] device (cdc-wdm0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Jun 28 15:49:02 ThinkPad-T500 NetworkManager[843]: <warn> [1656424142.1644] modem-broadband[cdc-wdm0]: failed to connect modem: Couldn't allocate IPv6 client in QMI port cdc-wdm0: Couldn't create client for service 'wds': QMI protocol error (5): 'ClientIdsExhausted'
When I use the following reset command of ModemManager several times it is sometimes able to connect again after some time:
mmcli -m 2 -v -r
mmcli -m 1 -v -r
Output of journalctl when resetting and it successfully connects:
$ journalctl -xe NM_CONNECTION=2e49886e-0f33-444c-b633-32312c1ca135 + NM_DEVICE=cdc-wdm0
Jun 28 17:59:41 ThinkPad-T500 NetworkManager[843]: <warn> [1656431981.5974] modem-broadband[cdc-wdm0]: failed to connect modem: Couldn't allocate IPv6 client in QMI port cdc-wdm0: Couldn't create client for service 'wds': QMI protocol error (5): 'ClientIdsExhausted'
Jun 28 17:59:41 ThinkPad-T500 NetworkManager[843]: <info> [1656431981.5974] device (cdc-wdm0): state change: prepare -> failed (reason 'unknown', sys-iface-state: 'managed')
Jun 28 17:59:41 ThinkPad-T500 NetworkManager[843]: <warn> [1656431981.5981] device (cdc-wdm0): Activation: failed for connection 'MedionMobile'
Jun 28 17:59:41 ThinkPad-T500 NetworkManager[843]: <info> [1656431981.5983] device (cdc-wdm0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Jun 28 18:01:04 ThinkPad-T500 NetworkManager[843]: <info> [1656432064.6270] device (cdc-wdm0): state change: disconnected -> unmanaged (reason 'removed', sys-iface-state: 'removed')
Jun 28 18:01:27 ThinkPad-T500 NetworkManager[843]: <info> [1656432087.3213] manager: (cdc-wdm0): new Broadband device (/org/freedesktop/NetworkManager/Devices/5)
Jun 28 18:01:27 ThinkPad-T500 NetworkManager[843]: <info> [1656432087.3243] device (cdc-wdm0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Jun 28 18:01:27 ThinkPad-T500 NetworkManager[843]: <info> [1656432087.3278] device (cdc-wdm0): modem state 'enabling'
Jun 28 18:01:27 ThinkPad-T500 NetworkManager[843]: <info> [1656432087.3302] device (cdc-wdm0): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
Jun 28 18:02:01 ThinkPad-T500 NetworkManager[843]: <info> [1656432121.0066] device (cdc-wdm0): state change: disconnected -> unmanaged (reason 'removed', sys-iface-state: 'removed')
Jun 28 18:02:24 ThinkPad-T500 NetworkManager[843]: <info> [1656432144.2639] manager: (cdc-wdm0): new Broadband device (/org/freedesktop/NetworkManager/Devices/6)
Jun 28 18:02:24 ThinkPad-T500 NetworkManager[843]: <info> [1656432144.2657] device (cdc-wdm0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Jun 28 18:02:24 ThinkPad-T500 NetworkManager[843]: <info> [1656432144.2660] device (cdc-wdm0): modem state 'enabling'
Jun 28 18:02:24 ThinkPad-T500 NetworkManager[843]: <info> [1656432144.2664] device (cdc-wdm0): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
Jun 28 18:03:00 ThinkPad-T500 NetworkManager[843]: <info> [1656432180.7766] device (cdc-wdm0): state change: disconnected -> unmanaged (reason 'removed', sys-iface-state: 'removed')
Jun 28 18:03:23 ThinkPad-T500 NetworkManager[843]: <info> [1656432203.2790] manager: (cdc-wdm0): new Broadband device (/org/freedesktop/NetworkManager/Devices/7)
Jun 28 18:03:23 ThinkPad-T500 NetworkManager[843]: <info> [1656432203.2793] device (cdc-wdm0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Jun 28 18:03:23 ThinkPad-T500 NetworkManager[843]: <info> [1656432203.2796] device (cdc-wdm0): modem state 'enabling'
Jun 28 18:03:23 ThinkPad-T500 NetworkManager[843]: <info> [1656432203.2799] device (cdc-wdm0): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
Jun 28 18:04:41 ThinkPad-T500 NetworkManager[843]: <info> [1656432281.8660] device (cdc-wdm0): Activation: starting connection 'MedionMobile' (2e49886e-0f33-444c-b633-32312c1ca135)
Jun 28 18:04:41 ThinkPad-T500 NetworkManager[843]: <info> [1656432281.8662] device (cdc-wdm0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Jun 28 18:04:41 ThinkPad-T500 NetworkManager[843]: <info> [1656432281.8669] device (cdc-wdm0): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')
Jun 28 18:04:41 ThinkPad-T500 NetworkManager[843]: <info> [1656432281.8701] device (cdc-wdm0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Jun 28 18:04:45 ThinkPad-T500 NetworkManager[843]: <info> [1656432285.9600] device (cdc-wdm0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Jun 28 18:04:45 ThinkPad-T500 NetworkManager[843]: <info> [1656432285.9612] device (cdc-wdm0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Jun 28 18:04:45 ThinkPad-T500 NetworkManager[843]: <warn> [1656432285.9622] device (cdc-wdm0): retrieving IP configuration failed: modem IP method unsupported
Jun 28 18:04:45 ThinkPad-T500 NetworkManager[843]: <info> [1656432285.9671] device (cdc-wdm0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Jun 28 18:04:45 ThinkPad-T500 NetworkManager[843]: <info> [1656432285.9945] device (cdc-wdm0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Jun 28 18:04:45 ThinkPad-T500 NetworkManager[843]: <info> [1656432285.9948] device (cdc-wdm0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Jun 28 18:04:45 ThinkPad-T500 NetworkManager[843]: <info> [1656432285.9965] device (cdc-wdm0): Activation: successful, device activated.
Information about the modem:
$ mmcli -m 3
--------------------------------
General | path: /org/freedesktop/ModemManager1/Modem/3
| device id: 0333333922b071ac77d996a3471751cabcd722b9
--------------------------------
Hardware | manufacturer: Sierra Wireless, Incorporated
| model: MC7700
| firmware revision: SWI9200X_03.05.21.01ap r5616 carmd-en-10527 2012/12/11 19:18:49
| h/w revision: 10
| supported: gsm-umts, lte
| current: gsm-umts, lte
| equipment id: 012810001492618
--------------------------------
System | device: /sys/devices/pci0000:00/0000:00:1d.7/usb2/2-4
| drivers: qmi_wwan, qcserial
| plugin: sierra
| primary port: cdc-wdm0
| ports: cdc-wdm0 (qmi), ttyUSB0 (qcdm), ttyUSB2 (at), wwan0 (net)
--------------------------------
Status | lock: sim-pin2
| unlock retries: sim-pin (3), sim-puk (10), sim-pin2 (3), sim-puk2 (10)
| state: connected
| power state: on
| access tech: gsm
| signal quality: 49% (cached)
--------------------------------
Modes | supported: allowed: 2g; preferred: none
| allowed: 3g; preferred: none
| allowed: 4g; preferred: none
| allowed: 2g, 3g; preferred: 3g
| allowed: 2g, 3g; preferred: 2g
| allowed: 2g, 4g; preferred: 4g
| allowed: 2g, 4g; preferred: 2g
| allowed: 3g, 4g; preferred: 4g
| allowed: 3g, 4g; preferred: 3g
| allowed: 2g, 3g, 4g; preferred: 4g
| allowed: 2g, 3g, 4g; preferred: 3g
| allowed: 2g, 3g, 4g; preferred: 2g
| current: allowed: 2g, 3g, 4g; preferred: 4g
--------------------------------
Bands | supported: egsm, dcs, pcs, g850, utran-1, utran-6, utran-5, utran-2,
| eutran-1, eutran-4, eutran-17
| current: egsm, dcs, pcs, g850, utran-1, utran-6, utran-5, utran-2,
| eutran-1, eutran-4, eutran-17
--------------------------------
IP | supported: ipv4, ipv6, ipv4v6
--------------------------------
3GPP | imei: 012810001492618
| enabled locks: fixed-dialing
| operator id: 26203
| operator name: MEDIONmobile
| registration: home
--------------------------------
3GPP EPS | ue mode of operation: ps-1
--------------------------------
SIM | primary sim path: /org/freedesktop/ModemManager1/SIM/3
--------------------------------
Bearer | paths: /org/freedesktop/ModemManager1/Bearer/3
As far as I have read ModemManager uses a qml proxy, so why is it out of client ids? Any ideas why the 'ClientIdsExhausted' error occurs?
Is there a better workaround than resetting the modem via mmcli -m 0 -v -r
?
Any help is appreciated and thanks for the great work on libqmi!