I have a Boron LTE that randomly loses connection and flashes green for hours or days at a time. It can always be fixed by removing power and restarting it. I have not found a way to detect it and correct it in software.
I captured the following with cloud-debug. This sequence repeats for hours… From what I can tell, the physical connection is made but there is no response when it tries to make a PPP connection. The dozen or so lines starting at 1120464983 demonstrate this.
Can anyone shed light on what I am seeing here and what can be done to fix it?
1120450025 [ncp.client] TRACE: Powering modem on, ncpId: 0x44
1120450026 [net.pppncp] TRACE: NCP event 3
1120450026 [net.pppncp] TRACE: NCP power state changed: IF_POWER_STATE_POWERING_UP
1120450026 [system.nm] TRACE: Interface 4 power state changed: 4
1120450176 [net.pppncp] TRACE: NCP event 3
1120450176 [net.pppncp] TRACE: NCP power state changed: IF_POWER_STATE_UP
1120450177 [system.nm] TRACE: Interface 4 power state changed: 2
1120450177 [ncp.client] TRACE: Modem powered on
1120450177 [ncp.client] TRACE: Setting UART voltage translator state 1
1120450277 [ncp.client] TRACE: Setting UART voltage translator state 0
1120450377 [ncp.client] TRACE: Setting UART voltage translator state 1
1120451378 [ncp.at] TRACE: > AT
1120452379 [ncp.at] TRACE: > AT
1120453380 [ncp.at] TRACE: > AT
1120454203 [app] INFO: Still trying to connect to the cloud 311:13:35
1120454203 [app] INFO: Power source: USB Host
1120454206 [app] INFO: Battery state: charged, SoC: 100.00
1120454381 [ncp.at] TRACE: > AT
1120455382 [ncp.at] TRACE: > AT
1120456383 [ncp.at] TRACE: > AT
1120457384 [ncp.at] TRACE: > AT
1120458385 [ncp.at] TRACE: > AT
1120459386 [ncp.at] TRACE: > AT
1120460387 [ncp.at] TRACE: > AT
1120461389 [ncp.at] TRACE: > AT
1120461394 [ncp.at] TRACE: < OK
1120461395 [ncp.client] TRACE: NCP ready to accept AT commands
1120461395 [ncp.at] TRACE: > AT
1120461398 [ncp.at] TRACE: < OK
1120461398 [ncp.at] TRACE: > ATI9
1120461404 [ncp.at] TRACE: < OK
1120461405 [ncp.client] TRACE: App firmware: 201
1120461405 [ncp.at] TRACE: > AT+UGPIOC?
1120461414 [ncp.at] TRACE: < +UGPIOC:
1120461418 [ncp.at] TRACE: < OK
1120461419 [ncp.at] TRACE: > AT+UGPIOR=23
1120461427 [ncp.at] TRACE: < +UGPIOR: 23,1
1120461428 [ncp.at] TRACE: < OK
1120461428 [ncp.client] INFO: Using internal SIM card
1120461428 [ncp.at] TRACE: > AT+CPIN?
1120461436 [ncp.at] TRACE: < +CPIN: READY
1120461436 [ncp.at] TRACE: < OK
1120461437 [ncp.at] TRACE: > AT+CCID
1120461446 [ncp.at] TRACE: < +CCID: 89014103271529XXXXXXX
1120461446 [ncp.at] TRACE: < OK
1120461447 [ncp.at] TRACE: > AT+IFC?
1120461455 [ncp.at] TRACE: < +IFC: 2,2
1120461456 [ncp.at] TRACE: < OK
1120461456 [ncp.at] TRACE: > AT+IFC=2,2
1120461461 [ncp.at] TRACE: < OK
1120461461 [ncp.at] TRACE: > AT
1120461468 [ncp.at] TRACE: < OK
1120462468 [ncp.at] TRACE: > AT
1120462474 [ncp.at] TRACE: < OK
1120462474 [ncp.at] TRACE: > AT+CCID
1120462484 [ncp.at] TRACE: < +CCID: 89014103271529XXXXXXX
1120462484 [ncp.at] TRACE: < OK
1120462485 [ncp.at] TRACE: > AT+CIMI
1120462493 [ncp.at] TRACE: < OK
1120462494 [ncp.at] TRACE: > AT+UMNOPROF?
1120462505 [ncp.at] TRACE: < +UMNOPROF: 2
1120462508 [app.help] INFO: Mobile Network Operator Profile (UMNOPROF): AT&T (2)
1120462506 [ncp.at] TRACE: < OK
1120462506 [ncp.at] TRACE: > AT+COPS=3,2
1120462513 [app.help] INFO: Operator Selection (COPS) Set: mode=set format (3) format=numeric (2)
1120462511 [ncp.at] TRACE: < OK
1120462511 [ncp.at] TRACE: > AT+CGEREP=1,0
1120462519 [ncp.at] TRACE: < OK
1120462519 [ncp.at] TRACE: > AT+URAT?
1120462524 [ncp.at] TRACE: < +URAT: 7
1120462525 [ncp.at] TRACE: < OK
1120462525 [ncp.at] TRACE: > AT+CPSMS?
1120462534 [ncp.at] TRACE: < +CPSMS:0,,,"01100000","00000000"
1120462534 [ncp.at] TRACE: < OK
1120462535 [ncp.at] TRACE: > AT+CEDRXS?
1120462541 [ncp.at] TRACE: < +CEDRXS:
1120462542 [ncp.at] TRACE: < OK
1120462542 [ncp.at] TRACE: > AT+CMUX=0,0,,1509,,,,,
1120462551 [ncp.at] TRACE: < OK
1120462551 [mux] INFO: Starting GSM07.10 muxer
1120462552 [mux] INFO: GSM07.10 muxer thread started
1120462552 [mux] INFO: Openning mux channel 0
1120462555 [mux] INFO: Openning mux channel 1
1120462561 [ncp.at] TRACE: > AT
1120462562 [ncp.at] TRACE: < +CEREG: 0
1120462564 [app.help] INFO: EPS network (CEREG) Status: not registered, not searching (0)
1120462570 [ncp.at] TRACE: < OK
1120462570 [ncp.client] TRACE: NCP state changed: 1
1120462571 [net.pppncp] TRACE: NCP event 1
1120462571 [net.ppp.client] TRACE: PPP thread event ADM_UP data=0
1120462574 [ncp.at] TRACE: > AT+CFUN?
1120462579 [app.help] INFO: Set module functionality (CFUN): minimum functionality (0)
1120462585 [ncp.at] TRACE: < +CFUN: 1
1120462585 [ncp.at] TRACE: < OK
1120462585 [ncp.at] TRACE: > AT+CCID
1120462597 [ncp.at] TRACE: < +CCID: 89014103271529XXXXXXXX
1120462597 [ncp.at] TRACE: < OK
1120462598 [ncp.at] TRACE: > AT+CIMI
1120462609 [ncp.at] TRACE: < OK
1120462610 [ncp.at] TRACE: > AT+CGDCONT?
1120462611 [app.help] INFO: PDP context definition (CGDCONT): cid=0 pdpType= APN=
1120462622 [ncp.at] TRACE: < +CGDCONT: 1,"IP","10569.mcs","10.96.156.XXX",0,0,0,0
1120462623 [ncp.at] TRACE: < OK
1120462623 [ncp.at] TRACE: > AT+CFUN?
1120462627 [app.help] INFO: Set module functionality (CFUN): minimum functionality (0)
1120462632 [ncp.at] TRACE: < +CFUN: 1
1120462632 [ncp.at] TRACE: < OK
1120462633 [ncp.at] TRACE: > AT+CEREG=2
1120462636 [app.help] INFO: EPS network (CEREG) Set to location enabled (2)
1120462640 [ncp.at] TRACE: < OK
1120462640 [ncp.client] TRACE: NCP connection state changed: 1
1120462641 [net.pppncp] TRACE: NCP event 2
1120462641 [net.pppncp] TRACE: State changed event: 1
1120462642 [ncp.at] TRACE: > AT+COPS?
1120462642 [net.ppp.client] TRACE: PPP thread event LOWER_DOWN data=0
1120462651 [ncp.at] TRACE: < +COPS: 0,2,"310410",8
1120462655 [app.help] INFO: Operator Selection (COPS) Read: mode=automatic (0)
1120462657 [app.help] INFO: format=numeric (2)
1120462667 [app.help] INFO: oper=310410 carrier=AT&T Wireless Inc. country=United States
1120462652 [ncp.at] TRACE: < OK
1120462652 [ncp.at] TRACE: > AT+CEREG?
1120462663 [ncp.at] TRACE: < +CEREG: 2,1,"700","1640B09",8
1120462672 [app.help] INFO: EPS network (CEREG) Status: registered, home network (1)
1120462673 [app.help] INFO: Tracking area code: 700
1120462673 [app.help] INFO: Cell identifier: 1640B09
1120462675 [app.help] INFO: Access technology: LTE Cat-M1 (8)
1120462664 [ncp.at] TRACE: < OK
1120462664 [ncp.client] TRACE: NCP connection state changed: 2
1120462665 [mux] INFO: Openning mux channel 2
1120463931 [net.pppncp] TRACE: NCP event 100
1120463932 [net.pppncp] TRACE: New auth info
1120463933 [net.pppncp] TRACE: NCP event 2
1120463933 [net.pppncp] TRACE: State changed event: 2
1120463934 [net.ppp.client] TRACE: PPP thread event LOWER_UP data=0
1120463935 [net.ppp.client] TRACE: State READY -> CONNECT
1120463935 [net.ppp.client] TRACE: State CONNECT -> CONNECTING
1120463934 [ncp.at] TRACE: > AT+CIMI
1120463943 [ncp.at] TRACE: < OK
1120463944 [ncp.at] TRACE: > AT
1120463950 [ncp.at] TRACE: < OK
1120463951 [ncp.at] TRACE: > AT+CGATT?
1120463959 [ncp.at] TRACE: < +CGATT: 1
1120463959 [ncp.at] TRACE: < OK
1120464203 [app] INFO: Still trying to connect to the cloud 311:13:45
1120464203 [app] INFO: Power source: USB Host
1120464206 [app] INFO: Battery state: charged, SoC: 100.00
1120464961 [ncp.at] TRACE: > AT
1120464969 [ncp.at] TRACE: < OK
1120464970 [ncp.at] TRACE: > ATD*99***1#
1120464983 [net.ppp.client] TRACE: PPP phase -> Initialize
1120464984 [net.ppp.client] TRACE: PPP phase -> Establish
1120464984 [lwip.ppp] TRACE: sent [LCP ConfReq id=0xd8 <asyncmap 0x0> <magic 0x4b331e93> <pcomp> <a
1120470984 [lwip.ppp] TRACE: sent [LCP ConfReq id=0xd8 <asyncmap 0x0> <magic 0x4b331e93> <pcomp> <a
1120474203 [app] INFO: Still trying to connect to the cloud 311:13:55
1120474203 [app] INFO: Power source: USB Host
1120474206 [app] INFO: Battery state: charged, SoC: 100.00
1120476984 [lwip.ppp] TRACE: sent [LCP ConfReq id=0xd8 <asyncmap 0x0> <magic 0x4b331e93> <pcomp> <a
1120482984 [lwip.ppp] TRACE: sent [LCP ConfReq id=0xd8 <asyncmap 0x0> <magic 0x4b331e93> <pcomp> <a
1120484203 [app] INFO: Still trying to connect to the cloud 311:14:05
1120484203 [app] INFO: Power source: USB Host
1120484206 [app] INFO: Battery state: charged, SoC: 100.00
1120488984 [lwip.ppp] TRACE: sent [LCP ConfReq id=0xd8 <asyncmap 0x0> <magic 0x4b331e93> <pcomp> <a
1120494203 [app] INFO: Still trying to connect to the cloud 311:14:15
1120494203 [app] INFO: Power source: USB Host
1120494206 [app] INFO: Battery state: charged, SoC: 100.00
1120494984 [lwip.ppp] TRACE: sent [LCP ConfReq id=0xd8 <asyncmap 0x0> <magic 0x4b331e93> <pcomp> <a
1120500984 [lwip.ppp] TRACE: sent [LCP ConfReq id=0xd8 <asyncmap 0x0> <magic 0x4b331e93> <pcomp> <a
1120504203 [app] INFO: Still trying to connect to the cloud 311:14:25
1120504203 [app] INFO: Power source: USB Host
1120504206 [app] INFO: Battery state: charged, SoC: 100.00
1120506984 [lwip.ppp] TRACE: sent [LCP ConfReq id=0xd8 <asyncmap 0x0> <magic 0x4b331e93> <pcomp> <a
1120512984 [lwip.ppp] TRACE: sent [LCP ConfReq id=0xd8 <asyncmap 0x0> <magic 0x4b331e93> <pcomp> <a
1120514203 [app] INFO: Still trying to connect to the cloud 311:14:35
1120514203 [app] INFO: Power source: USB Host
1120514206 [app] INFO: Battery state: charged, SoC: 100.00
1120518984 [lwip.ppp] TRACE: sent [LCP ConfReq id=0xd8 <asyncmap 0x0> <magic 0x4b331e93> <pcomp> <a
1120524203 [app] INFO: Still trying to connect to the cloud 311:14:45
1120524203 [app] INFO: Power source: USB Host
1120524206 [app] INFO: Battery state: charged, SoC: 100.00
1120524984 [net.ppp.client] TRACE: PPP phase -> Disconnect
1120524985 [net.ppp.client] TRACE: PPP phase -> Dead
1120524985 [net.ppp.client] TRACE: PPP thread event ERROR data=5
1120524985 [net.pppncp] ERROR: PPP error event data=5
1120524986 [net.ppp.client] TRACE: PPP thread event DOWN data=0
1120524986 [net.ppp.client] TRACE: State CONNECTING -> DISCONNECT
1120524986 [net.ppp.client] TRACE: State DISCONNECT -> DISCONNECTING
1120524987 [net.ppp.client] TRACE: PPP thread event ERROR data=5
1120524987 [net.pppncp] ERROR: PPP error event data=5
1120524987 [net.ppp.client] TRACE: PPP thread event DOWN data=0
1120524988 [net.ppp.client] TRACE: State DISCONNECTING -> DISCONNECTED
1120524988 [net.ppp.client] TRACE: State DISCONNECTED -> CONNECT
1120525088 [net.ppp.client] TRACE: State CONNECT -> CONNECTING
1120525089 [ncp.at] TRACE: > AT
1120525098 [ncp.at] TRACE: < OK
1120525098 [ncp.at] TRACE: > AT+CGATT?
1120525109 [ncp.at] TRACE: < +CGATT: 1
1120525110 [ncp.at] TRACE: < OK
1120526111 [ncp.at] TRACE: > AT
1120527112 [ncp.at] TRACE: > AT
1120528113 [ncp.at] TRACE: > AT
1120529114 [ncp.at] TRACE: > AT
1120530115 [ncp.at] TRACE: > AT
1120531115 [ncp.client] ERROR: Failed to enter data mode
1120531116 [net.ppp.client] ERROR: Failed to dial
1120531116 [net.ppp.client] TRACE: State CONNECTING -> CONNECT
1120531116 [net.pppncp] TRACE: NCP event 3
1120531117 [net.pppncp] TRACE: NCP power state changed: IF_POWER_STATE_POWERING_DOWN
1120531117 [system.nm] TRACE: Interface 4 power state changed: 3
1120531117 [ncp.client] TRACE: Try powering modem off using AT command
1120531118 [ncp.at] TRACE: > AT+CPWROFF
1120531128 [ncp.at] TRACE: < OK
1120531128 [ncp.client] TRACE: Waiting the modem to be turned off...
1120531216 [net.ppp.client] TRACE: State CONNECT -> CONNECTING
1120531348 [net.pppncp] TRACE: NCP event 3
1120531348 [net.pppncp] TRACE: NCP power state changed: IF_POWER_STATE_DOWN
1120531349 [system.nm] TRACE: Interface 4 power state changed: 1
1120531349 [ncp.client] TRACE: It takes 221 ms to power off the modem.
1120531349 [mux] INFO: Stopping GSM07.10 muxer
1120531350 [mux] INFO: Gracefully stopping GSM07.10 muxer
1120531350 [mux] INFO: Closing all muxed channels
1120531350 [mux] INFO: Closing mux channel 1
1120531351 [mux] INFO: Closing mux channel 2
1120531351 [mux] INFO: Muxed channel 3 already closed
1120531351 [mux] INFO: Muxed channel 4 already closed
1120531352 [mux] INFO: GSM07.10 muxer thread exiting
1120531352 [ncp.client] TRACE: NCP connection state changed: 1
1120531352 [net.pppncp] TRACE: NCP event 2
1120531353 [net.pppncp] TRACE: State changed event: 1
1120531353 [mux] INFO: GSM07.10 muxer stopped
1120531353 [ncp.client] TRACE: Setting UART voltage translator state 0
1120531354 [ncp.client] TRACE: Soft power off modem successfully
1120531354 [ncp.client] TRACE: Deinit modem serial.
1120531355 [ncp.client] ERROR: Failed to enter data mode
1120531355 [net.ppp.client] ERROR: Failed to dial
1120531355 [net.ppp.client] TRACE: State CONNECTING -> CONNECT
1120531356 [net.ppp.client] TRACE: PPP thread event LOWER_DOWN data=0
1120531356 [net.ppp.client] TRACE: State CONNECT -> DISCONNECT
1120531356 [net.ppp.client] TRACE: State DISCONNECT -> DISCONNECTING
1120531357 [net.ppp.client] TRACE: PPP thread event ERROR data=5
1120531357 [net.pppncp] ERROR: PPP error event data=5
1120531357 [net.ppp.client] TRACE: PPP thread event DOWN data=0
1120531358 [net.ppp.client] TRACE: State DISCONNECTING -> DISCONNECTED
1120531358 [net.ppp.client] TRACE: State DISCONNECTED -> READY
1120531454 [net.pppncp] ERROR: Failed to initialize cellular NCP client: -210
1120531455 [ncp.client] TRACE: Modem already off
1120531455 [ncp.client] TRACE: Setting UART voltage translator state 0
1120531455 [ncp.client] TRACE: Soft power off modem successfully
1120531455 [ncp.client] TRACE: Deinit modem serial.
1120531456 [ncp.client] TRACE: NCP connection state changed: 0
1120531456 [net.pppncp] TRACE: NCP event 2
1120531456 [net.pppncp] TRACE: State changed event: 0
1120531457 [ncp.client] TRACE: NCP state changed: 0
1120531457 [net.pppncp] TRACE: NCP event 1
1120531457 [net.ppp.client] TRACE: PPP thread event LOWER_DOWN data=0
1120531557 [ncp.client] TRACE: Powering modem on, ncpId: 0x44
1120531558 [net.pppncp] TRACE: NCP event 3
1120531558 [net.pppncp] TRACE: NCP power state changed: IF_POWER_STATE_POWERING_UP
1120531558 [system.nm] TRACE: Interface 4 power state changed: 4
1120531708 [net.pppncp] TRACE: NCP event 3
1120531708 [net.pppncp] TRACE: NCP power state changed: IF_POWER_STATE_UP
1120531709 [system.nm] TRACE: Interface 4 power state changed: 2
1120531709 [ncp.client] TRACE: Modem powered on
1120531709 [ncp.client] TRACE: Setting UART voltage translator state 1
1120531809 [ncp.client] TRACE: Setting UART voltage translator state 0
1120531909 [ncp.client] TRACE: Setting UART voltage translator state 1
For reference, here is what a successful connection looks like after cycling the power:
Opening serial monitor for com port: "/dev/tty.usbmodem142301"
Serial monitor opened successfully:
> 0000015470 [app] INFO: Starting Tests!
0000015470 [app] INFO: Platform: Boron
0000015470 [app] INFO: Binary compiled for: 4.0.0
0000015470 [app] INFO: Cloud Debug Release 4.0.5
0000015471 [app] INFO: System version: 4.0.2
0000015472 [app] INFO: Device ID: e00fce68f7abeefdxxxxxxxxxx
0000015472 [app] INFO: Power source: USB Host
0000015472 [app] INFO: Battery state: disconnected, SoC: -1.00
0000015473 [app] INFO: This device could have Ethernet (is 3rd generation)
0000015474 [app] INFO: FEATURE_ETHERNET_DETECTION not enabled, so Ethernet will not be used (even i
0000023484 [app] INFO: deviceID: e00fce68f7abeefdxxxxxxxx
0000023485 [app] INFO: PMIC inputVoltageLimit: 3880 mV
0000023486 [app] INFO: PMIC inputCurrentLimit: 500 mA
0000023487 [app] INFO: PMIC minimumSystemVoltage: 3500 mV
0000023488 [app] INFO: PMIC chargeCurrentValue: 896 mA
0000023488 [app] INFO: PMIC chargeVoltageValue: 4112 mV
0000023489 [app] INFO: modem is not yet responding
0000023490 [system.nm] INFO: State changed: DISABLED -> IFACE_DOWN
0000023491 [system.nm] INFO: State changed: IFACE_DOWN -> IFACE_REQUEST_UP
0000023492 [ncp.client] TRACE: Powering modem on, ncpId: 0x44
0000023493 [net.pppncp] TRACE: NCP event 3
0000023493 [net.pppncp] TRACE: NCP power state changed: IF_POWER_STATE_POWERING_UP
0000023493 [system.nm] INFO: State changed: IFACE_REQUEST_UP -> IFACE_UP
0000023494 [system.nm] TRACE: Interface 4 power state changed: 4
0000023507 [app] INFO: Still trying to connect to cellular 00:00
0000023507 [app] INFO: Power source: USB Host
0000023510 [app] INFO: Battery state: charged, SoC: 100.00
0000023644 [net.pppncp] TRACE: NCP event 3
0000023644 [net.pppncp] TRACE: NCP power state changed: IF_POWER_STATE_UP
0000023645 [system.nm] TRACE: Interface 4 power state changed: 2
0000023645 [ncp.client] TRACE: Modem powered on
0000023645 [ncp.client] TRACE: Setting UART voltage translator state 1
0000023745 [ncp.client] TRACE: Setting UART voltage translator state 0
0000023845 [ncp.client] TRACE: Setting UART voltage translator state 1
0000024846 [ncp.at] TRACE: > AT
0000025846 [ncp.at] TRACE: > AT
0000026846 [ncp.at] TRACE: > AT
0000027846 [ncp.at] TRACE: > AT
0000028846 [ncp.at] TRACE: > AT
0000029846 [ncp.at] TRACE: > AT
0000030846 [ncp.at] TRACE: > AT
0000031846 [ncp.at] TRACE: > AT
0000032846 [ncp.at] TRACE: > AT
0000033846 [ncp.at] TRACE: > AT
0000034846 [ncp.at] TRACE: > AT
0000034850 [ncp.at] TRACE: < OK
0000034851 [ncp.client] TRACE: NCP ready to accept AT commands
0000034851 [ncp.at] TRACE: > AT
0000034854 [ncp.at] TRACE: < OK
0000034854 [ncp.at] TRACE: > ATI9
0000034860 [ncp.at] TRACE: < OK
0000034861 [ncp.client] TRACE: App firmware: 201
0000034861 [ncp.at] TRACE: > AT+UGPIOC?
0000034866 [ncp.at] TRACE: < +UGPIOC:
0000034871 [ncp.at] TRACE: < OK
0000034871 [ncp.at] TRACE: > AT+UGPIOR=23
0000034877 [ncp.at] TRACE: < +UGPIOR: 23,1
0000034877 [ncp.at] TRACE: < OK
0000034878 [ncp.client] INFO: Using internal SIM card
0000034878 [ncp.at] TRACE: > AT+CPIN?
0000034883 [ncp.at] TRACE: < +CPIN: READY
0000034884 [ncp.at] TRACE: < OK
0000034884 [ncp.at] TRACE: > AT+CCID
0000034892 [ncp.at] TRACE: < +CCID: 8901410327129XXXXXXXX
0000034892 [ncp.at] TRACE: < OK
0000034892 [ncp.at] TRACE: > AT+IFC?
0000034898 [ncp.at] TRACE: < +IFC: 2,2
0000034899 [ncp.at] TRACE: < OK
0000034899 [ncp.at] TRACE: > AT+IFC=2,2
0000034904 [ncp.at] TRACE: < OK
0000034904 [ncp.at] TRACE: > AT
0000034908 [ncp.at] TRACE: < OK
0000035909 [ncp.at] TRACE: > AT
0000035913 [ncp.at] TRACE: < OK
0000035913 [ncp.at] TRACE: > AT+CCID
0000035919 [ncp.at] TRACE: < +CCID: 89014103271529007930
0000035920 [ncp.at] TRACE: < OK
0000035920 [ncp.at] TRACE: > AT+CIMI
0000035926 [ncp.at] TRACE: < OK
0000035926 [ncp.at] TRACE: > AT+UMNOPROF?
0000035933 [ncp.at] TRACE: < +UMNOPROF: 2
0000038611 [app.help] INFO: Mobile Network Operator Profile (UMNOPROF): AT&T (2)
0000035934 [ncp.at] TRACE: < OK
0000035934 [ncp.at] TRACE: > AT+COPS=3,2
0000038616 [app.help] INFO: Operator Selection (COPS) Set: mode=set format (3) format=numeric (2)
0000035939 [ncp.at] TRACE: < OK
0000035939 [ncp.at] TRACE: > AT+CGEREP=1,0
0000035944 [ncp.at] TRACE: < OK
0000035944 [ncp.at] TRACE: > AT+URAT?
0000035951 [ncp.at] TRACE: < +URAT: 7
0000035951 [ncp.at] TRACE: < OK
0000035952 [ncp.at] TRACE: > AT+CPSMS?
0000035959 [ncp.at] TRACE: < +CPSMS:0,,,"01100000","00000000"
0000035959 [ncp.at] TRACE: < OK
0000035959 [ncp.at] TRACE: > AT+CEDRXS?
0000035968 [ncp.at] TRACE: < +CEDRXS:
0000035969 [ncp.at] TRACE: < OK
0000035969 [ncp.at] TRACE: > AT+CMUX=0,0,,1509,,,,,
0000035978 [ncp.at] TRACE: < OK
0000035979 [mux] INFO: Starting GSM07.10 muxer
0000035980 [mux] INFO: Openning mux channel 0
0000035980 [mux] INFO: GSM07.10 muxer thread started
0000035983 [mux] INFO: Openning mux channel 1
0000035988 [ncp.at] TRACE: > AT
0000035999 [ncp.at] TRACE: < OK
0000035999 [ncp.client] TRACE: NCP state changed: 1
0000035999 [net.pppncp] TRACE: NCP event 1
0000036000 [net.ppp.client] TRACE: PPP thread event ADM_UP data=0
0000036000 [net.ppp.client] TRACE: State NONE -> READY
0000036003 [ncp.at] TRACE: > AT+CFUN?
0000038637 [app.help] INFO: Set module functionality (CFUN): minimum functionality (0)
0000036014 [ncp.at] TRACE: < +CFUN: 1
0000036014 [ncp.at] TRACE: < OK
0000036015 [ncp.at] TRACE: > AT+CCID
0000036027 [ncp.at] TRACE: < +CCID: 89014103271529XXXXXXX
0000036027 [ncp.at] TRACE: < OK
0000036028 [ncp.at] TRACE: > AT+CIMI
0000036039 [ncp.at] TRACE: < OK
0000036040 [ncp.at] TRACE: > AT+CGDCONT?
0000038646 [app.help] INFO: PDP context definition (CGDCONT): cid=0 pdpType= APN=
0000036055 [ncp.at] TRACE: < +CGDCONT: 1,"IP","10569.mcs","10.96.156.109",0,0,0,0
0000036056 [ncp.at] TRACE: < OK
0000036056 [ncp.at] TRACE: > AT+CFUN?
0000038651 [app.help] INFO: Set module functionality (CFUN): minimum functionality (0)
0000036067 [ncp.at] TRACE: < +CFUN: 1
0000036067 [ncp.at] TRACE: < OK
0000036068 [ncp.at] TRACE: > AT+CEREG=2
0000038655 [app.help] INFO: EPS network (CEREG) Set to location enabled (2)
0000036078 [ncp.at] TRACE: < OK
0000036078 [ncp.client] TRACE: NCP connection state changed: 1
0000036079 [net.pppncp] TRACE: NCP event 2
0000036079 [net.pppncp] TRACE: State changed event: 1
0000036080 [ncp.at] TRACE: > AT+COPS?
0000036080 [net.ppp.client] TRACE: PPP thread event LOWER_DOWN data=0
0000036092 [ncp.at] TRACE: < +COPS: 0,2,"310410",8
0000038662 [app.help] INFO: Operator Selection (COPS) Read: mode=automatic (0)
0000038664 [app.help] INFO: format=numeric (2)
0000038667 [app.help] INFO: oper=310410 carrier=AT&T Wireless Inc. country=United States
0000036092 [ncp.at] TRACE: < OK
0000036093 [ncp.at] TRACE: > AT+CEREG?
0000036105 [ncp.at] TRACE: < +CEREG: 2,1,"700","1640B09",8
0000038673 [app.help] INFO: EPS network (CEREG) Status: registered, home network (1)
0000038674 [app.help] INFO: Tracking area code: 700
0000038675 [app.help] INFO: Cell identifier: 1640B09
0000038677 [app.help] INFO: Access technology: LTE Cat-M1 (8)
0000036106 [ncp.at] TRACE: < OK
0000036106 [ncp.client] TRACE: NCP connection state changed: 2
0000036107 [mux] INFO: Openning mux channel 2
0000037374 [net.pppncp] TRACE: NCP event 100
0000037374 [net.pppncp] TRACE: New auth info
0000037376 [net.pppncp] TRACE: NCP event 2
0000037376 [net.pppncp] TRACE: State changed event: 2
0000037377 [net.ppp.client] TRACE: PPP thread event LOWER_UP data=0
0000037377 [net.ppp.client] TRACE: State READY -> CONNECT
0000037378 [net.ppp.client] TRACE: State CONNECT -> CONNECTING
0000037377 [ncp.at] TRACE: > AT+CIMI
0000037386 [ncp.at] TRACE: < OK
0000037386 [ncp.at] TRACE: > AT
0000037395 [ncp.at] TRACE: < OK
0000037396 [ncp.at] TRACE: > AT+CGATT?
0000037407 [ncp.at] TRACE: < +CGATT: 1
0000037407 [ncp.at] TRACE: < OK
0000038408 [ncp.at] TRACE: > AT
0000038417 [ncp.at] TRACE: < OK
0000038417 [ncp.at] TRACE: > ATD*99***1#
0000038431 [net.ppp.client] TRACE: PPP phase -> Initialize
0000038431 [net.ppp.client] TRACE: PPP phase -> Establish
0000038432 [lwip.ppp] TRACE: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x5852897f> <pcomp> <ac
0000038433 [ncp.at] TRACE: > AT+CGMI
0000038457 [ncp.at] TRACE: < OK
0000038455 [lwip.ppp] TRACE: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0xfcb3a
0000038458 [lwip.ppp] TRACE: sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0xfcb3a
0000038460 [lwip.ppp] TRACE: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x5852897f> <pcomp> <ac
0000038461 [lwip.ppp] TRACE: sent [LCP EchoReq id=0x0 magic=0x5852897f]
0000038461 [net.ppp.client] TRACE: PPP phase -> Authenticate
0000038462 [app] INFO: manufacturer: u-blox
0000038484 [lwip.ppp] TRACE: rcvd [LCP DiscReq id=0x1 magic=0xfcb3a72b]
0000038488 [lwip.ppp] TRACE: rcvd [CHAP Challenge id=0x1 <f7fdf79960d5106db5a88b6bd6059460>, name =
0000038489 [lwip.ppp] TRACE: sent [CHAP Response id=0x1 <2c9accbd83291aec1d2d05506c83eace>, name =
0000038490 [lwip.ppp] TRACE: rcvd [LCP EchoRep id=0x0 magic=0xfcb3a72b 58 52 89 7f]
0000038491 [app] INFO: model: SARA-R410M-02B
0000038509 [lwip.ppp] TRACE: rcvd [CHAP Success id=0x1 ""]
0000038510 [net.ppp.client] TRACE: PPP phase -> Network
0000038510 [lwip.ppp] TRACE: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <msdns1 8.8.8.8> <msdns2 8.8.
0000038512 [app] INFO: firmware version: L0.0.00.00.05.06 [Feb 03 2018 13:00:41]
0000038528 [lwip.ppp] TRACE: rcvd [IPCP ConfReq id=0x0]
0000038529 [lwip.ppp] TRACE: sent [IPCP ConfAck id=0x0]
0000038531 [lwip.ppp] TRACE: rcvd [IPCP ConfNak id=0x1 <addr 10.96.156.XXX> <msdns1 174.47.40.106>
0000038532 [lwip.ppp] TRACE: sent [IPCP ConfReq id=0x2 <addr 10.96.156.XXX> <msdns1 174.47.40.106>
0000038534 [app] INFO: ordering code: SARA-R410M-02B
0000038549 [app] INFO: IMEI: 356726103514253
0000038552 [lwip.ppp] TRACE: rcvd [IPCP ConfAck id=0x2 <addr 10.96.156.109> <msdns1 174.47.40.106>
0000038553 [system.nm] INFO: State changed: IFACE_UP -> IFACE_LINK_UP
0000038554 [net.ppp.client] TRACE: PPP thread event UP data=0
0000038555 [net.ppp.client] TRACE: State CONNECTING -> CONNECTED
0000038555 [net.pppncp] TRACE: Negotiated MTU: 1500
0000038555 [net.pppncp] TRACE: Updating MTU to: 990
0000038554 [system.nm] INFO: State changed: IFACE_LINK_UP -> IP_CONFIGURED
0000038556 [net.ppp.client] TRACE: PPP phase -> Running
0000038568 [app] INFO: IMSI: u-blox
0000038582 [app] INFO: ICCID: 89014103271529XXXXXXXXX
0000038735 [app] INFO: Connected to cellular in 00:15
0000038735 [app] INFO: Connecting to the Particle cloud...
0000038757 [system] INFO: Cloud: connecting
0000038759 [system] WARN: Failed to load session data from persistent storage
0000039236 [system] INFO: Cloud socket connected
0000039236 [comm.protocol.handshake] INFO: Establish secure connection
0000039241 [comm.dtls] INFO: (CMPL,RENEG,NO_SESS,ERR) restoreStatus=2
0000040454 [comm.protocol.handshake] INFO: Sending HELLO message
0000040598 [comm.protocol.handshake] INFO: Handshake completed
0000040598 [comm.protocol.handshake] TRACE: Updating cached session parameters
0000040599 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000040601 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000041001 [ncp.at] TRACE: > AT+CFUN?
0000041003 [app.help] INFO: Set module functionality (CFUN): minimum functionality (0)
0000041011 [ncp.at] TRACE: < +CFUN: 1
0000041011 [ncp.at] TRACE: < OK
0000041012 [ncp.at] TRACE: > AT+CCID
0000041022 [ncp.at] TRACE: < +CCID: 89014103271529XXXXXXX
0000041022 [ncp.at] TRACE: < OK
0000041023 [ncp.at] TRACE: > AT+CGSN
0000041032 [ncp.at] TRACE: < OK
0000041032 [ncp.at] TRACE: > ATI9
0000041042 [ncp.at] TRACE: < OK
0000041162 [comm.protocol] INFO: Sending subscriptions
0000041330 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000041330 [comm.protocol] TRACE: message id 2 complete with code 0.00
0000041331 [comm.protocol] TRACE: Updating system DESCRIBE checksum
0000041337 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000041760 [ncp.at] TRACE: > AT+CFUN?
0000041762 [app.help] INFO: Set module functionality (CFUN): minimum functionality (0)
0000041770 [ncp.at] TRACE: < +CFUN: 1
0000041770 [ncp.at] TRACE: < OK
0000041772 [ncp.at] TRACE: > AT+CCID
0000041784 [ncp.at] TRACE: < +CCID: 89014103271529XXXXXXX
0000041784 [ncp.at] TRACE: < OK
0000041786 [ncp.at] TRACE: > AT+CGSN
0000041797 [ncp.at] TRACE: < OK
0000041797 [ncp.at] TRACE: > ATI9
0000041809 [ncp.at] TRACE: < OK
0000041809 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000041811 [comm.protocol] TRACE: rcv'd message type=13
0000041812 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000041813 [comm.protocol] TRACE: message id 3 complete with code 0.00
0000041814 [comm.protocol] TRACE: rcv'd message type=13
0000041915 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000041915 [comm.protocol] TRACE: message id 4 complete with code 0.00
0000041916 [comm.protocol] TRACE: rcv'd message type=13
0000042016 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000042016 [comm.protocol] TRACE: message id 5 complete with code 0.00
0000042018 [comm.protocol] TRACE: rcv'd message type=13
0000042118 [comm.protocol] TRACE: Reply recieved: type=2, code=69
0000042118 [comm.protocol] TRACE: message id 6 complete with code 2.05
0000042119 [comm.protocol] INFO: Received TIME response: 1678213185
0000042119 [comm.protocol] TRACE: rcv'd message type=12
0000042345 [comm.protocol] TRACE: rcv'd message type=8
0000042626 [comm.protocol] INFO: Received DESCRIBE request; flags: 0x04
0000042633 [ncp.at] TRACE: > AT+COPS=3,2
0000042636 [app.help] INFO: Operator Selection (COPS) Set: mode=set format (3) format=numeric (2)
0000042644 [ncp.at] TRACE: < OK
0000042644 [ncp.at] TRACE: > AT+COPS?
0000042654 [ncp.at] TRACE: < +COPS: 0,2,"310410",8
0000042657 [app.help] INFO: Operator Selection (COPS) Read: mode=automatic (0)
0000042658 [app.help] INFO: format=numeric (2)
0000042665 [app.help] INFO: oper=310410 carrier=AT&T Wireless Inc. country=United States
0000042654 [ncp.at] TRACE: < OK
0000042655 [ncp.at] TRACE: > AT+UCGED=5
0000042662 [ncp.at] TRACE: < OK
0000042663 [ncp.at] TRACE: > AT+UCGED?
0000042676 [ncp.at] TRACE: < +RSRP: 058,675,"-085.10",
0000042676 [ncp.at] TRACE: < +RSRQ: 058,675,"-09.80",
0000042677 [ncp.at] TRACE: < OK
0000042678 [ncp.at] TRACE: > AT+COPS=3,2
0000042688 [app.help] INFO: Operator Selection (COPS) Set: mode=set format (3) format=numeric (2)
0000042685 [ncp.at] TRACE: < OK
0000042686 [ncp.at] TRACE: > AT+COPS?
0000042695 [ncp.at] TRACE: < +COPS: 0,2,"310410",8
0000042700 [app.help] INFO: Operator Selection (COPS) Read: mode=automatic (0)
0000042705 [app.help] INFO: format=numeric (2)
0000042713 [app.help] INFO: oper=310410 carrier=AT&T Wireless Inc. country=United States
0000042696 [ncp.at] TRACE: < OK
0000042697 [ncp.at] TRACE: > AT+CEREG?
0000042707 [ncp.at] TRACE: < +CEREG: 2,1,"700","1640B09",8
0000042719 [app.help] INFO: EPS network (CEREG) Status: registered, home network (1)
0000042721 [app.help] INFO: Tracking area code: 700
0000042722 [app.help] INFO: Cell identifier: 1640B09
0000042723 [app.help] INFO: Access technology: LTE Cat-M1 (8)
0000042709 [ncp.at] TRACE: < OK
0000042713 [comm.protocol] TRACE: rcv'd message type=1
0000042921 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000042922 [comm.protocol] TRACE: message id 11 complete with code 0.00
0000042923 [comm.protocol] TRACE: rcv'd message type=13
0000045714 [comm.protocol] INFO: Received DESCRIBE request; flags: 0x02
0000045719 [comm.protocol] TRACE: rcv'd message type=1
0000045799 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000045800 [comm.protocol] TRACE: message id 9 complete with code 0.00
0000045801 [comm.protocol] TRACE: rcv'd message type=13
0000045803 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000045803 [comm.protocol] TRACE: message id 8 complete with code 0.00
0000045805 [comm.protocol] TRACE: rcv'd message type=13
0000045882 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000045882 [comm.protocol] TRACE: message id 12 complete with code 0.00
0000045883 [comm.protocol] TRACE: Updating application DESCRIBE checksum
0000045883 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000045885 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000045885 [comm.protocol] TRACE: rcv'd message type=13
0000046195 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000046195 [comm.protocol] TRACE: message id 10 complete with code 0.00
0000046196 [comm.protocol] TRACE: Updating subscriptions checksum
0000046197 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000046199 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000046199 [comm.protocol] TRACE: rcv'd message type=13
0000046994 [comm.protocol] TRACE: Reply recieved: type=2, code=0
0000046995 [comm.protocol] TRACE: message id 7 complete with code 0.00
0000046995 [comm.protocol] TRACE: Updating application DESCRIBE checksum
0000046996 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000046997 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000046998 [comm.protocol] TRACE: rcv'd message type=13
0000047099 [system] INFO: Cloud connected
0000047100 [app] INFO: Successfully connected to the Particle cloud in 00:08