I have a u-blox TOBY-R200 running on an embedded Linux device with the
ModemManager 1.8-rc2 build, plus the patch for "ublox: fix 'any' mode
building". On this device there seems to be an issue between the automatic
registration of the TOBY-R200 modem and ModemManager reaching the Simple
Connect State (5/8) Register.
Between reboots I can get ModemManager to have a quick registration and then
have a slow (40 or more seconds) registration, where ModemManager seems to have
caught the modem right before it finished auto registration or for some reason
a denied state occurs and restarts the entire registration over. The issue
seems to happen right before simple connect state (5/8) Register is run.
Here is what is reported during a quick registration step:
Simple connect state (5/8): Register
Already registered in network 'XXXXXX', automatic registration not launched...
Here is what is reported during a slow registration step:
Simple connect state (5/8): Register
Launching automatic network registration...
See attached files for logs of the fast and slow registration from the start of
a simple connect to step (6/8) Bearer
Any idea on what the difference is between the fast and slow registration and
what might be causing it? Any ideas how to fix it?
Best regards,
Matthew Starr
Apr 3 19:28:08 canect2 daemon.info ModemManager[253]: <info>
[1522783688.313995] Simple connect started...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.314179] PIN: unspecified
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.314271] Operator ID: unspecified
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.314352] Allowed roaming: yes
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.314430] APN: iot.aer.net
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.314516] IP family: ipv4v6
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.314593] Allowed authentication: unspecified
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.314676] User: unspecified
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.314751] Password: unspecified
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.314825] Number: *99#
Apr 3 19:28:08 canect2 daemon.info ModemManager[253]: <info>
[1522783688.314884] Simple connect state (4/8): Wait to get fully enabled
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.371520] (ttyACM0) device open count is 2 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.371897] (ttyACM0): --> 'AT+CFUN?<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.373456] (ttyACM0): <-- '<CR><LF>+CFUN:
1,0<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.374155] No need to change power state: already in 'on' power state
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.374465] Checking if SIM was swapped...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.374695] loading SIM identifier...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.374956] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.375359] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.375703] (ttyACM0): --> 'AT+CRSM=176,12258,0,0,10<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.391825] (ttyACM0): <-- '<CR><LF>+CRSM:
144,0,"XXXXXXXXXXXXXXXXXXXX"<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.392588] loaded SIM identifier: XXXXXXXXXXXXXXXXXXXX
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.392965] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.393380] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.393781] (ttyACM0): --> 'AT+IFC=?<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.395463] (ttyACM0): <-- '<CR><LF>+IFC:
(0-2),(0-2)<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.396347] TE supports no flow control
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.396663] TE supports XON/XOFF flow control
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.396856] TE supports RTS/CTS flow control
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.397058] TA supports no flow control
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.397243] TA supports XON/XOFF flow control
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.397411] TA supports RTS/CTS flow control
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.397769] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.398262] (ttyACM0) device open count is 4 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.398668] (ttyACM0) device open count is 3 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.399121] (ttyACM0): --> 'AT+IFC=2,2<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.400713] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.401297] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.401790] (ttyACM0): --> 'AT+CSCS=?<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.403340] (ttyACM0): <-- '<CR><LF>+CSCS:
("IRA","GSM","PCCP437","8859-1","UCS2","HEX")<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.404614] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.405199] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.405646] (ttyACM0): --> 'AT+CSCS="UCS2"<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.407217] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.407921] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.408364] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.408822] (ttyACM0): --> 'AT+CSCS?<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.410479] (ttyACM0): <-- '<CR><LF>+CSCS:
"UCS2"<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.411214] Modem has 3GPP capabilities, enabling the Modem 3GPP
interface...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.411592] Checking indicator support...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.411937] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.412359] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.412830] (ttyACM0): --> 'AT+CIND=?<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.414375] (ttyACM0): <-- '<CR><LF>+CIND:
("battchg",(0-5)),("signal",(0-5)),("service",(0-1)),("sounder",(0-1)),("message",(0-1)),("call",(0-1)),("roam",(0-1)),("smsfull",(0-1)),("gprs",(0-2)),("cal
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.415758] Modem supports signal quality indications via CIND at index
'2'(min: 0, max: 5)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.416061] Modem supports roaming indications via CIND at index '7'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.416324] Modem supports service indications via CIND at index '3'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.416632] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.417023] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.417489] (ttyACM0): --> 'AT+CMER=?<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.418713] (ttyACM0): <-- '<CR><LF>+CMER:
(0-3),(0),(0),(0-2),(0-1)<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.419497] Supported +CMER modes: discard-urcs,
discard-urcs-if-link-reserved, buffer-urcs-if-link-reserved, forward-urcs
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.419838] Supported +CMER indication settings: disable,
enable-not-caused-by-cind, enable-all
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.420048] +CMER enable mode: forward-urcs
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.420237] +CMER disable mode: discard-urcs
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.420407] +CMER indication setting: enable-not-caused-by-cind
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.420677] (ttyACM0) Setting 3GPP unsolicited events handlers
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.420942] (ttyACM1) Setting 3GPP unsolicited events handlers
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.421324] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.421744] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.422167] (ttyACM0): --> 'AT+CMER=3,0,0,1<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.423342] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.424000] (ttyACM1) device open count is 2 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.424486] (ttyACM0) device open count is 1 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.424900] (ttyACM1): --> 'AT+CMER=3,0,0,1<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.426209] (ttyACM1): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.428247] (ttyACM0) setting up 3GPP unsolicited registration messages
handlers
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.428586] (ttyACM1) setting up 3GPP unsolicited registration messages
handlers
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.429085] (ttyACM1) device open count is 1 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.429684] (ttyACM0) device open count is 2 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.430223] (ttyACM0): --> 'AT+CREG=2<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.431715] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.432452] (ttyACM1) device open count is 2 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.432931] (ttyACM0) device open count is 1 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.433351] (ttyACM1): --> 'AT+CREG=2<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.434714] (ttyACM1): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.435465] (ttyACM0) device open count is 2 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.435952] (ttyACM1) device open count is 1 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.436376] (ttyACM0): --> 'AT+CGREG=2<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.437834] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.438552] (ttyACM1) device open count is 2 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.438987] (ttyACM0) device open count is 1 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.439449] (ttyACM1): --> 'AT+CGREG=2<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.440831] (ttyACM1): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.441529] (ttyACM0) device open count is 2 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.441964] (ttyACM1) device open count is 1 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.442424] (ttyACM0): --> 'AT+CEREG=2<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.443707] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.444440] (ttyACM1) device open count is 2 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.444917] (ttyACM0) device open count is 1 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.445394] (ttyACM1): --> 'AT+CEREG=2<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.446830] (ttyACM1): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.447479] Modem has 3GPP/USSD capabilities, enabling the Modem
3GPP/USSD interface...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.447931] (ttyACM0) Setting unsolicited result code handlers
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.448186] (ttyACM1) Setting unsolicited result code handlers
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.448484] (ttyACM1) device open count is 1 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.449013] (ttyACM0) device open count is 2 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.449606] (ttyACM0): --> 'AT+CUSD=1<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.451089] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.451984] Modem has location capabilities, enabling the Location
interface...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.452508] Need to enable the following location sources: '3gpp-lac-ci'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.453201] Running registration checks (CS: 'yes', PS: 'yes', EPS:
'yes')
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.453622] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.454120] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.460386] Modem has messaging capabilities, enabling the Messaging
interface...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.461377] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.461988] (ttyACM0): --> 'AT+CREG?<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.463474] (ttyACM0): <-- '<CR><LF>+CREG:
2,1,"XXXX","XXXXXXXX",6<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.info ModemManager[253]: <info>
[1522783688.464251] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP
Registration state changed (unknown -> registering)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.464625] loading Operator Code...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.464975] (ttyACM0) device open count is 4 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.465769] Modem /org/freedesktop/ModemManager1/Modem/0: access
technology changed (unknown -> hspa)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.466255] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location
updated (MCC: '0', MNC: '0', Location area code: 'XXXX', Cell ID: 'XXXXXXX')
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.466941] (ttyACM0) device open count is 5 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.467369] (ttyACM0) device open count is 4 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.470803] (ttyACM0): --> 'AT+CMGF=?<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.472348] (ttyACM0): <-- '<CR><LF>+CMGF:
(0-1)<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.473429] (ttyACM0) device open count is 5 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.473870] (ttyACM0) device open count is 4 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.474357] (ttyACM0): --> 'AT+COPS=3,2;+COPS?<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.476082] (ttyACM0): <-- '<CR><LF>+COPS:
0,2,"XXXXXXXXXXXXXXXXXXXXXXXX",6<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.477795] loaded Operator Code: XXXXXX
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.478542] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location
updated (MCC: 'XXX', MNC: 'XXX', Location area code: 'XXXX', Cell ID: 'XXXXXXX')
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.478892] loading Operator Name...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.479191] (ttyACM0) device open count is 5 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.479567] (ttyACM0) device open count is 4 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.482937] (ttyACM0): --> 'AT+CGREG?<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.484508] (ttyACM0): <-- '<CR><LF>+CGREG:
2,1,"XXXX","XXXXXXXX",6,"6C"<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.485645] (ttyACM0) device open count is 5 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.486095] (ttyACM0) device open count is 4 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.486624] (ttyACM0): --> 'AT+CMGF=0<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.487957] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.488550] Successfully set preferred SMS mode: 'PDU'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.489388] (ttyACM0) device open count is 5 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.489857] (ttyACM0) device open count is 4 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.493184] (ttyACM0): --> 'AT+COPS=3,0;+COPS?<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.573973] (ttyACM0): <-- '<CR><LF>+COPS:
0,0,"0041005400260054",6<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.574667] loaded Operator Name: AT&T
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.575050] (ttyACM0) device open count is 3 (close)
Apr 3 19:28:08 canect2 daemon.info ModemManager[253]: <info>
[1522783688.578331] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP
Registration state changed (registering -> home)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.578958] Will start keeping track of state for subsystem '3gpp'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.582102] (ttyACM0): --> 'AT+CEREG?<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.583843] (ttyACM0): <-- '<CR><LF>+CEREG:
2,0<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.584801] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.585365] (ttyACM0): --> 'AT+CPMS="SR","ME","ME"<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.586972] (ttyACM0): <-- '<CR><LF>+CPMS:
0,10,1,100,1,100<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.587696] Listing SMS parts in storage 'bm'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.588021] Locking SMS storages to: mem1 (BM), mem2 (none)...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.588322] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.588780] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.589192] (ttyACM0): --> 'AT+CPMS="BM"<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.590714] (ttyACM0): <-- '<CR><LF>+CPMS:
0,10,1,100,1,100<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.591465] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.591976] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.592404] (ttyACM0): --> 'AT+CMGL=4<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.593966] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.594848] Listing SMS parts in storage 'me'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.595240] Locking SMS storages to: mem1 (ME), mem2 (none)...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.595611] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.596025] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.596479] (ttyACM0): --> 'AT+CPMS="ME"<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.598220] (ttyACM0): <-- '<CR><LF>+CPMS:
1,100,1,100,1,100<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.598983] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.599478] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.599909] (ttyACM0): --> 'AT+CMGL=4<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.601471] (ttyACM0): <-- '<CR><LF>+CMGL:
1,1,,44<CR><LF>XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.602611] Parsing PDU (1)...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.602944] SMSC address parsed: '+XXXXXXXXXXX'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.603153] Deliver type PDU detected
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.603331] Number parsed: '+XXXXX'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.603501] PID: 0
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.603672] user data encoding is GSM7
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.603830] user data length: 32 elements
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.603961] user data length: 28 bytes
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.604124] Decoding SMS text with '32' elements
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.604288] Converting SMS part text from GSM-7 to UTF-8...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.604565] Got UTF-8 text: 'This is a test of the LTE modem.'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.604767] Correctly parsed PDU (1)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.605013] SMS part at 'me/1' is from a singlepart SMS
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.608117] Added received SMS at '/org/freedesktop/ModemManager1/SMS/0'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.611508] Listing SMS parts in storage 'sm'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.611899] Locking SMS storages to: mem1 (SM), mem2 (none)...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.612276] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.612682] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.616190] (ttyACM0): --> 'AT+CPMS="SM"<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.618098] (ttyACM0): <-- '<CR><LF>+CPMS:
0,3,1,100,1,100<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.618886] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.619392] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.619816] (ttyACM0): --> 'AT+CMGL=4<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.621838] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.622730] Listing SMS parts in storage 'sr'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.623086] Locking SMS storages to: mem1 (SR), mem2 (none)...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.623402] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.623897] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.624332] (ttyACM0): --> 'AT+CPMS="SR"<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.626093] (ttyACM0): <-- '<CR><LF>+CPMS:
0,10,1,100,1,100<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.626860] (ttyACM0) device open count is 3 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.627361] (ttyACM0) device open count is 2 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.627790] (ttyACM0): --> 'AT+CMGL=4<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.629206] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.630221] (ttyACM0) Setting messaging unsolicited events handlers
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.630520] (ttyACM1) Setting messaging unsolicited events handlers
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.630828] (ttyACM0) device open count is 1 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.631289] (ttyACM0) Enabling messaging unsolicited events on primary
port
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.631615] (ttyACM0) device open count is 2 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.632151] (ttyACM0): --> 'AT+CNMI=2,1,2,1,0<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.633587] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.634177] (ttyACM0) Messaging unsolicited events enabled on primary
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.634477] (ttyACM1) Enabling messaging unsolicited events on
secondary port
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.634760] (ttyACM1) device open count is 2 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.635256] (ttyACM0) device open count is 1 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.635686] (ttyACM1): --> 'AT+CNMI=2,1,2,1,0<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.637222] (ttyACM1): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.637817] (ttyACM1) Messaging unsolicited events enabled on secondary
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.638146] Modem has voice capabilities, enabling the Voice
interface...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.639096] (ttyACM0) Setting voice unsolicited events handlers
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.639484] (ttyACM1) Setting voice unsolicited events handlers
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.639862] (ttyACM1) device open count is 1 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.640397] (ttyACM0) device open count is 2 (open)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.640960] (ttyACM0): --> 'AT+CLIP=1<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.642482] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.643338] (ttyACM0): --> 'AT+CRC=1<CR>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.644829] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.645545] Modem has time capabilities, enabling the Time interface...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.646061] (ttyACM0) device open count is 1 (close)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.646566] Modem has extended signal reporting capabilities, enabling
the Signal interface...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.646915] Extended signal information reporting disabled (rate: 0
seconds)
Apr 3 19:28:08 canect2 daemon.info ModemManager[253]: <info>
[1522783688.650160] Modem /org/freedesktop/ModemManager1/Modem/0: state changed
(enabling -> registered)
Apr 3 19:28:08 canect2 daemon.info ModemManager[253]: <info>
[1522783688.650917] Simple connect state (5/8): Register
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.651356] Already registered in network 'XXXXXX', automatic
registration not launched...
Apr 3 19:28:08 canect2 daemon.info NetworkManager[259]: <info> (ttyACM0):
modem state changed, 'enabling' --> 'registered' (reason: user-requested)
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.657865] Periodic signal checks enabled
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.658206] Periodic signal check refresh requested
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.658418] loading signal quality...
Apr 3 19:28:08 canect2 daemon.debug ModemManager[253]: <debug>
[1522783688.658717] (ttyACM0) device open count is 2 (open)
Apr 3 19:28:08 canect2 daemon.info ModemManager[253]: <info>
[1522783688.659285] Simple connect state (6/8): Bearer
Apr 3 20:40:51 canect2 daemon.info ModemManager[252]: <info>
[1522788051.345001] Simple connect started...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.345181] PIN: unspecified
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.345272] Operator ID: unspecified
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.345355] Allowed roaming: yes
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.345429] APN: iot.aer.net
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.345516] IP family: ipv4v6
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.345598] Allowed authentication: unspecified
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.345677] User: unspecified
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.345752] Password: unspecified
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.345827] Number: *99#
Apr 3 20:40:51 canect2 daemon.info ModemManager[252]: <info>
[1522788051.345884] Simple connect state (4/8): Wait to get fully enabled
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.415548] (ttyACM0) device open count is 2 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.416021] (ttyACM0): --> 'AT+CFUN?<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.419478] (ttyACM0): <-- '<CR><LF>+CFUN:
1,0<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.420169] No need to change power state: already in 'on' power state
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.420478] Checking if SIM was swapped...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.420713] loading SIM identifier...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.420973] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.421295] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.421632] (ttyACM0): --> 'AT+CRSM=176,12258,0,0,10<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.440233] (ttyACM0): <-- '<CR><LF>+CRSM:
144,0,"XXXXXXXXXXXXXXXXXXXX"<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.441004] loaded SIM identifier: XXXXXXXXXXXXXXXXXXXX
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.441383] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.441732] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.442074] (ttyACM0): --> 'AT+IFC=?<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.445002] (ttyACM0): <-- '<CR><LF>+IFC:
(0-2),(0-2)<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.445694] TE supports no flow control
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.445936] TE supports XON/XOFF flow control
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.446103] TE supports RTS/CTS flow control
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.446266] TA supports no flow control
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.446414] TA supports XON/XOFF flow control
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.446548] TA supports RTS/CTS flow control
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.446834] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.447229] (ttyACM0) device open count is 4 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.447553] (ttyACM0) device open count is 3 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.447886] (ttyACM0): --> 'AT+IFC=2,2<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.450851] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.451328] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.451697] (ttyACM0): --> 'AT+CSCS=?<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.454870] (ttyACM0): <-- '<CR><LF>+CSCS:
("IRA","GSM","PCCP437","8859-1","UCS2","HEX")<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.455855] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.456276] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.456670] (ttyACM0): --> 'AT+CSCS="UCS2"<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.459599] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.460148] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.460517] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.460853] (ttyACM0): --> 'AT+CSCS?<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.463725] (ttyACM0): <-- '<CR><LF>+CSCS:
"UCS2"<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.464378] Modem has 3GPP capabilities, enabling the Modem 3GPP
interface...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.464681] Checking indicator support...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.464943] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.465260] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.465588] (ttyACM0): --> 'AT+CIND=?<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.468628] (ttyACM0): <-- '<CR><LF>+CIND:
("battchg",(0-5)),("signal",(0-5)),("service",(0-1)),("sounder",(0-1)),("message",(0-1)),("call",(0-1)),("roam",(0-1)),("smsfull",(0-1)),("gprs",(0-2)),("cal
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.469671] Modem supports signal quality indications via CIND at index
'2'(min: 0, max: 5)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.469941] Modem supports roaming indications via CIND at index '7'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.470111] Modem supports service indications via CIND at index '3'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.470371] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.470721] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.471065] (ttyACM0): --> 'AT+CMER=?<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.473353] (ttyACM0): <-- '<CR><LF>+CMER:
(0-3),(0),(0),(0-2),(0-1)<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.474042] Supported +CMER modes: discard-urcs,
discard-urcs-if-link-reserved, buffer-urcs-if-link-reserved, forward-urcs
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.474323] Supported +CMER indication settings: disable,
enable-not-caused-by-cind, enable-all
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.474495] +CMER enable mode: forward-urcs
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.474636] +CMER disable mode: discard-urcs
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.474772] +CMER indication setting: enable-not-caused-by-cind
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.475012] (ttyACM0) Setting 3GPP unsolicited events handlers
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.475189] (ttyACM1) Setting 3GPP unsolicited events handlers
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.475488] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.475812] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.476150] (ttyACM0): --> 'AT+CMER=3,0,0,1<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.478353] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.478902] (ttyACM1) device open count is 2 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.479261] (ttyACM0) device open count is 1 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.479597] (ttyACM1): --> 'AT+CMER=3,0,0,1<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.481727] (ttyACM1): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.483336] (ttyACM0) setting up 3GPP unsolicited registration messages
handlers
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.483636] (ttyACM1) setting up 3GPP unsolicited registration messages
handlers
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.484136] (ttyACM1) device open count is 1 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.484624] (ttyACM0) device open count is 2 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.485071] (ttyACM0): --> 'AT+CREG=2<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.487724] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.488292] (ttyACM1) device open count is 2 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.488661] (ttyACM0) device open count is 1 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.489008] (ttyACM1): --> 'AT+CREG=2<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.491469] (ttyACM1): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.492009] (ttyACM0) device open count is 2 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.492363] (ttyACM1) device open count is 1 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.492701] (ttyACM0): --> 'AT+CGREG=2<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.495101] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.495662] (ttyACM1) device open count is 2 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.496033] (ttyACM0) device open count is 1 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.496378] (ttyACM1): --> 'AT+CGREG=2<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.498846] (ttyACM1): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.499394] (ttyACM0) device open count is 2 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.499753] (ttyACM1) device open count is 1 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.500085] (ttyACM0): --> 'AT+CEREG=2<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.502724] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.503289] (ttyACM1) device open count is 2 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.503654] (ttyACM0) device open count is 1 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.504076] (ttyACM1): --> 'AT+CEREG=2<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.506846] (ttyACM1): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.507343] Modem has 3GPP/USSD capabilities, enabling the Modem
3GPP/USSD interface...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.507724] (ttyACM0) Setting unsolicited result code handlers
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.507946] (ttyACM1) Setting unsolicited result code handlers
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.508197] (ttyACM1) device open count is 1 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.508592] (ttyACM0) device open count is 2 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.509022] (ttyACM0): --> 'AT+CUSD=1<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.511899] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.512591] Modem has location capabilities, enabling the Location
interface...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.512996] Need to enable the following location sources: '3gpp-lac-ci'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.513535] Running registration checks (CS: 'yes', PS: 'yes', EPS:
'yes')
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.513953] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.514346] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.519933] Modem has messaging capabilities, enabling the Messaging
interface...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.520672] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.521173] (ttyACM0): --> 'AT+CREG?<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.523789] (ttyACM0): <-- '<CR><LF>+CREG:
2,3<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.info ModemManager[252]: <info>
[1522788051.524438] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP
Registration state changed (unknown -> denied)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.525211] Will start keeping track of state for subsystem '3gpp'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.525825] (ttyACM0) device open count is 4 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.526181] (ttyACM0) device open count is 3 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.529255] (ttyACM0): --> 'AT+CMGF=?<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.531872] (ttyACM0): <-- '<CR><LF>+CMGF:
(0-1)<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.532696] (ttyACM0) device open count is 4 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.533070] (ttyACM0) device open count is 3 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.533431] (ttyACM0): --> 'AT+CGREG?<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.535985] (ttyACM0): <-- '<CR><LF>+CGREG:
2,3<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.info ModemManager[252]: <info>
[1522788051.536555] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP
Registration state changed (denied -> unknown)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.537547] (ttyACM0) device open count is 4 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.537931] (ttyACM0) device open count is 3 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.540948] (ttyACM0): --> 'AT+CMGF=0<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.543606] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.544180] Successfully set preferred SMS mode: 'PDU'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.544813] (ttyACM0) device open count is 4 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.545201] (ttyACM0) device open count is 3 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.548183] (ttyACM0): --> 'AT+CEREG?<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.550891] (ttyACM0): <-- '<CR><LF>+CEREG:
2,0<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.info ModemManager[252]: <info>
[1522788051.551461] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP
Registration state changed (unknown -> idle)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.552384] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.555535] (ttyACM0): --> 'AT+CPMS="SR","ME","ME"<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.558741] (ttyACM0): <-- '<CR><LF>+CPMS:
0,10,1,100,1,100<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.559324] Listing SMS parts in storage 'bm'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.559581] Locking SMS storages to: mem1 (BM), mem2 (none)...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.559854] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.560178] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.560507] (ttyACM0): --> 'AT+CPMS="BM"<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.563352] (ttyACM0): <-- '<CR><LF>+CPMS:
0,10,1,100,1,100<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.564032] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.564425] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.564796] (ttyACM0): --> 'AT+CMGL=4<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.567721] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.568416] Listing SMS parts in storage 'me'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.568689] Locking SMS storages to: mem1 (ME), mem2 (none)...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.568959] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.569277] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.569602] (ttyACM0): --> 'AT+CPMS="ME"<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.572482] (ttyACM0): <-- '<CR><LF>+CPMS:
1,100,1,100,1,100<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.573089] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.573470] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.573879] (ttyACM0): --> 'AT+CMGL=4<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.576994] (ttyACM0): <-- '<CR><LF>+CMGL:
1,1,,44<CR><LF>XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.577908] Parsing PDU (1)...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.578185] SMSC address parsed: '+XXXXXXXXXXX'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.578350] Deliver type PDU detected
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.578492] Number parsed: '+XXXXX'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.578627] PID: 0
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.578759] user data encoding is GSM7
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.578931] user data length: 32 elements
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.579063] user data length: 28 bytes
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.579191] Decoding SMS text with '32' elements
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.579316] Converting SMS part text from GSM-7 to UTF-8...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.579521] Got UTF-8 text: 'This is a test of the LTE modem.'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.579720] Correctly parsed PDU (1)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.579943] SMS part at 'me/1' is from a singlepart SMS
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.582194] Added received SMS at '/org/freedesktop/ModemManager1/SMS/0'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.585337] Listing SMS parts in storage 'sm'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.585670] Locking SMS storages to: mem1 (SM), mem2 (none)...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.586027] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.586375] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.589391] (ttyACM0): --> 'AT+CPMS="SM"<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.592741] (ttyACM0): <-- '<CR><LF>+CPMS:
0,3,1,100,1,100<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.593369] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.593821] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.594186] (ttyACM0): --> 'AT+CMGL=4<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.598094] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.598796] Listing SMS parts in storage 'sr'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.599069] Locking SMS storages to: mem1 (SR), mem2 (none)...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.599336] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.599655] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.599979] (ttyACM0): --> 'AT+CPMS="SR"<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.603106] (ttyACM0): <-- '<CR><LF>+CPMS:
0,10,1,100,1,100<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.603727] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.604219] (ttyACM0) device open count is 2 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.604568] (ttyACM0): --> 'AT+CMGL=4<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.607350] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.608127] (ttyACM0) Setting messaging unsolicited events handlers
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.608395] (ttyACM1) Setting messaging unsolicited events handlers
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.608667] (ttyACM0) device open count is 1 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.609003] (ttyACM0) Enabling messaging unsolicited events on primary
port
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.609286] (ttyACM0) device open count is 2 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.609676] (ttyACM0): --> 'AT+CNMI=2,1,2,1,0<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.612343] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.612837] (ttyACM0) Messaging unsolicited events enabled on primary
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.613056] (ttyACM1) Enabling messaging unsolicited events on
secondary port
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.613333] (ttyACM1) device open count is 2 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.613646] (ttyACM0) device open count is 1 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.614059] (ttyACM1): --> 'AT+CNMI=2,1,2,1,0<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.616842] (ttyACM1): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.617327] (ttyACM1) Messaging unsolicited events enabled on secondary
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.617575] Modem has voice capabilities, enabling the Voice
interface...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.618366] (ttyACM0) Setting voice unsolicited events handlers
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.618661] (ttyACM1) Setting voice unsolicited events handlers
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.618958] (ttyACM1) device open count is 1 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.619365] (ttyACM0) device open count is 2 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.619798] (ttyACM0): --> 'AT+CLIP=1<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.622596] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.623261] (ttyACM0): --> 'AT+CRC=1<CR>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.625965] (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.626487] Modem has time capabilities, enabling the Time interface...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.626908] (ttyACM0) device open count is 1 (close)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.627258] Modem has extended signal reporting capabilities, enabling
the Signal interface...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.627556] Extended signal information reporting disabled (rate: 0
seconds)
Apr 3 20:40:51 canect2 daemon.info ModemManager[252]: <info>
[1522788051.630380] Modem /org/freedesktop/ModemManager1/Modem/0: state changed
(enabling -> enabled)
Apr 3 20:40:51 canect2 daemon.info ModemManager[252]: <info>
[1522788051.630992] Simple connect state (5/8): Register
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.631363] Launching automatic network registration...
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.631656] (ttyACM0) device open count is 2 (open)
Apr 3 20:40:51 canect2 daemon.info NetworkManager[258]: <info> (ttyACM0):
modem state changed, 'enabling' --> 'enabled' (reason: user-requested)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.637801] Running registration checks (CS: 'yes', PS: 'yes', EPS:
'yes')
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.638179] (ttyACM0) device open count is 3 (open)
Apr 3 20:40:51 canect2 daemon.debug ModemManager[252]: <debug>
[1522788051.638542] (ttyACM0): --> 'AT+COPS=0<CR>'
Apr 3 20:40:53 canect2 daemon.debug ModemManager[252]: <debug>
[1522788053.488558] (ttyACM1): <-- '<CR><LF>+CIEV: 9,1<CR><LF><CR><LF>+CEREG:
3<CR><LF>'
Apr 3 20:40:53 canect2 daemon.info ModemManager[252]: <info>
[1522788053.489053] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP
Registration state changed (idle -> unknown)
Apr 3 20:40:53 canect2 daemon.debug ModemManager[252]: <debug>
[1522788053.666272] (ttyACM1): <-- '<CR><LF>+CIEV: 2,2<CR><LF>'
Apr 3 20:40:53 canect2 daemon.debug ModemManager[252]: <debug>
[1522788053.666996] Modem /org/freedesktop/ModemManager1/Modem/0: signal
quality updated (40)
Apr 3 20:40:55 canect2 daemon.debug ModemManager[252]: <debug>
[1522788055.060208] (ttyACM1): <-- '<CR><LF>+CGREG:
1,"XXXX","XXXXXXXX",6,"6C"<CR><LF><CR><LF>+CIEV: 9,2<CR><LF><CR><LF>+CEREG:
4<CR><LF>'
Apr 3 20:40:55 canect2 daemon.info ModemManager[252]: <info>
[1522788055.060971] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP
Registration state changed (unknown -> registering)
Apr 3 20:40:55 canect2 daemon.debug ModemManager[252]: <debug>
[1522788055.061281] loading Operator Code...
Apr 3 20:40:55 canect2 daemon.debug ModemManager[252]: <debug>
[1522788055.061547] (ttyACM0) device open count is 4 (open)
Apr 3 20:40:55 canect2 daemon.debug ModemManager[252]: <debug>
[1522788055.062068] Modem /org/freedesktop/ModemManager1/Modem/0: access
technology changed (unknown -> hspa)
Apr 3 20:40:55 canect2 daemon.debug ModemManager[252]: <debug>
[1522788055.062407] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location
updated (MCC: '0', MNC: '0', Location area code: 'XXXX', Cell ID: 'XXXXXXX')
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.606142] (ttyACM0): <-- '<CR><LF>OK<CR><LF><CR><LF>+CEREG:
3<CR><LF><CR><LF>+CGREG: 1,"XXXX","XXXXXXXX",6,"6C"<CR><LF><CR><LF>+CEREG:
4<CR><LF><CR><LF>+CIEV: 9,1<CR><LF><CR><LF>+CIEV: 2,2<CR><LF><C
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.606881] Modem /org/freedesktop/ModemManager1/Modem/0: signal
quality updated (40)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.608089] Running registration checks (CS: 'yes', PS: 'yes', EPS:
'yes')
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.608319] (ttyACM0) device open count is 5 (open)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.608499] (ttyACM0) device open count is 4 (close)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.608746] (ttyACM0): --> 'AT+CREG?<CR>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.609631] (ttyACM1): <-- '<CR><LF>+CREG:
1,"XXXX","XXXXXXXX",6<CR><LF><CR><LF>+CIEV: 3,1<CR><LF>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.610950] (ttyACM0): <-- '<CR><LF>+CREG:
2,1,"XXXX","XXXXXXXX",6<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.611802] (ttyACM0) device open count is 5 (open)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.612181] (ttyACM0) device open count is 4 (close)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.612545] (ttyACM0): --> 'AT+COPS=3,2;+COPS?<CR>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.614280] (ttyACM0): <-- '<CR><LF>+COPS:
0,2,"XXXXXXXXXXXXXXXXXXXXXXXX",6<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.615585] loaded Operator Code: XXXXXX
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.616236] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location
updated (MCC: 'XXX', MNC: 'XXX', Location area code: 'XXXX', Cell ID: 'XXXXXXX')
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.616525] loading Operator Name...
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.616777] (ttyACM0) device open count is 5 (open)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.617055] (ttyACM0) device open count is 4 (close)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.620390] (ttyACM0): --> 'AT+CREG?<CR>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.622536] (ttyACM0): <-- '<CR><LF>+CREG:
2,1,"XXXX","XXXXXXXX",6<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.623492] (ttyACM0) device open count is 5 (open)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.623873] (ttyACM0) device open count is 4 (close)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.624235] (ttyACM0): --> 'AT+CGREG?<CR>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.626906] (ttyACM0): <-- '<CR><LF>+CGREG:
2,1,"XXXX","XXXXXXXX",6,"6C"<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.627798] (ttyACM0) device open count is 5 (open)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.628170] (ttyACM0) device open count is 4 (close)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.628538] (ttyACM0): --> 'AT+COPS=3,0;+COPS?<CR>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.880423] (ttyACM0): <-- '<CR><LF>+COPS:
0,0,"0041005400260054",6<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.881255] loaded Operator Name: AT&T
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.881781] (ttyACM0) device open count is 3 (close)
Apr 3 20:41:29 canect2 daemon.info ModemManager[252]: <info>
[1522788089.884912] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP
Registration state changed (registering -> home)
Apr 3 20:41:29 canect2 daemon.info ModemManager[252]: <info>
[1522788089.885508] Modem /org/freedesktop/ModemManager1/Modem/0: state changed
(enabled -> registered)
Apr 3 20:41:29 canect2 daemon.info NetworkManager[258]: <info> (ttyACM0):
modem state changed, 'enabled' --> 'registered' (reason: unknown)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.891482] Periodic signal checks enabled
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.891731] Periodic signal check refresh requested
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.891898] loading signal quality...
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.892158] (ttyACM0) device open count is 4 (open)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.895265] (ttyACM0): --> 'AT+CGREG?<CR>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.899051] (ttyACM0): <-- '<CR><LF>+CGREG:
2,1,"XXXX","XXXXXXXX",6,"6C"<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.899900] (ttyACM0) device open count is 5 (open)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.900278] (ttyACM0) device open count is 4 (close)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.900639] (ttyACM0): --> 'AT+CEREG?<CR>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.903400] (ttyACM0): <-- '<CR><LF>+CEREG:
2,0<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.904144] Initial 3GPP registration checks finished
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.904428] (ttyACM0) device open count is 3 (close)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.904755] (ttyACM0): --> 'AT+CIND?<CR>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.907784] (ttyACM0): <-- '<CR><LF>+CIND:
5,2,1,0,0,0,0,0,2,0,0,0<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.908781] Modem /org/freedesktop/ModemManager1/Modem/0: signal
quality updated (40)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.909212] (ttyACM0) device open count is 2 (close)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.909581] Polling to refresh access technologies is unsupported
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.909829] Initial signal quality and access technology ready:
fallback to default frequency
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.910035] Periodic signal quality checks scheduled in 30s
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.910331] (ttyACM0): --> 'AT+CEREG?<CR>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.913040] (ttyACM0): <-- '<CR><LF>+CEREG:
2,0<CR><LF><CR><LF>OK<CR><LF>'
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.913796] Periodic signal check refresh requested
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.914065] loading signal quality...
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.914339] (ttyACM0) device open count is 3 (open)
Apr 3 20:41:29 canect2 daemon.debug ModemManager[252]: <debug>
[1522788089.914637] Modem is currently registered in a 3GPP network
Apr 3 20:41:29 canect2 daemon.info ModemManager[252]: <info>
[1522788089.914849] Simple connect state (6/8): Bearer
_______________________________________________
ModemManager-devel mailing list
[email protected]
https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel
