Structured logging for Plone
Project description
ftw.structlog
This package implements structured request logging in Plone.
It does so by writing logfiles (one per instance) that contain one JSON entry per line for every request. That JSON entry contains all the information the Z2 log provides, and more, in structured key/value pairs.
Installation
Install ftw.structlog by adding it to the list of eggs in your buildout. Then run buildout and restart your instance:
[instance]
eggs +=
ftw.structlogAlternatively, add it as a dependency to your package’s setup.py.
Logged Information
Example entry:
{
"bytes": 6875,
"cient_ip": "127.0.0.1",
"duration": 0.30268411636353,
"host": "127.0.0.1",
"method": "GET",
"referer": "http:\/\/localhost:8080\/plone",
"site": "plone",
"status": 200,
"timestamp": "2017-07-29T12:30:58.000750+02:00",
"url": "http:\/\/localhost:8080\/plone\/my-page",
"user": "john.doe",
"user_agent": "Mozilla\/5.0 (Macintosh; Intel Mac OS X 10_11_6) AppleWebKit\/537.36 (KHTML, like Gecko) Chrome\/60.0.3112.113 Safari\/537.36",
"view": "some_view"
}The logged JSON entry contains the following data:
key |
value |
|---|---|
bytes |
Size of response body in bytes (Content-Length) |
client_ip |
Host where the request originated from (respecting X-Forwarded-For) |
duration |
Time spent in ZPublisher to handle request (time between IPubStart and IPubSuccess / IPubFailure ) |
host |
Deprecated. You should use client_ip instead. |
method |
HTTP request method |
referer |
Referer |
site |
Plone site ID |
status |
HTTP response status |
timestamp |
Time when request was received (non-naive local time in ISO 8601, in the server’s local timezone as determined by tzlocal) |
url |
URL of the request (including query string if present) |
user |
Username of the authenticated user, "Anonymous" otherwise |
user_agent |
User-Agent |
view |
Name of the browser view or REST API endpoint (see below) |
If SQLAlchemy is installed and integrated via z3c.saconfig, SQL query times will also be logged. For requests that perform SQL queries, there will be an additional key sql_query_time containing the cumulative time of all SQL queries during that request:
key |
value |
|---|---|
sql_query_time |
Cumulative time of all SQL queries during request (in seconds) |
Log Destinations
ftw.structlog logs to a file by default, but can be configured to log to a Fluentd / Fluent Bit instance instead.
Logging to file
By default, ftw.structlog will log to a local file with one JSON object per line.
One logfile per Zope2 instance will be created, and its location and name will be derived from the instance’s eventlog path. If the instance’s eventlog path is var/log/instance2.log, the JSON logfile’s path will be var/log/instance2-json.log.
Note: Because ftw.structlog derives its logfile name from the eventlog path, an eventlog must be configured in zope.conf, otherwise ftw.structlog will not log any requests and complain noisily through the root logger.
When running tests in other projects, these errors can be muted by setting the environment variable FTW_STRUCTLOG_MUTE_SETUP_ERRORS=true.
Logging to Fluentd
If the environment variable FLUENT_HOST is set, ftw.structlog will log to that fluent host using the Fluentd Forward Protocol, instead of logging to a local file. FLUENT_HOST (optional) allows to specify the port, and defaults to 24224 if not set.
In order for ftw.structlog to use a proper tag for events logged to Fluentd, the Pod namespace needs to be exposed in the KUBERNETES_NAMESPACE env var.
View Name
An attempt is made to log the name of the invoked browser view or REST API endpoint, so that requests to particular views can easily be grouped without having to resort to URL string parsing.
However, this is intentionally limited, and aims to only handle the most common and useful cases. It’s also implemented in a way to not fill up logs with too many diverse values for view, by grouping together very common requests (CSS and JS assets) under common names.
The following table gives an example of how names of different “views” are logged:
View Type |
view |
|---|---|
Regular browser view |
‘some_view’ |
Regular browser view, published attributes |
‘some_view/attr’ |
plone.rest named services |
|
plone.rest named services with path params |
|
plone.rest unnamed GET/POST/… |
‘context’ |
CSS |
‘portal_css’ |
JS |
‘portal_javascripts’ |
Resources |
‘++resource++’ |
Theme resources |
‘++theme++’ |
Links
Continuous integration: https://jenkins.4teamwork.ch/search?q=ftw.structlog
Copyright
This package is copyright by 4teamwork.
ftw.structlog is licensed under GNU General Public License, version 2.
Changelog
1.4.1 (2023-04-04)
Fluentd logging: Use K8s namespace in tag. [lgraf]
1.4.0 (2023-02-01)
Add support for logging to Fluentd. [lgraf]
1.3.1 (2020-05-19)
SQL query logging: Be more defensive in trying to annotate a request that might not always be ready yet (e.g. during testing). [lgraf]
1.3.0 (2020-05-19)
Log view name for browser views and REST API services. [deiferni, lukasg]
1.2.0 (2020-05-19)
Track query execution time if SQLAlchemy is present. [lgraf]
1.1.0 (2019-01-11)
DEPRECATED: The host field is deprecated. Instead, the newly introduced client_ip field should be used to get the client’s IP address. [lgraf]
Always log missing referer as empty string instead of null. [lgraf]
1.0.1 (2017-09-03)
Fail gracefully if eventlog config can’t be found in order to derive log location from it. Instead of preventing instance startup, log a noticeable error message using the root logger. [lgraf]
1.0.0 (2017-09-03)
Initial implementation [lgraf]
Download files
Download the file for your platform. If you're not sure which to choose, learn more about installing packages.
