Reworking logging in mreg.

[terjekv]

This change migrates the entire logging backend to structlog (https://www.structlog.org/en/stable/) and implements an internal framework to offer the following funtionality:

• Logs are context aware, and context is tracked via a request_id.
• Each new request creates a new request_id.
• Associated log entries are given the same request_id.
• This request_id is also returned to the client via the header X-Request-ID.
• Collation-IDs may be passed via X-Collation-ID and are both logged and returned to the client as such.
• Console output is colorized via Rich
• If the environment variable CI isn't set, the console gets raw JSON like the file.
• The environment variable MREG_LOG_LEVEL controls the logging output.
• To see an example in action, try CI=True MREG_LOG_LEVEL=debug pytest mreg/api/v1/tests/test_hostgroups.py -vv -s, or see https://gist.github.com/terjekv/8e97915c8b66c30241ff421a087e510d

Logging to file is also supported:

• The log file gets raw json, no colours or sorting, but they inherit request_id and collation_id as expected.
• The log file is rotated based on size (MREG_LOG_FILE_SIZE, defaults to 10MB) and a number of version are kept (MREG_LOG_FILE_COUNT, defaults to 5).
• File name can be set by MREG_LOG_FILE_NAME (may contain slashes)
• Log directory is extrated from the filename, and created if needed.

An example of the output can be seen here: https://github.com/unioslo/mreg/pull/515#issuecomment-1647920124

[coveralls]

coverage: 99.185% (-0.06%) from 99.243% when pulling 238d5fef877d29e789efee4d3798c9a64061e9d9 on terjekv:logging_reworked into 1920fdcbc8a67e2c7886dced4d43a4e249e5dbea on unioslo:master.

[terjekv]

[terjekv]

Note that there is no review or filtering of the content returned from http requests, nor on the contents offered in POST data.

[oyvindhagberg]

I tested the container image from the artifact in https://github.com/unioslo/mreg/actions/runs/5961486496. I got it to log something to the console after setting MREG_LOG_LEVEL=INFO. It also created logs/app.log, but the log file remained empty... Any ideas?

[terjekv]

I'm willing to bet that the path to the file is broken. Fixed a bug and added some hard validation of the writability of the log file.

[oyvindhagberg]

When testing the latest changes locally, I get no log file at all. Tried both with and without setting CI. I'm running docker compose up with the following changes to docker-compose.yml:

+      - MREG_LOG_LEVEL=INFO
+      #- CI=yes
+    volumes:
+      - /mnt/oyvind/mreg/mregsite:/app/mreg/mregsite
+      - /mnt/oyvind/mreg/logs:/app/mreg/logs

I test by first running manage.py create_mreg_superuser inside the container, then using mreg-cli to authenticate and run host add something -f.

[terjekv]

Weird. Does it work if you run it with pytest or similar directly, ie, outside of a container?

[terjekv]

Huh. It creates the logs folder, but not the file? That's really odd.

[terjekv]

Right, this seems to be a bind issue. If I do docker exec -it /bin/sh mreg-mreg and cat /app/logs/app.log I see data in the log file.

[oyvindhagberg]

Good news, it turns out I had used the wrong path for the volume. It worked after I corrected it.

[terjekv]

At last it ensured I added some more checking and validation. :)