Make access log use local time with timezone

PR aio-libs#3860 by @NewUserHa Co-Authored-By: Sviatoslav Sydorenko <wk.cvs.github@sydorenko.org.ua>
cdce8p · Aug 25, 2023 · f364692 · f364692
1 parent b9b0906
commit f364692
Show file tree

Hide file tree

Showing 2 changed files with 46 additions and 26 deletions.
diff --git a/aiohttp/web_log.py b/aiohttp/web_log.py
@@ -4,6 +4,7 @@
 import os
 import re
 from collections import namedtuple
+import time as time_mod
 from typing import Any, Callable, Dict, Iterable, List, Tuple  # noqa
 
 from .abc import AbstractAccessLogger
@@ -142,9 +143,10 @@ def _format_a(request: BaseRequest, response: StreamResponse, time: float) -> st
 
     @staticmethod
     def _format_t(request: BaseRequest, response: StreamResponse, time: float) -> str:
-        now = datetime.datetime.utcnow()
+        tz = datetime.timezone(datetime.timedelta(seconds=-time_mod.timezone))
+        now = datetime.datetime.now(tz)
         start_time = now - datetime.timedelta(seconds=time)
-        return start_time.strftime("[%d/%b/%Y:%H:%M:%S +0000]")
+        return start_time.strftime("[%d/%b/%Y:%H:%M:%S %z]")
 
     @staticmethod
     def _format_P(request: BaseRequest, response: StreamResponse, time: float) -> str:

diff --git a/tests/test_web_log.py b/tests/test_web_log.py
@@ -1,6 +1,7 @@
 import datetime
 import logging
 import platform
+from typing import Any
 from unittest import mock
 
 import pytest
@@ -51,13 +52,46 @@ def test_access_logger_format() -> None:
     Ref: https://stackoverflow.com/a/46102240/595220
     """,
 )
-def test_access_logger_atoms(mocker) -> None:
-    utcnow = datetime.datetime(1843, 1, 1, 0, 30)
-    mock_datetime = mocker.patch("datetime.datetime")
-    mock_getpid = mocker.patch("os.getpid")
-    mock_datetime.utcnow.return_value = utcnow
-    mock_getpid.return_value = 42
-    log_format = '%a %t %P %r %s %b %T %Tf %D "%{H1}i" "%{H2}i"'
+@pytest.mark.parametrize(
+    "log_format,expected,extra",
+    [
+        (
+            "%t",
+            "[01/Jan/1843:00:29:56 +0800]",
+            {"request_start_time": "[01/Jan/1843:00:29:56 +0800]"},
+        ),
+        (
+            '%a %t %P %r %s %b %T %Tf %D "%{H1}i" "%{H2}i"',
+            (
+                "127.0.0.2 [01/Jan/1843:00:29:56 +0800] <42> "
+                'GET /path HTTP/1.1 200 42 3 3.141593 3141593 "a" "b"'
+            ),
+            {
+                "first_request_line": "GET /path HTTP/1.1",
+                "process_id": "<42>",
+                "remote_address": "127.0.0.2",
+                "request_start_time": "[01/Jan/1843:00:29:56 +0800]",
+                "request_time": "3",
+                "request_time_frac": "3.141593",
+                "request_time_micro": "3141593",
+                "response_size": 42,
+                "response_status": 200,
+                "request_header": {"H1": "a", "H2": "b"},
+            },
+        ),
+    ],
+)
+def test_access_logger_atoms(
+    monkeypatch: Any, log_format: Any, expected: Any, extra: Any
+) -> None:
+    class PatchedDatetime(datetime.datetime):
+        @staticmethod
+        def now(tz):
+            return datetime.datetime(1843, 1, 1, 0, 30, tzinfo=tz)
+
+    monkeypatch.setattr("datetime.datetime", PatchedDatetime)
+    monkeypatch.setattr("time.timezone", -28800)
+    monkeypatch.setattr("os.getpid", lambda: 42)
     mock_logger = mock.Mock()
     access_logger = AccessLogger(mock_logger, log_format)
     request = mock.Mock(
@@ -69,23 +103,7 @@ def test_access_logger_atoms(mocker) -> None:
     )
     response = mock.Mock(headers={}, body_length=42, status=200)
     access_logger.log(request, response, 3.1415926)
-    assert not mock_logger.exception.called
-    expected = (
-        "127.0.0.2 [01/Jan/1843:00:29:56 +0000] <42> "
-        'GET /path HTTP/1.1 200 42 3 3.141593 3141593 "a" "b"'
-    )
-    extra = {
-        "first_request_line": "GET /path HTTP/1.1",
-        "process_id": "<42>",
-        "remote_address": "127.0.0.2",
-        "request_start_time": "[01/Jan/1843:00:29:56 +0000]",
-        "request_time": "3",
-        "request_time_frac": "3.141593",
-        "request_time_micro": "3141593",
-        "response_size": 42,
-        "response_status": 200,
-        "request_header": {"H1": "a", "H2": "b"},
-    }
+    assert not mock_logger.exception.called, mock_logger.exception.call_args
 
     mock_logger.info.assert_called_with(expected, extra=extra)