QMI modems with MM-master branch error
Penalva, Salvador
Salvador.Penalva at digi.com
Mon May 8 09:46:54 UTC 2017
Hi,
I send debug logs in both cases. Sometimes (rarely), this problem is not launched and connects at the first attempt, but with the other commit didn't appear at all. But always that the error is launched, another simple-connection is enough to connect.
This is the debug log with Telit LE910 and commit 8c04cc036782dab0e80c1f2314baa3376eecad02 (the commit where it's working)
-----
<info> [1494233350.342090] [../../git/src/mm-iface-modem-simple.c:650] connect_auth_ready(): Simple connect started...
<debug> [1494233350.342220] [../../git/src/mm-iface-modem-simple.c:660] connect_auth_ready(): PIN: 8770
<debug> [1494233350.342281] [../../git/src/mm-iface-modem-simple.c:662] connect_auth_ready(): Operator ID: unspecified
<debug> [1494233350.342343] [../../git/src/mm-iface-modem-simple.c:664] connect_auth_ready(): Allowed roaming: yes
<debug> [1494233350.342405] [../../git/src/mm-iface-modem-simple.c:666] connect_auth_ready(): APN: ac.vodafone.es
<debug> [1494233350.342466] [../../git/src/mm-iface-modem-simple.c:674] connect_auth_ready(): IP family: unspecified
<debug> [1494233350.342524] [../../git/src/mm-iface-modem-simple.c:682] connect_auth_ready(): Allowed authentication: unspecified
<debug> [1494233350.342584] [../../git/src/mm-iface-modem-simple.c:684] connect_auth_ready(): User: unspecified
<debug> [1494233350.342640] [../../git/src/mm-iface-modem-simple.c:686] connect_auth_ready(): Password: unspecified
<debug> [1494233350.342695] [../../git/src/mm-iface-modem-simple.c:688] connect_auth_ready(): Number: unspecified
<info> [1494233350.342738] [../../git/src/mm-iface-modem-simple.c:452] connection_step(): Simple connect state (1/8): Unlock check
<debug> [1494233350.342881] [../../git/src/mm-broadband-modem-qmi.c:1845] load_unlock_required_context_step(): loading unlock required (DMS)...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:0F:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 15
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:0F:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:01:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 15
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<debug> [1494233350.376160] [../../git/src/mm-broadband-modem-qmi.c:2072] modem_load_unlock_retries(): loading unlock retries...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:10:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 16
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:10:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:01:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 16
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<debug> [1494233350.410257] [../../git/src/mm-sim-qmi.c:548] send_pin(): Verifying PIN...
<debug> [1494233350.410524] [../../git/src/mm-sim-qmi.c:518] dms_uim_verify_pin(): Sending PIN...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 22
<<<<<< data = 01:15:00:00:02:01:00:11:00:28:00:09:00:01:06:00:01:04:38:37:37:30
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 21
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 17
<<<<<< tlv_length = 9
<<<<<< message = "UIM Verify PIN" (0x0028)
<<<<<< TLV:
<<<<<< type = "Info" (0x01)
<<<<<< length = 6
<<<<<< value = 01:04:38:37:37:30
<<<<<< translated = [ pin_id = 'pin' pin = '8770' ]
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:02:01:02:11:00:28:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 17
<<<<<< tlv_length = 7
<<<<<< message = "UIM Verify PIN" (0x0028)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<debug> [1494233350.507831] [../../git/src/mm-broadband-modem-qmi.c:1845] load_unlock_required_context_step(): loading unlock required (DMS)...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:12:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 18
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
<debug> [1494233350.748495] [../../git/src/mm-port-serial-qcdm.c:221] debug_log(): (ttymxc1): --> 7e 00 78 f0 7e
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:12:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:02:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 18
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 02:03:0A
<<<<<< translated = [ current_status = 'enabled-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<debug> [1494233351.308437] [../../git/src/mm-iface-modem.c:3101] update_lock_info_context_step(): SIM is ready, and no need for the after SIM unlock step...
<debug> [1494233351.308728] [../../git/src/mm-broadband-modem-qmi.c:2072] modem_load_unlock_retries(): loading unlock retries...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:13:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 19
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:13:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:02:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 19
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 02:03:0A
<<<<<< translated = [ current_status = 'enabled-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<info> [1494233351.540053] [../../git/src/mm-iface-modem-simple.c:461] connection_step(): Simple connect state (2/8): Wait to get fully initialized
<info> [1494233351.540853] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (locked -> initializing)
<debug> [1494233351.563284] [../../git/src/mm-port-serial.c:1096] mm_port_serial_open(): (ttyUSB2) opening serial port...
<debug> [1494233351.564776] [../../git/src/mm-port-serial.c:370] real_config_fd(): (ttyUSB2): setting up baudrate: 57600
<warn> [1494233351.565059] [../../git/src/mm-port-serial.c:447] real_config_fd(): (ttyUSB2): port attributes not fully set
<debug> [1494233351.565484] [../../git/src/mm-port-serial.c:1226] mm_port_serial_open(): (ttyUSB2) device open count is 1 (open)
<debug> [1494233351.565641] [../../git/src/mm-port-serial-at.c:495] mm_port_serial_at_run_init_sequence(): (ttyUSB2): running init sequence...
<debug> [1494233351.566227] [../../git/src/mm-port-serial.c:1226] mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
<debug> [1494233351.567680] [../../git/src/mm-port-serial.c:1226] mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
<debug> [1494233351.570396] [../../git/src/mm-broadband-modem-qmi.c:1845] load_unlock_required_context_step(): loading unlock required (DMS)...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:14:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 20
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
<debug> [1494233351.573012] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATE0<CR>'
<debug> [1494233351.581947] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233351.582951] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATV1<CR>'
<debug> [1494233351.591059] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233351.592050] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CMEE=1<CR>'
<debug> [1494233351.607939] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233351.608579] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATX4<CR>'
<debug> [1494233351.733104] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233351.734172] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT&C1<CR>'
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 34
<<<<<< data = 01:21:00:80:03:03:04:00:00:24:00:15:00:22:05:00:04:03:04:01:00:11:01:00:00:01:06:00:00:02:02:00:01:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 33
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 21
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x22)
<<<<<< length = 5
<<<<<< value = 04:03:04:01:00
<<<<<< translated = [ status = 'power-save' capability = 'cs-ps' hdr_status = 'power-save' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 00:02:02:00:01:00
<<<<<< translated = [ registration_state = 'not-registered' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = 'unknown' radio_interfaces = '{ [0] = 'none '}' ]
<debug> [1494233351.847428] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233351.848491] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATE0<CR>'
<debug> [1494233351.860889] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233351.866103] [../../git/src/mm-port-serial.c:1283] _close_internal(): (ttyUSB2) device open count is 2 (close)
<debug> [1494233351.873583] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CMEE=1<CR>'
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:14:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:02:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 20
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 02:03:0A
<<<<<< translated = [ current_status = 'enabled-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<debug> [1494233351.889856] [../../git/src/mm-iface-modem.c:3101] update_lock_info_context_step(): SIM is ready, and no need for the after SIM unlock step...
<debug> [1494233351.890325] [../../git/src/mm-broadband-modem-qmi.c:2072] modem_load_unlock_retries(): loading unlock retries...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:15:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 21
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
<debug> [1494233351.903349] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233351.904141] [../../git/src/mm-port-serial.c:1283] _close_internal(): (ttyUSB2) device open count is 1 (close)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:15:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:02:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 21
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 02:03:0A
<<<<<< translated = [ current_status = 'enabled-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<debug> [1494233351.976625] [../../git/src/mm-sim-qmi.c:206] load_imsi(): loading IMSI...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:16:00:43:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 22
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get IMSI" (0x0043)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 38
<<<<<< data = 01:25:00:80:02:01:02:16:00:43:00:19:00:02:04:00:00:00:00:00:01:0F:00:32:31:34:30:31:39:38:32:32:39:38:38:34:33:33
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 37
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 22
<<<<<< tlv_length = 25
<<<<<< message = "UIM Get IMSI" (0x0043)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "IMSI" (0x01)
<<<<<< length = 15
<<<<<< value = 32:31:34:30:31:39:38:32:32:39:38:38:34:33:33
<<<<<< translated = 214019822988433
<debug> [1494233352.008716] [../../git/src/mm-sim-qmi.c:325] load_operator_identifier(): loading SIM operator identifier...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:06:00:25:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 6
<<<<<< tlv_length = 0
<<<<<< message = "Get Home Network" (0x0025)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:03:03:02:06:00:25:00:07:00:02:04:00:01:00:10:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 6
<<<<<< tlv_length = 7
<<<<<< message = "Get Home Network" (0x0025)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:10:00
<<<<<< translated = FAILURE: NotProvisioned
<warn> [1494233352.044119] [../../git/src/mm-base-sim.c:1424] load_operator_identifier_ready(): couldn't load Operator identifier: 'Couldn't get home network: QMI protocol error (16): 'NotProvisioned''
<debug> [1494233352.044362] [../../git/src/mm-sim-qmi.c:374] load_operator_name(): loading SIM operator name...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:07:00:25:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 7
<<<<<< tlv_length = 0
<<<<<< message = "Get Home Network" (0x0025)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:03:03:02:07:00:25:00:07:00:02:04:00:01:00:10:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 7
<<<<<< tlv_length = 7
<<<<<< message = "Get Home Network" (0x0025)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:10:00
<<<<<< translated = FAILURE: NotProvisioned
<warn> [1494233352.072157] [../../git/src/mm-base-sim.c:1425] load_operator_name_ready(): couldn't load Operator name: 'Couldn't get home network: QMI protocol error (16): 'NotProvisioned''
<debug> [1494233352.072581] [../../git/src/mm-broadband-modem-qmi.c:1411] modem_load_own_numbers(): loading own numbers...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:17:00:24:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 23
<<<<<< tlv_length = 0
<<<<<< message = "Get MSISDN" (0x0024)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:02:01:02:17:00:24:00:07:00:02:04:00:01:00:10:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 23
<<<<<< tlv_length = 7
<<<<<< message = "Get MSISDN" (0x0024)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:10:00
<<<<<< translated = FAILURE: NotProvisioned
<warn> [1494233352.138414] [../../git/src/mm-iface-modem.c:4156] load_own_numbers_ready(): couldn't load list of Own Numbers: 'Couldn't get MSISDN: QMI protocol error (16): 'NotProvisioned''
<debug> [1494233352.143286] [../../git/src/mm-broadband-modem-qmi.c:3931] modem_3gpp_load_imei_finish(): loaded IMEI: 359852050097642
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:02:01:00:18:00:40:00:04:00:01:01:00:04
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 24
<<<<<< tlv_length = 4
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Facility" (0x01)
<<<<<< length = 1
<<<<<< value = 04
<<<<<< translated = pf
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 60
<<<<<< data = 01:3B:00:80:03:03:04:00:00:24:00:2F:00:29:05:00:D6:00:01:00:00:22:05:00:01:02:04:01:00:15:03:00:01:08:01:12:05:00:D6:00:01:00:00:11:01:00:00:10:01:00:01:01:06:00:02:02:02:02:01:08
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 59
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 47
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "MNC PCS Digit Include Status" (0x29)
<<<<<< length = 5
<<<<<< value = D6:00:01:00:00
<<<<<< translated = [ mcc = '214' mnc = '1' includes_pcs_digit = 'no' ]
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x22)
<<<<<< length = 5
<<<<<< value = 01:02:04:01:00
<<<<<< translated = [ status = 'limited' capability = 'ps' hdr_status = 'power-save' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "Roaming Indicator List" (0x15)
<<<<<< length = 3
<<<<<< value = 01:08:01
<<<<<< translated = { [0] = '[ radio_interface = 'lte' roaming_indicator = 'off' ] '}
<<<<<< TLV:
<<<<<< type = "Current PLMN" (0x12)
<<<<<< length = 5
<<<<<< value = D6:00:01:00:00
<<<<<< translated = [ mcc = '214' mnc = '1' description = '' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Roaming Indicator" (0x10)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = off
<<<<<< 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 '}' ]
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 26
<<<<<< data = 01:19:00:80:02:01:02:18:00:40:00:0D:00:02:04:00:00:00:00:00:01:03:00:00:0A:20
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 25
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 24
<<<<<< tlv_length = 13
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "CK Status" (0x01)
<<<<<< length = 3
<<<<<< value = 00:0A:20
<<<<<< translated = [ facility_state = 'deactivated' verify_retries_left = '10' unblock_retries_left = '32' ]
<debug> [1494233352.232216] [../../git/src/mm-broadband-modem-qmi.c:4088] dms_uim_get_ck_status_ready(): Facility 'ph-sim' is: 'deactivated'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:02:01:00:19:00:40:00:04:00:01:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 25
<<<<<< tlv_length = 4
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Facility" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = pn
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 26
<<<<<< data = 01:19:00:80:02:01:02:19:00:40:00:0D:00:02:04:00:00:00:00:00:01:03:00:00:0A:20
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 25
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 25
<<<<<< tlv_length = 13
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "CK Status" (0x01)
<<<<<< length = 3
<<<<<< value = 00:0A:20
<<<<<< translated = [ facility_state = 'deactivated' verify_retries_left = '10' unblock_retries_left = '32' ]
<debug> [1494233352.265246] [../../git/src/mm-broadband-modem-qmi.c:4088] dms_uim_get_ck_status_ready(): Facility 'net-pers' is: 'deactivated'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:02:01:00:1A:00:40:00:04:00:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 26
<<<<<< tlv_length = 4
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Facility" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = pu
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 26
<<<<<< data = 01:19:00:80:02:01:02:1A:00:40:00:0D:00:02:04:00:00:00:00:00:01:03:00:00:0A:20
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 25
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 26
<<<<<< tlv_length = 13
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "CK Status" (0x01)
<<<<<< length = 3
<<<<<< value = 00:0A:20
<<<<<< translated = [ facility_state = 'deactivated' verify_retries_left = '10' unblock_retries_left = '32' ]
<debug> [1494233352.297574] [../../git/src/mm-broadband-modem-qmi.c:4088] dms_uim_get_ck_status_ready(): Facility 'net-sub-pers' is: 'deactivated'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:02:01:00:1B:00:40:00:04:00:01:01:00:02
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 27
<<<<<< tlv_length = 4
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Facility" (0x01)
<<<<<< length = 1
<<<<<< value = 02
<<<<<< translated = pp
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 26
<<<<<< data = 01:19:00:80:02:01:02:1B:00:40:00:0D:00:02:04:00:00:00:00:00:01:03:00:00:0A:20
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 25
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 27
<<<<<< tlv_length = 13
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "CK Status" (0x01)
<<<<<< length = 3
<<<<<< value = 00:0A:20
<<<<<< translated = [ facility_state = 'deactivated' verify_retries_left = '10' unblock_retries_left = '32' ]
<debug> [1494233352.329745] [../../git/src/mm-broadband-modem-qmi.c:4088] dms_uim_get_ck_status_ready(): Facility 'provider-pers' is: 'deactivated'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:02:01:00:1C:00:40:00:04:00:01:01:00:03
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 28
<<<<<< tlv_length = 4
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Facility" (0x01)
<<<<<< length = 1
<<<<<< value = 03
<<<<<< translated = pc
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 26
<<<<<< data = 01:19:00:80:02:01:02:1C:00:40:00:0D:00:02:04:00:00:00:00:00:01:03:00:00:0A:20
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 25
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 28
<<<<<< tlv_length = 13
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "CK Status" (0x01)
<<<<<< length = 3
<<<<<< value = 00:0A:20
<<<<<< translated = [ facility_state = 'deactivated' verify_retries_left = '10' unblock_retries_left = '32' ]
<debug> [1494233352.361238] [../../git/src/mm-broadband-modem-qmi.c:4088] dms_uim_get_ck_status_ready(): Facility 'corp-pers' is: 'deactivated'
<debug> [1494233352.361416] [../../git/src/mm-broadband-modem-qmi.c:4048] get_sim_lock_status_via_pin_status(): Retrieving PIN status to check for enabled PIN
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:1D:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 29
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:1D:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:02:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 29
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 02:03:0A
<<<<<< translated = [ current_status = 'enabled-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<debug> [1494233352.393343] [../../git/src/mm-broadband-modem-qmi.c:4020] get_sim_lock_status_via_pin_status_ready(): PIN is reported enabled
<debug> [1494233352.417030] [../../git/src/mm-broadband-modem.c:9925] iface_modem_3gpp_ussd_initialize_ready(): Couldn't initialize interface: 'USSD not supported'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:06:01:00:01:00:2E:00:04:00:12:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "pds"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 1
<<<<<< tlv_length = 4
<<<<<< message = "Get AGPS Config" (0x002E)
<<<<<< TLV:
<<<<<< type = "Network Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = umts
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 31
<<<<<< data = 01:1E:00:80:06:01:02:01:00:2E:00:12:00:02:04:00:00:00:00:00:10:08:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 30
<<<<<< flags = 0x80
<<<<<< service = "pds"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 1
<<<<<< tlv_length = 18
<<<<<< message = "Get AGPS Config" (0x002E)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Location Server Address" (0x10)
<<<<<< length = 8
<<<<<< value = 00:00:00:00:00:00:00:00
<<<<<< translated = [ ip = '0' port = '0' ]
<debug> [1494233352.476301] [../../git/src/mm-broadband-modem-qmi.c:7276] messaging_check_support(): Messaging capabilities supported
<debug> [1494233352.478148] [../../git/src/mm-iface-modem-messaging.c:1149] load_supported_storages_ready(): Supported storages loaded:
<debug> [1494233352.478271] [../../git/src/mm-iface-modem-messaging.c:1150] load_supported_storages_ready(): mem1 (list/read/delete) storages: 'sm, me'
<debug> [1494233352.478338] [../../git/src/mm-iface-modem-messaging.c:1151] load_supported_storages_ready(): mem2 (write/send) storages: 'sm, me'
<debug> [1494233352.478395] [../../git/src/mm-iface-modem-messaging.c:1152] load_supported_storages_ready(): mem3 (reception) storages: 'sm, me'
<debug> [1494233352.478801] [../../git/src/mm-port-serial.c:1226] mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
<debug> [1494233352.479199] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CPMS?<CR>'
<debug> [1494233352.492089] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>+CMS ERROR: 500<CR><LF>'
<debug> [1494233352.492591] [../../git/src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code 500: Unknown
<debug> [1494233352.492819] [../../git/src/mm-iface-modem-messaging.c:1229] init_current_storages_ready(): Couldn't initialize current storages: 'Unknown'
<debug> [1494233352.502243] [../../git/src/mm-port-serial.c:1283] _close_internal(): (ttyUSB2) device open count is 1 (close)
<debug> [1494233352.503498] [../../git/src/mm-port-serial.c:1226] mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
<debug> [1494233352.503964] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATH<CR>'
<debug> [1494233352.512419] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233352.522347] [../../git/src/mm-port-serial.c:1283] _close_internal(): (ttyUSB2) device open count is 1 (close)
<debug> [1494233352.524375] [../../git/src/mm-port-serial.c:1226] mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
<debug> [1494233352.524873] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CTZU=1<CR>'
<debug> [1494233352.542561] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233352.543316] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CCLK?<CR>'
<debug> [1494233352.564810] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>+CCLK: "80/01/06,00:01:09+08"<CR><LF><CR><LF>OK<CR><LF>'
<debug> [1494233352.574463] [../../git/src/mm-port-serial.c:1283] _close_internal(): (ttyUSB2) device open count is 1 (close)
<debug> [1494233352.575863] [../../git/src/mm-broadband-modem-qmi.c:10631] signal_check_support(): Extended signal capabilities supported
<debug> [1494233352.586854] [../../git/src/mm-broadband-modem-qmi.c:9345] oma_check_support(): OMA capabilities not supported
<debug> [1494233352.587778] [../../git/src/mm-broadband-modem.c:9932] iface_modem_oma_initialize_ready(): Couldn't initialize interface: 'OMA not supported'
<debug> [1494233352.588458] [../../git/src/mm-broadband-modem.c:9933] iface_modem_firmware_initialize_ready(): Couldn't initialize interface: 'Firmware interface not available'
<info> [1494233352.588822] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (initializing -> disabled)
<info> [1494233352.589327] [../../git/src/mm-iface-modem-simple.c:470] connection_step(): Simple connect state (3/8): Enable
<debug> [1494233352.601030] [../../git/src/mm-port-serial.c:1283] _close_internal(): (ttyUSB2) device open count is 0 (close)
<debug> [1494233352.601203] [../../git/src/mm-port-serial.c:1299] _close_internal(): (ttyUSB2) closing serial port...
<debug> [1494233352.604527] [../../git/src/mm-port-serial.c:1347] _close_internal(): (ttyUSB2) serial port closed
<info> [1494233352.604954] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling)
<debug> [1494233352.615677] [../../git/src/mm-broadband-modem.c:8836] enabling_started(): Skipping modem initialization: not required
<debug> [1494233352.616651] [../../git/src/mm-port-serial.c:1096] mm_port_serial_open(): (ttyUSB2) opening serial port...
<debug> [1494233352.618382] [../../git/src/mm-port-serial.c:370] real_config_fd(): (ttyUSB2): setting up baudrate: 57600
<warn> [1494233352.618602] [../../git/src/mm-port-serial.c:447] real_config_fd(): (ttyUSB2): port attributes not fully set
<debug> [1494233352.618832] [../../git/src/mm-port-serial.c:1226] mm_port_serial_open(): (ttyUSB2) device open count is 1 (open)
<debug> [1494233352.618923] [../../git/src/mm-port-serial-at.c:495] mm_port_serial_at_run_init_sequence(): (ttyUSB2): running init sequence...
<debug> [1494233352.619213] [../../git/src/mm-broadband-modem.c:8849] enabling_started(): Flashing primary AT port before enabling...
<debug> [1494233352.619591] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATE0<CR>'
<debug> [1494233352.626519] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233352.627147] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATV1<CR>'
<debug> [1494233352.634267] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233352.634882] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CMEE=1<CR>'
<debug> [1494233352.647657] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233352.648292] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATX4<CR>'
<debug> [1494233352.655271] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233352.655939] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT&C1<CR>'
<debug> [1494233352.664659] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233352.721004] [../../git/src/mm-broadband-modem-qmi.c:3284] load_power_state(): Getting device operating mode...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:1E:00:2D:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 30
<<<<<< tlv_length = 0
<<<<<< message = "Get Operating Mode" (0x002D)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 24
<<<<<< data = 01:17:00:80:02:01:02:1E:00:2D:00:0B:00:02:04:00:00:00:00:00:01:01:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 23
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 30
<<<<<< tlv_length = 11
<<<<<< message = "Get Operating Mode" (0x002D)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Mode" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = online
<debug> [1494233352.744233] [../../git/src/mm-iface-modem.c:3298] set_power_state(): No need to change power state: already in 'on' power state
<debug> [1494233352.744686] [../../git/src/mm-broadband-modem.c:9494] enabling_step(): Modem has 3GPP capabilities, enabling the Modem 3GPP interface...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 23
<<<<<< data = 01:16:00:00:03:03:00:08:00:02:00:0A:00:10:07:00:01:05:B0:D8:00:28:50
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 22
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 8
<<<<<< tlv_length = 10
<<<<<< message = "Set Event Report" (0x0002)
<<<<<< TLV:
<<<<<< type = "Signal Strength Indicator" (0x10)
<<<<<< length = 7
<<<<<< value = 01:05:B0:D8:00:28:50
<<<<<< translated = [ report = 'yes' thresholds = '{ [0] = '-80 ' [1] = '-40 ' [2] = '0 ' [3] = '40 ' [4] = '80 '}' ]
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:03:03:02:08:00:02:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 8
<<<<<< tlv_length = 7
<<<<<< message = "Set Event Report" (0x0002)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:03:03:00:09:00:03:00:04:00:13:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 9
<<<<<< tlv_length = 4
<<<<<< message = "Register Indications" (0x0003)
<<<<<< TLV:
<<<<<< type = "Serving System Events" (0x13)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:03:03:02:09:00:03:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 9
<<<<<< tlv_length = 7
<<<<<< message = "Register Indications" (0x0003)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<debug> [1494233352.808518] [../../git/src/mm-broadband-modem.c:9535] enabling_step(): Modem has location capabilities, enabling the Location interface...
<debug> [1494233352.808788] [../../git/src/mm-iface-modem-location.c:738] setup_gathering(): Location 'gps-raw' gathering is already disabled...
<debug> [1494233352.808883] [../../git/src/mm-iface-modem-location.c:738] setup_gathering(): Location 'gps-nmea' gathering is already disabled...
<debug> [1494233352.808950] [../../git/src/mm-iface-modem-location.c:738] setup_gathering(): Location 'agps' gathering is already disabled...
<debug> [1494233352.809021] [../../git/src/mm-iface-modem-location.c:762] setup_gathering(): Need to enable the following location sources: '3gpp-lac-ci'
<debug> [1494233352.813084] [../../git/src/mm-iface-modem-3gpp.c:798] mm_iface_modem_3gpp_run_registration_checks(): Running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes')
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:0A:00:24:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 10
<<<<<< tlv_length = 0
<<<<<< message = "Get Serving System" (0x0024)
<debug> [1494233352.820813] [../../git/src/mm-broadband-modem.c:9548] enabling_step(): Modem has messaging capabilities, enabling the Messaging interface...
<debug> [1494233352.823822] [../../git/src/mm-broadband-modem-qmi.c:7464] messaging_set_default_storage(): setting default messaging routes...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 26
<<<<<< data = 01:19:00:00:05:02:00:01:00:32:00:0D:00:01:0A:00:02:00:00:00:01:01:00:01:01:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 25
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 1
<<<<<< tlv_length = 13
<<<<<< message = "Set Routes" (0x0032)
<<<<<< TLV:
<<<<<< type = "Route List" (0x01)
<<<<<< length = 10
<<<<<< value = 02:00:00:00:01:01:00:01:01:01
<<<<<< translated = { [0] = '[ message_type = 'point' message_class = '0' storage = 'nv' receipt_action = 'store-and-notify' ] ' [1] = '[ message_type = 'point' message_class = '1' storage = 'nv' receipt_action = 'store-and-notify' ] '}
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 67
<<<<<< data = 01:42:00:80:03:03:02:0A:00:24:00:36:00:02:04:00:00:00:00:00:27:05:00:D6:00:01:00:00:21:05:00:01:02:04:01:00:15:03:00:01:08:01:12:05:00:D6:00:01:00:00:11:01:00:00:10:01:00:01:01:06:00:02:02:02:02:01:08
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 66
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 10
<<<<<< tlv_length = 54
<<<<<< message = "Get Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "MNC PCS Digit Include Status" (0x27)
<<<<<< length = 5
<<<<<< value = D6:00:01:00:00
<<<<<< translated = [ mcc = '214' mnc = '1' includes_pcs_digit = 'no' ]
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x21)
<<<<<< length = 5
<<<<<< value = 01:02:04:01:00
<<<<<< translated = [ status = 'limited' capability = 'ps' hdr_status = 'power-save' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "Roaming Indicator List" (0x15)
<<<<<< length = 3
<<<<<< value = 01:08:01
<<<<<< translated = { [0] = '[ radio_interface = 'lte' roaming_indicator = 'off' ] '}
<<<<<< TLV:
<<<<<< type = "Current PLMN" (0x12)
<<<<<< length = 5
<<<<<< value = D6:00:01:00:00
<<<<<< translated = [ mcc = '214' mnc = '1' description = '' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Roaming Indicator" (0x10)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = off
<<<<<< 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 '}' ]
<debug> [1494233352.844449] [../../git/src/mm-broadband-modem-qmi.c:4615] common_process_serving_system_3gpp(): Processing 3GPP info...
<info> [1494233352.845483] [../../git/src/mm-iface-modem-3gpp.c:1212] update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (unknown -> idle)
<debug> [1494233352.846415] [../../git/src/mm-iface-modem.c:1602] get_updated_consolidated_state(): Will start keeping track of state for subsystem '3gpp'
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:05:02:04:00:00:46:00:13:00:01:10:00:31:34:35:0C:2B:33:34:36:30:37:30:30:33:31:31:30
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 19
<<<<<< message = "SMSC Address" (0x0046)
<<<<<< TLV:
<<<<<< type = "Address" (0x01)
<<<<<< length = 16
<<<<<< value = 31:34:35:0C:2B:33:34:36:30:37:30:30:33:31:31:30
<<<<<< translated = [ type = '145' digits = '+34607003110' ]
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:01:00:32:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 1
<<<<<< tlv_length = 7
<<<<<< message = "Set Routes" (0x0032)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<debug> [1494233353.035568] [../../git/src/mm-broadband-modem-qmi.c:7758] load_initial_sms_parts_step(): loading all 3GPP messages from storage 'sm'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 21
<<<<<< data = 01:14:00:00:05:02:00:02:00:31:00:08:00:12:01:00:01:01:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 20
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 2
<<<<<< tlv_length = 8
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = uim
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:02:00:31:00:07:00:02:04:00:01:00:11:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 2
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:11:00
<<<<<< translated = FAILURE: MissingArgument
<debug> [1494233353.065160] [../../git/src/mm-broadband-modem-qmi.c:7711] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (17): 'MissingArgument'
<debug> [1494233353.065322] [../../git/src/mm-broadband-modem-qmi.c:7763] load_initial_sms_parts_step(): loading 3GPP MT-read messages from storage 'sm'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:03:00:31:00:0C:00:12:01:00:01:11:01:00:00:01:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 3
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = mt-read
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = uim
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:03:00:31:00:07:00:02:04:00:01:00:34:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 3
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:34:00
<<<<<< translated = FAILURE: DeviceNotReady
<debug> [1494233353.097062] [../../git/src/mm-broadband-modem-qmi.c:7711] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (52): 'DeviceNotReady'
<debug> [1494233353.097548] [../../git/src/mm-broadband-modem-qmi.c:7769] load_initial_sms_parts_step(): loading 3GPP MT-not-read messages from storage 'sm'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:04:00:31:00:0C:00:12:01:00:01:11:01:00:01:01:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 4
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = mt-not-read
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = uim
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 27
<<<<<< data = 01:1A:00:80:05:02:02:04:00:31:00:0E:00:02:04:00:00:00:00:00:01:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 26
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 4
<<<<<< tlv_length = 14
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Message List" (0x01)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = {}
<debug> [1494233353.129437] [../../git/src/mm-broadband-modem-qmi.c:7775] load_initial_sms_parts_step(): loading 3GPP MO-sent messages from storage 'sm'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:05:00:31:00:0C:00:12:01:00:01:11:01:00:02:01:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 5
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 02
<<<<<< translated = mo-sent
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = uim
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:05:00:31:00:07:00:02:04:00:01:00:30:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 5
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:30:00
<<<<<< translated = FAILURE: InvalidArgument
<debug> [1494233353.161186] [../../git/src/mm-broadband-modem-qmi.c:7711] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (48): 'InvalidArgument'
<debug> [1494233353.161345] [../../git/src/mm-broadband-modem-qmi.c:7781] load_initial_sms_parts_step(): loading 3GPP MO-not-sent messages from storage 'sm'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:06:00:31:00:0C:00:12:01:00:01:11:01:00:03:01:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 6
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 03
<<<<<< translated = mo-not-sent
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = uim
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:06:00:31:00:07:00:02:04:00:01:00:30:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 6
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:30:00
<<<<<< translated = FAILURE: InvalidArgument
<debug> [1494233353.193074] [../../git/src/mm-broadband-modem-qmi.c:7711] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (48): 'InvalidArgument'
<debug> [1494233353.193439] [../../git/src/mm-broadband-modem-qmi.c:7758] load_initial_sms_parts_step(): loading all 3GPP messages from storage 'me'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 21
<<<<<< data = 01:14:00:00:05:02:00:07:00:31:00:08:00:12:01:00:01:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 20
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 7
<<<<<< tlv_length = 8
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = nv
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:07:00:31:00:07:00:02:04:00:01:00:11:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 7
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:11:00
<<<<<< translated = FAILURE: MissingArgument
<debug> [1494233353.225323] [../../git/src/mm-broadband-modem-qmi.c:7711] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (17): 'MissingArgument'
<debug> [1494233353.225482] [../../git/src/mm-broadband-modem-qmi.c:7763] load_initial_sms_parts_step(): loading 3GPP MT-read messages from storage 'me'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:08:00:31:00:0C:00:12:01:00:01:11:01:00:00:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 8
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = mt-read
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = nv
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:08:00:31:00:07:00:02:04:00:01:00:34:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 8
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:34:00
<<<<<< translated = FAILURE: DeviceNotReady
<debug> [1494233353.260959] [../../git/src/mm-broadband-modem-qmi.c:7711] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (52): 'DeviceNotReady'
<debug> [1494233353.261103] [../../git/src/mm-broadband-modem-qmi.c:7769] load_initial_sms_parts_step(): loading 3GPP MT-not-read messages from storage 'me'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:09:00:31:00:0C:00:12:01:00:01:11:01:00:01:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 9
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = mt-not-read
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = nv
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 52
<<<<<< data = 01:33:00:80:03:03:04:00:00:24:00:27:00:25:02:00:00:08:22:05:00:02:03:04:01:00:1E:04:00:02:62:FC:03:1D:02:00:FE:FF:11:02:00:01:0B:01:06:00:01:01:01:02:01:08
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 51
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 39
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "LTE TAC" (0x25)
<<<<<< length = 2
<<<<<< value = 00:08
<<<<<< translated = 2048
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x22)
<<<<<< length = 5
<<<<<< value = 02:03:04:01:00
<<<<<< translated = [ status = 'available' capability = 'cs-ps' hdr_status = 'power-save' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "CID 3GPP" (0x1e)
<<<<<< length = 4
<<<<<< value = 02:62:FC:03
<<<<<< translated = 66871810
<<<<<< TLV:
<<<<<< type = "LAC 3GPP" (0x1d)
<<<<<< length = 2
<<<<<< value = FE:FF
<<<<<< translated = 65534
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 2
<<<<<< value = 01:0B
<<<<<< translated = { [0] = 'lte '}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 01:01:01:02:01:08
<<<<<< translated = [ registration_state = 'registered' cs_attach_state = 'attached' ps_attach_state = 'attached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'lte '}' ]
<debug> [1494233353.320636] [../../git/src/mm-broadband-modem-qmi.c:4615] common_process_serving_system_3gpp(): Processing 3GPP info...
<info> [1494233353.320858] [../../git/src/mm-iface-modem-3gpp.c:1197] update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (idle -> registering)
<debug> [1494233353.321189] [../../git/src/mm-iface-modem-location.c:297] notify_3gpp_location_update(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: 'FFFE', Cell ID: '3FC6202')
<debug> [1494233353.324130] [../../git/src/mm-iface-modem-location.c:297] notify_3gpp_location_update(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '214', MNC: '1', Location area code: 'FFFE', Cell ID: '3FC6202')
<info> [1494233353.359931] [../../git/src/mm-iface-modem-3gpp.c:1114] update_registration_reload_current_registration_info_ready(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (registering -> home)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 27
<<<<<< data = 01:1A:00:80:05:02:02:09:00:31:00:0E:00:02:04:00:00:00:00:00:01:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 26
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 9
<<<<<< tlv_length = 14
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Message List" (0x01)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = {}
<debug> [1494233353.366723] [../../git/src/mm-broadband-modem-qmi.c:7775] load_initial_sms_parts_step(): loading 3GPP MO-sent messages from storage 'me'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:0A:00:31:00:0C:00:12:01:00:01:11:01:00:02:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 10
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 02
<<<<<< translated = mo-sent
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = nv
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 46
<<<<<< data = 01:2D:00:80:03:03:04:00:00:24:00:21:00:1C:08:00:E1:07:05:08:08:31:0D:08:1B:01:00:01:1A:01:00:08:11:02:00:01:0B:01:06:00:01:01:01:02:01:08
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 45
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 33
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Universal Time and Local Time Zone 3GPP" (0x1c)
<<<<<< length = 8
<<<<<< value = E1:07:05:08:08:31:0D:08
<<<<<< translated = [ year = '2017' month = '5' day = '8' hour = '8' minute = '49' second = '13' time_zone = '8' ]
<<<<<< TLV:
<<<<<< type = "Daylight Saving Time Adjustment 3GPP" (0x1b)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = 1
<<<<<< TLV:
<<<<<< type = "Time Zone 3GPP" (0x1a)
<<<<<< length = 1
<<<<<< value = 08
<<<<<< translated = 8
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 2
<<<<<< value = 01:0B
<<<<<< translated = { [0] = 'lte '}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 01:01:01:02:01:08
<<<<<< translated = [ registration_state = 'registered' cs_attach_state = 'attached' ps_attach_state = 'attached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'lte '}' ]
<debug> [1494233353.384481] [../../git/src/mm-broadband-modem-qmi.c:4615] common_process_serving_system_3gpp(): Processing 3GPP info...
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 42
<<<<<< data = 01:29:00:80:03:03:04:00:00:3A:00:1D:00:14:1A:00:00:00:00:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 41
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 29
<<<<<< message = "Operator Name" (0x003A)
<<<<<< TLV:
<<<<<< type = "Operator NITZ Information" (0x14)
<<<<<< length = 26
<<<<<< value = 00:00:00:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14
<<<<<< translated = [ name_encoding = 'gsm' short_country_initials = 'initials-do-not-add' long_name_spare_bits = 'unknown' short_name_spare_bits = 'unknown' long_name = '��~܋b' short_name = '��~܋b' ]
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:0A:00:31:00:07:00:02:04:00:01:00:30:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 10
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:30:00
<<<<<< translated = FAILURE: InvalidArgument
<debug> [1494233353.448285] [../../git/src/mm-broadband-modem-qmi.c:7711] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (48): 'InvalidArgument'
<debug> [1494233353.448379] [../../git/src/mm-broadband-modem-qmi.c:7781] load_initial_sms_parts_step(): loading 3GPP MO-not-sent messages from storage 'me'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:0B:00:31:00:0C:00:12:01:00:01:11:01:00:03:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 11
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 03
<<<<<< translated = mo-not-sent
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = nv
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 53
<<<<<< data = 01:34:00:80:03:03:04:00:00:24:00:28:00:29:05:00:D6:00:01:00:00:12:0F:00:D6:00:01:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14:11:02:00:01:0B:01:06:00:01:01:01:02:01:08
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 52
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 40
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "MNC PCS Digit Include Status" (0x29)
<<<<<< length = 5
<<<<<< value = D6:00:01:00:00
<<<<<< translated = [ mcc = '214' mnc = '1' includes_pcs_digit = 'no' ]
<<<<<< TLV:
<<<<<< type = "Current PLMN" (0x12)
<<<<<< length = 15
<<<<<< value = D6:00:01:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14
<<<<<< translated = [ mcc = '214' mnc = '1' description = '��~܋b' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 2
<<<<<< value = 01:0B
<<<<<< translated = { [0] = 'lte '}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 01:01:01:02:01:08
<<<<<< translated = [ registration_state = 'registered' cs_attach_state = 'attached' ps_attach_state = 'attached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'lte '}' ]
<debug> [1494233353.480552] [../../git/src/mm-broadband-modem-qmi.c:4615] common_process_serving_system_3gpp(): Processing 3GPP info...
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:0B:00:31:00:07:00:02:04:00:01:00:30:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 11
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:30:00
<<<<<< translated = FAILURE: InvalidArgument
<debug> [1494233353.514148] [../../git/src/mm-broadband-modem-qmi.c:7711] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (48): 'InvalidArgument'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:05:02:00:0C:00:01:00:04:00:10:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 12
<<<<<< tlv_length = 4
<<<<<< message = "Set Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "New MT Message Indicator" (0x10)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = [ report = 'yes' ]
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:0C:00:01:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 12
<<<<<< tlv_length = 7
<<<<<< message = "Set Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<debug> [1494233353.545777] [../../git/src/mm-broadband-modem.c:9561] enabling_step(): Modem has voice capabilities, enabling the Voice interface...
<debug> [1494233353.546828] [../../git/src/mm-broadband-modem.c:6591] set_voice_unsolicited_events_handlers(): (ttyUSB2) Setting voice unsolicited events handlers
<debug> [1494233353.547599] [../../git/src/mm-port-serial.c:1226] mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
<debug> [1494233353.548052] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CLIP=1<CR>'
<debug> [1494233353.563039] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233353.563937] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CRC=1<CR>'
<debug> [1494233353.576033] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494233353.576639] [../../git/src/mm-port-serial.c:1283] _close_internal(): (ttyUSB2) device open count is 1 (close)
<debug> [1494233353.576908] [../../git/src/mm-broadband-modem.c:9574] enabling_step(): Modem has time capabilities, enabling the Time interface...
<debug> [1494233353.577731] [../../git/src/mm-broadband-modem.c:9587] enabling_step(): Modem has extended signal reporting capabilities, enabling the Signal interface...
<debug> [1494233353.577965] [../../git/src/mm-iface-modem-signal.c:206] setup_refresh_context(): Extended signal information reporting disabled (rate: 0 seconds)
<info> [1494233353.578880] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabling -> registered)
<debug> [1494233353.590209] [../../git/src/mm-iface-modem.c:1357] periodic_signal_quality_check_enable(): Periodic signal quality checks enabled (interval = 3s)
<debug> [1494233353.590460] [../../git/src/mm-broadband-modem-qmi.c:2951] load_signal_quality(): loading signal quality...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:0B:00:20:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 11
<<<<<< tlv_length = 0
<<<<<< message = "Get Signal Strength" (0x0020)
<info> [1494233353.593025] [../../git/src/mm-iface-modem-simple.c:478] connection_step(): Simple connect state (4/8): Wait to get fully enabled
<info> [1494233353.593451] [../../git/src/mm-iface-modem-simple.c:487] connection_step(): Simple connect state (5/8): Register
<debug> [1494233353.593733] [../../git/src/mm-iface-modem-3gpp.c:437] mm_iface_modem_3gpp_register_in_network(): Already registered in network '21401', automatic registration not launched...
<info> [1494233353.593998] [../../git/src/mm-iface-modem-simple.c:510] connection_step(): Simple connect state (6/8): Bearer
<debug> [1494233353.594127] [../../git/src/mm-iface-modem-simple.c:530] connection_step(): Creating new bearer...
<debug> [1494233353.603125] [../../git/src/mm-broadband-modem-qmi.c:304] modem_create_bearer_finish(): New bearer created at DBus path '/org/freedesktop/ModemManager1/Bearer/0'
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:03:03:02:0B:00:20:00:13:00:02:04:00:00:00:00:00:01:02:00:83:08:10:04:00:01:00:83:02
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 11
<<<<<< tlv_length = 19
<<<<<< message = "Get Signal Strength" (0x0020)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Signal Strength" (0x01)
<<<<<< length = 2
<<<<<< value = 83:08
<<<<<< translated = [ strength = '-125' radio_interface = 'lte' ]
<<<<<< TLV:
<<<<<< type = "Strength List" (0x10)
<<<<<< length = 4
<<<<<< value = 01:00:83:02
<<<<<< translated = { [0] = '[ strength = '-125' radio_interface = 'cdma-1xevdo' ] '}
<info> [1494233353.613423] [../../git/src/mm-iface-modem-simple.c:592] connection_step(): Simple connect state (7/8): Connect
<debug> [1494233353.613628] [../../git/src/mm-base-bearer.c:817] mm_base_bearer_connect(): Connecting bearer '/org/freedesktop/ModemManager1/Bearer/0'
<info> [1494233353.613864] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
<debug> [1494233353.626117] [../../git/src/mm-bearer-qmi.c:1417] _connect(): Launching connection with QMI port (usb/cdc-wdm0) and data port (net/wwan0)
<debug> [1494233353.626402] [../../git/src/mm-bearer-qmi.c:1451] _connect(): No specific IP family requested, defaulting to ipv4
<debug> [1494233353.627463] [../../git/src/mm-bearer-qmi.c:1074] connect_context_step(): Defaulting to use dhcp IP method
<debug> [1494233353.627606] [../../git/src/mm-bearer-qmi.c:1088] connect_context_step(): Running IPv4 connection setup
<debug> [1494233353.627675] [../../git/src/mm-bearer-qmi.c:1101] connect_context_step(): Allocating IPv4-specific WDS client
[/dev/cdc-wdm0] Allocating new client ID...[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 16
<<<<<< data = 01:0F:00:00:00:00:00:0A:22:00:04:00:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 15
<<<<<< flags = 0x00
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 10
<<<<<< tlv_length = 4
<<<<<< message = "Allocate CID" (0x0022)
<<<<<< TLV:
<<<<<< type = "Service" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = wds
<debug> [1494233353.632206] [../../git/src/mm-broadband-modem-qmi.c:2841] signal_strength_get_quality_and_access_tech(): Signal strength (lte): -125 dBm
<debug> [1494233353.632387] [../../git/src/mm-broadband-modem-qmi.c:2860] signal_strength_get_quality_and_access_tech(): Signal strength (cdma-1xevdo): -125 dBm
<debug> [1494233353.632455] [../../git/src/mm-broadband-modem-qmi.c:2874] signal_strength_get_quality_and_access_tech(): Signal strength: -125 dBm --> 0%
<debug> [1494233353.632959] [../../git/src/mm-iface-modem.c:935] mm_iface_modem_update_access_technologies(): Modem /org/freedesktop/ModemManager1/Modem/0: access technology changed (unknown -> lte)
<debug> [1494233353.633597] [../../git/src/mm-iface-modem.c:1206] update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (0)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 24
<<<<<< data = 01:17:00:80:00:00:01:0A:22:00:0C:00:02:04:00:00:00:00:00:01:02:00:01:0B
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 23
<<<<<< flags = 0x80
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 10
<<<<<< tlv_length = 12
<<<<<< message = "Allocate CID" (0x0022)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Allocation Info" (0x01)
<<<<<< length = 2
<<<<<< value = 01:0B
<<<<<< translated = [ service = 'wds' cid = '11' ]
[/dev/cdc-wdm0] Registered 'wds' (version 1.36) client with ID '11'[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 61
<<<<<< data = 01:3C:00:00:01:0B:00:01:00:01:00:30:00:1E:01:00:01:1C:01:00:01:1B:01:00:01:1A:01:00:01:19:01:00:01:18:01:00:01:17:01:00:01:15:01:00:01:14:01:00:01:13:01:00:01:12:01:00:01:10:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 60
<<<<<< flags = 0x00
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 1
<<<<<< tlv_length = 48
<<<<<< message = "Set Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Extended Data Bearer Technology" (0x1e)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Limited Data System Status" (0x1c)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Uplink Flow Control" (0x1b)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Data Systems" (0x1a)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "EVDO PM Change" (0x19)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Preferred Data System" (0x18)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Data Call Status" (0x17)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Current Data Bearer Technology" (0x15)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "MIP Status" (0x14)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = 1
<<<<<< TLV:
<<<<<< type = "Dormancy Status" (0x13)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Data Bearer Technology" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Channel Rate" (0x10)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<debug> [1494233353.655060] [../../git/src/mm-iface-modem-3gpp.c:798] mm_iface_modem_3gpp_run_registration_checks(): Running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes')
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:0C:00:24:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 12
<<<<<< tlv_length = 0
<<<<<< message = "Get Serving System" (0x0024)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:01:0B:02:01:00:01:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 1
<<<<<< tlv_length = 7
<<<<<< message = "Set Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<debug> [1494233353.673892] [../../git/src/mm-bearer-qmi.c:1155] connect_context_step(): Starting IPv4 connection...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 30
<<<<<< data = 01:1D:00:00:01:0B:00:02:00:20:00:11:00:14:0E:00:61:63:2E:76:6F:64:61:66:6F:6E:65:2E:65:73
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 29
<<<<<< flags = 0x00
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 2
<<<<<< tlv_length = 17
<<<<<< message = "Start Network" (0x0020)
<<<<<< TLV:
<<<<<< type = "APN" (0x14)
<<<<<< length = 14
<<<<<< value = 61:63:2E:76:6F:64:61:66:6F:6E:65:2E:65:73
<<<<<< translated = ac.vodafone.es
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 36
<<<<<< data = 01:23:00:80:01:0B:04:00:00:01:00:17:00:24:14:00:00:02:00:20:00:00:00:00:10:00:00:01:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 35
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 23
<<<<<< message = "Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Data Systems" (0x24)
<<<<<< length = 20
<<<<<< value = 00:02:00:20:00:00:00:00:10:00:00:01:00:00:00:00:00:00:00:00
<<<<<< translated = [ preferred_network_type = '3gpp' networks = '{ [0] = '[ network_type = '3gpp' rat_mask = '32' so_mask = '4096' ] ' [1] = '[ network_type = '3gpp2' rat_mask = '0' so_mask = '0' ] '}' ]
<debug> [1494233353.706512] [../../git/src/mm-bearer-qmi.c:859] event_report_indication_cb(): Got QMI WDS event report
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:01:0B:04:00:00:01:00:07:00:20:04:00:05:00:00:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 7
<<<<<< message = "Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Preferred Data System" (0x20)
<<<<<< length = 4
<<<<<< value = 05:00:00:00
<<<<<< translated = lte
<debug> [1494233353.736010] [../../git/src/mm-bearer-qmi.c:859] event_report_indication_cb(): Got QMI WDS event report
<debug> [1494233353.747618] [../../git/src/mm-port-probe.c:260] mm_port_probe_set_result_qcdm(): (tty/ttymxc1) port is not QCDM-capable
<debug> [1494233353.747859] [../../git/src/mm-plugin-manager.c:283] port_context_supported(): [plugin manager] task 1,ttymxc1: found best plugin for port (Generic)
<debug> [1494233353.747962] [../../git/src/mm-plugin-manager.c:265] port_context_complete(): [plugin manager] task 1,ttymxc1: finished in '22.256870' seconds
<debug> [1494233353.748106] [../../git/src/mm-plugin-manager.c:979] device_context_continue(): [plugin manager] task 1: no more ports to probe
<debug> [1494233353.748715] [../../git/src/mm-plugin-manager.c:813] device_context_complete(): [plugin manager] task 1: finished in '22.258375' seconds
<info> [1494233353.749033] [../../git/src/mm-device.c:385] mm_device_create_modem(): [device /sys/devices/platform/soc/2100000.aips-bus/21e8000.serial] creating modem with plugin 'Generic' and '1' ports
<warn> [1494233353.751666] [../../git/src/mm-plugin.c:948] mm_plugin_create_modem(): Could not grab port (tty/ttymxc1): 'Cannot add port 'tty/ttymxc1', unhandled serial type'
<debug> [1494233353.751998] [../../git/src/mm-base-modem.c:1409] finalize(): Modem (Generic) '/sys/devices/platform/soc/2100000.aips-bus/21e8000.serial' completely disposed
<warn> [1494233353.752110] [../../git/src/mm-base-manager.c:185] device_support_check_ready(): Couldn't create modem for device '/sys/devices/platform/soc/2100000.aips-bus/21e8000.serial': Failed to find primary AT port
<debug> [1494233353.752582] [../../git/src/mm-port-serial.c:1283] _close_internal(): (ttymxc1) device open count is 0 (close)
<debug> [1494233353.752707] [../../git/src/mm-port-serial.c:1299] _close_internal(): (ttymxc1) closing serial port...
<debug> [1494233353.757665] [../../git/src/mm-port-serial.c:1347] _close_internal(): (ttymxc1) serial port closed
<debug> [1494233353.757926] [../../git/src/mm-port-serial.c:1409] port_serial_close_force(): (ttymxc1) forced to close port
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 103
<<<<<< data = 01:66:00:80:03:03:02:0C:00:24:00:5A:00:02:04:00:00:00:00:00:27:05:00:D6:00:01:00:00:24:02:00:00:08:21:05:00:02:03:04:01:00:1D:04:00:02:62:FC:03:1C:02:00:FE:FF:1B:01:00:01:1A:01:00:08:15:03:00:01:08:01:12:0F:00:D6:00:01:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14:11:02:00:01:0B:10:01:00:01:01:06:00:01:01:01:02:01:08
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 102
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 12
<<<<<< tlv_length = 90
<<<<<< message = "Get Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "MNC PCS Digit Include Status" (0x27)
<<<<<< length = 5
<<<<<< value = D6:00:01:00:00
<<<<<< translated = [ mcc = '214' mnc = '1' includes_pcs_digit = 'no' ]
<<<<<< TLV:
<<<<<< type = "LTE TAC" (0x24)
<<<<<< length = 2
<<<<<< value = 00:08
<<<<<< translated = 2048
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x21)
<<<<<< length = 5
<<<<<< value = 02:03:04:01:00
<<<<<< translated = [ status = 'available' capability = 'cs-ps' hdr_status = 'power-save' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "CID 3GPP" (0x1d)
<<<<<< length = 4
<<<<<< value = 02:62:FC:03
<<<<<< translated = 66871810
<<<<<< TLV:
<<<<<< type = "LAC 3GPP" (0x1c)
<<<<<< length = 2
<<<<<< value = FE:FF
<<<<<< translated = 65534
<<<<<< TLV:
<<<<<< type = "Daylight Saving Time Adjustment 3GPP" (0x1b)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = 1
<<<<<< TLV:
<<<<<< type = "Time Zone 3GPP" (0x1a)
<<<<<< length = 1
<<<<<< value = 08
<<<<<< translated = 8
<<<<<< TLV:
<<<<<< type = "Roaming Indicator List" (0x15)
<<<<<< length = 3
<<<<<< value = 01:08:01
<<<<<< translated = { [0] = '[ radio_interface = 'lte' roaming_indicator = 'off' ] '}
<<<<<< TLV:
<<<<<< type = "Current PLMN" (0x12)
<<<<<< length = 15
<<<<<< value = D6:00:01:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14
<<<<<< translated = [ mcc = '214' mnc = '1' description = '��~܋b' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 2
<<<<<< value = 01:0B
<<<<<< translated = { [0] = 'lte '}
<<<<<< TLV:
<<<<<< type = "Roaming Indicator" (0x10)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = off
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 01:01:01:02:01:08
<<<<<< translated = [ registration_state = 'registered' cs_attach_state = 'attached' ps_attach_state = 'attached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'lte '}' ]
<debug> [1494233353.769565] [../../git/src/mm-broadband-modem-qmi.c:4615] common_process_serving_system_3gpp(): Processing 3GPP info...
<debug> [1494233353.769921] [../../git/src/mm-broadband-modem.c:8871] modem_3gpp_run_registration_checks_ready(): Initial 3GPP registration checks finished
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:80:01:0B:04:00:00:01:00:04:00:27:01:00:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 4
<<<<<< message = "Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Uplink Flow Control Enabled" (0x27)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<debug> [1494233354.440897] [../../git/src/mm-bearer-qmi.c:859] event_report_indication_cb(): Got QMI WDS event report
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 27
<<<<<< data = 01:1A:00:80:01:0B:02:02:00:20:00:0E:00:02:04:00:00:00:00:00:01:04:00:10:CA:E4:43
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 26
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 2
<<<<<< tlv_length = 14
<<<<<< message = "Start Network" (0x0020)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Packet Data Handle" (0x01)
<<<<<< length = 4
<<<<<< value = 10:CA:E4:43
<<<<<< translated = 1139067408
<debug> [1494233354.473333] [../../git/src/mm-bearer-qmi.c:1170] connect_context_step(): Getting IPv4 configuration...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:00:01:0B:00:03:00:2D:00:07:00:10:04:00:30:E3:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x00
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 3
<<<<<< tlv_length = 7
<<<<<< message = "Get Current Settings" (0x002D)
<<<<<< TLV:
<<<<<< type = "Requested Settings" (0x10)
<<<<<< length = 4
<<<<<< value = 30:E3:00:00
<<<<<< translated = dns-address, granted-qos, ip-address, gateway-info, mtu, domain-name-list, ip-family
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 22
<<<<<< data = 01:15:00:80:01:0B:04:00:00:01:00:09:00:22:02:00:02:01:1F:01:00:01
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 21
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 9
<<<<<< message = "Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Data Call Type" (0x22)
<<<<<< length = 2
<<<<<< value = 02:01
<<<<<< translated = [ data_call_type = 'tethered' tethered_call_type = 'rmnet' ]
<<<<<< TLV:
<<<<<< type = "Data Call Status" (0x1f)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = activated
<debug> [1494233354.505239] [../../git/src/mm-bearer-qmi.c:859] event_report_indication_cb(): Got QMI WDS event report
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 27
<<<<<< data = 01:1A:00:80:01:0B:04:00:00:22:00:0E:00:01:02:00:02:00:12:01:00:04:13:02:00:80:88
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 26
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 14
<<<<<< message = "Packet Service Status" (0x0022)
<<<<<< TLV:
<<<<<< type = "Connection Status" (0x01)
<<<<<< length = 2
<<<<<< value = 02:00
<<<<<< translated = [ status = 'connected' reconfiguration_required = 'no' ]
<<<<<< TLV:
<<<<<< type = "IP Family" (0x12)
<<<<<< length = 1
<<<<<< value = 04
<<<<<< translated = ipv4
<<<<<< TLV:
<<<<<< type = 0x13
<<<<<< length = 2
<<<<<< value = 80:88
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:80:01:0B:04:00:00:01:00:0C:00:1D:09:00:02:20:00:00:00:00:00:00:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 12
<<<<<< message = "Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Current Data Bearer Technology" (0x1d)
<<<<<< length = 9
<<<<<< value = 02:20:00:00:00:00:00:00:00
<<<<<< translated = [ network_type = '3gpp' rat_mask = '32' so_mask = '0' ]
<debug> [1494233354.570791] [../../git/src/mm-bearer-qmi.c:859] event_report_indication_cb(): Got QMI WDS event report
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:01:0B:04:00:00:01:00:13:00:2A:10:00:00:00:00:00:03:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 19
<<<<<< message = "Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Extended Data Bearer Technology" (0x2a)
<<<<<< length = 16
<<<<<< value = 00:00:00:00:03:00:00:00:00:00:00:00:00:00:00:00
<<<<<< translated = [ data_bearer_technology = '3gpp' radio_access_technology = '3gpp-lte' extended_data_bearer_technology_3gpp = 'unknown' reserved1 = '0' extended_data_bearer_technology_3gpp2 = 'unknown' reserved2 = '0' reserved3 = '0' reserved4 = '0' ]
<debug> [1494233354.603665] [../../git/src/mm-bearer-qmi.c:859] event_report_indication_cb(): Got QMI WDS event report
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:80:01:0B:04:00:00:01:00:04:00:18:01:00:02
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 4
<<<<<< message = "Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Dormancy Status" (0x18)
<<<<<< length = 1
<<<<<< value = 02
<<<<<< translated = traffic-channel-active
<debug> [1494233354.631989] [../../git/src/mm-bearer-qmi.c:859] event_report_indication_cb(): Got QMI WDS event report
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 70
<<<<<< data = 01:45:00:80:01:0B:02:03:00:2D:00:39:00:02:04:00:00:00:00:00:1E:04:00:4D:D6:D2:4D:15:04:00:06:D2:A6:D4:16:04:00:43:20:49:D4:20:04:00:4E:D6:D2:4D:21:04:00:FC:FF:FF:FF:29:04:00:96:05:00:00:2A:01:00:00:2B:01:00:04
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 69
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 3
<<<<<< tlv_length = 57
<<<<<< message = "Get Current Settings" (0x002D)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "IPv4 Address" (0x1e)
<<<<<< length = 4
<<<<<< value = 4D:D6:D2:4D
<<<<<< translated = 1305663053
<<<<<< TLV:
<<<<<< type = "Primary IPv4 DNS Address" (0x15)
<<<<<< length = 4
<<<<<< value = 06:D2:A6:D4
<<<<<< translated = 3567702534
<<<<<< TLV:
<<<<<< type = "Secondary IPv4 DNS Address" (0x16)
<<<<<< length = 4
<<<<<< value = 43:20:49:D4
<<<<<< translated = 3561562179
<<<<<< TLV:
<<<<<< type = "IPv4 Gateway Address" (0x20)
<<<<<< length = 4
<<<<<< value = 4E:D6:D2:4D
<<<<<< translated = 1305663054
<<<<<< TLV:
<<<<<< type = "IPv4 Gateway Subnet Mask" (0x21)
<<<<<< length = 4
<<<<<< value = FC:FF:FF:FF
<<<<<< translated = 4294967292
<<<<<< TLV:
<<<<<< type = "MTU" (0x29)
<<<<<< length = 4
<<<<<< value = 96:05:00:00
<<<<<< translated = 1430
<<<<<< TLV:
<<<<<< type = "Domain Name List" (0x2a)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "IP Family" (0x2b)
<<<<<< length = 1
<<<<<< value = 04
<<<<<< translated = ipv4
<debug> [1494233354.668619] [../../git/src/mm-bearer-qmi.c:689] get_current_settings_ready(): IP Family: IPv4
<info> [1494233354.671185] [../../git/src/mm-bearer-qmi.c:514] get_ipv4_config(): QMI IPv4 Settings:
<info> [1494233354.671549] [../../git/src/mm-bearer-qmi.c:523] get_ipv4_config(): Address: 77.210.214.77/30
<info> [1494233354.676886] [../../git/src/mm-bearer-qmi.c:529] get_ipv4_config(): Gateway: 77.210.214.78
<info> [1494233354.676993] [../../git/src/mm-bearer-qmi.c:539] get_ipv4_config(): DNS #1: 212.166.210.6
<info> [1494233354.677144] [../../git/src/mm-bearer-qmi.c:549] get_ipv4_config(): DNS #2: 212.73.32.67
<info> [1494233354.680635] [../../git/src/mm-bearer-qmi.c:560] get_ipv4_config(): MTU: 1430
<debug> [1494233354.680738] [../../git/src/mm-bearer-qmi.c:711] get_current_settings_ready(): Domains:
<debug> [1494233354.680876] [../../git/src/mm-port.c:94] mm_port_set_connected(): (wwan0): port now connected
<debug> [1494233354.686301] [../../git/src/mm-base-bearer.c:715] connect_ready(): Connected bearer '/org/freedesktop/ModemManager1/Bearer/0'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:00:01:0B:00:04:00:24:00:07:00:01:04:00:C0:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x00
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 4
<<<<<< tlv_length = 7
<<<<<< message = "Get Packet Statistics" (0x0024)
<<<<<< TLV:
<<<<<< type = "Mask" (0x01)
<<<<<< length = 4
<<<<<< value = C0:00:00:00
<<<<<< translated = tx-bytes-ok, rx-bytes-ok
<info> [1494233354.711835] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> connected)
<info> [1494233354.722554] [../../git/src/mm-iface-modem-simple.c:611] connection_step(): Simple connect state (8/8): All done
-------
And this is the debug with latest fix in QMI from Aleksander:
<info> [1494235726.171885] [../../git/src/mm-iface-modem-simple.c:650] connect_auth_ready(): Simple connect started...
<debug> [1494235726.172033] [../../git/src/mm-iface-modem-simple.c:660] connect_auth_ready(): PIN: 8770
<debug> [1494235726.172097] [../../git/src/mm-iface-modem-simple.c:662] connect_auth_ready(): Operator ID: unspecified
<debug> [1494235726.172158] [../../git/src/mm-iface-modem-simple.c:664] connect_auth_ready(): Allowed roaming: yes
<debug> [1494235726.172215] [../../git/src/mm-iface-modem-simple.c:666] connect_auth_ready(): APN: ac.vodafone.es
<debug> [1494235726.172275] [../../git/src/mm-iface-modem-simple.c:674] connect_auth_ready(): IP family: unspecified
<debug> [1494235726.172332] [../../git/src/mm-iface-modem-simple.c:682] connect_auth_ready(): Allowed authentication: unspecified
<debug> [1494235726.172388] [../../git/src/mm-iface-modem-simple.c:684] connect_auth_ready(): User: unspecified
<debug> [1494235726.172442] [../../git/src/mm-iface-modem-simple.c:686] connect_auth_ready(): Password: unspecified
<debug> [1494235726.172496] [../../git/src/mm-iface-modem-simple.c:688] connect_auth_ready(): Number: unspecified
<info> [1494235726.172537] [../../git/src/mm-iface-modem-simple.c:452] connection_step(): Simple connect state (1/8): Unlock check
<debug> [1494235726.172688] [../../git/src/mm-broadband-modem-qmi.c:1845] load_unlock_required_context_step(): loading unlock required (DMS)...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:0F:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 15
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:0F:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:01:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 15
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<debug> [1494235726.194568] [../../git/src/mm-broadband-modem-qmi.c:2072] modem_load_unlock_retries(): loading unlock retries...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:10:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 16
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:10:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:01:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 16
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<debug> [1494235726.226684] [../../git/src/mm-sim-qmi.c:548] send_pin(): Verifying PIN...
<debug> [1494235726.226848] [../../git/src/mm-sim-qmi.c:518] dms_uim_verify_pin(): Sending PIN...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 22
<<<<<< data = 01:15:00:00:02:01:00:11:00:28:00:09:00:01:06:00:01:04:38:37:37:30
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 21
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 17
<<<<<< tlv_length = 9
<<<<<< message = "UIM Verify PIN" (0x0028)
<<<<<< TLV:
<<<<<< type = "Info" (0x01)
<<<<<< length = 6
<<<<<< value = 01:04:38:37:37:30
<<<<<< translated = [ pin_id = 'pin' pin = '8770' ]
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:02:01:02:11:00:28:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 17
<<<<<< tlv_length = 7
<<<<<< message = "UIM Verify PIN" (0x0028)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<debug> [1494235726.322366] [../../git/src/mm-broadband-modem-qmi.c:1845] load_unlock_required_context_step(): loading unlock required (DMS)...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:12:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 18
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:12:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:02:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 18
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 02:03:0A
<<<<<< translated = [ current_status = 'enabled-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<debug> [1494235727.124722] [../../git/src/mm-iface-modem.c:3101] update_lock_info_context_step(): SIM is ready, and no need for the after SIM unlock step...
<debug> [1494235727.124992] [../../git/src/mm-broadband-modem-qmi.c:2072] modem_load_unlock_retries(): loading unlock retries...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:13:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 19
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:13:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:02:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 19
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 02:03:0A
<<<<<< translated = [ current_status = 'enabled-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<info> [1494235727.326484] [../../git/src/mm-iface-modem-simple.c:461] connection_step(): Simple connect state (2/8): Wait to get fully initialized
<info> [1494235727.327304] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (locked -> initializing)
<debug> [1494235727.348113] [../../git/src/mm-port-serial.c:1120] mm_port_serial_open(): (ttyUSB2) opening serial port...
<debug> [1494235727.351351] [../../git/src/mm-port-serial.c:421] real_config_fd(): (ttyUSB2): setting up baudrate: 57600
<debug> [1494235727.351673] [../../git/src/mm-port-serial.c:399] internal_tcsetattr(): (ttyUSB2): port attributes not fully set
<debug> [1494235727.352086] [../../git/src/mm-port-serial.c:1250] mm_port_serial_open(): (ttyUSB2) device open count is 1 (open)
<debug> [1494235727.352245] [../../git/src/mm-port-serial-at.c:495] mm_port_serial_at_run_init_sequence(): (ttyUSB2): running init sequence...
<debug> [1494235727.352821] [../../git/src/mm-port-serial.c:1250] mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
<debug> [1494235727.353642] [../../git/src/mm-port-serial.c:1250] mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
<debug> [1494235727.355225] [../../git/src/mm-broadband-modem-qmi.c:1845] load_unlock_required_context_step(): loading unlock required (DMS)...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:14:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 20
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
<debug> [1494235727.357888] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATE0<CR>'
<debug> [1494235727.365919] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235727.366931] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATV1<CR>'
<debug> [1494235727.375018] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235727.376005] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CMEE=1<CR>'
<debug> [1494235727.506307] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235727.507369] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATX4<CR>'
<debug> [1494235727.523674] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235727.524678] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT&C1<CR>'
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 34
<<<<<< data = 01:21:00:80:03:03:04:00:00:24:00:15:00:22:05:00:04:03:04:01:00:11:01:00:00:01:06:00:00:02:02:00:01:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 33
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 21
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x22)
<<<<<< length = 5
<<<<<< value = 04:03:04:01:00
<<<<<< translated = [ status = 'power-save' capability = 'cs-ps' hdr_status = 'power-save' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 00:02:02:00:01:00
<<<<<< translated = [ registration_state = 'not-registered' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = 'unknown' radio_interfaces = '{ [0] = 'none '}' ]
<debug> [1494235727.616451] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235727.617497] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATE0<CR>'
<debug> [1494235727.626578] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235727.627344] [../../git/src/mm-port-serial.c:1307] _close_internal(): (ttyUSB2) device open count is 2 (close)
<debug> [1494235727.627835] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CMEE=1<CR>'
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:14:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:02:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 20
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 02:03:0A
<<<<<< translated = [ current_status = 'enabled-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<debug> [1494235727.637027] [../../git/src/mm-iface-modem.c:3101] update_lock_info_context_step(): SIM is ready, and no need for the after SIM unlock step...
<debug> [1494235727.637317] [../../git/src/mm-broadband-modem-qmi.c:2072] modem_load_unlock_retries(): loading unlock retries...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:15:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 21
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
<debug> [1494235727.658904] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235727.659716] [../../git/src/mm-port-serial.c:1307] _close_internal(): (ttyUSB2) device open count is 1 (close)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:15:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:02:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 21
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 02:03:0A
<<<<<< translated = [ current_status = 'enabled-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<debug> [1494235727.669021] [../../git/src/mm-sim-qmi.c:206] load_imsi(): loading IMSI...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:16:00:43:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 22
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get IMSI" (0x0043)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 38
<<<<<< data = 01:25:00:80:02:01:02:16:00:43:00:19:00:02:04:00:00:00:00:00:01:0F:00:32:31:34:30:31:39:38:32:32:39:38:38:34:33:33
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 37
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 22
<<<<<< tlv_length = 25
<<<<<< message = "UIM Get IMSI" (0x0043)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "IMSI" (0x01)
<<<<<< length = 15
<<<<<< value = 32:31:34:30:31:39:38:32:32:39:38:38:34:33:33
<<<<<< translated = 214019822988433
<debug> [1494235727.698806] [../../git/src/mm-sim-qmi.c:325] load_operator_identifier(): loading SIM operator identifier...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:06:00:25:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 6
<<<<<< tlv_length = 0
<<<<<< message = "Get Home Network" (0x0025)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:03:03:02:06:00:25:00:07:00:02:04:00:01:00:10:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 6
<<<<<< tlv_length = 7
<<<<<< message = "Get Home Network" (0x0025)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:10:00
<<<<<< translated = FAILURE: NotProvisioned
<warn> [1494235727.730552] [../../git/src/mm-base-sim.c:1424] load_operator_identifier_ready(): couldn't load Operator identifier: 'Couldn't get home network: QMI protocol error (16): 'NotProvisioned''
<debug> [1494235727.730794] [../../git/src/mm-sim-qmi.c:374] load_operator_name(): loading SIM operator name...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:07:00:25:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 7
<<<<<< tlv_length = 0
<<<<<< message = "Get Home Network" (0x0025)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:03:03:02:07:00:25:00:07:00:02:04:00:01:00:10:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 7
<<<<<< tlv_length = 7
<<<<<< message = "Get Home Network" (0x0025)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:10:00
<<<<<< translated = FAILURE: NotProvisioned
<warn> [1494235727.762441] [../../git/src/mm-base-sim.c:1425] load_operator_name_ready(): couldn't load Operator name: 'Couldn't get home network: QMI protocol error (16): 'NotProvisioned''
<debug> [1494235727.762849] [../../git/src/mm-broadband-modem-qmi.c:1411] modem_load_own_numbers(): loading own numbers...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:17:00:24:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 23
<<<<<< tlv_length = 0
<<<<<< message = "Get MSISDN" (0x0024)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:02:01:02:17:00:24:00:07:00:02:04:00:01:00:10:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 23
<<<<<< tlv_length = 7
<<<<<< message = "Get MSISDN" (0x0024)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:10:00
<<<<<< translated = FAILURE: NotProvisioned
<warn> [1494235727.827338] [../../git/src/mm-iface-modem.c:4156] load_own_numbers_ready(): couldn't load list of Own Numbers: 'Couldn't get MSISDN: QMI protocol error (16): 'NotProvisioned''
<debug> [1494235727.835793] [../../git/src/mm-broadband-modem-qmi.c:3931] modem_3gpp_load_imei_finish(): loaded IMEI: 359852050097642
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:02:01:00:18:00:40:00:04:00:01:01:00:04
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 24
<<<<<< tlv_length = 4
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Facility" (0x01)
<<<<<< length = 1
<<<<<< value = 04
<<<<<< translated = pf
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 26
<<<<<< data = 01:19:00:80:02:01:02:18:00:40:00:0D:00:02:04:00:00:00:00:00:01:03:00:00:0A:20
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 25
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 24
<<<<<< tlv_length = 13
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "CK Status" (0x01)
<<<<<< length = 3
<<<<<< value = 00:0A:20
<<<<<< translated = [ facility_state = 'deactivated' verify_retries_left = '10' unblock_retries_left = '32' ]
<debug> [1494235727.891652] [../../git/src/mm-broadband-modem-qmi.c:4088] dms_uim_get_ck_status_ready(): Facility 'ph-sim' is: 'deactivated'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:02:01:00:19:00:40:00:04:00:01:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 25
<<<<<< tlv_length = 4
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Facility" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = pn
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 26
<<<<<< data = 01:19:00:80:02:01:02:19:00:40:00:0D:00:02:04:00:00:00:00:00:01:03:00:00:0A:20
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 25
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 25
<<<<<< tlv_length = 13
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "CK Status" (0x01)
<<<<<< length = 3
<<<<<< value = 00:0A:20
<<<<<< translated = [ facility_state = 'deactivated' verify_retries_left = '10' unblock_retries_left = '32' ]
<debug> [1494235727.923924] [../../git/src/mm-broadband-modem-qmi.c:4088] dms_uim_get_ck_status_ready(): Facility 'net-pers' is: 'deactivated'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:02:01:00:1A:00:40:00:04:00:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 26
<<<<<< tlv_length = 4
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Facility" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = pu
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 26
<<<<<< data = 01:19:00:80:02:01:02:1A:00:40:00:0D:00:02:04:00:00:00:00:00:01:03:00:00:0A:20
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 25
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 26
<<<<<< tlv_length = 13
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "CK Status" (0x01)
<<<<<< length = 3
<<<<<< value = 00:0A:20
<<<<<< translated = [ facility_state = 'deactivated' verify_retries_left = '10' unblock_retries_left = '32' ]
<debug> [1494235727.955662] [../../git/src/mm-broadband-modem-qmi.c:4088] dms_uim_get_ck_status_ready(): Facility 'net-sub-pers' is: 'deactivated'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:02:01:00:1B:00:40:00:04:00:01:01:00:02
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 27
<<<<<< tlv_length = 4
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Facility" (0x01)
<<<<<< length = 1
<<<<<< value = 02
<<<<<< translated = pp
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 26
<<<<<< data = 01:19:00:80:02:01:02:1B:00:40:00:0D:00:02:04:00:00:00:00:00:01:03:00:00:0A:20
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 25
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 27
<<<<<< tlv_length = 13
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "CK Status" (0x01)
<<<<<< length = 3
<<<<<< value = 00:0A:20
<<<<<< translated = [ facility_state = 'deactivated' verify_retries_left = '10' unblock_retries_left = '32' ]
<debug> [1494235727.987425] [../../git/src/mm-broadband-modem-qmi.c:4088] dms_uim_get_ck_status_ready(): Facility 'provider-pers' is: 'deactivated'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:02:01:00:1C:00:40:00:04:00:01:01:00:03
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 28
<<<<<< tlv_length = 4
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Facility" (0x01)
<<<<<< length = 1
<<<<<< value = 03
<<<<<< translated = pc
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 26
<<<<<< data = 01:19:00:80:02:01:02:1C:00:40:00:0D:00:02:04:00:00:00:00:00:01:03:00:00:0A:20
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 25
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 28
<<<<<< tlv_length = 13
<<<<<< message = "UIM Get CK Status" (0x0040)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "CK Status" (0x01)
<<<<<< length = 3
<<<<<< value = 00:0A:20
<<<<<< translated = [ facility_state = 'deactivated' verify_retries_left = '10' unblock_retries_left = '32' ]
<debug> [1494235728.019522] [../../git/src/mm-broadband-modem-qmi.c:4088] dms_uim_get_ck_status_ready(): Facility 'corp-pers' is: 'deactivated'
<debug> [1494235728.019694] [../../git/src/mm-broadband-modem-qmi.c:4048] get_sim_lock_status_via_pin_status(): Retrieving PIN status to check for enabled PIN
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:1D:00:2B:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 29
<<<<<< tlv_length = 0
<<<<<< message = "UIM Get PIN Status" (0x002B)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:02:01:02:1D:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:03:0A:11:03:00:02:03:0A
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 29
<<<<<< tlv_length = 19
<<<<<< message = "UIM Get PIN Status" (0x002B)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "PIN2 Status" (0x12)
<<<<<< length = 3
<<<<<< value = 01:03:0A
<<<<<< translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<<<<<< TLV:
<<<<<< type = "PIN1 Status" (0x11)
<<<<<< length = 3
<<<<<< value = 02:03:0A
<<<<<< translated = [ current_status = 'enabled-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<debug> [1494235728.055170] [../../git/src/mm-broadband-modem-qmi.c:4020] get_sim_lock_status_via_pin_status_ready(): PIN is reported enabled
<debug> [1494235728.097744] [../../git/src/mm-broadband-modem.c:10004] iface_modem_3gpp_ussd_initialize_ready(): Couldn't initialize interface: 'USSD not supported'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:06:01:00:01:00:2E:00:04:00:12:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "pds"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 1
<<<<<< tlv_length = 4
<<<<<< message = "Get AGPS Config" (0x002E)
<<<<<< TLV:
<<<<<< type = "Network Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = umts
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 31
<<<<<< data = 01:1E:00:80:06:01:02:01:00:2E:00:12:00:02:04:00:00:00:00:00:10:08:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 30
<<<<<< flags = 0x80
<<<<<< service = "pds"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 1
<<<<<< tlv_length = 18
<<<<<< message = "Get AGPS Config" (0x002E)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Location Server Address" (0x10)
<<<<<< length = 8
<<<<<< value = 00:00:00:00:00:00:00:00
<<<<<< translated = [ ip = '0' port = '0' ]
<debug> [1494235728.182500] [../../git/src/mm-broadband-modem-qmi.c:7278] messaging_check_support(): Messaging capabilities supported
<debug> [1494235728.184196] [../../git/src/mm-iface-modem-messaging.c:1149] load_supported_storages_ready(): Supported storages loaded:
<debug> [1494235728.184306] [../../git/src/mm-iface-modem-messaging.c:1150] load_supported_storages_ready(): mem1 (list/read/delete) storages: 'sm, me'
<debug> [1494235728.184361] [../../git/src/mm-iface-modem-messaging.c:1151] load_supported_storages_ready(): mem2 (write/send) storages: 'sm, me'
<debug> [1494235728.184405] [../../git/src/mm-iface-modem-messaging.c:1152] load_supported_storages_ready(): mem3 (reception) storages: 'sm, me'
<debug> [1494235728.184769] [../../git/src/mm-port-serial.c:1250] mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
<debug> [1494235728.185104] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CPMS?<CR>'
<debug> [1494235728.198790] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>+CMS ERROR: 500<CR><LF>'
<debug> [1494235728.199206] [../../git/src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code 500: Unknown
<debug> [1494235728.199408] [../../git/src/mm-iface-modem-messaging.c:1229] init_current_storages_ready(): Couldn't initialize current storages: 'Unknown'
<debug> [1494235728.207557] [../../git/src/mm-port-serial.c:1307] _close_internal(): (ttyUSB2) device open count is 1 (close)
<debug> [1494235728.208688] [../../git/src/mm-port-serial.c:1250] mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
<debug> [1494235728.209087] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATH<CR>'
<debug> [1494235728.217198] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235728.237736] [../../git/src/mm-port-serial.c:1307] _close_internal(): (ttyUSB2) device open count is 1 (close)
<debug> [1494235728.255995] [../../git/src/mm-port-serial.c:1250] mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
<debug> [1494235728.260705] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CTZU=1<CR>'
<debug> [1494235728.273630] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235728.274289] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CCLK?<CR>'
<debug> [1494235728.288252] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>+CCLK: "17/05/08,11:28:47+08"<CR><LF><CR><LF>OK<CR><LF>'
<debug> [1494235728.295350] [../../git/src/mm-port-serial.c:1307] _close_internal(): (ttyUSB2) device open count is 1 (close)
<debug> [1494235728.296622] [../../git/src/mm-broadband-modem-qmi.c:10633] signal_check_support(): Extended signal capabilities supported
<debug> [1494235728.309001] [../../git/src/mm-broadband-modem-qmi.c:9347] oma_check_support(): OMA capabilities not supported
<debug> [1494235728.314940] [../../git/src/mm-broadband-modem.c:10011] iface_modem_oma_initialize_ready(): Couldn't initialize interface: 'OMA not supported'
<debug> [1494235728.315622] [../../git/src/mm-broadband-modem.c:10012] iface_modem_firmware_initialize_ready(): Couldn't initialize interface: 'Firmware interface not available'
<info> [1494235728.315949] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (initializing -> disabled)
<info> [1494235728.316401] [../../git/src/mm-iface-modem-simple.c:470] connection_step(): Simple connect state (3/8): Enable
<debug> [1494235728.345988] [../../git/src/mm-port-serial.c:1307] _close_internal(): (ttyUSB2) device open count is 0 (close)
<debug> [1494235728.346180] [../../git/src/mm-port-serial.c:1323] _close_internal(): (ttyUSB2) closing serial port...
<debug> [1494235728.359028] [../../git/src/mm-port-serial.c:1371] _close_internal(): (ttyUSB2) serial port closed
<info> [1494235728.359423] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling)
<debug> [1494235728.370179] [../../git/src/mm-broadband-modem.c:8915] enabling_started(): Skipping modem initialization: not required
<debug> [1494235728.371244] [../../git/src/mm-port-serial.c:1120] mm_port_serial_open(): (ttyUSB2) opening serial port...
<debug> [1494235728.372269] [../../git/src/mm-port-serial.c:421] real_config_fd(): (ttyUSB2): setting up baudrate: 57600
<debug> [1494235728.372463] [../../git/src/mm-port-serial.c:399] internal_tcsetattr(): (ttyUSB2): port attributes not fully set
<debug> [1494235728.372692] [../../git/src/mm-port-serial.c:1250] mm_port_serial_open(): (ttyUSB2) device open count is 1 (open)
<debug> [1494235728.372790] [../../git/src/mm-port-serial-at.c:495] mm_port_serial_at_run_init_sequence(): (ttyUSB2): running init sequence...
<debug> [1494235728.373309] [../../git/src/mm-broadband-modem.c:8928] enabling_started(): Flashing primary AT port before enabling...
<debug> [1494235728.373572] [../../git/src/mm-port-serial.c:399] internal_tcsetattr(): (ttyUSB2): port attributes not fully set
<debug> [1494235728.373919] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATE0<CR>'
<debug> [1494235728.380364] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235728.380990] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATV1<CR>'
<debug> [1494235728.387765] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235728.388378] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CMEE=1<CR>'
<debug> [1494235728.401225] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235728.401759] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'ATX4<CR>'
<debug> [1494235728.407848] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235728.408375] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT&C1<CR>'
<debug> [1494235728.415966] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235728.475537] [../../git/src/mm-broadband-modem-qmi.c:3284] load_power_state(): Getting device operating mode...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:02:01:00:1E:00:2D:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 30
<<<<<< tlv_length = 0
<<<<<< message = "Get Operating Mode" (0x002D)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:05:02:04:00:00:46:00:13:00:01:10:00:31:34:35:0C:2B:33:34:36:30:37:30:30:33:31:31:30
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 19
<<<<<< message = "SMSC Address" (0x0046)
<<<<<< TLV:
<<<<<< type = "Address" (0x01)
<<<<<< length = 16
<<<<<< value = 31:34:35:0C:2B:33:34:36:30:37:30:30:33:31:31:30
<<<<<< translated = [ type = '145' digits = '+34607003110' ]
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 24
<<<<<< data = 01:17:00:80:02:01:02:1E:00:2D:00:0B:00:02:04:00:00:00:00:00:01:01:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 23
<<<<<< flags = 0x80
<<<<<< service = "dms"
<<<<<< client = 1
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 30
<<<<<< tlv_length = 11
<<<<<< message = "Get Operating Mode" (0x002D)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Mode" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = online
<debug> [1494235728.531421] [../../git/src/mm-iface-modem.c:3298] set_power_state(): No need to change power state: already in 'on' power state
<debug> [1494235728.532078] [../../git/src/mm-broadband-modem.c:9573] enabling_step(): Modem has 3GPP capabilities, enabling the Modem 3GPP interface...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 23
<<<<<< data = 01:16:00:00:03:03:00:08:00:02:00:0A:00:10:07:00:01:05:B0:D8:00:28:50
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 22
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 8
<<<<<< tlv_length = 10
<<<<<< message = "Set Event Report" (0x0002)
<<<<<< TLV:
<<<<<< type = "Signal Strength Indicator" (0x10)
<<<<<< length = 7
<<<<<< value = 01:05:B0:D8:00:28:50
<<<<<< translated = [ report = 'yes' thresholds = '{ [0] = '-80 ' [1] = '-40 ' [2] = '0 ' [3] = '40 ' [4] = '80 '}' ]
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:03:03:02:08:00:02:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 8
<<<<<< tlv_length = 7
<<<<<< message = "Set Event Report" (0x0002)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:03:03:00:09:00:03:00:04:00:13:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 9
<<<<<< tlv_length = 4
<<<<<< message = "Register Indications" (0x0003)
<<<<<< TLV:
<<<<<< type = "Serving System Events" (0x13)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:03:03:02:09:00:03:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 9
<<<<<< tlv_length = 7
<<<<<< message = "Register Indications" (0x0003)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<debug> [1494235728.595928] [../../git/src/mm-broadband-modem.c:9614] enabling_step(): Modem has location capabilities, enabling the Location interface...
<debug> [1494235728.596344] [../../git/src/mm-iface-modem-location.c:738] setup_gathering(): Location 'gps-raw' gathering is already disabled...
<debug> [1494235728.596517] [../../git/src/mm-iface-modem-location.c:738] setup_gathering(): Location 'gps-nmea' gathering is already disabled...
<debug> [1494235728.596645] [../../git/src/mm-iface-modem-location.c:738] setup_gathering(): Location 'agps' gathering is already disabled...
<debug> [1494235728.596763] [../../git/src/mm-iface-modem-location.c:762] setup_gathering(): Need to enable the following location sources: '3gpp-lac-ci'
<debug> [1494235728.601179] [../../git/src/mm-iface-modem-3gpp.c:798] mm_iface_modem_3gpp_run_registration_checks(): Running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes')
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:0A:00:24:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 10
<<<<<< tlv_length = 0
<<<<<< message = "Get Serving System" (0x0024)
<debug> [1494235728.610333] [../../git/src/mm-broadband-modem.c:9627] enabling_step(): Modem has messaging capabilities, enabling the Messaging interface...
<debug> [1494235728.612547] [../../git/src/mm-broadband-modem-qmi.c:7466] messaging_set_default_storage(): setting default messaging routes...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 26
<<<<<< data = 01:19:00:00:05:02:00:01:00:32:00:0D:00:01:0A:00:02:00:00:00:01:01:00:01:01:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 25
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 1
<<<<<< tlv_length = 13
<<<<<< message = "Set Routes" (0x0032)
<<<<<< TLV:
<<<<<< type = "Route List" (0x01)
<<<<<< length = 10
<<<<<< value = 02:00:00:00:01:01:00:01:01:01
<<<<<< translated = { [0] = '[ message_type = 'point' message_class = '0' storage = 'nv' receipt_action = 'store-and-notify' ] ' [1] = '[ message_type = 'point' message_class = '1' storage = 'nv' receipt_action = 'store-and-notify' ] '}
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 41
<<<<<< data = 01:28:00:80:03:03:02:0A:00:24:00:1C:00:02:04:00:00:00:00:00:21:05:00:04:03:04:01:00:11:01:00:00:01:06:00:00:02:02:00:01:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 40
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 10
<<<<<< tlv_length = 28
<<<<<< message = "Get Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x21)
<<<<<< length = 5
<<<<<< value = 04:03:04:01:00
<<<<<< translated = [ status = 'power-save' capability = 'cs-ps' hdr_status = 'power-save' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 00:02:02:00:01:00
<<<<<< translated = [ registration_state = 'not-registered' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = 'unknown' radio_interfaces = '{ [0] = 'none '}' ]
<debug> [1494235728.629755] [../../git/src/mm-broadband-modem-qmi.c:4619] common_process_serving_system_3gpp(): No 3GPP info given...
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:01:00:32:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 1
<<<<<< tlv_length = 7
<<<<<< message = "Set Routes" (0x0032)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<debug> [1494235728.659783] [../../git/src/mm-broadband-modem-qmi.c:7760] load_initial_sms_parts_step(): loading all 3GPP messages from storage 'sm'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 21
<<<<<< data = 01:14:00:00:05:02:00:02:00:31:00:08:00:12:01:00:01:01:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 20
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 2
<<<<<< tlv_length = 8
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = uim
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:02:00:31:00:07:00:02:04:00:01:00:11:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 2
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:11:00
<<<<<< translated = FAILURE: MissingArgument
<debug> [1494235728.690385] [../../git/src/mm-broadband-modem-qmi.c:7713] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (17): 'MissingArgument'
<debug> [1494235728.690536] [../../git/src/mm-broadband-modem-qmi.c:7765] load_initial_sms_parts_step(): loading 3GPP MT-read messages from storage 'sm'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:03:00:31:00:0C:00:12:01:00:01:11:01:00:00:01:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 3
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = mt-read
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = uim
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:03:00:31:00:07:00:02:04:00:01:00:34:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 3
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:34:00
<<<<<< translated = FAILURE: DeviceNotReady
<debug> [1494235728.722300] [../../git/src/mm-broadband-modem-qmi.c:7713] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (52): 'DeviceNotReady'
<debug> [1494235728.722388] [../../git/src/mm-broadband-modem-qmi.c:7771] load_initial_sms_parts_step(): loading 3GPP MT-not-read messages from storage 'sm'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:04:00:31:00:0C:00:12:01:00:01:11:01:00:01:01:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 4
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = mt-not-read
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = uim
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 27
<<<<<< data = 01:1A:00:80:05:02:02:04:00:31:00:0E:00:02:04:00:00:00:00:00:01:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 26
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 4
<<<<<< tlv_length = 14
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Message List" (0x01)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = {}
<debug> [1494235728.755737] [../../git/src/mm-broadband-modem-qmi.c:7777] load_initial_sms_parts_step(): loading 3GPP MO-sent messages from storage 'sm'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:05:00:31:00:0C:00:12:01:00:01:11:01:00:02:01:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 5
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 02
<<<<<< translated = mo-sent
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = uim
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:05:00:31:00:07:00:02:04:00:01:00:30:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 5
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:30:00
<<<<<< translated = FAILURE: InvalidArgument
<debug> [1494235728.787917] [../../git/src/mm-broadband-modem-qmi.c:7713] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (48): 'InvalidArgument'
<debug> [1494235728.788060] [../../git/src/mm-broadband-modem-qmi.c:7783] load_initial_sms_parts_step(): loading 3GPP MO-not-sent messages from storage 'sm'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:06:00:31:00:0C:00:12:01:00:01:11:01:00:03:01:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 6
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 03
<<<<<< translated = mo-not-sent
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = uim
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:06:00:31:00:07:00:02:04:00:01:00:30:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 6
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:30:00
<<<<<< translated = FAILURE: InvalidArgument
<debug> [1494235728.819285] [../../git/src/mm-broadband-modem-qmi.c:7713] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (48): 'InvalidArgument'
<debug> [1494235728.819650] [../../git/src/mm-broadband-modem-qmi.c:7760] load_initial_sms_parts_step(): loading all 3GPP messages from storage 'me'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 21
<<<<<< data = 01:14:00:00:05:02:00:07:00:31:00:08:00:12:01:00:01:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 20
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 7
<<<<<< tlv_length = 8
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = nv
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:07:00:31:00:07:00:02:04:00:01:00:11:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 7
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:11:00
<<<<<< translated = FAILURE: MissingArgument
<debug> [1494235728.851411] [../../git/src/mm-broadband-modem-qmi.c:7713] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (17): 'MissingArgument'
<debug> [1494235728.851563] [../../git/src/mm-broadband-modem-qmi.c:7765] load_initial_sms_parts_step(): loading 3GPP MT-read messages from storage 'me'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:08:00:31:00:0C:00:12:01:00:01:11:01:00:00:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 8
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = mt-read
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = nv
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:08:00:31:00:07:00:02:04:00:01:00:34:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 8
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:34:00
<<<<<< translated = FAILURE: DeviceNotReady
<debug> [1494235728.883748] [../../git/src/mm-broadband-modem-qmi.c:7713] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (52): 'DeviceNotReady'
<debug> [1494235728.883923] [../../git/src/mm-broadband-modem-qmi.c:7771] load_initial_sms_parts_step(): loading 3GPP MT-not-read messages from storage 'me'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:09:00:31:00:0C:00:12:01:00:01:11:01:00:01:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 9
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = mt-not-read
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = nv
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 27
<<<<<< data = 01:1A:00:80:05:02:02:09:00:31:00:0E:00:02:04:00:00:00:00:00:01:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 26
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 9
<<<<<< tlv_length = 14
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Message List" (0x01)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = {}
<debug> [1494235728.915614] [../../git/src/mm-broadband-modem-qmi.c:7777] load_initial_sms_parts_step(): loading 3GPP MO-sent messages from storage 'me'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:0A:00:31:00:0C:00:12:01:00:01:11:01:00:02:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 10
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 02
<<<<<< translated = mo-sent
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = nv
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:0A:00:31:00:07:00:02:04:00:01:00:30:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 10
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:30:00
<<<<<< translated = FAILURE: InvalidArgument
<debug> [1494235728.947262] [../../git/src/mm-broadband-modem-qmi.c:7713] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (48): 'InvalidArgument'
<debug> [1494235728.947415] [../../git/src/mm-broadband-modem-qmi.c:7783] load_initial_sms_parts_step(): loading 3GPP MO-not-sent messages from storage 'me'...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 25
<<<<<< data = 01:18:00:00:05:02:00:0B:00:31:00:0C:00:12:01:00:01:11:01:00:03:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 24
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 11
<<<<<< tlv_length = 12
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Message Mode" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = gsm-wcdma
<<<<<< TLV:
<<<<<< type = "Message Tag" (0x11)
<<<<<< length = 1
<<<<<< value = 03
<<<<<< translated = mo-not-sent
<<<<<< TLV:
<<<<<< type = "Storage Type" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = nv
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:0B:00:31:00:07:00:02:04:00:01:00:30:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 11
<<<<<< tlv_length = 7
<<<<<< message = "List Messages" (0x0031)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:30:00
<<<<<< translated = FAILURE: InvalidArgument
<debug> [1494235728.979227] [../../git/src/mm-broadband-modem-qmi.c:7713] wms_list_messages_ready(): Couldn't read SMS messages: QMI protocol error (48): 'InvalidArgument'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:05:02:00:0C:00:01:00:04:00:10:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 12
<<<<<< tlv_length = 4
<<<<<< message = "Set Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "New MT Message Indicator" (0x10)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = [ report = 'yes' ]
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:05:02:02:0C:00:01:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wms"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 12
<<<<<< tlv_length = 7
<<<<<< message = "Set Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<debug> [1494235729.013434] [../../git/src/mm-broadband-modem.c:9640] enabling_step(): Modem has voice capabilities, enabling the Voice interface...
<debug> [1494235729.015199] [../../git/src/mm-broadband-modem.c:6669] set_voice_unsolicited_events_handlers(): (ttyUSB2) Setting voice unsolicited events handlers
<debug> [1494235729.016086] [../../git/src/mm-port-serial.c:1250] mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
<debug> [1494235729.016704] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CLIP=1<CR>'
<debug> [1494235729.031405] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235729.032241] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CRC=1<CR>'
<debug> [1494235729.043681] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
<debug> [1494235729.044299] [../../git/src/mm-port-serial.c:1307] _close_internal(): (ttyUSB2) device open count is 1 (close)
<debug> [1494235729.044573] [../../git/src/mm-broadband-modem.c:9653] enabling_step(): Modem has time capabilities, enabling the Time interface...
<debug> [1494235729.045026] [../../git/src/mm-broadband-modem.c:9666] enabling_step(): Modem has extended signal reporting capabilities, enabling the Signal interface...
<debug> [1494235729.045275] [../../git/src/mm-iface-modem-signal.c:206] setup_refresh_context(): Extended signal information reporting disabled (rate: 0 seconds)
<info> [1494235729.046055] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabling -> enabled)
<info> [1494235729.056978] [../../git/src/mm-iface-modem-simple.c:478] connection_step(): Simple connect state (4/8): Wait to get fully enabled
<info> [1494235729.057357] [../../git/src/mm-iface-modem-simple.c:487] connection_step(): Simple connect state (5/8): Register
<debug> [1494235729.057664] [../../git/src/mm-iface-modem-3gpp.c:444] mm_iface_modem_3gpp_register_in_network(): Launching automatic network registration...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 17
<<<<<< data = 01:10:00:00:03:03:00:0B:00:22:00:04:00:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 16
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 11
<<<<<< tlv_length = 4
<<<<<< message = "Initiate Network Register" (0x0022)
<<<<<< TLV:
<<<<<< type = "Action" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = automatic
<debug> [1494235729.062767] [../../git/src/mm-iface-modem-3gpp.c:798] mm_iface_modem_3gpp_run_registration_checks(): Running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes')
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:0C:00:24:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 12
<<<<<< tlv_length = 0
<<<<<< message = "Get Serving System" (0x0024)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:03:03:02:0B:00:22:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 11
<<<<<< tlv_length = 7
<<<<<< message = "Initiate Network Register" (0x0022)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<debug> [1494235729.106518] [../../git/src/mm-iface-modem-3gpp.c:798] mm_iface_modem_3gpp_run_registration_checks(): Running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes')
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:0D:00:24:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 13
<<<<<< tlv_length = 0
<<<<<< message = "Get Serving System" (0x0024)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 30
<<<<<< data = 01:1D:00:80:03:03:04:00:00:24:00:11:00:27:01:00:01:11:01:00:00:01:06:00:00:02:02:00:01:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 29
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 17
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "PLMN Not Changed Indication" (0x27)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 00:02:02:00:01:00
<<<<<< translated = [ registration_state = 'not-registered' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = 'unknown' radio_interfaces = '{ [0] = 'none '}' ]
<debug> [1494235729.140425] [../../git/src/mm-broadband-modem-qmi.c:4619] common_process_serving_system_3gpp(): No 3GPP info given...
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 41
<<<<<< data = 01:28:00:80:03:03:02:0C:00:24:00:1C:00:02:04:00:00:00:00:00:21:05:00:04:03:04:01:00:11:01:00:00:01:06:00:00:02:02:00:01:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 40
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 12
<<<<<< tlv_length = 28
<<<<<< message = "Get Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x21)
<<<<<< length = 5
<<<<<< value = 04:03:04:01:00
<<<<<< translated = [ status = 'power-save' capability = 'cs-ps' hdr_status = 'power-save' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 00:02:02:00:01:00
<<<<<< translated = [ registration_state = 'not-registered' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = 'unknown' radio_interfaces = '{ [0] = 'none '}' ]
<debug> [1494235729.170690] [../../git/src/mm-broadband-modem-qmi.c:4619] common_process_serving_system_3gpp(): No 3GPP info given...
<debug> [1494235729.171005] [../../git/src/mm-broadband-modem.c:8950] modem_3gpp_run_registration_checks_ready(): Initial 3GPP registration checks finished
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 41
<<<<<< data = 01:28:00:80:03:03:02:0D:00:24:00:1C:00:02:04:00:00:00:00:00:21:05:00:04:03:04:01:00:11:01:00:00:01:06:00:00:02:02:00:01:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 40
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 13
<<<<<< tlv_length = 28
<<<<<< message = "Get Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x21)
<<<<<< length = 5
<<<<<< value = 04:03:04:01:00
<<<<<< translated = [ status = 'power-save' capability = 'cs-ps' hdr_status = 'power-save' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 00:02:02:00:01:00
<<<<<< translated = [ registration_state = 'not-registered' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = 'unknown' radio_interfaces = '{ [0] = 'none '}' ]
<debug> [1494235729.204471] [../../git/src/mm-broadband-modem-qmi.c:4619] common_process_serving_system_3gpp(): No 3GPP info given...
<debug> [1494235729.205003] [../../git/src/mm-iface-modem-3gpp.c:334] run_registration_checks_ready(): Modem not yet registered in a 3GPP network... will recheck soon
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 34
<<<<<< data = 01:21:00:80:03:03:04:00:00:24:00:15:00:22:05:00:00:03:00:01:00:11:01:00:00:01:06:00:02:02:02:00:01:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 33
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 21
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x22)
<<<<<< length = 5
<<<<<< value = 00:03:00:01:00
<<<<<< translated = [ status = 'none' capability = 'cs-ps' hdr_status = 'none' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 02:02:02:00:01:00
<<<<<< translated = [ registration_state = 'not-registered-searching' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = 'unknown' radio_interfaces = '{ [0] = 'none '}' ]
<debug> [1494235732.373407] [../../git/src/mm-broadband-modem-qmi.c:4619] common_process_serving_system_3gpp(): No 3GPP info given...
<info> [1494235732.373650] [../../git/src/mm-iface-modem-3gpp.c:1212] update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (unknown -> searching)
<debug> [1494235732.374438] [../../git/src/mm-iface-modem.c:1602] get_updated_consolidated_state(): Will start keeping track of state for subsystem '3gpp'
<info> [1494235732.376934] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabled -> searching)
<debug> [1494235732.734439] [../../git/src/mm-iface-modem-3gpp.c:798] mm_iface_modem_3gpp_run_registration_checks(): Running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes')
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:0E:00:24:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 14
<<<<<< tlv_length = 0
<<<<<< message = "Get Serving System" (0x0024)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 41
<<<<<< data = 01:28:00:80:03:03:02:0E:00:24:00:1C:00:02:04:00:00:00:00:00:21:05:00:00:03:00:01:00:11:01:00:00:01:06:00:02:02:02:00:01:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 40
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 14
<<<<<< tlv_length = 28
<<<<<< message = "Get Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x21)
<<<<<< length = 5
<<<<<< value = 00:03:00:01:00
<<<<<< translated = [ status = 'none' capability = 'cs-ps' hdr_status = 'none' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 02:02:02:00:01:00
<<<<<< translated = [ registration_state = 'not-registered-searching' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = 'unknown' radio_interfaces = '{ [0] = 'none '}' ]
<debug> [1494235732.756436] [../../git/src/mm-broadband-modem-qmi.c:4619] common_process_serving_system_3gpp(): No 3GPP info given...
<debug> [1494235732.756963] [../../git/src/mm-iface-modem-3gpp.c:334] run_registration_checks_ready(): Modem not yet registered in a 3GPP network... will recheck soon
<debug> [1494235735.736831] [../../git/src/mm-iface-modem-3gpp.c:798] mm_iface_modem_3gpp_run_registration_checks(): Running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes')
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:0F:00:24:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 15
<<<<<< tlv_length = 0
<<<<<< message = "Get Serving System" (0x0024)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 41
<<<<<< data = 01:28:00:80:03:03:02:0F:00:24:00:1C:00:02:04:00:00:00:00:00:21:05:00:00:03:00:01:00:11:01:00:00:01:06:00:02:02:02:00:01:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 40
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 15
<<<<<< tlv_length = 28
<<<<<< message = "Get Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x21)
<<<<<< length = 5
<<<<<< value = 00:03:00:01:00
<<<<<< translated = [ status = 'none' capability = 'cs-ps' hdr_status = 'none' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 02:02:02:00:01:00
<<<<<< translated = [ registration_state = 'not-registered-searching' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = 'unknown' radio_interfaces = '{ [0] = 'none '}' ]
<debug> [1494235735.764535] [../../git/src/mm-broadband-modem-qmi.c:4619] common_process_serving_system_3gpp(): No 3GPP info given...
<debug> [1494235735.765075] [../../git/src/mm-iface-modem-3gpp.c:334] run_registration_checks_ready(): Modem not yet registered in a 3GPP network... will recheck soon
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 60
<<<<<< data = 01:3B:00:80:03:03:04:00:00:24:00:2F:00:29:05:00:D6:00:01:00:00:22:05:00:01:01:00:01:00:15:03:00:01:04:01:12:05:00:D6:00:01:00:00:11:01:00:00:10:01:00:01:01:06:00:02:02:02:02:01:04
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 59
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 47
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "MNC PCS Digit Include Status" (0x29)
<<<<<< length = 5
<<<<<< value = D6:00:01:00:00
<<<<<< translated = [ mcc = '214' mnc = '1' includes_pcs_digit = 'no' ]
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x22)
<<<<<< length = 5
<<<<<< value = 01:01:00:01:00
<<<<<< translated = [ status = 'limited' capability = 'cs' hdr_status = 'none' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "Roaming Indicator List" (0x15)
<<<<<< length = 3
<<<<<< value = 01:04:01
<<<<<< translated = { [0] = '[ radio_interface = 'gsm' roaming_indicator = 'off' ] '}
<<<<<< TLV:
<<<<<< type = "Current PLMN" (0x12)
<<<<<< length = 5
<<<<<< value = D6:00:01:00:00
<<<<<< translated = [ mcc = '214' mnc = '1' description = '' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Roaming Indicator" (0x10)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = off
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 02:02:02:02:01:04
<<<<<< translated = [ registration_state = 'not-registered-searching' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'gsm '}' ]
<debug> [1494235736.916770] [../../git/src/mm-broadband-modem-qmi.c:4615] common_process_serving_system_3gpp(): Processing 3GPP info...
<info> [1494235736.917261] [../../git/src/mm-iface-modem-3gpp.c:1212] update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (searching -> idle)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 62
<<<<<< data = 01:3D:00:80:03:03:04:00:00:24:00:31:00:26:08:00:03:00:00:00:03:00:00:00:22:05:00:02:03:00:01:00:21:01:00:00:1E:04:00:CC:39:00:00:1D:02:00:72:10:11:02:00:01:02:01:06:00:01:01:02:02:01:04
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 61
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 49
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Call Barring Status" (0x26)
<<<<<< length = 8
<<<<<< value = 03:00:00:00:03:00:00:00
<<<<<< translated = [ cs_status = 'all-calls' ps_status = 'all-calls' ]
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x22)
<<<<<< length = 5
<<<<<< value = 02:03:00:01:00
<<<<<< translated = [ status = 'available' capability = 'cs-ps' hdr_status = 'none' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "DTM Support" (0x21)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<<<<<< TLV:
<<<<<< type = "CID 3GPP" (0x1e)
<<<<<< length = 4
<<<<<< value = CC:39:00:00
<<<<<< translated = 14796
<<<<<< TLV:
<<<<<< type = "LAC 3GPP" (0x1d)
<<<<<< length = 2
<<<<<< value = 72:10
<<<<<< translated = 4210
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 2
<<<<<< value = 01:02
<<<<<< translated = { [0] = 'edge '}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 01:01:02:02:01:04
<<<<<< translated = [ registration_state = 'registered' cs_attach_state = 'attached' ps_attach_state = 'detached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'gsm '}' ]
<debug> [1494235736.948668] [../../git/src/mm-broadband-modem-qmi.c:4615] common_process_serving_system_3gpp(): Processing 3GPP info...
<info> [1494235736.948965] [../../git/src/mm-iface-modem-3gpp.c:1197] update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (idle -> registering)
<debug> [1494235736.949515] [../../git/src/mm-iface-modem-location.c:297] notify_3gpp_location_update(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '1072', Cell ID: '39CC')
<debug> [1494235736.952814] [../../git/src/mm-iface-modem-location.c:297] notify_3gpp_location_update(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '214', MNC: '1', Location area code: '1072', Cell ID: '39CC')
<info> [1494235736.972185] [../../git/src/mm-iface-modem-3gpp.c:1114] update_registration_reload_current_registration_info_ready(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (registering -> home)
<info> [1494235736.973596] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (searching -> registered)
<debug> [1494235736.989695] [../../git/src/mm-iface-modem.c:1357] periodic_signal_quality_check_enable(): Periodic signal quality checks enabled (interval = 3s)
<debug> [1494235736.989940] [../../git/src/mm-broadband-modem-qmi.c:2951] load_signal_quality(): loading signal quality...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:10:00:20:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 16
<<<<<< tlv_length = 0
<<<<<< message = "Get Signal Strength" (0x0020)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 53
<<<<<< data = 01:34:00:80:03:03:04:00:00:24:00:28:00:29:05:00:D6:00:01:00:00:12:0F:00:D6:00:01:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14:11:02:00:01:02:01:06:00:01:01:02:02:01:04
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 52
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 40
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "MNC PCS Digit Include Status" (0x29)
<<<<<< length = 5
<<<<<< value = D6:00:01:00:00
<<<<<< translated = [ mcc = '214' mnc = '1' includes_pcs_digit = 'no' ]
<<<<<< TLV:
<<<<<< type = "Current PLMN" (0x12)
<<<<<< length = 15
<<<<<< value = D6:00:01:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14
<<<<<< translated = [ mcc = '214' mnc = '1' description = '��~܋b' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 2
<<<<<< value = 01:02
<<<<<< translated = { [0] = 'edge '}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 01:01:02:02:01:04
<<<<<< translated = [ registration_state = 'registered' cs_attach_state = 'attached' ps_attach_state = 'detached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'gsm '}' ]
<debug> [1494235736.998373] [../../git/src/mm-broadband-modem-qmi.c:4615] common_process_serving_system_3gpp(): Processing 3GPP info...
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:03:03:02:10:00:20:00:13:00:02:04:00:00:00:00:00:01:02:00:9E:04:10:04:00:01:00:83:02
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 16
<<<<<< tlv_length = 19
<<<<<< message = "Get Signal Strength" (0x0020)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Signal Strength" (0x01)
<<<<<< length = 2
<<<<<< value = 9E:04
<<<<<< translated = [ strength = '-98' radio_interface = 'gsm' ]
<<<<<< TLV:
<<<<<< type = "Strength List" (0x10)
<<<<<< length = 4
<<<<<< value = 01:00:83:02
<<<<<< translated = { [0] = '[ strength = '-125' radio_interface = 'cdma-1xevdo' ] '}
<debug> [1494235737.012762] [../../git/src/mm-broadband-modem-qmi.c:2841] signal_strength_get_quality_and_access_tech(): Signal strength (gsm): -98 dBm
<debug> [1494235737.012933] [../../git/src/mm-broadband-modem-qmi.c:2860] signal_strength_get_quality_and_access_tech(): Signal strength (cdma-1xevdo): -125 dBm
<debug> [1494235737.013259] [../../git/src/mm-broadband-modem-qmi.c:2874] signal_strength_get_quality_and_access_tech(): Signal strength: -98 dBm --> 25%
<debug> [1494235737.013778] [../../git/src/mm-iface-modem.c:935] mm_iface_modem_update_access_technologies(): Modem /org/freedesktop/ModemManager1/Modem/0: access technology changed (unknown -> gsm)
<debug> [1494235737.014488] [../../git/src/mm-iface-modem.c:1206] update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (25)
<debug> [1494235737.014668] [../../git/src/mm-iface-modem.c:1276] signal_quality_check_ready(): Periodic signal quality checks rescheduled (interval = 30s)
<debug> [1494235738.735571] [../../git/src/mm-iface-modem-3gpp.c:798] mm_iface_modem_3gpp_run_registration_checks(): Running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes')
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:11:00:24:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 17
<<<<<< tlv_length = 0
<<<<<< message = "Get Serving System" (0x0024)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 105
<<<<<< data = 01:68:00:80:03:03:02:11:00:24:00:5C:00:02:04:00:00:00:00:00:27:05:00:D6:00:01:00:00:25:08:00:03:00:00:00:03:00:00:00:21:05:00:02:03:00:01:00:20:01:00:00:1D:04:00:CC:39:00:00:1C:02:00:72:10:15:03:00:01:04:01:12:0F:00:D6:00:01:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14:11:02:00:01:02:10:01:00:01:01:06:00:01:01:02:02:01:04
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 104
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 17
<<<<<< tlv_length = 92
<<<<<< message = "Get Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "MNC PCS Digit Include Status" (0x27)
<<<<<< length = 5
<<<<<< value = D6:00:01:00:00
<<<<<< translated = [ mcc = '214' mnc = '1' includes_pcs_digit = 'no' ]
<<<<<< TLV:
<<<<<< type = "Call Barring Status" (0x25)
<<<<<< length = 8
<<<<<< value = 03:00:00:00:03:00:00:00
<<<<<< translated = [ cs_status = 'all-calls' ps_status = 'all-calls' ]
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x21)
<<<<<< length = 5
<<<<<< value = 02:03:00:01:00
<<<<<< translated = [ status = 'available' capability = 'cs-ps' hdr_status = 'none' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "DTM Support" (0x20)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<<<<<< TLV:
<<<<<< type = "CID 3GPP" (0x1d)
<<<<<< length = 4
<<<<<< value = CC:39:00:00
<<<<<< translated = 14796
<<<<<< TLV:
<<<<<< type = "LAC 3GPP" (0x1c)
<<<<<< length = 2
<<<<<< value = 72:10
<<<<<< translated = 4210
<<<<<< TLV:
<<<<<< type = "Roaming Indicator List" (0x15)
<<<<<< length = 3
<<<<<< value = 01:04:01
<<<<<< translated = { [0] = '[ radio_interface = 'gsm' roaming_indicator = 'off' ] '}
<<<<<< TLV:
<<<<<< type = "Current PLMN" (0x12)
<<<<<< length = 15
<<<<<< value = D6:00:01:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14
<<<<<< translated = [ mcc = '214' mnc = '1' description = '��~܋b' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 2
<<<<<< value = 01:02
<<<<<< translated = { [0] = 'edge '}
<<<<<< TLV:
<<<<<< type = "Roaming Indicator" (0x10)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = off
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 01:01:02:02:01:04
<<<<<< translated = [ registration_state = 'registered' cs_attach_state = 'attached' ps_attach_state = 'detached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'gsm '}' ]
<debug> [1494235738.776745] [../../git/src/mm-broadband-modem-qmi.c:4615] common_process_serving_system_3gpp(): Processing 3GPP info...
<debug> [1494235738.777421] [../../git/src/mm-iface-modem-3gpp.c:312] run_registration_checks_ready(): Modem is currently registered in a 3GPP network
<info> [1494235738.778007] [../../git/src/mm-iface-modem-simple.c:510] connection_step(): Simple connect state (6/8): Bearer
<debug> [1494235738.778260] [../../git/src/mm-iface-modem-simple.c:530] connection_step(): Creating new bearer...
<debug> [1494235738.802617] [../../git/src/mm-broadband-modem-qmi.c:304] modem_create_bearer_finish(): New bearer created at DBus path '/org/freedesktop/ModemManager1/Bearer/0'
<info> [1494235738.818619] [../../git/src/mm-iface-modem-simple.c:592] connection_step(): Simple connect state (7/8): Connect
<debug> [1494235738.818887] [../../git/src/mm-base-bearer.c:817] mm_base_bearer_connect(): Connecting bearer '/org/freedesktop/ModemManager1/Bearer/0'
<info> [1494235738.819127] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
<debug> [1494235738.857048] [../../git/src/mm-bearer-qmi.c:1417] _connect(): Launching connection with QMI port (usb/cdc-wdm0) and data port (net/wwan0)
<debug> [1494235738.857370] [../../git/src/mm-bearer-qmi.c:1451] _connect(): No specific IP family requested, defaulting to ipv4
<debug> [1494235738.857502] [../../git/src/mm-bearer-qmi.c:1074] connect_context_step(): Defaulting to use dhcp IP method
<debug> [1494235738.857571] [../../git/src/mm-bearer-qmi.c:1088] connect_context_step(): Running IPv4 connection setup
<debug> [1494235738.857630] [../../git/src/mm-bearer-qmi.c:1101] connect_context_step(): Allocating IPv4-specific WDS client
[/dev/cdc-wdm0] Allocating new client ID...[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 16
<<<<<< data = 01:0F:00:00:00:00:00:0A:22:00:04:00:01:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 15
<<<<<< flags = 0x00
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 10
<<<<<< tlv_length = 4
<<<<<< message = "Allocate CID" (0x0022)
<<<<<< TLV:
<<<<<< type = "Service" (0x01)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = wds
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 24
<<<<<< data = 01:17:00:80:00:00:01:0A:22:00:0C:00:02:04:00:00:00:00:00:01:02:00:01:0B
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 23
<<<<<< flags = 0x80
<<<<<< service = "ctl"
<<<<<< client = 0
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 10
<<<<<< tlv_length = 12
<<<<<< message = "Allocate CID" (0x0022)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Allocation Info" (0x01)
<<<<<< length = 2
<<<<<< value = 01:0B
<<<<<< translated = [ service = 'wds' cid = '11' ]
[/dev/cdc-wdm0] Registered 'wds' (version 1.36) client with ID '11'[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 61
<<<<<< data = 01:3C:00:00:01:0B:00:01:00:01:00:30:00:1E:01:00:01:1C:01:00:01:1B:01:00:01:1A:01:00:01:19:01:00:01:18:01:00:01:17:01:00:01:15:01:00:01:14:01:00:01:13:01:00:01:12:01:00:01:10:01:00:01
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 60
<<<<<< flags = 0x00
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 1
<<<<<< tlv_length = 48
<<<<<< message = "Set Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Extended Data Bearer Technology" (0x1e)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Limited Data System Status" (0x1c)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Uplink Flow Control" (0x1b)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Data Systems" (0x1a)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "EVDO PM Change" (0x19)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Preferred Data System" (0x18)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Data Call Status" (0x17)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Current Data Bearer Technology" (0x15)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "MIP Status" (0x14)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = 1
<<<<<< TLV:
<<<<<< type = "Dormancy Status" (0x13)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Data Bearer Technology" (0x12)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
<<<<<< TLV:
<<<<<< type = "Channel Rate" (0x10)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = yes
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:01:0B:02:01:00:01:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 1
<<<<<< tlv_length = 7
<<<<<< message = "Set Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<debug> [1494235738.911184] [../../git/src/mm-bearer-qmi.c:1155] connect_context_step(): Starting IPv4 connection...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 30
<<<<<< data = 01:1D:00:00:01:0B:00:02:00:20:00:11:00:14:0E:00:61:63:2E:76:6F:64:61:66:6F:6E:65:2E:65:73
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 29
<<<<<< flags = 0x00
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 2
<<<<<< tlv_length = 17
<<<<<< message = "Start Network" (0x0020)
<<<<<< TLV:
<<<<<< type = "APN" (0x14)
<<<<<< length = 14
<<<<<< value = 61:63:2E:76:6F:64:61:66:6F:6E:65:2E:65:73
<<<<<< translated = ac.vodafone.es
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 36
<<<<<< data = 01:23:00:80:01:0B:04:00:00:01:00:17:00:24:14:00:00:02:00:00:80:00:00:00:00:00:00:01:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 35
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 23
<<<<<< message = "Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Data Systems" (0x24)
<<<<<< length = 20
<<<<<< value = 00:02:00:00:80:00:00:00:00:00:00:01:00:00:00:00:00:00:00:00
<<<<<< translated = [ preferred_network_type = '3gpp' networks = '{ [0] = '[ network_type = '3gpp' rat_mask = '32768' so_mask = '0' ] ' [1] = '[ network_type = '3gpp2' rat_mask = '0' so_mask = '0' ] '}' ]
<debug> [1494235738.936658] [../../git/src/mm-bearer-qmi.c:859] event_report_indication_cb(): Got QMI WDS event report
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:01:0B:04:00:00:01:00:07:00:20:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 7
<<<<<< message = "Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Preferred Data System" (0x20)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = unknown
<debug> [1494235738.962390] [../../git/src/mm-bearer-qmi.c:859] event_report_indication_cb(): Got QMI WDS event report
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 24
<<<<<< data = 01:17:00:80:01:0B:04:00:00:01:00:0B:00:16:08:00:00:9D:03:00:40:84:04:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 23
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 11
<<<<<< message = "Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Channel Rates" (0x16)
<<<<<< length = 8
<<<<<< value = 00:9D:03:00:40:84:04:00
<<<<<< translated = [ tx_rate_bps = '236800' rx_rate_bps = '296000' ]
<debug> [1494235739.061864] [../../git/src/mm-bearer-qmi.c:859] event_report_indication_cb(): Got QMI WDS event report
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 24
<<<<<< data = 01:17:00:80:01:0B:04:00:00:01:00:0B:00:16:08:00:00:9D:03:00:40:84:04:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 23
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 11
<<<<<< message = "Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Channel Rates" (0x16)
<<<<<< length = 8
<<<<<< value = 00:9D:03:00:40:84:04:00
<<<<<< translated = [ tx_rate_bps = '236800' rx_rate_bps = '296000' ]
<debug> [1494235739.094557] [../../git/src/mm-bearer-qmi.c:859] event_report_indication_cb(): Got QMI WDS event report
<debug> [1494235741.736782] [../../git/src/mm-port-serial.c:1250] mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
<debug> [1494235741.737268] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): --> 'AT+CCLK?<CR>'
<debug> [1494235741.751106] [../../git/src/mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <-- '<CR><LF>+CCLK: "17/05/08,11:29:01+08"<CR><LF><CR><LF>OK<CR><LF>'
<debug> [1494235741.755110] [../../git/src/mm-port-serial.c:1307] _close_internal(): (ttyUSB2) device open count is 1 (close)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 34
<<<<<< data = 01:21:00:80:03:03:04:00:00:24:00:15:00:22:05:00:01:01:00:01:00:11:01:00:00:01:06:00:02:02:02:02:01:04
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 33
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 21
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x22)
<<<<<< length = 5
<<<<<< value = 01:01:00:01:00
<<<<<< translated = [ status = 'limited' capability = 'cs' hdr_status = 'none' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 02:02:02:02:01:04
<<<<<< translated = [ registration_state = 'not-registered-searching' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'gsm '}' ]
<debug> [1494235742.420106] [../../git/src/mm-broadband-modem-qmi.c:4615] common_process_serving_system_3gpp(): Processing 3GPP info...
<info> [1494235742.420398] [../../git/src/mm-iface-modem-3gpp.c:1212] update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (home -> idle)
<debug> [1494235742.421319] [../../git/src/mm-iface-modem-location.c:297] notify_3gpp_location_update(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '1072', Cell ID: '39CC')
<debug> [1494235742.422241] [../../git/src/mm-base-bearer.c:487] modem_3gpp_registration_state_changed(): Bearer not allowed to connect, not registered in 3GPP network
<debug> [1494235742.422510] [../../git/src/mm-base-bearer.c:1195] mm_base_bearer_disconnect_force(): Forcing disconnection of bearer '/org/freedesktop/ModemManager1/Bearer/0'
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 18
<<<<<< data = 01:11:00:00:01:0B:00:03:00:02:00:05:00:01:02:00:02:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 17
<<<<<< flags = 0x00
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 3
<<<<<< tlv_length = 5
<<<<<< message = "Abort" (0x0002)
<<<<<< TLV:
<<<<<< type = "Transaction ID" (0x01)
<<<<<< length = 2
<<<<<< value = 02:00
<<<<<< translated = 2
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 61
<<<<<< data = 01:3C:00:00:01:0B:00:04:00:01:00:30:00:1E:01:00:00:1C:01:00:00:1B:01:00:00:1A:01:00:00:19:01:00:00:18:01:00:00:17:01:00:00:15:01:00:00:14:01:00:00:13:01:00:00:12:01:00:00:10:01:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 60
<<<<<< flags = 0x00
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 4
<<<<<< tlv_length = 48
<<<<<< message = "Set Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Extended Data Bearer Technology" (0x1e)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<<<<<< TLV:
<<<<<< type = "Limited Data System Status" (0x1c)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<<<<<< TLV:
<<<<<< type = "Uplink Flow Control" (0x1b)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<<<<<< TLV:
<<<<<< type = "Data Systems" (0x1a)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<<<<<< TLV:
<<<<<< type = "EVDO PM Change" (0x19)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<<<<<< TLV:
<<<<<< type = "Preferred Data System" (0x18)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<<<<<< TLV:
<<<<<< type = "Data Call Status" (0x17)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<<<<<< TLV:
<<<<<< type = "Current Data Bearer Technology" (0x15)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<<<<<< TLV:
<<<<<< type = "MIP Status" (0x14)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = 0
<<<<<< TLV:
<<<<<< type = "Dormancy Status" (0x13)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<<<<<< TLV:
<<<<<< type = "Data Bearer Technology" (0x12)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<<<<<< TLV:
<<<<<< type = "Channel Rate" (0x10)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<debug> [1494235742.440934] [../../git/src/mm-base-bearer.c:692] connect_ready(): Couldn't connect bearer '/org/freedesktop/ModemManager1/Bearer/0': 'Connection setup operation has been cancelled'
<info> [1494235742.441448] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> disconnecting)
<debug> [1494235742.459541] [../../git/src/mm-iface-modem-simple.c:230] connect_bearer_ready(): Couldn't connect bearer: 'Connection setup operation has been cancelled'
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 52
<<<<<< data = 01:33:00:80:03:03:04:00:00:24:00:27:00:29:05:00:D6:00:01:00:00:12:0F:00:D6:00:01:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14:11:01:00:00:01:06:00:02:02:02:02:01:04
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 51
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 39
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "MNC PCS Digit Include Status" (0x29)
<<<<<< length = 5
<<<<<< value = D6:00:01:00:00
<<<<<< translated = [ mcc = '214' mnc = '1' includes_pcs_digit = 'no' ]
<<<<<< TLV:
<<<<<< type = "Current PLMN" (0x12)
<<<<<< length = 15
<<<<<< value = D6:00:01:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14
<<<<<< translated = [ mcc = '214' mnc = '1' description = '��~܋b' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = {}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 02:02:02:02:01:04
<<<<<< translated = [ registration_state = 'not-registered-searching' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'gsm '}' ]
<warn> [1494235742.470239] [../../git/src/mm-base-bearer.c:664] disconnect_after_cancel_ready(): Error disconnecting bearer '/org/freedesktop/ModemManager1/Bearer/0': 'Couldn't disconnect QMI bearer: this bearer is not connected'. Will assume disconnected anyway.
<info> [1494235742.470692] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disconnecting -> enabled)
<debug> [1494235742.494203] [../../git/src/mm-iface-modem.c:1206] update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (0)
<debug> [1494235742.494364] [../../git/src/mm-iface-modem.c:1323] periodic_signal_quality_check_disable(): Periodic signal quality checks disabled
<debug> [1494235742.494632] [../../git/src/mm-iface-modem.c:935] mm_iface_modem_update_access_technologies(): Modem /org/freedesktop/ModemManager1/Modem/0: access technology changed (gsm -> unknown)
<debug> [1494235742.494712] [../../git/src/mm-iface-modem.c:1049] periodic_access_technologies_check_disable(): Periodic access technology checks disabled
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 42
<<<<<< data = 01:29:00:80:03:03:04:00:00:3A:00:1D:00:14:1A:00:00:00:03:03:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 41
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 29
<<<<<< message = "Operator Name" (0x003A)
<<<<<< TLV:
<<<<<< type = "Operator NITZ Information" (0x14)
<<<<<< length = 26
<<<<<< value = 00:00:03:03:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14
<<<<<< translated = [ name_encoding = 'gsm' short_country_initials = 'initials-do-not-add' long_name_spare_bits = 'bits-68' short_name_spare_bits = 'bits-68' long_name = '��~܋b' short_name = '��~܋b' ]
<debug> [1494235742.505219] [../../git/src/mm-broadband-modem-qmi.c:4615] common_process_serving_system_3gpp(): Processing 3GPP info...
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 24
<<<<<< data = 01:17:00:80:01:0B:04:00:00:01:00:0B:00:16:08:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 23
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 11
<<<<<< message = "Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Channel Rates" (0x16)
<<<<<< length = 8
<<<<<< value = 00:00:00:00:00:00:00:00
<<<<<< translated = [ tx_rate_bps = '0' rx_rate_bps = '0' ]
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 24
<<<<<< data = 01:17:00:80:01:0B:04:00:00:01:00:0B:00:16:08:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 23
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 11
<<<<<< message = "Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Channel Rates" (0x16)
<<<<<< length = 8
<<<<<< value = 00:00:00:00:00:00:00:00
<<<<<< translated = [ tx_rate_bps = '0' rx_rate_bps = '0' ]
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:01:0B:02:02:00:20:00:07:00:02:04:00:01:00:04:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 2
<<<<<< tlv_length = 7
<<<<<< message = "Start Network" (0x0020)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 01:00:04:00
<<<<<< translated = FAILURE: Aborted
[/dev/cdc-wdm0] No transaction matched in received message[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:01:0B:02:03:00:02:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 3
<<<<<< tlv_length = 7
<<<<<< message = "Abort" (0x0002)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 20
<<<<<< data = 01:13:00:80:01:0B:02:04:00:01:00:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 19
<<<<<< flags = 0x80
<<<<<< service = "wds"
<<<<<< client = 11
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 4
<<<<<< tlv_length = 7
<<<<<< message = "Set Event Report" (0x0001)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 107
<<<<<< data = 01:6A:00:80:03:03:04:00:00:24:00:5E:00:29:05:00:D6:00:01:00:00:26:08:00:03:00:00:00:03:00:00:00:22:05:00:02:03:00:01:00:21:01:00:00:1E:04:00:CC:39:00:00:1D:02:00:72:10:1C:08:00:E1:07:05:08:09:1D:02:08:1B:01:00:01:1A:01:00:08:12:0F:00:D6:00:01:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14:11:02:00:01:02:01:06:00:01:01:01:02:01:04
[/dev/cdc-wdm0] received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 106
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 0
<<<<<< tlv_length = 94
<<<<<< message = "Serving System" (0x0024)
<<<<<< TLV:
<<<<<< type = "MNC PCS Digit Include Status" (0x29)
<<<<<< length = 5
<<<<<< value = D6:00:01:00:00
<<<<<< translated = [ mcc = '214' mnc = '1' includes_pcs_digit = 'no' ]
<<<<<< TLV:
<<<<<< type = "Call Barring Status" (0x26)
<<<<<< length = 8
<<<<<< value = 03:00:00:00:03:00:00:00
<<<<<< translated = [ cs_status = 'all-calls' ps_status = 'all-calls' ]
<<<<<< TLV:
<<<<<< type = "Detailed Service Status" (0x22)
<<<<<< length = 5
<<<<<< value = 02:03:00:01:00
<<<<<< translated = [ status = 'available' capability = 'cs-ps' hdr_status = 'none' hdr_hybrid = 'yes' forbidden = 'no' ]
<<<<<< TLV:
<<<<<< type = "DTM Support" (0x21)
<<<<<< length = 1
<<<<<< value = 00
<<<<<< translated = no
<<<<<< TLV:
<<<<<< type = "CID 3GPP" (0x1e)
<<<<<< length = 4
<<<<<< value = CC:39:00:00
<<<<<< translated = 14796
<<<<<< TLV:
<<<<<< type = "LAC 3GPP" (0x1d)
<<<<<< length = 2
<<<<<< value = 72:10
<<<<<< translated = 4210
<<<<<< TLV:
<<<<<< type = "Universal Time and Local Time Zone 3GPP" (0x1c)
<<<<<< length = 8
<<<<<< value = E1:07:05:08:09:1D:02:08
<<<<<< translated = [ year = '2017' month = '5' day = '8' hour = '9' minute = '29' second = '2' time_zone = '8' ]
<<<<<< TLV:
<<<<<< type = "Daylight Saving Time Adjustment 3GPP" (0x1b)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = 1
<<<<<< TLV:
<<<<<< type = "Time Zone 3GPP" (0x1a)
<<<<<< length = 1
<<<<<< value = 08
<<<<<< translated = 8
<<<<<< TLV:
<<<<<< type = "Current PLMN" (0x12)
<<<<<< length = 15
<<<<<< value = D6:00:01:00:0A:F6:37:39:6C:7E:BB:CB:A0:E2:14
<<<<<< translated = [ mcc = '214' mnc = '1' description = '��~܋b' ]
<<<<<< TLV:
<<<<<< type = "Data Service Capability" (0x11)
<<<<<< length = 2
<<<<<< value = 01:02
<<<<<< translated = { [0] = 'edge '}
<<<<<< TLV:
<<<<<< type = "Serving System" (0x01)
<<<<<< length = 6
<<<<<< value = 01:01:01:02:01:04
<<<<<< translated = [ registration_state = 'registered' cs_attach_state = 'attached' ps_attach_state = 'attached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'gsm '}' ]
<debug> [1494235751.065975] [../../git/src/mm-broadband-modem-qmi.c:4615] common_process_serving_system_3gpp(): Processing 3GPP info...
<info> [1494235751.066198] [../../git/src/mm-iface-modem-3gpp.c:1197] update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (idle -> registering)
<debug> [1494235751.066973] [../../git/src/mm-iface-modem-location.c:297] notify_3gpp_location_update(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '214', MNC: '1', Location area code: '1072', Cell ID: '39CC')
<warn> [1494235751.078072] [../../git/src/mm-iface-modem-3gpp.c:850] load_operator_name_ready(): Couldn't load Operator Name: 'Current operator description is still unknown'
<info> [1494235751.081165] [../../git/src/mm-iface-modem-3gpp.c:1114] update_registration_reload_current_registration_info_ready(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (registering -> home)
<info> [1494235751.089989] [../../git/src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabled -> registered)
<debug> [1494235751.111067] [../../git/src/mm-iface-modem.c:1357] periodic_signal_quality_check_enable(): Periodic signal quality checks enabled (interval = 3s)
<debug> [1494235751.111255] [../../git/src/mm-broadband-modem-qmi.c:2951] load_signal_quality(): loading signal quality...
[/dev/cdc-wdm0] sent message...
<<<<<< RAW:
<<<<<< length = 13
<<<<<< data = 01:0C:00:00:03:03:00:12:00:20:00:00:00
[/dev/cdc-wdm0] sent generic request (translated)...
<<<<<< QMUX:
<<<<<< length = 12
<<<<<< flags = 0x00
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "none"
<<<<<< transaction = 18
<<<<<< tlv_length = 0
<<<<<< message = "Get Signal Strength" (0x0020)
[/dev/cdc-wdm0] received message...
<<<<<< RAW:
<<<<<< length = 32
<<<<<< data = 01:1F:00:80:03:03:02:12:00:20:00:13:00:02:04:00:00:00:00:00:01:02:00:9E:04:10:04:00:01:00:83:02
[/dev/cdc-wdm0] received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 31
<<<<<< flags = 0x80
<<<<<< service = "nas"
<<<<<< client = 3
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 18
<<<<<< tlv_length = 19
<<<<<< message = "Get Signal Strength" (0x0020)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS
<<<<<< TLV:
<<<<<< type = "Signal Strength" (0x01)
<<<<<< length = 2
<<<<<< value = 9E:04
<<<<<< translated = [ strength = '-98' radio_interface = 'gsm' ]
<<<<<< TLV:
<<<<<< type = "Strength List" (0x10)
<<<<<< length = 4
<<<<<< value = 01:00:83:02
<<<<<< translated = { [0] = '[ strength = '-125' radio_interface = 'cdma-1xevdo' ] '}
<debug> [1494235751.124173] [../../git/src/mm-broadband-modem-qmi.c:2841] signal_strength_get_quality_and_access_tech(): Signal strength (gsm): -98 dBm
<debug> [1494235751.124264] [../../git/src/mm-broadband-modem-qmi.c:2860] signal_strength_get_quality_and_access_tech(): Signal strength (cdma-1xevdo): -125 dBm
<debug> [1494235751.124314] [../../git/src/mm-broadband-modem-qmi.c:2874] signal_strength_get_quality_and_access_tech(): Signal strength: -98 dBm --> 25%
<debug> [1494235751.124710] [../../git/src/mm-iface-modem.c:935] mm_iface_modem_update_access_technologies(): Modem /org/freedesktop/ModemManager1/Modem/0: access technology changed (unknown -> gsm)
<debug> [1494235751.125160] [../../git/src/mm-iface-modem.c:1206] update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (25)
<debug> [1494235751.125281] [../../git/src/mm-iface-modem.c:1276] signal_quality_check_ready(): Periodic signal quality checks rescheduled (interval = 30s)
-----Original Message-----
From: Dan Williams [mailto:dcbw at redhat.com]
Sent: viernes, 05 de mayo de 2017 18:17
To: Penalva, Salvador; Aleksander Morgado
Cc: ModemManager (development); Ben Chan
Subject: Re: QMI modems with MM-master branch error
On Fri, 2017-05-05 at 14:08 +0000, Penalva, Salvador wrote:
> I thought that too,
>
> but this modem still worked with the commit before the last changes I
> mentioned in the email before. Why is the connection attempt cancelled
> then an in the second retry working again?
The issue from the original logs has been fixed as mentioned by Aleksander.
In your latest logs, the modem really is indicating that it has lost registration during the connection attempt:
ModemManager[918]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (searching -> idle)
ModemManager[918]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (idle -> registering)
ModemManager[918]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (registering -> home)
ModemManager[918]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: state changed (searching -> registered)
ModemManager[918]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
ModemManager[918]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (home -> idle)
"idle" is not a registered state, and the modem is reporting that it has disconnected from the netowrk.
To debug further, would you be able to back up to commit
8c04cc036782dab0e80c1f2314baa3376eecad02 and grab debug logs of the full connect sequence so we can see what's going on when the first connect is successful?
Thanks!
Dan
> Thanks,
>
> Salvador
>
> -----Original Message-----
> From: Aleksander Morgado [mailto:aleksander at aleksander.es]
> Sent: viernes, 05 de mayo de 2017 14:52
> To: Penalva, Salvador
> Cc: ModemManager (development); Ben Chan
> Subject: Re: QMI modems with MM-master branch error
>
> On Fri, May 5, 2017 at 1:36 PM, Penalva, Salvador <Salvador.Penalva at d
> igi.com> wrote:
> > ModemManager[918]: <info> Modem
> > /org/freedesktop/ModemManager1/Modem/0: state changed (searching
> > ->
> > registered)
> > ModemManager[918]: <info> Simple connect state (6/8): Bearer
> > ModemManager[918]: <info> Simple connect state (7/8): Connect
> > ModemManager[918]: <info> Modem
> > /org/freedesktop/ModemManager1/Modem/0: state changed (registered
> > ->
> > connecting)
> > ModemManager[918]: [/dev/cdc-wdm0] Allocating new client ID...
> > ModemManager[918]: [/dev/cdc-wdm0] Registered 'wds' (version 1.36)
> > client with ID '11'
> > ModemManager[918]: <info> Modem
> > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
> > changed (home -> idle)
> > ModemManager[918]: <info> Modem
> > /org/freedesktop/ModemManager1/Modem/0: state changed (connecting
> > ->
> > disconnecting)
> > ModemManager[918]: <warn> Error disconnecting bearer
> > '/org/freedesktop/ModemManager1/Bearer/0': 'Couldn't disconnect QMI
> > bearer: this bearer is not connected'. Will assume disconnected
> > anyway.
> > error: couldn't connect the modem:
> > 'GDBus.Error:org.freedesktop.ModemManager1.Error.Core.Cancelled:
> > Connection setup operation has been cancelled'
> > ModemManager[918]: <info> Modem
> > /org/freedesktop/ModemManager1/Modem/0: state changed (disconnecting
> > -> enabled)
>
> This issue seems unrelated to the original bug; it looks like the
> modem registration is going away (home->idle) just in the middle of a
> connection attempt, so the connection attempt is cancelled.
>
>
> --
> Aleksander
> https://aleksander.es
> _______________________________________________
> ModemManager-devel mailing list
> ModemManager-devel at lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel
More information about the ModemManager-devel
mailing list