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 exportersfor 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.