Board continually receives CoAP messages and wakes from sleep mode

Firmware
1

I have a fleet of 30 boards. I have them all set up to sleep for most of the time but wake up from network messages, a GPIO pin, or a duration of 15 minutes (to keep them all cloud connected). Only the GPIO pin wakeup method keeps the board awake for an extended period of time, the other wake up methods wake the board up for a very short amount of time, publish their vitals, and then put them back to sleep.

This mostly works. Except, only occasionally on some boards do they continuously wake up about every 10 seconds. I'm logging these messages during that time but I don't know what to make of them. I can't figure out what network activity is causing them to wakeup. Here are the logs:

Serial connection closed.  Attempting to reconnect...
Serial monitor opened successfully:
0000044226 [comm.coap] TRACE: Received CoAP message
0000044227 [comm.coap] TRACE: ACK 0.00  size=5 token=29 id=251
Time to sleep.. bye!
reason: 4
0000045035 [system.sleep] TRACE: Entering system_sleep_ext()
0000045036 [system.sleep] TRACE: Interface 3 is off already


Serial connection closed.  Attempting to reconnect...
Serial monitor opened successfully:
Time to sleep.. bye!
reason: 4
0000070588 [system.sleep] TRACE: Entering system_sleep_ext()
0000070589 [system.sleep] TRACE: Interface 3 is off already


Serial connection closed.  Attempting to reconnect...
Serial monitor opened successfully:
Time to sleep.. bye!
reason: 4
0000074814 [system.sleep] TRACE: Entering system_sleep_ext()
0000074815 [system.sleep] TRACE: Interface 3 is off already


Serial connection closed.  Attempting to reconnect...
Serial monitor opened successfully:
0000078911 [comm.coap] TRACE: Received CoAP message
0000078912 [comm.coap] TRACE: ACK 0.00  size=5 token=2d id=259
Time to sleep.. bye!
reason: 4
0000079740 [system.sleep] TRACE: Entering system_sleep_ext()
0000079741 [system.sleep] TRACE: Interface 3 is off already


Serial connection closed.  Attempting to reconnect...
Serial monitor opened successfully:
0000086670 [comm.coap] TRACE: Received CoAP message
0000086671 [comm.coap] TRACE: ACK 0.00  size=5 token=2e id=261
Time to sleep.. bye!
reason: 4
0000087543 [system.sleep] TRACE: Entering system_sleep_ext()
0000087544 [system.sleep] TRACE: Interface 3 is off already

The "reason: 4" log is tracking the "System.wakeUpReason()"
Could someone help me interpret this? If you're wondering - I have the boards set up with a webhook integration but they are set up to only subscribe to events attached to their board's ID.

2

Unfortunately there isn't enough information in this log to determine what is happening.

The best way to debug this is to use a USB to 3.3 UART serial adapter (FT232) and log to Serial1 instead of USB serial. The reason is that it takes several seconds to connect to USB serial (longer under Windows) even with --follow and the wake reason is already lost by then. When using an external adapter, the USB serial connection stays up when the device is asleep, so the log messages at wake will be printed.

You'll something like this in your firmware to log to Serial1 instead of Serial.

Serial1LogHandler logHandler(115200, LOG_LEVEL_TRACE);
3

Ahh, ok. I might do this eventually but it's not such a huge problem right now. Thank you for the help

4

I went ahead and performed this set up. This is the full messaged my board received:

0000140860 [comm.coap] TRACE: Sending CoAP message
0000140860 [comm.coap] TRACE: CON 0.00  size=4 token= id=17
0000140869 [ncp.at] TRACE: > AT+COPS=3,2
0000140870 [ncp.at] TRACE: < +CEREG: 5,"5506","0be71b10",7
0000140875 [ncp.at] TRACE: < OK
0000140881 [ncp.at] TRACE: > AT+COPS?
0000140885 [ncp.at] TRACE: < +COPS: 0,2,"310410",7
0000140886 [ncp.at] TRACE: < OK
0000140888 [ncp.at] TRACE: > AT+UCGED?
0000141375 [ncp.at] TRACE: < +UCGED: 2
0000141376 [ncp.at] TRACE: < 6,4,310,410
0000141378 [ncp.at] TRACE: < 5110,12,50,50,5506,be71b10,181,cccb4d98,ff01,13,57,13,-1.43,3,255,255,56,7,-12,300,255,255,80
0000141389 [ncp.at] TRACE: < OK
0000141394 [ncp.at] TRACE: > AT+COPS=3,2
0000141398 [ncp.at] TRACE: < OK
0000141399 [ncp.at] TRACE: > AT+COPS?
0000141405 [ncp.at] TRACE: < +COPS: 0,2,"310410",7
0000141406 [ncp.at] TRACE: < OK
0000141411 [ncp.at] TRACE: > AT+CEREG?
0000141416 [ncp.at] TRACE: < +CEREG: 2,5,"5506","0be71b10",7
0000141421 [ncp.at] TRACE: < OK
0000141422 [comm.coap] TRACE: Sending CoAP message
0000141427 [comm.coap] TRACE: CON POST /d?\x04 size=197 token=6b id=18
0000141435 [comm.coap] TRACE: Received CoAP message
0000141436 [comm.coap] TRACE: ACK 0.00  size=4 token= id=17
0000141639 [comm.coap] TRACE: Received CoAP message
0000141640 [comm.coap] TRACE: ACK 0.00  size=5 token=6b id=18
0000142371 [system.sleep] TRACE: Entering system_sleep_ext()
0000142371 [system.sleep] TRACE: Interface 3 is off already

Any clue to why this happened? It's pretty important to me because my project is battery powered and because the board is waking up so frequently, the battery is draining quicker. I should also note that I have a fleet of 30 boards and this happens seemingly randomly to some boards and it will continue for a set amount of time and then taper off. On the particle console side, every time this happens I get a " spark/device/diagnostics/update" log. Here is the extended version of that log:

{
"device":{
"network":{
"cellular":{
"radio_access_technology":"LTE"
"operator":"AT&T Wireless Inc."
"cell_global_identity":{
"mobile_country_code":310
"mobile_network_code":"410"
"location_area_code":21766
"cell_id":199695120
}
}
"signal":{
"at":"LTE Cat-M1"
"strength":76.66
"strength_units":"%"
"strengthv":-84
"strengthv_units":"dBm"
"strengthv_type":"RSRP"
"quality":37.5
"quality_units":"%"
"qualityv":-13.5
"qualityv_units":"dB"
"qualityv_type":"RSRQ"
}
"connection":{
"status":"connected"
"error":0
"disconnects":0
"attempts":1
"disconnect_reason":"unknown"
}
}
"cloud":{
"connection":{
"status":"connected"
"error":0
"attempts":1
"disconnects":0
"disconnect_reason":"none"
}
"coap":{
"transmit":17
"retransmit":4
"unack":0
"round_trip":296
}
"publish":{
"rate_limited":0
}
}
"power":{
"battery":{
"charge":{
"err":-210
}
"state":"disconnected"
}
"source":"USB adapter"
}
"system":{
"uptime":140
"memory":{
"used":71152
"total":165960
}
}
}
"service":{
"device":{
"status":"ok"
}
"cloud":{
"uptime":124
"publish":{
"sent":3
}
}
"coap":{
"round_trip":195
}
}
}

Any help is much appreciated. Thank you!

5

For more information, here is a short snippet of the events log. I have a fleet of 30 boards that all turn on and go to sleep until triggered by a either 1) GPIO input 2) Network message 3) Timeout of 15 minutes

Unless the wakeup reason is a GPIO input, the board will go back to sleep pretty much instantaneously. In my case, I have 30 boards that are all turned on and then put to sleep indefinitely. None of them are detecting any GPIO input. They're waking up very frequently so they are not timing out at 15 minutes. It must be a network message. I am watching them on my events log though wake up very frequently.

log
log1093×924 83 KB

Here is my sleep config code:

  config.mode(SystemSleepMode::STOP)
    .gpio(LIMIT_SWITCH, CHANGE) 
    .duration(15min)
    .network(NETWORK_INTERFACE_CELLULAR);

I am stumped as to why this is happening. I want to fix it because it seems like my boards are draining battery power faster than I would like. I have my device names commented out to protect information about the project but I kept the first two letters so you can see that it is multiple different boards waking up, not just one. From what I can tell, some boards are waking up very frequently, and some aren't waking up at all. It also seems that a board is more likely to wake up frequently if more boards in the fleet are powered on. Is there some network message that my product of boards receive that could possibly trigger another network message to be sent, over and over?

6

This topic was automatically closed 182 days after the last reply. New replies are no longer allowed.