Never use python print() statements, use logging in batches…
If we know, print() statements are expensive statements to execute. They require calls to kernel code which in turn write to IOStreams which can be either a file or Screen (stdio) or network. A kernel call involves a context switch as the CPU gets ready to execute code from the kernel space aka OS code.
If we have coded in C, we must have opened a file handler and used fseek() operation. print() statement is similar to that but it uses stdout as the output stream to write to.
In our software projects, if we consume a Kafka payload or serve a network request, we usually log heavily mostly for debugging proposes. Sometimes, it can be hundreds or even thousands of lines.
Imagine making a system kernel call for each of the print() statement. It can take away hundreds of milliseconds (~100ms) of your latency.
Can we solve this? Is there a way to collect all the print statements and log only at the end of execution?
Fortunately, yes. In python, logging library itself provides a handler to hold all the logs and flush them to stdout or any other streamhandler that we want to use. Its called MemoryHandler.
It can collect some specified number of logs and triggers a flush() to clear its buffer which sends logs to the target handler. Target handler can be any another handler like file/NetworkIO etc.
Usually, Its better to trigger a flush() whenever we have completed the processing of the network request or consumed the Kafka payload. So, we can trigger flush in hooks().
An example logging configuration is below:
References:
- https://stackoverflow.com/questions/13288185/performance-effect-of-using-print-statements-in-python-script
- https://docs.python.org/3/library/logging.config.html
- https://docs.python.org/3/library/logging.handlers.html
- https://opentelemetry-python.readthedocs.io/en/latest/sdk/trace.export.html
- https://opentelemetry-python.readthedocs.io/en/latest/exporter/jaeger/jaeger.html
