Boron LTE - Permanently flashing green after running out of battery

I'm seeing similar behavior from a Boron LTE v1.5.2. Power source = AA batteries, which ran down but were still able to keep the device running (I didn't take a voltage measurement before replacing them).

Initially the device wouldn't connect to the cloud while running my application code, so debugging info is limited to log messages, which exactly matched what user Fragma reported in the following thread:

I replaced the batteries, re-flashed application firmware, power cycled multiple times, etc., and after repeated connection failures installed the cloud debugging tool referenced above by user evk02. I let the debugging tool run for quite a while and it made multiple failed attempts to connect to the cloud (perhaps some attempts were rejected by the carrier because too many attempts were being made? -- see multiple "Resetting the modem due to the network registration timeout" messages)

Unlike evk02's device, however, mine did eventually connect on the 5th or 6th try. Then I re-flashed device OS 1.5.2, and re-installed my application firmware. All seems to be good now.

Any insights from Particle into what happened, and how to avoid it in the future? I certainly agree with evk02 that a low battery shouldn't brick an IOT device. I'll add that no additional effort besides replacing the batteries should be required in order to revive it.

Pasted below is the very long output from the cloud debug tool. To get below the character limit of this forum, several failed connection attempts after timestamp 351831 have been deleted. The successful connection cycle starts around timestamp 979536.

Opening serial monitor for com port: "COM4"
Serial monitor opened successfully:
starting tests...
turning cellular on...
0000015002 [system.nm] INFO: State changed: DISABLED -> IFACE_DOWN
0000024257 [hal] INFO: Using internal SIM card
0000024329 [gsm0710muxer] INFO: Starting GSM07.10 muxer      
0000024330 [gsm0710muxer] INFO: Openning mux channel 0       
0000024331 [gsm0710muxer] INFO: GSM07.10 muxer thread started
deviceID=e00fce68c3416c8481a33abd
0000024384 [gsm0710muxer] INFO: Resuming channel 0    
0000024384 [gsm0710muxer] INFO: Openning mux channel 1
0000024485 [gsm0710muxer] INFO: Resuming channel 1
0000024485 [gsm0710muxer] INFO: Resuming channel 1
manufacturer=u-blox
model=SARA-R410M-02B
firmware version=L0.0.00.00.05.08 [Apr 17 2019 19:34:02]
ordering code=SARA-R410M-02B
IMEI=354444112249596
IMSI=u-blox
ICCID=89014103272321627982
0000024888 [app] INFO: enabling trace logging
0000024889 [ncp.at] TRACE: > AT+CGDCONT?     
0000024938 [ncp.at] TRACE: < +CGDCONT: 1,"IP","10569.mcs","0.0.0.0",0,0,0,0
0000024938 [ncp.at] TRACE: < OK
0000024939 [ncp.at] TRACE: > AT+CSQ
0000024988 [ncp.at] TRACE: < +CSQ: 99,99
0000024988 [ncp.at] TRACE: < OK
attempting to connect to the cellular network...
0000024991 [system.nm] INFO: State changed: IFACE_DOWN -> IFACE_REQUEST_UP
0000024991 [system.nm] INFO: State changed: IFACE_DOWN -> IFACE_REQUEST_UP
0000024994 [hal] TRACE: PPP netif -> 8
0000024996 [net.ifapi] INFO: Netif pp3 state UP
0000024996 [net.ifapi] INFO: Netif pp3 state UP
0000024998 [hal] TRACE: PPP thread event LOWER_DOWN
0000025001 [hal] TRACE: PPP thread event ADM_DOWN
0000025003 [hal] TRACE: PPP thread event ADM_UP
0000025005 [hal] TRACE: State NONE -> READY
0000025004 [ncp.at] TRACE: > AT+CIMI
0000025008 [system.nm] INFO: State changed: IFACE_REQUEST_UP -> IFACE_UP
0000025008 [system.nm] INFO: State changed: IFACE_REQUEST_UP -> IFACE_UP
0000025038 [ncp.at] TRACE: < 310410232162798
0000025039 [ncp.at] TRACE: < OK
0000025040 [ncp.at] TRACE: > AT+CGDCONT=1,"IP","10569.mcs"
0000025088 [ncp.at] TRACE: < OK
0000025089 [ncp.at] TRACE: > AT+CEREG=2
0000025138 [ncp.at] TRACE: < OK
0000025138 [hal] TRACE: NCP connection state changed: 1
0000025139 [net.pppncp] TRACE: NCP event 2
0000025139 [net.pppncp] TRACE: State changed event: 1
0000025140 [ncp.at] TRACE: > AT+COPS=0,2
0000025141 [hal] TRACE: PPP thread event LOWER_DOWN
0000025188 [ncp.at] TRACE: < OK
0000025188 [ncp.at] TRACE: > AT+CEREG?
0000025238 [ncp.at] TRACE: < +CEREG: 2,0
0000025239 [ncp.at] TRACE: < OK
0000026340 [ncp.at] TRACE: < +CEREG: 2
0000040240 [ncp.at] TRACE: > AT+CEREG?
0000040288 [ncp.at] TRACE: < +CEREG: 2,2
0000040289 [ncp.at] TRACE: < OK
0000055290 [ncp.at] TRACE: > AT+CEREG?
0000055338 [ncp.at] TRACE: < +CEREG: 2,2
0000055339 [ncp.at] TRACE: < OK
0000070339 [ncp.at] TRACE: > AT+CEREG?
0000070388 [ncp.at] TRACE: < +CEREG: 2,2
0000070389 [ncp.at] TRACE: < OK
0000085390 [ncp.at] TRACE: > AT+CEREG?
0000085438 [ncp.at] TRACE: < +CEREG: 2,2
0000085439 [ncp.at] TRACE: < OK
0000100439 [ncp.at] TRACE: > AT+CEREG?
0000100488 [ncp.at] TRACE: < +CEREG: 2,2
0000100488 [ncp.at] TRACE: < OK
0000115489 [ncp.at] TRACE: > AT+CEREG?
0000115538 [ncp.at] TRACE: < +CEREG: 2,2
0000115539 [ncp.at] TRACE: < OK
0000130540 [ncp.at] TRACE: > AT+CEREG?
0000130588 [ncp.at] TRACE: < +CEREG: 2,2
0000130588 [ncp.at] TRACE: < OK
0000145589 [ncp.at] TRACE: > AT+CEREG?
0000145638 [ncp.at] TRACE: < +CEREG: 2,2
0000145638 [ncp.at] TRACE: < OK
0000160639 [ncp.at] TRACE: > AT+CEREG?
0000160688 [ncp.at] TRACE: < +CEREG: 2,2
0000160688 [ncp.at] TRACE: < OK
0000175689 [ncp.at] TRACE: > AT+CEREG?
0000175738 [ncp.at] TRACE: < +CEREG: 2,2
0000175739 [ncp.at] TRACE: < OK
0000190739 [ncp.at] TRACE: > AT+CEREG?
0000190788 [ncp.at] TRACE: < +CEREG: 2,2
0000190789 [ncp.at] TRACE: < OK
0000205789 [ncp.at] TRACE: > AT+CEREG?
0000205838 [ncp.at] TRACE: < +CEREG: 2,2
0000205839 [ncp.at] TRACE: < OK
0000205940 [ncp.at] TRACE: < +CEREG: 0
0000220840 [ncp.at] TRACE: > AT+CEREG?
0000220888 [ncp.at] TRACE: < +CEREG: 2,0
0000220888 [ncp.at] TRACE: < OK
0000233789 [ncp.at] TRACE: < +CEREG: 2
0000235890 [ncp.at] TRACE: > AT+CEREG?
0000235938 [ncp.at] TRACE: < +CEREG: 2,2
0000235939 [ncp.at] TRACE: < OK
0000250940 [ncp.at] TRACE: > AT+CEREG?
0000250988 [ncp.at] TRACE: < +CEREG: 2,2
0000250989 [ncp.at] TRACE: < OK
0000265990 [ncp.at] TRACE: > AT+CEREG?
0000266038 [ncp.at] TRACE: < +CEREG: 2,2
0000266038 [ncp.at] TRACE: < OK
0000281039 [ncp.at] TRACE: > AT+CEREG?
0000281088 [ncp.at] TRACE: < +CEREG: 2,2
0000281089 [ncp.at] TRACE: < OK
0000296090 [ncp.at] TRACE: > AT+CEREG?
0000296138 [ncp.at] TRACE: < +CEREG: 2,2
0000296139 [ncp.at] TRACE: < OK
0000296239 [ncp.at] TRACE: < +CEREG: 0
0000311139 [ncp.at] TRACE: > AT+CEREG?
0000311188 [ncp.at] TRACE: < +CEREG: 2,0
0000311188 [ncp.at] TRACE: < OK
0000326189 [ncp.at] TRACE: > AT+CEREG?
0000326238 [ncp.at] TRACE: < +CEREG: 2,0
0000326239 [ncp.at] TRACE: < OK
0000326240 [hal] WARN: Resetting the modem due to the network registration timeout
0000326240 [hal] WARN: Resetting the modem due to the network registration timeout
0000326243 [gsm0710muxer] INFO: Stopping GSM07.10 muxer
0000326243 [gsm0710muxer] INFO: Stopping GSM07.10 muxer
0000326246 [gsm0710muxer] INFO: Gracefully stopping GSM07.10 muxer
0000326246 [gsm0710muxer] INFO: Gracefully stopping GSM07.10 muxer
0000326249 [gsm0710muxer] INFO: Closing all muxed channels
0000326249 [gsm0710muxer] INFO: Closing all muxed channels
0000326252 [gsm0710muxer] INFO: Closing mux channel 1
0000326252 [gsm0710muxer] INFO: Closing mux channel 1
0000326255 [gsm0710muxer] INFO: Muxed channel 2 already closed
0000326255 [gsm0710muxer] INFO: Muxed channel 2 already closed
0000326257 [gsm0710muxer] INFO: Muxed channel 3 already closed
0000326257 [gsm0710muxer] INFO: Muxed channel 3 already closed
0000326260 [gsm0710muxer] INFO: Muxed channel 4 already closed
0000326260 [gsm0710muxer] INFO: Muxed channel 4 already closed
0000326360 [gsm0710muxer] INFO: Sending CLD (multiplexer close down)
0000326360 [gsm0710muxer] INFO: Sending CLD (multiplexer close down)
0000326412 [gsm0710muxer] INFO: Received response to CLD or timed out, exiting multiplexed mode
0000326412 [gsm0710muxer] INFO: Received response to CLD or timed out, exiting multiplexed mode
0000326414 [gsm0710muxer] INFO: GSM07.10 muxer thread exiting
0000326414 [gsm0710muxer] INFO: GSM07.10 muxer thread exiting
0000326416 [gsm0710muxer] INFO: GSM07.10 muxer stopped
0000326416 [gsm0710muxer] INFO: GSM07.10 muxer stopped
0000326418 [hal] TRACE: Hard resetting the modem
0000337418 [hal] TRACE: Powering on the modem after the hard reset
0000337419 [hal] TRACE: Powering modem on
0000337570 [hal] TRACE: Modem powered on
0000337571 [hal] TRACE: Setting UART voltage translator state 0
0000337573 [hal] TRACE: Powering modem off
0000337574 [hal] TRACE: Setting UART voltage translator state 0
0000349175 [hal] ERROR: Failed to power off modem
0000349175 [hal] ERROR: Failed to power off modem
0000349177 [hal] TRACE: NCP state changed: 0
0000349178 [net.pppncp] TRACE: NCP event 1
0000349280 [hal] TRACE: Modem already on
0000349281 [hal] TRACE: Setting UART voltage translator state 1
0000350282 [ncp.at] TRACE: > AT
0000350287 [ncp.at] TRACE: < OK
0000351288 [hal] TRACE: NCP ready to accept AT commands
0000351288 [ncp.at] TRACE: > AT+UGPIOC?
0000351296 [ncp.at] TRACE: < +UGPIOC:
0000351296 [ncp.at] TRACE: < 7,255
0000351297 [ncp.at] TRACE: < 16,255
0000351298 [ncp.at] TRACE: < 19,255
0000351299 [ncp.at] TRACE: < 23,0
0000351299 [ncp.at] TRACE: < 24,255
0000351300 [ncp.at] TRACE: < 25,255
0000351301 [ncp.at] TRACE: < 42,255
0000351301 [ncp.at] TRACE: < OK
0000351302 [ncp.at] TRACE: > AT+UGPIOR=23
0000351311 [ncp.at] TRACE: < +UGPIOR: 23,1
0000351312 [ncp.at] TRACE: < OK
0000351312 [hal] INFO: Using internal SIM card
0000351312 [hal] INFO: Using internal SIM card
0000351313 [ncp.at] TRACE: > AT+CPIN?
0000351321 [ncp.at] TRACE: < +CPIN: READY
0000351322 [ncp.at] TRACE: < OK
0000351322 [ncp.at] TRACE: > AT+CCID
0000351332 [ncp.at] TRACE: < +CCID: 89014103272321627982
0000351333 [ncp.at] TRACE: < OK
0000351334 [ncp.at] TRACE: > AT+COPS=2,2
0000351349 [ncp.at] TRACE: < OK
0000351349 [ncp.at] TRACE: > AT+COPS=3,2
0000351354 [ncp.at] TRACE: < OK
0000351355 [ncp.at] TRACE: > ATI9
0000351360 [ncp.at] TRACE: < L0.0.00.00.05.08,A.02.04
0000351362 [ncp.at] TRACE: < OK
0000351363 [ncp.at] TRACE: > AT+UMNOPROF?
0000351368 [ncp.at] TRACE: < +UMNOPROF: 2
0000351369 [ncp.at] TRACE: < OK
0000351370 [ncp.at] TRACE: > AT+URAT?
0000351378 [ncp.at] TRACE: < +CME ERROR: Operation not supported
0000351379 [ncp.at] TRACE: > AT+CEDRXS?
0000351384 [ncp.at] TRACE: < +CEDRXS:
0000351385 [ncp.at] TRACE: < OK
0000351386 [ncp.at] TRACE: > AT+CPSMS=0
0000351404 [ncp.at] TRACE: < OK
0000351405 [ncp.at] TRACE: > AT+CMUX=0,0,,1509,,,,,
0000351413 [ncp.at] TRACE: < OK
0000351413 [gsm0710muxer] INFO: Starting GSM07.10 muxer
0000351413 [gsm0710muxer] INFO: Starting GSM07.10 muxer
0000351417 [gsm0710muxer] INFO: Openning mux channel 0
0000351417 [gsm0710muxer] INFO: Openning mux channel 0
0000351418 [gsm0710muxer] INFO: GSM07.10 muxer thread started
0000351418 [gsm0710muxer] INFO: GSM07.10 muxer thread started
0000351473 [gsm0710muxer] INFO: Resuming channel 0
0000351473 [gsm0710muxer] INFO: Resuming channel 0
0000351475 [gsm0710muxer] INFO: Openning mux channel 1
0000351475 [gsm0710muxer] INFO: Openning mux channel 1
0000351576 [gsm0710muxer] INFO: Resuming channel 1
0000351576 [gsm0710muxer] INFO: Resuming channel 1
0000351578 [gsm0710muxer] INFO: Resuming channel 1
0000351578 [gsm0710muxer] INFO: Resuming channel 1
0000351580 [ncp.at] TRACE: > AT
0000351630 [ncp.at] TRACE: < OK
0000351630 [hal] TRACE: NCP state changed: 1
0000351631 [net.pppncp] TRACE: NCP event 1
0000351632 [hal] TRACE: Muxer AT channel live
0000351632 [hal] TRACE: PPP thread event LOWER_DOWN
0000351633 [hal] TRACE: PPP thread event ADM_DOWN
0000351635 [hal] TRACE: State READY -> NONE
0000351639 [hal] TRACE: PPP thread event ADM_UP
0000351640 [hal] TRACE: State NONE -> READY
0000351638 [ncp.at] TRACE: > AT+CIMI
0000351680 [ncp.at] TRACE: < 310410232162798
0000351680 [ncp.at] TRACE: < OK
0000351681 [ncp.at] TRACE: > AT+CGDCONT=1,"IP","10569.mcs"
0000351730 [ncp.at] TRACE: < OK
0000351731 [ncp.at] TRACE: > AT+CEREG=2
0000351780 [ncp.at] TRACE: < OK
0000351780 [hal] TRACE: NCP connection state changed: 1
0000351781 [net.pppncp] TRACE: NCP event 2
0000351782 [net.pppncp] TRACE: State changed event: 1
0000351783 [hal] TRACE: PPP thread event LOWER_DOWN
0000351785 [ncp.at] TRACE: > AT+COPS=0,2
0000351830 [ncp.at] TRACE: < OK
0000351831 [ncp.at] TRACE: > AT+CEREG?
...
0000979536 [hal] WARN: Resetting the modem due to the network registration timeout
0000979536 [hal] WARN: Resetting the modem due to the network registration timeout
0000979540 [gsm0710muxer] INFO: Stopping GSM07.10 muxer
0000979540 [gsm0710muxer] INFO: Stopping GSM07.10 muxer
0000979543 [gsm0710muxer] INFO: Gracefully stopping GSM07.10 muxer
0000979543 [gsm0710muxer] INFO: Gracefully stopping GSM07.10 muxer
0000979546 [gsm0710muxer] INFO: Closing all muxed channels
0000979546 [gsm0710muxer] INFO: Closing all muxed channels
0000979549 [gsm0710muxer] INFO: Closing mux channel 1
0000979549 [gsm0710muxer] INFO: Closing mux channel 1
0000979551 [gsm0710muxer] INFO: Muxed channel 2 already closed
0000979551 [gsm0710muxer] INFO: Muxed channel 2 already closed
0000979554 [gsm0710muxer] INFO: Muxed channel 3 already closed
0000979554 [gsm0710muxer] INFO: Muxed channel 3 already closed
0000979558 [gsm0710muxer] INFO: Muxed channel 4 already closed
0000979558 [gsm0710muxer] INFO: Muxed channel 4 already closed
0000979660 [gsm0710muxer] INFO: Sending CLD (multiplexer close down)
0000979660 [gsm0710muxer] INFO: Sending CLD (multiplexer close down)
0000979711 [gsm0710muxer] INFO: Received response to CLD or timed out, exiting multiplexed mode
0000979711 [gsm0710muxer] INFO: Received response to CLD or timed out, exiting multiplexed mode
0000979714 [gsm0710muxer] INFO: GSM07.10 muxer thread exiting
0000979714 [gsm0710muxer] INFO: GSM07.10 muxer thread exiting
0000979716 [gsm0710muxer] INFO: GSM07.10 muxer stopped
0000979716 [gsm0710muxer] INFO: GSM07.10 muxer stopped
0000979718 [hal] TRACE: Hard resetting the modem
0000990719 [hal] TRACE: Powering on the modem after the hard reset
0000990720 [hal] TRACE: Powering modem on
0000990871 [hal] TRACE: Modem powered on
0000990871 [hal] TRACE: Setting UART voltage translator state 0
0000990871 [hal] TRACE: Powering modem off
0000990872 [hal] TRACE: Setting UART voltage translator state 0
0001002473 [hal] ERROR: Failed to power off modem
0001002473 [hal] ERROR: Failed to power off modem
0001002475 [hal] TRACE: NCP state changed: 0
0001002476 [net.pppncp] TRACE: NCP event 1
0001002577 [hal] TRACE: Modem already on
0001002578 [hal] TRACE: Setting UART voltage translator state 1
0001003579 [ncp.at] TRACE: > AT
0001003584 [ncp.at] TRACE: < OK
0001004585 [hal] TRACE: NCP ready to accept AT commands
0001004585 [ncp.at] TRACE: > AT+UGPIOC?
0001004593 [ncp.at] TRACE: < +UGPIOC:
0001004594 [ncp.at] TRACE: < 7,255
0001004595 [ncp.at] TRACE: < 16,255
0001004596 [ncp.at] TRACE: < 19,255
0001004597 [ncp.at] TRACE: < 23,0
0001004598 [ncp.at] TRACE: < 24,255
0001004599 [ncp.at] TRACE: < 25,255
0001004600 [ncp.at] TRACE: < 42,255
0001004601 [ncp.at] TRACE: < OK
0001004602 [ncp.at] TRACE: > AT+UGPIOR=23
0001004610 [ncp.at] TRACE: < +UGPIOR: 23,1
0001004611 [ncp.at] TRACE: < OK
0001004612 [hal] INFO: Using internal SIM card
0001004612 [hal] INFO: Using internal SIM card
0001004614 [ncp.at] TRACE: > AT+CPIN?
0001004621 [ncp.at] TRACE: < +CPIN: READY
0001004623 [ncp.at] TRACE: < OK
0001004624 [ncp.at] TRACE: > AT+CCID
0001004632 [ncp.at] TRACE: < +CCID: 89014103272321627982
0001004633 [ncp.at] TRACE: < OK
0001004634 [ncp.at] TRACE: > AT+COPS=2,2
0001004648 [ncp.at] TRACE: < OK
0001004649 [ncp.at] TRACE: > AT+COPS=3,2
0001004654 [ncp.at] TRACE: < OK
0001004655 [ncp.at] TRACE: > ATI9
0001004660 [ncp.at] TRACE: < L0.0.00.00.05.08,A.02.04
0001004661 [ncp.at] TRACE: < OK
0001004662 [ncp.at] TRACE: > AT+UMNOPROF?
0001004670 [ncp.at] TRACE: < +UMNOPROF: 2
0001004671 [ncp.at] TRACE: < OK
0001004672 [ncp.at] TRACE: > AT+URAT?
0001004679 [ncp.at] TRACE: < +CME ERROR: Operation not supported
0001004681 [ncp.at] TRACE: > AT+CEDRXS?
0001004687 [ncp.at] TRACE: < +CEDRXS:
0001004687 [ncp.at] TRACE: < OK
0001004688 [ncp.at] TRACE: > AT+CPSMS=0
0001004695 [ncp.at] TRACE: < OK
0001004696 [ncp.at] TRACE: > AT+CMUX=0,0,,1509,,,,,
0001004704 [ncp.at] TRACE: < OK
0001004705 [gsm0710muxer] INFO: Starting GSM07.10 muxer
0001004705 [gsm0710muxer] INFO: Starting GSM07.10 muxer
0001004708 [gsm0710muxer] INFO: Openning mux channel 0
0001004708 [gsm0710muxer] INFO: Openning mux channel 0
0001004708 [gsm0710muxer] INFO: GSM07.10 muxer thread started
0001004708 [gsm0710muxer] INFO: GSM07.10 muxer thread started
0001004763 [gsm0710muxer] INFO: Resuming channel 0
0001004763 [gsm0710muxer] INFO: Resuming channel 0
0001004765 [gsm0710muxer] INFO: Openning mux channel 1
0001004765 [gsm0710muxer] INFO: Openning mux channel 1
0001004866 [gsm0710muxer] INFO: Resuming channel 1
0001004866 [gsm0710muxer] INFO: Resuming channel 1
0001004868 [gsm0710muxer] INFO: Resuming channel 1
0001004868 [gsm0710muxer] INFO: Resuming channel 1
0001004871 [ncp.at] TRACE: > AT
0001004922 [ncp.at] TRACE: < OK
0001004922 [hal] TRACE: NCP state changed: 1
0001004923 [net.pppncp] TRACE: NCP event 1
0001004924 [hal] TRACE: Muxer AT channel live
0001004925 [hal] TRACE: PPP thread event LOWER_DOWN
0001004926 [hal] TRACE: PPP thread event ADM_DOWN
0001004928 [hal] TRACE: State READY -> NONE
0001004930 [ncp.at] TRACE: > AT+CIMI
0001004931 [hal] TRACE: PPP thread event ADM_UP
0001004934 [hal] TRACE: State NONE -> READY
0001004972 [ncp.at] TRACE: < 310410232162798
0001004973 [ncp.at] TRACE: < OK
0001004974 [ncp.at] TRACE: > AT+CGDCONT=1,"IP","10569.mcs"
0001005022 [ncp.at] TRACE: < OK
0001005023 [ncp.at] TRACE: > AT+CEREG=2
0001005072 [ncp.at] TRACE: < OK
0001005073 [hal] TRACE: NCP connection state changed: 1
0001005074 [net.pppncp] TRACE: NCP event 2
0001005075 [net.pppncp] TRACE: State changed event: 1
0001005076 [ncp.at] TRACE: > AT+COPS=0,2
0001005077 [hal] TRACE: PPP thread event LOWER_DOWN
0001005122 [ncp.at] TRACE: < OK
0001005123 [ncp.at] TRACE: > AT+CEREG?
0001005124 [ncp.at] TRACE: < +CEREG: 2
0001005172 [ncp.at] TRACE: < +CEREG: 2,2
0001005173 [ncp.at] TRACE: < OK
0001006773 [ncp.at] TRACE: < +CEREG: 1,"8B39","A196F0F",7
0001006774 [hal] TRACE: NCP connection state changed: 2
0001006776 [gsm0710muxer] INFO: Openning mux channel 2
0001006776 [gsm0710muxer] INFO: Openning mux channel 2
0001006872 [gsm0710muxer] INFO: Resuming channel 2
0001006872 [gsm0710muxer] INFO: Resuming channel 2
0001006874 [net.pppncp] TRACE: NCP event 100
0001006875 [net.pppncp] TRACE: New auth info
0001006876 [net.pppncp] TRACE: NCP event 2
0001006877 [net.pppncp] TRACE: State changed event: 2
0001006878 [hal] TRACE: PPP thread event LOWER_UP
0001006879 [hal] TRACE: State READY -> CONNECT
0001006880 [net.ppp.ipcp] TRACE: IPCP: init
0001006881 [net.ppp.ipcp] TRACE: IPCP: disable 0 0 0
0001006882 [net.ppp.ipcp] TRACE: IPCP: enable 0 0 0
0001006884 [hal] TRACE: Outputing 13 bytes
0001006884 [hal] TRACE: State CONNECT -> CONNECTING
0001006885 [lwip] TRACE: ppp_connect[3]: holdoff=1
0001006887 [lwip] TRACE: ppp phase changed[3]: phase=2
0001006888 [hal] TRACE: PPP phase -> 2
0001006924 [lwip] TRACE: pppos_input[3]: got 12 bytes
0001006925 [lwip] TRACE: pppos_input[3]: got 21 bytes
0001007889 [lwip] TRACE: ppp phase changed[3]: phase=3
0001007889 [hal] TRACE: PPP phase -> 3
0001007890 [lwip] TRACE: pppos_connect: unit 3: connecting
0001007890 [lwip] TRACE: ppp_start[3]
0001007891 [lwip] TRACE: ppp phase changed[3]: phase=6
0001007892 [hal] TRACE: PPP phase -> 6
0001007892 [lwip] TRACE: pppos_send_config[3]: out_accm=FF FF FF FF
0001007893 [lwip] TRACE: ppp_send_config[3]
0001007893 [lwip] TRACE: pppos_recv_config[3]: in_accm=FF FF FF FF
0001007894 [lwip] TRACE: ppp_recv_config[3]
0001007895 [lwip] TRACE: ppp: auth protocols:
0001007896 [lwip] TRACE:  PAP=1
0001007896 [lwip] TRACE:  CHAP=1 CHAP_MD5=1
0001007897 [lwip] TRACE:
0001007897 [hal] TRACE: Outputing 46 bytes
0001007898 [lwip] TRACE: pppos_write[3]: len=24
0001007899 [lwip] TRACE: ppp_start[3]: finished
0001008226 [lwip] TRACE: pppos_input[3]: got 54 bytes
0001008226 [hal] TRACE: Outputing 54 bytes
0001008227 [lwip] TRACE: pppos_write[3]: len=29
0001008228 [lwip] TRACE: pppos_input[3]: got 47 bytes
0001008229 [lwip] TRACE: netif_set_mtu[3]: mtu=1500
0001008230 [lwip] TRACE: pppos_send_config[3]: out_accm=0 0 0 0
0001008232 [lwip] TRACE: ppp_send_config[3]
0001008233 [lwip] TRACE: pppos_recv_config[3]: in_accm=0 0 0 0
0001008234 [lwip] TRACE: ppp_recv_config[3]
0001008236 [hal] TRACE: Outputing 15 bytes
0001008237 [lwip] TRACE: pppos_write[3]: len=12
0001008238 [net.ppp.ipcp] TRACE: IPCP: lowerUp
0001008240 [lwip] TRACE: ppp phase changed[3]: phase=7
0001008241 [hal] TRACE: PPP phase -> 7
0001008543 [lwip] TRACE: pppos_input[3]: got 22 bytes
0001008544 [lwip] TRACE: pppos_input[3]: got 41 bytes
0001008545 [lwip] TRACE: No CHAP secret found for authenticating us to UMTS_CHAP_SRVR
0001008546 [hal] TRACE: Outputing 29 bytes
0001008547 [lwip] TRACE: pppos_write[3]: len=25
0001008548 [lwip] TRACE: pppos_input[3]: got 27 bytes
0001008899 [lwip] TRACE: pppos_input[3]: got 10 bytes
0001008900 [lwip] TRACE: CHAP authentication succeeded
0001008900 [lwip] TRACE: CHAP authentication succeeded
0001008901 [lwip] TRACE: ppp phase changed[3]: phase=9
0001008902 [hal] TRACE: PPP phase -> 9
0001008903 [net.ppp.ipcp] TRACE: IPCP: open
0001008903 [net.ppp.ipcp] TRACE: IPCP: reset ci
0001008904 [net.ppp.ipcp] TRACE: IPCP: get ci length
0001008904 [net.ppp.ipcp] TRACE: IPCP: Our CI length: 24
0001008905 [hal] TRACE: Outputing 36 bytes
0001008906 [lwip] TRACE: pppos_write[3]: len=32
0001008907 [hal] TRACE: Outputing 21 bytes
0001008908 [lwip] TRACE: pppos_write[3]: len=18
0001009209 [lwip] TRACE: pppos_input[3]: got 10 bytes
0001009209 [net.ppp.ipcp] TRACE: IPCP: input 4
0001009210 [net.ppp.ipcp] TRACE: IPCP: request ci
0001009210 [hal] TRACE: Outputing 12 bytes
0001009211 [lwip] TRACE: pppos_write[3]: len=8
0001009212 [lwip] TRACE: pppos_input[3]: got 16 bytes
0001009213 [net.ppp.ipcp] TRACE: IPCP: input 10
0001009215 [net.ppp.ipcp] TRACE: IPCP: reject ci
0001009216 [net.ppp.ipcp] TRACE: IPCP: get ci length
0001009217 [net.ppp.ipcp] TRACE: IPCP: Our CI length: 18
0001009218 [hal] TRACE: Outputing 29 bytes
0001009219 [lwip] TRACE: pppos_write[3]: len=26
0001009520 [lwip] TRACE: pppos_input[3]: got 28 bytes
0001009520 [net.ppp.ipcp] TRACE: IPCP: input 22
0001009521 [net.ppp.ipcp] TRACE: IPCP: nak ci
0001009522 [net.ppp.ipcp] TRACE: IPCP: get ci length
0001009522 [net.ppp.ipcp] TRACE: IPCP: Our CI length: 18
0001009523 [hal] TRACE: Outputing 30 bytes
0001009524 [lwip] TRACE: pppos_write[3]: len=26
0001009826 [lwip] TRACE: pppos_input[3]: got 28 bytes
0001009827 [net.ppp.ipcp] TRACE: IPCP: input 22
0001009828 [net.ppp.ipcp] TRACE: IPCP: ack ci
0001009829 [net.ppp.ipcp] TRACE: IPCP: up
0001009830 [hal] TRACE: PPP netif -> 4
0001009831 [net.ifapi] INFO: Netif pp3 link UP
0001009831 [net.ifapi] INFO: Netif pp3 link UP
0001009833 [system.nm] INFO: State changed: IFACE_UP -> IFACE_LINK_UP
0001009833 [system.nm] INFO: State changed: IFACE_UP -> IFACE_LINK_UP
0001009836 [lwip] TRACE: sifup[3]: err_code=0
0001009837 [hal] TRACE: PPP status -> 0
0001009838 [hal] TRACE: PPP netif -> b0
0001009839 [net.ifapi] TRACE: Netif pp3 ipv4 configuration changed
0001009839 [hal] TRACE: PPP thread event UP
0001009842 [hal] INFO: DNS server list changed
0001009842 [hal] INFO: DNS server list changed
0001009844 [system.nm] TRACE: br_enabled=1
0001009845 [system.nm] INFO: State changed: IFACE_LINK_UP -> IP_CONFIGURED
0001009845 [system.nm] INFO: State changed: IFACE_LINK_UP -> IP_CONFIGURED
0001009847 [hal] INFO: DNS server list changed
0001009847 [hal] INFO: DNS server list changed
0001009842 [hal] TRACE: State CONNECTING -> CONNECTED
0001009851 [net.pppncp] TRACE: Negotiated MTU: 1500
0001009852 [net.pppncp] INFO: Updating MTU to: 1000
0001009852 [net.pppncp] INFO: Updating MTU to: 1000
0001009850 [lwip] TRACE: ppp phase changed[3]: phase=10
0001009856 [hal] TRACE: PPP phase -> 10
connected to the cellular network in 984845 milliseconds
0001009859 [system.nm] TRACE: br_enabled=1, br_permitted=0
0001009860 [system.nm] INFO: Checking gateway status with the device cloud
0001009860 [system.nm] INFO: Checking gateway status with the device cloud
connected to cellular network!
0001009864 [ncp.at] TRACE: > AT+UDOPN=9
0001009907 [ncp.at] TRACE: < ERROR
operator name=
0001009908 [ncp.at] TRACE: > AT+CSQ
0001009957 [ncp.at] TRACE: < +CSQ: 24,99
0001009957 [ncp.at] TRACE: < OK
rssi=-65, qual=99
0001009958 [ncp.at] TRACE: > AT+CGED=5
0001010007 [ncp.at] TRACE: < ERROR
0001010008 [ncp.at] TRACE: > AT+CGED=3
0001010057 [ncp.at] TRACE: < ERROR
0001010058 [app] INFO: service rat=GSM mcc=65535, mnc=255, lac=0 ci=0 band=GSM 900 rssi=-121 bsic=0 arfcn=0 rxlev=0
0001010058 [app] INFO: service rat=GSM mcc=65535, mnc=255, lac=0 ci=0 band=GSM 900 rssi=-121 bsic=0 arfcn=0 rxlev=0
0001010061 [ncp.at] TRACE: > AT+UPING="8.8.8.8"
0001010107 [ncp.at] TRACE: < ERROR
ping addr 8.8.8.8=0
0001010108 [ncp.at] TRACE: > AT+UDNSRN=0,"device.spark.io"
0001010807 [ncp.at] TRACE: < +UDNSRN: "18.215.131.110", "3.230.53.201", "52.1.233.8", "54.86.95.155", "3.225.178.96", "54.89.85.128", "34.195.89.106", "3.230
0001010808 [ncp.at] TRACE: < OK
device.spark.io=18.215.131.110
connecting to cloud
0001010810 [system] INFO: Cloud: connecting
0001010810 [system] INFO: Cloud: connecting
0001010814 [system] INFO: Read Server Address = type:1,domain:$id.udp-mesh.particle.io
0001010814 [system] INFO: Read Server Address = type:1,domain:$id.udp-mesh.particle.io
0001010818 [system] ERROR: Failed to load session data from persistent storage
0001010818 [system] ERROR: Failed to load session data from persistent storage
0001010821 [system] INFO: Discarding session data
0001010821 [system] INFO: Discarding session data
0001010824 [system] TRACE: Resolving e00fce68c3416c8481a33abd.udp-mesh.particle.io#5684
0001010826 [hal] TRACE: Outputing 96 bytes
0001010827 [lwip] TRACE: pppos_netif_output[3]: proto=0x21, len = 91
0001011207 [lwip] TRACE: pppos_input[3]: got 287 bytes
0001011208 [lwip] TRACE: ppp_input[3]: ip in pbuf len=281
0001011210 [hal] TRACE: Outputing 96 bytes
0001011211 [lwip] TRACE: pppos_netif_output[3]: proto=0x21, len = 91
0001011248 [hal] TRACE: Outputing 95 bytes
0001011249 [lwip] TRACE: pppos_netif_output[3]: proto=0x21, len = 91
0001011559 [lwip] TRACE: pppos_input[3]: got 361 bytes
0001011561 [lwip] TRACE: ppp_input[3]: ip in pbuf len=356
0001011562 [system] TRACE: Address type: 3
0001011563 [system] TRACE: Cloud socket=0, family=2, type=2, protocol=17
0001011565 [system] INFO: Cloud socket=0, connecting to 3.222.253.60#5684
0001011565 [system] INFO: Cloud socket=0, connecting to 3.222.253.60#5684
0001011568 [system] TRACE: Cloud socket=0, connected to 3.222.253.60#5684
0001011569 [system] TRACE: Updating cloud keepalive for AF_INET: 1380000 -> 1380000
0001011571 [system] TRACE: Applying new keepalive interval now
0001011573 [system] INFO: Cloud socket connected
0001011573 [system] INFO: Cloud socket connected
0001011574 [system] INFO: Starting handshake: presense_announce=0
0001011574 [system] INFO: Starting handshake: presense_announce=0
0001011576 [comm.protocol.handshake] INFO: Establish secure connection
0001011576 [comm.protocol.handshake] INFO: Establish secure connection
0001011612 [lwip] TRACE: pppos_input[3]: got 361 bytes
0001011613 [lwip] TRACE: ppp_input[3]: ip in pbuf len=356
0001011615 [hal] TRACE: Outputing 61 bytes
0001011616 [lwip] TRACE: pppos_netif_output[3]: proto=0x21, len = 56
0001011820 [ncp.at] TRACE: > AT+CCID
0001011867 [ncp.at] TRACE: < +CCID: 89014103272321627982
0001011867 [ncp.at] TRACE: < OK
0001011868 [ncp.at] TRACE: > AT+CGSN
0001011917 [ncp.at] TRACE: < 354444112249596
0001011917 [ncp.at] TRACE: < OK
0001011919 [comm.dtls] TRACE: restore size mismatch 1: 0/220
0001011920 [comm.dtls] INFO: (CMPL,RENEG,NO_SESS,ERR) restoreStatus=2
0001011920 [comm.dtls] INFO: (CMPL,RENEG,NO_SESS,ERR) restoreStatus=2
0001011926 [hal] TRACE: Outputing 144 bytes
0001011928 [lwip] TRACE: pppos_netif_output[3]: proto=0x21, len = 139
0001012517 [lwip] TRACE: pppos_input[3]: got 94 bytes
0001012518 [lwip] TRACE: ppp_input[3]: ip in pbuf len=88
0001012519 [hal] TRACE: Outputing 177 bytes
0001012521 [lwip] TRACE: pppos_netif_output[3]: proto=0x21, len = 171
0001012969 [lwip] TRACE: pppos_input[3]: got 152 bytes
0001012970 [lwip] TRACE: ppp_input[3]: ip in pbuf len=146
0001012971 [lwip] TRACE: pppos_input[3]: got 202 bytes
0001012972 [lwip] TRACE: ppp_input[3]: ip in pbuf len=197
0001012974 [lwip] TRACE: pppos_input[3]: got 58 bytes
0001012975 [lwip] TRACE: ppp_input[3]: ip in pbuf len=53
0001012976 [lwip] TRACE: pppos_input[3]: got 66 bytes
0001012977 [lwip] TRACE: ppp_input[3]: ip in pbuf len=61
0001013175 [hal] TRACE: Outputing 411 bytes
0001013176 [lwip] TRACE: pppos_netif_output[3]: proto=0x21, len = 405
0001013238 [hal] TRACE: Outputing 15 bytes
0001013239 [lwip] TRACE: pppos_write[3]: len=12
0001013427 [lwip] TRACE: pppos_input[3]: got 27 bytes
0001013827 [lwip] TRACE: pppos_input[3]: got 47 bytes
0001013827 [lwip] TRACE: ppp_input[3]: ip in pbuf len=42
0001013829 [lwip] TRACE: pppos_input[3]: got 86 bytes
0001013830 [lwip] TRACE: ppp_input[3]: ip in pbuf len=81
0001013833 [comm.protocol.handshake] INFO: Sending HELLO message
0001013833 [comm.protocol.handshake] INFO: Sending HELLO message
0001013835 [comm] TRACE: sending message id=1 synchronously
0001013836 [comm.coap] TRACE: sending message id=1
0001013838 [hal] TRACE: Outputing 92 bytes
0001013839 [lwip] TRACE: pppos_netif_output[3]: proto=0x21, len = 86