> On 17 April 2017 at 18:32 Dan Williams <[email protected]> wrote:
>
> On Sat, 2017-04-15 at 13:11 +0100, Colin Helliwell wrote:
>
> > I have NM setup with ModemManager and GSM modem, and can bring up the
> > connection. But when I enable a SIM PIN lock, the first 'nmcli conn
> > up' from reboot fails.
> > I can see that the modem is being unlocked ok, and is indeed
> > registered afterwards. And a retry of the 'conn up' also works.
> > I wonder if there's some sequence/timing issue on the first time,
> > when the modem has to be brought out of locked state. (I leave the
> > enabling to NM/MM; with the PIN in the NM connection settings).
> >
> > NM log is below. I *think* the point at which it goes awry is
> > indicated by the
> > 'enabling' --> 'disabled' (reason: unknown) @ 12:51:37
> > Unable to spot at the MM end of things [these logs omitted here]
> > what's triggering this change. Could it just be a timeout? (circa
> > 20secs)
>
> Can you grab MM debug logs for this sequence too? I can't see what it
> would be from the NM side, maybe having both together would help.
>
> Dan
>
Attached.
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.8252]
agent-manager: req[0x1c4e918, :1.9/nmcli-connect/0]: requesting permissions
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.8283]
agent-manager: req[0x1c4e918, :1.9/nmcli-connect/0]: agent registered
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.8367]
policy: re-enabling autoconnect for all connections with failed secrets
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.8477]
active-connection[0x1c3bdd0]: set device "ttyMux1" [0x1c3e3b0]
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.8500]
device[0x1c3e3b0] (ttyMux1): add_pending_action (1): 'activation-0x1c3bdd0'
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.8583]
active-connection[0x1c3bdd0]: constructed (NMActRequest, version-id 2, type
managed)
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.8611]
device[0x1c3e3b0] (ttyMux1): add_pending_action (2): 'autoactivate'
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.8634]
device[0x1c3e3b0] (ttyMux1): remove_pending_action (1): 'autoactivate'
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.8645]
device[0x1c3e3b0] (ttyMux1): unmanaged: flags set to
[!sleeping,!loopback,!platform-init,!user-explicit,!user-settings=0x0/0x79/managed],
set-managed [user-explicit=0x20], reason user-requested)
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <info> [1492257074.8820]
device (ttyMux1): Activation: starting connection 'Vodafone'
(e0f97177-2f8e-4ed4-9942-7b4e499397cc)
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.8845]
device[0x1c3e3b0] (ttyMux1): activation-stage: schedule
activate_stage1_device_prepare,2 (id 204)
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.8903]
create NMAuditManager singleton (0x75300ec0)
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <info> [1492257074.8926]
audit: op="connection-activate" uuid="e0f97177-2f8e-4ed4-9942-7b4e499397cc"
name="Vodafone" pid=1383 uid=0 result="success"
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.9030]
device[0x1c3e3b0] (ttyMux1): activation-stage: invoke
activate_stage1_device_prepare,2 (id 204)
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <info> [1492257074.9036]
device (ttyMux1): state change: disconnected -> prepare (reason 'none') [30 40
0]
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.9105]
active-connection[0x1c3bdd0]: set state activating (was unknown)
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.9164]
active-connection[0x1c3bdd0]: check-master-ready: not signalling (state
activating, no master)
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.9216]
Secrets requested for connection /org/freedesktop/NetworkManager/Settings/2
(Vodafone/gsm)
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.9219]
agent-manager: req[0x1c4e918, :1.9/nmcli-connect/0]: agent allowed for secrets
request [0x1c5ca18/"Vodafone"/"gsm"]
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.9222]
settings-connection[0x75302fa0,e0f97177-2f8e-4ed4-9942-7b4e499397cc]:
(gsm:0x1c5ca18) secrets requested flags 0x5 hints 'pin'
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <info> [1492257074.9224]
device (ttyMux1): state change: prepare -> need-auth (reason 'none') [40 60 0]
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.9358]
device[0x1c3e3b0] (ttyMux1): activation-stage: complete
activate_stage1_device_prepare,2 (id 204)
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.9606]
agent-manager: ([0x1c5ca18/"Vodafone"/"gsm"]) system settings secrets sufficient
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.9669]
settings-connection[0x75302fa0,e0f97177-2f8e-4ed4-9942-7b4e499397cc]:
(gsm:0x1c4d880) existing secrets returned
Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257074.9691]
settings-connection[0x75302fa0,e0f97177-2f8e-4ed4-9942-7b4e499397cc]:
(gsm:0x1c4d880) secrets request completed
Apr 15 12:51:15 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257075.0033]
settings-connection[0x75302fa0,e0f97177-2f8e-4ed4-9942-7b4e499397cc]:
(gsm:0x1c4d880) new agent secrets processed
Apr 15 12:51:15 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257075.0084]
device[0x1c3e3b0] (ttyMux1): activation-stage: schedule
activate_stage1_device_prepare,2 (id 219)
Apr 15 12:51:15 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257075.0744]
device[0x1c3e3b0] (ttyMux1): activation-stage: invoke
activate_stage1_device_prepare,2 (id 219)
Apr 15 12:51:15 wg2xx-tx6s NetworkManager[1154]: <info> [1492257075.0770]
device (ttyMux1): state change: need-auth -> prepare (reason 'none') [60 40 0]
Apr 15 12:51:15 wg2xx-tx6s ModemManager[1186]: <debug> [1492257075.087537]
[src/mm-port-serial.c:1092] mm_port_serial_open(): (ttyMux1) opening serial
port...
Apr 15 12:51:15 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257075.0902]
device[0x1c3e3b0] (ttyMux1): activation-stage: complete
activate_stage1_device_prepare,2 (id 219)
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.215734]
[src/mm-port-serial.c:366] real_config_fd(): (ttyMux1): setting up baudrate:
57600
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.216079]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 1 (open)
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.216466]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPIN="1234"<CR>'
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.237386]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT+CPIN='
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.240453]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"1234"<CR>'
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.299374]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.299856]
[src/mm-broadband-modem.c:1334] modem_load_unlock_required(): checking if
unlock required...
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.300056]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.300298]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.300547]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPIN?<CR>'
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.318118]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT+CPI'
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.320867]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'N?<CR>'
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.340710]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <--
'<CR><LF>ERROR<CR><LF>'
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.341046]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.341246]
[src/mm-iface-modem.c:268] load_unlock_required_ready(): Couldn't check if
unlock required: 'Unknown error'
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.341572]
[src/mm-iface-modem.c:292] load_unlock_required_ready(): Retrying (1) unlock
required check
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.341751]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 0
(close)
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.341880]
[src/mm-port-serial.c:1295] _close_internal(): (ttyMux1) closing serial port...
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <warn> [1492257077.341999]
[src/mm-port-serial.c:1308] _close_internal(): (ttyMux1): serial port
closing_wait was reset!
Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: <debug> [1492257077.350581]
[src/mm-port-serial.c:1343] _close_internal(): (ttyMux1) serial port closed
Apr 15 12:51:19 wg2xx-tx6s ModemManager[1186]: <debug> [1492257079.888665]
[src/mm-broadband-modem.c:1334] modem_load_unlock_required(): checking if
unlock required...
Apr 15 12:51:19 wg2xx-tx6s ModemManager[1186]: <debug> [1492257079.888903]
[src/mm-port-serial.c:1092] mm_port_serial_open(): (ttyMux1) opening serial
port...
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <debug> [1492257082.095751]
[src/mm-port-serial.c:366] real_config_fd(): (ttyMux1): setting up baudrate:
57600
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <debug> [1492257082.096090]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 1 (open)
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <debug> [1492257082.096440]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPIN?<CR>'
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <debug> [1492257082.107496]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT+CP'
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <debug> [1492257082.108600]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'IN?'
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <debug> [1492257082.110204]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR>'
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <debug> [1492257082.130418]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CPIN:
READY<CR><LF>'
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <debug> [1492257082.134377]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <debug> [1492257082.134900]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 0
(close)
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <debug> [1492257082.135046]
[src/mm-port-serial.c:1295] _close_internal(): (ttyMux1) closing serial port...
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <warn> [1492257082.135163]
[src/mm-port-serial.c:1308] _close_internal(): (ttyMux1): serial port
closing_wait was reset!
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <debug> [1492257082.143741]
[src/mm-port-serial.c:1343] _close_internal(): (ttyMux1) serial port closed
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <debug> [1492257082.144122]
[src/mm-iface-modem.c:3092] update_lock_info_context_step(): SIM is ready,
running after SIM unlock step...
Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: <debug> [1492257082.144346]
[src/mm-port-serial.c:1092] mm_port_serial_open(): (ttyMux1) opening serial
port...
Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: <debug> [1492257084.285725]
[src/mm-port-serial.c:366] real_config_fd(): (ttyMux1): setting up baudrate:
57600
Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: <debug> [1492257084.286067]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 1 (open)
Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: <debug> [1492257084.286451]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): -->
'AT^SIND="simstatus",1<CR>'
Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: <debug> [1492257084.315147]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SIND="simstatu'
Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: <debug> [1492257084.318116]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 's",1<CR>'
Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: <debug> [1492257084.342413]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <--
'<CR><LF>ERROR<CR><LF>'
Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: <debug> [1492257084.342749]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: <debug> [1492257084.343001]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 0
(close)
Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: <debug> [1492257084.343137]
[src/mm-port-serial.c:1295] _close_internal(): (ttyMux1) closing serial port...
Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: <warn> [1492257084.343257]
[src/mm-port-serial.c:1308] _close_internal(): (ttyMux1): serial port
closing_wait was reset!
Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: <debug> [1492257084.351802]
[src/mm-port-serial.c:1343] _close_internal(): (ttyMux1) serial port closed
Apr 15 12:51:25 wg2xx-tx6s ModemManager[1186]: <debug> [1492257085.887900]
[src/mm-port-serial.c:1092] mm_port_serial_open(): (ttyMux1) opening serial
port...
Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: <debug> [1492257088.035748]
[src/mm-port-serial.c:366] real_config_fd(): (ttyMux1): setting up baudrate:
57600
Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: <debug> [1492257088.036086]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 1 (open)
Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: <debug> [1492257088.036432]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): -->
'AT^SIND="simstatus",1<CR>'
Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: <debug> [1492257088.062834]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SIND="simstatus"'
Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: <debug> [1492257088.065973]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- ',1<CR>'
Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: <debug> [1492257088.084107]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <--
'<CR><LF>ERROR<CR><LF>'
Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: <debug> [1492257088.085910]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: <debug> [1492257088.086165]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 0
(close)
Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: <debug> [1492257088.086293]
[src/mm-port-serial.c:1295] _close_internal(): (ttyMux1) closing serial port...
Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: <warn> [1492257088.086415]
[src/mm-port-serial.c:1308] _close_internal(): (ttyMux1): serial port
closing_wait was reset!
Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: <debug> [1492257088.094946]
[src/mm-port-serial.c:1343] _close_internal(): (ttyMux1) serial port closed
Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: <debug> [1492257088.887359]
[src/mm-port-serial.c:1092] mm_port_serial_open(): (ttyMux1) opening serial
port...
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.015739]
[src/mm-port-serial.c:366] real_config_fd(): (ttyMux1): setting up baudrate:
57600
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.016087]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 1 (open)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.016461]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): -->
'AT+CSIM=10,"0020000100"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.047683]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT+CSIM=10,"002000'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.050172]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '0100'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.052515]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.070491]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CSIM:
4,"63C3"<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.073212]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.073910]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.074173]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.074424]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): -->
'AT+CSIM=10,"002C000100"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.107601]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT+CSIM=10,"002C00'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.110012]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '0100'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.112342]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.124030]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CSIM:
4,"63CA"<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.126810]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.127504]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.127763]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.128010]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): -->
'AT+CSIM=10,"0020008100"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.161357]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT+CSIM=10,"00'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.164144]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '20008100"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.178610]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CSIM:
4,"6A88"<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.182477]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <warn> [1492257091.183102]
[plugins/cinterion/mm-broadband-modem-cinterion.c:1453]
load_unlock_retries_ready(): Parse error in step 2: Could not parse reponse
'+CSIM: 4,"6A88"'.
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.183234]
[plugins/cinterion/mm-broadband-modem-cinterion.c:1458]
load_unlock_retries_ready(): Couldn't parse retry count value for lock
'sim-pin2'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.183423]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.183660]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.183915]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): -->
'AT+CSIM=10,"002C008100"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.221577]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT+CSIM=10,"002C008'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.224006]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '100'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.226450]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.242644]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CSIM:
4,"6A88"<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.245460]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <warn> [1492257091.246208]
[plugins/cinterion/mm-broadband-modem-cinterion.c:1453]
load_unlock_retries_ready(): Parse error in step 3: Could not parse reponse
'+CSIM: 4,"6A88"'.
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.246337]
[plugins/cinterion/mm-broadband-modem-cinterion.c:1458]
load_unlock_retries_ready(): Couldn't parse retry count value for lock
'sim-puk2'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.246523]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.246761]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.247014]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="SC"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.270979]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPIC="'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.273721]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'SC"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.282862]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <--
'<CR><LF>ERROR<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.283200]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.283393]
[plugins/cinterion/mm-broadband-modem-cinterion.c:1430]
load_unlock_retries_ready(): Couldn't load retry count for lock 'sim-pin':
Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.283592]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.283831]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.284068]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="SC",1<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.311347]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPIC='
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.314099]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"SC",1<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.323228]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <--
'<CR><LF>ERROR<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.323561]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.323752]
[plugins/cinterion/mm-broadband-modem-cinterion.c:1430]
load_unlock_retries_ready(): Couldn't load retry count for lock 'sim-puk':
Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.323948]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.324188]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.324435]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="P2"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.349599]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPI'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.352317]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'C="P2"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.361614]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <--
'<CR><LF>ERROR<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.361956]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.362147]
[plugins/cinterion/mm-broadband-modem-cinterion.c:1430]
load_unlock_retries_ready(): Couldn't load retry count for lock 'sim-pin2':
Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.362343]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.362574]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.362812]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="P2",1<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.390551]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPIC='
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.393338]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"P2",1<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.402442]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <--
'<CR><LF>ERROR<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.402774]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.402967]
[plugins/cinterion/mm-broadband-modem-cinterion.c:1430]
load_unlock_retries_ready(): Couldn't load retry count for lock 'sim-puk2':
Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.403165]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.403395]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.403635]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="PS"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.428849]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPI'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.431586]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'C="PS"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.440820]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <--
'<CR><LF>ERROR<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.442877]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.443104]
[plugins/cinterion/mm-broadband-modem-cinterion.c:1430]
load_unlock_retries_ready(): Couldn't load retry count for lock 'ph-fsim-pin':
Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.443310]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.443547]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.443790]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="PS",1<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.469320]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPIC='
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.472056]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"PS",1<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.481293]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <--
'<CR><LF>ERROR<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.481626]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.481817]
[plugins/cinterion/mm-broadband-modem-cinterion.c:1430]
load_unlock_retries_ready(): Couldn't load retry count for lock 'ph-fsim-puk':
Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.482016]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.482250]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.482486]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="PN"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.507441]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPIC='
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.510160]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"PN"<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.519450]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <--
'<CR><LF>ERROR<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.519786]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.519976]
[plugins/cinterion/mm-broadband-modem-cinterion.c:1430]
load_unlock_retries_ready(): Couldn't load retry count for lock 'ph-net-pin':
Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.520174]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.520412]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.520649]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="PN",1<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.548569]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPIC'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.551308]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '="PN",1<CR>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.560508]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <--
'<CR><LF>ERROR<CR><LF>'
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.562563]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.562789]
[plugins/cinterion/mm-broadband-modem-cinterion.c:1430]
load_unlock_retries_ready(): Couldn't load retry count for lock 'ph-net-puk':
Unknown error
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.563644]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 0
(close)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.563800]
[src/mm-port-serial.c:1295] _close_internal(): (ttyMux1) closing serial port...
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <warn> [1492257091.563923]
[src/mm-port-serial.c:1308] _close_internal(): (ttyMux1): serial port
closing_wait was reset!
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.572547]
[src/mm-port-serial.c:1343] _close_internal(): (ttyMux1) serial port closed
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <info> [1492257091.580300]
[src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (locked -> initializing)
Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: <debug> [1492257091.592076]
[src/mm-port-serial.c:1092] mm_port_serial_open(): (ttyMux1) opening serial
port...
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.725741]
[src/mm-port-serial.c:366] real_config_fd(): (ttyMux1): setting up baudrate:
57600
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.726080]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 1 (open)
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.726206]
[src/mm-port-serial-at.c:495] mm_port_serial_at_run_init_sequence(): (ttyMux1):
running init sequence...
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.726546]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.726786]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.727282]
[src/mm-broadband-modem.c:1607] modem_load_supported_modes(): loading supported
modes...
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.727514]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 4 (open)
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.727806]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATE0<CR>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.742078]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ATE0'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.743624]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.757896]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.758387]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATV1<CR>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.789487]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.789972]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMEE=1<CR>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.821686]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.822168]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATX4<CR>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.853054]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.853541]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT&C1<CR>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.884915]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.885427]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATE0<CR>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.916190]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.916606]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 3
(close)
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.916883]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMEE=1<CR>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.947754]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.948152]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.948421]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT*CNTI=2<CR>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.981051]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CME ERROR:
100<CR><LF>'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.981456]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.981643]
[src/mm-broadband-modem.c:1541] supported_modes_cnti_ready(): Generic query of
supported 3GPP networks with *CNTI failed: 'Unknown error'
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.981836]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.982065]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: <debug> [1492257093.982310]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+WS46=?<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.013066]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CME ERROR:
100<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.013478]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.013669]
[src/mm-broadband-modem.c:1465] supported_modes_ws46_test_ready(): Generic
query of supported 3GPP networks with WS46=? failed: 'Unknown error'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <warn> [1492257094.013821]
[src/mm-iface-modem.c:3999] load_supported_modes_ready(): couldn't load
Supported Modes: 'Couldn't retrieve supported modes'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.014023]
[src/mm-broadband-modem.c:1681] modem_load_supported_ip_families(): loading
supported IP families...
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.014252]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.014516]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.014753]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CGDCONT=?<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.053827]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CGDCONT:
(1-11),"IP",,,0,0<CR><LF><CR><LF>+CGDCONT:
(1-11),"IPV6",,,(0,1,2),(0,1,2,3,4)<CR><LF><CR><LF>+CGDCONT:
(1-11),"IPV4V6",,,(0,1,2),(0,1,2,3,4)<CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.055042]
[src/mm-base-sim.c:1074] load_imsi(): loading IMSI...
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.055261]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.055506]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.060004]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CIMI<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.081428]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <--
'<CR><LF>234159108784146<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.086000]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.086446]
[src/mm-base-sim.c:1063] load_imsi_finish(): loaded IMSI: 234159108784146
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.086733]
[src/mm-base-sim.c:1194] load_operator_identifier(): loading Operator ID...
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.086932]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.087182]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.091348]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): -->
'AT+CRSM=176,28589,0,0,4<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.156633]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CRSM:
144,0,"00000102"<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.162421]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.163316]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.169806]
[src/mm-broadband-modem.c:1212] modem_load_own_numbers(): loading own numbers...
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.170051]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.170389]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CNUM<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.233462]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.234514]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.237079]
[src/mm-broadband-modem.c:3284] modem_3gpp_load_imei(): loading IMEI...
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.237298]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.237625]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CGSN<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.273755]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <--
'<CR><LF>357040069466469<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.277197]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.277668]
[src/mm-broadband-modem.c:3275] modem_3gpp_load_imei_finish(): loaded IMEI:
357040069466469
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.277936]
[src/mm-broadband-modem.c:3443] modem_3gpp_load_enabled_facility_locks():
loading enabled facility locks...
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.278117]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.278335]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.278581]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK=?<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.313950]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CLCK:
("AO","OI","AI","IR","OX","AB","AG","AC","PS","PN","PU","PP","PC","SC","FD")<CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.314795]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.315050]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.315303]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="SC",2<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.341646]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CLCK:
1<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.345406]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.346171]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.346427]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.346676]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="FD",2<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.374713]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CLCK:
0<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.378283]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.378929]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.379182]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.379433]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="PS",2<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.407742]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CLCK:
0<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.411284]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.411910]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.412159]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.412411]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="PN",2<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.440632]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CLCK:
0<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.444431]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.445059]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.445310]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.445753]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="PU",2<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.473529]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CLCK:
0<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.477254]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.477891]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.478142]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.478392]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="PP",2<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.506639]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CLCK:
0<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.510153]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.510786]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.511036]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.511281]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="PC",2<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.539701]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CLCK:
0<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.542966]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.550862]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.552904]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.553258]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CUSD=?<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.577647]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CUSD:
(0-2)<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.580758]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.587545]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.601317]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.603656]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CNMI=?<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.633820]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CNMI:
(0-2),(0-1),(0-3),(0,2),(0-1)<CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.634803]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.635076]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.635327]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPMS=?<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.668297]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CPMS:
("BM","ME","SM","SR"),("ME","SM"),("BM","ME","SM","SR")<CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.669235]
[src/mm-iface-modem-messaging.c:1149] load_supported_storages_ready():
Supported storages loaded:
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.669360]
[src/mm-iface-modem-messaging.c:1150] load_supported_storages_ready(): mem1
(list/read/delete) storages: 'bm, me, sm, sr'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.669459]
[src/mm-iface-modem-messaging.c:1151] load_supported_storages_ready(): mem2
(write/send) storages: 'me, sm'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.669549]
[src/mm-iface-modem-messaging.c:1152] load_supported_storages_ready(): mem3
(reception) storages: 'bm, me, sm, sr'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.669914]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.670173]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.670415]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPMS?<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.698272]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CPMS:
"SM",0,25,"SM",0,25,"SM",0,25<CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.699078]
[src/mm-broadband-modem.c:5334] cpms_query_ready(): Current storages
initialized:
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.699235]
[src/mm-broadband-modem.c:5336] cpms_query_ready(): mem1 (list/read/delete)
storages: 'sm'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.699349]
[src/mm-broadband-modem.c:5338] cpms_query_ready(): mem2 (write/send)
storages: 'sm'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.699471]
[src/mm-iface-modem-messaging.c:1232] init_current_storages_ready(): Current
storages initialized
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.706383]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.707371]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.707718]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATH<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.729338]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.736005]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.736950]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.737294]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CTZU=1<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.762632]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.763205]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CCLK?<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.796550]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CCLK:
"04/01/01,00:02:28"<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.799003]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.805195]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.806427]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.806784]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CESQ=?<CR>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.833437]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CME ERROR:
100<CR><LF>'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.833833]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.834030]
[src/mm-iface-modem-signal.c:428] check_support_ready(): Extended signal
support check failed: 'Unknown error'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.834206]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.834436]
[src/mm-broadband-modem.c:9931] iface_modem_signal_initialize_ready(): Couldn't
initialize interface: 'Extended Signal information not supported'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.836278]
[src/mm-broadband-modem.c:9932] iface_modem_oma_initialize_ready(): Couldn't
initialize interface: 'OMA not supported'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.836804]
[src/mm-broadband-modem.c:9933] iface_modem_firmware_initialize_ready():
Couldn't initialize interface: 'Firmware interface not available'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <info> [1492257094.837136]
[src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (initializing -> disabled)
Apr 15 12:51:34 wg2xx-tx6s NetworkManager[1154]: <info> [1492257094.8482]
(ttyMux1): modem state changed, 'locked' --> 'disabled' (reason: unknown)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.858104]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 0
(close)
Apr 15 12:51:34 wg2xx-tx6s NetworkManager[1154]: <info> [1492257094.8492]
(ttyMux1): modem state changed, 'disabled' --> 'enabling' (reason: user
preference)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.858286]
[src/mm-port-serial.c:1295] _close_internal(): (ttyMux1) closing serial port...
Apr 15 12:51:34 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257094.8494]
device[0x1c3e3b0] (ttyMux1): add_pending_action (2): 'recheck-available'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <warn> [1492257094.858410]
[src/mm-port-serial.c:1308] _close_internal(): (ttyMux1): serial port
closing_wait was reset!
Apr 15 12:51:34 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257094.8516]
modem-broadband[ttyMux1]: launching connection with ip type 'ipv4' (try 1)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.867310]
[src/mm-port-serial.c:1343] _close_internal(): (ttyMux1) serial port closed
Apr 15 12:51:34 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257094.8530]
device[0x1c3e3b0] (ttyMux1): remove_pending_action (1): 'recheck-available'
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <info> [1492257094.868600]
[src/mm-iface-modem-simple.c:641] connect_auth_ready(): Simple connect
started...
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.868756]
[src/mm-iface-modem-simple.c:651] connect_auth_ready(): PIN: 1234
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.868872]
[src/mm-iface-modem-simple.c:653] connect_auth_ready(): Operator ID:
unspecified
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.868989]
[src/mm-iface-modem-simple.c:655] connect_auth_ready(): Allowed roaming: yes
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.869101]
[src/mm-iface-modem-simple.c:657] connect_auth_ready(): APN:
wap.vodafone.co.uk
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.869226]
[src/mm-iface-modem-simple.c:662] connect_auth_ready(): IP family: ipv4
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.869335]
[src/mm-iface-modem-simple.c:673] connect_auth_ready(): Allowed
authentication: unspecified
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.869444]
[src/mm-iface-modem-simple.c:675] connect_auth_ready(): User: unspecified
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.869549]
[src/mm-iface-modem-simple.c:677] connect_auth_ready(): Password: unspecified
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.869655]
[src/mm-iface-modem-simple.c:679] connect_auth_ready(): Number: unspecified
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <info> [1492257094.869751]
[src/mm-iface-modem-simple.c:461] connection_step(): Simple connect state
(3/8): Enable
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <info> [1492257094.870057]
[src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling)
Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: <debug> [1492257094.882059]
[src/mm-port-serial.c:1092] mm_port_serial_open(): (ttyMux1) opening serial
port...
Apr 15 12:51:36 wg2xx-tx6s ModemManager[1186]: <debug> [1492257096.995741]
[src/mm-port-serial.c:366] real_config_fd(): (ttyMux1): setting up baudrate:
57600
Apr 15 12:51:36 wg2xx-tx6s ModemManager[1186]: <debug> [1492257096.996087]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 1 (open)
Apr 15 12:51:36 wg2xx-tx6s ModemManager[1186]: <debug> [1492257096.996218]
[src/mm-broadband-modem.c:8849] enabling_started(): Flashing primary AT port
before enabling...
Apr 15 12:51:36 wg2xx-tx6s ModemManager[1186]: <debug> [1492257096.996584]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:36 wg2xx-tx6s ModemManager[1186]: <debug> [1492257096.996712]
[src/mm-broadband-modem.c:8849] enabling_started(): Flashing primary AT port
before enabling...
Apr 15 12:51:36 wg2xx-tx6s ModemManager[1186]: <debug> [1492257096.997028]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <info> [1492257097.0123]
(ttyMux1): modem state changed, 'enabling' --> 'disabled' (reason: unknown)
Apr 15 12:51:36 wg2xx-tx6s ModemManager[1186]: <info> [1492257096.997308]
[src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (enabling -> disabled)
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <info> [1492257097.0125]
device (ttyMux1): state change: prepare -> disconnected (reason
'user-requested') [40 30 39]
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0128]
device[0x1c3e3b0] (ttyMux1): deactivating device (reason 'user-requested') [39]
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0130]
firewall: [0x1bd8900,remove*:"ttyMux1"]: firewall zone remove ttyMux1:default
(not running, simulate success)
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0132]
firewall: [0x1bd8900,remove*:"ttyMux1"]: complete: drop request simulating
success
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0134]
device[0x1c3e3b0] (ttyMux1): remove_pending_action (1): 'dhcp6' not pending
(expected)
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0140]
device[0x1c3e3b0] (ttyMux1): remove_pending_action (1): 'autoconf6' not pending
(expected)
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0143]
platform-linux: sysctl: failed to open
'/proc/sys/net/ipv6/conf/ttyMux1/disable_ipv6': (2) No such file or directory
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0145]
platform-linux: sysctl: failed to open
'/proc/sys/net/ipv6/conf/ttyMux1/accept_ra': (2) No such file or directory
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.097478]
[src/mm-broadband-modem.c:8738] enabling_flash_done(): Running modem
initialization sequence...
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0148]
platform-linux: sysctl: failed to open
'/proc/sys/net/ipv6/conf/ttyMux1/use_tempaddr': (2) No such file or directory
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.097735]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0150]
modem-broadband[ttyMux1]: notifying ModemManager about the modem disconnection
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.098050]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATZ<CR>'
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0182]
device[0x1c3e3b0] (ttyMux1): ip4-config: update (commit=1, routes-full-sync=1,
new-config=(nil))
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.106252]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ATZ'
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0184]
device[0x1c3e3b0] (ttyMux1): ip6-config: update (commit=1, routes-full-sync=1,
new-config=(nil))
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.110060]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR>'
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0297]
active-connection[0x1c3bdd0]: set state deactivated (was activating)
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0378]
active-connection[0x1c3bdd0]: check-master-ready: not signalling (state
deactivated, no master)
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0380]
device[0x1c3e3b0] (ttyMux1): remove_pending_action (0): 'activation-0x1c3bdd0'
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0386]
modem-broadband[ttyMux1]: notifying ModemManager about the modem disconnection
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0446]
dns-mgr: (update_routing_and_dns): queueing DNS updates (1)
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0450]
dns-mgr: (update_routing_and_dns): DNS configuration did not change
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0452]
dns-mgr: (update_routing_and_dns): no DNS changes to commit (0)
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0454]
device[0x1c3e3b0] (ttyMux1): add_pending_action (1): 'autoactivate'
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0872]
active-connection[0x1c3bdd0]: disposing
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0899]
device[0x1c3e3b0] (ttyMux1): remove_pending_action (0): 'autoactivate'
Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257097.0905]
agent-manager: req[0x1c4e918, :1.9/nmcli-connect/0]: agent unregistered or
disappeared
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.166523]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.166959]
[src/mm-broadband-modem.c:8719] enabling_modem_init_ready(): Giving some time
to settle the modem...
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.167118]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.668118]
[src/mm-port-serial-at.c:495] mm_port_serial_at_run_init_sequence(): (ttyMux1):
running init sequence...
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.668647]
[src/mm-broadband-modem.c:3181] load_power_state(): loading power state...
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.668835]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.669112]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATE0<CR>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.676613]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ATE0'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.677958]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.695442]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.696027]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATV1<CR>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.727097]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.727581]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMEE=1<CR>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.759413]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.759891]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATX4<CR>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.790876]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.791368]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT&C1<CR>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.822626]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.823107]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CFUN?<CR>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.851782]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CFUN:
1,0<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.855467]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.856186]
[src/mm-iface-modem.c:3298] set_power_state(): No need to change power state:
already in 'on' power state
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.856387]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.856711]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.857027]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT\Q3<CR>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.887088]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.887637]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.887907]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.888153]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CSCS=?<CR>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.917615]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CSCS:
("GSM","UCS2")<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.920090]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.920854]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.921122]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.921366]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CSCS="UCS2"<CR>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.953347]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.953816]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.954075]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.954306]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CSCS?<CR>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.983361]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CSCS:
"UCS2"<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.986731]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.987262]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.987516]
[src/mm-broadband-modem.c:9494] enabling_step(): Modem has 3GPP capabilities,
enabling the Modem 3GPP interface...
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.987700]
[src/mm-broadband-modem.c:2675] modem_3gpp_setup_unsolicited_events(): Checking
indicator support...
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.987881]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: <debug> [1492257097.988179]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CIND=?<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.021011]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CIND :
("call",(0,1)), ("roam",(0,1)) <CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.021753]
[src/mm-broadband-modem.c:2637] cind_format_check_ready(): Modem supports
roaming indications via CIND at index '2'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.021979]
[src/mm-broadband-modem.c:2579] set_unsolicited_events_handlers(): (ttyMux1)
Setting 3GPP unsolicited events handlers
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.022205]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.022460]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.022712]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMER=3,0,0,2<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.054534]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CME ERROR:
50<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.054928]
[src/mm-error-helpers.c:131] mm_mobile_equipment_error_for_code(): Invalid
mobile equipment error code: 50
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.055094]
[src/mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code
100: Unknown error
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.055275]
[src/mm-iface-modem-3gpp.c:1667] enable_unsolicited_events_ready(): Enabling
unsolicited events failed: 'Unknown error'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.057112]
[src/mm-broadband-modem.c:3657]
modem_3gpp_setup_unsolicited_registration_events(): (ttyMux1) setting up 3GPP
unsolicited registration messages handlers
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.057378]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.057764]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.058080]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CREG=2<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.086187]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.086698]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.086955]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.087199]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CGREG=2<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.118423]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.118892]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.119232]
[src/mm-broadband-modem.c:9507] enabling_step(): Modem has 3GPP/USSD
capabilities, enabling the Modem 3GPP/USSD interface...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.119506]
[src/mm-broadband-modem.c:4971] set_unsolicited_result_code_handlers():
(ttyMux1) Setting unsolicited result code handlers
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.119825]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.120125]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CUSD=1<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.150501]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.151173]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.155317]
[src/mm-broadband-modem.c:9535] enabling_step(): Modem has location
capabilities, enabling the Location interface...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.155801]
[src/mm-iface-modem-location.c:762] setup_gathering(): Need to enable the
following location sources: '3gpp-lac-ci'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.156281]
[src/mm-iface-modem-3gpp.c:798] mm_iface_modem_3gpp_run_registration_checks():
Running registration checks (CS: 'yes', PS: 'yes', EPS: 'no')
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.156494]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.163203]
[src/mm-broadband-modem.c:9548] enabling_step(): Modem has messaging
capabilities, enabling the Messaging interface...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.163826]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.164124]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CREG?<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.187933]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CREG:
2,1,"035E","02A5F5BE",6<CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <info> [1492257098.188499]
[src/mm-iface-modem-3gpp.c:1197] update_registration_state(): Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed
(unknown -> registering)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.188688]
[src/mm-broadband-modem.c:3486] modem_3gpp_load_operator_code(): loading
Operator Code...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.188871]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 4 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.189180]
[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: '35E', Cell ID: '2A5F5BE')
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.189618]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 5 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.189839]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 4
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.190114]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMGF=?<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.217014]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CMGF:
(0-1)<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.220129]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.220877]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 5 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.221109]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 4
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.221380]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): -->
'AT+COPS=3,2;+COPS?<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.261236]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+COPS:
0,2,"00320033003400310035",2<CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.262065]
[src/mm-broadband-modem.c:3477] modem_3gpp_load_operator_code_finish(): loaded
Operator Code: 23415
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.262495]
[src/mm-iface-modem-location.c:297] notify_3gpp_location_update(): Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '234', MNC:
'15', Location area code: '35E', Cell ID: '2A5F5BE')
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.262648]
[src/mm-broadband-modem.c:3529] modem_3gpp_load_operator_name(): loading
Operator Name...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.262821]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 5 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.263029]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 4
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.269708]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CGREG?<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.295117]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CGREG:
2,1,"035E","02A5F5BE",6,"02"<CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.296062]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 3
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.296418]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMGF=0<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.327047]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.327462]
[src/mm-broadband-modem.c:5651] cmgf_set_ready(): Successfully set preferred
SMS mode: 'PDU'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.327981]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 4 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.328234]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 3
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.332758]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): -->
'AT+COPS=3,0;+COPS?<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.379191]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+COPS:
0,0,"0076006F006400610066006F006E006500200055004B",2<CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.379955]
[src/mm-broadband-modem.c:3520] modem_3gpp_load_operator_name_finish(): loaded
Operator Name: vodafone UK
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.380348]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <info> [1492257098.387104]
[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)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.387571]
[src/mm-iface-modem.c:1602] get_updated_consolidated_state(): Will start
keeping track of state for subsystem '3gpp'
Apr 15 12:51:38 wg2xx-tx6s NetworkManager[1154]: <info> [1492257098.3988]
(ttyMux1): modem state changed, 'disabled' --> 'registered' (reason: unknown)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <info> [1492257098.387747]
[src/mm-iface-modem.c:1433] __iface_modem_update_state_internal(): Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> registered)
Apr 15 12:51:38 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257098.3991]
device[0x1c3e3b0] (ttyMux1): add_pending_action (1): 'recheck-available'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.400312]
[src/mm-iface-modem.c:1357] periodic_signal_quality_check_enable(): Periodic
signal quality checks enabled (interval = 3s)
Apr 15 12:51:38 wg2xx-tx6s NetworkManager[1154]: <debug> [1492257098.3995]
device[0x1c3e3b0] (ttyMux1): remove_pending_action (0): 'recheck-available'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.400515]
[src/mm-broadband-modem.c:2065] modem_load_signal_quality(): loading signal
quality...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.400717]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.400929]
[src/mm-iface-modem.c:1077] periodic_access_technologies_check_enable():
Periodic access technology checks enabled
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.401148]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 4 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.407501]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): -->
'AT+CPMS="SM","ME","ME"<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.454744]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CPMS:
0,25,2,4,2,4<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.462476]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.462968]
[src/mm-broadband-modem.c:6423] modem_messaging_load_initial_sms_parts():
Listing SMS parts in storage 'bm'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.463117]
[src/mm-broadband-modem.c:5533] mm_broadband_modem_lock_sms_storages(): Locking
SMS storages to: mem1 (BM), mem2 (none)...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.463310]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 5 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.463540]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 4
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.463805]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CSQ<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.491196]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CSQ:
6,99<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.494735]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.495324]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 3
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.496164]
[src/mm-iface-modem.c:1206] update_signal_quality(): Modem
/org/freedesktop/ModemManager1/Modem/0: signal quality updated (19)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.496337]
[src/mm-iface-modem.c:1276] signal_quality_check_ready(): Periodic signal
quality checks rescheduled (interval = 30s)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.500614]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SIND?<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.576113]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>^SIND:
service,0,1<CR><LF>^SIND: message,0,0<CR><LF>^SIND: call,0,0<CR><LF>^SIND:
roam,0,0<CR><LF>^SIND: smsfull,0,0<CR><LF>^SIND: rssi,0,1<CR><LF>^SIND:
ciphcall,0,0<CR><LF>^SIND: simdata,0<CR><LF>^SIND:
eons,0,4,"0076006F006400610066006F006E006500200055004B",""<CR><LF>^SIND:
nitz,0,"00310037002F00300034002F00310035002C00310031003A00350031003A00320032",+04,1<CR><LF>^SIND:
psinfo,0,10<CR><LF>^SIND: pacsp,0,99<CR><LF>^SIND: simtray,0,1<CR><LF>^SIND:
vmwait,0,0<CR><LF>^SIND: lsta,0,0<CR><LF>^SIND: dtmf,0,1,0,0,0<CR><LF>^SIND:
ecallco,0,0<CR><LF>^SIND: ecallda,0,0<CR><LF>^SIND:
ecaller,0,0<CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.577533]
[src/mm-iface-modem.c:935] mm_iface_modem_update_access_technologies(): Modem
/org/freedesktop/ModemManager1/Modem/0: access technology changed (unknown ->
hsdpa, hsupa)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.577715]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.581936]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPMS="BM"<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.621567]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CPMS:
0,4,2,4,2,4<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.625947]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.626435]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.626776]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.627110]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMGL=4<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.657875]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.658501]
[src/mm-broadband-modem.c:6423] modem_messaging_load_initial_sms_parts():
Listing SMS parts in storage 'me'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.658649]
[src/mm-broadband-modem.c:5533] mm_broadband_modem_lock_sms_storages(): Locking
SMS storages to: mem1 (ME), mem2 (none)...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.658845]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.659098]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.659353]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPMS="ME"<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.688070]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CPMS:
2,4,2,4,2,4<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.690710]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.691178]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.691514]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.691839]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMGL=4<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.736121]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CMGL:
1,1,,24<CR><LF>0791448720003023040C9144777633877100007130712193740005D4F29C1E03<CR><LF>+CMGL:
2,1,,25<CR><LF>0791448720003023040C9144777633877100007130712173440006D4F29C1EC301<CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.737014]
[src/mm-sms-part-3gpp.c:368] mm_sms_part_3gpp_new_from_binary_pdu(): Parsing
PDU (1)...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.737156]
[src/mm-sms-part-3gpp.c:397] mm_sms_part_3gpp_new_from_binary_pdu(): SMSC
address parsed: '+447802000332'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.737260]
[src/mm-sms-part-3gpp.c:410] mm_sms_part_3gpp_new_from_binary_pdu(): Deliver
type PDU detected
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.737359]
[src/mm-sms-part-3gpp.c:471] mm_sms_part_3gpp_new_from_binary_pdu(): Number
parsed: '+447767337817'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.737459]
[src/mm-sms-part-3gpp.c:575] mm_sms_part_3gpp_new_from_binary_pdu(): PID: 0
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.737550]
[src/mm-sms-part-3gpp.c:586] mm_sms_part_3gpp_new_from_binary_pdu(): user
data encoding is GSM7
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.737641]
[src/mm-sms-part-3gpp.c:614] mm_sms_part_3gpp_new_from_binary_pdu(): user
data length: 5 elements
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.737728]
[src/mm-sms-part-3gpp.c:620] mm_sms_part_3gpp_new_from_binary_pdu(): user
data length: 5 bytes
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.737818]
[src/mm-sms-part-3gpp.c:695] mm_sms_part_3gpp_new_from_binary_pdu(): Decoding
SMS text with '5' elements
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.737906]
[src/mm-sms-part-3gpp.c:244] sms_decode_text(): Converting SMS part text from
GSM7 to UTF8...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.738015]
[src/mm-sms-part-3gpp.c:247] sms_decode_text(): Got UTF-8 text: 'Test1'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.738110]
[src/mm-broadband-modem.c:6356] sms_pdu_part_list_ready(): Correctly parsed PDU
(1)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.738261]
[src/mm-sms-list.c:384] mm_sms_list_take_part(): SMS part at 'me/1' is from a
singlepart SMS
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.741259]
[src/mm-iface-modem-messaging.c:511] sms_added(): Added received SMS at
'/org/freedesktop/ModemManager1/SMS/0'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.750643]
[src/mm-sms-part-3gpp.c:368] mm_sms_part_3gpp_new_from_binary_pdu(): Parsing
PDU (2)...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.750818]
[src/mm-sms-part-3gpp.c:397] mm_sms_part_3gpp_new_from_binary_pdu(): SMSC
address parsed: '+447802000332'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.750916]
[src/mm-sms-part-3gpp.c:410] mm_sms_part_3gpp_new_from_binary_pdu(): Deliver
type PDU detected
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.751015]
[src/mm-sms-part-3gpp.c:471] mm_sms_part_3gpp_new_from_binary_pdu(): Number
parsed: '+447767337817'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.751113]
[src/mm-sms-part-3gpp.c:575] mm_sms_part_3gpp_new_from_binary_pdu(): PID: 0
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.751206]
[src/mm-sms-part-3gpp.c:586] mm_sms_part_3gpp_new_from_binary_pdu(): user
data encoding is GSM7
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.751299]
[src/mm-sms-part-3gpp.c:614] mm_sms_part_3gpp_new_from_binary_pdu(): user
data length: 6 elements
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.751389]
[src/mm-sms-part-3gpp.c:620] mm_sms_part_3gpp_new_from_binary_pdu(): user
data length: 6 bytes
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.751476]
[src/mm-sms-part-3gpp.c:695] mm_sms_part_3gpp_new_from_binary_pdu(): Decoding
SMS text with '6' elements
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.751567]
[src/mm-sms-part-3gpp.c:244] sms_decode_text(): Converting SMS part text from
GSM7 to UTF8...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.751676]
[src/mm-sms-part-3gpp.c:247] sms_decode_text(): Got UTF-8 text: 'Test18'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.751771]
[src/mm-broadband-modem.c:6356] sms_pdu_part_list_ready(): Correctly parsed PDU
(2)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.751944]
[src/mm-sms-list.c:384] mm_sms_list_take_part(): SMS part at 'me/2' is from a
singlepart SMS
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.753396]
[src/mm-iface-modem-messaging.c:511] sms_added(): Added received SMS at
'/org/freedesktop/ModemManager1/SMS/1'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.760888]
[src/mm-broadband-modem.c:6423] modem_messaging_load_initial_sms_parts():
Listing SMS parts in storage 'sm'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.761075]
[src/mm-broadband-modem.c:5533] mm_broadband_modem_lock_sms_storages(): Locking
SMS storages to: mem1 (SM), mem2 (none)...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.761267]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.761515]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.767859]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPMS="SM"<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.799053]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CPMS:
0,25,2,4,2,4<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.810188]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.810675]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.811011]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.811336]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMGL=4<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.845941]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.846584]
[src/mm-broadband-modem.c:6423] modem_messaging_load_initial_sms_parts():
Listing SMS parts in storage 'sr'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.846740]
[src/mm-broadband-modem.c:5533] mm_broadband_modem_lock_sms_storages(): Locking
SMS storages to: mem1 (SR), mem2 (none)...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.846935]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.847181]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.847435]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPMS="SR"<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.876129]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CPMS:
0,4,2,4,2,4<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.879029]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.879505]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.879844]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.880165]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMGL=4<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.911419]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.912159]
[src/mm-broadband-modem.c:5954] set_messaging_unsolicited_events_handlers():
(ttyMux1) Setting messaging unsolicited events handlers
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.912377]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.912799]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.913137]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): -->
'AT+CNMI=2,1,2,2,1<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.946370]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.946846]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.947113]
[src/mm-broadband-modem.c:9561] enabling_step(): Modem has voice capabilities,
enabling the Voice interface...
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.947843]
[src/mm-broadband-modem.c:6591] set_voice_unsolicited_events_handlers():
(ttyMux1) Setting voice unsolicited events handlers
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.948210]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.948528]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLIP=1<CR>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.978320]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: <debug> [1492257098.978924]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CRC=1<CR>'
Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: <debug> [1492257099.010319]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: <debug> [1492257099.010795]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: <debug> [1492257099.011051]
[src/mm-broadband-modem.c:9574] enabling_step(): Modem has time capabilities,
enabling the Time interface...
Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: <debug> [1492257099.014763]
[src/mm-iface-modem-3gpp.c:798] mm_iface_modem_3gpp_run_registration_checks():
Running registration checks (CS: 'yes', PS: 'yes', EPS: 'no')
Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: <debug> [1492257099.015033]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: <debug> [1492257099.015363]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CREG?<CR>'
Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: <debug> [1492257099.042550]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CREG:
2,1,"035E","02A5F5BE",6<CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: <debug> [1492257099.043395]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 3 (open)
Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: <debug> [1492257099.043654]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 2
(close)
Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: <debug> [1492257099.043911]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CGREG?<CR>'
Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: <debug> [1492257099.075003]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CGREG:
2,1,"035E","02A5F5BE",6,"02"<CR><LF><CR><LF>OK<CR><LF>'
Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: <debug> [1492257099.076011]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: <debug> [1492257099.076291]
[src/mm-broadband-modem.c:8871] modem_3gpp_run_registration_checks_ready():
Initial 3GPP registration checks finished
Apr 15 12:51:43 wg2xx-tx6s ModemManager[1186]: <debug> [1492257103.888957]
[src/mm-port-serial.c:1222] mm_port_serial_open(): (ttyMux1) device open count
is 2 (open)
Apr 15 12:51:43 wg2xx-tx6s ModemManager[1186]: <debug> [1492257103.889381]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CCLK?<CR>'
Apr 15 12:51:43 wg2xx-tx6s ModemManager[1186]: <debug> [1492257103.919974]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>+CCLK:
"04/01/01,00:02:37"<CR><LF>'
Apr 15 12:51:43 wg2xx-tx6s ModemManager[1186]: <debug> [1492257103.924887]
[src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '<CR><LF>OK<CR><LF>'
Apr 15 12:51:43 wg2xx-tx6s ModemManager[1186]: <debug> [1492257103.926216]
[src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1
(close)
_______________________________________________
networkmanager-list mailing list
[email protected]
https://mail.gnome.org/mailman/listinfo/networkmanager-list
