Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Reworking logging in mreg. #515

Merged
merged 20 commits into from
Aug 28, 2023
Merged

Conversation

terjekv
Copy link
Collaborator

@terjekv terjekv commented Jul 21, 2023

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:
#515 (comment)

@terjekv terjekv self-assigned this Jul 21, 2023
@coveralls
Copy link
Collaborator

coveralls commented Jul 21, 2023

Coverage Status

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

@terjekv
Copy link
Collaborator Author

terjekv commented Jul 24, 2023

Screenshot 2023-07-24 at 23 43 11

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 (and other non-API-based context initiators) 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.
  - Console output is colorized via Rich
  - 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

An example of the output can be seen here:
  - Request_id is now added implicitly to all log messages, using a structlog processor. This alleviates the need for each log entry to manually insert it.
  - Add some visual touches to the logs to make them more readable on the console (only). This does not affect production logging.
  - Remove local implementation of contextvars.
  - Add support for correlation_id to passed through the calls.
  - This change also removes the request_id for non-request-sourced events.
  - Events without request_id are colored with a black dot with colored output.
@terjekv terjekv marked this pull request as ready for review August 18, 2023 08:59
@terjekv
Copy link
Collaborator Author

terjekv commented Aug 18, 2023

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

mregsite/settings.py Outdated Show resolved Hide resolved
  - The log file gets raw json, no colors or sorting.
  - The console should be unchanged.
  - If the environment variable CI isn't set, the console gets raw JSON like the file.
  - 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.
@oyvindhagberg
Copy link
Contributor

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
Copy link
Collaborator Author

terjekv commented Aug 24, 2023

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
Copy link
Contributor

oyvindhagberg commented Aug 25, 2023

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
Copy link
Collaborator Author

terjekv commented Aug 25, 2023

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

@terjekv
Copy link
Collaborator Author

terjekv commented Aug 26, 2023

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

@terjekv
Copy link
Collaborator Author

terjekv commented Aug 26, 2023

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
Copy link
Contributor

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

@terjekv
Copy link
Collaborator Author

terjekv commented Aug 28, 2023

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

@oyvindhagberg oyvindhagberg merged commit 238d5fe into unioslo:master Aug 28, 2023
21 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants