Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.8252] agent-manager: req[0x1c4e918, :1.9/nmcli-connect/0]: requesting permissions Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.8283] agent-manager: req[0x1c4e918, :1.9/nmcli-connect/0]: agent registered Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.8367] policy: re-enabling autoconnect for all connections with failed secrets Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.8477] active-connection[0x1c3bdd0]: set device "ttyMux1" [0x1c3e3b0] Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.8500] device[0x1c3e3b0] (ttyMux1): add_pending_action (1): 'activation-0x1c3bdd0' Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.8583] active-connection[0x1c3bdd0]: constructed (NMActRequest, version-id 2, type managed) Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.8611] device[0x1c3e3b0] (ttyMux1): add_pending_action (2): 'autoactivate' Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.8634] device[0x1c3e3b0] (ttyMux1): remove_pending_action (1): 'autoactivate' Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [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]: [1492257074.8820] device (ttyMux1): Activation: starting connection 'Vodafone' (e0f97177-2f8e-4ed4-9942-7b4e499397cc) Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.8845] device[0x1c3e3b0] (ttyMux1): activation-stage: schedule activate_stage1_device_prepare,2 (id 204) Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.8903] create NMAuditManager singleton (0x75300ec0) Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [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]: [1492257074.9030] device[0x1c3e3b0] (ttyMux1): activation-stage: invoke activate_stage1_device_prepare,2 (id 204) Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.9036] device (ttyMux1): state change: disconnected -> prepare (reason 'none') [30 40 0] Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.9105] active-connection[0x1c3bdd0]: set state activating (was unknown) Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.9164] active-connection[0x1c3bdd0]: check-master-ready: not signalling (state activating, no master) Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.9216] Secrets requested for connection /org/freedesktop/NetworkManager/Settings/2 (Vodafone/gsm) Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [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]: [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]: [1492257074.9224] device (ttyMux1): state change: prepare -> need-auth (reason 'none') [40 60 0] Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.9358] device[0x1c3e3b0] (ttyMux1): activation-stage: complete activate_stage1_device_prepare,2 (id 204) Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.9606] agent-manager: ([0x1c5ca18/"Vodafone"/"gsm"]) system settings secrets sufficient Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.9669] settings-connection[0x75302fa0,e0f97177-2f8e-4ed4-9942-7b4e499397cc]: (gsm:0x1c4d880) existing secrets returned Apr 15 12:51:14 wg2xx-tx6s NetworkManager[1154]: [1492257074.9691] settings-connection[0x75302fa0,e0f97177-2f8e-4ed4-9942-7b4e499397cc]: (gsm:0x1c4d880) secrets request completed Apr 15 12:51:15 wg2xx-tx6s NetworkManager[1154]: [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]: [1492257075.0084] device[0x1c3e3b0] (ttyMux1): activation-stage: schedule activate_stage1_device_prepare,2 (id 219) Apr 15 12:51:15 wg2xx-tx6s NetworkManager[1154]: [1492257075.0744] device[0x1c3e3b0] (ttyMux1): activation-stage: invoke activate_stage1_device_prepare,2 (id 219) Apr 15 12:51:15 wg2xx-tx6s NetworkManager[1154]: [1492257075.0770] device (ttyMux1): state change: need-auth -> prepare (reason 'none') [60 40 0] Apr 15 12:51:15 wg2xx-tx6s ModemManager[1186]: [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]: [1492257075.0902] device[0x1c3e3b0] (ttyMux1): activation-stage: complete activate_stage1_device_prepare,2 (id 219) Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257077.216466] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPIN="1234"' Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: [1492257077.237386] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT+CPIN=' Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: [1492257077.240453] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"1234"' Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: [1492257077.299374] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [1492257077.300547] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPIN?' Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: [1492257077.318118] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT+CPI' Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: [1492257077.320867] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'N?' Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: [1492257077.340710] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ERROR' Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257077.341880] [src/mm-port-serial.c:1295] _close_internal(): (ttyMux1) closing serial port... Apr 15 12:51:17 wg2xx-tx6s ModemManager[1186]: [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]: [1492257077.350581] [src/mm-port-serial.c:1343] _close_internal(): (ttyMux1) serial port closed Apr 15 12:51:19 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257082.096440] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPIN?' Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: [1492257082.107496] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT+CP' Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: [1492257082.108600] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'IN?' Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: [1492257082.110204] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '' Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: [1492257082.130418] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CPIN: READY' Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: [1492257082.134377] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: [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]: [1492257082.135046] [src/mm-port-serial.c:1295] _close_internal(): (ttyMux1) closing serial port... Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: [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]: [1492257082.143741] [src/mm-port-serial.c:1343] _close_internal(): (ttyMux1) serial port closed Apr 15 12:51:22 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257084.286451] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SIND="simstatus",1' Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: [1492257084.315147] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SIND="simstatu' Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: [1492257084.318116] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 's",1' Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: [1492257084.342413] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ERROR' Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257084.343137] [src/mm-port-serial.c:1295] _close_internal(): (ttyMux1) closing serial port... Apr 15 12:51:24 wg2xx-tx6s ModemManager[1186]: [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]: [1492257084.351802] [src/mm-port-serial.c:1343] _close_internal(): (ttyMux1) serial port closed Apr 15 12:51:25 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [1492257088.036432] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SIND="simstatus",1' Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: [1492257088.062834] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SIND="simstatus"' Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: [1492257088.065973] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- ',1' Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: [1492257088.084107] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ERROR' Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257088.086293] [src/mm-port-serial.c:1295] _close_internal(): (ttyMux1) closing serial port... Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: [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]: [1492257088.094946] [src/mm-port-serial.c:1343] _close_internal(): (ttyMux1) serial port closed Apr 15 12:51:28 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [1492257091.016461] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CSIM=10,"0020000100"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [1492257091.050172] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '0100' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.052515] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.070491] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CSIM: 4,"63C3"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.073212] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257091.074424] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CSIM=10,"002C000100"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [1492257091.110012] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '0100' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.112342] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.124030] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CSIM: 4,"63CA"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.126810] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257091.128010] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CSIM=10,"0020008100"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [1492257091.164144] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '20008100"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.178610] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CSIM: 4,"6A88"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.182477] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257091.183915] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CSIM=10,"002C008100"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [1492257091.224006] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '100' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.226450] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.242644] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CSIM: 4,"6A88"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.245460] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257091.247014] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="SC"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.270979] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPIC="' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.273721] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'SC"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.282862] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ERROR' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257091.284068] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="SC",1' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.311347] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPIC=' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.314099] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"SC",1' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.323228] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ERROR' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257091.324435] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="P2"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.349599] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPI' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.352317] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'C="P2"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.361614] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ERROR' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257091.362812] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="P2",1' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.390551] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPIC=' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.393338] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"P2",1' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.402442] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ERROR' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257091.403635] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="PS"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.428849] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPI' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.431586] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'C="PS"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.440820] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ERROR' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257091.443790] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="PS",1' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.469320] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPIC=' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.472056] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"PS",1' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.481293] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ERROR' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257091.482486] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="PN"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.507441] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPIC=' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.510160] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '"PN"' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.519450] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ERROR' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257091.520649] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SPIC="PN",1' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.548569] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'AT^SPIC' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.551308] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '="PN",1' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [1492257091.560508] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ERROR' Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [1492257091.563800] [src/mm-port-serial.c:1295] _close_internal(): (ttyMux1) closing serial port... Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [1492257091.572547] [src/mm-port-serial.c:1343] _close_internal(): (ttyMux1) serial port closed Apr 15 12:51:31 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [1492257093.727282] [src/mm-broadband-modem.c:1607] modem_load_supported_modes(): loading supported modes... Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [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]: [1492257093.727806] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATE0' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.742078] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ATE0' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.743624] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.757896] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.758387] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATV1' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.789487] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.789972] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMEE=1' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.821686] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.822168] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATX4' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.853054] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.853541] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT&C1' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.884915] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.885427] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATE0' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.916190] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [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]: [1492257093.916883] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMEE=1' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.947754] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [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]: [1492257093.948421] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT*CNTI=2' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [1492257093.981051] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CME ERROR: 100' Apr 15 12:51:33 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257093.982310] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+WS46=?' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.013066] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CME ERROR: 100' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [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]: [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]: [1492257094.014753] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CGDCONT=?' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.053827] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CGDCONT: (1-11),"IP",,,0,0+CGDCONT: (1-11),"IPV6",,,(0,1,2),(0,1,2,3,4)+CGDCONT: (1-11),"IPV4V6",,,(0,1,2),(0,1,2,3,4)OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.055042] [src/mm-base-sim.c:1074] load_imsi(): loading IMSI... Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.060004] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CIMI' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.081428] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '234159108784146' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.086000] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.086446] [src/mm-base-sim.c:1063] load_imsi_finish(): loaded IMSI: 234159108784146 Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.086733] [src/mm-base-sim.c:1194] load_operator_identifier(): loading Operator ID... Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.091348] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CRSM=176,28589,0,0,4' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.156633] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CRSM: 144,0,"00000102"' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.162421] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [1492257094.169806] [src/mm-broadband-modem.c:1212] modem_load_own_numbers(): loading own numbers... Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [1492257094.170389] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CNUM' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.233462] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [1492257094.237079] [src/mm-broadband-modem.c:3284] modem_3gpp_load_imei(): loading IMEI... Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [1492257094.237625] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CGSN' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.273755] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '357040069466469' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.277197] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257094.278581] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK=?' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.313950] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CLCK: ("AO","OI","AI","IR","OX","AB","AG","AC","PS","PN","PU","PP","PC","SC","FD")OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.315303] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="SC",2' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.341646] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CLCK: 1' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.345406] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.346676] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="FD",2' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.374713] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CLCK: 0' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.378283] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.379433] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="PS",2' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.407742] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CLCK: 0' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.411284] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.412411] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="PN",2' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.440632] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CLCK: 0' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.444431] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.445753] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="PU",2' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.473529] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CLCK: 0' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.477254] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.478392] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="PP",2' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.506639] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CLCK: 0' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.510153] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.511281] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLCK="PC",2' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.539701] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CLCK: 0' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.542966] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.553258] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CUSD=?' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.577647] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CUSD: (0-2)' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.580758] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.603656] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CNMI=?' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.633820] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CNMI: (0-2),(0-1),(0-3),(0,2),(0-1)OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.635327] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPMS=?' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.668297] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CPMS: ("BM","ME","SM","SR"),("ME","SM"),("BM","ME","SM","SR")OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [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]: [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]: [1492257094.670415] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPMS?' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.698272] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CPMS: "SM",0,25,"SM",0,25,"SM",0,25OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.699078] [src/mm-broadband-modem.c:5334] cpms_query_ready(): Current storages initialized: Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [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]: [1492257094.707718] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATH' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.729338] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.737294] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CTZU=1' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.762632] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.763205] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CCLK?' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.796550] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CCLK: "04/01/01,00:02:28"' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.799003] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257094.806784] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CESQ=?' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.833437] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CME ERROR: 100' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [1492257094.8482] (ttyMux1): modem state changed, 'locked' --> 'disabled' (reason: unknown) Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [1492257094.8492] (ttyMux1): modem state changed, 'disabled' --> 'enabling' (reason: user preference) Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.858286] [src/mm-port-serial.c:1295] _close_internal(): (ttyMux1) closing serial port... Apr 15 12:51:34 wg2xx-tx6s NetworkManager[1154]: [1492257094.8494] device[0x1c3e3b0] (ttyMux1): add_pending_action (2): 'recheck-available' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [1492257094.8516] modem-broadband[ttyMux1]: launching connection with ip type 'ipv4' (try 1) Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.867310] [src/mm-port-serial.c:1343] _close_internal(): (ttyMux1) serial port closed Apr 15 12:51:34 wg2xx-tx6s NetworkManager[1154]: [1492257094.8530] device[0x1c3e3b0] (ttyMux1): remove_pending_action (1): 'recheck-available' Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.868600] [src/mm-iface-modem-simple.c:641] connect_auth_ready(): Simple connect started... Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.868756] [src/mm-iface-modem-simple.c:651] connect_auth_ready(): PIN: 1234 Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.868872] [src/mm-iface-modem-simple.c:653] connect_auth_ready(): Operator ID: unspecified Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.868989] [src/mm-iface-modem-simple.c:655] connect_auth_ready(): Allowed roaming: yes Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [1492257094.869226] [src/mm-iface-modem-simple.c:662] connect_auth_ready(): IP family: ipv4 Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.869335] [src/mm-iface-modem-simple.c:673] connect_auth_ready(): Allowed authentication: unspecified Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.869444] [src/mm-iface-modem-simple.c:675] connect_auth_ready(): User: unspecified Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.869549] [src/mm-iface-modem-simple.c:677] connect_auth_ready(): Password: unspecified Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [1492257094.869655] [src/mm-iface-modem-simple.c:679] connect_auth_ready(): Number: unspecified Apr 15 12:51:34 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [1492257097.0123] (ttyMux1): modem state changed, 'enabling' --> 'disabled' (reason: unknown) Apr 15 12:51:36 wg2xx-tx6s ModemManager[1186]: [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]: [1492257097.0125] device (ttyMux1): state change: prepare -> disconnected (reason 'user-requested') [40 30 39] Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0128] device[0x1c3e3b0] (ttyMux1): deactivating device (reason 'user-requested') [39] Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0130] firewall: [0x1bd8900,remove*:"ttyMux1"]: firewall zone remove ttyMux1:default (not running, simulate success) Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0132] firewall: [0x1bd8900,remove*:"ttyMux1"]: complete: drop request simulating success Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0134] device[0x1c3e3b0] (ttyMux1): remove_pending_action (1): 'dhcp6' not pending (expected) Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0140] device[0x1c3e3b0] (ttyMux1): remove_pending_action (1): 'autoconf6' not pending (expected) Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [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]: [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]: [1492257097.097478] [src/mm-broadband-modem.c:8738] enabling_flash_done(): Running modem initialization sequence... Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [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]: [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]: [1492257097.0150] modem-broadband[ttyMux1]: notifying ModemManager about the modem disconnection Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.098050] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATZ' Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [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]: [1492257097.106252] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ATZ' Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [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]: [1492257097.110060] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '' Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0297] active-connection[0x1c3bdd0]: set state deactivated (was activating) Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0378] active-connection[0x1c3bdd0]: check-master-ready: not signalling (state deactivated, no master) Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0380] device[0x1c3e3b0] (ttyMux1): remove_pending_action (0): 'activation-0x1c3bdd0' Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0386] modem-broadband[ttyMux1]: notifying ModemManager about the modem disconnection Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0446] dns-mgr: (update_routing_and_dns): queueing DNS updates (1) Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0450] dns-mgr: (update_routing_and_dns): DNS configuration did not change Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0452] dns-mgr: (update_routing_and_dns): no DNS changes to commit (0) Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0454] device[0x1c3e3b0] (ttyMux1): add_pending_action (1): 'autoactivate' Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0872] active-connection[0x1c3bdd0]: disposing Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0899] device[0x1c3e3b0] (ttyMux1): remove_pending_action (0): 'autoactivate' Apr 15 12:51:37 wg2xx-tx6s NetworkManager[1154]: [1492257097.0905] agent-manager: req[0x1c4e918, :1.9/nmcli-connect/0]: agent unregistered or disappeared Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.166523] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [1492257097.668647] [src/mm-broadband-modem.c:3181] load_power_state(): loading power state... Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [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]: [1492257097.669112] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATE0' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.676613] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'ATE0' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.677958] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.695442] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.696027] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATV1' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.727097] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.727581] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMEE=1' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.759413] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.759891] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'ATX4' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.790876] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.791368] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT&C1' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.822626] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.823107] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CFUN?' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.851782] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CFUN: 1,0' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.855467] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [1492257097.857027] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT\Q3' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.887088] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257097.888153] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CSCS=?' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.917615] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CSCS: ("GSM","UCS2")' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.920090] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257097.921366] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CSCS="UCS2"' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.953347] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257097.954306] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CSCS?' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.983361] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CSCS: "UCS2"' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [1492257097.986731] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:37 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257097.988179] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CIND=?' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.021011] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CIND : ("call",(0,1)), ("roam",(0,1)) OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257098.022712] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMER=3,0,0,2' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.054534] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CME ERROR: 50' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [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]: [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]: [1492257098.058080] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CREG=2' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.086187] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257098.087199] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CGREG=2' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.118423] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257098.120125] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CUSD=1' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.150501] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [1492257098.164124] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CREG?' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.187933] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CREG: 2,1,"035E","02A5F5BE",6OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [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]: [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]: [1492257098.190114] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMGF=?' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.217014] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CMGF: (0-1)' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.220129] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257098.221380] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+COPS=3,2;+COPS?' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.261236] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+COPS: 0,2,"00320033003400310035",2OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [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]: [1492257098.269708] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CGREG?' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.295117] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CGREG: 2,1,"035E","02A5F5BE",6,"02"OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [1492257098.296418] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMGF=0' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.327047] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [1492257098.332758] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+COPS=3,0;+COPS?' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.379191] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+COPS: 0,0,"0076006F006400610066006F006E006500200055004B",2OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257098.3988] (ttyMux1): modem state changed, 'disabled' --> 'registered' (reason: unknown) Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [1492257098.3991] device[0x1c3e3b0] (ttyMux1): add_pending_action (1): 'recheck-available' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [1492257098.3995] device[0x1c3e3b0] (ttyMux1): remove_pending_action (0): 'recheck-available' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.400515] [src/mm-broadband-modem.c:2065] modem_load_signal_quality(): loading signal quality... Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [1492257098.407501] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPMS="SM","ME","ME"' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.454744] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CPMS: 0,25,2,4,2,4' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.462476] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257098.463805] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CSQ' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.491196] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CSQ: 6,99' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.494735] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [1492257098.500614] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT^SIND?' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.576113] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '^SIND: service,0,1^SIND: message,0,0^SIND: call,0,0^SIND: roam,0,0^SIND: smsfull,0,0^SIND: rssi,0,1^SIND: ciphcall,0,0^SIND: simdata,0^SIND: eons,0,4,"0076006F006400610066006F006E006500200055004B",""^SIND: nitz,0,"00310037002F00300034002F00310035002C00310031003A00350031003A00320032",+04,1^SIND: psinfo,0,10^SIND: pacsp,0,99^SIND: simtray,0,1^SIND: vmwait,0,0^SIND: lsta,0,0^SIND: dtmf,0,1,0,0,0^SIND: ecallco,0,0^SIND: ecallda,0,0^SIND: ecaller,0,0OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257098.581936] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPMS="BM"' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.621567] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CPMS: 0,4,2,4,2,4' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.625947] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257098.627110] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMGL=4' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.657875] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257098.659353] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPMS="ME"' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.688070] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CPMS: 2,4,2,4,2,4' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.690710] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257098.691839] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMGL=4' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.736121] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CMGL: 1,1,,240791448720003023040C9144777633877100007130712193740005D4F29C1E03+CMGL: 2,1,,250791448720003023040C9144777633877100007130712173440006D4F29C1EC301OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [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]: [1492257098.767859] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPMS="SM"' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.799053] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CPMS: 0,25,2,4,2,4' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.810188] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257098.811336] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMGL=4' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.845941] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257098.847435] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CPMS="SR"' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.876129] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CPMS: 0,4,2,4,2,4' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.879029] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257098.880165] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CMGL=4' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.911419] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [1492257098.913137] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CNMI=2,1,2,2,1' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.946370] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257098.948528] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CLIP=1' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.978320] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:38 wg2xx-tx6s ModemManager[1186]: [1492257098.978924] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CRC=1' Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: [1492257099.010319] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [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]: [1492257099.015363] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CREG?' Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: [1492257099.042550] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CREG: 2,1,"035E","02A5F5BE",6OK' Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [1492257099.043911] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CGREG?' Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: [1492257099.075003] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CGREG: 2,1,"035E","02A5F5BE",6,"02"OK' Apr 15 12:51:39 wg2xx-tx6s ModemManager[1186]: [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]: [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]: [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]: [1492257103.889381] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): --> 'AT+CCLK?' Apr 15 12:51:43 wg2xx-tx6s ModemManager[1186]: [1492257103.919974] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- '+CCLK: "04/01/01,00:02:37"' Apr 15 12:51:43 wg2xx-tx6s ModemManager[1186]: [1492257103.924887] [src/mm-port-serial-at.c:459] debug_log(): (ttyMux1): <-- 'OK' Apr 15 12:51:43 wg2xx-tx6s ModemManager[1186]: [1492257103.926216] [src/mm-port-serial.c:1279] _close_internal(): (ttyMux1) device open count is 1 (close)