Logging
Overview
When run CRIU can generate a lot of messages. By default CRIU only prints only critical messages on the screen, but using only these messages can make debugging impossible. On the other hand, increasing the verbosity can easily flood the output.
Verbosity
There are 4 types of messages CRIU can print
- Errors
- These show that something goes really wrong. If an error message appears on the screen CRIU doesn't complete the operation and exits with an error. At the same time, if CRIU's exit code is not 0, there should be an error message. Typically there are several of them, but only the first one denotes the real obstacle CRIU has hit, all subsequent ones can be due to this first.
- Warnings
- These are printed if something goes not the way CRIU expects, but still there's a way to handle the situation. Sometimes warnings show that the kernel functionality might not be enough to perform the requested operation, but whether or not it will be really required will be found out later.
- Info-s
- These are just messages with which CRIU shows what it's doing and why.
- Debug
- Debug messages show some technical details about CRIU workflow.
Log message
Messages have specific format.
- Timestamps
- Some lines start with numbers in brackets (like this
(12.345678)) which denote the time in msec-s passed since CRIU start
- PIE
- Code blobs have troubles generating sane logs and precede lines with the
pie:prefix
- PID-s
- Log lines generated by non-CRIU processes (during restore) show their pids right after timestamp and/or PIE prefix in the
PID:format.
Below are examples of all these types of messages
(00.000116) Version: 2.6 (gitid v2.6-205-ga66ed95) # CRIU message (00.004837) 39: Restoring 39 to 39 sid # Message from process 39 pie: 39: Switched to the restorer 39 # Message from PIE-context of process 39
Controlling the verbosity
The messages to be printed by CRIU are controlled by -v option. There are two ways of using it.
The first is to specify as many -v's as high level you want. One -v means there will be only errors printed, 4 -v's (-vvvv or -v -v -v -v) will make CRIU print everything.
The second option is to specify the log level with the number, e.g. -v3 will make CRIU print errors, warnings and info-s, but not debugs (which are of log level 4).
Telling -v0 will shut CRIU up, but that's really not recommended.
Early logging
During CRIU initialization some things can fail, i.e., reading the kerndat file. Those failures may happen before the logging is set up (log file descriptors open etc.). The failures might even happen while setting up the logging. For all those nuisances, there is a static buffer that stores everything until logging has successfully initialized. The buffer has compile-time size of EARLY_LOG_BUF_LEN and serves only on early CRIU initialization. Afterwards, it always flushes: if the logging was set up successfully, to the corresponding logs; to stderr in case CRIU caught early fault and is about to exit.
Log files
If requesting high log level you can get tons of logs on the screen. It's usually unwanted and hard to save (for further analyzes), so it's possible to ask CRIU write the logs into a log file. This is done by --log-file option. The log file will be created and truncated in the working directory, all messages will appear in it.
Per-pid logs
During restore, log entries are emitted for each process being restored. To make logs analysis easier, one can make CRIU generate separate per-process log files by using --log-pid option.