Field extraction per log template instead of per event

A log platform works out a line's fields event by event, with a regex per format kept current as the code changes. On its own, a number in a line could be an HTTP status or a value from a config dump. 10x does that work once per template, the line shape with its changing parts blanked out, and every matching event inherits the result. That is the bet V8 makes about JavaScript objects, applied to log lines.

An HTTP template finds the status-code slot on first sight, guarded by an HTTP marker within ±5 tokens. A kafka max.request.size = 200 binds nothing. Templates also pick their own names, each one a run of tokens the engine traces to one source file, which is the format string that printed the line. Splunk, Datadog, and Elasticsearch grok repeat the work per event.

Kubernetes control-plane logs carry lines like E1023 14:30:45.123456 controller.go:123 connection refused. That E is the severity, though there is no word ERROR in the line. klog glues severity to the front of the timestamp as a single character.

Grep every event for ERROR and none of the lines match. The error-rate dashboard reads zero while the controller fails.

Most of what an event says is carried by the shape it came from rather than by the values it happens to hold. A 3-digit number could be an HTTP status code, or it could be max.request.size = 200 in a kafka config dump. Telling one from the other takes the template the line matched, which is where the extraction gets attached.

JavaScript engines already solved a structurally identical problem. Object shape isn't declared in source, so they can't optimize access object by object. V8 records each object's shape as a hidden class (PyPy and CPython 3.11 do the same thing). The V8 docs call this bet intelligent design, on the grounds that there is a mind behind the incoming code, so only a finite set of shapes will ever show up.

On first sight of that class it finds where a property is stored and caches the offset at the access site, which every instance then inherits.

What a template is

We apply the same architecture to log events. A template is the log line with its changing parts blanked out. E$TIME controller.go:$N connection refused is one template, and every line of that shape matches it.

Fixed words that survive are the template's structural tokens, and each blanked position is a slot.

Reading the E/W/I/F prefix once, the klog template tags itself ERROR, and every matching line inherits that severity.

HTTP codes are where the slot has to be found before it can be read. Take a template whose structural tokens include status, GET, HTTP/, Completed. On first sight of the shape, it works out which slot holds the status code, guarded by a rule that an HTTP marker sits within ±5 tokens of the candidate, which leaves every event after that a slot read and a range check.

Word matching alone would let the kafka template through, since request is in the shipped HTTP keyword list and the template text max.request.size = $VAR contains it. What refuses the binding, though, is the adjacency rule. Strict markers (status, HTTP/, code, Completed, the method verbs) leave request out, and none of them sits within ±5 tokens of the candidate, so the template binds no slot and its size = 200 stays an ordinary value. A second guard runs at event time, writing http_code only when the value at a bound slot falls between 100 and 599.

That narrowness costs coverage. The strict marker list is deliberately shorter than the general keyword list, so a template whose only HTTP marker is a loose term such as request, path or url binds no slot. request sits in the general list and outside the strict one, which is what refuses the kafka template, and an HTTP template worded the same way is refused alongside it. Widening the ±5 window recovers none of those, since the missing piece is the marker rather than the distance.

The hidden-class mapping runs all the way through. Severity, the status-code slot, the datetime format, and the pattern are class fields, worked out once per template. Values sitting in the slots are instance fields, read per event, the way V8 caches a property's offset on the class and reads the value off each object.

One part of the analogy does not hold. V8 has to infer its classes from the objects alone, since objects are all it ever sees, but a template is matched against a vocabulary compiled from the code that prints the lines, so its classes are grounded in source, rather than in whatever traffic arrived first.

How a template is named

Beyond fields, a template inherits its name. 10x names every template with a message pattern, the few tokens that state what the line says with everything variable stripped away. Raw material comes from the symbol library, the vocabulary a compiler collects ahead of time from source and binary repos. For each known token the library records its file of origin and its role in that file: a log call's string literal, a class name, a string inside an executable.

The pattern is a run of consecutive template tokens that trace to the same file, chosen by coverage, so where several source origins could claim the same tokens, the engine ranks the candidates by how well each one pins the line to a single origin and selects deterministically. Rare symbols narrow the candidates more than ubiquitous ones, which is why the ranking is by coverage rather than by length, as in this Spark executor line:

17/06/09 20:10:42 INFO executor.CoarseGrainedExecutorBackend: Connecting to driver: spark://CoarseGrainedScheduler@10.10.34.11:48069

The winning run is Connecting to driver, and the file is CoarseGrainedExecutorBackend.scala. That run is the format string the developer wrote. Source is optional. A syslog line from sshd gets the pattern authentication failure, with the sshd binary itself as the origin, scanned as an executable.

Selection runs once per template, with every matching event inheriting the name. A dashboard grouped by message pattern is grouped by the code that printed the lines. Timestamps get the same treatment, with the engine working out a template's datetime format once and applying it to every instance, rather than re-detecting it per event.

The standard stack does all of this per event, when it should be done once per shape. Splunk sourcetype extractions, Datadog log pipelines and Elasticsearch grok rules each want a regex per format outside the prebuilt integrations, kept current as the code changes. Underneath, they have no stable address to pin the answer to. A grouping that drifts between queries forces the work back onto the raw value, which can't separate the kafka 200 from an HTTP 200.

The open question I find more interesting is how much per-event work should move to the shape. Cost attribution already has a per-shape answer, billing by template instead of by line, and retention has one too, since the decision whether a shape is worth keeping can be made once.

Runtime classifier modules are open source at github.com/log-10x/modules/tree/main/pipelines/run/modules/initialize. The HTTP config and its strict-marker adjacency check are at pipelines/run/initialize/httpCode/config.yaml, and the name selection is message-template.js.

Related: how a line gets assigned to a stable template and where the structural vocabulary comes from. A future post covers how templates also shrink the Bloom filters that route queries across events offloaded to S3.