Bringing up PPP after ModemManager is up

Tue Apr 21 09:36:56 PDT 2015

Hi Dan

Thanks for your response!

TTYUSB2 is our AT command port and TTYUSB3 is our PPP port.  The HSPA code
I attached earlier was the code we have been using for a while without MM
with no problem. I'm thinking maybe I need to tweak it to make it work with
MM but I'm not sure what I need to be tweaking...

Here is the logs I recaptured this morning, hopefully it helps shed some
light on this issue:

root at beaglebone:~# mmcli -m 0 --simple-connect="apn=internet.com
,number=*99#"
ModemManager[3261]: <info>  [947011579.036844]
[mm-iface-modem-simple.c:641] connect_auth_ready(): Simple connect
started...
ModemManager[3261]: <debug> [947011579.037205]
[mm-iface-modem-simple.c:651] connect_auth_ready():    PIN: unspecified
ModemManager[3261]: <debug> [947011579.037333]
[mm-iface-modem-simple.c:653] connect_auth_ready():    Operator ID:
unspecified
ModemManager[3261]: <debug> [947011579.037445]
[mm-iface-modem-simple.c:655] connect_auth_ready():    Allowed roaming: yes
ModemManager[3261]: <debug> [947011579.037556]
[mm-iface-modem-simple.c:657] connect_auth_ready():    APN: internet.com
ModemManager[3261]: <debug> [947011579.037663]
[mm-iface-modem-simple.c:665] connect_auth_ready():    IP family:
unspecified
ModemManager[3261]: <debug> [947011579.037772]
[mm-iface-modem-simple.c:673] connect_auth_ready():    Allowed
authentication: unspecified
ModemManager[3261]: <debug> [947011579.037880]
[mm-iface-modem-simple.c:675] connect_auth_ready():    User: unspecified
ModemManager[3261]: <debug> [947011579.037986]
[mm-iface-modem-simple.c:677] connect_auth_ready():    Password: unspecified
ModemManager[3261]: <debug> [947011579.038092]
[mm-iface-modem-simple.c:679] connect_auth_ready():    Number: *99#
ModemManager[3261]: <info>  [947011579.043746]
[mm-iface-modem-simple.c:461] connection_step(): Simple connect state
(3/8): Enable
ModemManager[3261]: <info>  [947011579.044312] [mm-iface-modem.c:1392]
__iface_modem_update_state_internal(): Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling)
ModemManager[3261]: <debug> [947011579.057229] [mm-port-serial.c:1099]
mm_port_serial_open(): (ttyUSB2) opening serial port...
ModemManager[3261]: <warn>  [947011579.061851] [mm-port-serial.c:515]
real_config_fd(): (ttyUSB2): port attributes not fully set
ModemManager[3261]: <debug> [947011579.062194] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 1 (open)
ModemManager[3261]: <debug> [947011579.062326] [mm-broadband-modem.c:8016]
enabling_started(): Flashing primary AT port before enabling...
ModemManager[3261]: <debug> [947011579.165473] [mm-broadband-modem.c:7905]
enabling_flash_done(): Running modem initialization sequence...
ModemManager[3261]: <debug> [947011579.165839] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947011579.166174] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'ATZ<CR>'
ModemManager[3261]: <debug> [947011579.216745] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011579.217374] [mm-broadband-modem.c:7886]
enabling_modem_init_ready(): Giving some time to settle the modem...
ModemManager[3261]: <debug> [947011579.217673] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
ModemManager[3261]: <debug> [947011579.718825] [mm-port-serial-at.c:476]
mm_port_serial_at_run_init_sequence(): (ttyUSB2): running init sequence...
ModemManager[3261]: <debug> [947011579.719555] [mm-broadband-modem.c:3132]
load_power_state(): loading power state...
ModemManager[3261]: <debug> [947011579.719767] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947011579.720054] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'ATE0<CR>'
ModemManager[3261]: <debug> [947011579.725245] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- 'A'
ModemManager[3261]: <debug> [947011579.726613] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- 'T'
ModemManager[3261]: <debug> [947011579.727675] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- 'E0<CR>'
ModemManager[3261]: <debug> [947011579.728926] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011579.729802] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'ATV1<CR>'
ModemManager[3261]: <debug> [947011579.741133] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011579.742179] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CMEE=1<CR>'
ModemManager[3261]: <debug> [947011579.757992] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011579.758968] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'ATX4<CR>'
ModemManager[3261]: <debug> [947011579.766770] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011579.767652] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT&C1<CR>'
ModemManager[3261]: <debug> [947011579.778973] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011579.779887] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CFUN?<CR>'
ModemManager[3261]: <debug> [947011579.794772] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CFUN: 1<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011579.795686] [mm-iface-modem.c:3259]
set_power_state(): No need to change power state: already in 'on' power
state
ModemManager[3261]: <debug> [947011579.796549] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
ModemManager[3261]: <debug> [947011579.802563] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947011579.803848] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT\Q3<CR>'
ModemManager[3261]: <debug> [947011579.818123] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011579.819403] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011579.820277] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011579.821013] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CSCS=?<CR>'
ModemManager[3261]: <debug> [947011579.837469] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CSCS:
("IRA","GSM","UCS2")<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011579.838933] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011579.839849] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011579.840590] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CSCS="UCS2"<CR>'
ModemManager[3261]: <debug> [947011579.864155] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011579.865128] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011579.865892] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011579.866526] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CSCS?<CR>'
ModemManager[3261]: <debug> [947011579.883316] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CSCS:
"UCS2"<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011579.884320] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
ModemManager[3261]: <debug> [947011579.885125] [mm-broadband-modem.c:8592]
enabling_step(): Modem has 3GPP capabilities, enabling the Modem 3GPP
interface...
ModemManager[3261]: <debug> [947011579.885819] [mm-broadband-modem.c:2594]
modem_3gpp_setup_unsolicited_events(): Checking indicator support...
ModemManager[3261]: <debug> [947011579.886404] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947011579.887154] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CIND=?<CR>'
ModemManager[3261]: <debug> [947011579.905496] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>ERROR<CR><LF>'
ModemManager[3261]: <debug> [947011579.906343] [mm-serial-parsers.c:364]
mm_serial_parser_v1_parse(): Got failure code 100: Unknown error
ModemManager[3261]: <debug> [947011579.906953] [mm-broadband-modem.c:2524]
cind_format_check_ready(): Marking indications as unsupported: 'Unknown
error'
ModemManager[3261]: <debug> [947011579.907553] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011579.908345] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011579.909075] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CMER=3,0,0,2<CR>'
ModemManager[3261]: <debug> [947011579.934398] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>ERROR<CR><LF>'
ModemManager[3261]: <debug> [947011579.935186] [mm-serial-parsers.c:364]
mm_serial_parser_v1_parse(): Got failure code 100: Unknown error
ModemManager[3261]: <debug> [947011579.935971] [mm-iface-modem-3gpp.c:1625]
enable_unsolicited_events_ready(): Enabling unsolicited events failed:
'Unknown error'
ModemManager[3261]: <debug> [947011579.937500] [mm-broadband-modem.c:3594]
modem_3gpp_setup_unsolicited_registration_events(): (ttyUSB2) setting up
3GPP unsolicited registration messages handlers
ModemManager[3261]: <debug> [947011579.938277] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
ModemManager[3261]: <debug> [947011580.274511] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947011580.275338] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CREG=2<CR>'
ModemManager[3261]: <debug> [947011580.296239] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011580.297217] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011580.298008] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011580.298785] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CGREG=2<CR>'
ModemManager[3261]: <debug> [947011580.321184] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CME ERROR: 21<CR><LF>'
ModemManager[3261]: <debug> [947011580.322082] [mm-serial-parsers.c:364]
mm_serial_parser_v1_parse(): Got failure code 21: Invalid index
ModemManager[3261]: <debug> [947011580.322947] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CGREG=1<CR>'
ModemManager[3261]: <debug> [947011580.347412] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011580.348060] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
ModemManager[3261]: <debug> [947011580.348516] [mm-iface-modem-3gpp.c:751]
mm_iface_modem_3gpp_run_registration_checks(): Running registration checks
(CS: 'yes', PS: 'yes', EPS: 'no')
ModemManager[3261]: <debug> [947011580.348778] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947011580.349090] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CREG?<CR>'
ModemManager[3261]: <debug> [947011580.376331] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CREG:
2,1,"FFDC","01DF3D8"<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <info>  [947011580.376956] [mm-iface-modem-3gpp.c:1154]
update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0:
3GPP Registration state changed (unknown -> registering)
ModemManager[3261]: <debug> [947011580.377220] [mm-broadband-modem.c:3430]
modem_3gpp_load_operator_code(): loading Operator Code...
ModemManager[3261]: <debug> [947011580.377428] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011580.378036] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 4 (open)
ModemManager[3261]: <debug> [947011580.379527] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 3 (close)
ModemManager[3261]: <debug> [947011580.380374] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+COPS=3,2;+COPS?<CR>'
ModemManager[3261]: <debug> [947011580.417548] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+COPS:
0,2,"302720",2<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011580.418887] [mm-broadband-modem.c:3420]
modem_3gpp_load_operator_code_finish(): loaded Operator Code: 302720
ModemManager[3261]: <debug> [947011580.419945] [mm-broadband-modem.c:3466]
modem_3gpp_load_operator_name(): loading Operator Name...
ModemManager[3261]: <debug> [947011580.420669] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 4 (open)
ModemManager[3261]: <debug> [947011580.421318] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 3 (close)
ModemManager[3261]: <debug> [947011580.427283] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CGREG?<CR>'
ModemManager[3261]: <debug> [947011580.443506] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CGREG: 1,0<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011580.444760] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011580.445716] [mm-broadband-modem.c:8605]
enabling_step(): Modem has 3GPP/USSD capabilities, enabling the Modem
3GPP/USSD interface...
ModemManager[3261]: <debug> [947011580.446416] [mm-broadband-modem.c:4908]
set_unsolicited_result_code_handlers(): (ttyUSB2) Setting unsolicited
result code handlers
ModemManager[3261]: <debug> [947011580.447229] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011580.447958] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+COPS=3,0;+COPS?<CR>'
ModemManager[3261]: <debug> [947011580.479971] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+COPS:
0,0,"ROGERS",2<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011580.481737] [mm-broadband-modem.c:3456]
modem_3gpp_load_operator_name_finish(): loaded Operator Name: ROGERS
ModemManager[3261]: <debug> [947011580.482878] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <info>  [947011580.489480] [mm-iface-modem-3gpp.c:1079]
update_registration_reload_current_registration_info_ready(): Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed
(registering -> home)
ModemManager[3261]: <debug> [947011580.490893] [mm-iface-modem.c:1561]
get_updated_consolidated_state(): Will start keeping track of state for
subsystem '3gpp'
ModemManager[3261]: <debug> [947011580.496894] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CUSD=1<CR>'
ModemManager[3261]: <debug> [947011580.512051] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011580.513526] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
ModemManager[3261]: <debug> [947011580.519694] [mm-broadband-modem.c:8633]
enabling_step(): Modem has location capabilities, enabling the Location
interface...
ModemManager[3261]: <debug> [947011580.520699]
[mm-iface-modem-location.c:735] setup_gathering(): Location 'gps-raw'
gathering is already disabled...
ModemManager[3261]: <debug> [947011580.521346]
[mm-iface-modem-location.c:735] setup_gathering(): Location 'gps-nmea'
gathering is already disabled...
ModemManager[3261]: <debug> [947011580.521843]
[mm-iface-modem-location.c:735] setup_gathering(): Location 'gps-unmanaged'
gathering is already disabled...
ModemManager[3261]: <debug> [947011580.522390]
[mm-iface-modem-location.c:759] setup_gathering(): Need to enable the
following location sources: '3gpp-lac-ci'
ModemManager[3261]: <debug> [947011580.523510] [mm-iface-modem-3gpp.c:751]
mm_iface_modem_3gpp_run_registration_checks(): Running registration checks
(CS: 'yes', PS: 'yes', EPS: 'no')
ModemManager[3261]: <debug> [947011580.858542] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947011580.859324] [mm-broadband-modem.c:3430]
modem_3gpp_load_operator_code(): loading Operator Code...
ModemManager[3261]: <debug> [947011580.859920] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011580.866135] [mm-broadband-modem.c:8646]
enabling_step(): Modem has messaging capabilities, enabling the Messaging
interface...
ModemManager[3261]: <debug> [947011580.867755] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 4 (open)
ModemManager[3261]: <debug> [947011580.868763] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CREG?<CR>'
ModemManager[3261]: <debug> [947011580.890132] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CREG:
2,1,"FFDC","01DF3D8"<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011580.891170]
[mm-iface-modem-location.c:295] notify_3gpp_location_update(): Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0',
MNC: '0', Location area code: 'FFDC', Cell ID: '1DF3D8')
ModemManager[3261]: <debug> [947011580.892233] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 5 (open)
ModemManager[3261]: <debug> [947011580.893009] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 4 (close)
ModemManager[3261]: <debug> [947011580.893932] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+COPS=3,2;+COPS?<CR>'
ModemManager[3261]: <debug> [947011580.918046] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+COPS:
0,2,"302720",2<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011580.919131] [mm-broadband-modem.c:3420]
modem_3gpp_load_operator_code_finish(): loaded Operator Code: 302720
ModemManager[3261]: <debug> [947011580.920111]
[mm-iface-modem-location.c:295] notify_3gpp_location_update(): Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '302',
MNC: '720', Location area code: 'FFDC', Cell ID: '1DF3D8')
ModemManager[3261]: <debug> [947011580.920777] [mm-broadband-modem.c:3466]
modem_3gpp_load_operator_name(): loading Operator Name...
ModemManager[3261]: <debug> [947011580.921349] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 5 (open)
ModemManager[3261]: <debug> [947011580.921957] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 4 (close)
ModemManager[3261]: <debug> [947011580.922651] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CMGF=?<CR>'
ModemManager[3261]: <debug> [947011580.937038] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CMGF: (0-1)<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011580.938322] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 5 (open)
ModemManager[3261]: <debug> [947011580.939154] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 4 (close)
ModemManager[3261]: <debug> [947011580.939837] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CGREG?<CR>'
ModemManager[3261]: <debug> [947011580.952578] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CGREG: 1,0<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011580.953754] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 3 (close)
ModemManager[3261]: <debug> [947011580.954642] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+COPS=3,0;+COPS?<CR>'
ModemManager[3261]: <debug> [947011580.979248] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+COPS:
0,0,"ROGERS",2<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011580.980335] [mm-broadband-modem.c:3456]
modem_3gpp_load_operator_name_finish(): loaded Operator Name: ROGERS
ModemManager[3261]: <debug> [947011580.981278] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011580.982420] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CMGF=0<CR>'
ModemManager[3261]: <debug> [947011580.998062] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011580.999039] [mm-broadband-modem.c:5485]
cmgf_set_ready(): Successfully set preferred SMS mode: 'PDU'
ModemManager[3261]: <debug> [947011581.000060] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011581.000867] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011581.006839] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CPMS="","MT","MT"<CR>'
ModemManager[3261]: <debug> [947011581.038213] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CPMS:
1,255,1,255,1,255<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011581.039404] [mm-broadband-modem.c:6184]
modem_messaging_load_initial_sms_parts(): Listing SMS parts in storage 'me'
ModemManager[3261]: <debug> [947011581.040131] [mm-broadband-modem.c:5379]
mm_broadband_modem_lock_sms_storages(): Locking SMS storages to: mem1 (ME),
mem2 (none)...
ModemManager[3261]: <debug> [947011581.040733] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011581.041461] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011581.042097] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CPMS="ME"<CR>'
ModemManager[3261]: <debug> [947011581.063480] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CPMS:
1,255,1,255,1,255<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011581.064465] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011581.065271] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011581.400310] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CMGL=4<CR>'
ModemManager[3261]: <debug> [947011581.494988] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CMGL:
0,1,,24<CR><LF>07917150979633F0040B916140277429F200035140025134218A05C830081D06<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011581.496418] [mm-sms-part-3gpp.c:368]
mm_sms_part_3gpp_new_from_binary_pdu(): Parsing PDU (0)...
ModemManager[3261]: <debug> [947011581.497256] [mm-sms-part-3gpp.c:397]
mm_sms_part_3gpp_new_from_binary_pdu():   SMSC address parsed:
'+17057969330'
ModemManager[3261]: <debug> [947011581.497754] [mm-sms-part-3gpp.c:410]
mm_sms_part_3gpp_new_from_binary_pdu():   Deliver type PDU detected
ModemManager[3261]: <debug> [947011581.498342] [mm-sms-part-3gpp.c:471]
mm_sms_part_3gpp_new_from_binary_pdu():   Number parsed: '+16047247922'
ModemManager[3261]: <debug> [947011581.498814] [mm-sms-part-3gpp.c:575]
mm_sms_part_3gpp_new_from_binary_pdu():   PID: 0
ModemManager[3261]: <debug> [947011581.499223] [mm-sms-part-3gpp.c:586]
mm_sms_part_3gpp_new_from_binary_pdu():   user data encoding is GSM7
ModemManager[3261]: <debug> [947011581.499676] [mm-sms-part-3gpp.c:614]
mm_sms_part_3gpp_new_from_binary_pdu():   user data length: 5 elements
ModemManager[3261]: <debug> [947011581.500067] [mm-sms-part-3gpp.c:620]
mm_sms_part_3gpp_new_from_binary_pdu():   user data length: 5 bytes
ModemManager[3261]: <debug> [947011581.500451] [mm-sms-part-3gpp.c:695]
mm_sms_part_3gpp_new_from_binary_pdu(): Decoding SMS text with '5' elements
ModemManager[3261]: <debug> [947011581.500878] [mm-sms-part-3gpp.c:244]
sms_decode_text(): Converting SMS part text from GSM7 to UTF8...
ModemManager[3261]: <debug> [947011581.501288] [mm-sms-part-3gpp.c:247]
sms_decode_text():    Got UTF-8 text: 'Ha ha'
ModemManager[3261]: <debug> [947011581.501688] [mm-broadband-modem.c:6117]
sms_pdu_part_list_ready(): Correctly parsed PDU (0)
ModemManager[3261]: <debug> [947011581.502202] [mm-sms-list.c:384]
mm_sms_list_take_part(): SMS part at 'me/0' is from a singlepart SMS
ModemManager[3261]: <debug> [947011581.506391]
[mm-iface-modem-messaging.c:511] sms_added(): Added received SMS at
'/org/freedesktop/ModemManager1/SMS/0'
ModemManager[3261]: <debug> [947011581.512412] [mm-broadband-modem.c:6184]
modem_messaging_load_initial_sms_parts(): Listing SMS parts in storage 'sm'
ModemManager[3261]: <debug> [947011581.513443] [mm-broadband-modem.c:5379]
mm_broadband_modem_lock_sms_storages(): Locking SMS storages to: mem1 (SM),
mem2 (none)...
ModemManager[3261]: <debug> [947011581.514178] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011581.514929] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011581.520986] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CPMS="SM"<CR>'
ModemManager[3261]: <debug> [947011581.562540] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CPMS:
0,50,1,255,1,255<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011581.563793] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011581.564628] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011581.565352] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CMGL=4<CR>'
ModemManager[3261]: <debug> [947011581.588792] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011581.589927] [mm-broadband-modem.c:5791]
set_messaging_unsolicited_events_handlers(): (ttyUSB2) Setting messaging
unsolicited events handlers
ModemManager[3261]: <debug> [947011581.590676] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
ModemManager[3261]: <debug> [947011581.591711] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947011581.592547] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CNMI=2,1,2,0,1<CR>'
ModemManager[3261]: <debug> [947011581.631687] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011581.632686] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
ModemManager[3261]: <info>  [947011581.633622] [mm-iface-modem.c:1392]
__iface_modem_update_state_internal(): Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (enabling ->
registered)
ModemManager[3261]: <debug> [947011581.644382] [mm-iface-modem.c:1316]
periodic_signal_quality_check_enable(): Periodic signal quality checks
enabled (interval = 3s)
ModemManager[3261]: <debug> [947011581.645341] [mm-broadband-modem.c:1991]
modem_load_signal_quality(): loading signal quality...
ModemManager[3261]: <debug> [947011581.646084] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947011581.646762] [mm-iface-modem.c:1036]
periodic_access_technologies_check_enable(): Periodic access technology
checks enabled
ModemManager[3261]: <debug> [947011581.647374] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <info>  [947011581.648342]
[mm-iface-modem-simple.c:469] connection_step(): Simple connect state
(4/8): Wait to get fully enabled
ModemManager[3261]: <info>  [947011581.648739]
[mm-iface-modem-simple.c:478] connection_step(): Simple connect state
(5/8): Register
ModemManager[3261]: <debug> [947011581.649143] [mm-iface-modem-3gpp.c:390]
mm_iface_modem_3gpp_register_in_network(): Already registered in network
'302720', automatic registration not launched...
ModemManager[3261]: <info>  [947011581.649518]
[mm-iface-modem-simple.c:501] connection_step(): Simple connect state
(6/8): Bearer
ModemManager[3261]: <debug> [947011581.984379]
[mm-iface-modem-simple.c:574] connection_step(): Using already existing
bearer at '/org/freedesktop/ModemManager1/Bearer/0'...
ModemManager[3261]: <info>  [947011581.984587]
[mm-iface-modem-simple.c:583] connection_step(): Simple connect state
(7/8): Connect
ModemManager[3261]: <debug> [947011581.984811] [mm-base-bearer.c:590]
mm_base_bearer_connect(): Connecting bearer
'/org/freedesktop/ModemManager1/Bearer/0'
ModemManager[3261]: <info>  [947011581.985140] [mm-iface-modem.c:1392]
__iface_modem_update_state_internal(): Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (registered ->
connecting)
ModemManager[3261]: <debug> [947011581.995541] [mm-broadband-bearer.c:1254]
connect(): Launching 3GPP connection attempt with APN 'internet.com'
ModemManager[3261]: <debug> [947011581.996014] [mm-broadband-bearer.c:177]
detailed_connect_context_new(): No specific IP family requested, defaulting
to ipv4
ModemManager[3261]: <debug> [947011581.996235] [mm-broadband-bearer.c:1044]
connect_3gpp(): Looking for best CID...
ModemManager[3261]: <debug> [947011581.996484] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 4 (open)
ModemManager[3261]: <debug> [947011581.996950] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CSQ<CR>'
ModemManager[3261]: <debug> [947011582.018762] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CSQ: 13,99<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011582.019474] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 3 (close)
ModemManager[3261]: <debug> [947011582.020313] [mm-iface-modem.c:1165]
update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0:
signal quality updated (41)
ModemManager[3261]: <debug> [947011582.020648] [mm-iface-modem.c:1235]
signal_quality_check_ready(): Periodic signal quality checks rescheduled
(interval = 30s)
ModemManager[3261]: <debug> [947011582.026298] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT^SIND?<CR>'
ModemManager[3261]: <debug> [947011584.976788] [mm-iface-modem.c:934]
access_technologies_check_ready(): Couldn't refresh access technologies:
'Serial command timed out'
ModemManager[3261]: <debug> [947011584.977166] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011584.977476] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CGDCONT?<CR>'
ModemManager[3261]: <debug> [947011585.010905] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>^SIND: signal,0,99<CR><LF>^SIND:
service,0,1<CR><LF>^SIND: sounder,0,0<CR><LF>^SIND:
message,0,0<CR><LF>^SIND: call,0,0<CR><LF>^SIND: roam,0,0<CR><LF>^SIND:
smsfull,0,0<CR><LF>^SIND: rssi,0,2<CR><LF>^SIND: audio,0,0<CR><LF>^SIND:
simstatus,1,5<CR><LF>^SIND: simdata,0<CR><LF>^SIND:
eons,0,1,"0052004F0047004500520053","0052004F0047004500520053",1<CR><LF>^SIND:
nitz,0,"00310035002F00300034002F00320031002C00310036003A00300039003A00330031",-28,1<CR><LF>^SIND:
psinfo,0,5<CR><LF>^SIND: vcall,0,0<CR><LF>^SIND: simlocal,0,1<CR><LF>^SIND:
lsta,0,0<CR><LF>^SIND: ratmode,0,99<CR><LF>^SIND: pacsp,0,1<CR><LF>^SIND:
steerroam,0<CR><LF><CR><LF><CR><LF>OK<CR><LF><CR><LF>+CGDCONT: 1,"IP","
internet.com","0.0.0.0",0,0<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011585.012587] [mm-broadband-bearer.c:961]
parse_pdp_list(): Found '1' PDP contexts
ModemManager[3261]: <debug> [947011585.012921] [mm-broadband-bearer.c:970]
parse_pdp_list():   PDP context [cid=1] [type='ipv4'] [apn='internet.com']
ModemManager[3261]: <debug> [947011585.013137] [mm-broadband-bearer.c:994]
parse_pdp_list(): Found PDP context with CID 1 and PDP type ipv4 for APN '
internet.com'
ModemManager[3261]: <debug> [947011585.013532] [mm-port-serial.c:1099]
mm_port_serial_open(): (ttyUSB3) opening serial port...
ModemManager[3261]: <warn>  [947011585.018533] [mm-port-serial.c:515]
real_config_fd(): (ttyUSB3): port attributes not fully set
ModemManager[3261]: <debug> [947011585.018986] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB3) device open count is 1 (open)
ModemManager[3261]: <debug> [947011585.019230] [mm-broadband-bearer.c:214]
common_get_at_data_port(): Connection through a plain serial AT port
(ttyUSB3)
ModemManager[3261]: <debug> [947011585.019586] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB3) device open count is 2 (open)
ModemManager[3261]: <debug> [947011585.019966] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
ModemManager[3261]: <debug> [947011585.020439] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB3): --> 'ATD*99***1#<CR>'
ModemManager[3261]: <debug> [947011585.131106] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB3): <-- '<CR><LF>CONNECT<CR><LF>'
ModemManager[3261]: <debug> [947011585.131815] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB3) device open count is 1 (close)
ModemManager[3261]: <debug> [947011585.132372] [mm-port.c:95]
mm_port_set_connected(): (ttyUSB3): port now connected
ModemManager[3261]: <debug> [947011585.132883] [mm-base-bearer.c:488]
connect_ready(): Connected bearer '/org/freedesktop/ModemManager1/Bearer/0'
ModemManager[3261]: <info>  [947011585.134106] [mm-iface-modem.c:1392]
__iface_modem_update_state_internal(): Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (connecting ->
connected)
ModemManager[3261]: <info>  [947011585.144578]
[mm-iface-modem-simple.c:602] connection_step(): Simple connect state
(8/8): All done
successfully connected the modem

root at beaglebone:~# ModemManager[3261]: <debug> [947011671.994119]
[mm-port-serial.c:1237] mm_port_serial_open(): (ttyUSB2) device open count
is 2 (open)
ModemManager[3261]: <debug> [947011671.994598] [mm-broadband-modem.c:1991]
modem_load_signal_quality(): loading signal quality...
ModemManager[3261]: <debug> [947011671.994805] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011671.995121] [mm-iface-modem.c:1101]
expire_signal_quality(): Signal quality value not updated in 60s, marking
as not being recent
ModemManager[3261]: <debug> [947011671.999169] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT^SIND?<CR>'
ModemManager[3261]: <debug> [947011674.977116] [mm-iface-modem.c:934]
access_technologies_check_ready(): Couldn't refresh access technologies:
'Serial command timed out'
ModemManager[3261]: <debug> [947011674.977499] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011674.977792] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CSQ<CR>'
ModemManager[3261]: <debug> [947011674.999278] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>^SIND: signal,0,99<CR><LF>^SIND:
service,0,1<CR><LF>^SIND: sounder,0,0<CR><LF>^SIND:
message,0,0<CR><LF>^SIND: call,0,0<CR><LF>^SIND: roam,0,0<CR><LF>^SIND:
smsfull,0,0<CR><LF>^SIND: rssi,0,2<CR><LF>^SIND: audio,0,0<CR><LF>^SIND:
simstatus,1,5<CR><LF>^SIND: simdata,0<CR><LF>^SIND:
eons,0,1,"0052004F0047004500520053","0052004F0047004500520053",1<CR><LF>^SIND:
nitz,0,"00310035002F00300034002F00320031002C00310036003A00300039003A00330031",-28,1<CR><LF>^SIND:
psinfo,0,5<CR><LF>^SIND: vcall,0,0<CR><LF>^SIND: simlocal,0,1<CR><LF>^SIND:
lsta,0,0<CR><LF>^SIND: ratmode,0,99<CR><LF>^SIND: pacsp,0,1<CR><LF>^SIND:
steerroam,0<CR><LF><CR><LF><CR><LF>OK<CR><LF><CR><LF>+CSQ:
13,99<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011675.000326] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
ModemManager[3261]: <debug> [947011675.000620] [mm-iface-modem.c:1221]
signal_quality_check_ready(): Couldn't refresh signal quality: 'Could not
parse signal quality results'
cd /etc/ppp/peers/
root at beaglebone:/etc/ppp/peers# pppd call hspa
{hspa_chat} Establishing Link...
Script /usr/sbin/chat -v -f /etc/ppp/peers/hspa_chat finished (pid 4962),
status = 0x0
Serial connection established.
using channel 1
Using interface ppp0
Connect: ppp0 <--> /dev/ttyUSB3
ModemManager[3261]: <debug> [947011699.820755] [mm-base-manager.c:296]
device_added(): (net/ppp0): could not get port's parent device
Warning - secret file /etc/ppp/pap-secrets has world and/or group access
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xdf31bf8f> <pcomp> <accomp>]
ModemManager[3261]: <debug> [947011701.975954] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947011701.976442] [mm-broadband-modem.c:1991]
modem_load_signal_quality(): loading signal quality...
ModemManager[3261]: <debug> [947011701.976649] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947011701.976922] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT^SIND?<CR>'
ModemManager[3261]: <debug> [947011702.049414] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011702.050791] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 4 (open)
ModemManager[3261]: <debug> [947011702.051690] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 3 (close)
ModemManager[3261]: <debug> [947011702.052479] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CSQ<CR>'
ModemManager[3261]: <debug> [947011702.077731] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CSQ: 13,99<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947011702.078895] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947011702.080065] [mm-iface-modem.c:1165]
update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0:
signal quality updated (41)
ModemManager[3261]: <debug> [947011702.083394] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT^SMONG<CR>'
ModemManager[3261]: <debug> [947011702.103334] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>ERROR<CR><LF>'
ModemManager[3261]: <debug> [947011702.104258] [mm-serial-parsers.c:364]
mm_serial_parser_v1_parse(): Got failure code 100: Unknown error
ModemManager[3261]: <debug> [947011702.104909] [mm-iface-modem.c:934]
access_technologies_check_ready(): Couldn't refresh access technologies:
'Unknown error'
ModemManager[3261]: <debug> [947011702.105511] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xdf31bf8f> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xdf31bf8f> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xdf31bf8f> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xdf31bf8f> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xdf31bf8f> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xdf31bf8f> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xdf31bf8f> <pcomp> <accomp>]
LCP: timeout sending Config-Requests
Connection terminated.
Script /usr/sbin/chat -v -f /etc/ppp/peers/hspa_chat_down finished (pid
5134), status = 0x0
Serial link disconnected.
Modem hangup

root at beaglebone:/etc/ppp/peers# mmcli -m 0 --command="AT+CGATT=1"
ModemManager[3261]: <debug> [947012293.812427] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947012293.813013] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CGATT=1<CR>'
ModemManager[3261]: <debug> [947012293.845406] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
response: ''
ModemManager[3261]: <debug> [947012293.852252] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
root at beaglebone:/etc/ppp/peers# mmcli -m 0 --command="AT+CGATT?"
ModemManager[3261]: <debug> [947012299.542900] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947012299.543599] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CGATT?<CR>'
ModemManager[3261]: <debug> [947012299.593493] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CGATT: 1<CR><LF><CR><LF>OK<CR><LF>'
response: '+CGATT: 1'
ModemManager[3261]: <debug> [947012299.601497] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
root at beaglebone:/etc/ppp/peers# ModemManager[3261]: <debug>
[947012301.976345] [mm-port-serial.c:1237] mm_port_serial_open(): (ttyUSB2)
device open count is 2 (open)
ModemManager[3261]: <debug> [947012301.976828] [mm-broadband-modem.c:1991]
modem_load_signal_quality(): loading signal quality...
ModemManager[3261]: <debug> [947012301.977041] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947012301.977336] [mm-iface-modem.c:1101]
expire_signal_quality(): Signal quality value not updated in 60s, marking
as not being recent
ModemManager[3261]: <debug> [947012301.981464] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT^SIND?<CR>'
ModemManager[3261]: <debug> [947012304.976458] [mm-iface-modem.c:934]
access_technologies_check_ready(): Couldn't refresh access technologies:
'Serial command timed out'
ModemManager[3261]: <debug> [947012304.976838] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947012304.977144] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CSQ<CR>'
ModemManager[3261]: <debug> [947012305.002359] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>^SIND: signal,0,99<CR><LF>^SIND:
service,0,1<CR><LF>^SIND: sounder,0,0<CR><LF>^SIND:
message,0,0<CR><LF>^SIND: call,0,0<CR><LF>^SIND: roam,0,0<CR><LF>^SIND:
smsfull,0,0<CR><LF>^SIND: rssi,0,2<CR><LF>^SIND: audio,0,0<CR><LF>^SIND:
simstatus,1,5<CR><LF>^SIND: simdata,0<CR><LF>^SIND:
eons,0,1,"0052004F0047004500520053","0052004F0047004500520053",1<CR><LF>^SIND:
nitz,0,"00310035002F00300034002F00320031002C00310036003A00310038003A00330032",-28,1<CR><LF>^SIND:
psinfo,0,6<CR><LF>^SIND: vcall,0,0<CR><LF>^SIND: simlocal,0,1<CR><LF>^SIND:
lsta,0,0<CR><LF>^SIND: ratmode,0,99<CR><LF>^SIND: pacsp,0,1<CR><LF>^SIND:
steerroam,0<CR><LF><CR><LF><CR><LF>OK<CR><LF><CR><LF>+CSQ:
12,99<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947012305.003488] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
ModemManager[3261]: <debug> [947012305.003785] [mm-iface-modem.c:1221]
signal_quality_check_ready(): Couldn't refresh signal quality: 'Could not
parse signal quality results'

root at beaglebone:/etc/ppp/peers# mmcli -m 0 --command="AT+CGATT?"
ModemManager[3261]: <debug> [947012923.278536] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947012923.279825] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CGATT?<CR>'
ModemManager[3261]: <debug> [947012923.307176] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CGATT: 1<CR><LF><CR><LF>OK<CR><LF>'
response: '+CGATT: 1'
ModemManager[3261]: <debug> [947012923.315190] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
root at beaglebone:/etc/ppp/peers# pppd call hspa
{hspa_chat} Establishing Link...
Script /usr/sbin/chat -v -f /etc/ppp/peers/hspa_chat finished (pid 12393),
status = 0x0
Serial connection established.
using channel 4
Using interface ppp0
Connect: ppp0 <--> /dev/ttyUSB3
ModemManager[3261]: <debug> [947012927.848496] [mm-base-manager.c:296]
device_added(): (net/ppp0): could not get port's parent device
Warning - secret file /etc/ppp/pap-secrets has world and/or group access
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x23d187ee> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x23d187ee> <pcomp> <accomp>]
ModemManager[3261]: <debug> [947012931.978455] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
ModemManager[3261]: <debug> [947012931.978898] [mm-broadband-modem.c:1991]
modem_load_signal_quality(): loading signal quality...
ModemManager[3261]: <debug> [947012931.979101] [mm-port-serial.c:1237]
mm_port_serial_open(): (ttyUSB2) device open count is 3 (open)
ModemManager[3261]: <debug> [947012931.979398] [mm-iface-modem.c:1101]
expire_signal_quality(): Signal quality value not updated in 60s, marking
as not being recent
ModemManager[3261]: <debug> [947012931.983252] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT^SIND?<CR>'
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x23d187ee> <pcomp> <accomp>]
ModemManager[3261]: <debug> [947012934.977239] [mm-iface-modem.c:934]
access_technologies_check_ready(): Couldn't refresh access technologies:
'Serial command timed out'
ModemManager[3261]: <debug> [947012934.977565] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 2 (close)
ModemManager[3261]: <debug> [947012934.977862] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): --> 'AT+CSQ<CR>'
ModemManager[3261]: <debug> [947012935.025309] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>^SIND: signal,0,99<CR><LF>^SIND:
service,0,1<CR><LF>^SIND: sounder,0,0<CR><LF>^SIND:
message,0,0<CR><LF>^SIND: call,0,0<CR><LF>^SIND: roam,0,0<CR><LF>^SIND:
smsfull,0,0<CR><LF>^SIND: rssi,0,2<CR><LF>^SIND: audio,0,0<CR><LF>^SIND:
simstatus,1,5<CR><LF>^SIND: simdata,0<CR><LF>^SIND:
eons,0,1,"0052004F0047004500520053","0052004F0047004500520053",1<CR><LF>^SIND:
nitz,0,"00310035002F00300034002F00320031002C00310036003A00310038003A00330032",-28,1<CR><LF>^SIND:
psinfo,0,6<CR><LF>^SIND: vcall,0,0<CR><LF>^SIND: simlocal,0,1<CR><LF>^SIND:
lsta,0,0<CR><LF>^SIND: ratmode,0,99<CR><LF>^SIND: pacsp,0,1<CR><LF>^SIND:
steerroam,0<CR><LF><CR><LF><CR><LF>OK<CR><LF><CR><LF>+CSQ:
12,99<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[3261]: <debug> [947012935.027049] [mm-port-serial.c:1294]
_close_internal(): (ttyUSB2) device open count is 1 (close)
ModemManager[3261]: <debug> [947012935.027847] [mm-iface-modem.c:1221]
signal_quality_check_ready(): Couldn't refresh signal quality: 'Could not
parse signal quality results'
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x23d187ee> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x23d187ee> <pcomp> <accomp>]
ModemManager[3261]: <debug> [947012943.109123] [mm-port-serial-at.c:440]
debug_log(): (ttyUSB2): <-- '<CR><LF>+CREG: 1,"FFDC","01DE0DD"<CR><LF>'
ModemManager[3261]: <debug> [947012943.109802]
[mm-iface-modem-location.c:295] notify_3gpp_location_update(): Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '302',
MNC: '720', Location area code: 'FFDC', Cell ID: '1DE0DD')
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x23d187ee> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x23d187ee> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x23d187ee> <pcomp> <accomp>]
LCP: timeout sending Config-Requests
Connection terminated.
Script /usr/sbin/chat -v -f /etc/ppp/peers/hspa_chat_down finished (pid
12549), status = 0x0
Serial link disconnected.
Modem hangup

On Tue, Apr 21, 2015 at 7:45 AM, Dan Williams <dcbw at redhat.com> wrote:

> On Mon, 2015-04-20 at 16:55 -0700, Ali Nematollahi wrote:
> > Hi guys
> >
> > I finally got Modem Manager up and running, and set it up with my Modem.
> > It's working great and I learned a lot playing around with it.
> > My question right now is, I managed to bring up a context on the modem
> but
> > I'm not sure how to hook up the PPP to it. I have a hspa and hspa_chat
> that
> > I call but they fail to connect to the network:
>
> Modems typically have different ports for different things; are you
> absolutely sure that ttyUSB3 is the right port for PPP?  Which TTY port
> is ModemManager reporting the "CONNECT" response on?
>
> Dan
>
> > pppd call hspa
> > {hspa_chat} Establishing Link...
> > Script /usr/sbin/chat -v -f /etc/ppp/peers/hspa_chat finished (pid
> 14633),
> > status = 0x0
> > Serial connection established.
> > using channel 3
> > Using interface ppp0
> > Connect: ppp0 <--> /dev/ttyUSB3
> > ModemManager[4728]: <debug> [946952787.798597] [mm-base-manager.c:296]
> > device_added(): (net/ppp0): could not get port's parent device
> > Warning - secret file /etc/ppp/pap-secrets has world and/or group access
> > sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x60506051> <pcomp>
> <accomp>]
> > sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x60506051> <pcomp>
> <accomp>]
> > sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x60506051> <pcomp>
> <accomp>]
> > sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x60506051> <pcomp>
> <accomp>]
> > sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x60506051> <pcomp>
> <accomp>]
> > sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x60506051> <pcomp>
> <accomp>]
> > sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x60506051> <pcomp>
> <accomp>]
> > sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x60506051> <pcomp>
> <accomp>]
> > LCP: timeout sending Config-Requests
> > Connection terminated.
> > Script /usr/sbin/chat -v -f /etc/ppp/peers/hspa_chat_down finished (pid
> > 14788), status = 0x0
> > Serial link disconnected.
> > Modem hangup
> >
> >
> > My hspa:
> > debug
> > child-timeout 10
> > nodetach
> > maxfail 0
> > unit 0
> > ktune
> > /dev/ttyUSB3
> > 115200
> > defaultroute
> > usepeerdns
> > mtu 496
> > mru 496
> >
> > lcp-echo-failure 3
> > lcp-echo-interval 15
> > lcp-max-configure 8
> > lcp-max-failure 5
> > lcp-max-terminate 5
> >
> > ipcp-max-failure 5
> > ipcp-max-configure 8
> > ipcp-max-terminate 5
> > ipcp-accept-local
> > ipcp-accept-remote
> >
> > novj
> > noccp
> >
> > noauth
> >
> > nocrtscts
> > lock
> > connect '/usr/sbin/chat -v -f /etc/ppp/peers/hspa_chat'
> > disconnect '/usr/sbin/chat -v -f /etc/ppp/peers/hspa_chat_down'
> >
> >
> >  and hspa_chat:
> > SAY '{hspa_chat} Establishing Link...\n'
> > TIMEOUT 1
> >
> >
> > Any documentation on this?
> > Thanks!
> > _______________________________________________
> > ModemManager-devel mailing list
> > ModemManager-devel at lists.freedesktop.org
> > http://lists.freedesktop.org/mailman/listinfo/modemmanager-devel
>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freedesktop.org/archives/modemmanager-devel/attachments/20150421/9209d211/attachment-0001.html>