B402 with white led not responding to RESET pin

We recently migrated from the Electron to the B402 in our design. As part of the migration, we went from deviceOS 1.5.2 to 2.3.0.

Out of 100 devices deployed, we have observed the following on about 5 units:

  • status LED goes solid white
  • device does not respond to toggling the RESET pin (where our HW WDT is also connected)
  • user can only reset the device by removing power completely from the unit

This is problematic as our customers often mount our devices in inaccessible locations.

Our device operates by waking from sleep every 15 minutes, collecting data from a number of devices over LoRa and then transmitting this data to the Particle Console before going back to sleep.

We have inconsistently been able to reproduce this issue by disconnecting the antenna from a unit. A handful of times the units latches up and produces a solid white led.

Attempts to address:

  • I removed a significant amount of output on serial port as suggested in this post

Differences between Electron and B402 code:

  • Aside from the difference in deviceOS, the sleep method has changed from
System.sleep(SLEEP_MODE_DEEP, secsTilQtr);

to

SystemSleepConfiguration config;
  config.mode(SystemSleepMode::ULTRA_LOW_POWER)
      .duration(secsTilQtr*1000);
  Particle.publish("SLEEP");
  System.sleep(config);
  System.reset();

We rely on the system reset to restart the device and run our setup() function. This was handled automatically in Gen2 when waking from SLEEP_MODE_DEEP. For Gen 3, the reset needed to be explicitly called with the way ULTRA_LOW_POWER is implemented.

Any reason to think this is the culprit? Would using the RESET_NO_FLAG help address? I may be grasping at straws here…

Not too sure if I can help since I do not use the sleep features on the Boron but just one comment regards to:

The serial output/logs/prints in the post you mentioned only caused the device to lock up when the prints were done in the onChange handler. Regular serial output for us doesn’t cause the device to freeze. I guess the moral the story is to keep handlers or interrupts as short as possible. Don’t do any IO or length functions within the interrupts or handlers.

One other scenario which may cause the device to freeze is if you have multiple interrupt triggers really quickly (e.g. glitches). Solution to this would either be a hardware fix or perhaps mitigated by the noInterrupts() and interrupts() functions within the ISR. This is to prevent interrupts triggering within an interrupts etc…

Not sure if this helps.

1 Like

Solid white at boot is almost always called by deadlock that occurs during global object initialization. There are two important changes that occurred between 1.5.2 and 3.x:

  • The gcc compiler was upgraded, and the order of global object initialization changed
  • More things that did not previously mutex lock which resulted in random failure due to thread safety issues now lock

The side effect of #2, however, is that it’s now easier to deadlock if your code accidentally calls a Device OS API function that uses a mutex lock from within an ATOMIC_BLOCK or SINGLE_THREADED_BLOCK.

See:

The reason it looks like the reset button does not work is that the device deadlocks immediately after boot, after turning the white LED on. The amount of time the LED is off is not visible, but it really is resetting. It’s not definite that’s what’s happening in your case, but it is a known situation that can occur.

2 Likes

I appreciate the suggestions @rickkas7 and @slacker89 . Let me dig into this.

@rickkas7 Any thoughts on why a power down would resolve these issues and not a reset?

That’s harder to explain, but there’s probably something that’s subtly different. One thing is that nRF52 reset doesn’t reset the cellular modem, so pressing reset leaves the modem in the state that it was previously in. It could be that code that is running early in startup is interacting with the modem or interacting with the system which is interacting with the modem causing this behavior.

Is there any way to access the modem reset pin directly? I see it’s tied internally to P0.12.

Code issues aside, would it make sense to reset the modem every time the system resets? Are there any power considerations that need to be made in doing that?

The modem power pin is not accessible, and it’s intentional to not reset it. It allows the modem to stay connected during System.reset and OTA firmware updates, which greatly speeds reconnection.

I’ve been able to capture logger output from three white LED events. All happened with the antenna disconnected. Not sure if this plays a role or not.

  1. The first from double clicking the reset button.
  2. Unit left idle and it occurred on its own
  3. Combination of mashing the mode and reset button

Once the device goes into the white LED state, the serial port closes and we loose visibility of what’s going on inside. Anything stand out as being suspect?

Side note: It would be a helpful feature if there were system logs being stored in flash (either internal or external) that could be recovered for events like this.

Serial monitor opened successfully:
0000000908 [app.main] INFO: Turning on cellular
0000000908 [system.nm] TRACE: Request to power on the interface
0000000909 [net.pppncp] TRACE: PPP netif event from queue: 5
0000000910 [ncp.client] TRACE: Powering modem on, ncpId: 0x44
0000000910 [ncp.client] TRACE: Modem already on
0000000910 [ncp.client] TRACE: Setting UART voltage translator state 1
0000000911 [system.nm] INFO: State changed: DISABLED -> IFACE_DOWN
ETC Receiver
0000001011 [ncp.client] TRACE: Setting UART voltage translator state 0
0000001111 [ncp.client] TRACE: Setting UART voltage translator state 1
0000001111 [ncp.client] TRACE: Muxer is not currently running
0000001112 [ncp.client] TRACE: Initialized muxer @ 460800 baudrate
0000001113 [gsm0710muxer] INFO: Starting GSM07.10 muxer
0000001113 [gsm0710muxer] INFO: GSM07.10 muxer thread started
0000001116 [ncp.client] TRACE: Resumed muxed session
0000001117 [gsm0710muxer] INFO: Openning mux channel 1
0000001466 [gsm0710muxer] INFO: Closing mux channel 2
0000001816 [ncp.at] TRACE: > AT
0000001824 [ncp.at] TRACE: < OK
0000001824 [ncp.client] TRACE: NCP ready to accept AT commands
0000001825 [ncp.at] TRACE: > AT
0000001833 [ncp.at] TRACE: < OK
0000001834 [ncp.at] TRACE: > ATI9
0000001842 [ncp.at] TRACE: < L0.0.00.00.05.08,A.02.04
0000001842 [ncp.at] TRACE: < OK
0000001843 [ncp.client] TRACE: App firmware: 204
0000001844 [ncp.at] TRACE: > AT+UGPIOC?
0000001853 [ncp.at] TRACE: < +UGPIOC:
0000001853 [ncp.at] TRACE: < 7,255
0000001853 [ncp.at] TRACE: < 16,255
0000001854 [ncp.at] TRACE: < 19,255
0000001855 [ncp.at] TRACE: < 23,0
0000001855 [ncp.at] TRACE: < 24,255
0000001855 [ncp.at] TRACE: < 25,255
0000001856 [ncp.at] TRACE: < 42,255
0000001856 [ncp.at] TRACE: < OK
0000001857 [ncp.at] TRACE: > AT+UGPIOR=23
0000001865 [ncp.at] TRACE: < +UGPIOR: 23,1
0000001866 [ncp.at] TRACE: < OK
0000001866 [ncp.client] INFO: Using internal SIM card
0000001867 [ncp.at] TRACE: > AT+CPIN?
0000001876 [ncp.at] TRACE: < +CPIN: READY
0000001876 [ncp.at] TRACE: < OK
0000001877 [ncp.at] TRACE: > AT+CCID
0000001885 [ncp.at] TRACE: < +CCID: 89014103273526067131
0000001886 [ncp.at] TRACE: < OK
0000001886 [ncp.at] TRACE: > AT+IFC=2,2
0000001894 [ncp.at] TRACE: < OK
0000001895 [ncp.at] TRACE: > AT
0000001902 [ncp.at] TRACE: < OK
0000001903 [ncp.at] TRACE: > AT+CCID
0000001911 [ncp.at] TRACE: < +CCID: 89014103273526067131
0000001912 [ncp.at] TRACE: < OK
0000001912 [ncp.at] TRACE: > AT+CIMI
0000001921 [ncp.at] TRACE: < 310410352606713
0000001921 [ncp.at] TRACE: < OK
0000001922 [ncp.at] TRACE: > AT+UMNOPROF?
0000001930 [ncp.at] TRACE: < +UMNOPROF: 2
0000001930 [ncp.at] TRACE: < OK
0000001931 [ncp.at] TRACE: > AT+COPS=3,2
0000001939 [ncp.at] TRACE: < OK
0000001940 [ncp.at] TRACE: > AT+CGEREP=1,0
0000001947 [ncp.at] TRACE: < OK
0000001948 [ncp.at] TRACE: > AT+URAT?
0000001957 [ncp.at] TRACE: < +CME ERROR: Operation not supported
0000001957 [ncp.at] TRACE: > AT+CPSMS?
0000001966 [ncp.at] TRACE: < +CPSMS:0,,,"10000101","00000011"
0000001966 [ncp.at] TRACE: < OK
0000001967 [ncp.at] TRACE: > AT+CEDRXS?
0000001975 [ncp.at] TRACE: < +CEDRXS:
0000001975 [ncp.at] TRACE: < OK
0000001976 [gsm0710muxer] INFO: Mux channel 1 already opened
0000001977 [ncp.at] TRACE: > AT
0000001984 [ncp.at] TRACE: < OK
0000001985 [ncp.client] TRACE: NCP state changed: 1
0000001985 [net.pppncp] TRACE: NCP event 1
0000001986 [ncp.at] TRACE: > AT+CFUN?
0000001994 [ncp.at] TRACE: < +CFUN: 1
0000001995 [ncp.at] TRACE: < OK
0000001996 [ncp.at] TRACE: > AT+CCID
0000002004 [ncp.at] TRACE: < +CCID: 89014103273526067131
0000002004 [ncp.at] TRACE: < OK
0000002005 [ncp.at] TRACE: > AT+CGSN
0000002013 [ncp.at] TRACE: < 356211692147930
0000002013 [ncp.at] TRACE: < OK
0000002014 [ncp.at] TRACE: > ATI9
0000002023 [ncp.at] TRACE: < L0.0.00.00.05.08,A.02.04
0000002023 [ncp.at] TRACE: < OK
0000002023 [app.main] INFO: 89014103273526067131
0000002024 [app.main] INFO: My ICCID is: 7131
Starting LoRa
0000002044 [app] INFO: LoRa Version: 18
0000002046 [app.main] INFO: LoRa in receive mode
Setup SIM and connect
0000002046 [app.main] INFO: Checking if the modem is on...
0000002047 [ncp.at] TRACE: > AT
0000002055 [ncp.at] TRACE: < OK
0000002055 [app.main] INFO: Modem is on!
0000002055 [app.main] INFO: Response code was -2 (RESP_OK)
0000002056 [app.main] INFO: Returning modemIsOn() = TRUE
0000002056 [app.main] INFO: Checking if modem is on before attempting to proceed with acquireIMSI() function
0000002057 [app.main] INFO: Checking if the modem is on...
0000002058 [ncp.at] TRACE: > AT
0000002064 [ncp.at] TRACE: < OK
0000002065 [app.main] INFO: Modem is on!
0000002065 [app.main] INFO: Response code was -2 (RESP_OK)
0000002065 [app.main] INFO: Returning modemIsOn() = TRUE
0000002066 [app.main] INFO: About to request the 4th byte of E.F. 6FAD from SIM card via modem
0000002067 [ncp.at] TRACE: > AT+CRSM=176,28589,0,3,1
0000002075 [ncp.at] TRACE: < +CRSM: 144,0,"03"
0000002075 [ncp.at] TRACE: < OK
0000002075 [app.main] INFO: Successfully parsed the MNC length..
================>  MNC length is: 48
0000002076 [app.main] INFO: About to request the IMSI number from the modem
0000002077 [ncp.at] TRACE: > AT+CIMI
0000002084 [ncp.at] TRACE: < 310410352606713
Successfully Parsed IMSI: 310410352606713
0000002085 [ncp.at] TRACE: < OK
0000002085 [app.main] INFO: Successfully parsed a potential IMSI number..
================>  parsed string is: 310410352606713
0000002086 [app.main] INFO: Now figuring out which cell credentials to use based on IMSI
0000002087 [app.main] INFO: MCC_str == 310
0000002087 [app.main] INFO: MNC string = 41
0000002088 [app.main] INFO: Decoding IMSI resulted in:
 MCC = 310  |  MNC = 041
0000002089 [app.main] INFO:   IMSI = 310410352606713  |  MCC = 310  |  MNC = 041  | MNC_len =                                                                                             ~      
0000002092 [app.main] INFO: ASSUME A PARTICLE SIM CARD
0000002093 [app.main] INFO: Attempting to set cellular credentials
0000002094 [ncp.at] TRACE: > AT+COPS=0
0000002106 [ncp.at] TRACE: < OK
0000002106 [app.main] INFO: Current SIMtype: 0
0000002109 [app.main] INFO: Reading SIMtype: 255
0000002109 [app.main] INFO: Unknown SIM card. Set network selection to default
0000002110 [ncp.at] TRACE: > AT+COPS=0
0000002122 [ncp.at] TRACE: < OK
0000002294 [app.main] INFO: Calling Particle.connect()
0000002295 [app.main] INFO: Wait for valid time
0000002396 [system.nm] INFO: State changed: IFACE_DOWN -> IFACE_REQUEST_UP
0000002398 [net.pppncp] TRACE: PPP netif event from queue: 1
0000002399 [net.ppp.client] TRACE: PPP thread event ADM_UP
0000002399 [net.ppp.client] TRACE: State NONE -> READY
0000002402 [ncp.at] TRACE: > AT+CFUN?
0000002404 [system.nm] INFO: State changed: IFACE_REQUEST_UP -> IFACE_UP
0000002410 [ncp.at] TRACE: < +CFUN: 1
0000002410 [ncp.at] TRACE: < OK
0000002411 [ncp.at] TRACE: > AT+CGDCONT?
0000002417 [ncp.at] TRACE: < +CGDCONT: 1,"IP","","0.0.0.0",0,0,0,0
0000002417 [ncp.at] TRACE: < OK
0000002418 [ncp.at] TRACE: > AT+CGDCONT=1,"IP",""
0000002442 [ncp.at] TRACE: < OK
0000002443 [ncp.at] TRACE: > AT+CFUN?
0000002451 [ncp.at] TRACE: < +CFUN: 1
0000002452 [ncp.at] TRACE: < OK
0000002452 [ncp.at] TRACE: > AT+CEREG=2
0000002460 [ncp.at] TRACE: < OK
0000002460 [ncp.client] TRACE: NCP connection state changed: 1
0000002461 [net.pppncp] TRACE: NCP event 2
0000002461 [net.pppncp] TRACE: State changed event: 1
0000002462 [net.ppp.client] TRACE: PPP thread event LOWER_DOWN
0000002462 [ncp.at] TRACE: > AT+COPS?
0000002470 [ncp.at] TRACE: < +COPS: 0
0000002470 [ncp.at] TRACE: < OK
0000002471 [ncp.at] TRACE: > AT+CEREG?
0000002479 [ncp.at] TRACE: < +CEREG: 2,2
0000002480 [ncp.at] TRACE: < OK


Serial connection closed.  Attempting to reconnect...
Serial monitor opened successfully:
0000000917 [app.main] INFO: Turning on cellular
0000000917 [system.nm] TRACE: Request to power on the interface
0000000918 [net.pppncp] TRACE: PPP netif event from queue: 5
0000000918 [ncp.client] TRACE: Powering modem on, ncpId: 0x44
0000000919 [ncp.client] TRACE: Modem already on
0000000919 [ncp.client] TRACE: Setting UART voltage translator state 1
0000000920 [system.nm] INFO: State changed: DISABLED -> IFACE_DOWN
ETC Receiver
0000001019 [ncp.client] TRACE: Setting UART voltage translator state 0
0000001119 [ncp.client] TRACE: Setting UART voltage translator state 1
0000001119 [ncp.client] TRACE: Muxer is not currently running
0000001121 [ncp.client] TRACE: Initialized muxer @ 460800 baudrate
0000001121 [gsm0710muxer] INFO: Starting GSM07.10 muxer
0000001122 [gsm0710muxer] INFO: GSM07.10 muxer thread started
0000001125 [ncp.client] TRACE: Resumed muxed session
0000001125 [gsm0710muxer] INFO: Openning mux channel 1
0000001474 [gsm0710muxer] INFO: Closing mux channel 2
0000001825 [ncp.at] TRACE: > AT
0000001832 [ncp.at] TRACE: < OK
0000001832 [ncp.client] TRACE: NCP ready to accept AT commands
0000001833 [ncp.at] TRACE: > AT
0000001840 [ncp.at] TRACE: < OK
0000001841 [ncp.at] TRACE: > ATI9
0000001849 [ncp.at] TRACE: < L0.0.00.00.05.08,A.02.04
0000001850 [ncp.at] TRACE: < OK
0000001850 [ncp.client] TRACE: App firmware: 204
0000001851 [ncp.at] TRACE: > AT+UGPIOC?
0000001859 [ncp.at] TRACE: < +UGPIOC:
0000001860 [ncp.at] TRACE: < 7,255
0000001860 [ncp.at] TRACE: < 16,255
0000001861 [ncp.at] TRACE: < 19,255
0000001861 [ncp.at] TRACE: < 23,0
0000001862 [ncp.at] TRACE: < 24,255
0000001862 [ncp.at] TRACE: < 25,255
0000001862 [ncp.at] TRACE: < 42,255
0000001863 [ncp.at] TRACE: < OK
0000001864 [ncp.at] TRACE: > AT+UGPIOR=23
0000001872 [ncp.at] TRACE: < +UGPIOR: 23,1
0000001872 [ncp.at] TRACE: < OK
0000001872 [ncp.client] INFO: Using internal SIM card
0000001873 [ncp.at] TRACE: > AT+CPIN?
0000001881 [ncp.at] TRACE: < +CPIN: READY
0000001882 [ncp.at] TRACE: < OK
0000001882 [ncp.at] TRACE: > AT+CCID
0000001890 [ncp.at] TRACE: < +CCID: 89014103273526067131
0000001891 [ncp.at] TRACE: < OK
0000001891 [ncp.at] TRACE: > AT+IFC=2,2
0000001899 [ncp.at] TRACE: < OK
0000001899 [ncp.at] TRACE: > AT
0000001907 [ncp.at] TRACE: < OK
0000001907 [ncp.at] TRACE: > AT+CCID
0000001915 [ncp.at] TRACE: < +CCID: 89014103273526067131
0000001916 [ncp.at] TRACE: < OK
0000001917 [ncp.at] TRACE: > AT+CIMI
0000001924 [ncp.at] TRACE: < 310410352606713
0000001925 [ncp.at] TRACE: < OK
0000001926 [ncp.at] TRACE: > AT+UMNOPROF?
0000001934 [ncp.at] TRACE: < +UMNOPROF: 2
0000001934 [ncp.at] TRACE: < OK
0000001935 [ncp.at] TRACE: > AT+COPS=3,2
0000001943 [ncp.at] TRACE: < OK
0000001943 [ncp.at] TRACE: > AT+CGEREP=1,0
0000001951 [ncp.at] TRACE: < OK
0000001952 [ncp.at] TRACE: > AT+URAT?
0000001960 [ncp.at] TRACE: < +CME ERROR: Operation not supported
0000001961 [ncp.at] TRACE: > AT+CPSMS?
0000001969 [ncp.at] TRACE: < +CPSMS:0,,,"10000101","00000011"
0000001970 [ncp.at] TRACE: < OK
0000001971 [ncp.at] TRACE: > AT+CEDRXS?
0000001978 [ncp.at] TRACE: < +CEDRXS:
0000001978 [ncp.at] TRACE: < OK
0000001979 [gsm0710muxer] INFO: Mux channel 1 already opened
0000001980 [ncp.at] TRACE: > AT
0000001988 [ncp.at] TRACE: < OK
0000001988 [ncp.client] TRACE: NCP state changed: 1
0000001988 [net.pppncp] TRACE: NCP event 1
0000001989 [ncp.at] TRACE: > AT+CFUN?
0000001997 [ncp.at] TRACE: < +CFUN: 1
0000001997 [ncp.at] TRACE: < OK
0000001998 [ncp.at] TRACE: > AT+CCID
0000002006 [ncp.at] TRACE: < +CCID: 89014103273526067131
0000002007 [ncp.at] TRACE: < OK
0000002008 [ncp.at] TRACE: > AT+CGSN
0000002015 [ncp.at] TRACE: < 356211692147930
0000002016 [ncp.at] TRACE: < OK
0000002017 [ncp.at] TRACE: > ATI9
0000002025 [ncp.at] TRACE: < L0.0.00.00.05.08,A.02.04
0000002025 [ncp.at] TRACE: < OK
0000002025 [app.main] INFO: 89014103273526067131
0000002026 [app.main] INFO: My ICCID is: 7131
Starting LoRa
0000002047 [app] INFO: LoRa Version: 18
0000002048 [app.main] INFO: LoRa in receive mode
Setup SIM and connect
0000002048 [app.main] INFO: Checking if the modem is on...
0000002049 [ncp.at] TRACE: > AT
0000002057 [ncp.at] TRACE: < OK
0000002058 [app.main] INFO: Modem is on!
0000002058 [app.main] INFO: Response code was -2 (RESP_OK)
0000002058 [app.main] INFO: Returning modemIsOn() = TRUE
0000002059 [app.main] INFO: Checking if modem is on before attempting to proceed with acquireIMSI() function
0000002060 [app.main] INFO: Checking if the modem is on...
0000002060 [ncp.at] TRACE: > AT
0000002068 [ncp.at] TRACE: < OK
0000002068 [app.main] INFO: Modem is on!
0000002068 [app.main] INFO: Response code was -2 (RESP_OK)
0000002069 [app.main] INFO: Returning modemIsOn() = TRUE
0000002069 [app.main] INFO: About to request the 4th byte of E.F. 6FAD from SIM card via modem
0000002070 [ncp.at] TRACE: > AT+CRSM=176,28589,0,3,1
0000002079 [ncp.at] TRACE: < +CRSM: 144,0,"03"
0000002079 [ncp.at] TRACE: < OK
0000002079 [app.main] INFO: Successfully parsed the MNC length..
================>  MNC length is: 48
0000002080 [app.main] INFO: About to request the IMSI number from the modem
0000002081 [ncp.at] TRACE: > AT+CIMI
0000002089 [ncp.at] TRACE: < 310410352606713
Successfully Parsed IMSI: 310410352606713
0000002090 [ncp.at] TRACE: < OK
0000002090 [app.main] INFO: Successfully parsed a potential IMSI number..
================>  parsed string is: 310410352606713
0000002091 [app.main] INFO: Now figuring out which cell credentials to use based on IMSI
0000002092 [app.main] INFO: MCC_str == 310
0000002092 [app.main] INFO: MNC string = 41
0000002093 [app.main] INFO: Decoding IMSI resulted in:
 MCC = 310  |  MNC = 041
0000002093 [app.main] INFO:   IMSI = 310410352606713  |  MCC = 310  |  MNC = 041  | MNC_len =                                                                                             ~      
0000002097 [app.main] INFO: ASSUME A PARTICLE SIM CARD
0000002097 [app.main] INFO: Attempting to set cellular credentials
0000002099 [ncp.at] TRACE: > AT+COPS=0
0000002113 [ncp.at] TRACE: < OK
0000002113 [app.main] INFO: Current SIMtype: 0
0000002116 [app.main] INFO: Reading SIMtype: 255
0000002117 [app.main] INFO: Unknown SIM card. Set network selection to default
0000002118 [ncp.at] TRACE: > AT+COPS=0
0000002129 [ncp.at] TRACE: < OK
0000002297 [app.main] INFO: Calling Particle.connect()
0000002297 [app.main] INFO: Wait for valid time
0000002398 [system.nm] INFO: State changed: IFACE_DOWN -> IFACE_REQUEST_UP
0000002399 [net.pppncp] TRACE: PPP netif event from queue: 1
0000002400 [net.ppp.client] TRACE: PPP thread event ADM_UP
0000002400 [net.ppp.client] TRACE: State NONE -> READY
0000002403 [ncp.at] TRACE: > AT+CFUN?
0000002404 [system.nm] INFO: State changed: IFACE_REQUEST_UP -> IFACE_UP
0000002408 [ncp.at] TRACE: < +CFUN: 1
0000002409 [ncp.at] TRACE: < OK
0000002410 [ncp.at] TRACE: > AT+CGDCONT?
0000002415 [ncp.at] TRACE: < +CGDCONT: 1,"IP","","0.0.0.0",0,0,0,0
0000002416 [ncp.at] TRACE: < OK
0000002416 [ncp.at] TRACE: > AT+CGDCONT=1,"IP",""
0000002444 [ncp.at] TRACE: < OK
0000002445 [ncp.at] TRACE: > AT+CFUN?
0000002450 [ncp.at] TRACE: < +CFUN: 1
0000002450 [ncp.at] TRACE: < OK
0000002451 [ncp.at] TRACE: > AT+CEREG=2
0000002456 [ncp.at] TRACE: < OK
0000002457 [ncp.client] TRACE: NCP connection state changed: 1
0000002457 [net.pppncp] TRACE: NCP event 2
0000002457 [net.pppncp] TRACE: State changed event: 1
0000002458 [net.ppp.client] TRACE: PPP thread event LOWER_DOWN
0000002459 [ncp.at] TRACE: > AT+COPS?
0000002463 [ncp.at] TRACE: < +COPS: 0
0000002463 [ncp.at] TRACE: < OK
0000002464 [ncp.at] TRACE: > AT+CEREG?
0000002469 [ncp.at] TRACE: < +CEREG: 2,2
0000002470 [ncp.at] TRACE: < OK
0000017478 [ncp.at] TRACE: > AT+CEREG?
0000017485 [ncp.at] TRACE: < +CEREG: 2,2
0000017486 [ncp.at] TRACE: < OK
0000017486 [ncp.at] TRACE: > AT+UCGED=5
0000017494 [ncp.at] TRACE: < OK
0000017495 [ncp.at] TRACE: > AT+UCGED?
0000017504 [ncp.at] TRACE: < +RSRP: 210,5060,"-133.70",383,5060,"-140.00",
0000017505 [ncp.at] TRACE: < +RSRQ: 210,5060,"-16.60",383,5060,"-20.00",
0000017505 [ncp.at] TRACE: < OK
0000032606 [ncp.at] TRACE: > AT+CEREG?
0000032613 [ncp.at] TRACE: < +CEREG: 2,2
0000032614 [ncp.at] TRACE: < OK
0000032614 [ncp.at] TRACE: > AT+UCGED=5
0000032622 [ncp.at] TRACE: < OK
0000032623 [ncp.at] TRACE: > AT+UCGED?
0000032632 [ncp.at] TRACE: < +RSRP: 210,5060,"-132.20",
0000032632 [ncp.at] TRACE: < +RSRQ: 210,5060,"-16.00",
0000032632 [ncp.at] TRACE: < OK
0000047637 [ncp.at] TRACE: > AT+CEREG?
0000047642 [ncp.at] TRACE: < +CEREG: 2,2
0000047642 [ncp.at] TRACE: < OK
0000047643 [ncp.at] TRACE: > AT+UCGED=5
0000047648 [ncp.at] TRACE: < OK
0000047649 [ncp.at] TRACE: > AT+UCGED?
0000047658 [ncp.at] TRACE: < +RSRP: 121,5145,"-137.10",417,5145,"-134.60",415,2325,"-140.00",245,2325,"-140.00",
0000047659 [ncp.at] TRACE: < +RSRQ: 121,5145,"-18.90",417,5145,"-18.60",415,2325,"-20.00",245,2325,"-20.00",
0000047659 [ncp.at] TRACE: < OK
0000062298 [app.main] INFO: Register Callbacks...
Wait until cellular is ready...
0000062563 [ncp.at] TRACE: > AT+CIMI
0000062570 [ncp.at] TRACE: < 310410352606713
0000062570 [ncp.at] TRACE: < OK
0000062671 [ncp.at] TRACE: > AT+CEREG?
0000062679 [ncp.at] TRACE: < +CEREG: 2,2
0000062679 [ncp.at] TRACE: < OK
0000062680 [ncp.at] TRACE: > AT+UCGED=5
0000062688 [ncp.at] TRACE: < OK
0000062688 [ncp.at] TRACE: > AT+UCGED?
0000062698 [ncp.at] TRACE: < +RSRP: 121,5145,"-137.10",417,5145,"-131.10",
0000062698 [ncp.at] TRACE: < +RSRQ: 121,5145,"-19.30",417,5145,"-15.30",
0000062699 [ncp.at] TRACE: < OK
0000077700 [ncp.at] TRACE: > AT+CEREG?
0000077705 [ncp.at] TRACE: < +CEREG: 2,2
0000077706 [ncp.at] TRACE: < OK
0000077706 [ncp.at] TRACE: > AT+UCGED=5
0000077711 [ncp.at] TRACE: < OK
0000077712 [ncp.at] TRACE: > AT+UCGED?
0000077717 [ncp.at] TRACE: < +CME ERROR: unknown
0000092718 [ncp.at] TRACE: > AT+CEREG?
0000092725 [ncp.at] TRACE: < +CEREG: 2,2
0000092726 [ncp.at] TRACE: < OK
0000092726 [ncp.at] TRACE: > AT+UCGED=5
0000092734 [ncp.at] TRACE: < OK
0000092735 [ncp.at] TRACE: > AT+UCGED?
0000092743 [ncp.at] TRACE: < +RSRP: 210,5060,"-132.20",
0000092744 [ncp.at] TRACE: < +RSRQ: 210,5060,"-15.30",
0000092744 [ncp.at] TRACE: < OK
0000107752 [ncp.at] TRACE: > AT+CEREG?
0000107759 [ncp.at] TRACE: < +CEREG: 2,2
0000107759 [ncp.at] TRACE: < OK
0000107760 [ncp.at] TRACE: > AT+UCGED=5
0000107765 [ncp.at] TRACE: < OK
0000107766 [ncp.at] TRACE: > AT+UCGED?
0000107772 [ncp.at] TRACE: < +RSRP: 210,5060,"-132.80",
0000107772 [ncp.at] TRACE: < +RSRQ: 210,5060,"-15.80",
0000107773 [ncp.at] TRACE: < OK
0000122608 [ncp.at] TRACE: > AT+CIMI
0000122615 [ncp.at] TRACE: < 310410352606713
0000122615 [ncp.at] TRACE: < OK
0000122816 [ncp.at] TRACE: > AT+CEREG?
0000122824 [ncp.at] TRACE: < +CEREG: 2,2
0000122824 [ncp.at] TRACE: < OK
0000122825 [ncp.at] TRACE: > AT+UCGED=5
0000122833 [ncp.at] TRACE: < OK
0000122833 [ncp.at] TRACE: > AT+UCGED?
0000122842 [ncp.at] TRACE: < +RSRP: 210,5060,"-135.10",
0000122842 [ncp.at] TRACE: < +RSRQ: 210,5060,"-18.00",
0000122843 [ncp.at] TRACE: < OK
0000137920 [ncp.at] TRACE: > AT+CEREG?
0000137927 [ncp.at] TRACE: < +CEREG: 2,2
0000137928 [ncp.at] TRACE: < OK
0000137929 [ncp.at] TRACE: > AT+UCGED=5
0000137936 [ncp.at] TRACE: < OK
0000137937 [ncp.at] TRACE: > AT+UCGED?
0000137948 [ncp.at] TRACE: < +RSRP: 417,5145,"-134.10",121,5145,"-134.60",245,2325,"-134.10",
0000137949 [ncp.at] TRACE: < +RSRQ: 417,5145,"-16.10",121,5145,"-18.90",245,2325,"-18.50",
0000137950 [ncp.at] TRACE: < OK
0000153019 [ncp.at] TRACE: > AT+CEREG?
0000153026 [ncp.at] TRACE: < +CEREG: 2,2
0000153027 [ncp.at] TRACE: < OK
0000153027 [ncp.at] TRACE: > AT+UCGED=5
0000153035 [ncp.at] TRACE: < OK
0000153036 [ncp.at] TRACE: > AT+UCGED?
0000153044 [ncp.at] TRACE: < +RSRP: 417,5145,"-134.30",
0000153045 [ncp.at] TRACE: < +RSRQ: 417,5145,"-16.50",
0000153045 [ncp.at] TRACE: < OK
0000168110 [ncp.at] TRACE: > AT+CEREG?
0000168117 [ncp.at] TRACE: < +CEREG: 2,2
0000168118 [ncp.at] TRACE: < OK
0000168119 [ncp.at] TRACE: > AT+UCGED=5
0000168126 [ncp.at] TRACE: < OK
0000168127 [ncp.at] TRACE: > AT+UCGED?
0000168136 [ncp.at] TRACE: < +RSRP: 417,5145,"-133.60",245,2325,"-132.80",
0000168137 [ncp.at] TRACE: < +RSRQ: 417,5145,"-15.90",245,2325,"-17.00",
...
0000288684 [ncp.at] TRACE: < OK
0000302740 [ncp.at] TRACE: > AT+CIMI
0000302747 [ncp.at] TRACE: < 310410352606713
0000302748 [ncp.at] TRACE: < OK
0000303755 [ncp.at] TRACE: > AT+CEREG?
0000303762 [ncp.at] TRACE: < +CEREG: 2,2
0000303763 [ncp.at] TRACE: < OK
0000303766 [ncp.at] TRACE: > AT+UCGED=5
0000303773 [ncp.at] TRACE: < OK
0000303774 [ncp.at] TRACE: > AT+UCGED?
0000303783 [ncp.at] TRACE: < +RSRP: 210,5060,"-132.50",
0000303783 [ncp.at] TRACE: < +RSRQ: 210,5060,"-15.70",
0000303784 [ncp.at] TRACE: < OK
0000318848 [ncp.at] TRACE: > AT+CEREG?
0000318855 [ncp.at] TRACE: < +CEREG: 2,2
0000318856 [ncp.at] TRACE: < OK
0000318856 [ncp.at] TRACE: > AT+UCGED=5
0000318865 [ncp.at] TRACE: < OK
0000318866 [ncp.at] TRACE: > AT+UCGED?
0000318874 [ncp.at] TRACE: < +RSRP: 210,5060,"-132.30",
0000318875 [ncp.at] TRACE: < +RSRQ: 210,5060,"-15.50",
0000318875 [ncp.at] TRACE: < OK
0000333939 [ncp.at] TRACE: > AT+CEREG?
0000333946 [ncp.at] TRACE: < +CEREG: 2,2
0000333946 [ncp.at] TRACE: < OK
0000333947 [ncp.at] TRACE: > AT+UCGED=5
0000333955 [ncp.at] TRACE: < OK
0000333955 [ncp.at] TRACE: > AT+UCGED?
0000333964 [ncp.at] TRACE: < +RSRP: 210,5060,"-131.60",
0000333965 [ncp.at] TRACE: < +RSRQ: 210,5060,"-15.00",
0000333965 [ncp.at] TRACE: < OK
0000349021 [ncp.at] TRACE: > AT+CEREG?
0000349028 [ncp.at] TRACE: < +CEREG: 2,2
0000349029 [ncp.at] TRACE: < OK
0000349029 [ncp.at] TRACE: > AT+UCGED=5
0000349037 [ncp.at] TRACE: < OK
0000349038 [ncp.at] TRACE: > AT+UCGED?
0000349050 [ncp.at] TRACE: < +RSRP: 417,5145,"-133.80",121,5145,"-134.60",488,5145,"-140.00",188,5145,"-140.00",
0000349050 [ncp.at] TRACE: < +RSRQ: 417,5145,"-16.50",121,5145,"-19.50",488,5145,"-20.00",188,5145,"-20.00",
0000349051 [ncp.at] TRACE: < OK


Serial connection closed.  Attempting to reconnect...
Serial monitor opened successfully:
0000000904 [app.main] INFO: Turning on cellular
0000000905 [system.nm] TRACE: Request to power on the interface
0000000905 [net.pppncp] TRACE: PPP netif event from queue: 5
0000000906 [ncp.client] TRACE: Powering modem on, ncpId: 0x44
0000000907 [ncp.client] TRACE: Modem already on
0000000907 [ncp.client] TRACE: Setting UART voltage translator state 1
0000000908 [system.nm] INFO: State changed: DISABLED -> IFACE_DOWN
ETC Receiver
0000001007 [ncp.client] TRACE: Setting UART voltage translator state 0
0000001107 [ncp.client] TRACE: Setting UART voltage translator state 1
0000001108 [ncp.client] TRACE: Muxer is not currently running
0000001109 [ncp.client] TRACE: Initialized muxer @ 460800 baudrate
0000001109 [gsm0710muxer] INFO: Starting GSM07.10 muxer
0000001110 [gsm0710muxer] INFO: GSM07.10 muxer thread started
0000001409 [gsm0710muxer] INFO: Stopping GSM07.10 muxer
0000001409 [gsm0710muxer] INFO: Gracefully stopping GSM07.10 muxer
0000001410 [gsm0710muxer] INFO: Closing all muxed channels
0000001410 [gsm0710muxer] INFO: Muxed channel 1 already closed
0000001411 [gsm0710muxer] INFO: Muxed channel 2 already closed
0000001411 [gsm0710muxer] INFO: Muxed channel 3 already closed
0000001412 [gsm0710muxer] INFO: Muxed channel 4 already closed
0000002063 [gsm0710muxer] INFO: Sending CLD (multiplexer close down)
0000002964 [gsm0710muxer] INFO: Received response to CLD or timed out, exiting multiplexed mode
0000003014 [gsm0710muxer] INFO: GSM07.10 muxer thread exiting
0000003014 [gsm0710muxer] INFO: GSM07.10 muxer stopped
0000003015 [ncp.client] TRACE: Initialized muxer @ 115200 baudrate
0000003016 [gsm0710muxer] INFO: Starting GSM07.10 muxer
0000003016 [gsm0710muxer] INFO: GSM07.10 muxer thread started
0000003316 [gsm0710muxer] INFO: Stopping GSM07.10 muxer
0000003316 [gsm0710muxer] INFO: Gracefully stopping GSM07.10 muxer
0000003317 [gsm0710muxer] INFO: Closing all muxed channels
0000003317 [gsm0710muxer] INFO: Muxed channel 1 already closed
0000003318 [gsm0710muxer] INFO: Muxed channel 2 already closed
0000003318 [gsm0710muxer] INFO: Muxed channel 3 already closed
0000003319 [gsm0710muxer] INFO: Muxed channel 4 already closed
0000003970 [gsm0710muxer] INFO: Sending CLD (multiplexer close down)
0000004871 [gsm0710muxer] INFO: Received response to CLD or timed out, exiting multiplexed mode
0000004921 [gsm0710muxer] INFO: GSM07.10 muxer thread exiting
0000004922 [gsm0710muxer] INFO: GSM07.10 muxer stopped
0000004923 [ncp.at] TRACE: > AT
0000004926 [ncp.at] TRACE: < OK
0000004926 [ncp.client] TRACE: NCP ready to accept AT commands
0000004926 [ncp.at] TRACE: > AT
0000004928 [ncp.at] TRACE: < OK
0000004929 [ncp.at] TRACE: > ATI9
0000004931 [ncp.at] TRACE: < L0.0.00.00.05.08,A.02.04
0000004932 [ncp.at] TRACE: < OK
0000004932 [ncp.client] TRACE: App firmware: 204
0000004932 [ncp.at] TRACE: > AT+UGPIOC?
0000004935 [ncp.at] TRACE: < +UGPIOC:
0000004936 [ncp.at] TRACE: < 7,255
0000004936 [ncp.at] TRACE: < 16,255
0000004937 [ncp.at] TRACE: < 19,255
0000004937 [ncp.at] TRACE: < 23,0
0000004937 [ncp.at] TRACE: < 24,255
0000004938 [ncp.at] TRACE: < 25,255
0000004938 [ncp.at] TRACE: < 42,255
0000004939 [ncp.at] TRACE: < OK
0000004939 [ncp.at] TRACE: > AT+UGPIOR=23
0000004942 [ncp.at] TRACE: < +UGPIOR: 23,1
0000004942 [ncp.at] TRACE: < OK
0000004943 [ncp.client] INFO: Using internal SIM card
0000004943 [ncp.at] TRACE: > AT+CPIN?
0000004946 [ncp.at] TRACE: < +CPIN: READY
0000004946 [ncp.at] TRACE: < OK
0000004947 [ncp.at] TRACE: > AT+CCID
0000004949 [ncp.at] TRACE: < +CCID: 89014103273526067131
0000004950 [ncp.at] TRACE: < OK
0000004950 [ncp.at] TRACE: > AT+IFC=2,2
0000004952 [ncp.at] TRACE: < OK
0000004952 [ncp.at] TRACE: > AT
0000004954 [ncp.at] TRACE: < OK
0000004954 [ncp.at] TRACE: > AT+IPR=460800
0000004962 [ncp.at] TRACE: < OK
0000005962 [ncp.at] TRACE: > AT
0000005965 [ncp.at] TRACE: < OK
0000005965 [ncp.at] TRACE: > AT+CCID
0000005968 [ncp.at] TRACE: < +CCID: 89014103273526067131
0000005968 [ncp.at] TRACE: < OK
0000005969 [ncp.at] TRACE: > AT+CIMI
0000005971 [ncp.at] TRACE: < 310410352606713
0000005971 [ncp.at] TRACE: < OK
0000005972 [ncp.at] TRACE: > AT+UMNOPROF?
0000005978 [ncp.at] TRACE: < +UMNOPROF: 2
0000005978 [ncp.at] TRACE: < OK
0000005979 [ncp.at] TRACE: > AT+COPS=3,2
0000005981 [ncp.at] TRACE: < OK
0000005981 [ncp.at] TRACE: > AT+CGEREP=1,0
0000005984 [ncp.at] TRACE: < OK
0000005984 [ncp.at] TRACE: > AT+URAT?
0000005987 [ncp.at] TRACE: < +CME ERROR: Operation not supported
0000005987 [ncp.at] TRACE: > AT+CPSMS?
0000005992 [ncp.at] TRACE: < +CPSMS:0,,,"10000101","00000011"
0000005992 [ncp.at] TRACE: < OK
0000005993 [ncp.at] TRACE: > AT+CEDRXS?
0000005995 [ncp.at] TRACE: < +CEDRXS:
0000005996 [ncp.at] TRACE: < OK
0000005996 [ncp.at] TRACE: > AT+CMUX=0,0,,1509,,,,,
0000006001 [ncp.at] TRACE: < OK
0000006001 [gsm0710muxer] INFO: Starting GSM07.10 muxer
0000006001 [gsm0710muxer] INFO: Openning mux channel 0
0000006002 [gsm0710muxer] INFO: GSM07.10 muxer thread started
0000006005 [gsm0710muxer] INFO: Openning mux channel 1
0000006009 [ncp.at] TRACE: > AT
0000006012 [ncp.at] TRACE: < OK
0000006013 [ncp.client] TRACE: NCP state changed: 1
0000006013 [net.pppncp] TRACE: NCP event 1
0000006014 [ncp.at] TRACE: > AT+CFUN?
0000006019 [ncp.at] TRACE: < +CFUN: 1
0000006019 [ncp.at] TRACE: < OK
0000006020 [ncp.at] TRACE: > AT+CCID
0000006025 [ncp.at] TRACE: < +CCID: 89014103273526067131
0000006025 [ncp.at] TRACE: < OK
0000006026 [ncp.at] TRACE: > AT+CGSN
0000006031 [ncp.at] TRACE: < 356211692147930
0000006031 [ncp.at] TRACE: < OK
0000006032 [ncp.at] TRACE: > ATI9
0000006037 [ncp.at] TRACE: < L0.0.00.00.05.08,A.02.04
0000006037 [ncp.at] TRACE: < OK
0000006038 [app.main] INFO: 89014103273526067131
0000006038 [app.main] INFO: My ICCID is: 7131
Starting LoRa
0000006059 [app] INFO: LoRa Version: 18
0000006060 [app.main] INFO: LoRa in receive mode
Setup SIM and connect
0000006060 [app.main] INFO: Checking if the modem is on...
0000006062 [ncp.at] TRACE: > AT
0000006065 [ncp.at] TRACE: < OK
0000006065 [app.main] INFO: Modem is on!
0000006066 [app.main] INFO: Response code was -2 (RESP_OK)
0000006066 [app.main] INFO: Returning modemIsOn() = TRUE
0000006067 [app.main] INFO: Checking if modem is on before attempting to proceed with acquireIMSI() function
0000006067 [app.main] INFO: Checking if the modem is on...
0000006069 [ncp.at] TRACE: > AT
0000006072 [ncp.at] TRACE: < OK
0000006073 [app.main] INFO: Modem is on!
0000006073 [app.main] INFO: Response code was -2 (RESP_OK)
0000006073 [app.main] INFO: Returning modemIsOn() = TRUE
0000006074 [app.main] INFO: About to request the 4th byte of E.F. 6FAD from SIM card via modem
0000006075 [ncp.at] TRACE: > AT+CRSM=176,28589,0,3,1
0000006081 [ncp.at] TRACE: < +CRSM: 144,0,"03"
0000006081 [ncp.at] TRACE: < OK
0000006081 [app.main] INFO: Successfully parsed the MNC length..
================>  MNC length is: 48
0000006082 [app.main] INFO: About to request the IMSI number from the modem
0000006084 [ncp.at] TRACE: > AT+CIMI
0000006088 [ncp.at] TRACE: < 310410352606713
Successfully Parsed IMSI: 310410352606713
0000006089 [ncp.at] TRACE: < OK
0000006089 [app.main] INFO: Successfully parsed a potential IMSI number..
================>  parsed string is: 310410352606713
0000006090 [app.main] INFO: Now figuring out which cell credentials to use based on IMSI
0000006091 [app.main] INFO: MCC_str == 310
0000006091 [app.main] INFO: MNC string = 41
0000006092 [app.main] INFO: Decoding IMSI resulted in:
 MCC = 310  |  MNC = 041
0000006092 [app.main] INFO:   IMSI = 310410352606713  |  MCC = 310  |  MNC = 041  | MNC_len =                                                                                             ~      
0000006096 [app.main] INFO: ASSUME A PARTICLE SIM CARD
0000006097 [app.main] INFO: Attempting to set cellular credentials
0000006098 [ncp.at] TRACE: > AT+COPS=0
0000006111 [ncp.at] TRACE: < OK
0000006443 [ncp.client] TRACE: NCP connection state changed: 1
0000006443 [net.pppncp] TRACE: NCP event 2
0000006444 [net.pppncp] TRACE: State changed event: 1
0000006444 [net.ppp.client] TRACE: PPP thread event LOWER_DOWN
0000006445 [ncp.at] TRACE: > AT+COPS?
0000006448 [ncp.at] TRACE: < +COPS: 0
0000006448 [ncp.at] TRACE: < OK
0000006449 [ncp.at] TRACE: > AT+CEREG?
0000006452 [ncp.at] TRACE: < +CEREG: 2,2
0000006452 [ncp.at] TRACE: < OK


Serial connection closed.  Attempting to reconnect...

@rickkas7 Are there any significant updates post deviceOS 2.3.0 that would make us consider updating to a later version given this issue?

How are you powering the B402? What does the supply circuitry look like?

A power-related issue could cause the nRF52 to lock up and not reset. The time after > AT+CEREG? is when the power usage dramatically increases.

It’s fine to stay back at 2.x for now, but should probably eventually figure out why you have a failure with 3.x because 2.x will only be supported for a year or so after 4.0 comes out. 4.0 is based on 3.x, not 2.x, so it could be affected by the same thing.

Our circuitry is fairly similar to what’s on the Boron:

There are some caveats though. Due to a part substitution, the 3.3V rail is actually closer to 3.165V. Given that the B402 datasheet says this rail can go down to 3.0V, we thought this was fine.