Logging debug messages over long periods
-
This post describes a method I utilize for logging of long term debug messages. Hopefully it will help others. It is not as useful or elegant as the battery powered sd-card module @sundberg84 is looking at, but it works for my purposes.
I have a @ceech solar board with sensors for temp/hum (HTU21DF), barometer (BMP180), light sensor (BH1750), and a lightning sensor (AS3935). The board is great, all the code works fine. But on a random basis the node will freeze, sometimes in 8 hrs, sometimes 5 days, completely random it appears. So I needed to put debug statements in the code, and find a way to log the debug messages over a period of at least a week. The node wakes every 1 minute to check Baro for weather forecasting, and every 4 mins for all the sensors to report. Additionally, it wakes on interrupt from the lightning sensor. This board is destined to be set up outside powered by a small solar panel, and an 18650 battery. So this has to be solved before sealing it up and mounting in the yard somewhere.
I have a Raspberry PI 2 sitting around so I decided to use it to do the logging. It is connected via a USB port to an FTDI serial module, which in turn is connected to the solar board tx/rx pins. For software, I found a Python program called ‘grabserial’ (github.com/tbird20d/grabserial) which will take serial input from the USB port and write it to a log file.
The Pi is operating in a headless mode, connected via WiFi. So I can put the Pi and solar board anywhere out of the way as long as there is an outlet to power the Pi. I log in via SSH to the Pi.
Using ’grabserial’ requires running the program in background and also to keep it running after I log off the the pi. The command I use is:
nohup ~/grabserial -d /dev/ttyUSB0 -T -o ceechlog -Q &where:
nohup => allows the program to continue running (not hangup) when I log off the Pi.
-d => The device to listen on. To get which USB port, I ran ls /dev/tty* which lists all devices. Just look for your USB in the list.
-T => Puts a system time stamp on each line of logged data. Valuable!
-o => Tells grabserial the file to output the logging to. In this case I called it ceechlog.
-Q => Instructs grabserial to operate in quiet mode, i.e., don’t copy logging to the terminal.
& => Starts the program running in background.To confirm the program is running in background, I use ps -A, then look for ‘grabserial’, and its process id. To stop it, just use kill xxxxx, where x is the process id. (I am a linux amateur, I am sure there are cleaner commands, but works for me.)
For the debug statements, In each sketch function, I put Serial.print statements with a number. For example:
void sendTempHum(void)
{
Serial.print(" 9”); //HERE
float humidity = htu.readHumidity();
send(humidityMsg.set(humidity, 0));Serial.print(" 10"); //HERE
float temperatureHTU = htu.readTemperature();
send(temperatureMsg.set(temperatureHTU, 1));
Serial.println(" 11"); //HERE
}
}Note that the debug statements in an individual function will print on a single line in the output. The function example above will look like:
9 10 11 The last ‘serial.print in a function is actually a serial.println to get a carriage return. This makes reading the log easier. Don’t forget to a put a blank space before each number so as to separate the #’s on each line. Of course each different function being debugged gets different numbers in the serial.print statements.Every few days I log in and erase the ceechlog file as it can get quite large. This kills the ‘grabserial’ process, so I just start it up again with the command above. This is not necessary though. It is just housekeeping.
My sketch had 39 different serial.print() statements which track the progress of the program as it executes. After setting this up, my first ‘random’ freeze actually caught the exact line which caused the freeze. I had put serial.print statements on both sides of the offending line.
Hope this is helpful to others trying to find a difficult debug issue.
-
Good tip! thanks for sharing
