May 2020 to August 2020
During the execution, CRIU writes many logs. Most of these logs are not used, but if some operations fail, they are the only way to figure out the reason for this failure.
Currently, CRIU's logging is done using fprintf statements. The printf family of functions takes significant amount of time to execute. They scan the format string for the format specifiers are then typecast all the arguments to string. It is observed that running criu with and without logging causes a considerable time difference.
Since printf family functions spend the majority of the time during logging in parsing the format string for format specifiers, and also these log files are left unused majority of the time, we dump this string and all the arguments associated with this string into the file as it is.
If later this file needs to be read, we process it through the decoder. The decoder passes these statements through the printf family functions later, reducing criu's runtime.
As the outcome of this project, CRIU now has two separate printers, which it uses to log. When the binary logging is not enabled, CRIU uses the regular printer to log in standard text, but when binary logging is enabled, CRIU uses the flog printer to store the logs in binary.
The flog printer takes input as the format string and all the arguments following it. It finds the type of each argument and stores it. All these are stored in a buffer. When the buffer is full, the logs are dumped into a file.
The decoder traverses through the file. It selects the format string and its arguments from the binary file and passes it through a printf family function. The logs can then be observed in the output file provided.
Adding a -b or --binary-log at the end of a criu command allows it to use the binary printer and log in binary.
These are the changes that should be made to dump a trivial program given here.
criu dump -t 2221 -vvv -o dump.log -b && echo OK
criu restore -d -vvv -o restore.log -b && echo OK
The decoder is placed in the crit folder. It requires two file names as input, one which needs to be proccessed and on where the decoded information is stored.
crit/decoder dump.log decoded_dump.log && echo OK
Commit Number | Commit Name | Status |
---|---|---|
Commit 1/10 | Add flog to criu | Merged |
Commit 2/10 | flog: transfer files from separate subtree to criu/criu | Pushed |
Commit 3/10 | Add option to convert logs to binary | Pushed |
Commit 4/10 | flog: add option to fallback to default textual logging | Pushed |
Commit 5/10 | flog: remove commented code and unused function headers | Pushed |
Commit 6/10 | flog: bypass incompatible architectures | Pushed |
Commit 7/10 | Implement flog in criu | Pushed |
Commit 8/10 | Add decoding facility to crit | Pushed |
Commit 9/10 | zdtm.py: use flog printer to log | Pushed |
Commit 10/10 | Document the usage of binary logger | Pushed |
If used with the decoder, the overall time taken by the flog printer would be equivalent to the time taken by the regular printer. Since most of the logs are expected not to be used, the decoder will not be used on these logs. This is where the maximum performance improvement is observed.
Integrate flog into criu and add it into the criu makefile.
Use the flog’s flog_encoder() to generate binary logs into a file.
Provide external option to log in binary.
Build the decoder to convert the binary log files to text files.
Use decoder in criu wherever the log files are being read.
Document the work done.
- Fix: _Generic function usage so it is compatible with all versions of GCC.
- Fix: The decoder to be compatible with amd architectures.
- Add time stamp and PID to logs.
I am incredibly thankful to my mentor Pavel Emelyanov for guiding me through this project and clarifying all my queries. I would also like to thank the community for everything. I got introduced into open-source with this community, and I could not have chosen a more accommodating community for this learning journey. I am eager to continue working with CRIU.