NanoLog is great where there is a critical need for high-performance logging. It shifts the work from runtime to compile-time and post-execution phases and a throughput of up to 80 million log messages per second with the log invocation overhead of just 8 nanoseconds.
NanoLog serializes log messages into a compact binary format at the time of logging and deferring the emission of logs to a separate thread, all while maintaining a lock-free operation and reducing the I/O bandwidth requirements. Three things that I found most interesting are:
compile-time optimization and specialized code generation for each log statement
lock-free, cache-optimized circular buffers
custom lightweight encoding and compression scheme
Three interesting things
Continuing the discussion from the above TL;DR, here are three things that I found interesting in this paper and some quick details about each.
Compile-time optimization and code generation
One of the most fascinating aspects of NanoLog is its use of a preprocessor to perform compile-time optimizations. This approach shifts a significant portion of the work traditionally done at runtime to the compilation phase. The preprocessor analyzes each NANO_LOG() statement and generates two specialized functions:
record()
captures only the dynamic data for each log message,
compact()
optimized for efficient compression of that specific log entry.
The preprocessor extracts type information from the format string (e.g., “%d%f” indicating an integer followed by a float) and generates type-specific code for handling each argument. This eliminates the need for runtime parsing and type inference, which are typically expensive operations in logging systems. Thus we get extremely fast logging with the ease of use of a printf-like API.
Lock-free, cache-optimized staging buffers
NanoLog’s use of lock-free logging, with circular buffers, to avoid locks, contention, and cache coherency issues in multi-threaded environments. This buffer is per logging thread, implemented as a single-producer, single-consumer circular queue. Each log message is serialized and atomically placed into the next available slot in the circular buffer.
The circular buffer, being a fixed-size FIFO queue, provides predictable memory usage and minimizes cache misses, which is critical for maintaining high throughput. NanoLog also does micro-optimizations by arranging data to avoid false sharing by placing the private variables for the logging and background threads on separate cache lines.
Lightweight encoding
Instead of formatting log messages into human-readable strings at runtime, which is computationally expensive, NanoLog serializes the parameters into a compact binary format. It performs binary serialization directly at the point of logging and the log message is not converted into a string; instead, the data is serialized into the binary format which is much faster to generate and easier to store.
Instead of using standard compression algorithms like LZ77, which proved too computationally expensive for real-time logging, NanoLog uses a lightweight compression scheme specifically for integer types. This decision is based on the observation that most logged integers are relatively small and don’t use all the bits of their type.
The compression encodes integers using the minimum number of bytes necessary, with a 4-bit nibble of metadata to indicate the number of bytes used and whether the number is negative. This provides a good balance between compression ratio and computational cost, which is crucial for a high-performance logging system. The scheme can represent small integers (positive or negative) in as little as 1.5 bytes, including the metadata.
Notes and a quick explanation
Logging is fundamental and traditional logging systems have a significant overhead, and this might not be acceptable in latency-sensitive applications. NanoLog operates at nanosecond granularity. NanoLog is built on a three-component system - Preprocessor/Combiner, Runtime Library, and Decompressor. The core idea is to shift work out of the runtime hot path, distributing it across compilation and post-execution phases.
Performance Bottlenecks in Traditional Logging
Traditional logging frameworks are implemented using printf or syslog and the overheads happen because of the following reasons
formatting log messages into human-readable strings
flushing and writing log messages to disk or over the network
to ensure thread safety, traditional logging systems often employ locks, leading to contention
Architecture Overview
NanoLog essentially breaks down the logging into the following steps - capturing log messages, serializing them into a binary format, storing them in a circular buffer, and asynchronously emitting them (via emission thread), decompressing and writing them to the final output destination. This allows the main application to proceed without waiting for log emission.
In NanoLog, this log message is serialized into a binary format, with the timestamp, symbol, and price stored as binary values. The serialization process might take just a few nanoseconds, compared to microseconds or milliseconds for traditional logging.
Preprocessor: Static Analysis and Code Generation
The preprocessor is where NanoLog innovates and takes care of several crucial tasks, like
analyzing NANO_LOG()
statements and extracting static information at compile-time
inferring argument types by parsing format strings (e.g., “%d %f”)
generating type-specific processing code
replacing original logging statements with optimized code (for each log)
Each log statement is also associated with a unique identifier at compile time. This identifier, along with the values of the variables associated with the log statement, is encoded into a compact binary format. Static information for each log statement is cataloged in a dictionary entry, including file name, line number, severity level, and format string.
Thus NanoLog does not need to interpret the log message format at runtime. The compile-time knowledge allows Nanolog to encode log messages extremely efficiently, as it avoids the runtime overhead associated with string formatting. For each NANO_LOG() statement, two critical functions are generated
record()
: captures dynamic data in memory buffers.
compact()
: compresses recorded data for efficient I/O.
Runtime Efficiency
NanoLog achieves runtime efficiency through the use of lock-free implementation of circular buffers (queues). During logging, the encoded log messages are atomically appended to the buffer. By using a circular buffer, Nanolog
avoids the need for expensive memory allocations and deallocations
ensures that memory is reused efficiently, avoiding cache misses and reducing latency.
NanoLog also employs some interesting micro-optimizations, some of which are
each logging thread has its buffer, eliminating synchronization (shared-nothing
)
2. each buffer is a single-producer, single-consumer circular queue, eradicating locks
3. private variables for logging and background threads are stored on separate cache lines.
Aligning variables on different cache lines minimizes false sharing and cache thrashing. This can be demonstrated with this quick example
Plain text
The use of __attribute__((aligned(CACHE_LINE_SIZE))) attribute (called alignment modifier) ensures each structure starts at the beginning of a cache line minimizing false sharing and cache thrashing.
Plain text
Serialization and Encoding
NanoLog serializes log parameters into a compact binary representation. This approach has several advantages:
faster than string formatting, reducing the time spent in the logging path
more compact than text, reducing the memory footprint of the log buffer
By specifying log formats statically at compile time, NanoLog ensures that the correct types are used in log messages, preventing type-related bugs. Some nuances around this efficient binary log format:
maps Intel Time Stamp Counter (TSC) to wall time, avoiding runtime wall time conversion
each message is variable-sized and is designed to take up the bare minimum space
non-string parameters are compacted (small ints take up fewer bytes than larger ones)
strings are null-terminated to avoid explicit length storage
Background logging thread
Once the log messages are encoded and stored in the in-memory circular buffer, NanoLog uses a background thread to process the serialized log messages and persist them to a durable storage medium. This ensures that the critical path of execution is not blocked by I/O operations. This decouples the logging from I/O, reducing the impact of logging on the application’s performance. The thread is optimized for rapid log processing and it
defers the formatting and sorting to post-execution, reducing runtime overhead
processes buffer contents while logging threads continue to record new messages
Decompressor and Chronological Ordering
Decompressor now combines compacted data with dictionary information to produce readable logs. It restores the chronological order of the log messages by processing roughly time-ordered buffer entries.
Performance Optimizations
Traditional logging frameworks often rely on mutexes to synchronize access to shared resources, such as the log buffer. However, mutexes introduce significant latency due to contention and context switching. Nanolog uses a lock-free circular buffer for managing the in-memory log message buffer.
NanoLog also minimizes memory allocations during the logging process by pre-allocating memory for the circular buffer and reusing this memory for subsequent log messages. This avoids the performance penalties associated with dynamic memory allocation.
NanoLog’s design allows it to scale effectively across multiple cores, making it ideal for modern multicore processors.
The content presented here is a collection of my notes and
explanations based on the paper. You can access the full
paper Paper Notes - NanoLog - A Nanosecond Scale Logging System
. This is by no means an exhaustive explanation, and I
strongly encourage you to read the actual paper for a
comprehensive understanding. Any images you see are either
taken directly from the paper or illustrated by me
.
