Access Logging

The Vespa access log format allows the logs to be processed by a number of available tools handling JSON based (log) files. With the ability to add custom key/value pairs to the log from any Searcher, you can easily track the decisions done by container components for given requests.

Vespa Access Log Format

In the Vespa access log, each log event is logged as a JSON object on a single line. The log format defines a list of fields that can be logged with every request. In addition to these fields, custom key/value pairs can be logged via Searcher code. Pre-defined fields:

An example log line will look like this (here, pretty-printed):

{
  "ip": "152.200.54.243",
  "time": 920880005.023,
  "duration": 0.122,
  "responsesize": 9875,
  "code": 200,
  "method": "GET",
  "uri": "/search?query=test&param=value",
  "version": "HTTP/1.1",
  "agent": "Mozilla/4.05 [en] (Win95; I)",
  "host": "localhost",
  "search": {
    "totalhits": 1234,
    "hits": 0,
    "coverage": {
      "coverage": 98,
      "documents": 100,
      "degraded": {
        "non-ideal-state": true
      }
    }
  }
}

Example: Decompress, pretty-print, with human-readable timestamps:

$ jq '. + {iso8601date:(.time | todateiso8601)}' \
  <(unzstd -c /opt/vespa/logs/vespa/access/JsonAccessLog.default.20210601010000.zst)

Logging Remote Address/Port

In some cases when a request passes through an intermediate service, this service may add HTTP headers indicating the IP address and port of the real origin client. These values are logged as remoteaddr and remoteport respectively. Vespa will log the contents in any of the following HTTP request headers as remoteaddr: X-Forwarded-For, Y-RA, YahooRemoteIP or Client-IP. If more than one of these headers are present, the precedence is in the order listed here, i.e. X-Forwarded-For takes precedence over Y-RA. The contents of the Y-RP HTTP request header will be logged as remoteport.

If the remote address or -port differs from those initiating the HTTP request, the address and port for the immediate client making the request are logged as peeraddress and peerport respectively.

Configuring Logging

For details on the access logging configuration see accesslog in the container element in services.xml.

File name pattern

The file name pattern is expanded using the time when the file is created. The following parts in the file name are expanded:

Log rotation

Apache httpd style log rotation can be configured by setting the rotationScheme. There's two alternatives for the rotationScheme, sequence and date. The rotation time is controlled by setting rotationInterval.

Sequence rotation scheme

The fileNamePattern is used for the active log file name (which in this case will often be a constant string). At rotation, this file is given the name fileNamePattern.N where N is 1 + the largest integer found by extracting the integers from all files ending by .<Integer> in the same directory

<accesslog type='json'
           fileNamePattern='logs/vespa/access/JsonAccessLog.<container id>.%Y%m%d%H%M%S'
           rotationScheme='sequence' />

Date rotation scheme

The fileNamePattern is used for the active log file name here too, but the log files are not renamed at rotation. Instead, you must specify a time-dependent fileNamePattern so that each time a new log file is created, the name is unique. In addition, a symlink is created pointing to the active log file. The name of the symlink is specified using symlinkName.

<accesslog type='json'
           fileNamePattern='logs/vespa/access/JsonAccessLog.<container id>.%Y%m%d%H%M%S'
           rotationScheme='date'
           symlinkName='JsonAccessLog' />

Rotation interval

The time of rotation is controlled by setting rotationInterval:

<accesslog type='json'
           fileNamePattern='logs/vespa/access/JsonAccessLog.<container id>.%Y%m%d%H%M%S'
           rotationInterval='0 60 ...'
           rotationScheme='date'
           symlinkName='JsonAccessLog.<container id>' />

The rotationInterval is a list of numbers specifying when to do rotation. Each element represents the number of minutes since midnight. Ending the list with '...' means continuing the arithmetic progression defined by the two last numbers for the rest of the day. E.g. "0 100 240 480 ..." is expanded to "0 100 240 480 720 960 1200"

Log retention

Access logs are rotated, but not deleted by Vespa processes. It is up to the application owner to take care of archiving of access logs.

Logging Key/Value pairs to the JSON Access Log from Searchers

To add a key/value pair to the access log from a searcher, use

query/result.getContext(true).logValue(key,value)

Such key/value pairs may be added from any thread participating in handling the query without incurring synchronization overhead.

If the same key is logged multiple times, the values written will be included in the log as an array of strings rather than a single string value.

The key/value pairs are added to the attributes object in the log.

An example log line will then look something like this:

{"ip":"152.200.54.243","time":920880005.023,"duration":0.122,"responsesize":9875,"code":200,"method":"GET","uri":"/search?query=test&param=value","version":"HTTP/1.1","agent":"Mozilla/4.05 [en] (Win95; I)","host":"localhost","search":{"totalhits":1234,"hits":0},"attributes":{"singlevalue":"value1","multivalue":["value2","value3"]}}

A pretty print version of the same example:

{
  "ip": "152.200.54.243",
  "time": 920880005.023,
  "duration": 0.122,
  "responsesize": 9875,
  "code": 200,
  "method": "GET",
  "uri": "/search?query=test&param=value",
  "version": "HTTP/1.1",
  "agent": "Mozilla/4.05 [en] (Win95; I)",
  "host": "localhost",
  "search": {
    "totalhits": 1234,
    "hits": 0
  },
  "attributes": {
    "singlevalue": "value1",
    "multivalue": [
      "value2",
      "value3"
    ]
  }
}

Connection log

In addition to the access log, one entry per connection is written to the connection log. This entry is written on connection close. Available fields:

SSL information