SIM PIN Unlock Error in MM 1.22.0
Amol Lad
Amol.Lad at 4rf.com
Mon Apr 22 08:52:58 UTC 2024
Hi,
We are getting following error when trying to send pin to the SIM card. The problem is not observed in MM 1.20.4. However, please note that the SIM card does unlocks after the below command even though error is reported.
# mmcli -i 0 --pin=1234
error: couldn't send PIN code to the SIM: 'GDBus.Error:org.freedesktop.ModemManager1.Error.Core.Failed: Couldn't get interface skeleton'
Now, after looking through the code, following change is causing this issue. This change was not present in 1.20.4
----
mm-broadband-modem-mbim.c:
if ((self->priv->enabled_cache.last_ready_state != MBIM_SUBSCRIBER_READY_STATE_DEVICE_LOCKED &&
ready_state == MBIM_SUBSCRIBER_READY_STATE_DEVICE_LOCKED) ||
(self->priv->enabled_cache.last_ready_state == MBIM_SUBSCRIBER_READY_STATE_DEVICE_LOCKED &&
ready_state != MBIM_SUBSCRIBER_READY_STATE_DEVICE_LOCKED)) {
mm_obj_dbg (self, "Lock state change detected");
active_sim_event = TRUE;
}
self->priv->enabled_cache.last_ready_state = ready_state;
if (active_sim_event) {
mm_iface_modem_process_sim_event (MM_IFACE_MODEM (self));
}
----
What is happening is when SIM PIN lock state changes then mm_iface_modem_process_sim_event () is called which eventually calls mm_base_modem_set_reprobe(). The reprobe, "unexports" the current modem instance (modem 0) and recreates a new modem instance (1). As a result, the above mmcli command is reporting error. I'm not sure why this should happen for SIM Lock state change.
The logs are below. As you can see at timestamp 1713774618.140486, the modem is unexported and then it's all cleanup and creation of new modem instance.
Please advise.
<dbg> [1713774617.896807] [modem0/sim0] sending PIN...
<dbg> [1713774617.896908] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 80
<<<<<< data = 03:00:00:00:50:00:00:00:17:00:00:00...
<dbg> [1713774617.897063] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 80
<<<<<< type = command (0x00000003)
<<<<<< transaction = 23
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<< cid = 'pin' (0x00000004)
<<<<<< type = 'set' (0x00000001)
<<<<<< Fields:
<<<<<< PinType = 'pin1'
<<<<<< PinOperation = 'enter'
<<<<<< Pin = '1234'
<<<<<< NewPin = '(NULL)'
<dbg> [1713774618.139714] [/dev/cdc-wdm0] received message...
>>>>>> RAW:
>>>>>> length = 144
>>>>>> data = 07:00:00:80:90:00:00:00:00:00:00:00...
<dbg> [1713774618.139908] [/dev/cdc-wdm0] received message (translated)...
>>>>>> Header:
>>>>>> length = 144
>>>>>> type = indicate-status (0x80000007)
>>>>>> transaction = 0
>>>>>> Fragment header:
>>>>>> total = 1
>>>>>> current = 0
>>>>>> Contents:
>>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>> cid = 'subscriber-ready-status' (0x00000002)
>>>>>> Fields:
>>>>>> ReadyState = 'not-initialized'
>>>>>> SubscriberId = '###'
>>>>>> SimIccId = '###'
>>>>>> ReadyInfo = 'none'
>>>>>> TelephoneNumbersCount = '0'
>>>>>> TelephoneNumbers = '###'
<dbg> [1713774618.139979] [modem0] received notification (service 'basic-connect', command 'subscriber-ready-status')
<dbg> [1713774618.140012] [modem0] processed subscriber ready status notification
<dbg> [1713774618.140033] [modem0] Lock state change detected
<inf> [1713774618.140052] [modem0] Processing SIM event
<dbg> [1713774618.140486] [device /sys/devices/platform/soc/soc:internal-regs/f10f0000.usb3/usb3/3-1] unexported modem from path '/org/freedesktop/ModemManager1/Modem/0'
<dbg> [1713774618.140532] [modem0] supported notifications: signal (no), registration (no), sms (no), connect (no), subscriber (no), packet (no), pco (no), ussd (no), lte attach info (no), provisioned contexts (no), slot_info_status (no)
<dbg> [1713774618.140585] [cdc-wdm0/mbim] Releasing client for service 'uim'...
<dbg> [1713774618.140623] [/dev/cdc-wdm0] releasing 'uim' client with flags 'release-cid'...
<dbg> [1713774618.140657] [/dev/cdc-wdm0] unregistered 'uim' client with ID '2'
<dbg> [1713774618.140769] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:00:00:00:07:23:00:05:00...
<dbg> [1713774618.140910] [/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 7
<<<<<< tlv_length = 5
<<<<<< message = "Release CID" (0x0023)
<<<<<< TLV:
<<<<<< type = "Release Info" (0x01)
<<<<<< length = 2
<<<<<< value = 0B:02
<<<<<< translated = [ service = 'uim' cid = '2' ]
<dbg> [1713774618.140994] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 65
<<<<<< data = 03:00:00:00:41:00:00:00:15:00:00:00...
<dbg> [1713774618.141233] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 65
<<<<<< type = command (0x00000003)
<<<<<< transaction = 21
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'qmi' (d1a30bc2-f97a-6e43-bf65-c7e24fb0f0d3)
<<<<<< cid = 'msg' (0x00000001)
<<<<<< type = 'set' (0x00000001)
<<<<<< Fields:
<<<<<< QmiMsg = '01:10:00:00:00:00:00:07:23:00:05:00:01:02:00:0b:02'
<dbg> [1713774618.141459] [cdc-wdm0/mbim] Releasing client for service 'pdc'...
<dbg> [1713774618.141503] [/dev/cdc-wdm0] releasing 'pdc' client with flags 'release-cid'...
<dbg> [1713774618.141541] [/dev/cdc-wdm0] unregistered 'pdc' client with ID '1'
<dbg> [1713774618.141637] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:00:00:00:08:23:00:05:00...
<dbg> [1713774618.141777] [/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 8
<<<<<< tlv_length = 5
<<<<<< message = "Release CID" (0x0023)
<<<<<< TLV:
<<<<<< type = "Release Info" (0x01)
<<<<<< length = 2
<<<<<< value = 24:01
<<<<<< translated = [ service = 'pdc' cid = '1' ]
<dbg> [1713774618.141864] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 65
<<<<<< data = 03:00:00:00:41:00:00:00:16:00:00:00...
<dbg> [1713774618.142035] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 65
<<<<<< type = command (0x00000003)
<<<<<< transaction = 22
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'qmi' (d1a30bc2-f97a-6e43-bf65-c7e24fb0f0d3)
<<<<<< cid = 'msg' (0x00000001)
<<<<<< type = 'set' (0x00000001)
<<<<<< Fields:
<<<<<< QmiMsg = '01:10:00:00:00:00:00:08:23:00:05:00:01:02:00:24:01'
<dbg> [1713774618.142226] [cdc-wdm0/mbim] Releasing client for service 'loc'...
<dbg> [1713774618.142268] [/dev/cdc-wdm0] releasing 'loc' client with flags 'release-cid'...
<dbg> [1713774618.142304] [/dev/cdc-wdm0] unregistered 'loc' client with ID '1'
<dbg> [1713774618.142398] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:00:00:00:09:23:00:05:00...
<dbg> [1713774618.142536] [/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 9
<<<<<< tlv_length = 5
<<<<<< message = "Release CID" (0x0023)
<<<<<< TLV:
<<<<<< type = "Release Info" (0x01)
<<<<<< length = 2
<<<<<< value = 10:01
<<<<<< translated = [ service = 'loc' cid = '1' ]
<dbg> [1713774618.142608] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 65
<<<<<< data = 03:00:00:00:41:00:00:00:17:00:00:00...
<dbg> [1713774618.142778] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 65
<<<<<< type = command (0x00000003)
<<<<<< transaction = 23
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'qmi' (d1a30bc2-f97a-6e43-bf65-c7e24fb0f0d3)
<<<<<< cid = 'msg' (0x00000001)
<<<<<< type = 'set' (0x00000001)
<<<<<< Fields:
<<<<<< QmiMsg = '01:10:00:00:00:00:00:09:23:00:05:00:01:02:00:10:01'
<dbg> [1713774618.142941] [cdc-wdm0/mbim] Releasing client for service 'nas'...
<dbg> [1713774618.142981] [/dev/cdc-wdm0] releasing 'nas' client with flags 'release-cid'...
<dbg> [1713774618.143017] [/dev/cdc-wdm0] unregistered 'nas' client with ID '2'
<dbg> [1713774618.143120] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:00:00:00:0A:23:00:05:00...
<dbg> [1713774618.143255] [/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 10
<<<<<< tlv_length = 5
<<<<<< message = "Release CID" (0x0023)
<<<<<< TLV:
<<<<<< type = "Release Info" (0x01)
<<<<<< length = 2
<<<<<< value = 03:02
<<<<<< translated = [ service = 'nas' cid = '2' ]
<dbg> [1713774618.143329] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 65
<<<<<< data = 03:00:00:00:41:00:00:00:18:00:00:00...
<dbg> [1713774618.143500] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 65
<<<<<< type = command (0x00000003)
<<<<<< transaction = 24
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'qmi' (d1a30bc2-f97a-6e43-bf65-c7e24fb0f0d3)
<<<<<< cid = 'msg' (0x00000001)
<<<<<< type = 'set' (0x00000001)
<<<<<< Fields:
<<<<<< QmiMsg = '01:10:00:00:00:00:00:0a:23:00:05:00:01:02:00:03:02'
<dbg> [1713774618.143662] [cdc-wdm0/mbim] Releasing client for service 'dms'...
<dbg> [1713774618.143703] [/dev/cdc-wdm0] releasing 'dms' client with flags 'release-cid'...
<dbg> [1713774618.143739] [/dev/cdc-wdm0] unregistered 'dms' client with ID '1'
<dbg> [1713774618.143831] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:00:00:00:0B:23:00:05:00...
<dbg> [1713774618.143975] [/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 11
<<<<<< tlv_length = 5
<<<<<< message = "Release CID" (0x0023)
<<<<<< TLV:
<<<<<< type = "Release Info" (0x01)
<<<<<< length = 2
<<<<<< value = 02:01
<<<<<< translated = [ service = 'dms' cid = '1' ]
<dbg> [1713774618.144053] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 65
<<<<<< data = 03:00:00:00:41:00:00:00:19:00:00:00...
<dbg> [1713774618.144688] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 65
<<<<<< type = command (0x00000003)
<<<<<< transaction = 25
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'qmi' (d1a30bc2-f97a-6e43-bf65-c7e24fb0f0d3)
<<<<<< cid = 'msg' (0x00000001)
<<<<<< type = 'set' (0x00000001)
<<<<<< Fields:
<<<<<< QmiMsg = '01:10:00:00:00:00:00:0b:23:00:05:00:01:02:00:02:01'
<dbg> [1713774618.144932] [/dev/cdc-wdm0] closing device...
<dbg> [1713774618.144994] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 12
<<<<<< data = 02:00:00:00:0C:00:00:00:1A:00:00:00...
<dbg> [1713774618.145042] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 12
<<<<<< type = close (0x00000002)
<<<<<< transaction = 26
<dbg> [1713774618.145701] [modem0] cleaning up port 'unknown/ttyUSB0'...
<dbg> [1713774618.145742] [modem0] cleaning up port 'tty/ttyUSB1'...
<dbg> [1713774618.145767] [modem0] cleaning up port 'tty/ttyUSB2'...
<dbg> [1713774618.145794] [modem0] cleaning up port 'usbmisc/cdc-wdm0'...
<dbg> [1713774618.145842] [modem0] cleaning up port 'net/wwan0'...
<dbg> [1713774618.145883] [modem0/ttyUSB1/gps] forced to close port
<dbg> [1713774618.145982] [ttyUSB2/at] forced to close port
<dbg> [1713774618.146170] [/dev/cdc-wdm0] received message...
>>>>>> RAW:
>>>>>> length = 16
>>>>>> data = 02:00:00:80:10:00:00:00:1A:00:00:00...
<dbg> [1713774618.146209] [/dev/cdc-wdm0] channel destroyed
<dbg> [1713774618.146453] [/dev/cdc-wdm0] closing device...
<dbg> [1713774618.146518] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 12
<<<<<< data = 02:00:00:00:0C:00:00:00:18:00:00:00...
<dbg> [1713774618.146567] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 12
<<<<<< type = close (0x00000002)
<<<<<< transaction = 24
<dbg> [1713774618.148503] [/dev/cdc-wdm0] received message...
>>>>>> RAW:
>>>>>> length = 16
>>>>>> data = 02:00:00:80:10:00:00:00:18:00:00:00...
<dbg> [1713774618.148550] [/dev/cdc-wdm0] channel destroyed
<dbg> [1713774620.526412] [device /sys/devices/platform/soc/soc:internal-regs/f10f0000.usb3/usb3/3-1] Reprobing modem...
<msg> [1713774620.526462] [device /sys/devices/platform/soc/soc:internal-regs/f10f0000.usb3/usb3/3-1] creating modem with plugin 'sierra' and '5' ports
<dbg> [1713774620.526495] [plugin/sierra] (sierra) MBIM-powered Sierra modem found...
<dbg> [1713774620.527187] [ttyUSB2/at] port monitoring enabled in AT port
<dbg> [1713774620.527379] [ttyUSB2/at] AT port flagged as primary
<dbg> [1713774620.527406] [modem1] port 'tty/ttyUSB2' grabbed
<dbg> [1713774620.527491] [modem1] port 'tty/ttyUSB1' grabbed
<dbg> [1713774620.527515] [plugin/sierra] port ttyUSB0 is explicitly ignored
<dbg> [1713774620.527569] [modem1] port 'tty/ttyUSB0' grabbed
<dbg> [1713774620.527618] [cdc-wdm0/mbim] port monitoring enabled in MBIM port
<dbg> [1713774620.527668] [modem1] port 'usbmisc/cdc-wdm0' grabbed
<dbg> [1713774620.527729] [modem1] port 'net/wwan0' grabbed
<inf> [1713774620.527759] [modem1] tty/ttyUSB2: at (primary)
<inf> [1713774620.527782] [modem1] tty/ttyUSB2: at (data primary)
<inf> [1713774620.527804] [modem1] net/wwan0: net (data)
<inf> [1713774620.527825] [modem1] tty/ttyUSB1: gps (nmea)
<inf> [1713774620.527846] [modem1] usbmisc/cdc-wdm0: mbim
<dbg> [1713774620.527879] [modem1] at data ports available but ignored
<dbg> [1713774620.528522] [modem1] not running data interface reset procedure: device is hotplugged
<dbg> [1713774620.528714] [device /sys/devices/platform/soc/soc:internal-regs/f10f0000.usb3/usb3/3-1] modem recreated
<dbg> [1713774620.528857] [/dev/cdc-wdm0] opening device...
<dbg> [1713774620.529546] [/dev/cdc-wdm0] read max control message size from descriptors file: 4096
<dbg> [1713774620.529696] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
---
Modem details:
root at AprisaLTE:/# mmcli -m 1
----------------------------------
General | path: /org/freedesktop/ModemManager1/Modem/1
| device id: efbe77ae4f80684040aa8189e7ce658a8f93cc1b
----------------------------------
Hardware | manufacturer: Sierra Wireless, Incorporated
| model: Sierra Wireless EM7565 Qualcomm® Snapdragon™ X16 LTE-A
| firmware revision: SWI9X50C_01.14.13.00
| carrier config: default
| h/w revision: EM7565
| supported: gsm-umts, lte
| current: gsm-umts, lte
| equipment id: 353533100763419
----------------------------------
System | device: /sys/devices/platform/soc/soc:internal-regs/f10f0000.usb3/usb3/3-1
| physdev: /sys/devices/platform/soc/soc:internal-regs/f10f0000.usb3/usb3/3-1
| drivers: cdc_mbim, qcserial
| plugin: sierra
| primary port: cdc-wdm0
| ports: cdc-wdm0 (mbim), ttyUSB0 (ignored), ttyUSB1 (gps),
| ttyUSB2 (at), wwan0 (net)
----------------------------------
Status | lock: sim-pin2
| unlock retries: sim-pin2 (3)
| state: disabled
| power state: on
----------------------------------
Modes | supported: allowed: 3g; preferred: none
| allowed: 4g; preferred: none
| allowed: 3g, 4g; preferred: 4g
| allowed: 3g, 4g; preferred: 3g
| current: allowed: 4g; preferred: none
----------------------------------
Bands | supported: utran-1, utran-4, utran-6, utran-5, utran-8, utran-9,
| utran-2, eutran-1, eutran-2, eutran-3, eutran-4, eutran-5, eutran-7,
| eutran-8, eutran-9, eutran-12, eutran-13, eutran-18, eutran-19,
| eutran-20, eutran-26, eutran-28, eutran-29, eutran-30, eutran-32,
| eutran-41, eutran-42, eutran-43, eutran-46, eutran-48, eutran-66,
| utran-19
| current: eutran-1, eutran-2, eutran-3, eutran-4, eutran-5, eutran-7,
| eutran-8, eutran-9, eutran-12, eutran-13, eutran-18, eutran-19,
| eutran-20, eutran-26, eutran-28, eutran-29, eutran-30, eutran-32,
| eutran-41, eutran-42, eutran-43, eutran-46, eutran-48, eutran-66
----------------------------------
IP | supported: ipv4, ipv6, ipv4v6
----------------------------------
3GPP | imei: 353533100763419
| enabled locks: sim, fixed-dialing
----------------------------------
3GPP EPS | ue mode of operation: csps-2
| initial bearer apn: internet
| initial bearer ip type: ipv4
----------------------------------
SIM | primary sim path: /org/freedesktop/ModemManager1/SIM/1
| sim slot paths: slot 1: none (active)
| slot 2: none
-------------- next part --------------
Hi,
We are getting following error when trying to send pin to the SIM card. The problem is not observed in MM 1.20.4. However, please note that the SIM card does unlocks after the below command even though error is reported.
# mmcli -i 0 --pin=1234
error: couldn't send PIN code to the SIM: 'GDBus.Error:org.freedesktop.ModemManager1.Error.Core.Failed: Couldn't get interface skeleton'
Now, after looking through the code, following change is causing this issue. This change was not present in 1.20.4
----
mm-broadband-modem-mbim.c:
if ((self->priv->enabled_cache.last_ready_state != MBIM_SUBSCRIBER_READY_STATE_DEVICE_LOCKED &&
ready_state == MBIM_SUBSCRIBER_READY_STATE_DEVICE_LOCKED) ||
(self->priv->enabled_cache.last_ready_state == MBIM_SUBSCRIBER_READY_STATE_DEVICE_LOCKED &&
ready_state != MBIM_SUBSCRIBER_READY_STATE_DEVICE_LOCKED)) {
mm_obj_dbg (self, "Lock state change detected");
active_sim_event = TRUE;
}
self->priv->enabled_cache.last_ready_state = ready_state;
if (active_sim_event) {
mm_iface_modem_process_sim_event (MM_IFACE_MODEM (self));
}
----
What is happening is when SIM PIN lock state changes then mm_iface_modem_process_sim_event () is called which eventually calls mm_base_modem_set_reprobe(). The reprobe, "unexports" the current modem instance (modem 0) and recreates a new modem instance (1). As a result, the above mmcli command is reporting error. I'm not sure why this should happen for SIM Lock state change.
The logs are below. As you can see at timestamp 1713774618.140486, the modem is unexported and then it's all cleanup and creation of new modem instance.
Please advise.
<dbg> [1713774617.896807] [modem0/sim0] sending PIN...
<dbg> [1713774617.896908] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 80
<<<<<< data = 03:00:00:00:50:00:00:00:17:00:00:00...
<dbg> [1713774617.897063] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 80
<<<<<< type = command (0x00000003)
<<<<<< transaction = 23
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<< cid = 'pin' (0x00000004)
<<<<<< type = 'set' (0x00000001)
<<<<<< Fields:
<<<<<< PinType = 'pin1'
<<<<<< PinOperation = 'enter'
<<<<<< Pin = '1234'
<<<<<< NewPin = '(NULL)'
<dbg> [1713774618.139714] [/dev/cdc-wdm0] received message...
>>>>>> RAW:
>>>>>> length = 144
>>>>>> data = 07:00:00:80:90:00:00:00:00:00:00:00...
<dbg> [1713774618.139908] [/dev/cdc-wdm0] received message (translated)...
>>>>>> Header:
>>>>>> length = 144
>>>>>> type = indicate-status (0x80000007)
>>>>>> transaction = 0
>>>>>> Fragment header:
>>>>>> total = 1
>>>>>> current = 0
>>>>>> Contents:
>>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>> cid = 'subscriber-ready-status' (0x00000002)
>>>>>> Fields:
>>>>>> ReadyState = 'not-initialized'
>>>>>> SubscriberId = '###'
>>>>>> SimIccId = '###'
>>>>>> ReadyInfo = 'none'
>>>>>> TelephoneNumbersCount = '0'
>>>>>> TelephoneNumbers = '###'
<dbg> [1713774618.139979] [modem0] received notification (service 'basic-connect', command 'subscriber-ready-status')
<dbg> [1713774618.140012] [modem0] processed subscriber ready status notification
<dbg> [1713774618.140033] [modem0] Lock state change detected
<inf> [1713774618.140052] [modem0] Processing SIM event
<dbg> [1713774618.140486] [device /sys/devices/platform/soc/soc:internal-regs/f10f0000.usb3/usb3/3-1] unexported modem from path '/org/freedesktop/ModemManager1/Modem/0'
<dbg> [1713774618.140532] [modem0] supported notifications: signal (no), registration (no), sms (no), connect (no), subscriber (no), packet (no), pco (no), ussd (no), lte attach info (no), provisioned contexts (no), slot_info_status (no)
<dbg> [1713774618.140585] [cdc-wdm0/mbim] Releasing client for service 'uim'...
<dbg> [1713774618.140623] [/dev/cdc-wdm0] releasing 'uim' client with flags 'release-cid'...
<dbg> [1713774618.140657] [/dev/cdc-wdm0] unregistered 'uim' client with ID '2'
<dbg> [1713774618.140769] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:00:00:00:07:23:00:05:00...
<dbg> [1713774618.140910] [/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 7
<<<<<< tlv_length = 5
<<<<<< message = "Release CID" (0x0023)
<<<<<< TLV:
<<<<<< type = "Release Info" (0x01)
<<<<<< length = 2
<<<<<< value = 0B:02
<<<<<< translated = [ service = 'uim' cid = '2' ]
<dbg> [1713774618.140994] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 65
<<<<<< data = 03:00:00:00:41:00:00:00:15:00:00:00...
<dbg> [1713774618.141233] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 65
<<<<<< type = command (0x00000003)
<<<<<< transaction = 21
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'qmi' (d1a30bc2-f97a-6e43-bf65-c7e24fb0f0d3)
<<<<<< cid = 'msg' (0x00000001)
<<<<<< type = 'set' (0x00000001)
<<<<<< Fields:
<<<<<< QmiMsg = '01:10:00:00:00:00:00:07:23:00:05:00:01:02:00:0b:02'
<dbg> [1713774618.141459] [cdc-wdm0/mbim] Releasing client for service 'pdc'...
<dbg> [1713774618.141503] [/dev/cdc-wdm0] releasing 'pdc' client with flags 'release-cid'...
<dbg> [1713774618.141541] [/dev/cdc-wdm0] unregistered 'pdc' client with ID '1'
<dbg> [1713774618.141637] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:00:00:00:08:23:00:05:00...
<dbg> [1713774618.141777] [/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 8
<<<<<< tlv_length = 5
<<<<<< message = "Release CID" (0x0023)
<<<<<< TLV:
<<<<<< type = "Release Info" (0x01)
<<<<<< length = 2
<<<<<< value = 24:01
<<<<<< translated = [ service = 'pdc' cid = '1' ]
<dbg> [1713774618.141864] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 65
<<<<<< data = 03:00:00:00:41:00:00:00:16:00:00:00...
<dbg> [1713774618.142035] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 65
<<<<<< type = command (0x00000003)
<<<<<< transaction = 22
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'qmi' (d1a30bc2-f97a-6e43-bf65-c7e24fb0f0d3)
<<<<<< cid = 'msg' (0x00000001)
<<<<<< type = 'set' (0x00000001)
<<<<<< Fields:
<<<<<< QmiMsg = '01:10:00:00:00:00:00:08:23:00:05:00:01:02:00:24:01'
<dbg> [1713774618.142226] [cdc-wdm0/mbim] Releasing client for service 'loc'...
<dbg> [1713774618.142268] [/dev/cdc-wdm0] releasing 'loc' client with flags 'release-cid'...
<dbg> [1713774618.142304] [/dev/cdc-wdm0] unregistered 'loc' client with ID '1'
<dbg> [1713774618.142398] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:00:00:00:09:23:00:05:00...
<dbg> [1713774618.142536] [/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 9
<<<<<< tlv_length = 5
<<<<<< message = "Release CID" (0x0023)
<<<<<< TLV:
<<<<<< type = "Release Info" (0x01)
<<<<<< length = 2
<<<<<< value = 10:01
<<<<<< translated = [ service = 'loc' cid = '1' ]
<dbg> [1713774618.142608] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 65
<<<<<< data = 03:00:00:00:41:00:00:00:17:00:00:00...
<dbg> [1713774618.142778] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 65
<<<<<< type = command (0x00000003)
<<<<<< transaction = 23
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'qmi' (d1a30bc2-f97a-6e43-bf65-c7e24fb0f0d3)
<<<<<< cid = 'msg' (0x00000001)
<<<<<< type = 'set' (0x00000001)
<<<<<< Fields:
<<<<<< QmiMsg = '01:10:00:00:00:00:00:09:23:00:05:00:01:02:00:10:01'
<dbg> [1713774618.142941] [cdc-wdm0/mbim] Releasing client for service 'nas'...
<dbg> [1713774618.142981] [/dev/cdc-wdm0] releasing 'nas' client with flags 'release-cid'...
<dbg> [1713774618.143017] [/dev/cdc-wdm0] unregistered 'nas' client with ID '2'
<dbg> [1713774618.143120] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:00:00:00:0A:23:00:05:00...
<dbg> [1713774618.143255] [/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 10
<<<<<< tlv_length = 5
<<<<<< message = "Release CID" (0x0023)
<<<<<< TLV:
<<<<<< type = "Release Info" (0x01)
<<<<<< length = 2
<<<<<< value = 03:02
<<<<<< translated = [ service = 'nas' cid = '2' ]
<dbg> [1713774618.143329] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 65
<<<<<< data = 03:00:00:00:41:00:00:00:18:00:00:00...
<dbg> [1713774618.143500] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 65
<<<<<< type = command (0x00000003)
<<<<<< transaction = 24
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'qmi' (d1a30bc2-f97a-6e43-bf65-c7e24fb0f0d3)
<<<<<< cid = 'msg' (0x00000001)
<<<<<< type = 'set' (0x00000001)
<<<<<< Fields:
<<<<<< QmiMsg = '01:10:00:00:00:00:00:0a:23:00:05:00:01:02:00:03:02'
<dbg> [1713774618.143662] [cdc-wdm0/mbim] Releasing client for service 'dms'...
<dbg> [1713774618.143703] [/dev/cdc-wdm0] releasing 'dms' client with flags 'release-cid'...
<dbg> [1713774618.143739] [/dev/cdc-wdm0] unregistered 'dms' client with ID '1'
<dbg> [1713774618.143831] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:00:00:00:0B:23:00:05:00...
<dbg> [1713774618.143975] [/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 11
<<<<<< tlv_length = 5
<<<<<< message = "Release CID" (0x0023)
<<<<<< TLV:
<<<<<< type = "Release Info" (0x01)
<<<<<< length = 2
<<<<<< value = 02:01
<<<<<< translated = [ service = 'dms' cid = '1' ]
<dbg> [1713774618.144053] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 65
<<<<<< data = 03:00:00:00:41:00:00:00:19:00:00:00...
<dbg> [1713774618.144688] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 65
<<<<<< type = command (0x00000003)
<<<<<< transaction = 25
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'qmi' (d1a30bc2-f97a-6e43-bf65-c7e24fb0f0d3)
<<<<<< cid = 'msg' (0x00000001)
<<<<<< type = 'set' (0x00000001)
<<<<<< Fields:
<<<<<< QmiMsg = '01:10:00:00:00:00:00:0b:23:00:05:00:01:02:00:02:01'
<dbg> [1713774618.144932] [/dev/cdc-wdm0] closing device...
<dbg> [1713774618.144994] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 12
<<<<<< data = 02:00:00:00:0C:00:00:00:1A:00:00:00...
<dbg> [1713774618.145042] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 12
<<<<<< type = close (0x00000002)
<<<<<< transaction = 26
<dbg> [1713774618.145701] [modem0] cleaning up port 'unknown/ttyUSB0'...
<dbg> [1713774618.145742] [modem0] cleaning up port 'tty/ttyUSB1'...
<dbg> [1713774618.145767] [modem0] cleaning up port 'tty/ttyUSB2'...
<dbg> [1713774618.145794] [modem0] cleaning up port 'usbmisc/cdc-wdm0'...
<dbg> [1713774618.145842] [modem0] cleaning up port 'net/wwan0'...
<dbg> [1713774618.145883] [modem0/ttyUSB1/gps] forced to close port
<dbg> [1713774618.145982] [ttyUSB2/at] forced to close port
<dbg> [1713774618.146170] [/dev/cdc-wdm0] received message...
>>>>>> RAW:
>>>>>> length = 16
>>>>>> data = 02:00:00:80:10:00:00:00:1A:00:00:00...
<dbg> [1713774618.146209] [/dev/cdc-wdm0] channel destroyed
<dbg> [1713774618.146453] [/dev/cdc-wdm0] closing device...
<dbg> [1713774618.146518] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 12
<<<<<< data = 02:00:00:00:0C:00:00:00:18:00:00:00...
<dbg> [1713774618.146567] [/dev/cdc-wdm0] sent message (translated)...
<<<<<< Header:
<<<<<< length = 12
<<<<<< type = close (0x00000002)
<<<<<< transaction = 24
<dbg> [1713774618.148503] [/dev/cdc-wdm0] received message...
>>>>>> RAW:
>>>>>> length = 16
>>>>>> data = 02:00:00:80:10:00:00:00:18:00:00:00...
<dbg> [1713774618.148550] [/dev/cdc-wdm0] channel destroyed
<dbg> [1713774620.526412] [device /sys/devices/platform/soc/soc:internal-regs/f10f0000.usb3/usb3/3-1] Reprobing modem...
<msg> [1713774620.526462] [device /sys/devices/platform/soc/soc:internal-regs/f10f0000.usb3/usb3/3-1] creating modem with plugin 'sierra' and '5' ports
<dbg> [1713774620.526495] [plugin/sierra] (sierra) MBIM-powered Sierra modem found...
<dbg> [1713774620.527187] [ttyUSB2/at] port monitoring enabled in AT port
<dbg> [1713774620.527379] [ttyUSB2/at] AT port flagged as primary
<dbg> [1713774620.527406] [modem1] port 'tty/ttyUSB2' grabbed
<dbg> [1713774620.527491] [modem1] port 'tty/ttyUSB1' grabbed
<dbg> [1713774620.527515] [plugin/sierra] port ttyUSB0 is explicitly ignored
<dbg> [1713774620.527569] [modem1] port 'tty/ttyUSB0' grabbed
<dbg> [1713774620.527618] [cdc-wdm0/mbim] port monitoring enabled in MBIM port
<dbg> [1713774620.527668] [modem1] port 'usbmisc/cdc-wdm0' grabbed
<dbg> [1713774620.527729] [modem1] port 'net/wwan0' grabbed
<inf> [1713774620.527759] [modem1] tty/ttyUSB2: at (primary)
<inf> [1713774620.527782] [modem1] tty/ttyUSB2: at (data primary)
<inf> [1713774620.527804] [modem1] net/wwan0: net (data)
<inf> [1713774620.527825] [modem1] tty/ttyUSB1: gps (nmea)
<inf> [1713774620.527846] [modem1] usbmisc/cdc-wdm0: mbim
<dbg> [1713774620.527879] [modem1] at data ports available but ignored
<dbg> [1713774620.528522] [modem1] not running data interface reset procedure: device is hotplugged
<dbg> [1713774620.528714] [device /sys/devices/platform/soc/soc:internal-regs/f10f0000.usb3/usb3/3-1] modem recreated
<dbg> [1713774620.528857] [/dev/cdc-wdm0] opening device...
<dbg> [1713774620.529546] [/dev/cdc-wdm0] read max control message size from descriptors file: 4096
<dbg> [1713774620.529696] [/dev/cdc-wdm0] sent message...
<<<<<< RAW:
---
Modem details:
root at AprisaLTE:/# mmcli -m 1
----------------------------------
General | path: /org/freedesktop/ModemManager1/Modem/1
| device id: efbe77ae4f80684040aa8189e7ce658a8f93cc1b
----------------------------------
Hardware | manufacturer: Sierra Wireless, Incorporated
| model: Sierra Wireless EM7565 Qualcomm® Snapdragon™ X16 LTE-A
| firmware revision: SWI9X50C_01.14.13.00
| carrier config: default
| h/w revision: EM7565
| supported: gsm-umts, lte
| current: gsm-umts, lte
| equipment id: 353533100763419
----------------------------------
System | device: /sys/devices/platform/soc/soc:internal-regs/f10f0000.usb3/usb3/3-1
| physdev: /sys/devices/platform/soc/soc:internal-regs/f10f0000.usb3/usb3/3-1
| drivers: cdc_mbim, qcserial
| plugin: sierra
| primary port: cdc-wdm0
| ports: cdc-wdm0 (mbim), ttyUSB0 (ignored), ttyUSB1 (gps),
| ttyUSB2 (at), wwan0 (net)
----------------------------------
Status | lock: sim-pin2
| unlock retries: sim-pin2 (3)
| state: disabled
| power state: on
----------------------------------
Modes | supported: allowed: 3g; preferred: none
| allowed: 4g; preferred: none
| allowed: 3g, 4g; preferred: 4g
| allowed: 3g, 4g; preferred: 3g
| current: allowed: 4g; preferred: none
----------------------------------
Bands | supported: utran-1, utran-4, utran-6, utran-5, utran-8, utran-9,
| utran-2, eutran-1, eutran-2, eutran-3, eutran-4, eutran-5, eutran-7,
| eutran-8, eutran-9, eutran-12, eutran-13, eutran-18, eutran-19,
| eutran-20, eutran-26, eutran-28, eutran-29, eutran-30, eutran-32,
| eutran-41, eutran-42, eutran-43, eutran-46, eutran-48, eutran-66,
| utran-19
| current: eutran-1, eutran-2, eutran-3, eutran-4, eutran-5, eutran-7,
| eutran-8, eutran-9, eutran-12, eutran-13, eutran-18, eutran-19,
| eutran-20, eutran-26, eutran-28, eutran-29, eutran-30, eutran-32,
| eutran-41, eutran-42, eutran-43, eutran-46, eutran-48, eutran-66
----------------------------------
IP | supported: ipv4, ipv6, ipv4v6
----------------------------------
3GPP | imei: 353533100763419
| enabled locks: sim, fixed-dialing
----------------------------------
3GPP EPS | ue mode of operation: csps-2
| initial bearer apn: internet
| initial bearer ip type: ipv4
----------------------------------
SIM | primary sim path: /org/freedesktop/ModemManager1/SIM/1
| sim slot paths: slot 1: none (active)
| slot 2: none
More information about the ModemManager-devel
mailing list