Logging functions in HelenOS

If you want to use some kind of logging - either for debugging purposes or to report errors - consider using the one provided in libc. The current implementation does not offer any spectacular features but shall be sufficient for most cases.

The logging messages are printed to screen (depending on kernel configuration) and are also written to files. To prevent flooding of the system with logging messages, the messages are assigned severity levels (see table below) and the user specifies how verbose the system shall be - i.e. to which detail are the messages actually printed. To allow more fine-grained tuning of what-to-print, the messages are directed to different logs that form a tree-like structure. It is possible to control reporting level (verbosity) of each log separately, giving user the ability to exactly specify which part of the system shall be monitored in the greatest detail.

For example, a (hypothetical) USB keyboard driver can offer a separate log for each keyboard that is plugged in. Thus, user trying to find out why his special button does not work can specify that all messages for the special keyboard shall be printed but also suppress any other messages - namely from the other keyboard that works and which is used to control the system.

Currently, following levels are recognised.

Name	Typical usage
LVL_FATAL	Fatal error, program is not able to recover at all.
LVL_ERROR	Serious error but the program can recover from it. E.g. driver cannot control one device but otherwise is healthy.
LVL_WARN	Easily recoverable problem, such as one corrupted packet that can be skipped.
LVL_NOTE	Message that does not indicate a problem, but should be printed at the default logging level.
LVL_DEBUG	Debugging-purpose message. Not printed at the default logging level. Increasing logging level to LVL_DEBUG should not swamp the log.
LVL_DEBUG2	More detailed debugging message.

By default, messages with level LVL_NOTE and above (i. e. warning and errors) are printed. To see the debugging messages, the user has to enable them: see below how to increase the verbosity level at boot-time and at run-time.

Going through existing logs

All logs are stored under the /log/ directory and file name corresponds to the server/application where the messages originated. To examine these files, one can use edit or cat.

The file contains the whole tree of the logs - each line is prefixed with severity level of the message and name of the log.

Example: running tester application with logger1 test shall create a /log/tester file with dummy messages. The test tries to print message at every severity level, what is actually stored into the file depends on current settings (see below for more examples).

Changing reported level at boot-time

The following currently works only for GRUB-based platforms.

To change the default reporting level, simply add its name (e. g. fatal or debug2) after the logger module load in the GRUB.

Example (making default reporting level less verbose): append the word warn to the logger module line once the GRUB menu appears (use e to enter the edit mode).

module /boot/logger /boot/logger warn

Then use F10 to boot HelenOS.

It is also possible to change reporting level of an individual log. Simply write the log name and append to it the desired level. This can be repeated for more logs.

Example (making tester very verbose): change the logger line to the following.

module /boot/logger /boot/logger tester=debug2

Both possibilities can be combined. For example, it is possible to set the default reporting level to errors only and only make several (problematic) drivers more verbose.

Changing reported level at run-time

It is also possible to change reported log level at run-time. For that the user shall use the logset utility. The utility is controlled purely via its command-line arguments - one of them is always the name of the level that is supposed to be set.

To change the default reporting level, simply run logset with the level name - following would make the system very quiet.

logset fatal

To change the reporting level of a certain log, run logset with the log name followed by the level name. For example, to make devman more verbose, run the following:

logset devman debug2

It is also possibly to target a nested log - simply separate individual names with a slash (like in a file name).

Example (tester logger2): To demonstrate how setting log levels at run-time works, you shall open at least three terminals. In one, start the tester with logger2 test. This test only prints messages at different levels to different logs.

In the second, you shall monitor the tester log - either by catting /log/tester or you can switch to kernel console (if you configure HelenOS without GUI, seventh console shall display that output).

And in the third console you can issue the logset to see what happens.

By default, you would see that tester continuously prints errors, warnings and notes into three logs: the default one (i. e. tester), alpha and bravo (tester/alpha and tester/alpha/bravo).

Running

logset tester/alpha fatal

would mute all the output to alpha and alpha/bravo logs. The reason why bravo was muted as well is because it is a child of alpha and has to respect its settings (unless explicitly overridden).

But it is possible to explicitly enable bravo output. If we ran

logset tester/alpha/bravo warn

the alpha is still muted but together with the original tester messages, bravo warnings are interleaved.

Using the C API

TODO log_msg, log_init

Behind the scene

TODO - how logger, logset and log_*() works

Obsoleted

Information below is obsoleted and will be rewritten soon.

To use logging functions, include io/log.h and initialize the logging

subsystem. After that, you can use the log_msg to do the logging.

...
#include <io/log.h>

#define NAME "myapp"
...

int main(int argc, char *argv[])
{
    log_init(NAME, LVL_NOTE);
    ...
    if (rc != EOK) {
        log_msg(LVL_ERROR, "Something failed (rc=%d), trying fallback...", rc);
        ...
    }
}

The first argument to log_init is application name, the second is the default logging level. Messages with higher level won't be printed at all.

Normally the (when an application is not being debugged) the logging level should be set to LVL_NOTE. That is, messages with level LVL_NOTE or higher are printed.

log_msg is a printf-like function where first argument is level of the message (its seriousness).