fix: rollback json access logging (#3694)

api/Makefile

@@ -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:

api/app/settings/common.py

@@ -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,

api/scripts/run-docker.sh

@@ -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() {

api/tests/unit/util/test_logging.py

@@ -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)
@@ -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"
+    )

api/util/logging.py

@@ -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)}"

docs/docs/deployment/hosting/docker.md

@@ -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
 

docs/docs/deployment/hosting/locally-api.md

@@ -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.