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

fix: rollback json access logging #3694

Merged
merged 3 commits into from
Mar 28, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion api/Makefile
Original file line number Diff line number Diff line change
Expand Up @@ -83,7 +83,7 @@ django-collect-static:

.PHONY: serve
serve:
poetry run gunicorn --config scripts/gunicorn.conf.py --bind 0.0.0.0:8000 app.wsgi --reload
poetry run gunicorn --bind 0.0.0.0:8000 app.wsgi --reload

.PHONY: generate-ld-client-types
generate-ld-client-types:
Expand Down
4 changes: 2 additions & 2 deletions api/app/settings/common.py
Original file line number Diff line number Diff line change
Expand Up @@ -535,13 +535,13 @@
CHARGEBEE_SITE = env("CHARGEBEE_SITE", default=None)

# Logging configuration
LOG_FORMAT = env.str("LOG_FORMAT", default="generic")
LOG_LEVEL = env.str("LOG_LEVEL", default="WARNING")
LOGGING_CONFIGURATION_FILE = env.str("LOGGING_CONFIGURATION_FILE", default=None)
if LOGGING_CONFIGURATION_FILE:
with open(LOGGING_CONFIGURATION_FILE, "r") as f:
LOGGING = json.loads(f.read())
else:
LOG_FORMAT = env.str("LOG_FORMAT", default="generic")
LOG_LEVEL = env.str("LOG_LEVEL", default="WARNING")
LOGGING = {
"version": 1,
"disable_existing_loggers": False,
Expand Down
16 changes: 0 additions & 16 deletions api/scripts/gunicorn.conf.py

This file was deleted.

11 changes: 9 additions & 2 deletions api/scripts/run-docker.sh
Original file line number Diff line number Diff line change
Expand Up @@ -17,8 +17,15 @@ function serve() {
python manage.py waitfordb

exec gunicorn --bind 0.0.0.0:8000 \
--worker-tmp-dir=/dev/shm \
--config=/app/scripts/gunicorn.conf.py \
--worker-tmp-dir /dev/shm \
--timeout ${GUNICORN_TIMEOUT:-30} \
--workers ${GUNICORN_WORKERS:-3} \
--threads ${GUNICORN_THREADS:-2} \
--access-logfile $ACCESS_LOG_LOCATION \
--access-logformat '%(h)s %(l)s %(u)s %(t)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s" %({origin}i)s %({access-control-allow-origin}o)s' \
--keep-alive ${GUNICORN_KEEP_ALIVE:-2} \
${STATSD_HOST:+--statsd-host $STATSD_HOST:$STATSD_PORT} \
${STATSD_HOST:+--statsd-prefix $STATSD_PREFIX} \
app.wsgi
}
function run_task_processor() {
Expand Down
48 changes: 44 additions & 4 deletions api/tests/unit/util/test_logging.py
Original file line number Diff line number Diff line change
Expand Up @@ -4,16 +4,16 @@
from util.logging import JsonFormatter


def test_json_formatter__outputs_expected():
def test_json_formatter():
json_formatter = JsonFormatter()

log_record = logging.LogRecord(
name="test_logger",
level=logging.INFO,
pathname="test.py",
lineno=42,
msg="This is a test message with args: %s and %s",
args=("arg1", "arg2"),
msg="This is a test.",
args=(),
exc_info=None,
)
formatted_message = json_formatter.format(log_record)
Expand All @@ -25,4 +25,44 @@ def test_json_formatter__outputs_expected():
assert "logger_name" in json_message
assert "process_id" in json_message
assert "thread_name" in json_message
assert json_message["message"] == "This is a test message with args: arg1 and arg2"


def test_json_formatter_with_old_style_placeholders():
json_formatter = JsonFormatter()

log_record = logging.LogRecord(
name="test_logger",
level=logging.INFO,
pathname="example.py",
lineno=42,
msg="This is a test with old-style placeholders: %s and %s",
args=("arg1", "arg2"),
exc_info=None,
)

formatted_message = json_formatter.format(log_record)
parsed_json = json.loads(formatted_message)
assert (
parsed_json["message"]
== "This is a test with old-style placeholders: arg1 and arg2"
)


def test_json_formatter_arguments_with_new_style_placeholders():
json_formatter = JsonFormatter()
log_record = logging.LogRecord(
name="test_logger",
level=logging.INFO,
pathname="example.py",
lineno=42,
msg="This is a test with new-style placeholders: {} and {}",
args=("arg1", "arg2"),
exc_info=None,
)

formatted_message = json_formatter.format(log_record)
parsed_json = json.loads(formatted_message)
assert (
parsed_json["message"]
== "This is a test with new-style placeholders: arg1 and arg2"
)
77 changes: 18 additions & 59 deletions api/util/logging.py
Original file line number Diff line number Diff line change
@@ -1,68 +1,27 @@
import json
import logging
import os
import sys
from datetime import datetime
from typing import Any

from gunicorn.config import Config
from gunicorn.glogging import Logger as GunicornLogger


class JsonFormatter(logging.Formatter):
"""Custom formatter for json logs."""

def get_json_record(self, record: logging.LogRecord) -> dict[str, Any]:
formatted_message = record.getMessage()
return {
"levelname": record.levelname,
"message": formatted_message,
"timestamp": self.formatTime(record, self.datefmt),
"logger_name": record.name,
"process_id": record.process,
"thread_name": record.threadName,
}

def format(self, record: logging.LogRecord) -> str:
def format(self, record):
"""
%s is replaced with {} because legacy string formatting
conventions in django-axes module prevent correct
interpolation of arguments when using this formatter.
"""
try:
return json.dumps(self.get_json_record(record))
log_message = record.msg.replace("%s", "{}")
formatted_message = log_message.format(*record.args)
log_record = {
"levelname": record.levelname,
"message": formatted_message,
"timestamp": self.formatTime(record, self.datefmt),
"logger_name": record.name,
"process_id": record.process,
"thread_name": record.threadName,
}
return json.dumps(log_record)
except (ValueError, TypeError) as e:
return json.dumps({"message": f"{e} when dumping log"})


class GunicornAccessLogJsonFormatter(JsonFormatter):
def get_json_record(self, record: logging.LogRecord) -> dict[str, Any]:
response_time = datetime.strptime(record.args["t"], "[%d/%b/%Y:%H:%M:%S %z]")
url = record.args["U"]
if record.args["q"]:
url += f"?{record.args['q']}"

return {
**super().get_json_record(record),
"time": response_time.isoformat(),
"path": url,
"remote_ip": record.args["h"],
"method": record.args["m"],
"status": str(record.args["s"]),
"user_agent": record.args["a"],
"referer": record.args["f"],
"duration_in_ms": record.args["M"],
"pid": record.args["p"],
}


class GunicornJsonCapableLogger(GunicornLogger):
def setup(self, cfg: Config) -> None:
super().setup(cfg)
if os.getenv("LOG_FORMAT") == "json":
self._set_handler(
self.error_log,
cfg.errorlog,
JsonFormatter(),
)
self._set_handler(
self.access_log,
cfg.accesslog,
GunicornAccessLogJsonFormatter(),
stream=sys.stdout,
)
return f"Error formatting log record: {str(e)}"
7 changes: 1 addition & 6 deletions docs/docs/deployment/hosting/docker.md
Original file line number Diff line number Diff line change
Expand Up @@ -20,18 +20,13 @@ new account at [http://localhost:8000/signup](http://localhost:8000/signup)
As well as the Environment Variables specified in the [API](/deployment/hosting/locally-api#environment-variables) and
[Front End](/deployment/hosting/locally-frontend#environment-variables) you can also specify the following:

- `GUNICORN_CMD_ARGS`: Gunicorn command line arguments. Overrides Flagsmith's defaults. See
[Gunicorn documentation](https://docs.gunicorn.org/en/stable/settings.html) for reference.
- `GUNICORN_WORKERS`: The number of [Gunicorn Workers](https://docs.gunicorn.org/en/stable/settings.html#workers) that
are created
- `GUNICORN_THREADS`: The number of
[Gunicorn Threads per Worker](https://docs.gunicorn.org/en/stable/settings.html#threads)
- `GUNICORN_TIMEOUT`: The number of seconds before the
[Gunicorn times out](https://docs.gunicorn.org/en/stable/settings.html#timeout)
- `ACCESS_LOG_FORMAT`: Message format for Gunicorn's access log. See
[variable details](https://docs.gunicorn.org/en/stable/settings.html#access-log-format) to define your own format.
- `ACCESS_LOG_LOCATION`: The location to write access logs to. If not set, or set to `-`, the logs will be sent to
`stdout`
- `ACCESS_LOG_LOCATION`: The location to write access logs to

## Platform Architectures

Expand Down
8 changes: 2 additions & 6 deletions docs/docs/deployment/hosting/locally-api.md
Original file line number Diff line number Diff line change
Expand Up @@ -150,12 +150,8 @@ the below variables will be ignored.
define a shared DJANGO_SECRET_KEY.
- `LOG_LEVEL`: DJANGO logging level. Can be one of `DEBUG`, `INFO`, `WARNING`, `ERROR`, `CRITICAL`
- `LOG_FORMAT`: Can be `generic` (plain-text) or `json`. Defaults to `generic`.
- `GUNICORN_CMD_ARGS`: Gunicorn command line arguments. Overrides Flagsmith's defaults. See
[Gunicorn documentation](https://docs.gunicorn.org/en/stable/settings.html) for reference.
- `ACCESS_LOG_FORMAT`: Message format for Gunicorn's access log. See
[variable details](https://docs.gunicorn.org/en/stable/settings.html#access-log-format) to define your own format.
- `ACCESS_LOG_LOCATION`: The location to store web logs generated by Gunicorn if running as a Docker container. If not
set, no logs will be stored. If not set, or set to `-`, the logs will be sent to `stdout`.
- `ACCESS_LOG_LOCATION`: The location to store web logs generated by gunicorn if running as a Docker container. If not
set, no logs will be stored. If set to `-` the logs will be sent to `stdout`.
- `DJANGO_SETTINGS_MODULE`: python path to settings file for the given environment, e.g. "app.settings.develop"
- `ALLOW_ADMIN_INITIATION_VIA_CLI`: Enables the `bootstrap` management command which creates default admin user,
organisation, and project.
Expand Down