Logging Howto and Best Practices
Logging Functions
The logging macros are defined in the project libebee_common in the file log/log.h .
macros:
| Logging Macro | Description |
|---|---|
| LOG_<log severity>_FN | log formatted message with the severity, source file name, line in code, function name |
| LOG_<log severity> | log formatted message with the severity, source file name, line in code |
| LOG_FN_BEGIN | can be used at the beginning of a function, just logs out “<function name()>” in TRACE level |
| LOG_FN_EXIT | can be used at the end of a function, just logs “leaving <function name>()” in TRACE level |
User Logs
When creating a diagnostics package there is included a user log file home/charge/user.logs . It is a subset of the regular log file and contains all relevant information for the user.
There are special log macros for generating user log entries
| Log Macro | Description |
|---|---|
| USER_INFO | used for logging relevat information, e.g. start of charging, CP line state changes, … |
| USER_WARN | used for warnings where the controller can react properly, e.g. disconnect from backend, disconnect from DLM slave, failed firmware update |
| USER_ERR | used when the controller cannot react properly on failures, e.g. contactor cannot be opened, ADC is not responding |
| USER_INFO_FN | same as USER_INFO, logs the the function name additionally |
| USER_WARN_FN | same as USER_WARN, logs the the function name additionally |
| USER_ERR_FN | same as USER_ERR, logs the the function name additionally |
Default Logging Level
The default logging level in DEBUG.
Logging Level Description
| Log Level | Description |
|---|---|
| ERR | identifies error events that may still let the software run, but with restricted capabilities in the impacted routes |
| WARN | raise a “red sign”, less important than errors, should be used when e.g. expected results take longer than expected, file sizes are near their limit, and so on, only use them if the software can handle these events properly without reduction of the functionality |
| DBG | default log level, should contain all the information which help to understand relevant state changes or state details, e.g. charging duration, meter values |
| VDBG | used when want to log additional information which can also be developer related, e.g. message queue length, length of data packets |
| TRACE | can be used as logpoint when it is relevant to find out whether the function was called, can contain information only developer related |
Best Practices
- In case of malfunctions the logs should help to understand the situation which lead to the issue. So “unknown error” or “exception at …” will not help.
- In the logs should be all relevant information which help to understand relevant state changes, e.g. a cable was attached –> show the PP value
- Repeated logs should be avoided when they do not help to understand the issue. If there are repeated logs expected they should be suppressed for a specific period, then logged again (one log entry) and then suppressed again.
- The log message should contain all the relevant information in a human readable format. E.g. Enumeration values as integer will not help, there should also be the corresponding name of the enum value.
- Use English Language, i18n is not needed
- Use only ASCII, otherwise messages could be unreadable
- The log in the default log level (DEBUG) should last a week due to delayed diagnostic file pulling.
- Don’t log sensitive information: no passwords, customers' individual data, …
- Don’t log for troubleshooting purposes only: Relevant state changes, user interactions, monitoring is also important.
Setting the log level system wide
You can select a log level via the web interface or by modifying the file '/home/charge/persistency/LogLevel_custom' directly.
Additionally can change the log level at run-time. For this there's a FIFO '/home/charge/ebee_log_level'. Simply writing (echoing) a log level into it with e.g.:
charge@~$ echo TRACE > ebee_log_level
will change the log level to TRACE level. Just keep in mind that this is only a temporary change until next reboot, it won't modify the persistency file for the log level.
Setting the log level module wide
You can also change the log level of individual components. If you want to switch e.g. only the log level for the RFID subsystem to TRACE, but leave all others at their current level, you can do e.g.:
charge@~$ echo "RFID=TRACE" > ebee_log_level
Instead of the name of the subsystem you can also its number. If you look into the log file and search for a line coming from the RFID subsystem, you may find a line like an
Jan 1 00:48:25 cp cp_app[1713]: <15> auth_rfid.c:923 [01e8d000] (*D) - auth_rfid_init(): init
The number of the subsystem is the number enclosed in '<>'. So the number for the RFID subsystem is 15 and you can thus change its log level using:
charge@~$ echo "15=VDBG" > ebee_log_level
And you can also set several components in the same command, just separate them by a ';', i.e.
charge@~$ echo "RFID=VDBG; SOCKETTYPE2=ERR" > ebee_log_level
michael-kornfeld
Discussion
A pitfall might be the 15118 subsystem. The module name is recognized as a number, so writing short
won't work.
In this case the shortest way is to use the number <22> of the module: