Google Summer of Code 2020

Optimize Logging Engine

May 2020 to August 2020

Name: Prakriti Goyal

Organization: CRIU

Mentor:

Official Documentation:

The Issue

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.

The Solution

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.

The Usage

To make criu log in binary:

Adding a -b or --binary-log at the end of a criu command allows it to use the binary printer and log in binary.

For a simple loop

These are the changes that should be made to dump a trivial program given here.

Dumping the process:

   criu dump -t 2221 -vvv -o dump.log -b && echo OK

Restoring the process:

   criu restore -d -vvv -o restore.log -b && echo OK

To use the decoder:

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

List of Commits

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

Performance Impact

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.

Proposed Objectives and Status

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.

Pending Work and Improvments

-  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.

Acknowledgements

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.