Logging

Here you can find information about access logging. Access log, will track which API endpoints are accessed. For each request two long entries are created on for request and optionaly another for response. Response entry might not be created, if there was no response due to an error.

Configuring logging

Access log is controlled by accesslog component. You can find all available accesslog components using this command:

$ spinta config components.accesslog
Origin  Name                         Value
------  ---------------------------  ---------------------------------------
spinta  components.accesslog.file    spinta.accesslog.file:FileAccessLog
spinta  components.accesslog.python  spinta.accesslog.python:PythonAccessLog

Here we can see two logging components available, file and python.

python component is mainly used for testing, it saves log messages in memory, do not use it in production environment, you will run out of memory.

For production you should use file component.

You can set logging backend like this:

accesslog:
  type: file
  file: /path/to/file.log

See Configuration for more information.

Log message format

Log messages are stored in JSON Lines format, a new JSON object is appended to the specified file as a new line.

For each request two messages and two lines are added to log file. One message for request and another for response. In case of an error, response message might not be added.

Both request and response messages share the same txn value. You can find matching requests and response entries by txn. It is not guaranteed, that request and response are added one after the other, because multiple parallel requests might be added and responses will follow as soon as request is completed.

Request message

Example of request log message:

{
  "time": "2024-07-31T07:37:03.552142+00:00",
  "pid": "1000",
  "type": "request",
  "method": "GET",
  "action": "getall",
  "ns": "example/:ns",
  "model": "example/City",
  "prop": "example/City/prop",
  "id": "3317125b-bf21-4458-9977-46a9dec05897",
  "rev": "3012e5e5-a24d-4535-b140-560601b3e7d5",
  "txn": "db5e8248-c1e6-4ca4-a5ea-c63e5d2d005b"
  "rctype": "application/json",
  "format": "json",
  "url": "http://localhost:8000/example/City"
  "client": "a2f712a5-33e2-4620-a609-018eb9c9c212",
  "reason": "",
  "agent": "HTTPie/2.5.0",
}

Example is pretty printed for readability, but in log files, each message is stored in a single line.

Always present fields:

time:

Date and time when log message was recorded.

txn:

Transaction id (UUID) of this request. Same id is used in response log message.

type:

For requests this will always be request.

Added in version 0.1.40: (2022-11-01)

pid:

Process id of a web worker who issued log message.

Added in version 0.1.43: (2022-11-15)

method:

HTTP request method.

action:

Data request action (available actions).

format:

Requested data format (see spinta config exporters for supported formats).

url:

Full request URL.

client:

Client id in UUID format, which was used to access data (see Client credentials).

Changed in version 0.1.59: (2023-11-14)

Before 0.1.59, client name was used, starting with 0.1.59 client id is used in logs.

agent:

User agent used to access data.

Extra fields fields, that might not be present in log message:

rctype:

Request body content type, for example application/json. This is used only for write operations and describes content type of request payload.

ns:

Accessed namespace name (if a namespace was accessed).

model:

Accessed absolute model name (if a model was accessed).

prop:

Accessed property name of a model (if a subresource was accessed).

id:

Accessed object id (if object was accessed directly).

rev:

Accessed object revision (if object was accessed directly for writing).

Response message

Added in version 0.1.40: (2022-11-01)

Example of response log message:

{
  "time": "2024-07-31T07:37:03.557142+00:00",
  "type": "response",
  "delta": 7.822166530415416,
  "memory": 2433024,
  "objects": 200,
  "txn": "db5e8248-c1e6-4ca4-a5ea-c63e5d2d005b"
}

Example is pretty printed for readability, but in log files, each message is stored in a single line.

Always present fields:

time:

Date and time when log message was recorded.

txn:

Transaction id (UUID) of this request. Same id is used in response log message.

type:

For responses this will always be set to response.

memory:

RAM memory difference between request and response in bytes.

Difference might include memory used by other requests, if multiple requests happen at the same time and on the same web worker.

delta:

Time difference between request and response in seconds.

objects:

Number of objects processed during requests. This counts only top levels objects and does not include composite objects attached to the top level object.

Response message does not include data which is already provided in request message. You can find request of a response by txn value.

Log messages contain only relevant fields. For example rctype is only available for write operations, ns, model, prop are only available if a namespace, a model or a property is accessed.

Reading log messages

You can use jq tool for reading log messages from a json lines file.

For example if you want to get only messages where a model was accessed, you can run this command:

jq 'select(.type=="request" and has("model"))' accesslog.json

Or if you want to get all model messages where action was getall:

jq 'select(.type=="request" and has("model") and .action == "getall")' accesslog.json

Count number of requests by month:

jq 'select(.type=="request") | .time[:7]' accesslog.json | sort | uniq -c

Count number of response by month:

jq 'select(.type=="response") | .time[:7]' accesslog.json | sort | uniq -c

Count number of objects processed by month:

jq -r 'select(.type=="response") | [.time[:7], .objects | tostring] | join(" ")' accesslog.json | \
    awk '{sum[$1] += $2} END {for (date in sum) print sum[date], date}'

In most cases you need to add select(.type=="request") or select(.type=="response") in order to avoid dublication.