Application logging

Firmware Device OS
1

I’ve been away for awhile, so please excuse what may be a dumb question. I wrote a new program and am trying to utilize Log.info() in lieu of Serial.println() statements as recommended. The “weird” thing is that on the first run through the program (prior to a 5 second ULTRA_LOW_SLEEP), I get all of the app log messages. However, after it comes back from sleep, I’m only seeing system level log messages. Do I need to configure something differently? I’m running 3.1.0 on an Argon. Here’s an example:

Serial connection closed.  Attempting to reconnect...
particleSerial monitor opened successfully:
0000000917 [app] INFO: Sensor online!
0000000922 [app] INFO: Ranging started
0000000922 [app] INFO: -------------------------
0000001116 [app] INFO: Starting to check distance
0000001116 [app] INFO: distance: 2557
0000001116 [app] INFO: tripPoint:2041
0000001116 [app] INFO: Space is empty
0000001117 [app] INFO: RelayStatus: 0
0000001117 [app] INFO: Ready to go to delay/sleep
0000002404 [gsm0710muxer] INFO: Starting GSM07.10 muxer
0000002404 [gsm0710muxer] INFO: Openning mux channel 0
0000002405 [gsm0710muxer] INFO: GSM07.10 muxer thread started
0000002531 [gsm0710muxer] INFO: Openning mux channel 1
0000003811 [net.esp32ncp] INFO: Setting WiFi interface MAC to 24:6f:28:3c:84:bc
0000003812 [gsm0710muxer] INFO: Stopping GSM07.10 muxer
0000003812 [gsm0710muxer] INFO: Gracefully stopping GSM07.10 muxer
0000003813 [gsm0710muxer] INFO: Closing all muxed channels
0000003813 [gsm0710muxer] INFO: Closing mux channel 1
0000003814 [gsm0710muxer] INFO: Muxed channel 2 already closed
0000003814 [gsm0710muxer] INFO: Muxed channel 3 already closed
0000003815 [gsm0710muxer] INFO: Muxed channel 4 already closed
0000005082 [gsm0710muxer] INFO: Sending CLD (multiplexer close down)
0000005084 [gsm0710muxer] INFO: Received response to CLD or timed out, exiting multiplexed mode
0000005084 [gsm0710muxer] INFO: GSM07.10 muxer thread exiting
0000005085 [gsm0710muxer] INFO: GSM07.10 muxer stopped


Serial connection closed.  Attempting to reconnect...
Serial monitor opened successfully:
0000022554 [gsm0710muxer] INFO: Starting GSM07.10 muxer
0000022555 [gsm0710muxer] INFO: Openning mux channel 0
0000022555 [gsm0710muxer] INFO: GSM07.10 muxer thread started
0000022559 [gsm0710muxer] INFO: Openning mux channel 1
0000022571 [gsm0710muxer] INFO: Stopping GSM07.10 muxer
0000022571 [gsm0710muxer] INFO: Gracefully stopping GSM07.10 muxer
0000022572 [gsm0710muxer] INFO: Closing all muxed channels
0000022572 [gsm0710muxer] INFO: Closing mux channel 1
0000022573 [gsm0710muxer] INFO: Muxed channel 2 already closed
0000022573 [gsm0710muxer] INFO: Muxed channel 3 already closed
0000022574 [gsm0710muxer] INFO: Muxed channel 4 already closed
0000023840 [gsm0710muxer] INFO: Sending CLD (multiplexer close down)
0000023842 [gsm0710muxer] INFO: Received response to CLD or timed out, exiting multiplexed mode
0000023843 [gsm0710muxer] INFO: GSM07.10 muxer thread exiting
0000023843 [gsm0710muxer] INFO: GSM07.10 muxer stopped


Serial connection closed.  Attempting to reconnect...
2

It’s probably not a configuration issue. There are a few things that affect post-sleep logs:

  • The time to reconnect to USB serial is a big one. It’s at least a few seconds, and up to 8 on Windows, and by then much of the reconnection has already occurred and the log messages lost. The solution is to use Serial1 (hardware UART) logging with an external USB to serial converter. That works because the USB connection to the converter stays up even when the Particle device is asleep.
  • In STOP or ULP sleep modes, enough state is kept that some of those messages don’t occur again because the modem is partially initialized already, even if it was powered off.
  • In network standby mode, none of the messages appear because the connection was completely up so there was nothing to reinitialize.
1 Like