Configuring Logging

Protari uses the standard Python logging library for logging, which can be configured by the user via a json or yaml file. This file should follow the Python configuration dictionary schema.

Place the path to this configuration file in the global settings file.

An example configuration file is provided in the protari-sample repository, logging_config_example.yaml:

version: 1
formatters:
  standard:
    format: '%(levelname)s:%(name)s:%(message)s'
  with_time:
    format: '%(asctime)s:%(levelname)s:%(name)s:%(message)s'
handlers:
  console:
    class: logging.StreamHandler
    level: DEBUG
    formatter: standard
    stream: ext://sys.stdout
  wsgi:
    class: logging.StreamHandler
    level: DEBUG
    formatter: with_time
    stream: ext://flask.logging.wsgi_errors_stream
loggers:
  protari.api:
    level: DEBUG
    handlers:
    - console
    - wsgi
    propagate: no
root:
  level: INFO
  handlers:
  - console
  - wsgi

Loggers

Protari provides the following named loggers:

You can include API request headers in the API's logs by including them in log_headers in the settings file, eg. to record users' IP addresses or user agent.

Some dependencies such as Flask also include their own loggers.

Example logging

When the Protari API starts up, depending on the configuration, the following might be logged:

INFO:protari.auth:Loading json web key set from <url>
INFO:protari.auth:Successfully loaded jwks from <url>
INFO:protari.load.dataset_config:Loading table metadata...
INFO:protari.load.dataset_config:    sample_longitudinal.json        : sample_longitudinal
INFO:protari.load.dataset_config:    sample.json                     : sample
INFO:protari.load.dataset_config:    secret.json                     : secret
INFO:protari.load.utils:Overriding value_tiebreaker_name: {tbe_perturb.record_key_name} with id
WARNING:protari.load.field:Integer field "AGE" has neither minimum and maximum, nor any non-sentinel values.
INFO:protari.load.dataset_config:Checking sample_longitudinal
WARNING:protari.load.validate:Running validation checks: ['types'] of ['types', 'config-values', 'db-values', 'db-group-values']
INFO:protari.load.validate:Perturbation algorithm: TBEPerturb
INFO:protari.load.dataset_config:No problems found.
INFO:protari.load.dataset_config:Checking sample
INFO:protari.load.validate:Perturbation algorithm: TBEPerturb
INFO:protari.load.dataset_config:No problems found.
INFO:protari.load.dataset_config:Checking secret
INFO:protari.load.validate:Perturbation algorithm: TBEPerturb
WARNING:protari.load.dataset_config:1 warnings:
WARNING:protari.load.dataset_config:'DWELL: type-mismatch - config string vs database INTEGER'
WARNING:protari.load.dataset_config:1 warnings in total

During running, logging of requests is output at the "info" level of the protari.api logger, eg.

INFO:protari.api.request:{"op": "datasets"}
INFO:protari.api.request:{"op": "dataset", "dataset": "sample"}
INFO:protari.api.request:{"op": "aggregation", "dataset": "sample", "function": ["count"], "group_by": null, "where": ["COUNTRY=1100"], "totals": false, "format": "json"}
INFO:protari.api.request:{"op": "aggregation", "dataset": "sample", "function": ["mean ROOMS"], "group_by": null, "where": null, "totals": false, "format": "json"}

If the settings include log_attributes or log_headers, these will also be present, eg.

INFO:protari.api.request:{"op": "dataset", "attributes": {"remote_addr": "127.0.0.1"}, "dataset": "sample"}

Most queries that fail also produce log entries, eg.

INFO:protari.api:{"op": "dataset", "error": {"detail": "Dataset \"foo\" does not exist.", "reported_as": "Unknown dataset foo", "type": "UnknownDatasetError"}}

INFO:protari.api:{"op": "unknown", "error": {
  "detail": "the requested url was not found on the server.  if you entered the url manually please check your spelling and try again.",
  "reported_as": "The requested URL was not found on the server.  If you entered the URL manually please check your spelling and try again.",
  "name": null
 }}

INFO:protari.api:{"op": "unknown", "error": {
  "detail": "extra query parameter(s) foo not in spec",
  "reported_as": "Extra query parameter(s) foo not in spec",
  "name": null
}}

INFO:protari.api.request:{"op": "aggregation", "dataset": "sample", "function": ["mean BAR"], "group_by": null, "where": null, "totals": false, "format": "json"}
INFO:protari.api:{"op": "aggregation", "error": {
  "detail": null,
  "reported_as": "Unknown field \"BAR\"",
  "name": "InvalidFieldError",
  "uid": "xpydl4DIZS",
  "sub": "user@example.com"
}}

INFO:protari.api.request:{"op": "aggregation", "dataset": "sample", "function": ["foo"], "group_by": null, "where": null, "totals": false, "format": "json"}
INFO:protari.api:{"op": "aggregation", "error": {
  "detail": null,
  "reported_as": "Unknown function 'foo'.",
  "name": "InvalidFunctionError",
  "uid": "xpydl4DIZS",
  "sub": "user@example.com"
}}

INFO:protari.api.request:{"op": "aggregation", "dataset": "sample", "function": ["count"], "group_by": ["foo"], "where": null, "totals": false, "format": "json"}
INFO:protari.api:{"op": "aggregation", "error": {
  "detail": null,
  "reported_as": "Unknown field \"foo\"",
  "name": "InvalidFieldError",
  "uid": "xpydl4DIZS",
  "sub": "user@example.com"
}}

INFO:protari.api.request:{"op": "aggregation", "dataset": "sample", "function": ["count"], "group_by": null, "where": ["COUNTRY=bar"], "totals": false, "format": "json"}
INFO:protari.api:{"op": "aggregation", "error": {
  "detail": null,
  "reported_as": "Unknown value \"bar\".",
  "name": "InvalidValueError",
  "uid": "xpydl4DIZS",
  "sub": "user@example.com"
}}

WARNING:protari.api:{"op": "aggregation", "error": {
  "detail": "Unknown authentication error: Signature verification failed.",
  "reported_as": "Authentication failed.",
  "name": "AuthenticationError"
}}

INFO:protari.api:{"op": "aggregation", "error": {
  "detail": "Attempt to access dataset \"secret\" without any authentication.",
  "reported_as": "Unknown dataset secret",
  "name": "UnknownDatasetError"
}}

WARNING:protari.api:{"op": "aggregation", "error": {
  "detail": "Unauthorized query attempted on "secret" with token: {'iss': ..., 'aud': ..., 'sub': ..., ...}",
  "reported_as": "You do not have permission to query this dataset.",
  "name": "AuthorizationError"
}}