Principle:Vespa engine Vespa Runtime Level Control
Runtime Level Control
Overview
Runtime level control enables changing log verbosity of running Vespa processes without restart. It uses memory-mapped files as a shared-memory IPC mechanism between the vespa-logctl CLI tool and running processes. The control file maps component names to level bitmasks, which processes check on every log call to determine whether to emit the message.
Motivation
Diagnosing production issues in a distributed system often requires increasing log verbosity for specific components. However, restarting a process to change log configuration has significant drawbacks:
- Disruption: Restarting a search node or distributor interrupts query serving and data processing.
- State loss: The issue being investigated may not reproduce after restart.
- Delay: Restart time (including warmup) can be minutes, during which the issue may resolve on its own.
- Scope: Operators often want to enable verbose logging for a single component, not the entire process.
Runtime level control solves all of these problems by allowing an operator to modify log levels on a running process through a simple CLI command. The change takes effect immediately on the next log call.
Architecture
The runtime level control system consists of three components:
The control file is a memory-mapped binary file (typically stored at /var/log/vespa/logcontrol/<service>.logcontrol) that contains:
- A versioned header (
"Vespa log control file version 1\n") - An application prefix (up to 64 bytes)
- A table of component entries, each containing:
- A null-terminated component name string
- A level bitmask (8 bytes, one per level)
2. vespa-logctl CLI Tool
The vespa-logctl command-line tool opens the control file, locates (or creates) the entry for the specified component, and modifies the level bitmask. Because the file is memory-mapped by the target process, the change is visible immediately without any signal or notification mechanism.
3. Process-Side Level Checking
On the process side, the LevelController.shouldLog(Level) method reads the level byte from the memory-mapped region. This is a simple memory read operation with no system call overhead, no lock contention, and no I/O blocking.
How Level Checking Works
When a JUL logger method is called (e.g., logger.info("message")), the log record flows through the VespaLogHandler.publish() method, which performs:
LevelController ctrl = getLevelControl(loggerName);
if (!ctrl.shouldLog(level)) { return; }
The shouldLog() call reads a single byte from the memory-mapped buffer at the offset corresponding to the component's level entry. If the byte is non-zero, the level is enabled; if zero, the log record is silently dropped.
This design means:
- Enabled levels: The overhead is a single memory read (nanoseconds).
- Disabled levels: The overhead is the same single memory read, plus an early return. No string formatting, no I/O.
- No synchronization: The single-byte read is atomic on all supported architectures.
Level Modification Syntax
The vespa-logctl tool uses the following syntax for level modifications:
vespa-logctl <service>[:component] <level-mods>
Level modifications are comma-separated assignments:
all=on # Enable all levels
all=off # Disable all levels
debug=on,spam=on # Enable debug and spam
all=on,debug=off,spam=off # Enable all except debug and spam
Examples
# Enable debug for all components of the searchnode service
vespa-logctl searchnode debug=on
# Enable debug only for the query handler component
vespa-logctl searchnode:com.yahoo.search.handler debug=on
# Reset all levels to default for configserver
vespa-logctl -r configserver
# List current level settings for all components
vespa-logctl searchnode
Control File Management
File Creation
The control file is created by the first process that starts with a given service name. If the file already exists (from a previous run), it is opened and reused. Existing component entries retain their level settings, which means that level changes made by vespa-logctl persist across process restarts.
Component Registration
When a process encounters a new logger name (component) for the first time, it registers it in the control file by:
- Checking if an entry for the component already exists (e.g., from a previous run or a
vespa-logctl -npre-registration). - If not, appending a new entry with the component name and the default level bitmask.
File Growth
The control file grows as new components are registered. Entries are never removed during the lifetime of the file. In practice, the number of unique logger names in a Vespa process is bounded (typically hundreds, not thousands), so file size is not a concern.
C++ Control File Implementation
The C++ implementation (ControlFile class) provides the same functionality for C++ processes:
class ControlFile {
public:
enum Mode { READONLY, READWRITE, CREATE };
ControlFile(const char *filename, Mode mode);
unsigned int *getLevels(const char *name);
char *getComponentName(unsigned int offset);
void ensureComponent(const char *pattern);
void flush();
ComponentIterator begin();
ComponentIterator end();
};
The C++ class uses mmap() directly (rather than Java's MappedByteBuffer) but operates on the same file format. This means:
- A Java process and a C++ process with the same service name share the same control file.
- The
vespa-logctltool (which is a C++ program) can control both Java and C++ processes.
The ComponentIterator
The ComponentIterator allows enumeration of all registered components in a control file:
for (auto it = controlFile.begin(); it != controlFile.end(); ++it) {
const char *name = it->name();
unsigned int *levels = it->levels();
// Display or modify levels
}
This is used by vespa-logctl to display the current level settings when invoked without level modification arguments.
Design Constraints
- No notification mechanism: Level changes are detected by polling (reading the memory-mapped byte). There is no signal, callback, or event to notify the process. This is acceptable because the check happens on every log call anyway.
- Atomic single-byte writes: The level bitmask uses one byte per level. Single-byte writes are atomic on all supported architectures, so no locking is needed.
- Stale component entries: Old entries from previous runs or removed components remain in the file. They consume space but are otherwise harmless.
- File format versioning: The header includes a version string. Incompatible format changes would require a new version number, but the format has been stable since inception.
Interaction with Other Components
- Control File Initialization: Creates and memory-maps the control file at process startup.
- Log Rotation and Special Handling: The
publish()method callsshouldLog()on every record, using the runtime level control. - Log Target and Level Configuration: Provides the default level string used to initialize new component entries.