Implementation:Vespa engine Vespa VespaFormatter Format

VespaFormatter.format

Logging Observability

API Signature

public String format(LogRecord r)

Source Location

• File: vespalog/src/main/java/com/yahoo/log/VespaFormatter.java
• Lines: L94-135
• Class: class VespaFormatter extends SimpleFormatter
• Package: com.yahoo.log

Description

The format method converts a JUL LogRecord into Vespa's tab-delimited log line format. It produces a single line containing the timestamp, hostname, process/thread IDs, service name, component path, log level, and escaped message. This method is called by the VespaLogHandler for every log record that passes level control and reject filtering.

Key Fields

Field	Type	Purpose
hostname	String	The hostname of the machine, resolved once at formatter construction time
processID	String	The process ID (PID) of the current JVM, resolved once at construction time
serviceName	String	The Vespa service name (e.g., "searchnode") from VESPA_SERVICE_NAME
componentPrefix	String	The application prefix (e.g., "container") prepended to the logger name in the component field

Parameters

Parameter	Type	Description
r	LogRecord	The JUL log record to format. Contains the log level, logger name, message, thread ID, timestamp, optional thrown exception, and optional parameters.

Return Value

String -- A single tab-delimited log line ending with \n. The format is:

<time>\t<hostname>\t<pid/tid>\t<service>\t<component>\t<level>\t<message>\n

Full Method Source

public String format(LogRecord r) {
    StringBuilder sbuf = new StringBuilder(300);

    String levelName = LogLevel.getVespaLogLevel(r.getLevel())
                               .toString().toLowerCase();

    String component = r.getLoggerName();

    sbuf.append(VespaFormat.formatTime(r.getInstant()));
    sbuf.append("\t");
    sbuf.append(hostname).append("\t")
        .append(processID).append("/")
        .append(r.getThreadID()).append("\t")
        .append(serviceName).append("\t");

    if (component == null && componentPrefix == null) {
        sbuf.append("-");
    } else if (component == null) {
        sbuf.append(componentPrefix);
    } else if (componentPrefix == null) {
        sbuf.append(".").append(component);
    } else {
        sbuf.append(componentPrefix).append(".").append(component);
    }

    sbuf.append("\t").append(levelName).append("\t");

    if (r.getLevel() == LogLevel.EVENT) {
        Event event = (Event) r.getParameters()[0];
        sbuf.append(VespaFormat.escape(event.toString()));
    } else {
        sbuf.append(VespaFormat.escape(formatMessage(r)));
    }

    appendException(r.getThrown(), sbuf);
    sbuf.append("\n");

    return sbuf.toString();
}

Field-by-Field Breakdown

1. Timestamp

sbuf.append(VespaFormat.formatTime(r.getInstant()));

Formats the log record's Instant as seconds.microseconds in Unix epoch format (e.g., 1696000000.123456). The VespaFormat.formatTime() utility method handles the conversion.

2. Hostname

sbuf.append(hostname);

The hostname is resolved once at formatter construction time and stored as a field. It does not change during the lifetime of the process.

3. PID/TID

sbuf.append(processID).append("/").append(r.getThreadID());

The process ID is resolved once at construction. The thread ID is extracted from the LogRecord and changes per log call. The format is pid/tid (e.g., 12345/67).

4. Service Name

sbuf.append(serviceName);

The service name is set during formatter construction from the VESPA_SERVICE_NAME value (e.g., "searchnode", "configserver").

5. Component

if (component == null && componentPrefix == null) {
    sbuf.append("-");
} else if (component == null) {
    sbuf.append(componentPrefix);
} else if (componentPrefix == null) {
    sbuf.append(".").append(component);
} else {
    sbuf.append(componentPrefix).append(".").append(component);
}

The component field is built from the application prefix and the JUL logger name:

componentPrefix	component (logger name)	Output
null	null	-
"container"	null	container
null	"com.yahoo.search"	.com.yahoo.search
"container"	"com.yahoo.search"	container.com.yahoo.search

6. Level

String levelName = LogLevel.getVespaLogLevel(r.getLevel())
                           .toString().toLowerCase();
sbuf.append(levelName);

The JUL level is mapped to Vespa's level names via LogLevel.getVespaLogLevel() and converted to lowercase (e.g., "info", "warning", "error").

7. Message

if (r.getLevel() == LogLevel.EVENT) {
    Event event = (Event) r.getParameters()[0];
    sbuf.append(VespaFormat.escape(event.toString()));
} else {
    sbuf.append(VespaFormat.escape(formatMessage(r)));
}

Two code paths exist:

• EVENT level: The first parameter of the log record is cast to an Event object and serialized via its toString() method. Events represent structured occurrences (service start/stop, state changes).
• All other levels: The standard JUL formatMessage(r) is used, which handles message format substitution if parameters are present.

In both cases, the output is passed through VespaFormat.escape() to escape tabs, newlines, and backslashes.

8. Exception (Optional)

appendException(r.getThrown(), sbuf);

If the log record has a thrown exception, the full stack trace is appended to the message. Stack trace newlines are escaped so the entire record remains on a single line.

9. Newline

sbuf.append("\n");

The log line is terminated with a single newline character.

Example Output

1696000000.123456	node-01.example.com	12345/67	searchnode	container.com.yahoo.search.handler	info	Query completed in 42ms

Performance Notes

• The StringBuilder is initialized with a capacity of 300 characters, which is a reasonable estimate for most log lines and avoids reallocation in the common case.
• The hostname and process ID are resolved once and cached, avoiding per-record system calls.
• The VespaFormat.escape() method only allocates a new string if the input contains characters that need escaping.

Implements Principle

Log Message Formatting

Related Implementations

• VespaLogHandler.publish -- Calls this format method for each log record that passes filtering
• VespaLogHandler Constructor -- Creates the formatter during handler initialization

Related Pages

• Principle:Vespa_engine_Vespa_Log_Message_Formatting