SIM Card PIN Change Timeout (MM 1.18.2)

Aleksander Morgado aleksander at aleksander.es
Mon Nov 8 09:34:25 UTC 2021


Hey,

>
>
> If we attempt to change SIM Card PIN when the SIM is in locked state then "Timeout is reached" error is reported BUT the PIN is actually changed. Below are some details.
>
>
>
> # mmcli -m 0
>
>   -----------------------------
>
>   General  |              path: /org/freedesktop/ModemManager1/Modem/0
>
>            |         device id: 02c606168e3d349049dd25edafba09756e8ca26d
>
>   -----------------------------
>
>   Hardware |      manufacturer: Sierra Wireless, Incorporated
>
>            |             model: Sierra Wireless EM7455 Qualcomm(r) Snapdragon(tm) X7 LTE-A
>
>            | firmware revision: SWI9X30C_02.24.05.06
>
>            |    carrier config: default
>
>            |      h/w revision: EM7455
>
>            |         supported: gsm-umts, lte
>
>            |           current: gsm-umts, lte
>
>            |      equipment id: 359073061147272
>
>   -----------------------------
>
>   System   |            device: /sys/devices/platform/soc/soc:internal-regs/f10f0000.usb3/usb2/2-1
>
>            |           drivers: qcserial, cdc_mbim
>
>            |            plugin: sierra
>
>            |      primary port: cdc-wdm0
>
>            |             ports: cdc-wdm0 (mbim), ttyUSB0 (qcdm), ttyUSB1 (gps),
>
>            |                    ttyUSB2 (at), wwan0 (net)
>
>   -----------------------------
>
>   Status   |             state: locked
>
>            |       power state: on
>
>            |    signal quality: 0% (cached)
>
>   -----------------------------
>
>   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-3, utran-4, utran-5, utran-8, utran-2,
>
>            |                    eutran-1, eutran-2, eutran-3, eutran-4, eutran-5, eutran-7, eutran-8,
>
>            |                    eutran-12, eutran-13, eutran-20, eutran-25, eutran-26, eutran-29,
>
>            |                    eutran-30, eutran-41
>
>            |           current: eutran-1, eutran-2, eutran-3, eutran-4, eutran-5, eutran-7,
>
>            |                    eutran-8, eutran-12, eutran-13, eutran-20, eutran-25, eutran-26,
>
>            |                    eutran-29, eutran-30, eutran-41
>
>   -----------------------------
>
>   IP       |         supported: ipv4, ipv6, ipv4v6
>
>   -----------------------------
>
>   3GPP     |     enabled locks: sim, fixed-dialing
>
>   -----------------------------
>
>   SIM      |  primary sim path: /org/freedesktop/ModemManager1/SIM/0
>
>
>
> # mmcli -i 0 --change-pin=1234 --pin=0000
>
> error: couldn't change PIN code in the SIM: 'Timeout was reached'
>
>
>
> <NOTE: The PIN actually got changed after above operation>
>
> Below are the MM logs when "-change-pin" operation was in progress:
>
> debug 2021-11-06T06:46:22+00:00 : <debug> [1636181182.916042] [modem0/sim0] changing PIN...
> debug 2021-11-06T06:46:22+00:00 : [/dev/cdc-wdm0] Sent message...
> <<<<<< RAW:
> <<<<<<   length = 88
> <<<<<<   data   = 03:00:00:00:58:00:00:00:15:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:04:00:00:00:01:00:00:00:28:00:00:00:02:00:00:00:03:00:00:00:18:00:00:00:08:00:00:00:20:00:00:00:08:00:00:00:30:00:30:00:30:00:30:00:31:00:32:00:33:00:34:00
> debug 2021-11-06T06:46:22+00:00 : [/dev/cdc-wdm0] Sent message (translated)...
> <<<<<< Header:
> <<<<<<   length      = 88
> <<<<<<   type        = command (0x00000003)
> <<<<<<   transaction = 21
> <<<<<< 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 = 'change'
> <<<<<<   Pin = '0000'
> <<<<<<   NewPin = '1234'
> debug 2021-11-06T06:46:22+00:00 : [/dev/cdc-wdm0] Received message...
> >>>>>> RAW:
> >>>>>>   length = 60
> >>>>>>   data   = 03:00:00:80:3C:00:00:00:15:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:04:00:00:00:00:00:00:00:0C:00:00:00:03:00:00:00:01:00:00:00:03:00:00:00
> debug 2021-11-06T06:46:22+00:00 : [/dev/cdc-wdm0] Received message (translated)...
> >>>>>> Header:
> >>>>>>   length      = 60
> >>>>>>   type        = command-done (0x80000003)
> >>>>>>   transaction = 21
> >>>>>> Fragment header:
> >>>>>>   total   = 1
> >>>>>>   current = 0
> >>>>>> Contents:
> >>>>>>   status error = 'None' (0x00000000)
> >>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
> >>>>>>   cid          = 'pin' (0x00000004)
> >>>>>> Fields:
> >>>>>>   PinType = 'pin2'
> >>>>>>   PinState = 'locked'
> >>>>>>   RemainingAttempts = '3'
> debug 2021-11-06T06:46:22+00:00 : [/dev/cdc-wdm0] Sent message...
> <<<<<< RAW:
> <<<<<<   length = 48
> <<<<<<   data   = 03:00:00:00:30:00:00:00:16:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:02:00:00:00:00:00:00:00:00:00:00:00
> debug 2021-11-06T06:46:22+00:00 : [/dev/cdc-wdm0] Sent message (translated)...
> <<<<<< Header:
> <<<<<<   length      = 48
> <<<<<<   type        = command (0x00000003)
> <<<<<<   transaction = 22
> <<<<<< Fragment header:
> <<<<<<   total   = 1
> <<<<<<   current = 0
> <<<<<< Contents:
> <<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
> <<<<<<   cid     = 'subscriber-ready-status' (0x00000002)
> <<<<<<   type    = 'query' (0x00000000)
> debug 2021-11-06T06:46:23+00:00 : [/dev/cdc-wdm0] Received message...
> >>>>>> RAW:
> >>>>>>   length = 48
> >>>>>>   data   = 03:00:00:80:30:00:00:00:16:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:02:00:00:00:02:00:00:00:00:00:00:00
> debug 2021-11-06T06:46:23+00:00 : [/dev/cdc-wdm0] Received message (translated)...
> >>>>>> Header:
> >>>>>>   length      = 48
> >>>>>>   type        = command-done (0x80000003)
> >>>>>>   transaction = 22
> >>>>>> Fragment header:
> >>>>>>   total   = 1
> >>>>>>   current = 0
> >>>>>> Contents:
> >>>>>>   status error = 'Failure' (0x00000002)
> >>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
> >>>>>>   cid          = 'subscriber-ready-status' (0x00000002)
> debug 2021-11-06T06:46:23+00:00 : <debug> [1636181183.048410] [modem0] couldn't check if unlock required: Failure
...
> debug 2021-11-06T06:47:20+00:00 : <debug> [1636181240.808474] [modem0] retrying (30) unlock required check
> debug 2021-11-06T06:47:22+00:00 : [/dev/cdc-wdm0] Sent message...
> <<<<<< RAW:
> <<<<<<   length = 48
> <<<<<<   data   = 03:00:00:00:30:00:00:00:34:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:02:00:00:00:00:00:00:00:00:00:00:00
> debug 2021-11-06T06:47:22+00:00 : [/dev/cdc-wdm0] Sent message (translated)...
> <<<<<< Header:
> <<<<<<   length      = 48
> <<<<<<   type        = command (0x00000003)
> <<<<<<   transaction = 52
> <<<<<< Fragment header:
> <<<<<<   total   = 1
> <<<<<<   current = 0
> <<<<<< Contents:
> <<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
> <<<<<<   cid     = 'subscriber-ready-status' (0x00000002)
> <<<<<<   type    = 'query' (0x00000000)
> debug 2021-11-06T06:47:22+00:00 : [/dev/cdc-wdm0] Received message...
> >>>>>> RAW:
> >>>>>>   length = 48
> >>>>>>   data   = 03:00:00:80:30:00:00:00:34:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:02:00:00:00:02:00:00:00:00:00:00:00
> debug 2021-11-06T06:47:22+00:00 : [/dev/cdc-wdm0] Received message (translated)...
> >>>>>> Header:
> >>>>>>   length      = 48
> >>>>>>   type        = command-done (0x80000003)
> >>>>>>   transaction = 52
> >>>>>> Fragment header:
> >>>>>>   total   = 1
> >>>>>>   current = 0
> >>>>>> Contents:
> >>>>>>   status error = 'Failure' (0x00000002)
> >>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
> >>>>>>   cid          = 'subscriber-ready-status' (0x00000002)
> debug 2021-11-06T06:47:22+00:00 : <debug> [1636181242.824564] [modem0] couldn't check if unlock required: Failure

This is definitely a firmware error I think. You changed the SIM-PIN
while locked, and after that the modem is unlocked (which is fine),
but the "Subscriber ready status" MBIM query keeps on failing over and
over (30 queries done over 60s!). We could probably skip that query as
we know we should be unlocked, but ideally this is something to fix in
the firmware. Do you have Sierra Wireless support? Can you report this
to the manufacturer?

-- 
Aleksander
https://aleksander.es


More information about the ModemManager-devel mailing list