SIM Card PIN Change Timeout (MM 1.18.2)

Amol Lad Amol.Lad at 4rf.com
Mon Nov 8 15:25:14 UTC 2021


The problem is coming in QMI also but logs are a bit different:

root at AprisaLTE:/# mmcli -i 1 --change-pin=1234 --pin=0000
error: couldn't change PIN code in the SIM: 'Timeout was reached'

Logs are below:

debug 2021-11-08T15:20:38+00:00 : <debug> [1636384838.121620] [modem0/sim1] changing PIN...
debug 2021-11-08T15:20:38+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 32
<<<<<<   data   = 01:1F:00:00:0B:02:00:0F:00:28:00:13:00:02:0B:00:01:04:30:30:30:30:04:31:32:33:34:01:02:00:06:00
debug 2021-11-08T15:20:38+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 31
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 15
<<<<<<   tlv_length  = 19
<<<<<<   message     = "Change PIN" (0x0028)
<<<<<< TLV:
<<<<<<   type       = "Info" (0x02)
<<<<<<   length     = 11
<<<<<<   value      = 01:04:30:30:30:30:04:31:32:33:34
<<<<<<   translated = [ pin_id = 'pin1' old_pin = '0000' new_pin = '1234' ]
<<<<<< TLV:
<<<<<<   type       = "Session" (0x01)
<<<<<<   length     = 2
<<<<<<   value      = 06:00
<<<<<<   translated = [ session_type = 'card-slot-1' application_identifier = '{}' ]
debug 2021-11-08T15:20:38+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 93
<<<<<<   data   = 01:5C:00:80:0B:02:02:0F:00:28:00:50:00:02:04:00:00:00:00:00:13:02:00:63:C3:11:41:00:40:35:C7:A6:4F:93:0A:F0:9C:F1:13:65:9B:8C:E1:51:51:38:71:7A:0D:11:DC:04:4F:A0:29:01:07:13:0C:01:3F:19:A8:0E:95:29:0C:15:73:6F:10:9A:72:76:F1:5E:86:5D:77:CF:AC:00:00:00:00:00:00:00:00:00:00:00:00
debug 2021-11-08T15:20:38+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 92
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 15
<<<<<<   tlv_length  = 80
<<<<<<   message     = "Change PIN" (0x0028)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type       = "Card Result" (0x13)
<<<<<<   length     = 2
<<<<<<   value      = 63:C3
<<<<<<   translated = [ sw1 = '99' sw2 = '195' ]
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 65
<<<<<<   value  = 40:35:C7:A6:4F:93:0A:F0:9C:F1:13:65:9B:8C:E1:51:51:38:71:7A:0D:11:DC:04:4F:A0:29:01:07:13:0C:01:3F:19:A8:0E:95:29:0C:15:73:6F:10:9A:72:76:F1:5E:86:5D:77:CF:AC:00:00:00:00:00:00:00:00:00:00:00:00
debug 2021-11-08T15:20:38+00:00 : <debug> [1636384838.204934] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:20:38+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:10:00:2F:00:00:00
debug 2021-11-08T15:20:38+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 16
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:20:38+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:10:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:20:38+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 16
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:20:38+00:00 : <debug> [1636384838.237310] [modem0] GW primary session index: 0
debug 2021-11-08T15:20:38+00:00 : <debug> [1636384838.237362] [modem0] GW primary application index: 0
debug 2021-11-08T15:20:38+00:00 : <debug> [1636384838.237416] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:20:38+00:00 : <debug> [1636384838.237459] [modem0] retrying (1) unlock required check
debug 2021-11-08T15:20:40+00:00 : <debug> [1636384840.669386] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:20:40+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:11:00:2F:00:00:00
debug 2021-11-08T15:20:40+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 17
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:20:40+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:11:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:20:40+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 17
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:20:40+00:00 : <debug> [1636384840.700501] [modem0] GW primary session index: 0
debug 2021-11-08T15:20:40+00:00 : <debug> [1636384840.700548] [modem0] GW primary application index: 0
debug 2021-11-08T15:20:40+00:00 : <debug> [1636384840.700600] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:20:40+00:00 : <debug> [1636384840.700641] [modem0] retrying (2) unlock required check
debug 2021-11-08T15:20:42+00:00 : <debug> [1636384842.668565] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:20:42+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:12:00:2F:00:00:00
debug 2021-11-08T15:20:42+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 18
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:20:42+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:12:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:20:42+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 18
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:20:42+00:00 : <debug> [1636384842.684469] [modem0] GW primary session index: 0
debug 2021-11-08T15:20:42+00:00 : <debug> [1636384842.684516] [modem0] GW primary application index: 0
debug 2021-11-08T15:20:42+00:00 : <debug> [1636384842.684567] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:20:42+00:00 : <debug> [1636384842.684610] [modem0] retrying (3) unlock required check
debug 2021-11-08T15:20:44+00:00 : <debug> [1636384844.668710] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:20:44+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:13:00:2F:00:00:00
debug 2021-11-08T15:20:44+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 19
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:20:44+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:13:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:20:44+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 19
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:20:44+00:00 : <debug> [1636384844.700527] [modem0] GW primary session index: 0
debug 2021-11-08T15:20:44+00:00 : <debug> [1636384844.700575] [modem0] GW primary application index: 0
debug 2021-11-08T15:20:44+00:00 : <debug> [1636384844.700628] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:20:44+00:00 : <debug> [1636384844.700670] [modem0] retrying (4) unlock required check
debug 2021-11-08T15:20:46+00:00 : <debug> [1636384846.669958] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:20:46+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:14:00:2F:00:00:00
debug 2021-11-08T15:20:46+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 20
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:20:46+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:14:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:20:46+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 20
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:20:46+00:00 : <debug> [1636384846.684529] [modem0] GW primary session index: 0
debug 2021-11-08T15:20:46+00:00 : <debug> [1636384846.684577] [modem0] GW primary application index: 0
debug 2021-11-08T15:20:46+00:00 : <debug> [1636384846.684629] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:20:46+00:00 : <debug> [1636384846.684671] [modem0] retrying (5) unlock required check
debug 2021-11-08T15:20:48+00:00 : <debug> [1636384848.669233] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:20:48+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:15:00:2F:00:00:00
debug 2021-11-08T15:20:48+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 21
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:20:48+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:15:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:20:48+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 21
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:20:48+00:00 : <debug> [1636384848.700475] [modem0] GW primary session index: 0
debug 2021-11-08T15:20:48+00:00 : <debug> [1636384848.700521] [modem0] GW primary application index: 0
debug 2021-11-08T15:20:48+00:00 : <debug> [1636384848.700574] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:20:48+00:00 : <debug> [1636384848.700616] [modem0] retrying (6) unlock required check
debug 2021-11-08T15:20:50+00:00 : <debug> [1636384850.669671] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:20:50+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:16:00:2F:00:00:00
debug 2021-11-08T15:20:50+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 22
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:20:50+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:16:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:20:50+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 22
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:20:50+00:00 : <debug> [1636384850.684475] [modem0] GW primary session index: 0
debug 2021-11-08T15:20:50+00:00 : <debug> [1636384850.684522] [modem0] GW primary application index: 0
debug 2021-11-08T15:20:50+00:00 : <debug> [1636384850.684576] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:20:50+00:00 : <debug> [1636384850.684620] [modem0] retrying (7) unlock required check
debug 2021-11-08T15:20:52+00:00 : <debug> [1636384852.669099] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:20:52+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:17:00:2F:00:00:00
debug 2021-11-08T15:20:52+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 23
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:20:52+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:17:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:20:52+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 23
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:20:52+00:00 : <debug> [1636384852.700541] [modem0] GW primary session index: 0
debug 2021-11-08T15:20:52+00:00 : <debug> [1636384852.700589] [modem0] GW primary application index: 0
debug 2021-11-08T15:20:52+00:00 : <debug> [1636384852.700641] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:20:52+00:00 : <debug> [1636384852.700685] [modem0] retrying (8) unlock required check
debug 2021-11-08T15:20:54+00:00 : <debug> [1636384854.668910] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:20:54+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:18:00:2F:00:00:00
debug 2021-11-08T15:20:54+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 24
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:20:54+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:18:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:20:54+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 24
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:20:54+00:00 : <debug> [1636384854.684478] [modem0] GW primary session index: 0
debug 2021-11-08T15:20:54+00:00 : <debug> [1636384854.684524] [modem0] GW primary application index: 0
debug 2021-11-08T15:20:54+00:00 : <debug> [1636384854.684577] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:20:54+00:00 : <debug> [1636384854.684620] [modem0] retrying (9) unlock required check
debug 2021-11-08T15:20:56+00:00 : <debug> [1636384856.668571] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:20:56+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:19:00:2F:00:00:00
debug 2021-11-08T15:20:56+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 25
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:20:56+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:19:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:20:56+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 25
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:20:56+00:00 : <debug> [1636384856.700750] [modem0] GW primary session index: 0
debug 2021-11-08T15:20:56+00:00 : <debug> [1636384856.700802] [modem0] GW primary application index: 0
debug 2021-11-08T15:20:56+00:00 : <debug> [1636384856.700862] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:20:56+00:00 : <debug> [1636384856.700907] [modem0] retrying (10) unlock required check
debug 2021-11-08T15:20:58+00:00 : <debug> [1636384858.669322] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:20:58+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:1A:00:2F:00:00:00
debug 2021-11-08T15:20:58+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 26
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:20:58+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:1A:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:20:58+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 26
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:20:58+00:00 : <debug> [1636384858.686226] [modem0] GW primary session index: 0
debug 2021-11-08T15:20:58+00:00 : <debug> [1636384858.686282] [modem0] GW primary application index: 0
debug 2021-11-08T15:20:58+00:00 : <debug> [1636384858.686355] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:20:58+00:00 : <debug> [1636384858.686427] [modem0] retrying (11) unlock required check
debug 2021-11-08T15:21:00+00:00 : <debug> [1636384860.669727] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:00+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:1B:00:2F:00:00:00
debug 2021-11-08T15:21:00+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 27
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:00+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:1B:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:00+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 27
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:00+00:00 : <debug> [1636384860.700531] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:00+00:00 : <debug> [1636384860.700578] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:00+00:00 : <debug> [1636384860.700632] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:00+00:00 : <debug> [1636384860.700673] [modem0] retrying (12) unlock required check
debug 2021-11-08T15:21:02+00:00 : <debug> [1636384862.668655] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:02+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:1C:00:2F:00:00:00
debug 2021-11-08T15:21:02+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 28
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:02+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:1C:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:02+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 28
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:02+00:00 : <debug> [1636384862.685469] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:02+00:00 : <debug> [1636384862.685515] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:02+00:00 : <debug> [1636384862.685569] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:02+00:00 : <debug> [1636384862.685611] [modem0] retrying (13) unlock required check
debug 2021-11-08T15:21:04+00:00 : <debug> [1636384864.668878] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:04+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:1D:00:2F:00:00:00
debug 2021-11-08T15:21:04+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 29
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:04+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:1D:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:04+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 29
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:04+00:00 : <debug> [1636384864.700525] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:04+00:00 : <debug> [1636384864.700573] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:04+00:00 : <debug> [1636384864.700627] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:04+00:00 : <debug> [1636384864.700669] [modem0] retrying (14) unlock required check
debug 2021-11-08T15:21:06+00:00 : <debug> [1636384866.669282] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:06+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:1E:00:2F:00:00:00
debug 2021-11-08T15:21:06+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 30
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:06+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:1E:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:06+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 30
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:06+00:00 : <debug> [1636384866.685395] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:06+00:00 : <debug> [1636384866.685443] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:06+00:00 : <debug> [1636384866.685495] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:06+00:00 : <debug> [1636384866.685535] [modem0] retrying (15) unlock required check
debug 2021-11-08T15:21:08+00:00 : <debug> [1636384868.668775] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:08+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:1F:00:2F:00:00:00
debug 2021-11-08T15:21:08+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 31
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:08+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:1F:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:08+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 31
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:08+00:00 : <debug> [1636384868.700627] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:08+00:00 : <debug> [1636384868.700678] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:08+00:00 : <debug> [1636384868.700733] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:08+00:00 : <debug> [1636384868.700774] [modem0] retrying (16) unlock required check
debug 2021-11-08T15:21:10+00:00 : <debug> [1636384870.669375] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:10+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:20:00:2F:00:00:00
debug 2021-11-08T15:21:10+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 32
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:10+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:20:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:10+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 32
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:10+00:00 : <debug> [1636384870.684935] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:10+00:00 : <debug> [1636384870.684983] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:10+00:00 : <debug> [1636384870.685037] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:10+00:00 : <debug> [1636384870.685080] [modem0] retrying (17) unlock required check
debug 2021-11-08T15:21:12+00:00 : <debug> [1636384872.669641] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:12+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:21:00:2F:00:00:00
debug 2021-11-08T15:21:12+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 33
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:12+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:21:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:12+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 33
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:12+00:00 : <debug> [1636384872.700814] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:12+00:00 : <debug> [1636384872.700868] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:12+00:00 : <debug> [1636384872.700938] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:12+00:00 : <debug> [1636384872.701004] [modem0] retrying (18) unlock required check
debug 2021-11-08T15:21:14+00:00 : <debug> [1636384874.669492] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:14+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:22:00:2F:00:00:00
debug 2021-11-08T15:21:14+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 34
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:14+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:22:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:14+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 34
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:14+00:00 : <debug> [1636384874.684606] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:14+00:00 : <debug> [1636384874.684652] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:14+00:00 : <debug> [1636384874.684703] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:14+00:00 : <debug> [1636384874.684744] [modem0] retrying (19) unlock required check
debug 2021-11-08T15:21:16+00:00 : <debug> [1636384876.669303] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:16+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:23:00:2F:00:00:00
debug 2021-11-08T15:21:16+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 35
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:16+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:23:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:16+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 35
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:16+00:00 : <debug> [1636384876.700534] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:16+00:00 : <debug> [1636384876.700581] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:16+00:00 : <debug> [1636384876.700635] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:16+00:00 : <debug> [1636384876.700677] [modem0] retrying (20) unlock required check
err 2021-11-08T15:21:17+00:00 ddns-scripts: wertrw_67: BIND host error: 1
warning 2021-11-08T15:21:17+00:00 ddns-scripts: wertrw_67: Get registered/public IP for xzy.aaa.com failed - retry 10/0 in 60 seconds
debug 2021-11-08T15:21:18+00:00 : <debug> [1636384878.668539] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:18+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:24:00:2F:00:00:00
debug 2021-11-08T15:21:18+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 36
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:18+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:24:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:18+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 36
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:18+00:00 : <debug> [1636384878.683990] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:18+00:00 : <debug> [1636384878.684040] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:18+00:00 : <debug> [1636384878.684093] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:18+00:00 : <debug> [1636384878.684135] [modem0] retrying (21) unlock required check
debug 2021-11-08T15:21:20+00:00 : <debug> [1636384880.668618] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:20+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:25:00:2F:00:00:00
debug 2021-11-08T15:21:20+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 37
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:20+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:25:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:20+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 37
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:20+00:00 : <debug> [1636384880.700572] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:20+00:00 : <debug> [1636384880.700621] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:20+00:00 : <debug> [1636384880.700675] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:20+00:00 : <debug> [1636384880.700716] [modem0] retrying (22) unlock required check
debug 2021-11-08T15:21:22+00:00 : <debug> [1636384882.669480] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:22+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:26:00:2F:00:00:00
debug 2021-11-08T15:21:22+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 38
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:22+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:26:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:22+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 38
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:22+00:00 : <debug> [1636384882.684246] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:22+00:00 : <debug> [1636384882.684295] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:22+00:00 : <debug> [1636384882.684349] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:22+00:00 : <debug> [1636384882.684392] [modem0] retrying (23) unlock required check
debug 2021-11-08T15:21:23+00:00 : <debug> [1636384883.752059] [modem0/ttyUSB2/at] device open count is 2 (open)
debug 2021-11-08T15:21:23+00:00 : <debug> [1636384883.752233] [modem0/ttyUSB2/at] --> 'AT#RFSTS<CR>'
debug 2021-11-08T15:21:23+00:00 : <debug> [1636384883.783339] [modem0/ttyUSB2/at] <-- '<CR><LF>#RFSTS: "404 45",39275,-100,-66,-15,2039,255,,1280,19,0,00E6217,"000000000000000","IND airtel",3,40<CR><LF><CR><LF>OK<CR><LF>'
debug 2021-11-08T15:21:23+00:00 : <debug> [1636384883.783649] [modem0/ttyUSB2/at] device open count is 1 (close)
debug 2021-11-08T15:21:24+00:00 : <debug> [1636384884.037509] [modem0/ttyUSB2/at] device open count is 2 (open)
debug 2021-11-08T15:21:24+00:00 : <debug> [1636384884.037655] [modem0/ttyUSB2/at] --> 'AT#TEMPSENS=2<CR>'
debug 2021-11-08T15:21:24+00:00 : <debug> [1636384884.068988] [modem0/ttyUSB2/at] <-- '<CR><LF>#TEMPSENS: TSENS,37<CR><LF>#TEMPSENS: PA_THERM,35<CR><LF><CR><LF>OK<CR><LF>'
debug 2021-11-08T15:21:24+00:00 : <debug> [1636384884.069359] [modem0/ttyUSB2/at] device open count is 1 (close)
debug 2021-11-08T15:21:24+00:00 : <debug> [1636384884.669091] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:24+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:27:00:2F:00:00:00
debug 2021-11-08T15:21:24+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 39
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:24+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:27:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:24+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 39
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:24+00:00 : <debug> [1636384884.700503] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:24+00:00 : <debug> [1636384884.700550] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:24+00:00 : <debug> [1636384884.700604] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:24+00:00 : <debug> [1636384884.700647] [modem0] retrying (24) unlock required check
debug 2021-11-08T15:21:26+00:00 : <debug> [1636384886.668983] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:26+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:28:00:2F:00:00:00
debug 2021-11-08T15:21:26+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 40
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:26+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:28:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:26+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 40
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:26+00:00 : <debug> [1636384886.683723] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:26+00:00 : <debug> [1636384886.683769] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:26+00:00 : <debug> [1636384886.683823] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:26+00:00 : <debug> [1636384886.683866] [modem0] retrying (25) unlock required check
debug 2021-11-08T15:21:28+00:00 : <debug> [1636384888.668661] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:28+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:29:00:2F:00:00:00
debug 2021-11-08T15:21:28+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 41
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:28+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:29:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:28+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 41
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:28+00:00 : <debug> [1636384888.700554] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:28+00:00 : <debug> [1636384888.700603] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:28+00:00 : <debug> [1636384888.700656] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:28+00:00 : <debug> [1636384888.700699] [modem0] retrying (26) unlock required check
debug 2021-11-08T15:21:30+00:00 : <debug> [1636384890.668445] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:30+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:2A:00:2F:00:00:00
debug 2021-11-08T15:21:30+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 42
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:30+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:2A:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:30+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 42
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:30+00:00 : <debug> [1636384890.683736] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:30+00:00 : <debug> [1636384890.683783] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:30+00:00 : <debug> [1636384890.683836] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:30+00:00 : <debug> [1636384890.683878] [modem0] retrying (27) unlock required check
debug 2021-11-08T15:21:32+00:00 : <debug> [1636384892.670089] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:32+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:2B:00:2F:00:00:00
debug 2021-11-08T15:21:32+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 43
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:32+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:2B:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:32+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 43
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:32+00:00 : <debug> [1636384892.700858] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:32+00:00 : <debug> [1636384892.700922] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:32+00:00 : <debug> [1636384892.701021] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:32+00:00 : <debug> [1636384892.701078] [modem0] retrying (28) unlock required check
debug 2021-11-08T15:21:34+00:00 : <debug> [1636384894.668974] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:34+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:2C:00:2F:00:00:00
debug 2021-11-08T15:21:34+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 44
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:34+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:2C:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:34+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 44
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:34+00:00 : <debug> [1636384894.683932] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:34+00:00 : <debug> [1636384894.683979] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:34+00:00 : <debug> [1636384894.684032] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:34+00:00 : <debug> [1636384894.684074] [modem0] retrying (29) unlock required check
debug 2021-11-08T15:21:36+00:00 : <debug> [1636384896.669500] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:36+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:2D:00:2F:00:00:00
debug 2021-11-08T15:21:36+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 45
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:36+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:2D:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:36+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 45
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:36+00:00 : <debug> [1636384896.700482] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:36+00:00 : <debug> [1636384896.700528] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:36+00:00 : <debug> [1636384896.700580] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress
debug 2021-11-08T15:21:36+00:00 : <debug> [1636384896.700622] [modem0] retrying (30) unlock required check
debug 2021-11-08T15:21:38+00:00 : <debug> [1636384898.669183] [modem0] loading unlock required (UIM)...
debug 2021-11-08T15:21:38+00:00 : [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:0B:02:00:2E:00:2F:00:00:00
debug 2021-11-08T15:21:38+00:00 : [/dev/cdc-wdm0] Sent generic request (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 46
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Card Status" (0x002F)
debug 2021-11-08T15:21:38+00:00 : [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<<   length = 86
<<<<<<   data   = 01:55:00:80:0B:02:02:2E:00:2F:00:49:00:02:04:00:00:00:00:00:16:05:00:01:00:00:00:00:15:02:00:01:00:11:02:00:01:00:10:2D:00:00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
debug 2021-11-08T15:21:38+00:00 : [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<<   length  = 85
<<<<<<   flags   = 0x80
<<<<<<   service = "uim"
<<<<<<   client  = 2
<<<<<< QMI:
<<<<<<   flags       = "response"
<<<<<<   transaction = 46
<<<<<<   tlv_length  = 73
<<<<<<   message     = "Get Card Status" (0x002F)
<<<<<< TLV:
<<<<<<   type       = "Result" (0x02)
<<<<<<   length     = 4
<<<<<<   value      = 00:00:00:00
<<<<<<   translated = SUCCESS
<<<<<< TLV:
<<<<<<   type   = 0x16
<<<<<<   length = 5
<<<<<<   value  = 01:00:00:00:00
<<<<<< TLV:
<<<<<<   type   = 0x15
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type   = 0x11
<<<<<<   length = 2
<<<<<<   value  = 01:00
<<<<<< TLV:
<<<<<<   type       = "Card Status" (0x10)
<<<<<<   length     = 45
<<<<<<   value      = 00:00:FF:FF:FF:FF:FF:FF:01:01:00:00:00:00:01:02:04:00:0B:00:00:10:A0:00:00:00:87:10:02:FF:45:FF:01:89:06:03:00:00:00:02:03:0A:01:03:0A
<<<<<<   translated = [ index_gw_primary = '0' index_1x_primary
debug 2021-11-08T15:21:38+00:00 : <debug> [1636384898.684909] [modem0] GW primary session index: 0
debug 2021-11-08T15:21:38+00:00 : <debug> [1636384898.684956] [modem0] GW primary application index: 0
debug 2021-11-08T15:21:38+00:00 : <debug> [1636384898.685009] [modem0] couldn't check if unlock required: QMI operation failed: Personalization check in progress


-----Original Message-----
From: Aleksander Morgado <aleksander at aleksander.es> 
Sent: Monday, 8 November 2021 8:24 PM
To: Amol Lad <Amol.Lad at 4rf.com>
Cc: ModemManager (development) <modemmanager-devel at lists.freedesktop.org>
Subject: Re: SIM Card PIN Change Timeout (MM 1.18.2)

Hey,

>
> I've tried to fix it. Below is for review and if OK then I'll submit MR.
>
> I think, we cannot make assumption that modem will be unlocked after sim pin change. Hence, we should not wait for unlock?
>

The mm_iface_modem_update_lock_info() is not "waiting for unlock", that method is reloading the current lock information status, and I think that is definitely what we should be doing. The problem now is what happens with this issue we're seeing; the modem returning Failure unconditionally if we attempt to reload the lock status. I'm not sure how to best workaround it, truth be told. Just wondering, have you tried this very same sequence with the EM7455 running in QMI mode instead of MBIM mode? Does the issue also happen there?


> diff --git a/src/mm-base-sim.c b/src/mm-base-sim.c index 
> 59af3a88..8a181970 100644
> --- a/src/mm-base-sim.c
> +++ b/src/mm-base-sim.c
> @@ -201,20 +201,17 @@ handle_change_pin_ready (MMBaseSim *self,
>                           GAsyncResult *res,
>                           HandleChangePinContext *ctx)  {
> -    MMModemLock known_lock = MM_MODEM_LOCK_UNKNOWN;
> +    MM_BASE_SIM_GET_CLASS (self)->change_pin_finish (self, res, 
> + &ctx->save_error);
>
> -    if (!MM_BASE_SIM_GET_CLASS (self)->change_pin_finish (self, res, &ctx->save_error)) {
> -        if (g_error_matches (ctx->save_error,
> -                             MM_MOBILE_EQUIPMENT_ERROR,
> -                             MM_MOBILE_EQUIPMENT_ERROR_SIM_PUK))
> -            known_lock = MM_MODEM_LOCK_SIM_PUK;
> +    if (ctx->save_error) {
> +        g_dbus_method_invocation_return_gerror (ctx->invocation, ctx->save_error);
> +        reprobe_if_puk_discovered (ctx->self, ctx->save_error);
> +        g_clear_error (&ctx->save_error);
> +    } else {
> +        mm_gdbus_sim_complete_change_pin (MM_GDBUS_SIM (ctx->self), ctx->invocation);
>      }
>
> -    mm_iface_modem_update_lock_info (
> -        MM_IFACE_MODEM (self->priv->modem),
> -        known_lock,
> -        (GAsyncReadyCallback)after_change_update_lock_info_ready,
> -        ctx);
> +    handle_change_pin_context_free (ctx);
>  }
>
> Thanks
> Amol
>
> -----Original Message-----
> From: Aleksander Morgado <aleksander at aleksander.es>
> Sent: Monday, 8 November 2021 5:25 PM
> To: Amol Lad <Amol.Lad at 4rf.com>
> Cc: ModemManager (development) <modemmanager-devel at lists.freedesktop.org>
> Subject: Re: SIM Card PIN Change Timeout (MM 1.18.2)
>
> Hey,
>
> On Mon, Nov 8, 2021 at 11:36 AM Amol Lad <Amol.Lad at 4rf.com> wrote:
> >
> > # mmcli -i 1 --change-pin=0000 --pin=1234
> > error: couldn't change PIN code in the SIM: 'Timeout was reached'
> >
> > # mmcli -m 0 --command=AT+CPIN?
> > response: '+CPIN: SIM PIN'
> >
> > So looks like modem is 'really' locked. Btw, which part of debug log showed modem went in searching?
> >
>
> Oh, interesting. Then I wouldn't know what to say :)
>
> Here's the debug log that lead me to think the modem was unlocked already:
>
> debug 2021-11-06T06:46:28+00:00 : [/dev/cdc-wdm0] Received message...
> <<<<<< RAW:
> <<<<<<   length = 50
> <<<<<<   data   =
> 01:31:00:80:03:04:04:02:00:24:00:25:00:01:06:00:02:02:02:02:01:08:11:01:00:00:12:05:00:94:01:2D:00:00:22:05:00:01:02:00:00:00:29:05:00:94:01:2D:00:00
> debug 2021-11-06T06:46:28+00:00 : [/dev/cdc-wdm0] Received generic indication (translated)...
> <<<<<< QMUX:
> <<<<<<   length  = 49
> <<<<<<   flags   = 0x80
> <<<<<<   service = "nas"
> <<<<<<   client  = 4
> <<<<<< QMI:
> <<<<<<   flags       = "indication"
> <<<<<<   transaction = 2
> <<<<<<   tlv_length  = 37
> <<<<<<   message     = "Serving System" (0x0024)
> <<<<<< TLV:
> <<<<<<   type       = "Serving System" (0x01)
> <<<<<<   length     = 6
> <<<<<<   value      = 02:02:02:02:01:08
> <<<<<<   translated = [ registration_state =
> 'not-registered-searching' cs_attach_state = 'detached'
> ps_attach_state = 'detached' selected_network = '3gpp'
> radio_interfaces = '{ [0] = 'lte '}' ]
> <<<<<< TLV:
> <<<<<<   type       = "Data Service Capability" (0x11)
> <<<<<<   length     = 1
> <<<<<<   value      = 00
> <<<<<<   translated = {}
> <<<<<< TLV:
> <<<<<<   type       = "Current PLMN" (0x12)
> <<<<<<   length     = 5
> <<<<<<   value      = 94:01:2D:00:00
> <<<<<<   translated = [ mcc = '404' mnc = '45' description = '' ]
>
> --
> Aleksander
> https://aleksander.es
> ________________________________
> The information in this email communication (inclusive of attachments) is confidential to 4RF Limited and the intended recipient(s). If you are not the intended recipient(s), please note that any use, disclosure, distribution or copying of this information or any part thereof is strictly prohibited and that the author accepts no liability for the consequences of any action taken on the basis of the information provided. If you have received this email in error, please notify the sender immediately by return email and then delete all instances of this email from your system. 4RF Limited will not accept responsibility for any consequences associated with the use of this email (including, but not limited to, damages sustained as a result of any viruses and/or any action or lack of action taken in reliance on it).



-- 
Aleksander
https://aleksander.es


More information about the ModemManager-devel mailing list