Understanding Modem Manager
Marc Murphy
marcmltd at marcm.co.uk
Tue Dec 10 14:26:55 PST 2013
Hey Aleksander
I have now updated and configured NetworkManager and with the SierraWireless MC8705 can connect and get an IP address (bingo!) With the Huawei however it can enable the modem but when I try to connect there are lots of timeouts. I have run ModemManager in debug to see if there is anything that can be deciphered from the log. (Sorry about the huge amount of info)
I issue the
#nmcli nm wwan on
#nmcli con up uuid uuid-number
and it goes through the following, it will eventually time out as it looks like the modem is not responding;
# ModemManager[883]: <info> [946684909.389072] [mm-broadband-modem.c:7349] enabling_step(): Modem enabling...
ModemManager[883]: <info> [946684909.390262] [mm-iface-modem.c:1176] mm_iface_modem_update_state(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling)
ModemManager[883]: <info> [946684909.413486] [mm-serial-port.c:857] mm_serial_port_open(): (ttyUSB3) opening serial port...
ModemManager[883]: <warn> [946684909.415866] [mm-serial-port.c:414] real_config_fd(): (ttyUSB3): port attributes not fully set
ModemManager[883]: <debug> [946684909.416507] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 1 (open)
ModemManager[883]: <info> [946684909.416843] [mm-serial-port.c:857] mm_serial_port_open(): (ttyUSB2) opening serial port...
ModemManager[883]: <debug> [946684909.434696] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB2) device open count is 1 (open)
ModemManager[883]: <debug> [946684909.435184] [mm-broadband-modem.c:6829] enabling_started(): Flashing primary port before enabling...
ModemManager[883]: <debug> [946684909.538211] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 2 (open)
ModemManager[883]: <debug> [946684909.539066] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'ATZ<CR>'
ModemManager[883]: <debug> [946684909.558139] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684909.559146] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'ATE0 V1<CR>'
ModemManager[883]: <debug> [946684909.567661] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- 'ATE0 V'
ModemManager[883]: <debug> [946684909.570194] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '1<CR>'
ModemManager[883]: <debug> [946684909.571109] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684909.571964] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CMEE=1<CR>'
ModemManager[883]: <debug> [946684909.585788] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684909.586765] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'ATX4 &C1<CR>'
ModemManager[883]: <debug> [946684909.599155] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684909.600009] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684909.600589] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684909.601047] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684909.601688] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 4 (open)
ModemManager[883]: <debug> [946684909.602268] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CFUN=1<CR>'
ModemManager[883]: <debug> [946684909.617313] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684909.618076] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 3 (close)
ModemManager[883]: <debug> [946684909.618595] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+IFC=1,1<CR>'
ModemManager[883]: <debug> [946684909.633792] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684909.634525] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684909.635013] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CSCS=?<CR>'
ModemManager[883]: <debug> [946684909.650943] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CSCS: ("IRA","GSM","UCS2")<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684909.652530] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684909.653110] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684909.653598] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CSCS="UCS2"<CR>'
ModemManager[883]: <debug> [946684909.675083] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684909.675876] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684909.676395] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684909.676914] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CSCS?<CR>'
ModemManager[883]: <debug> [946684909.691440] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CSCS: "UCS2"<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684909.692295] [huawei/mm-broadband-modem-huawei.c:717] load_allowed_modes(): loading allowed_modes (huawei)...
ModemManager[883]: <debug> [946684909.692752] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684909.693210] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684909.693698] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT^SYSCFG?<CR>'
ModemManager[883]: <debug> [946684909.710330] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>^SYSCFG:2,0,3FFFFFFF,1,2<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684909.712009] [huawei/mm-broadband-modem-huawei.c:579] load_current_bands(): loading current bands (huawei)...
ModemManager[883]: <debug> [946684909.712436] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684909.712863] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684909.713352] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT^SYSCFG?<CR>'
ModemManager[883]: <debug> [946684909.729709] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>^SYSCFG:2,0,3FFFFFFF,1,2<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684909.731510] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 1 (close)
ModemManager[883]: <debug> [946684909.732181] [mm-broadband-modem.c:7382] enabling_step(): Modem has 3GPP capabilities, enabling the Modem 3GPP interface...
ModemManager[883]: <debug> [946684909.732669] [mm-broadband-modem.c:1788] modem_3gpp_setup_unsolicited_events(): Checking indicator support...
ModemManager[883]: <debug> [946684909.733005] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 2 (open)
ModemManager[883]: <debug> [946684909.733554] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CIND=?<CR>'
ModemManager[883]: <debug> [946684909.747684] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CIND: ("battchg",(0-5)),("signal",(0-5)),("service",(0-1)),("call",(0-1)),("roam",(0-1)),("smsfull",(0-1)),("GPRS coverage",(0-1)),("callsetup",(0-3))<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684909.749546] [mm-broadband-modem.c:1741] cind_format_check_ready(): Modem supports signal quality indications via CIND at index '2'(min: 0, max: 5)
ModemManager[883]: <debug> [946684909.750003] [mm-broadband-modem.c:1750] cind_format_check_ready(): Modem supports roaming indications via CIND at index '5'
ModemManager[883]: <debug> [946684910.086673] [mm-broadband-modem.c:1759] cind_format_check_ready(): Modem supports service indications via CIND at index '3'
ModemManager[883]: <debug> [946684910.087131] [mm-broadband-modem.c:1692] set_unsolicited_events_handlers(): (ttyUSB3) Setting 3GPP unsolicited events handlers
ModemManager[883]: <debug> [946684910.087711] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684910.088291] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684910.088809] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CMER=3,0,0,1<CR>'
ModemManager[883]: <debug> [946684910.113712] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684910.114566] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684910.115116] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684910.115543] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT^PORTSEL=0<CR>'
ModemManager[883]: <debug> [946684910.133792] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684910.134738] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT^CURC=1<CR>'
ModemManager[883]: <debug> [946684910.148563] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684910.150669] [mm-broadband-modem.c:2735] modem_3gpp_setup_unsolicited_registration_events(): (ttyUSB3) setting up 3GPP unsolicited registration messages handlers
ModemManager[883]: <debug> [946684910.151279] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 1 (close)
ModemManager[883]: <debug> [946684910.152042] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 2 (open)
ModemManager[883]: <debug> [946684910.152683] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CREG=2<CR>'
ModemManager[883]: <debug> [946684910.168552] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684910.169406] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684910.169864] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684910.170322] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CGREG=2<CR>'
ModemManager[883]: <debug> [946684910.186069] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684910.186924] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 1 (close)
ModemManager[883]: <debug> [946684910.187473] [mm-iface-modem-3gpp.c:732] mm_iface_modem_3gpp_run_registration_checks(): Running registration checks (CS: 'yes', PS: 'yes')
ModemManager[883]: <debug> [946684910.187931] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 2 (open)
ModemManager[883]: <debug> [946684910.188480] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CREG?<CR>'
ModemManager[883]: <debug> [946684910.202060] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CREG: 2,1, CEE, CEEBF08<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <info> [946684910.203037] [mm-iface-modem-3gpp.c:1047] update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (unknown -> registering)
ModemManager[883]: <debug> [946684910.203647] [mm-broadband-modem.c:2619] modem_3gpp_load_operator_code(): loading Operator Code...
ModemManager[883]: <debug> [946684910.203952] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684910.205081] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 4 (open)
ModemManager[883]: <debug> [946684910.205539] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 3 (close)
ModemManager[883]: <debug> [946684910.206089] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+COPS=3,2;+COPS?<CR>'
ModemManager[883]: <debug> [946684910.228000] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>^RSSI:3<CR><LF><CR><LF>^CSNR:-105,-7<CR><LF>'
ModemManager[883]: <debug> [946684910.228824] [huawei/mm-broadband-modem-huawei.c:851] huawei_signal_changed(): 3GPP signal quality: 9
ModemManager[883]: <info> [946684910.230320] [mm-iface-modem.c:971] update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (9)
ModemManager[883]: <debug> [946684910.231144] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+COPS: 0,2,"23433",2<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684910.232273] [mm-broadband-modem.c:2609] modem_3gpp_load_operator_code_finish(): loaded Operator Code: 23433
ModemManager[883]: <debug> [946684910.233188] [mm-broadband-modem.c:2655] modem_3gpp_load_operator_name(): loading Operator Name...
ModemManager[883]: <debug> [946684910.233554] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 4 (open)
ModemManager[883]: <debug> [946684910.569706] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 3 (close)
ModemManager[883]: <debug> [946684910.583194] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CGREG?<CR>'
ModemManager[883]: <debug> [946684910.598850] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CGREG: 2,1, CEE, CEEBF08<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684910.600345] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684910.601139] [mm-broadband-modem.c:7395] enabling_step(): Modem has 3GPP/USSD capabilities, enabling the Modem 3GPP/USSD interface...
ModemManager[883]: <debug> [946684910.601780] [mm-broadband-modem.c:3916] set_unsolicited_result_code_handlers(): (ttyUSB3) Setting unsolicited result code handlers
ModemManager[883]: <debug> [946684910.602481] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684910.603000] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+COPS=3,0;+COPS?<CR>'
ModemManager[883]: <debug> [946684910.646213] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+COPS: 0,0,"Orange",2<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684910.648197] [mm-broadband-modem.c:2645] modem_3gpp_load_operator_name_finish(): loaded Operator Name: Orange
ModemManager[883]: <debug> [946684910.649387] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <info> [946684910.656498] [mm-iface-modem-3gpp.c:1004] update_registration_reload_current_operator_ready(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (registering -> home)
ModemManager[883]: <debug> [946684910.657901] [mm-iface-modem.c:1320] get_updated_consolidated_state(): Will start keeping track of state for subsystem '3gpp'
ModemManager[883]: <debug> [946684910.665012] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CUSD=1<CR>'
ModemManager[883]: <debug> [946684910.679844] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684910.681400] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 1 (close)
ModemManager[883]: <debug> [946684910.688541] [mm-broadband-modem.c:7423] enabling_step(): Modem has location capabilities, enabling the Location interface...
ModemManager[883]: <debug> [946684910.689365] [mm-iface-modem-location.c:737] setup_gathering(): Need to enable the following location sources: '3gpp-lac-ci'
ModemManager[883]: <debug> [946684910.690464] [mm-iface-modem-3gpp.c:732] mm_iface_modem_3gpp_run_registration_checks(): Running registration checks (CS: 'yes', PS: 'yes')
ModemManager[883]: <debug> [946684910.690921] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 2 (open)
ModemManager[883]: <debug> [946684910.698337] [mm-broadband-modem.c:7436] enabling_step(): Modem has messaging capabilities, enabling the Messaging interface...
ModemManager[883]: <debug> [946684910.699955] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684910.700657] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CREG?<CR>'
ModemManager[883]: <debug> [946684910.713230] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CREG: 2,1, CEE, CEEBF08<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <info> [946684910.714237] [mm-iface-modem-location.c:291] notify_3gpp_location_update(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: 'CEE', Cell ID: 'CEEBF08')
ModemManager[883]: <debug> [946684910.715244] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 4 (open)
ModemManager[883]: <debug> [946684910.715702] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 3 (close)
ModemManager[883]: <debug> [946684910.716282] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CMGF=?<CR>'
ModemManager[883]: <debug> [946684910.730808] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CMGF: (0-1)<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684910.732029] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 4 (open)
ModemManager[883]: <debug> [946684910.732486] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 3 (close)
ModemManager[883]: <debug> [946684910.733036] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CGREG?<CR>'
ModemManager[883]: <debug> [946684910.748203] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CGREG: 2,1, CEE, CEEBF08<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684910.749485] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684910.750309] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CMGF=0<CR>'
ModemManager[883]: <debug> [946684910.763950] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <info> [946684910.764713] [mm-broadband-modem.c:4493] cmgf_set_ready(): Successfully set preferred SMS mode: 'PDU'
ModemManager[883]: <debug> [946684910.765812] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684910.766452] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684910.773594] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CPMS="","MT","MT"<CR>'
ModemManager[883]: <debug> [946684910.808994] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CPMS: 0,23,0,23,0,23<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684910.810062] [mm-broadband-modem.c:5202] modem_messaging_load_initial_sms_parts(): Listing SMS parts in storage 'me'
ModemManager[883]: <debug> [946684910.810489] [mm-broadband-modem.c:4387] mm_broadband_modem_lock_sms_storages(): Locking SMS storages to: mem1 (ME), mem2 (none)...
ModemManager[883]: <debug> [946684910.810764] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684910.811191] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684910.811679] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CPMS="ME"<CR>'
ModemManager[883]: <debug> [946684911.170108] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CPMS: 0,23,0,23,0,23<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684911.171116] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684911.171665] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684911.172245] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CMGL=4<CR>'
ModemManager[883]: <debug> [946684911.189914] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684911.190769] [mm-broadband-modem.c:5202] modem_messaging_load_initial_sms_parts(): Listing SMS parts in storage 'sm'
ModemManager[883]: <debug> [946684911.191105] [mm-broadband-modem.c:4387] mm_broadband_modem_lock_sms_storages(): Locking SMS storages to: mem1 (SM), mem2 (none)...
ModemManager[883]: <debug> [946684911.191379] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684911.191776] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684911.192234] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CPMS="SM"<CR>'
ModemManager[883]: <debug> [946684911.211704] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CPMS: 5,30,0,23,0,23<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684911.212528] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684911.213047] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684911.213504] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CMGL=4<CR>'
ModemManager[883]: <debug> [946684911.287143] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CMGL: 0,1,,160<CR><LF>0791449737019037400ED0D456F32D4EB3CB000031609131345040A006080432A90201CEE2156496BFDB206AABF916A7D96517E85A3ED9CBA0B1BC1CA697C9A0693B2CA783A0E1F17A0EA2BF41E7B4BD0CCABFEB20F63B4C9E83DA6F7919D44EBBE72C10BD8CA7CF41613719440ED3C32E502006039DCBF43928FFAE8302371CE8FE96D3D1A0B719340EB3D97350D84D06D1CB78FA1C84A2A3C3F4D31C1483C140EDB47B0E0ABBC9<CR><LF>+CMGL: 1,1,,149<CR><LF>0791449737019037440ED0D456F32D4
ModemManager[883]: <debug> [946684911.322635] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '3F7781A8653C1D346D06A5D4180C447F8368B418C8FC9683CCF27219447F83C4F53C280C0AC460207878BC06B9DF7717C898769341EF3A1DD47ECBCB2074595E06A1E974B8EEF56ABBE8ADF65B9C66975DE3B7ABBE7ECDDB61391D<CR><LF>+CMGL: 2,1,,156<CR><LF>07914497370190374005B10708F0000031117181415100A006080487F20201D43C1CFD7EBB41C8703A1F7683D0E139885D36D3416F7B590E32BFEB72503BCD66A7DF6ED0189D6693E56537885C9EC3CBF230BD0C32BFE520F3FB4D6681C6EC72D80DBA87E9653928EC2683E6
ModemManager[883]: <debug> [946684911.325382] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '50C9297C36C761EE42E97C9<CR><LF>+CMGL: 3,1,,155<CR><LF>07914497370190374405B10708F00000311171814151009E06080487F20202A0FCBB2E07A1CB6C3888FE7EBB405076393C2F83E465383B0FCA16A720FA1B447EBBC3F43228500399DF7250B95D969FCBEE711E34AFC3E1EC7479EE0265DFF5139B0D3AA7ED6550A00632CBDF6D50FE5D9783C6F232394D0785DD64D01D1DA697ED653928FFAE83EAF37A98CDCE83E0E13CC8FC9683C2207A194F07B5CBF379F85C7601<CR><LF>+CMGL: 4,1,,122<CR><LF>079144973701903704
ModemManager[883]: <debug> [946684911.327518] [mm-sms-part.c:519] mm_sms_part_new_from_binary_pdu(): Parsing PDU (0)...
ModemManager[883]: <debug> [946684911.327915] [mm-sms-part.c:548] mm_sms_part_new_from_binary_pdu(): SMSC address parsed: '+4479XXXXXXXX'
ModemManager[883]: <debug> [946684911.328159] [mm-sms-part.c:561] mm_sms_part_new_from_binary_pdu(): Deliver type PDU detected
ModemManager[883]: <debug> [946684911.328525] [mm-sms-part.c:622] mm_sms_part_new_from_binary_pdu(): Number parsed: 'T-Mobile'
ModemManager[883]: <debug> [946684911.328769] [mm-sms-part.c:722] mm_sms_part_new_from_binary_pdu(): PID: 0
ModemManager[883]: <debug> [946684911.328952] [mm-sms-part.c:733] mm_sms_part_new_from_binary_pdu(): user data encoding is GSM7
ModemManager[883]: <debug> [946684911.329166] [mm-sms-part.c:761] mm_sms_part_new_from_binary_pdu(): user data length: 160 elements
ModemManager[883]: <debug> [946684911.329349] [mm-sms-part.c:767] mm_sms_part_new_from_binary_pdu(): user data length: 140 bytes
ModemManager[883]: <debug> [946684911.329563] [mm-sms-part.c:840] mm_sms_part_new_from_binary_pdu(): Decoding SMS text with '152' elements
ModemManager[883]: <debug> [946684911.329746] [mm-sms-part.c:244] sms_decode_text(): Converting SMS part text from GSM7 to UTF8...
ModemManager[883]: <debug> [946684911.330112] [mm-sms-part.c:247] sms_decode_text(): Got UTF-8 text: 'NEW from T-Mobile. We've created Smart Packs to give you loads more mins, texts and data. £10 gets you £78 worth of calls and texts (that's 100 mins and'
ModemManager[883]: <debug> [946684911.330326] [mm-broadband-modem.c:5137] sms_pdu_part_list_ready(): Correctly parsed PDU (0)
ModemManager[883]: <debug> [946684911.330661] [mm-sms-list.c:369] mm_sms_list_take_part(): SMS part at 'sm/0' is from a multipart SMS (reference: '12969', sequence: '1')
ModemManager[883]: <debug> [946684911.335453] [mm-iface-modem-messaging.c:500] sms_added(): Added received SMS at '/org/freedesktop/ModemManager1/SMS/0'
ModemManager[883]: <debug> [946684911.342197] [mm-sms-part.c:519] mm_sms_part_new_from_binary_pdu(): Parsing PDU (1)...
ModemManager[883]: <debug> [946684911.342716] [mm-sms-part.c:548] mm_sms_part_new_from_binary_pdu(): SMSC address parsed: '+4479XXXXXXXX '
ModemManager[883]: <debug> [946684911.342960] [mm-sms-part.c:561] mm_sms_part_new_from_binary_pdu(): Deliver type PDU detected
ModemManager[883]: <debug> [946684911.343235] [mm-sms-part.c:622] mm_sms_part_new_from_binary_pdu(): Number parsed: 'T-Mobile'
ModemManager[883]: <debug> [946684911.679020] [mm-sms-part.c:722] mm_sms_part_new_from_binary_pdu(): PID: 0
ModemManager[883]: <debug> [946684911.679233] [mm-sms-part.c:733] mm_sms_part_new_from_binary_pdu(): user data encoding is GSM7
ModemManager[883]: <debug> [946684911.679447] [mm-sms-part.c:761] mm_sms_part_new_from_binary_pdu(): user data length: 147 elements
ModemManager[883]: <debug> [946684911.679630] [mm-sms-part.c:767] mm_sms_part_new_from_binary_pdu(): user data length: 129 bytes
ModemManager[883]: <debug> [946684911.679813] [mm-sms-part.c:840] mm_sms_part_new_from_binary_pdu(): Decoding SMS text with '139' elements
ModemManager[883]: <debug> [946684911.680057] [mm-sms-part.c:244] sms_decode_text(): Converting SMS part text from GSM7 to UTF8...
ModemManager[883]: <debug> [946684911.680454] [mm-sms-part.c:247] sms_decode_text(): Got UTF-8 text: ' 400 texts) plus 1GB data for 30 days. Text SMART10 to 441 for free to buy a £10 pack now. Find out more here http://m.t-mobile.co.uk/smart'
ModemManager[883]: <debug> [946684911.680668] [mm-broadband-modem.c:5137] sms_pdu_part_list_ready(): Correctly parsed PDU (1)
ModemManager[883]: <debug> [946684911.681034] [mm-sms-list.c:369] mm_sms_list_take_part(): SMS part at 'sm/1' is from a multipart SMS (reference: '12969', sequence: '2')
ModemManager[883]: <debug> [946684911.683384] [mm-sms-part.c:519] mm_sms_part_new_from_binary_pdu(): Parsing PDU (2)...
ModemManager[883]: <debug> [946684911.683750] [mm-sms-part.c:548] mm_sms_part_new_from_binary_pdu(): SMSC address parsed: '+4479XXXXXXXX '
ModemManager[883]: <debug> [946684911.683964] [mm-sms-part.c:561] mm_sms_part_new_from_binary_pdu(): Deliver type PDU detected
ModemManager[883]: <debug> [946684911.684177] [mm-sms-part.c:622] mm_sms_part_new_from_binary_pdu(): Number parsed: '70800'
ModemManager[883]: <debug> [946684911.684391] [mm-sms-part.c:722] mm_sms_part_new_from_binary_pdu(): PID: 0
ModemManager[883]: <debug> [946684911.684604] [mm-sms-part.c:733] mm_sms_part_new_from_binary_pdu(): user data encoding is GSM7
ModemManager[883]: <debug> [946684911.684787] [mm-sms-part.c:761] mm_sms_part_new_from_binary_pdu(): user data length: 160 elements
ModemManager[883]: <debug> [946684911.684971] [mm-sms-part.c:767] mm_sms_part_new_from_binary_pdu(): user data length: 140 bytes
ModemManager[883]: <debug> [946684911.685184] [mm-sms-part.c:840] mm_sms_part_new_from_binary_pdu(): Decoding SMS text with '152' elements
ModemManager[883]: <debug> [946684911.685367] [mm-sms-part.c:244] sms_decode_text(): Converting SMS part text from GSM7 to UTF8...
ModemManager[883]: <debug> [946684911.685734] [mm-sms-part.c:247] sms_decode_text(): Got UTF-8 text: 'Typhoon Haiyan has left over four million children desperate for food, clean water and shelter. Together, EE and UNICEF are helping them. We really need'
ModemManager[883]: <debug> [946684911.686069] [mm-broadband-modem.c:5137] sms_pdu_part_list_ready(): Correctly parsed PDU (2)
ModemManager[883]: <debug> [946684911.686344] [mm-sms-list.c:369] mm_sms_list_take_part(): SMS part at 'sm/2' is from a multipart SMS (reference: '34802', sequence: '1')
ModemManager[883]: <debug> [946684911.688511] [mm-iface-modem-messaging.c:500] sms_added(): Added received SMS at '/org/freedesktop/ModemManager1/SMS/1'
ModemManager[883]: <debug> [946684911.694797] [mm-sms-part.c:519] mm_sms_part_new_from_binary_pdu(): Parsing PDU (3)...
ModemManager[883]: <debug> [946684911.695255] [mm-sms-part.c:548] mm_sms_part_new_from_binary_pdu(): SMSC address parsed: '+4479XXXXXXXX'
ModemManager[883]: <debug> [946684911.695499] [mm-sms-part.c:561] mm_sms_part_new_from_binary_pdu(): Deliver type PDU detected
ModemManager[883]: <debug> [946684911.695835] [mm-sms-part.c:622] mm_sms_part_new_from_binary_pdu(): Number parsed: '70800'
ModemManager[883]: <debug> [946684911.696079] [mm-sms-part.c:722] mm_sms_part_new_from_binary_pdu(): PID: 0
ModemManager[883]: <debug> [946684911.696262] [mm-sms-part.c:733] mm_sms_part_new_from_binary_pdu(): user data encoding is GSM7
ModemManager[883]: <debug> [946684912.032657] [mm-sms-part.c:761] mm_sms_part_new_from_binary_pdu(): user data length: 158 elements
ModemManager[883]: <debug> [946684912.032902] [mm-sms-part.c:767] mm_sms_part_new_from_binary_pdu(): user data length: 139 bytes
ModemManager[883]: <debug> [946684912.033115] [mm-sms-part.c:840] mm_sms_part_new_from_binary_pdu(): Decoding SMS text with '150' elements
ModemManager[883]: <debug> [946684912.033329] [mm-sms-part.c:244] sms_decode_text(): Converting SMS part text from GSM7 to UTF8...
ModemManager[883]: <debug> [946684912.033695] [mm-sms-part.c:247] sms_decode_text(): Got UTF-8 text: ' your help too. Please reply YES to donate £5 for emergency supplies. You'll give £5 from your credit and whatever you usually pay for a text message.'
ModemManager[883]: <debug> [946684912.033939] [mm-broadband-modem.c:5137] sms_pdu_part_list_ready(): Correctly parsed PDU (3)
ModemManager[883]: <debug> [946684912.034275] [mm-sms-list.c:369] mm_sms_list_take_part(): SMS part at 'sm/3' is from a multipart SMS (reference: '34802', sequence: '2')
ModemManager[883]: <debug> [946684912.036411] [mm-sms-part.c:519] mm_sms_part_new_from_binary_pdu(): Parsing PDU (4)...
ModemManager[883]: <debug> [946684912.036777] [mm-sms-part.c:548] mm_sms_part_new_from_binary_pdu(): SMSC address parsed: '+4479XXXXXXXX'
ModemManager[883]: <debug> [946684912.037021] [mm-sms-part.c:561] mm_sms_part_new_from_binary_pdu(): Deliver type PDU detected
ModemManager[883]: <debug> [946684912.037266] [mm-sms-part.c:622] mm_sms_part_new_from_binary_pdu(): Number parsed: '-EE-'
ModemManager[883]: <debug> [946684912.037479] [mm-sms-part.c:722] mm_sms_part_new_from_binary_pdu(): PID: 0
ModemManager[883]: <debug> [946684912.037662] [mm-sms-part.c:733] mm_sms_part_new_from_binary_pdu(): user data encoding is GSM7
ModemManager[883]: <debug> [946684912.037906] [mm-sms-part.c:761] mm_sms_part_new_from_binary_pdu(): user data length: 119 elements
ModemManager[883]: <debug> [946684912.038120] [mm-sms-part.c:767] mm_sms_part_new_from_binary_pdu(): user data length: 105 bytes
ModemManager[883]: <debug> [946684912.038303] [mm-sms-part.c:840] mm_sms_part_new_from_binary_pdu(): Decoding SMS text with '119' elements
ModemManager[883]: <debug> [946684912.038486] [mm-sms-part.c:244] sms_decode_text(): Converting SMS part text from GSM7 to UTF8...
ModemManager[883]: <debug> [946684912.038822] [mm-sms-part.c:247] sms_decode_text(): Got UTF-8 text: 'Get £5 FREE credit! Don't miss out, simply make a call by 27 Nov and we'll add £5 FREE credit to your account by 30 Nov'
ModemManager[883]: <debug> [946684912.039005] [mm-broadband-modem.c:5137] sms_pdu_part_list_ready(): Correctly parsed PDU (4)
ModemManager[883]: <debug> [946684912.039310] [mm-sms-list.c:382] mm_sms_list_take_part(): SMS part at 'sm/4' is from a singlepart SMS
ModemManager[883]: <debug> [946684912.042545] [mm-iface-modem-messaging.c:500] sms_added(): Added received SMS at '/org/freedesktop/ModemManager1/SMS/2'
ModemManager[883]: <debug> [946684912.048862] [mm-broadband-modem.c:5202] modem_messaging_load_initial_sms_parts(): Listing SMS parts in storage 'sr'
ModemManager[883]: <debug> [946684912.049473] [mm-broadband-modem.c:4387] mm_broadband_modem_lock_sms_storages(): Locking SMS storages to: mem1 (SR), mem2 (none)...
ModemManager[883]: <debug> [946684912.049778] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684912.050236] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684912.064701] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CPMS="SR"<CR>'
ModemManager[883]: <debug> [946684912.085209] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CPMS: 0,0,0,23,0,23<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684912.086307] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684912.086857] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684912.087375] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CMGL=4<CR>'
ModemManager[883]: <debug> [946684912.101444] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684912.102573] [mm-broadband-modem.c:4799] set_messaging_unsolicited_events_handlers(): (ttyUSB3) Setting messaging unsolicited events handlers
ModemManager[883]: <debug> [946684912.438419] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 1 (close)
ModemManager[883]: <debug> [946684912.438968] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 2 (open)
ModemManager[883]: <debug> [946684912.439548] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CNMI=2,1,2,1,0<CR>'
ModemManager[883]: <debug> [946684912.466038] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CMS ERROR: 303<CR><LF>'
ModemManager[883]: <debug> [946684912.467380] [mm-serial-parsers.c:316] mm_serial_parser_v1_parse(): Got failure code 303: Operation not supported
ModemManager[883]: <debug> [946684912.468113] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CNMI=2,1,2,2,0<CR>'
ModemManager[883]: <debug> [946684912.499424] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684912.500370] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 1 (close)
ModemManager[883]: <info> [946684912.500858] [mm-broadband-modem.c:7469] enabling_step(): Modem fully enabled...
ModemManager[883]: <info> [946684912.501285] [mm-iface-modem.c:1176] mm_iface_modem_update_state(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabling -> registered)
ModemManager[883]: <debug> [946684912.518009] [mm-iface-modem.c:1100] periodic_signal_quality_check_enable(): Periodic signal quality checks enabled
ModemManager[883]: <debug> [946684912.519169] [huawei/mm-broadband-modem-huawei.c:1416] modem_load_signal_quality(): loading signal quality...
ModemManager[883]: <debug> [946684912.519718] [mm-broadband-modem.c:1592] modem_load_signal_quality(): loading signal quality...
ModemManager[883]: <debug> [946684912.520084] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 2 (open)
ModemManager[883]: <debug> [946684912.520481] [mm-iface-modem.c:839] periodic_access_technologies_check_enable(): Periodic access technology checks enabled
ModemManager[883]: <debug> [946684912.520786] [huawei/mm-broadband-modem-huawei.c:252] load_access_technologies(): loading access technology (huawei)...
ModemManager[883]: <debug> [946684912.521030] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684912.527286] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CIND?<CR>'
ModemManager[883]: <debug> [946684912.542972] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CIND: 5,1,1,0,0,1,1,0<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684912.544407] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <info> [946684912.545963] [mm-iface-modem.c:971] update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (20)
ModemManager[883]: <debug> [946684912.553501] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT^SYSINFO<CR>'
ModemManager[883]: <debug> [946684912.569462] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>^SYSINFO:2,3,0,5,1,,4<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684912.570927] [huawei/mm-broadband-modem-huawei.c:239] load_access_technologies_finish(): Access Technology: 'umts'
ModemManager[883]: <info> [946684912.571964] [mm-iface-modem.c:723] mm_iface_modem_update_access_technologies(): Modem /org/freedesktop/ModemManager1/Modem/0: access technology changed (unknown -> umts)
ModemManager[883]: <debug> [946684912.572422] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 1 (close)
ModemManager[883]: <debug> [946684913.606602] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>^RSSI:3<CR><LF>'
ModemManager[883]: <debug> [946684913.607700] [huawei/mm-broadband-modem-huawei.c:851] huawei_signal_changed(): 3GPP signal quality: 9
ModemManager[883]: <info> [946684913.608890] [mm-iface-modem.c:971] update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (9)
ModemManager[883]: <debug> [946684913.609867] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>^CSNR:-104,-10<CR><LF>'
ModemManager[883]: <info> [946684919.997318] [mm-iface-modem-simple.c:778] connect_auth_ready(): Simple connect started...
ModemManager[883]: <info> [946684919.998325] [mm-iface-modem-simple.c:551] connection_step(): Simple connect state (4/10): Wait to get fully enabled
ModemManager[883]: <info> [946684919.999027] [mm-iface-modem-simple.c:563] connection_step(): Simple connect state (5/10): Allowed mode
ModemManager[883]: <debug> [946684920.004765] [mm-iface-modem-simple.c:311] set_allowed_modes_ready(): Will wait to settle down after updating allowed modes
ModemManager[883]: <info> [946684922.192021] [mm-iface-modem-simple.c:586] connection_step(): Simple connect state (6/10): Bands
ModemManager[883]: <info> [946684922.192387] [mm-iface-modem-simple.c:615] connection_step(): Simple connect state (7/10): Register
ModemManager[883]: <debug> [946684922.192875] [mm-iface-modem-3gpp.c:374] mm_iface_modem_3gpp_register_in_network(): Already registered in network '23433', automatic registration not launched...
ModemManager[883]: <info> [946684922.193424] [mm-iface-modem-simple.c:638] connection_step(): Simple connect state (8/10): Bearer
ModemManager[883]: <debug> [946684922.193668] [mm-iface-modem-simple.c:658] connection_step(): Creating new bearer...
ModemManager[883]: <debug> [946684922.193882] [mm-broadband-modem.c:264] modem_create_bearer(): Creating Broadband bearer in broadband modem
ModemManager[883]: <debug> [946684922.202244] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 2 (open)
ModemManager[883]: <debug> [946684922.202946] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 1 (close)
ModemManager[883]: <debug> [946684922.204258] [mm-broadband-modem.c:225] modem_create_bearer_finish(): New bearer created at DBus path '/org/freedesktop/ModemManager1/Bearer/0'
ModemManager[883]: <info> [946684922.205021] [mm-iface-modem-simple.c:720] connection_step(): Simple connect state (9/10): Connect
ModemManager[883]: <debug> [946684922.205448] [mm-bearer.c:517] mm_bearer_connect(): Connecting bearer '/org/freedesktop/ModemManager1/Bearer/0'
ModemManager[883]: <info> [946684922.206028] [mm-iface-modem.c:1176] mm_iface_modem_update_state(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
ModemManager[883]: <info> [946684922.219914] [mm-serial-port.c:857] mm_serial_port_open(): (ttyUSB0) opening serial port...
ModemManager[883]: <warn> [946684922.223209] [mm-serial-port.c:414] real_config_fd(): (ttyUSB0): port attributes not fully set
ModemManager[883]: <debug> [946684922.223820] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB0) device open count is 1 (open)
ModemManager[883]: <debug> [946684922.224308] [mm-broadband-bearer.c:999] connect_3gpp(): Looking for best CID...
ModemManager[883]: <debug> [946684922.224766] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 2 (open)
ModemManager[883]: <debug> [946684922.225468] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CGDCONT?<CR>'
ModemManager[883]: <debug> [946684922.243321] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>+CGDCONT: 1,"IP","internet","",0,0<CR><LF>+CGDCONT: 2,"IP","general.t-mobile.uk","",0,0<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684922.244846] [mm-broadband-bearer.c:921] parse_pdp_list(): Found '2' PDP contexts
ModemManager[883]: <debug> [946684922.245274] [mm-broadband-bearer.c:928] parse_pdp_list(): PDP context [cid=1] [type='ipv4'] [apn='internet']
ModemManager[883]: <debug> [946684922.245518] [mm-broadband-bearer.c:928] parse_pdp_list(): PDP context [cid=2] [type='ipv4'] [apn='general.t-mobile.uk']
ModemManager[883]: <debug> [946684922.245762] [mm-broadband-bearer.c:949] parse_pdp_list(): Found PDP context with CID 2 and PDP type ipv4 for APN 'general.t-mobile.uk'
ModemManager[883]: <debug> [946684922.246220] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684922.246678] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684922.247196] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CGDCONT=2,"IP","general.t-mobile.uk"<CR>'
ModemManager[883]: <debug> [946684922.313023] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
ModemManager[883]: <debug> [946684922.313969] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684922.314396] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 2 (close)
ModemManager[883]: <debug> [946684922.314915] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'ATD*99***2#<CR>'
ModemManager[883]: <debug> [946684922.335880] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): <-- '<CR><LF>CONNECT 28800000<CR><LF>'
ModemManager[883]: <debug> [946684922.337406] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 1 (close)
ModemManager[883]: <debug> [946684922.338291] [mm-port.c:149] mm_port_set_connected(): (ttyUSB0): port now connected
ModemManager[883]: <debug> [946684922.338932] [mm-bearer.c:413] connect_ready(): Connected bearer '/org/freedesktop/ModemManager1/Bearer/0'
ModemManager[883]: <info> [946684922.340885] [mm-iface-modem.c:1176] mm_iface_modem_update_state(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> connected)
ModemManager[883]: <info> [946684922.355045] [mm-iface-modem-simple.c:739] connection_step(): Simple connect state (10/10): All done
ModemManager[883]: <debug> [946684922.524632] [mm-bearer.c:687] mm_bearer_disconnect(): Disconnecting bearer '/org/freedesktop/ModemManager1/Bearer/0'
ModemManager[883]: <info> [946684922.525639] [mm-iface-modem.c:1176] mm_iface_modem_update_state(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connected -> disconnecting)
ModemManager[883]: <debug> [946684922.551365] [mm-broadband-bearer.c:1562] disconnect_3gpp(): Flash primary port...
ModemManager[883]: <debug> [946684923.558964] [mm-broadband-bearer.c:1481] primary_flash_3gpp_ready(): Sending PDP context deactivation in primary port...
ModemManager[883]: <debug> [946684923.559300] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 2 (open)
ModemManager[883]: <debug> [946684923.559818] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CGACT=0,2<CR>'
ModemManager[883]: <debug> [946684927.193699] [mm-broadband-bearer.c:1433] cgact_primary_ready(): PDP context deactivation failed (not fatal): Serial command timed out
ModemManager[883]: <debug> [946684927.194126] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 1 (close)
ModemManager[883]: <debug> [946684927.194615] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB0) device open count is 0 (close)
ModemManager[883]: <info> [946684927.194798] [mm-serial-port.c:982] mm_serial_port_close(): (ttyUSB0) closing serial port...
ModemManager[883]: <debug> [946684927.195011] [mm-port.c:149] mm_port_set_connected(): (ttyUSB0): port now disconnected
ModemManager[883]: <info> [946684927.197148] [mm-serial-port.c:1014] mm_serial_port_close(): (ttyUSB0) serial port closed
ModemManager[883]: <debug> [946684927.197758] [mm-bearer.c:620] disconnect_ready(): Disconnected bearer '/org/freedesktop/ModemManager1/Bearer/0'
ModemManager[883]: <info> [946684927.198399] [mm-iface-modem.c:1176] mm_iface_modem_update_state(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disconnecting -> registered)
ModemManager[883]: <debug> [946684943.204961] [huawei/mm-broadband-modem-huawei.c:1416] modem_load_signal_quality(): loading signal quality...
ModemManager[883]: <debug> [946684943.205479] [mm-broadband-modem.c:1592] modem_load_signal_quality(): loading signal quality...
ModemManager[883]: <debug> [946684943.205723] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 2 (open)
ModemManager[883]: <debug> [946684943.206029] [huawei/mm-broadband-modem-huawei.c:252] load_access_technologies(): loading access technology (huawei)...
ModemManager[883]: <debug> [946684943.206181] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 3 (open)
ModemManager[883]: <debug> [946684943.206517] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT+CIND?<CR>'
ModemManager[883]: <debug> [946684946.192448] [mm-serial-port.c:926] mm_serial_port_open(): (ttyUSB3) device open count is 4 (open)
ModemManager[883]: <debug> [946684946.192937] [mm-serial-port.c:966] mm_serial_port_close(): (ttyUSB3) device open count is 3 (close)
ModemManager[883]: <debug> [946684946.193394] [mm-at-serial-port.c:392] debug_log(): (ttyUSB3): --> 'AT^SYSINFO<CR>'
ModemManager[883]: <debug> [946684949.192937] [mm-iface-modem.c:761] access_technologies_check_ready(): Couldn't refresh access technologies: 'Serial command timed out'
If there is anything I can do I am prepared to change the driver to suit the EM820W modem. I have the AT commands document and datasheet.
Kind Regards
Marc
-----Original Message-----
From: Aleksander Morgado [mailto:aleksander at lanedo.com]
Sent: 09 December 2013 11:35
To: Marc Murphy; modemmanager-devel at lists.freedesktop.org
Subject: Re: Understanding Modem Manager
Hey Marc,
> I have a platform that has no GUI so I am trying to initialize a couple of 3G modems (Huawei EM820W and Sierra Wireless MC8705) to use as data connections when away from the local network.
>
> I have downloaded and compiled ModemManager and it seems to be working well with the daemon, the cards can be detected and various parameters can be extracted using the mmcli app.
>
> I am having some trouble in actually getting a useable connection.
> Previously with one of the cards (Sierra Wireless MC8705) I could manually setup with the AT commands, connect and get a valid IP address with all the dns and routing being setup with dhclient.
>
> I would like to have the same result but using ModemManager, if it is possible. Here is some debug about what I am attempting to do:
>
> # mmcli -m 0 --list-bearers
>
> No bearers were found
> # mmcli -m 0
>
> /org/freedesktop/ModemManager1/Modem/0 (device id
> '61d98ebe0deeb14a83d951229303f0e8a245cd35')
> -------------------------
> Hardware | manufacturer: 'huawei'
> | model: 'EM820W'
> | revision: '11.809.05.80.00'
> | capabilities: 'gsm-umts'
> | current: 'gsm-umts'
> | equipment id: '3542830400XXXXX'
> -------------------------
> System | device: '/sys/devices/platform/usbhs_omap/ehci-omap.0/usb1/1-1/1-1.1'
> | drivers: 'option1'
> | plugin: 'Huawei'
> | primary port: 'ttyUSB3'
> -------------------------
> Numbers | own : '+4475398XXXXX'
> -------------------------
> Status | lock: 'none'
> | unlock retries: 'sim-pin (3), sim-pin2 (3), sim-puk (10), sim-puk2 (10)'
> | state: 'disabled'
> | access tech: 'unknown'
> | signal quality: '0' (cached)
> -------------------------
> Modes | supported: '2g, 3g'
> | allowed: '2g, 3g'
> | preferred: 'none'
> -------------------------
> Bands | supported: 'unknown'
> | current: 'unknown'
> -------------------------
> 3GPP | imei: '3542830400XXXXX'
> | enabled locks: 'none'
> | operator id: 'unknown'
> | operator name: 'unknown'
> | registration: 'unknown'
> -------------------------
> SIM | path: '/org/freedesktop/ModemManager1/SIM/0'
>
> So it looks like the modem is detected. I then tried to connect by
> creating the bearer info (I'm using tmobile in the UK); # mmcli -m 0
> --create-bearer="apn=general.t-mobile.uk,user=t-mobile,password=tm,
> number=*99#"
> Successfully created new bearer in modem:
> /org/freedesktop/ModemManager1/Bearer/2
No need to pass the "number" parameter there; won't be used.
>
> # mmcli -m 0 -c -b /org/freedesktop/ModemManager1/Bearer/2
You shouldn't pass "-m 0" and then "-b /.../"; just "mmcli -b 2 -c"
should do it (i.e. only specify the bearer).
> ModemManager[805]: <info> Modem
> /org/freedesktop/ModemManager1/Modem/0: state changed (registered ->
> connecting)
> ModemManager[805]: <info> (ttyUSB0) opening serial port...
> ModemManager[805]: <warn> (ttyUSB0): port attributes not fully set
> ModemManager[805]: <warn> Couldn't initialize PDP context with our APN: 'Serial command timed out'
> ModemManager[805]: <info> (ttyUSB0) closing serial port...
> ModemManager[805]: <info> (ttyUSB0) serial port closed
> ModemManager[805]: <info> Modem
> /org/freedesktop/ModemManager1/Modem/0: state changed (connecting ->
> registered)
> error: couldn't connect the bearer: 'GDBus.Error:org.freedesktop.ModemManager1.Error.Serial.ResponseTimeout: Serial command timed out'
>
Oh well;.... Care to run ModemManager with --debug to see what is really happening?
> Which looked like it failed but the status shows
>
> # mmcli -m 0 --simple-status
>
> /org/freedesktop/ModemManager1/Modem/0
> -------------------------
> Status | state: 'registered'
> | signal quality: '6' (cached)
> | bands: 'unknown'
> | access tech: 'umts'
> -------------------------
> 3GPP | registration: 'home'
> | operator code: '23433'
> | operator name: 'Orange'
>
Yeah, it failed. It's only registered, not connected.
> So then decided to try the example with simple-connect
>
> # mmcli -m 0 --simple-connect="pin=1234,apn=internet"
> ModemManager[805]: <info> Simple connect started...
> ModemManager[805]: <info> Simple connect state (4/10): Wait to get
> fully enabled
> ModemManager[805]: <info> Simple connect state (5/10): Allowed mode
> ModemManager[805]: <info> Simple connect state (6/10): Bands
> ModemManager[805]: <info> Simple connect state (7/10): Register
> ModemManager[805]: <info> Simple connect state (8/10): Bearer
> ModemManager[805]: <info> Simple connect state (9/10): Connect
> ModemManager[805]: <info> Modem
> /org/freedesktop/ModemManager1/Modem/0: state changed (registered ->
> connecting)
> ModemManager[805]: <info> (ttyUSB0) opening serial port...
> ModemManager[805]: <warn> (ttyUSB0): port attributes not fully set
> ModemManager[805]: <info> Modem
> /org/freedesktop/ModemManager1/Modem/0: state changed (connecting ->
> connected)
> ModemManager[805]: <info> Simple connect state (10/10): All done
> successfully connected the modem
>
> That seemed to work ???
Yeah, it worked.
> # mmcli -m 0 --simple-status
>
> /org/freedesktop/ModemManager1/Modem/0
> -------------------------
> Status | state: 'registered'
> | signal quality: '6' (cached)
> | bands: 'unknown'
> | access tech: 'umts'
> -------------------------
> 3GPP | registration: 'home'
> | operator code: '23433'
> | operator name: 'Orange'
>
Hum... "state" should have said "connected" there.
> So how do I reliably get to connect and then generate a wwan0 network interface ? Do I need to use NetworkManager to obtain an IP interface to allow for routing ?
>
ModemManager will get the interface connected. Once it is connected, the modem will expose in the "bearer info" (e.g. mmcli -b 2) the "IP setup"
needed in the 'data' interface. This may be DHCP, or static or PPP. If DHCP is required in the net interface, you'll need to bring the interface up (e.g. ifup) and then run a DHCP client in the interface (e.g. dhclient). If you are using NetworkManager, it will handle all that for you, including the case where the needed setup is PPP or a static IP config.
> As you can guess I am in the early learning stages with this. Once I get the IP connection sorted I would like to look at the gps. This also isn't working when I try....
>
> # mmcli -m 0 --location-status
>
> /org/freedesktop/ModemManager1/Modem/0
> ----------------------------
> Location | capabilities: '3gpp-lac-ci'
> | enabled: '3gpp-lac-ci'
> | signals: 'no'
>
> # mmcli -m 0 --location-get-3gpp
> error: couldn't get 3GPP-based location from the modem: 'not available'
>
> # mmcli -m 0 --location-enable-gps-nmea
> error: couldn't setup location gathering: 'GDBus.Error:org.freedesktop.ModemManager1.Error.Core.Unsupported: Cannot enable unsupported location sources: 'gps-nmea''
>
> But the specs for the modem state that it can do NMEA gps?? Confusing.
>
No GPS location capabilities shown means that ModemManager doesn't know how to manage them. In your case, the Huawei plugin in ModemManager knows nothing about GPS.
--
Aleksander
More information about the ModemManager-devel
mailing list