{
    "file_diffs": [
        {
            "old_file_content": "",
            "new_file_content": "Make access log use local time with timezone\n",
            "header": {
                "file": {
                    "path": "CHANGES/3853.feature"
                },
                "misc_line": "new file mode 100644"
            },
            "index_line": {
                "old_commit_hash": "00000000",
                "new_commit_hash": "cdadc706",
                "mode": ""
            },
            "is_binary_file": false,
            "binary_line": null,
            "minus_file": {
                "path": "/dev/null"
            },
            "plus_file": {
                "path": "b/CHANGES/3853.feature"
            },
            "hunks": [
                {
                    "descriptor": {
                        "old_range": {
                            "start": 0,
                            "length": 0
                        },
                        "new_range": {
                            "start": 1,
                            "length": null
                        },
                        "section": ""
                    },
                    "line_group": {
                        "all_lines": [
                            {
                                "content": "Make access log use local time with timezone",
                                "type": "added"
                            }
                        ]
                    },
                    "modified_entities": [],
                    "added_entities": [],
                    "deleted_entities": []
                }
            ]
        },
        {
            "old_file_content": "import datetime\nimport functools\nimport logging\nimport os\nimport re\nfrom collections import namedtuple\nfrom typing import Any, Callable, Dict, Iterable, List, Tuple  # noqa\n\nfrom .abc import AbstractAccessLogger\nfrom .web_request import BaseRequest\nfrom .web_response import StreamResponse\n\nKeyMethod = namedtuple(\"KeyMethod\", \"key method\")\n\n\nclass AccessLogger(AbstractAccessLogger):\n    \"\"\"Helper object to log access.\n\n    Usage:\n        log = logging.getLogger(\"spam\")\n        log_format = \"%a %{User-Agent}i\"\n        access_logger = AccessLogger(log, log_format)\n        access_logger.log(request, response, time)\n\n    Format:\n        %%  The percent sign\n        %a  Remote IP-address (IP-address of proxy if using reverse proxy)\n        %t  Time when the request was started to process\n        %P  The process ID of the child that serviced the request\n        %r  First line of request\n        %s  Response status code\n        %b  Size of response in bytes, including HTTP headers\n        %T  Time taken to serve the request, in seconds\n        %Tf Time taken to serve the request, in seconds with floating fraction\n            in .06f format\n        %D  Time taken to serve the request, in microseconds\n        %{FOO}i  request.headers['FOO']\n        %{FOO}o  response.headers['FOO']\n        %{FOO}e  os.environ['FOO']\n\n    \"\"\"\n\n    LOG_FORMAT_MAP = {\n        \"a\": \"remote_address\",\n        \"t\": \"request_start_time\",\n        \"P\": \"process_id\",\n        \"r\": \"first_request_line\",\n        \"s\": \"response_status\",\n        \"b\": \"response_size\",\n        \"T\": \"request_time\",\n        \"Tf\": \"request_time_frac\",\n        \"D\": \"request_time_micro\",\n        \"i\": \"request_header\",\n        \"o\": \"response_header\",\n    }\n\n    LOG_FORMAT = '%a %t \"%r\" %s %b \"%{Referer}i\" \"%{User-Agent}i\"'\n    FORMAT_RE = re.compile(r\"%(\\{([A-Za-z0-9\\-_]+)\\}([ioe])|[atPrsbOD]|Tf?)\")\n    CLEANUP_RE = re.compile(r\"(%[^s])\")\n    _FORMAT_CACHE: Dict[str, Tuple[str, List[KeyMethod]]] = {}\n\n    def __init__(self, logger: logging.Logger, log_format: str = LOG_FORMAT) -> None:\n        \"\"\"Initialise the logger.\n\n        logger is a logger object to be used for logging.\n        log_format is a string with apache compatible log format description.\n\n        \"\"\"\n        super().__init__(logger, log_format=log_format)\n\n        _compiled_format = AccessLogger._FORMAT_CACHE.get(log_format)\n        if not _compiled_format:\n            _compiled_format = self.compile_format(log_format)\n            AccessLogger._FORMAT_CACHE[log_format] = _compiled_format\n\n        self._log_format, self._methods = _compiled_format\n\n    def compile_format(self, log_format: str) -> Tuple[str, List[KeyMethod]]:\n        \"\"\"Translate log_format into form usable by modulo formatting\n\n        All known atoms will be replaced with %s\n        Also methods for formatting of those atoms will be added to\n        _methods in appropriate order\n\n        For example we have log_format = \"%a %t\"\n        This format will be translated to \"%s %s\"\n        Also contents of _methods will be\n        [self._format_a, self._format_t]\n        These method will be called and results will be passed\n        to translated string format.\n\n        Each _format_* method receive 'args' which is list of arguments\n        given to self.log\n\n        Exceptions are _format_e, _format_i and _format_o methods which\n        also receive key name (by functools.partial)\n\n        \"\"\"\n        # list of (key, method) tuples, we don't use an OrderedDict as users\n        # can repeat the same key more than once\n        methods = list()\n\n        for atom in self.FORMAT_RE.findall(log_format):\n            if atom[1] == \"\":\n                format_key1 = self.LOG_FORMAT_MAP[atom[0]]\n                m = getattr(AccessLogger, \"_format_%s\" % atom[0])\n                key_method = KeyMethod(format_key1, m)\n            else:\n                format_key2 = (self.LOG_FORMAT_MAP[atom[2]], atom[1])\n                m = getattr(AccessLogger, \"_format_%s\" % atom[2])\n                key_method = KeyMethod(format_key2, functools.partial(m, atom[1]))\n\n            methods.append(key_method)\n\n        log_format = self.FORMAT_RE.sub(r\"%s\", log_format)\n        log_format = self.CLEANUP_RE.sub(r\"%\\1\", log_format)\n        return log_format, methods\n\n    @staticmethod\n    def _format_i(\n        key: str, request: BaseRequest, response: StreamResponse, time: float\n    ) -> str:\n        if request is None:\n            return \"(no headers)\"\n\n        # suboptimal, make istr(key) once\n        return request.headers.get(key, \"-\")\n\n    @staticmethod\n    def _format_o(\n        key: str, request: BaseRequest, response: StreamResponse, time: float\n    ) -> str:\n        # suboptimal, make istr(key) once\n        return response.headers.get(key, \"-\")\n\n    @staticmethod\n    def _format_a(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        if request is None:\n            return \"-\"\n        ip = request.remote\n        return ip if ip is not None else \"-\"\n\n    @staticmethod\n    def _format_t(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        now = datetime.datetime.utcnow()\n        start_time = now - datetime.timedelta(seconds=time)\n        return start_time.strftime(\"[%d/%b/%Y:%H:%M:%S +0000]\")\n\n    @staticmethod\n    def _format_P(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return \"<%s>\" % os.getpid()\n\n    @staticmethod\n    def _format_r(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        if request is None:\n            return \"-\"\n        return \"{} {} HTTP/{}.{}\".format(\n            request.method,\n            request.path_qs,\n            request.version.major,\n            request.version.minor,\n        )\n\n    @staticmethod\n    def _format_s(request: BaseRequest, response: StreamResponse, time: float) -> int:\n        return response.status\n\n    @staticmethod\n    def _format_b(request: BaseRequest, response: StreamResponse, time: float) -> int:\n        return response.body_length\n\n    @staticmethod\n    def _format_T(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return str(round(time))\n\n    @staticmethod\n    def _format_Tf(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return \"%06f\" % time\n\n    @staticmethod\n    def _format_D(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return str(round(time * 1000000))\n\n    def _format_line(\n        self, request: BaseRequest, response: StreamResponse, time: float\n    ) -> Iterable[Tuple[str, Callable[[BaseRequest, StreamResponse, float], str]]]:\n        return [(key, method(request, response, time)) for key, method in self._methods]\n\n    def log(self, request: BaseRequest, response: StreamResponse, time: float) -> None:\n        if not self.logger.isEnabledFor(logging.INFO):\n            # Avoid formatting the log line if it will not be emitted.\n            return\n        try:\n            fmt_info = self._format_line(request, response, time)\n\n            values = list()\n            extra = dict()\n            for key, value in fmt_info:\n                values.append(value)\n\n                if key.__class__ is str:\n                    extra[key] = value\n                else:\n                    k1, k2 = key  # type: ignore[misc]\n                    dct = extra.get(k1, {})  # type: ignore[var-annotated,has-type]\n                    dct[k2] = value  # type: ignore[index,has-type]\n                    extra[k1] = dct  # type: ignore[has-type,assignment]\n\n            self.logger.info(self._log_format % tuple(values), extra=extra)\n        except Exception:\n            self.logger.exception(\"Error in logging\")\n",
            "new_file_content": "import datetime\nimport functools\nimport logging\nimport os\nimport re\nimport time as time_mod\nfrom collections import namedtuple\nfrom typing import Any, Callable, Dict, Iterable, List, Tuple  # noqa\n\nfrom .abc import AbstractAccessLogger\nfrom .web_request import BaseRequest\nfrom .web_response import StreamResponse\n\nKeyMethod = namedtuple(\"KeyMethod\", \"key method\")\n\n\nclass AccessLogger(AbstractAccessLogger):\n    \"\"\"Helper object to log access.\n\n    Usage:\n        log = logging.getLogger(\"spam\")\n        log_format = \"%a %{User-Agent}i\"\n        access_logger = AccessLogger(log, log_format)\n        access_logger.log(request, response, time)\n\n    Format:\n        %%  The percent sign\n        %a  Remote IP-address (IP-address of proxy if using reverse proxy)\n        %t  Time when the request was started to process\n        %P  The process ID of the child that serviced the request\n        %r  First line of request\n        %s  Response status code\n        %b  Size of response in bytes, including HTTP headers\n        %T  Time taken to serve the request, in seconds\n        %Tf Time taken to serve the request, in seconds with floating fraction\n            in .06f format\n        %D  Time taken to serve the request, in microseconds\n        %{FOO}i  request.headers['FOO']\n        %{FOO}o  response.headers['FOO']\n        %{FOO}e  os.environ['FOO']\n\n    \"\"\"\n\n    LOG_FORMAT_MAP = {\n        \"a\": \"remote_address\",\n        \"t\": \"request_start_time\",\n        \"P\": \"process_id\",\n        \"r\": \"first_request_line\",\n        \"s\": \"response_status\",\n        \"b\": \"response_size\",\n        \"T\": \"request_time\",\n        \"Tf\": \"request_time_frac\",\n        \"D\": \"request_time_micro\",\n        \"i\": \"request_header\",\n        \"o\": \"response_header\",\n    }\n\n    LOG_FORMAT = '%a %t \"%r\" %s %b \"%{Referer}i\" \"%{User-Agent}i\"'\n    FORMAT_RE = re.compile(r\"%(\\{([A-Za-z0-9\\-_]+)\\}([ioe])|[atPrsbOD]|Tf?)\")\n    CLEANUP_RE = re.compile(r\"(%[^s])\")\n    _FORMAT_CACHE: Dict[str, Tuple[str, List[KeyMethod]]] = {}\n\n    def __init__(self, logger: logging.Logger, log_format: str = LOG_FORMAT) -> None:\n        \"\"\"Initialise the logger.\n\n        logger is a logger object to be used for logging.\n        log_format is a string with apache compatible log format description.\n\n        \"\"\"\n        super().__init__(logger, log_format=log_format)\n\n        _compiled_format = AccessLogger._FORMAT_CACHE.get(log_format)\n        if not _compiled_format:\n            _compiled_format = self.compile_format(log_format)\n            AccessLogger._FORMAT_CACHE[log_format] = _compiled_format\n\n        self._log_format, self._methods = _compiled_format\n\n    def compile_format(self, log_format: str) -> Tuple[str, List[KeyMethod]]:\n        \"\"\"Translate log_format into form usable by modulo formatting\n\n        All known atoms will be replaced with %s\n        Also methods for formatting of those atoms will be added to\n        _methods in appropriate order\n\n        For example we have log_format = \"%a %t\"\n        This format will be translated to \"%s %s\"\n        Also contents of _methods will be\n        [self._format_a, self._format_t]\n        These method will be called and results will be passed\n        to translated string format.\n\n        Each _format_* method receive 'args' which is list of arguments\n        given to self.log\n\n        Exceptions are _format_e, _format_i and _format_o methods which\n        also receive key name (by functools.partial)\n\n        \"\"\"\n        # list of (key, method) tuples, we don't use an OrderedDict as users\n        # can repeat the same key more than once\n        methods = list()\n\n        for atom in self.FORMAT_RE.findall(log_format):\n            if atom[1] == \"\":\n                format_key1 = self.LOG_FORMAT_MAP[atom[0]]\n                m = getattr(AccessLogger, \"_format_%s\" % atom[0])\n                key_method = KeyMethod(format_key1, m)\n            else:\n                format_key2 = (self.LOG_FORMAT_MAP[atom[2]], atom[1])\n                m = getattr(AccessLogger, \"_format_%s\" % atom[2])\n                key_method = KeyMethod(format_key2, functools.partial(m, atom[1]))\n\n            methods.append(key_method)\n\n        log_format = self.FORMAT_RE.sub(r\"%s\", log_format)\n        log_format = self.CLEANUP_RE.sub(r\"%\\1\", log_format)\n        return log_format, methods\n\n    @staticmethod\n    def _format_i(\n        key: str, request: BaseRequest, response: StreamResponse, time: float\n    ) -> str:\n        if request is None:\n            return \"(no headers)\"\n\n        # suboptimal, make istr(key) once\n        return request.headers.get(key, \"-\")\n\n    @staticmethod\n    def _format_o(\n        key: str, request: BaseRequest, response: StreamResponse, time: float\n    ) -> str:\n        # suboptimal, make istr(key) once\n        return response.headers.get(key, \"-\")\n\n    @staticmethod\n    def _format_a(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        if request is None:\n            return \"-\"\n        ip = request.remote\n        return ip if ip is not None else \"-\"\n\n    @staticmethod\n    def _format_t(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        tz = datetime.timezone(datetime.timedelta(seconds=-time_mod.timezone))\n        now = datetime.datetime.now(tz)\n        start_time = now - datetime.timedelta(seconds=time)\n        return start_time.strftime(\"[%d/%b/%Y:%H:%M:%S %z]\")\n\n    @staticmethod\n    def _format_P(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return \"<%s>\" % os.getpid()\n\n    @staticmethod\n    def _format_r(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        if request is None:\n            return \"-\"\n        return \"{} {} HTTP/{}.{}\".format(\n            request.method,\n            request.path_qs,\n            request.version.major,\n            request.version.minor,\n        )\n\n    @staticmethod\n    def _format_s(request: BaseRequest, response: StreamResponse, time: float) -> int:\n        return response.status\n\n    @staticmethod\n    def _format_b(request: BaseRequest, response: StreamResponse, time: float) -> int:\n        return response.body_length\n\n    @staticmethod\n    def _format_T(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return str(round(time))\n\n    @staticmethod\n    def _format_Tf(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return \"%06f\" % time\n\n    @staticmethod\n    def _format_D(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return str(round(time * 1000000))\n\n    def _format_line(\n        self, request: BaseRequest, response: StreamResponse, time: float\n    ) -> Iterable[Tuple[str, Callable[[BaseRequest, StreamResponse, float], str]]]:\n        return [(key, method(request, response, time)) for key, method in self._methods]\n\n    def log(self, request: BaseRequest, response: StreamResponse, time: float) -> None:\n        if not self.logger.isEnabledFor(logging.INFO):\n            # Avoid formatting the log line if it will not be emitted.\n            return\n        try:\n            fmt_info = self._format_line(request, response, time)\n\n            values = list()\n            extra = dict()\n            for key, value in fmt_info:\n                values.append(value)\n\n                if key.__class__ is str:\n                    extra[key] = value\n                else:\n                    k1, k2 = key  # type: ignore[misc]\n                    dct = extra.get(k1, {})  # type: ignore[var-annotated,has-type]\n                    dct[k2] = value  # type: ignore[index,has-type]\n                    extra[k1] = dct  # type: ignore[has-type,assignment]\n\n            self.logger.info(self._log_format % tuple(values), extra=extra)\n        except Exception:\n            self.logger.exception(\"Error in logging\")\n",
            "header": {
                "file": {
                    "path": "aiohttp/web_log.py"
                },
                "misc_line": null
            },
            "index_line": {
                "old_commit_hash": "abc0bf9a",
                "new_commit_hash": "633e9e3a",
                "mode": "100644"
            },
            "is_binary_file": false,
            "binary_line": null,
            "minus_file": {
                "path": "a/aiohttp/web_log.py"
            },
            "plus_file": {
                "path": "b/aiohttp/web_log.py"
            },
            "hunks": [
                {
                    "descriptor": {
                        "old_range": {
                            "start": 3,
                            "length": 6
                        },
                        "new_range": {
                            "start": 3,
                            "length": 7
                        },
                        "section": "import functools"
                    },
                    "line_group": {
                        "all_lines": [
                            {
                                "content": "import logging",
                                "type": "context"
                            },
                            {
                                "content": "import os",
                                "type": "context"
                            },
                            {
                                "content": "import re",
                                "type": "context"
                            },
                            {
                                "content": "import time as time_mod",
                                "type": "added"
                            },
                            {
                                "content": "from collections import namedtuple",
                                "type": "context"
                            },
                            {
                                "content": "from typing import Any, Callable, Dict, Iterable, List, Tuple  # noqa",
                                "type": "context"
                            },
                            {
                                "content": "",
                                "type": "context"
                            }
                        ]
                    },
                    "modified_entities": [],
                    "added_entities": [
                        {
                            "file_name": "aiohttp/web_log.py",
                            "type": "import",
                            "name": "time",
                            "content": "import time as time_mod",
                            "ast_type_str": "Import",
                            "start_lineno": 6,
                            "end_lineno": 6,
                            "parent": null
                        }
                    ],
                    "deleted_entities": []
                },
                {
                    "descriptor": {
                        "old_range": {
                            "start": 142,
                            "length": 9
                        },
                        "new_range": {
                            "start": 143,
                            "length": 10
                        },
                        "section": "class AccessLogger(AbstractAccessLogger):"
                    },
                    "line_group": {
                        "all_lines": [
                            {
                                "content": "",
                                "type": "context"
                            },
                            {
                                "content": "    @staticmethod",
                                "type": "context"
                            },
                            {
                                "content": "    def _format_t(request: BaseRequest, response: StreamResponse, time: float) -> str:",
                                "type": "context"
                            },
                            {
                                "content": "        now = datetime.datetime.utcnow()",
                                "type": "deleted"
                            },
                            {
                                "content": "        tz = datetime.timezone(datetime.timedelta(seconds=-time_mod.timezone))",
                                "type": "added"
                            },
                            {
                                "content": "        now = datetime.datetime.now(tz)",
                                "type": "added"
                            },
                            {
                                "content": "        start_time = now - datetime.timedelta(seconds=time)",
                                "type": "context"
                            },
                            {
                                "content": "        return start_time.strftime(\"[%d/%b/%Y:%H:%M:%S +0000]\")",
                                "type": "deleted"
                            },
                            {
                                "content": "        return start_time.strftime(\"[%d/%b/%Y:%H:%M:%S %z]\")",
                                "type": "added"
                            },
                            {
                                "content": "",
                                "type": "context"
                            },
                            {
                                "content": "    @staticmethod",
                                "type": "context"
                            },
                            {
                                "content": "    def _format_P(request: BaseRequest, response: StreamResponse, time: float) -> str:",
                                "type": "context"
                            }
                        ]
                    },
                    "modified_entities": [
                        {
                            "file_name": "aiohttp/web_log.py",
                            "type": "method",
                            "name": "AccessLogger._format_t",
                            "content": "class AccessLogger(AbstractAccessLogger):\n    \"\"\"Helper object to log access.\n\n    Usage:\n        log = logging.getLogger(\"spam\")\n        log_format = \"%a %{User-Agent}i\"\n        access_logger = AccessLogger(log, log_format)\n        access_logger.log(request, response, time)\n\n    Format:\n        %%  The percent sign\n        %a  Remote IP-address (IP-address of proxy if using reverse proxy)\n        %t  Time when the request was started to process\n        %P  The process ID of the child that serviced the request\n        %r  First line of request\n        %s  Response status code\n        %b  Size of response in bytes, including HTTP headers\n        %T  Time taken to serve the request, in seconds\n        %Tf Time taken to serve the request, in seconds with floating fraction\n            in .06f format\n        %D  Time taken to serve the request, in microseconds\n        %{FOO}i  request.headers['FOO']\n        %{FOO}o  response.headers['FOO']\n        %{FOO}e  os.environ['FOO']\n\n    \"\"\"\n\n    LOG_FORMAT_MAP = {\n        \"a\": \"remote_address\",\n        \"t\": \"request_start_time\",\n        \"P\": \"process_id\",\n        \"r\": \"first_request_line\",\n        \"s\": \"response_status\",\n        \"b\": \"response_size\",\n        \"T\": \"request_time\",\n        \"Tf\": \"request_time_frac\",\n        \"D\": \"request_time_micro\",\n        \"i\": \"request_header\",\n        \"o\": \"response_header\",\n    }\n\n    LOG_FORMAT = '%a %t \"%r\" %s %b \"%{Referer}i\" \"%{User-Agent}i\"'\n    FORMAT_RE = re.compile(r\"%(\\{([A-Za-z0-9\\-_]+)\\}([ioe])|[atPrsbOD]|Tf?)\")\n    CLEANUP_RE = re.compile(r\"(%[^s])\")\n    _FORMAT_CACHE: Dict[str, Tuple[str, List[KeyMethod]]] = {}\n\n    def __init__(self, logger: logging.Logger, log_format: str = LOG_FORMAT) -> None:\n        \"\"\"Initialise the logger.\n\n        logger is a logger object to be used for logging.\n        log_format is a string with apache compatible log format description.\n\n        \"\"\"\n        super().__init__(logger, log_format=log_format)\n\n        _compiled_format = AccessLogger._FORMAT_CACHE.get(log_format)\n        if not _compiled_format:\n            _compiled_format = self.compile_format(log_format)\n            AccessLogger._FORMAT_CACHE[log_format] = _compiled_format\n\n        self._log_format, self._methods = _compiled_format\n\n    def compile_format(self, log_format: str) -> Tuple[str, List[KeyMethod]]:\n        \"\"\"Translate log_format into form usable by modulo formatting\n\n        All known atoms will be replaced with %s\n        Also methods for formatting of those atoms will be added to\n        _methods in appropriate order\n\n        For example we have log_format = \"%a %t\"\n        This format will be translated to \"%s %s\"\n        Also contents of _methods will be\n        [self._format_a, self._format_t]\n        These method will be called and results will be passed\n        to translated string format.\n\n        Each _format_* method receive 'args' which is list of arguments\n        given to self.log\n\n        Exceptions are _format_e, _format_i and _format_o methods which\n        also receive key name (by functools.partial)\n\n        \"\"\"\n        # list of (key, method) tuples, we don't use an OrderedDict as users\n        # can repeat the same key more than once\n        methods = list()\n\n        for atom in self.FORMAT_RE.findall(log_format):\n            if atom[1] == \"\":\n                format_key1 = self.LOG_FORMAT_MAP[atom[0]]\n                m = getattr(AccessLogger, \"_format_%s\" % atom[0])\n                key_method = KeyMethod(format_key1, m)\n            else:\n                format_key2 = (self.LOG_FORMAT_MAP[atom[2]], atom[1])\n                m = getattr(AccessLogger, \"_format_%s\" % atom[2])\n                key_method = KeyMethod(format_key2, functools.partial(m, atom[1]))\n\n            methods.append(key_method)\n\n        log_format = self.FORMAT_RE.sub(r\"%s\", log_format)\n        log_format = self.CLEANUP_RE.sub(r\"%\\1\", log_format)\n        return log_format, methods\n\n    @staticmethod\n    def _format_i(\n        key: str, request: BaseRequest, response: StreamResponse, time: float\n    ) -> str:\n        if request is None:\n            return \"(no headers)\"\n\n        # suboptimal, make istr(key) once\n        return request.headers.get(key, \"-\")\n\n    @staticmethod\n    def _format_o(\n        key: str, request: BaseRequest, response: StreamResponse, time: float\n    ) -> str:\n        # suboptimal, make istr(key) once\n        return response.headers.get(key, \"-\")\n\n    @staticmethod\n    def _format_a(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        if request is None:\n            return \"-\"\n        ip = request.remote\n        return ip if ip is not None else \"-\"\n\n    @staticmethod\n    def _format_t(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        now = datetime.datetime.utcnow()\n        start_time = now - datetime.timedelta(seconds=time)\n        return start_time.strftime(\"[%d/%b/%Y:%H:%M:%S +0000]\")\n\n    @staticmethod\n    def _format_P(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return \"<%s>\" % os.getpid()\n\n    @staticmethod\n    def _format_r(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        if request is None:\n            return \"-\"\n        return \"{} {} HTTP/{}.{}\".format(\n            request.method,\n            request.path_qs,\n            request.version.major,\n            request.version.minor,\n        )\n\n    @staticmethod\n    def _format_s(request: BaseRequest, response: StreamResponse, time: float) -> int:\n        return response.status\n\n    @staticmethod\n    def _format_b(request: BaseRequest, response: StreamResponse, time: float) -> int:\n        return response.body_length\n\n    @staticmethod\n    def _format_T(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return str(round(time))\n\n    @staticmethod\n    def _format_Tf(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return \"%06f\" % time\n\n    @staticmethod\n    def _format_D(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return str(round(time * 1000000))\n\n    def _format_line(\n        self, request: BaseRequest, response: StreamResponse, time: float\n    ) -> Iterable[Tuple[str, Callable[[BaseRequest, StreamResponse, float], str]]]:\n        return [(key, method(request, response, time)) for key, method in self._methods]\n\n    def log(self, request: BaseRequest, response: StreamResponse, time: float) -> None:\n        if not self.logger.isEnabledFor(logging.INFO):\n            # Avoid formatting the log line if it will not be emitted.\n            return\n        try:\n            fmt_info = self._format_line(request, response, time)\n\n            values = list()\n            extra = dict()\n            for key, value in fmt_info:\n                values.append(value)\n\n                if key.__class__ is str:\n                    extra[key] = value\n                else:\n                    k1, k2 = key  # type: ignore[misc]\n                    dct = extra.get(k1, {})  # type: ignore[var-annotated,has-type]\n                    dct[k2] = value  # type: ignore[index,has-type]\n                    extra[k1] = dct  # type: ignore[has-type,assignment]\n\n            self.logger.info(self._log_format % tuple(values), extra=extra)\n        except Exception:\n            self.logger.exception(\"Error in logging\")",
                            "ast_type_str": "ClassDef",
                            "start_lineno": 144,
                            "end_lineno": 147,
                            "parent": {
                                "file_name": "aiohttp/web_log.py",
                                "type": "class",
                                "name": "AccessLogger",
                                "content": "class AccessLogger(AbstractAccessLogger):\n    \"\"\"Helper object to log access.\n\n    Usage:\n        log = logging.getLogger(\"spam\")\n        log_format = \"%a %{User-Agent}i\"\n        access_logger = AccessLogger(log, log_format)\n        access_logger.log(request, response, time)\n\n    Format:\n        %%  The percent sign\n        %a  Remote IP-address (IP-address of proxy if using reverse proxy)\n        %t  Time when the request was started to process\n        %P  The process ID of the child that serviced the request\n        %r  First line of request\n        %s  Response status code\n        %b  Size of response in bytes, including HTTP headers\n        %T  Time taken to serve the request, in seconds\n        %Tf Time taken to serve the request, in seconds with floating fraction\n            in .06f format\n        %D  Time taken to serve the request, in microseconds\n        %{FOO}i  request.headers['FOO']\n        %{FOO}o  response.headers['FOO']\n        %{FOO}e  os.environ['FOO']\n\n    \"\"\"\n\n    LOG_FORMAT_MAP = {\n        \"a\": \"remote_address\",\n        \"t\": \"request_start_time\",\n        \"P\": \"process_id\",\n        \"r\": \"first_request_line\",\n        \"s\": \"response_status\",\n        \"b\": \"response_size\",\n        \"T\": \"request_time\",\n        \"Tf\": \"request_time_frac\",\n        \"D\": \"request_time_micro\",\n        \"i\": \"request_header\",\n        \"o\": \"response_header\",\n    }\n\n    LOG_FORMAT = '%a %t \"%r\" %s %b \"%{Referer}i\" \"%{User-Agent}i\"'\n    FORMAT_RE = re.compile(r\"%(\\{([A-Za-z0-9\\-_]+)\\}([ioe])|[atPrsbOD]|Tf?)\")\n    CLEANUP_RE = re.compile(r\"(%[^s])\")\n    _FORMAT_CACHE: Dict[str, Tuple[str, List[KeyMethod]]] = {}\n\n    def __init__(self, logger: logging.Logger, log_format: str = LOG_FORMAT) -> None:\n        \"\"\"Initialise the logger.\n\n        logger is a logger object to be used for logging.\n        log_format is a string with apache compatible log format description.\n\n        \"\"\"\n        super().__init__(logger, log_format=log_format)\n\n        _compiled_format = AccessLogger._FORMAT_CACHE.get(log_format)\n        if not _compiled_format:\n            _compiled_format = self.compile_format(log_format)\n            AccessLogger._FORMAT_CACHE[log_format] = _compiled_format\n\n        self._log_format, self._methods = _compiled_format\n\n    def compile_format(self, log_format: str) -> Tuple[str, List[KeyMethod]]:\n        \"\"\"Translate log_format into form usable by modulo formatting\n\n        All known atoms will be replaced with %s\n        Also methods for formatting of those atoms will be added to\n        _methods in appropriate order\n\n        For example we have log_format = \"%a %t\"\n        This format will be translated to \"%s %s\"\n        Also contents of _methods will be\n        [self._format_a, self._format_t]\n        These method will be called and results will be passed\n        to translated string format.\n\n        Each _format_* method receive 'args' which is list of arguments\n        given to self.log\n\n        Exceptions are _format_e, _format_i and _format_o methods which\n        also receive key name (by functools.partial)\n\n        \"\"\"\n        # list of (key, method) tuples, we don't use an OrderedDict as users\n        # can repeat the same key more than once\n        methods = list()\n\n        for atom in self.FORMAT_RE.findall(log_format):\n            if atom[1] == \"\":\n                format_key1 = self.LOG_FORMAT_MAP[atom[0]]\n                m = getattr(AccessLogger, \"_format_%s\" % atom[0])\n                key_method = KeyMethod(format_key1, m)\n            else:\n                format_key2 = (self.LOG_FORMAT_MAP[atom[2]], atom[1])\n                m = getattr(AccessLogger, \"_format_%s\" % atom[2])\n                key_method = KeyMethod(format_key2, functools.partial(m, atom[1]))\n\n            methods.append(key_method)\n\n        log_format = self.FORMAT_RE.sub(r\"%s\", log_format)\n        log_format = self.CLEANUP_RE.sub(r\"%\\1\", log_format)\n        return log_format, methods\n\n    @staticmethod\n    def _format_i(\n        key: str, request: BaseRequest, response: StreamResponse, time: float\n    ) -> str:\n        if request is None:\n            return \"(no headers)\"\n\n        # suboptimal, make istr(key) once\n        return request.headers.get(key, \"-\")\n\n    @staticmethod\n    def _format_o(\n        key: str, request: BaseRequest, response: StreamResponse, time: float\n    ) -> str:\n        # suboptimal, make istr(key) once\n        return response.headers.get(key, \"-\")\n\n    @staticmethod\n    def _format_a(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        if request is None:\n            return \"-\"\n        ip = request.remote\n        return ip if ip is not None else \"-\"\n\n    @staticmethod\n    def _format_t(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        now = datetime.datetime.utcnow()\n        start_time = now - datetime.timedelta(seconds=time)\n        return start_time.strftime(\"[%d/%b/%Y:%H:%M:%S +0000]\")\n\n    @staticmethod\n    def _format_P(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return \"<%s>\" % os.getpid()\n\n    @staticmethod\n    def _format_r(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        if request is None:\n            return \"-\"\n        return \"{} {} HTTP/{}.{}\".format(\n            request.method,\n            request.path_qs,\n            request.version.major,\n            request.version.minor,\n        )\n\n    @staticmethod\n    def _format_s(request: BaseRequest, response: StreamResponse, time: float) -> int:\n        return response.status\n\n    @staticmethod\n    def _format_b(request: BaseRequest, response: StreamResponse, time: float) -> int:\n        return response.body_length\n\n    @staticmethod\n    def _format_T(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return str(round(time))\n\n    @staticmethod\n    def _format_Tf(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return \"%06f\" % time\n\n    @staticmethod\n    def _format_D(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return str(round(time * 1000000))\n\n    def _format_line(\n        self, request: BaseRequest, response: StreamResponse, time: float\n    ) -> Iterable[Tuple[str, Callable[[BaseRequest, StreamResponse, float], str]]]:\n        return [(key, method(request, response, time)) for key, method in self._methods]\n\n    def log(self, request: BaseRequest, response: StreamResponse, time: float) -> None:\n        if not self.logger.isEnabledFor(logging.INFO):\n            # Avoid formatting the log line if it will not be emitted.\n            return\n        try:\n            fmt_info = self._format_line(request, response, time)\n\n            values = list()\n            extra = dict()\n            for key, value in fmt_info:\n                values.append(value)\n\n                if key.__class__ is str:\n                    extra[key] = value\n                else:\n                    k1, k2 = key  # type: ignore[misc]\n                    dct = extra.get(k1, {})  # type: ignore[var-annotated,has-type]\n                    dct[k2] = value  # type: ignore[index,has-type]\n                    extra[k1] = dct  # type: ignore[has-type,assignment]\n\n            self.logger.info(self._log_format % tuple(values), extra=extra)\n        except Exception:\n            self.logger.exception(\"Error in logging\")",
                                "ast_type_str": "ClassDef",
                                "start_lineno": 16,
                                "end_lineno": 211,
                                "parent": null
                            }
                        },
                        {
                            "file_name": "aiohttp/web_log.py",
                            "type": "class",
                            "name": "AccessLogger",
                            "content": "class AccessLogger(AbstractAccessLogger):\n    \"\"\"Helper object to log access.\n\n    Usage:\n        log = logging.getLogger(\"spam\")\n        log_format = \"%a %{User-Agent}i\"\n        access_logger = AccessLogger(log, log_format)\n        access_logger.log(request, response, time)\n\n    Format:\n        %%  The percent sign\n        %a  Remote IP-address (IP-address of proxy if using reverse proxy)\n        %t  Time when the request was started to process\n        %P  The process ID of the child that serviced the request\n        %r  First line of request\n        %s  Response status code\n        %b  Size of response in bytes, including HTTP headers\n        %T  Time taken to serve the request, in seconds\n        %Tf Time taken to serve the request, in seconds with floating fraction\n            in .06f format\n        %D  Time taken to serve the request, in microseconds\n        %{FOO}i  request.headers['FOO']\n        %{FOO}o  response.headers['FOO']\n        %{FOO}e  os.environ['FOO']\n\n    \"\"\"\n\n    LOG_FORMAT_MAP = {\n        \"a\": \"remote_address\",\n        \"t\": \"request_start_time\",\n        \"P\": \"process_id\",\n        \"r\": \"first_request_line\",\n        \"s\": \"response_status\",\n        \"b\": \"response_size\",\n        \"T\": \"request_time\",\n        \"Tf\": \"request_time_frac\",\n        \"D\": \"request_time_micro\",\n        \"i\": \"request_header\",\n        \"o\": \"response_header\",\n    }\n\n    LOG_FORMAT = '%a %t \"%r\" %s %b \"%{Referer}i\" \"%{User-Agent}i\"'\n    FORMAT_RE = re.compile(r\"%(\\{([A-Za-z0-9\\-_]+)\\}([ioe])|[atPrsbOD]|Tf?)\")\n    CLEANUP_RE = re.compile(r\"(%[^s])\")\n    _FORMAT_CACHE: Dict[str, Tuple[str, List[KeyMethod]]] = {}\n\n    def __init__(self, logger: logging.Logger, log_format: str = LOG_FORMAT) -> None:\n        \"\"\"Initialise the logger.\n\n        logger is a logger object to be used for logging.\n        log_format is a string with apache compatible log format description.\n\n        \"\"\"\n        super().__init__(logger, log_format=log_format)\n\n        _compiled_format = AccessLogger._FORMAT_CACHE.get(log_format)\n        if not _compiled_format:\n            _compiled_format = self.compile_format(log_format)\n            AccessLogger._FORMAT_CACHE[log_format] = _compiled_format\n\n        self._log_format, self._methods = _compiled_format\n\n    def compile_format(self, log_format: str) -> Tuple[str, List[KeyMethod]]:\n        \"\"\"Translate log_format into form usable by modulo formatting\n\n        All known atoms will be replaced with %s\n        Also methods for formatting of those atoms will be added to\n        _methods in appropriate order\n\n        For example we have log_format = \"%a %t\"\n        This format will be translated to \"%s %s\"\n        Also contents of _methods will be\n        [self._format_a, self._format_t]\n        These method will be called and results will be passed\n        to translated string format.\n\n        Each _format_* method receive 'args' which is list of arguments\n        given to self.log\n\n        Exceptions are _format_e, _format_i and _format_o methods which\n        also receive key name (by functools.partial)\n\n        \"\"\"\n        # list of (key, method) tuples, we don't use an OrderedDict as users\n        # can repeat the same key more than once\n        methods = list()\n\n        for atom in self.FORMAT_RE.findall(log_format):\n            if atom[1] == \"\":\n                format_key1 = self.LOG_FORMAT_MAP[atom[0]]\n                m = getattr(AccessLogger, \"_format_%s\" % atom[0])\n                key_method = KeyMethod(format_key1, m)\n            else:\n                format_key2 = (self.LOG_FORMAT_MAP[atom[2]], atom[1])\n                m = getattr(AccessLogger, \"_format_%s\" % atom[2])\n                key_method = KeyMethod(format_key2, functools.partial(m, atom[1]))\n\n            methods.append(key_method)\n\n        log_format = self.FORMAT_RE.sub(r\"%s\", log_format)\n        log_format = self.CLEANUP_RE.sub(r\"%\\1\", log_format)\n        return log_format, methods\n\n    @staticmethod\n    def _format_i(\n        key: str, request: BaseRequest, response: StreamResponse, time: float\n    ) -> str:\n        if request is None:\n            return \"(no headers)\"\n\n        # suboptimal, make istr(key) once\n        return request.headers.get(key, \"-\")\n\n    @staticmethod\n    def _format_o(\n        key: str, request: BaseRequest, response: StreamResponse, time: float\n    ) -> str:\n        # suboptimal, make istr(key) once\n        return response.headers.get(key, \"-\")\n\n    @staticmethod\n    def _format_a(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        if request is None:\n            return \"-\"\n        ip = request.remote\n        return ip if ip is not None else \"-\"\n\n    @staticmethod\n    def _format_t(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        now = datetime.datetime.utcnow()\n        start_time = now - datetime.timedelta(seconds=time)\n        return start_time.strftime(\"[%d/%b/%Y:%H:%M:%S +0000]\")\n\n    @staticmethod\n    def _format_P(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return \"<%s>\" % os.getpid()\n\n    @staticmethod\n    def _format_r(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        if request is None:\n            return \"-\"\n        return \"{} {} HTTP/{}.{}\".format(\n            request.method,\n            request.path_qs,\n            request.version.major,\n            request.version.minor,\n        )\n\n    @staticmethod\n    def _format_s(request: BaseRequest, response: StreamResponse, time: float) -> int:\n        return response.status\n\n    @staticmethod\n    def _format_b(request: BaseRequest, response: StreamResponse, time: float) -> int:\n        return response.body_length\n\n    @staticmethod\n    def _format_T(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return str(round(time))\n\n    @staticmethod\n    def _format_Tf(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return \"%06f\" % time\n\n    @staticmethod\n    def _format_D(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return str(round(time * 1000000))\n\n    def _format_line(\n        self, request: BaseRequest, response: StreamResponse, time: float\n    ) -> Iterable[Tuple[str, Callable[[BaseRequest, StreamResponse, float], str]]]:\n        return [(key, method(request, response, time)) for key, method in self._methods]\n\n    def log(self, request: BaseRequest, response: StreamResponse, time: float) -> None:\n        if not self.logger.isEnabledFor(logging.INFO):\n            # Avoid formatting the log line if it will not be emitted.\n            return\n        try:\n            fmt_info = self._format_line(request, response, time)\n\n            values = list()\n            extra = dict()\n            for key, value in fmt_info:\n                values.append(value)\n\n                if key.__class__ is str:\n                    extra[key] = value\n                else:\n                    k1, k2 = key  # type: ignore[misc]\n                    dct = extra.get(k1, {})  # type: ignore[var-annotated,has-type]\n                    dct[k2] = value  # type: ignore[index,has-type]\n                    extra[k1] = dct  # type: ignore[has-type,assignment]\n\n            self.logger.info(self._log_format % tuple(values), extra=extra)\n        except Exception:\n            self.logger.exception(\"Error in logging\")",
                            "ast_type_str": "ClassDef",
                            "start_lineno": 16,
                            "end_lineno": 211,
                            "parent": null
                        }
                    ],
                    "added_entities": [],
                    "deleted_entities": []
                }
            ]
        },
        {
            "old_file_content": "import datetime\nimport logging\nimport platform\nfrom unittest import mock\n\nimport pytest\n\nimport aiohttp\nfrom aiohttp import web\nfrom aiohttp.abc import AbstractAccessLogger\nfrom aiohttp.typedefs import Handler\nfrom aiohttp.web_log import AccessLogger\n\ntry:\n    from contextvars import ContextVar\nexcept ImportError:\n    ContextVar = None\n\n\nIS_PYPY = platform.python_implementation() == \"PyPy\"\n\n\ndef test_access_logger_format() -> None:\n    log_format = '%T \"%{ETag}o\" %X {X} %%P'\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    expected = '%s \"%s\" %%X {X} %%%s'\n    assert expected == access_logger._log_format\n\n\n@pytest.mark.skipif(\n    IS_PYPY,\n    reason=\"\"\"\n    Because of patching :py:class:`datetime.datetime`, under PyPy it\n    fails in :py:func:`isinstance` call in\n    :py:meth:`datetime.datetime.__sub__` (called from\n    :py:meth:`aiohttp.AccessLogger._format_t`):\n\n    *** TypeError: isinstance() arg 2 must be a class, type, or tuple of classes and types\n\n    (Pdb) from datetime import datetime\n    (Pdb) isinstance(now, datetime)\n    *** TypeError: isinstance() arg 2 must be a class, type, or tuple of classes and types\n    (Pdb) datetime.__class__\n    <class 'unittest.mock.MagicMock'>\n    (Pdb) isinstance(now, datetime.__class__)\n    False\n\n    Ref: https://bitbucket.org/pypy/pypy/issues/1187/call-to-isinstance-in-__sub__-self-other\n    Ref: https://github.com/celery/celery/issues/811\n    Ref: https://stackoverflow.com/a/46102240/595220\n    \"\"\",\n)\ndef test_access_logger_atoms(mocker) -> None:\n    utcnow = datetime.datetime(1843, 1, 1, 0, 30)\n    mock_datetime = mocker.patch(\"datetime.datetime\")\n    mock_getpid = mocker.patch(\"os.getpid\")\n    mock_datetime.utcnow.return_value = utcnow\n    mock_getpid.return_value = 42\n    log_format = '%a %t %P %r %s %b %T %Tf %D \"%{H1}i\" \"%{H2}i\"'\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    request = mock.Mock(\n        headers={\"H1\": \"a\", \"H2\": \"b\"},\n        method=\"GET\",\n        path_qs=\"/path\",\n        version=aiohttp.HttpVersion(1, 1),\n        remote=\"127.0.0.2\",\n    )\n    response = mock.Mock(headers={}, body_length=42, status=200)\n    access_logger.log(request, response, 3.1415926)\n    assert not mock_logger.exception.called\n    expected = (\n        \"127.0.0.2 [01/Jan/1843:00:29:56 +0000] <42> \"\n        'GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"'\n    )\n    extra = {\n        \"first_request_line\": \"GET /path HTTP/1.1\",\n        \"process_id\": \"<42>\",\n        \"remote_address\": \"127.0.0.2\",\n        \"request_start_time\": \"[01/Jan/1843:00:29:56 +0000]\",\n        \"request_time\": \"3\",\n        \"request_time_frac\": \"3.141593\",\n        \"request_time_micro\": \"3141593\",\n        \"response_size\": 42,\n        \"response_status\": 200,\n        \"request_header\": {\"H1\": \"a\", \"H2\": \"b\"},\n    }\n\n    mock_logger.info.assert_called_with(expected, extra=extra)\n\n\ndef test_access_logger_dicts() -> None:\n    log_format = \"%{User-Agent}i %{Content-Length}o %{None}i\"\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    request = mock.Mock(\n        headers={\"User-Agent\": \"Mock/1.0\"}, version=(1, 1), remote=\"127.0.0.2\"\n    )\n    response = mock.Mock(headers={\"Content-Length\": 123})\n    access_logger.log(request, response, 0.0)\n    assert not mock_logger.error.called\n    expected = \"Mock/1.0 123 -\"\n    extra = {\n        \"request_header\": {\"User-Agent\": \"Mock/1.0\", \"None\": \"-\"},\n        \"response_header\": {\"Content-Length\": 123},\n    }\n\n    mock_logger.info.assert_called_with(expected, extra=extra)\n\n\ndef test_access_logger_unix_socket() -> None:\n    log_format = \"|%a|\"\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    request = mock.Mock(headers={\"User-Agent\": \"Mock/1.0\"}, version=(1, 1), remote=\"\")\n    response = mock.Mock()\n    access_logger.log(request, response, 0.0)\n    assert not mock_logger.error.called\n    expected = \"||\"\n    mock_logger.info.assert_called_with(expected, extra={\"remote_address\": \"\"})\n\n\ndef test_logger_no_message() -> None:\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, \"%r %{content-type}i\")\n    extra_dict = {\n        \"first_request_line\": \"-\",\n        \"request_header\": {\"content-type\": \"(no headers)\"},\n    }\n\n    access_logger.log(None, None, 0.0)\n    mock_logger.info.assert_called_with(\"- (no headers)\", extra=extra_dict)\n\n\ndef test_logger_internal_error() -> None:\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, \"%D\")\n    access_logger.log(None, None, \"invalid\")\n    mock_logger.exception.assert_called_with(\"Error in logging\")\n\n\ndef test_logger_no_transport() -> None:\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, \"%a\")\n    access_logger.log(None, None, 0)\n    mock_logger.info.assert_called_with(\"-\", extra={\"remote_address\": \"-\"})\n\n\ndef test_logger_abc() -> None:\n    class Logger(AbstractAccessLogger):\n        def log(self, request, response, time):\n            1 / 0\n\n    mock_logger = mock.Mock()\n    access_logger = Logger(mock_logger, None)\n\n    with pytest.raises(ZeroDivisionError):\n        access_logger.log(None, None, None)\n\n    class Logger(AbstractAccessLogger):\n        def log(self, request, response, time):\n            self.logger.info(\n                self.log_format.format(request=request, response=response, time=time)\n            )\n\n    mock_logger = mock.Mock()\n    access_logger = Logger(mock_logger, \"{request} {response} {time}\")\n    access_logger.log(\"request\", \"response\", 1)\n    mock_logger.info.assert_called_with(\"request response 1\")\n\n\nasync def test_contextvars_logger(aiohttp_server, aiohttp_client):\n    VAR = ContextVar(\"VAR\")\n\n    async def handler(request):\n        return web.Response()\n\n    @web.middleware\n    async def middleware(request, handler: Handler):\n        VAR.set(\"uuid\")\n        return await handler(request)\n\n    msg = None\n\n    class Logger(AbstractAccessLogger):\n        def log(self, request, response, time):\n            nonlocal msg\n            msg = f\"contextvars: {VAR.get()}\"\n\n    app = web.Application(middlewares=[middleware])\n    app.router.add_get(\"/\", handler)\n    server = await aiohttp_server(app, access_log_class=Logger)\n    client = await aiohttp_client(server)\n    resp = await client.get(\"/\")\n    assert 200 == resp.status\n    assert msg == \"contextvars: uuid\"\n\n\ndef test_logger_does_nothing_when_disabled(caplog: pytest.LogCaptureFixture) -> None:\n    \"\"\"Test that the logger does nothing when the log level is disabled.\"\"\"\n    mock_logger = logging.getLogger(\"test.aiohttp.log\")\n    mock_logger.setLevel(logging.INFO)\n    access_logger = AccessLogger(mock_logger, \"%b\")\n    access_logger.log(\n        mock.Mock(name=\"mock_request\"), mock.Mock(name=\"mock_response\"), 42\n    )\n    assert \"mock_response\" in caplog.text\n",
            "new_file_content": "import datetime\nimport logging\nimport platform\nfrom typing import Any\nfrom unittest import mock\n\nimport pytest\n\nimport aiohttp\nfrom aiohttp import web\nfrom aiohttp.abc import AbstractAccessLogger\nfrom aiohttp.typedefs import Handler\nfrom aiohttp.web_log import AccessLogger\n\ntry:\n    from contextvars import ContextVar\nexcept ImportError:\n    ContextVar = None\n\n\nIS_PYPY = platform.python_implementation() == \"PyPy\"\n\n\ndef test_access_logger_format() -> None:\n    log_format = '%T \"%{ETag}o\" %X {X} %%P'\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    expected = '%s \"%s\" %%X {X} %%%s'\n    assert expected == access_logger._log_format\n\n\n@pytest.mark.skipif(\n    IS_PYPY,\n    reason=\"\"\"\n    Because of patching :py:class:`datetime.datetime`, under PyPy it\n    fails in :py:func:`isinstance` call in\n    :py:meth:`datetime.datetime.__sub__` (called from\n    :py:meth:`aiohttp.AccessLogger._format_t`):\n\n    *** TypeError: isinstance() arg 2 must be a class, type, or tuple of classes and types\n\n    (Pdb) from datetime import datetime\n    (Pdb) isinstance(now, datetime)\n    *** TypeError: isinstance() arg 2 must be a class, type, or tuple of classes and types\n    (Pdb) datetime.__class__\n    <class 'unittest.mock.MagicMock'>\n    (Pdb) isinstance(now, datetime.__class__)\n    False\n\n    Ref: https://bitbucket.org/pypy/pypy/issues/1187/call-to-isinstance-in-__sub__-self-other\n    Ref: https://github.com/celery/celery/issues/811\n    Ref: https://stackoverflow.com/a/46102240/595220\n    \"\"\",\n)\n@pytest.mark.parametrize(\n    \"log_format,expected,extra\",\n    [\n        (\n            \"%t\",\n            \"[01/Jan/1843:00:29:56 +0800]\",\n            {\"request_start_time\": \"[01/Jan/1843:00:29:56 +0800]\"},\n        ),\n        (\n            '%a %t %P %r %s %b %T %Tf %D \"%{H1}i\" \"%{H2}i\"',\n            (\n                \"127.0.0.2 [01/Jan/1843:00:29:56 +0800] <42> \"\n                'GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"'\n            ),\n            {\n                \"first_request_line\": \"GET /path HTTP/1.1\",\n                \"process_id\": \"<42>\",\n                \"remote_address\": \"127.0.0.2\",\n                \"request_start_time\": \"[01/Jan/1843:00:29:56 +0800]\",\n                \"request_time\": \"3\",\n                \"request_time_frac\": \"3.141593\",\n                \"request_time_micro\": \"3141593\",\n                \"response_size\": 42,\n                \"response_status\": 200,\n                \"request_header\": {\"H1\": \"a\", \"H2\": \"b\"},\n            },\n        ),\n    ],\n)\ndef test_access_logger_atoms(\n    monkeypatch: Any, log_format: Any, expected: Any, extra: Any\n) -> None:\n    class PatchedDatetime(datetime.datetime):\n        @staticmethod\n        def now(tz):\n            return datetime.datetime(1843, 1, 1, 0, 30, tzinfo=tz)\n\n    monkeypatch.setattr(\"datetime.datetime\", PatchedDatetime)\n    monkeypatch.setattr(\"time.timezone\", -28800)\n    monkeypatch.setattr(\"os.getpid\", lambda: 42)\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    request = mock.Mock(\n        headers={\"H1\": \"a\", \"H2\": \"b\"},\n        method=\"GET\",\n        path_qs=\"/path\",\n        version=aiohttp.HttpVersion(1, 1),\n        remote=\"127.0.0.2\",\n    )\n    response = mock.Mock(headers={}, body_length=42, status=200)\n    access_logger.log(request, response, 3.1415926)\n    assert not mock_logger.exception.called, mock_logger.exception.call_args\n\n    mock_logger.info.assert_called_with(expected, extra=extra)\n\n\ndef test_access_logger_dicts() -> None:\n    log_format = \"%{User-Agent}i %{Content-Length}o %{None}i\"\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    request = mock.Mock(\n        headers={\"User-Agent\": \"Mock/1.0\"}, version=(1, 1), remote=\"127.0.0.2\"\n    )\n    response = mock.Mock(headers={\"Content-Length\": 123})\n    access_logger.log(request, response, 0.0)\n    assert not mock_logger.error.called\n    expected = \"Mock/1.0 123 -\"\n    extra = {\n        \"request_header\": {\"User-Agent\": \"Mock/1.0\", \"None\": \"-\"},\n        \"response_header\": {\"Content-Length\": 123},\n    }\n\n    mock_logger.info.assert_called_with(expected, extra=extra)\n\n\ndef test_access_logger_unix_socket() -> None:\n    log_format = \"|%a|\"\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    request = mock.Mock(headers={\"User-Agent\": \"Mock/1.0\"}, version=(1, 1), remote=\"\")\n    response = mock.Mock()\n    access_logger.log(request, response, 0.0)\n    assert not mock_logger.error.called\n    expected = \"||\"\n    mock_logger.info.assert_called_with(expected, extra={\"remote_address\": \"\"})\n\n\ndef test_logger_no_message() -> None:\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, \"%r %{content-type}i\")\n    extra_dict = {\n        \"first_request_line\": \"-\",\n        \"request_header\": {\"content-type\": \"(no headers)\"},\n    }\n\n    access_logger.log(None, None, 0.0)\n    mock_logger.info.assert_called_with(\"- (no headers)\", extra=extra_dict)\n\n\ndef test_logger_internal_error() -> None:\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, \"%D\")\n    access_logger.log(None, None, \"invalid\")\n    mock_logger.exception.assert_called_with(\"Error in logging\")\n\n\ndef test_logger_no_transport() -> None:\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, \"%a\")\n    access_logger.log(None, None, 0)\n    mock_logger.info.assert_called_with(\"-\", extra={\"remote_address\": \"-\"})\n\n\ndef test_logger_abc() -> None:\n    class Logger(AbstractAccessLogger):\n        def log(self, request, response, time):\n            1 / 0\n\n    mock_logger = mock.Mock()\n    access_logger = Logger(mock_logger, None)\n\n    with pytest.raises(ZeroDivisionError):\n        access_logger.log(None, None, None)\n\n    class Logger(AbstractAccessLogger):\n        def log(self, request, response, time):\n            self.logger.info(\n                self.log_format.format(request=request, response=response, time=time)\n            )\n\n    mock_logger = mock.Mock()\n    access_logger = Logger(mock_logger, \"{request} {response} {time}\")\n    access_logger.log(\"request\", \"response\", 1)\n    mock_logger.info.assert_called_with(\"request response 1\")\n\n\nasync def test_contextvars_logger(aiohttp_server, aiohttp_client):\n    VAR = ContextVar(\"VAR\")\n\n    async def handler(request):\n        return web.Response()\n\n    @web.middleware\n    async def middleware(request, handler: Handler):\n        VAR.set(\"uuid\")\n        return await handler(request)\n\n    msg = None\n\n    class Logger(AbstractAccessLogger):\n        def log(self, request, response, time):\n            nonlocal msg\n            msg = f\"contextvars: {VAR.get()}\"\n\n    app = web.Application(middlewares=[middleware])\n    app.router.add_get(\"/\", handler)\n    server = await aiohttp_server(app, access_log_class=Logger)\n    client = await aiohttp_client(server)\n    resp = await client.get(\"/\")\n    assert 200 == resp.status\n    assert msg == \"contextvars: uuid\"\n\n\ndef test_logger_does_nothing_when_disabled(caplog: pytest.LogCaptureFixture) -> None:\n    \"\"\"Test that the logger does nothing when the log level is disabled.\"\"\"\n    mock_logger = logging.getLogger(\"test.aiohttp.log\")\n    mock_logger.setLevel(logging.INFO)\n    access_logger = AccessLogger(mock_logger, \"%b\")\n    access_logger.log(\n        mock.Mock(name=\"mock_request\"), mock.Mock(name=\"mock_response\"), 42\n    )\n    assert \"mock_response\" in caplog.text\n",
            "header": {
                "file": {
                    "path": "tests/test_web_log.py"
                },
                "misc_line": null
            },
            "index_line": {
                "old_commit_hash": "01d949c4",
                "new_commit_hash": "543ccb9e",
                "mode": "100644"
            },
            "is_binary_file": false,
            "binary_line": null,
            "minus_file": {
                "path": "a/tests/test_web_log.py"
            },
            "plus_file": {
                "path": "b/tests/test_web_log.py"
            },
            "hunks": [
                {
                    "descriptor": {
                        "old_range": {
                            "start": 1,
                            "length": 6
                        },
                        "new_range": {
                            "start": 1,
                            "length": 7
                        },
                        "section": ""
                    },
                    "line_group": {
                        "all_lines": [
                            {
                                "content": "import datetime",
                                "type": "context"
                            },
                            {
                                "content": "import logging",
                                "type": "context"
                            },
                            {
                                "content": "import platform",
                                "type": "context"
                            },
                            {
                                "content": "from typing import Any",
                                "type": "added"
                            },
                            {
                                "content": "from unittest import mock",
                                "type": "context"
                            },
                            {
                                "content": "",
                                "type": "context"
                            },
                            {
                                "content": "import pytest",
                                "type": "context"
                            }
                        ]
                    },
                    "modified_entities": [],
                    "added_entities": [
                        {
                            "file_name": "tests/test_web_log.py",
                            "type": "statement",
                            "name": "",
                            "content": "from typing import Any",
                            "ast_type_str": "ImportFrom",
                            "start_lineno": 4,
                            "end_lineno": 4,
                            "parent": null
                        }
                    ],
                    "deleted_entities": []
                },
                {
                    "descriptor": {
                        "old_range": {
                            "start": 51,
                            "length": 13
                        },
                        "new_range": {
                            "start": 52,
                            "length": 46
                        },
                        "section": "def test_access_logger_format() -> None:"
                    },
                    "line_group": {
                        "all_lines": [
                            {
                                "content": "    Ref: https://stackoverflow.com/a/46102240/595220",
                                "type": "context"
                            },
                            {
                                "content": "    \"\"\",",
                                "type": "context"
                            },
                            {
                                "content": ")",
                                "type": "context"
                            },
                            {
                                "content": "def test_access_logger_atoms(mocker) -> None:",
                                "type": "deleted"
                            },
                            {
                                "content": "    utcnow = datetime.datetime(1843, 1, 1, 0, 30)",
                                "type": "deleted"
                            },
                            {
                                "content": "    mock_datetime = mocker.patch(\"datetime.datetime\")",
                                "type": "deleted"
                            },
                            {
                                "content": "    mock_getpid = mocker.patch(\"os.getpid\")",
                                "type": "deleted"
                            },
                            {
                                "content": "    mock_datetime.utcnow.return_value = utcnow",
                                "type": "deleted"
                            },
                            {
                                "content": "    mock_getpid.return_value = 42",
                                "type": "deleted"
                            },
                            {
                                "content": "    log_format = '%a %t %P %r %s %b %T %Tf %D \"%{H1}i\" \"%{H2}i\"'",
                                "type": "deleted"
                            },
                            {
                                "content": "@pytest.mark.parametrize(",
                                "type": "added"
                            },
                            {
                                "content": "    \"log_format,expected,extra\",",
                                "type": "added"
                            },
                            {
                                "content": "    [",
                                "type": "added"
                            },
                            {
                                "content": "        (",
                                "type": "added"
                            },
                            {
                                "content": "            \"%t\",",
                                "type": "added"
                            },
                            {
                                "content": "            \"[01/Jan/1843:00:29:56 +0800]\",",
                                "type": "added"
                            },
                            {
                                "content": "            {\"request_start_time\": \"[01/Jan/1843:00:29:56 +0800]\"},",
                                "type": "added"
                            },
                            {
                                "content": "        ),",
                                "type": "added"
                            },
                            {
                                "content": "        (",
                                "type": "added"
                            },
                            {
                                "content": "            '%a %t %P %r %s %b %T %Tf %D \"%{H1}i\" \"%{H2}i\"',",
                                "type": "added"
                            },
                            {
                                "content": "            (",
                                "type": "added"
                            },
                            {
                                "content": "                \"127.0.0.2 [01/Jan/1843:00:29:56 +0800] <42> \"",
                                "type": "added"
                            },
                            {
                                "content": "                'GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"'",
                                "type": "added"
                            },
                            {
                                "content": "            ),",
                                "type": "added"
                            },
                            {
                                "content": "            {",
                                "type": "added"
                            },
                            {
                                "content": "                \"first_request_line\": \"GET /path HTTP/1.1\",",
                                "type": "added"
                            },
                            {
                                "content": "                \"process_id\": \"<42>\",",
                                "type": "added"
                            },
                            {
                                "content": "                \"remote_address\": \"127.0.0.2\",",
                                "type": "added"
                            },
                            {
                                "content": "                \"request_start_time\": \"[01/Jan/1843:00:29:56 +0800]\",",
                                "type": "added"
                            },
                            {
                                "content": "                \"request_time\": \"3\",",
                                "type": "added"
                            },
                            {
                                "content": "                \"request_time_frac\": \"3.141593\",",
                                "type": "added"
                            },
                            {
                                "content": "                \"request_time_micro\": \"3141593\",",
                                "type": "added"
                            },
                            {
                                "content": "                \"response_size\": 42,",
                                "type": "added"
                            },
                            {
                                "content": "                \"response_status\": 200,",
                                "type": "added"
                            },
                            {
                                "content": "                \"request_header\": {\"H1\": \"a\", \"H2\": \"b\"},",
                                "type": "added"
                            },
                            {
                                "content": "            },",
                                "type": "added"
                            },
                            {
                                "content": "        ),",
                                "type": "added"
                            },
                            {
                                "content": "    ],",
                                "type": "added"
                            },
                            {
                                "content": ")",
                                "type": "added"
                            },
                            {
                                "content": "def test_access_logger_atoms(",
                                "type": "added"
                            },
                            {
                                "content": "    monkeypatch: Any, log_format: Any, expected: Any, extra: Any",
                                "type": "added"
                            },
                            {
                                "content": ") -> None:",
                                "type": "added"
                            },
                            {
                                "content": "    class PatchedDatetime(datetime.datetime):",
                                "type": "added"
                            },
                            {
                                "content": "        @staticmethod",
                                "type": "added"
                            },
                            {
                                "content": "        def now(tz):",
                                "type": "added"
                            },
                            {
                                "content": "            return datetime.datetime(1843, 1, 1, 0, 30, tzinfo=tz)",
                                "type": "added"
                            },
                            {
                                "content": "",
                                "type": "added"
                            },
                            {
                                "content": "    monkeypatch.setattr(\"datetime.datetime\", PatchedDatetime)",
                                "type": "added"
                            },
                            {
                                "content": "    monkeypatch.setattr(\"time.timezone\", -28800)",
                                "type": "added"
                            },
                            {
                                "content": "    monkeypatch.setattr(\"os.getpid\", lambda: 42)",
                                "type": "added"
                            },
                            {
                                "content": "    mock_logger = mock.Mock()",
                                "type": "context"
                            },
                            {
                                "content": "    access_logger = AccessLogger(mock_logger, log_format)",
                                "type": "context"
                            },
                            {
                                "content": "    request = mock.Mock(",
                                "type": "context"
                            }
                        ]
                    },
                    "modified_entities": [
                        {
                            "file_name": "tests/test_web_log.py",
                            "type": "function",
                            "name": "test_access_logger_atoms",
                            "content": "def test_access_logger_atoms(mocker) -> None:\n    utcnow = datetime.datetime(1843, 1, 1, 0, 30)\n    mock_datetime = mocker.patch(\"datetime.datetime\")\n    mock_getpid = mocker.patch(\"os.getpid\")\n    mock_datetime.utcnow.return_value = utcnow\n    mock_getpid.return_value = 42\n    log_format = '%a %t %P %r %s %b %T %Tf %D \"%{H1}i\" \"%{H2}i\"'\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    request = mock.Mock(\n        headers={\"H1\": \"a\", \"H2\": \"b\"},\n        method=\"GET\",\n        path_qs=\"/path\",\n        version=aiohttp.HttpVersion(1, 1),\n        remote=\"127.0.0.2\",\n    )\n    response = mock.Mock(headers={}, body_length=42, status=200)\n    access_logger.log(request, response, 3.1415926)\n    assert not mock_logger.exception.called\n    expected = (\n        \"127.0.0.2 [01/Jan/1843:00:29:56 +0000] <42> \"\n        'GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"'\n    )\n    extra = {\n        \"first_request_line\": \"GET /path HTTP/1.1\",\n        \"process_id\": \"<42>\",\n        \"remote_address\": \"127.0.0.2\",\n        \"request_start_time\": \"[01/Jan/1843:00:29:56 +0000]\",\n        \"request_time\": \"3\",\n        \"request_time_frac\": \"3.141593\",\n        \"request_time_micro\": \"3141593\",\n        \"response_size\": 42,\n        \"response_status\": 200,\n        \"request_header\": {\"H1\": \"a\", \"H2\": \"b\"},\n    }\n\n    mock_logger.info.assert_called_with(expected, extra=extra)",
                            "ast_type_str": "FunctionDef",
                            "start_lineno": 54,
                            "end_lineno": 90,
                            "parent": null
                        }
                    ],
                    "added_entities": [],
                    "deleted_entities": []
                },
                {
                    "descriptor": {
                        "old_range": {
                            "start": 69,
                            "length": 23
                        },
                        "new_range": {
                            "start": 103,
                            "length": 7
                        },
                        "section": "def test_access_logger_atoms(mocker) -> None:"
                    },
                    "line_group": {
                        "all_lines": [
                            {
                                "content": "    )",
                                "type": "context"
                            },
                            {
                                "content": "    response = mock.Mock(headers={}, body_length=42, status=200)",
                                "type": "context"
                            },
                            {
                                "content": "    access_logger.log(request, response, 3.1415926)",
                                "type": "context"
                            },
                            {
                                "content": "    assert not mock_logger.exception.called",
                                "type": "deleted"
                            },
                            {
                                "content": "    expected = (",
                                "type": "deleted"
                            },
                            {
                                "content": "        \"127.0.0.2 [01/Jan/1843:00:29:56 +0000] <42> \"",
                                "type": "deleted"
                            },
                            {
                                "content": "        'GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"'",
                                "type": "deleted"
                            },
                            {
                                "content": "    )",
                                "type": "deleted"
                            },
                            {
                                "content": "    extra = {",
                                "type": "deleted"
                            },
                            {
                                "content": "        \"first_request_line\": \"GET /path HTTP/1.1\",",
                                "type": "deleted"
                            },
                            {
                                "content": "        \"process_id\": \"<42>\",",
                                "type": "deleted"
                            },
                            {
                                "content": "        \"remote_address\": \"127.0.0.2\",",
                                "type": "deleted"
                            },
                            {
                                "content": "        \"request_start_time\": \"[01/Jan/1843:00:29:56 +0000]\",",
                                "type": "deleted"
                            },
                            {
                                "content": "        \"request_time\": \"3\",",
                                "type": "deleted"
                            },
                            {
                                "content": "        \"request_time_frac\": \"3.141593\",",
                                "type": "deleted"
                            },
                            {
                                "content": "        \"request_time_micro\": \"3141593\",",
                                "type": "deleted"
                            },
                            {
                                "content": "        \"response_size\": 42,",
                                "type": "deleted"
                            },
                            {
                                "content": "        \"response_status\": 200,",
                                "type": "deleted"
                            },
                            {
                                "content": "        \"request_header\": {\"H1\": \"a\", \"H2\": \"b\"},",
                                "type": "deleted"
                            },
                            {
                                "content": "    }",
                                "type": "deleted"
                            },
                            {
                                "content": "    assert not mock_logger.exception.called, mock_logger.exception.call_args",
                                "type": "added"
                            },
                            {
                                "content": "",
                                "type": "context"
                            },
                            {
                                "content": "    mock_logger.info.assert_called_with(expected, extra=extra)",
                                "type": "context"
                            },
                            {
                                "content": "",
                                "type": "context"
                            },
                            {
                                "content": "",
                                "type": "context"
                            }
                        ]
                    },
                    "modified_entities": [
                        {
                            "file_name": "tests/test_web_log.py",
                            "type": "function",
                            "name": "test_access_logger_atoms",
                            "content": "def test_access_logger_atoms(mocker) -> None:\n    utcnow = datetime.datetime(1843, 1, 1, 0, 30)\n    mock_datetime = mocker.patch(\"datetime.datetime\")\n    mock_getpid = mocker.patch(\"os.getpid\")\n    mock_datetime.utcnow.return_value = utcnow\n    mock_getpid.return_value = 42\n    log_format = '%a %t %P %r %s %b %T %Tf %D \"%{H1}i\" \"%{H2}i\"'\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    request = mock.Mock(\n        headers={\"H1\": \"a\", \"H2\": \"b\"},\n        method=\"GET\",\n        path_qs=\"/path\",\n        version=aiohttp.HttpVersion(1, 1),\n        remote=\"127.0.0.2\",\n    )\n    response = mock.Mock(headers={}, body_length=42, status=200)\n    access_logger.log(request, response, 3.1415926)\n    assert not mock_logger.exception.called\n    expected = (\n        \"127.0.0.2 [01/Jan/1843:00:29:56 +0000] <42> \"\n        'GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"'\n    )\n    extra = {\n        \"first_request_line\": \"GET /path HTTP/1.1\",\n        \"process_id\": \"<42>\",\n        \"remote_address\": \"127.0.0.2\",\n        \"request_start_time\": \"[01/Jan/1843:00:29:56 +0000]\",\n        \"request_time\": \"3\",\n        \"request_time_frac\": \"3.141593\",\n        \"request_time_micro\": \"3141593\",\n        \"response_size\": 42,\n        \"response_status\": 200,\n        \"request_header\": {\"H1\": \"a\", \"H2\": \"b\"},\n    }\n\n    mock_logger.info.assert_called_with(expected, extra=extra)",
                            "ast_type_str": "FunctionDef",
                            "start_lineno": 54,
                            "end_lineno": 90,
                            "parent": null
                        }
                    ],
                    "added_entities": [],
                    "deleted_entities": []
                }
            ]
        }
    ],
    "old_commit_hash": "2ac5bbce5c7c6e3a442951ef7638b23f61b76a25^",
    "new_commit_hash": "2ac5bbce5c7c6e3a442951ef7638b23f61b76a25",
    "commit_message": "[Backport][3.9] Make access log use local time with timezone (#7557)\n\n## What do these changes do?\r\nBackport #3860 to the `3.9` branch with the latest changes from `master`\r\nUse changelog fragment from #3860.\r\nIt was only ever merged into `master` and `3.8`.\r\n\r\n_This also resolves a DeprecationWarning for Users when running Python\r\n3.12 -> `utcnow`._\r\n\r\n---------\r\n\r\nCo-authored-by: NewUserHa <32261870+NewUserHa@users.noreply.github.com>\r\nCo-authored-by: Sviatoslav Sydorenko <wk.cvs.github@sydorenko.org.ua>\r\nCo-authored-by: pre-commit-ci[bot] <66853113+pre-commit-ci[bot]@users.noreply.github.com>",
    "commit_date": "2023-08-26T13:32:04+01:00",
    "metadata": {}
}
{
    "repo_name": "aiohttp",
    "new_commit_hash": "2ac5bbce5c7c6e3a442951ef7638b23f61b76a25",
    "test_file_codes": [
        "import datetime\nimport logging\nimport platform\nfrom typing import Any\nfrom unittest import mock\n\nimport pytest\n\nimport aiohttp\nfrom aiohttp import web\nfrom aiohttp.abc import AbstractAccessLogger\nfrom aiohttp.typedefs import Handler\nfrom aiohttp.web_log import AccessLogger\n\ntry:\n    from contextvars import ContextVar\nexcept ImportError:\n    ContextVar = None\n\n\nIS_PYPY = platform.python_implementation() == \"PyPy\"\n\n\ndef test_access_logger_format() -> None:\n    log_format = '%T \"%{ETag}o\" %X {X} %%P'\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    expected = '%s \"%s\" %%X {X} %%%s'\n    assert expected == access_logger._log_format\n\n\n@pytest.mark.skipif(\n    IS_PYPY,\n    reason=\"\"\"\n    Because of patching :py:class:`datetime.datetime`, under PyPy it\n    fails in :py:func:`isinstance` call in\n    :py:meth:`datetime.datetime.__sub__` (called from\n    :py:meth:`aiohttp.AccessLogger._format_t`):\n\n    *** TypeError: isinstance() arg 2 must be a class, type, or tuple of classes and types\n\n    (Pdb) from datetime import datetime\n    (Pdb) isinstance(now, datetime)\n    *** TypeError: isinstance() arg 2 must be a class, type, or tuple of classes and types\n    (Pdb) datetime.__class__\n    <class 'unittest.mock.MagicMock'>\n    (Pdb) isinstance(now, datetime.__class__)\n    False\n\n    Ref: https://bitbucket.org/pypy/pypy/issues/1187/call-to-isinstance-in-__sub__-self-other\n    Ref: https://github.com/celery/celery/issues/811\n    Ref: https://stackoverflow.com/a/46102240/595220\n    \"\"\",\n)\n@pytest.mark.parametrize(\n    \"log_format,expected,extra\",\n    [\n        (\n            \"%t\",\n            \"[01/Jan/1843:00:29:56 +0800]\",\n            {\"request_start_time\": \"[01/Jan/1843:00:29:56 +0800]\"},\n        ),\n        (\n            '%a %t %P %r %s %b %T %Tf %D \"%{H1}i\" \"%{H2}i\"',\n            (\n                \"127.0.0.2 [01/Jan/1843:00:29:56 +0800] <42> \"\n                'GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"'\n            ),\n            {\n                \"first_request_line\": \"GET /path HTTP/1.1\",\n                \"process_id\": \"<42>\",\n                \"remote_address\": \"127.0.0.2\",\n                \"request_start_time\": \"[01/Jan/1843:00:29:56 +0800]\",\n                \"request_time\": \"3\",\n                \"request_time_frac\": \"3.141593\",\n                \"request_time_micro\": \"3141593\",\n                \"response_size\": 42,\n                \"response_status\": 200,\n                \"request_header\": {\"H1\": \"a\", \"H2\": \"b\"},\n            },\n        ),\n    ],\n)\ndef test_access_logger_atoms(\n    monkeypatch: Any, log_format: Any, expected: Any, extra: Any\n) -> None:\n    class PatchedDatetime(datetime.datetime):\n        @staticmethod\n        def now(tz):\n            return datetime.datetime(1843, 1, 1, 0, 30, tzinfo=tz)\n\n    monkeypatch.setattr(\"datetime.datetime\", PatchedDatetime)\n    monkeypatch.setattr(\"time.timezone\", -28800)\n    monkeypatch.setattr(\"os.getpid\", lambda: 42)\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    request = mock.Mock(\n        headers={\"H1\": \"a\", \"H2\": \"b\"},\n        method=\"GET\",\n        path_qs=\"/path\",\n        version=aiohttp.HttpVersion(1, 1),\n        remote=\"127.0.0.2\",\n    )\n    response = mock.Mock(headers={}, body_length=42, status=200)\n    access_logger.log(request, response, 3.1415926)\n    assert not mock_logger.exception.called, mock_logger.exception.call_args\n\n    mock_logger.info.assert_called_with(expected, extra=extra)\n\n\ndef test_access_logger_dicts() -> None:\n    log_format = \"%{User-Agent}i %{Content-Length}o %{None}i\"\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    request = mock.Mock(\n        headers={\"User-Agent\": \"Mock/1.0\"}, version=(1, 1), remote=\"127.0.0.2\"\n    )\n    response = mock.Mock(headers={\"Content-Length\": 123})\n    access_logger.log(request, response, 0.0)\n    assert not mock_logger.error.called\n    expected = \"Mock/1.0 123 -\"\n    extra = {\n        \"request_header\": {\"User-Agent\": \"Mock/1.0\", \"None\": \"-\"},\n        \"response_header\": {\"Content-Length\": 123},\n    }\n\n    mock_logger.info.assert_called_with(expected, extra=extra)\n\n\ndef test_access_logger_unix_socket() -> None:\n    log_format = \"|%a|\"\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, log_format)\n    request = mock.Mock(headers={\"User-Agent\": \"Mock/1.0\"}, version=(1, 1), remote=\"\")\n    response = mock.Mock()\n    access_logger.log(request, response, 0.0)\n    assert not mock_logger.error.called\n    expected = \"||\"\n    mock_logger.info.assert_called_with(expected, extra={\"remote_address\": \"\"})\n\n\ndef test_logger_no_message() -> None:\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, \"%r %{content-type}i\")\n    extra_dict = {\n        \"first_request_line\": \"-\",\n        \"request_header\": {\"content-type\": \"(no headers)\"},\n    }\n\n    access_logger.log(None, None, 0.0)\n    mock_logger.info.assert_called_with(\"- (no headers)\", extra=extra_dict)\n\n\ndef test_logger_internal_error() -> None:\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, \"%D\")\n    access_logger.log(None, None, \"invalid\")\n    mock_logger.exception.assert_called_with(\"Error in logging\")\n\n\ndef test_logger_no_transport() -> None:\n    mock_logger = mock.Mock()\n    access_logger = AccessLogger(mock_logger, \"%a\")\n    access_logger.log(None, None, 0)\n    mock_logger.info.assert_called_with(\"-\", extra={\"remote_address\": \"-\"})\n\n\ndef test_logger_abc() -> None:\n    class Logger(AbstractAccessLogger):\n        def log(self, request, response, time):\n            1 / 0\n\n    mock_logger = mock.Mock()\n    access_logger = Logger(mock_logger, None)\n\n    with pytest.raises(ZeroDivisionError):\n        access_logger.log(None, None, None)\n\n    class Logger(AbstractAccessLogger):\n        def log(self, request, response, time):\n            self.logger.info(\n                self.log_format.format(request=request, response=response, time=time)\n            )\n\n    mock_logger = mock.Mock()\n    access_logger = Logger(mock_logger, \"{request} {response} {time}\")\n    access_logger.log(\"request\", \"response\", 1)\n    mock_logger.info.assert_called_with(\"request response 1\")\n\n\nasync def test_contextvars_logger(aiohttp_server, aiohttp_client):\n    VAR = ContextVar(\"VAR\")\n\n    async def handler(request):\n        return web.Response()\n\n    @web.middleware\n    async def middleware(request, handler: Handler):\n        VAR.set(\"uuid\")\n        return await handler(request)\n\n    msg = None\n\n    class Logger(AbstractAccessLogger):\n        def log(self, request, response, time):\n            nonlocal msg\n            msg = f\"contextvars: {VAR.get()}\"\n\n    app = web.Application(middlewares=[middleware])\n    app.router.add_get(\"/\", handler)\n    server = await aiohttp_server(app, access_log_class=Logger)\n    client = await aiohttp_client(server)\n    resp = await client.get(\"/\")\n    assert 200 == resp.status\n    assert msg == \"contextvars: uuid\"\n\n\ndef test_logger_does_nothing_when_disabled(caplog: pytest.LogCaptureFixture) -> None:\n    \"\"\"Test that the logger does nothing when the log level is disabled.\"\"\"\n    mock_logger = logging.getLogger(\"test.aiohttp.log\")\n    mock_logger.setLevel(logging.INFO)\n    access_logger = AccessLogger(mock_logger, \"%b\")\n    access_logger.log(\n        mock.Mock(name=\"mock_request\"), mock.Mock(name=\"mock_response\"), 42\n    )\n    assert \"mock_response\" in caplog.text\n",
        "import asyncio\nimport os\nimport socket\nimport ssl\nimport sys\nfrom hashlib import md5, sha256\nfrom pathlib import Path\nfrom tempfile import TemporaryDirectory\nfrom uuid import uuid4\n\nimport pytest\n\nfrom aiohttp.test_utils import loop_context\n\ntry:\n    import trustme\n\n    # Check if the CA is available in runtime, MacOS on Py3.10 fails somehow\n    trustme.CA()\n\n    TRUSTME: bool = True\nexcept ImportError:\n    TRUSTME = False\n\npytest_plugins = [\"aiohttp.pytest_plugin\", \"pytester\"]\n\nIS_HPUX = sys.platform.startswith(\"hp-ux\")\nIS_LINUX = sys.platform.startswith(\"linux\")\n\n\n@pytest.fixture\ndef tls_certificate_authority():\n    if not TRUSTME:\n        pytest.xfail(\"trustme is not supported\")\n    return trustme.CA()\n\n\n@pytest.fixture\ndef tls_certificate(tls_certificate_authority):\n    return tls_certificate_authority.issue_cert(\n        \"localhost\",\n        \"127.0.0.1\",\n        \"::1\",\n    )\n\n\n@pytest.fixture\ndef ssl_ctx(tls_certificate):\n    ssl_ctx = ssl.SSLContext(ssl.PROTOCOL_TLS_SERVER)\n    tls_certificate.configure_cert(ssl_ctx)\n    return ssl_ctx\n\n\n@pytest.fixture\ndef client_ssl_ctx(tls_certificate_authority):\n    ssl_ctx = ssl.create_default_context(purpose=ssl.Purpose.SERVER_AUTH)\n    tls_certificate_authority.configure_trust(ssl_ctx)\n    return ssl_ctx\n\n\n@pytest.fixture\ndef tls_ca_certificate_pem_path(tls_certificate_authority):\n    with tls_certificate_authority.cert_pem.tempfile() as ca_cert_pem:\n        yield ca_cert_pem\n\n\n@pytest.fixture\ndef tls_certificate_pem_path(tls_certificate):\n    with tls_certificate.private_key_and_cert_chain_pem.tempfile() as cert_pem:\n        yield cert_pem\n\n\n@pytest.fixture\ndef tls_certificate_pem_bytes(tls_certificate):\n    return tls_certificate.cert_chain_pems[0].bytes()\n\n\n@pytest.fixture\ndef tls_certificate_fingerprint_sha256(tls_certificate_pem_bytes):\n    tls_cert_der = ssl.PEM_cert_to_DER_cert(tls_certificate_pem_bytes.decode())\n    return sha256(tls_cert_der).digest()\n\n\n@pytest.fixture\ndef unix_sockname(tmp_path, tmp_path_factory):\n    \"\"\"Generate an fs path to the UNIX domain socket for testing.\n\n    N.B. Different OS kernels have different fs path length limitations\n    for it. For Linux, it's 108, for HP-UX it's 92 (or higher) depending\n    on its version. For for most of the BSDs (Open, Free, macOS) it's\n    mostly 104 but sometimes it can be down to 100.\n\n    Ref: https://github.com/aio-libs/aiohttp/issues/3572\n    \"\"\"\n    if not hasattr(socket, \"AF_UNIX\"):\n        pytest.skip(\"requires UNIX sockets\")\n\n    max_sock_len = 92 if IS_HPUX else 108 if IS_LINUX else 100\n    \"\"\"Amount of bytes allocated for the UNIX socket path by OS kernel.\n\n    Ref: https://unix.stackexchange.com/a/367012/27133\n    \"\"\"\n\n    sock_file_name = \"unix.sock\"\n    unique_prefix = f\"{uuid4()!s}-\"\n    unique_prefix_len = len(unique_prefix.encode())\n\n    root_tmp_dir = Path(\"/tmp\").resolve()\n    os_tmp_dir = Path(os.getenv(\"TMPDIR\", \"/tmp\")).resolve()\n    original_base_tmp_path = Path(\n        str(tmp_path_factory.getbasetemp()),\n    ).resolve()\n\n    original_base_tmp_path_hash = md5(\n        str(original_base_tmp_path).encode(),\n    ).hexdigest()\n\n    def make_tmp_dir(base_tmp_dir):\n        return TemporaryDirectory(\n            dir=str(base_tmp_dir),\n            prefix=\"pt-\",\n            suffix=f\"-{original_base_tmp_path_hash!s}\",\n        )\n\n    def assert_sock_fits(sock_path):\n        sock_path_len = len(sock_path.encode())\n        # exit-check to verify that it's correct and simplify debugging\n        # in the future\n        assert sock_path_len <= max_sock_len, (\n            \"Suggested UNIX socket ({sock_path}) is {sock_path_len} bytes \"\n            \"long but the current kernel only has {max_sock_len} bytes \"\n            \"allocated to hold it so it must be shorter. \"\n            \"See https://github.com/aio-libs/aiohttp/issues/3572 \"\n            \"for more info.\"\n        ).format_map(locals())\n\n    paths = original_base_tmp_path, os_tmp_dir, root_tmp_dir\n    unique_paths = [p for n, p in enumerate(paths) if p not in paths[:n]]\n    paths_num = len(unique_paths)\n\n    for num, tmp_dir_path in enumerate(paths, 1):\n        with make_tmp_dir(tmp_dir_path) as tmpd:\n            tmpd = Path(tmpd).resolve()\n            sock_path = str(tmpd / sock_file_name)\n            sock_path_len = len(sock_path.encode())\n\n            if num >= paths_num:\n                # exit-check to verify that it's correct and simplify\n                # debugging in the future\n                assert_sock_fits(sock_path)\n\n            if sock_path_len <= max_sock_len:\n                if max_sock_len - sock_path_len >= unique_prefix_len:\n                    # If we're lucky to have extra space in the path,\n                    # let's also make it more unique\n                    sock_path = str(tmpd / \"\".join((unique_prefix, sock_file_name)))\n                    # Double-checking it:\n                    assert_sock_fits(sock_path)\n                yield sock_path\n                return\n\n\n@pytest.fixture\ndef pipe_name():\n    name = rf\"\\\\.\\pipe\\{uuid4().hex}\"\n    return name\n\n\n@pytest.fixture\ndef selector_loop():\n    policy = asyncio.WindowsSelectorEventLoopPolicy()\n    asyncio.set_event_loop_policy(policy)\n\n    with loop_context(policy.new_event_loop) as _loop:\n        asyncio.set_event_loop(_loop)\n        yield _loop\n\n\n@pytest.fixture\ndef netrc_contents(\n    tmp_path: Path,\n    monkeypatch: pytest.MonkeyPatch,\n    request: pytest.FixtureRequest,\n):\n    \"\"\"\n    Prepare :file:`.netrc` with given contents.\n\n    Monkey-patches :envvar:`NETRC` to point to created file.\n    \"\"\"\n    netrc_contents = getattr(request, \"param\", None)\n\n    netrc_file_path = tmp_path / \".netrc\"\n    if netrc_contents is not None:\n        netrc_file_path.write_text(netrc_contents)\n\n    monkeypatch.setenv(\"NETRC\", str(netrc_file_path))\n\n    return netrc_file_path\n"
    ],
    "test_file_names": [
        "test_1.py",
        "conftest.py"
    ],
    "setup_res_code": 0,
    "setup_res_stdout": "re-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/requirements/cython.txt\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/tools/gen.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/hdrs.py\n./tools/gen.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/_helpers.pyx\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/_http_parser.pyx\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/_http_writer.pyx\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/_websocket.pyx\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/_helpers.pyi\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/_cparser.pxd\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/_find_header.pxd\ncython -3 -o aiohttp/_helpers.c aiohttp/_helpers.pyx -I aiohttp\ncython -3 -o aiohttp/_http_parser.c aiohttp/_http_parser.pyx -I aiohttp\ncython -3 -o aiohttp/_http_writer.c aiohttp/_http_writer.pyx -I aiohttp\ncython -3 -o aiohttp/_websocket.c aiohttp/_websocket.pyx -I aiohttp\ncd vendor/llhttp; npm install\n\n> llhttp@9.0.0 prepare\n> npm run clean && npm run build-ts\n\n\n> llhttp@9.0.0 clean\n> rm -rf lib && rm -rf test/tmp\n\n\n> llhttp@9.0.0 build-ts\n> tsc\n\n\nadded 157 packages, and audited 158 packages in 4s\n\n23 packages are looking for funding\n  run `npm fund` for details\n\n5 vulnerabilities (4 moderate, 1 high)\n\nTo address issues that do not require attention, run:\n  npm audit fix\n\nSome issues need review, and may require choosing\na different dependency.\n\nRun `npm audit` for details.\nmake -C vendor/llhttp generate\nmake[1]: Entering directory '/home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/vendor/llhttp'\nnpx ts-node bin/generate.ts\nmake[1]: Leaving directory '/home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/vendor/llhttp'\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/__init__.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/abc.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/base_protocol.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/client.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/client_exceptions.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/client_proto.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/client_reqrep.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/client_ws.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/compression_utils.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/connector.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/cookiejar.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/formdata.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/helpers.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/http.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/http_exceptions.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/http_parser.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/http_websocket.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/http_writer.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/locks.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/log.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/multipart.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/payload.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/payload_streamer.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/pytest_plugin.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/resolver.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/streams.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/tcp_helpers.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/test_utils.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/tracing.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/typedefs.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web_app.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web_exceptions.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web_fileresponse.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web_log.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web_middlewares.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web_protocol.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web_request.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web_response.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web_routedef.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web_runner.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web_server.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web_urldispatcher.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/web_ws.py\nre-hash /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/aiohttp/worker.py\nuv pip install -e . -c requirements/runtime-deps.txt\n",
    "setup_res_stderr": "Using CPython 3.9.21\nCreating virtual environment at: .venv\nActivate with: source .venv/bin/activate\nResolved 1 package in 43ms\nPrepared 1 package in 0.47ms\nInstalled 1 package in 47ms\n + pip==24.3.1\nResolved 3 packages in 9ms\nInstalled 3 packages in 15ms\n + cython==3.0.0\n + multidict==6.0.4\n + typing-extensions==4.7.1\nwarning: aiohttp/_http_parser.pyx:51:0: The 'DEF' statement is deprecated and will be removed in a future Cython version. Consider using global variables, constants, and in-place literals instead. See https://github.com/cython/cython/issues/4310\nwarning: aiohttp/_http_parser.pyx:84:0: The 'DEF' statement is deprecated and will be removed in a future Cython version. Consider using global variables, constants, and in-place literals instead. See https://github.com/cython/cython/issues/4310\nwarning: aiohttp/_http_writer.pyx:10:0: The 'DEF' statement is deprecated and will be removed in a future Cython version. Consider using global variables, constants, and in-place literals instead. See https://github.com/cython/cython/issues/4310\nResolved 98 packages in 40ms\nUninstalled 1 package in 5ms\nInstalled 96 packages in 101ms\n + aiodns==3.0.0\n + aiohttp-theme==0.1.6\n + aioredis==2.0.1\n + aiosignal==1.3.1\n + alabaster==0.7.13\n + annotated-types==0.5.0\n + async-timeout==4.0.3\n + attrs==23.1.0\n + babel==2.12.1\n + blockdiag==3.0.0\n + brotli==1.0.9\n + build==0.10.0\n + cchardet==2.1.7\n + certifi==2023.7.22\n + cffi==1.15.1\n + cfgv==3.3.1\n + charset-normalizer==3.2.0\n + cherry-picker==2.1.0\n + click==8.1.6\n + click-default-group==1.2.2\n + coverage==7.3.0\n + cryptography==41.0.3\n + distlib==0.3.7\n + docutils==0.20.1\n + exceptiongroup==1.1.2\n + filelock==3.12.2\n + freezegun==1.2.2\n + frozenlist==1.4.0\n + funcparserlib==1.0.1\n + gidgethub==5.3.0\n + gunicorn==21.2.0\n + identify==2.5.26\n + idna==3.4\n + imagesize==1.4.1\n + importlib-metadata==6.8.0\n + importlib-resources==6.0.0\n + incremental==22.10.0\n + iniconfig==2.0.0\n + jinja2==3.1.2\n + markupsafe==2.1.3\n + mypy==1.5.1\n + mypy-extensions==1.0.0\n + nodeenv==1.8.0\n + packaging==23.1\n + pillow==9.5.0\n - pip==24.3.1\n + pip==23.2.1\n + pip-tools==7.3.0\n + platformdirs==3.10.0\n + pluggy==1.2.0\n + pre-commit==3.3.3\n + proxy-py==2.4.3\n + pycares==4.3.0\n + pycparser==2.21\n + pydantic==2.2.0\n + pydantic-core==2.6.0\n + pygments==2.15.1\n + pyjwt==2.8.0\n + pyproject-hooks==1.0.0\n + pytest==7.4.0\n + pytest-cov==4.1.0\n + pytest-mock==3.11.1\n + python-dateutil==2.8.2\n + python-on-whales==0.64.2\n + pyyaml==6.0.1\n + re-assert==1.1.0\n + regex==2023.6.3\n + requests==2.31.0\n + setuptools==68.0.0\n + setuptools-git==1.2\n + six==1.16.0\n + slotscheck==0.17.0\n + snowballstemmer==2.2.0\n + sphinx==7.1.2\n + sphinxcontrib-applehelp==1.0.4\n + sphinxcontrib-blockdiag==3.0.0\n + sphinxcontrib-devhelp==1.0.2\n + sphinxcontrib-htmlhelp==2.0.1\n + sphinxcontrib-jsmath==1.0.1\n + sphinxcontrib-qthelp==1.0.3\n + sphinxcontrib-serializinghtml==1.1.5\n + sphinxcontrib-towncrier==0.3.2a0\n + toml==0.10.2\n + tomli==2.0.1\n + towncrier==23.6.0\n + tqdm==4.65.0\n + trustme==1.1.0\n + typer==0.9.0\n + uritemplate==4.1.1\n + urllib3==2.0.4\n + uvloop==0.17.0\n + virtualenv==20.24.2\n + wait-for-it==2.2.2\n + webcolors==1.13\n + wheel==0.41.0\n + yarl==1.9.2\n + zipp==3.16.2\nResolved 9 packages in 1.27s\nPrepared 1 package in 15.94s\nInstalled 1 package in 0.72ms\n + aiohttp==3.9.0.dev0 (from file:///home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25)\nResolved 24 packages in 14ms\nInstalled 5 packages in 6ms\n + async-generator==1.10\n + brotlipy==0.7.0\n + chardet==5.2.0\n + multdict==0.0.5\n + pytest-asyncio==0.23.8\n",
    "new_commit_res_code": 0,
    "new_commit_res_stdout": "============================= test session starts ==============================\nplatform linux -- Python 3.9.21, pytest-7.4.0, pluggy-1.2.0 -- /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/.venv/bin/python\ncachedir: .pytest_cache\nrootdir: /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25\nconfigfile: setup.cfg\nplugins: mock-3.11.1, asyncio-0.23.8, cov-4.1.0\nasyncio: mode=strict\ncollecting ... collected 11 items\n\nr2e_tests/test_1.py::test_access_logger_format PASSED                    [  9%]\nr2e_tests/test_1.py::test_access_logger_atoms[%t-[01/Jan/1843:00:29:56 +0800]-extra0] PASSED [ 18%]\nr2e_tests/test_1.py::test_access_logger_atoms[%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\"-extra1] PASSED [ 27%]\nr2e_tests/test_1.py::test_access_logger_dicts PASSED                     [ 36%]\nr2e_tests/test_1.py::test_access_logger_unix_socket PASSED               [ 45%]\nr2e_tests/test_1.py::test_logger_no_message PASSED                       [ 54%]\nr2e_tests/test_1.py::test_logger_internal_error PASSED                   [ 63%]\nr2e_tests/test_1.py::test_logger_no_transport PASSED                     [ 72%]\nr2e_tests/test_1.py::test_logger_abc PASSED                              [ 81%]\nr2e_tests/test_1.py::test_contextvars_logger[pyloop] PASSED              [ 90%]\nr2e_tests/test_1.py::test_logger_does_nothing_when_disabled PASSED       [100%]\n\n==================================== PASSES ====================================\n____________________ test_logger_does_nothing_when_disabled ____________________\n------------------------------ Captured log call -------------------------------\nINFO     test.aiohttp.log:web_log.py:211 <Mock name='mock_response.body_length' id='140074676204400'>\n\n---------- coverage: platform linux, python 3.9.21-final-0 -----------\nName                                     Stmts   Miss Branch BrPart  Cover\n--------------------------------------------------------------------------\naiohttp/__init__.py                         27      8      2      1    69%\naiohttp/abc.py                              90      2      0      0    98%\naiohttp/base_protocol.py                    66     36     22      3    38%\naiohttp/client.py                          488    242    178     48    44%\naiohttp/client_exceptions.py               135     57     16      1    52%\naiohttp/client_proto.py                    149     50     54     19    59%\naiohttp/client_reqrep.py                   650    304    280     59    45%\naiohttp/client_ws.py                       206    166     64      0    15%\naiohttp/compression_utils.py                65     34     14      0    39%\naiohttp/connector.py                       711    419    309     45    33%\naiohttp/cookiejar.py                       256    165    116     10    27%\naiohttp/formdata.py                         93     76     46      0    12%\naiohttp/hdrs.py                             90      0      0      0   100%\naiohttp/helpers.py                         511    262    176     22    41%\naiohttp/http.py                             11      0      2      0   100%\naiohttp/http_exceptions.py                  51     21      6      0    53%\naiohttp/http_parser.py                     476    382    176      1    15%\naiohttp/http_websocket.py                  385    285    152      0    19%\naiohttp/http_writer.py                     118     44     50     13    53%\naiohttp/locks.py                            24     16      4      0    29%\naiohttp/log.py                               7      0      0      0   100%\naiohttp/multipart.py                       562    455    232      0    14%\naiohttp/payload.py                         219    107     56      1    43%\naiohttp/payload_streamer.py                 29     10      4      0    70%\naiohttp/pytest_plugin.py                   167     56     42      8    65%\naiohttp/resolver.py                         68     47     22      0    23%\naiohttp/streams.py                         393    245    142     11    30%\naiohttp/tcp_helpers.py                      19      2      6      3    80%\naiohttp/test_utils.py                      313    118     52     11    58%\naiohttp/tracing.py                         191     69     32      0    69%\naiohttp/typedefs.py                         23      0      0      0   100%\naiohttp/web.py                             116     81     52      0    22%\naiohttp/web_app.py                         301    102     74     20    61%\naiohttp/web_exceptions.py                  151     22      6      0    82%\naiohttp/web_fileresponse.py                141    118     50      0    12%\naiohttp/web_log.py                         102      1     20      2    98%\naiohttp/web_middlewares.py                  55     35     20      0    27%\naiohttp/web_protocol.py                    343    151    157     39    46%\naiohttp/web_request.py                     435    245    128      7    36%\naiohttp/web_response.py                    474    256    206     31    37%\naiohttp/web_routedef.py                    106     46     10      0    55%\naiohttp/web_runner.py                      218     70     36     10    64%\naiohttp/web_server.py                       38      5      6      1    82%\naiohttp/web_urldispatcher.py               708    362    161     20    43%\naiohttp/web_ws.py                          316    254    106      0    15%\naiohttp/worker.py                          126    126     30      0     0%\ntests/__init__.py                            0      0      0      0   100%\ntests/conftest.py                          105    105     16      0     0%\ntests/test_base_protocol.py                198    198      2      0     0%\ntests/test_circular_imports.py              31     31     15      0     0%\ntests/test_classbasedview.py                39     39      0      0     0%\ntests/test_client_connection.py             94     94      2      0     0%\ntests/test_client_exceptions.py            183    183     14      0     0%\ntests/test_client_fingerprint.py            59     59      0      0     0%\ntests/test_client_functional.py           2188   2188     70      0     0%\ntests/test_client_proto.py                  99     99      0      0     0%\ntests/test_client_request.py               769    769     18      0     0%\ntests/test_client_response.py              469    469      2      0     0%\ntests/test_client_session.py               482    482     23      0     0%\ntests/test_client_ws.py                    415    415      2      0     0%\ntests/test_client_ws_functional.py         585    585     14      0     0%\ntests/test_connector.py                   1516   1516     76      0     0%\ntests/test_cookiejar.py                    332    332     22      0     0%\ntests/test_flowcontrol_streams.py          100    100      0      0     0%\ntests/test_formdata.py                      72     72      6      0     0%\ntests/test_helpers.py                      429    429     14      0     0%\ntests/test_http_exceptions.py              109    109     10      0     0%\ntests/test_http_parser.py                  785    785     40      0     0%\ntests/test_http_writer.py                  182    182     10      0     0%\ntests/test_imports.py                       31     31      6      0     0%\ntests/test_locks.py                         39     39      0      0     0%\ntests/test_loop.py                          36     36      0      0     0%\ntests/test_multipart.py                    747    747     22      0     0%\ntests/test_multipart_helpers.py            446    446      0      0     0%\ntests/test_payload.py                       94     94      0      0     0%\ntests/test_proxy.py                        285    285      0      0     0%\ntests/test_proxy_functional.py             472    472     22      0     0%\ntests/test_pytest_plugin.py                 27     27      0      0     0%\ntests/test_resolver.py                     176    176     12      0     0%\ntests/test_route_def.py                    210    210      0      0     0%\ntests/test_run_app.py                      460    460     24      0     0%\ntests/test_streams.py                     1071   1071     40      0     0%\ntests/test_tcp_helpers.py                   52     52      2      0     0%\ntests/test_test_utils.py                   242    242      6      0     0%\ntests/test_tracing.py                       48     48      0      0     0%\ntests/test_urldispatch.py                  844    844     24      0     0%\ntests/test_web_app.py                      454    454      6      0     0%\ntests/test_web_cli.py                       75     75      0      0     0%\ntests/test_web_exceptions.py               157    157     22      0     0%\ntests/test_web_functional.py              1520   1520     36      0     0%\ntests/test_web_log.py                      116    116      2      0     0%\ntests/test_web_middleware.py               266    266     12      0     0%\ntests/test_web_request.py                  490    490      8      0     0%\ntests/test_web_request_handler.py           40     40      0      0     0%\ntests/test_web_response.py                 817    817      4      0     0%\ntests/test_web_runner.py                   146    146      4      0     0%\ntests/test_web_sendfile.py                  76     76      0      0     0%\ntests/test_web_sendfile_functional.py      634    634     18      0     0%\ntests/test_web_server.py                   160    160      0      0     0%\ntests/test_web_urldispatcher.py            306    306     14      0     0%\ntests/test_web_websocket.py                304    304      4      0     0%\ntests/test_web_websocket_functional.py     542    542     16      0     0%\ntests/test_websocket_handshake.py          152    152     12      0     0%\ntests/test_websocket_parser.py             300    300     12      0     0%\ntests/test_websocket_writer.py              68     68      0      0     0%\ntests/test_worker.py                       191    191      4      0     0%\n--------------------------------------------------------------------------\nTOTAL                                    31558  26887   4005    386    15%\n\n============================= slowest 10 durations =============================\n0.02s teardown r2e_tests/test_1.py::test_contextvars_logger[pyloop]\n\n(9 durations < 0.005s hidden.  Use -vv to show these durations.)\n=========================== short test summary info ============================\nPASSED r2e_tests/test_1.py::test_access_logger_format\nPASSED r2e_tests/test_1.py::test_access_logger_atoms[%t-[01/Jan/1843:00:29:56 +0800]-extra0]\nPASSED r2e_tests/test_1.py::test_access_logger_atoms[%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\"-extra1]\nPASSED r2e_tests/test_1.py::test_access_logger_dicts\nPASSED r2e_tests/test_1.py::test_access_logger_unix_socket\nPASSED r2e_tests/test_1.py::test_logger_no_message\nPASSED r2e_tests/test_1.py::test_logger_internal_error\nPASSED r2e_tests/test_1.py::test_logger_no_transport\nPASSED r2e_tests/test_1.py::test_logger_abc\nPASSED r2e_tests/test_1.py::test_contextvars_logger[pyloop]\nPASSED r2e_tests/test_1.py::test_logger_does_nothing_when_disabled\n============================== 11 passed in 3.00s ==============================\n",
    "new_commit_res_stderr": "",
    "old_commit_res_code": 1,
    "old_commit_res_stdout": "============================= test session starts ==============================\nplatform linux -- Python 3.9.21, pytest-7.4.0, pluggy-1.2.0 -- /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25/.venv/bin/python\ncachedir: .pytest_cache\nrootdir: /home/gcpuser/buckets/local_repoeval_bucket/repos/aiohttp_2ac5bbce5c7c6e3a442951ef7638b23f61b76a25\nconfigfile: setup.cfg\nplugins: mock-3.11.1, asyncio-0.23.8, cov-4.1.0\nasyncio: mode=strict\ncollecting ... collected 11 items\n\nr2e_tests/test_1.py::test_access_logger_format PASSED                    [  9%]\nr2e_tests/test_1.py::test_access_logger_atoms[%t-[01/Jan/1843:00:29:56 +0800]-extra0] FAILED [ 18%]\nr2e_tests/test_1.py::test_access_logger_atoms[%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\"-extra1] FAILED [ 27%]\nr2e_tests/test_1.py::test_access_logger_dicts PASSED                     [ 36%]\nr2e_tests/test_1.py::test_access_logger_unix_socket PASSED               [ 45%]\nr2e_tests/test_1.py::test_logger_no_message PASSED                       [ 54%]\nr2e_tests/test_1.py::test_logger_internal_error PASSED                   [ 63%]\nr2e_tests/test_1.py::test_logger_no_transport PASSED                     [ 72%]\nr2e_tests/test_1.py::test_logger_abc PASSED                              [ 81%]\nr2e_tests/test_1.py::test_contextvars_logger[pyloop] PASSED              [ 90%]\nr2e_tests/test_1.py::test_logger_does_nothing_when_disabled PASSED       [100%]\n\n=================================== FAILURES ===================================\n_______ test_access_logger_atoms[%t-[01/Jan/1843:00:29:56 +0800]-extra0] _______\n\nself = <Mock name='mock.info' id='130861477846176'>\nargs = ('[01/Jan/1843:00:29:56 +0800]',)\nkwargs = {'extra': {'request_start_time': '[01/Jan/1843:00:29:56 +0800]'}}\nexpected = call('[01/Jan/1843:00:29:56 +0800]', extra={'request_start_time': '[01/Jan/1843:00:29:56 +0800]'})\nactual = call('[02/Jan/2025:03:21:43 +0000]', extra={'request_start_time': '[02/Jan/2025:03:21:43 +0000]'})\n_error_message = <function NonCallableMock.assert_called_with.<locals>._error_message at 0x77048fe47b80>\ncause = None\n\n    def assert_called_with(self, /, *args, **kwargs):\n        \"\"\"assert that the last call was made with the specified arguments.\n    \n        Raises an AssertionError if the args and keyword args passed in are\n        different to the last call to the mock.\"\"\"\n        if self.call_args is None:\n            expected = self._format_mock_call_signature(args, kwargs)\n            actual = 'not called.'\n            error_message = ('expected call not found.\\nExpected: %s\\nActual: %s'\n                    % (expected, actual))\n            raise AssertionError(error_message)\n    \n        def _error_message():\n            msg = self._format_mock_failure_message(args, kwargs)\n            return msg\n        expected = self._call_matcher(_Call((args, kwargs), two=True))\n        actual = self._call_matcher(self.call_args)\n        if actual != expected:\n            cause = expected if isinstance(expected, Exception) else None\n>           raise AssertionError(_error_message()) from cause\nE           AssertionError: expected call not found.\nE           Expected: info('[01/Jan/1843:00:29:56 +0800]', extra={'request_start_time': '[01/Jan/1843:00:29:56 +0800]'})\nE           Actual: info('[02/Jan/2025:03:21:43 +0000]', extra={'request_start_time': '[02/Jan/2025:03:21:43 +0000]'})\n\n_error_message = <function NonCallableMock.assert_called_with.<locals>._error_message at 0x77048fe47b80>\nactual     = call('[02/Jan/2025:03:21:43 +0000]', extra={'request_start_time': '[02/Jan/2025:03:21:43 +0000]'})\nargs       = ('[01/Jan/1843:00:29:56 +0800]',)\ncause      = None\nexpected   = call('[01/Jan/1843:00:29:56 +0800]', extra={'request_start_time': '[01/Jan/1843:00:29:56 +0800]'})\nkwargs     = {'extra': {'request_start_time': '[01/Jan/1843:00:29:56 +0800]'}}\nself       = <Mock name='mock.info' id='130861477846176'>\n\n../../../../.local/share/uv/python/cpython-3.9.21-linux-x86_64-gnu/lib/python3.9/unittest/mock.py:907: AssertionError\n\nDuring handling of the above exception, another exception occurred:\n\nmonkeypatch = <_pytest.monkeypatch.MonkeyPatch object at 0x77048fe6d400>\nlog_format = '%t', expected = '[01/Jan/1843:00:29:56 +0800]'\nextra = {'request_start_time': '[01/Jan/1843:00:29:56 +0800]'}\n\n    @pytest.mark.skipif(\n        IS_PYPY,\n        reason=\"\"\"\n        Because of patching :py:class:`datetime.datetime`, under PyPy it\n        fails in :py:func:`isinstance` call in\n        :py:meth:`datetime.datetime.__sub__` (called from\n        :py:meth:`aiohttp.AccessLogger._format_t`):\n    \n        *** TypeError: isinstance() arg 2 must be a class, type, or tuple of classes and types\n    \n        (Pdb) from datetime import datetime\n        (Pdb) isinstance(now, datetime)\n        *** TypeError: isinstance() arg 2 must be a class, type, or tuple of classes and types\n        (Pdb) datetime.__class__\n        <class 'unittest.mock.MagicMock'>\n        (Pdb) isinstance(now, datetime.__class__)\n        False\n    \n        Ref: https://bitbucket.org/pypy/pypy/issues/1187/call-to-isinstance-in-__sub__-self-other\n        Ref: https://github.com/celery/celery/issues/811\n        Ref: https://stackoverflow.com/a/46102240/595220\n        \"\"\",\n    )\n    @pytest.mark.parametrize(\n        \"log_format,expected,extra\",\n        [\n            (\n                \"%t\",\n                \"[01/Jan/1843:00:29:56 +0800]\",\n                {\"request_start_time\": \"[01/Jan/1843:00:29:56 +0800]\"},\n            ),\n            (\n                '%a %t %P %r %s %b %T %Tf %D \"%{H1}i\" \"%{H2}i\"',\n                (\n                    \"127.0.0.2 [01/Jan/1843:00:29:56 +0800] <42> \"\n                    'GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"'\n                ),\n                {\n                    \"first_request_line\": \"GET /path HTTP/1.1\",\n                    \"process_id\": \"<42>\",\n                    \"remote_address\": \"127.0.0.2\",\n                    \"request_start_time\": \"[01/Jan/1843:00:29:56 +0800]\",\n                    \"request_time\": \"3\",\n                    \"request_time_frac\": \"3.141593\",\n                    \"request_time_micro\": \"3141593\",\n                    \"response_size\": 42,\n                    \"response_status\": 200,\n                    \"request_header\": {\"H1\": \"a\", \"H2\": \"b\"},\n                },\n            ),\n        ],\n    )\n    def test_access_logger_atoms(\n        monkeypatch: Any, log_format: Any, expected: Any, extra: Any\n    ) -> None:\n        class PatchedDatetime(datetime.datetime):\n            @staticmethod\n            def now(tz):\n                return datetime.datetime(1843, 1, 1, 0, 30, tzinfo=tz)\n    \n        monkeypatch.setattr(\"datetime.datetime\", PatchedDatetime)\n        monkeypatch.setattr(\"time.timezone\", -28800)\n        monkeypatch.setattr(\"os.getpid\", lambda: 42)\n        mock_logger = mock.Mock()\n        access_logger = AccessLogger(mock_logger, log_format)\n        request = mock.Mock(\n            headers={\"H1\": \"a\", \"H2\": \"b\"},\n            method=\"GET\",\n            path_qs=\"/path\",\n            version=aiohttp.HttpVersion(1, 1),\n            remote=\"127.0.0.2\",\n        )\n        response = mock.Mock(headers={}, body_length=42, status=200)\n        access_logger.log(request, response, 3.1415926)\n        assert not mock_logger.exception.called, mock_logger.exception.call_args\n    \n>       mock_logger.info.assert_called_with(expected, extra=extra)\nE       AssertionError: expected call not found.\nE       Expected: info('[01/Jan/1843:00:29:56 +0800]', extra={'request_start_time': '[01/Jan/1843:00:29:56 +0800]'})\nE       Actual: info('[02/Jan/2025:03:21:43 +0000]', extra={'request_start_time': '[02/Jan/2025:03:21:43 +0000]'})\nE       \nE       pytest introspection follows:\nE       \nE       Args:\nE       assert ('[02/Jan/202...1:43 +0000]',) == ('[01/Jan/184...9:56 +0800]',)\nE         At index 0 diff: '[02/Jan/2025:03:21:43 +0000]' != '[01/Jan/1843:00:29:56 +0800]'\nE         Full diff:\nE         - ('[01/Jan/1843:00:29:56 +0800]',)\nE         + ('[02/Jan/2025:03:21:43 +0000]',)\nE       Kwargs:\nE       assert {'extra': {'r...1:43 +0000]'}} == {'extra': {'r...9:56 +0800]'}}\nE         Differing items:\nE         {'extra': {'request_start_time': '[02/Jan/2025:03:21:43 +0000]'}} != {'extra': {'request_start_time': '[01/Jan/1843:00:29:56 +0800]'}}\nE         Full diff:\nE         - {'extra': {'request_start_time': '[01/Jan/1843:00:29:56 +0800]'}}\nE         ?                                     ^      ^  ^  ----------\nE         + {'extra': {'request_start_time': '[02/Jan/2025:03:21:43 +0000]'}}\nE         ?                                     ^     +++++++++ ^  ^^\n\nPatchedDatetime = <class 'r2e_tests.test_1.test_access_logger_atoms.<locals>.PatchedDatetime'>\naccess_logger = <aiohttp.web_log.AccessLogger object at 0x77048fe6d8b0>\nexpected   = '[01/Jan/1843:00:29:56 +0800]'\nextra      = {'request_start_time': '[01/Jan/1843:00:29:56 +0800]'}\nlog_format = '%t'\nmock_logger = <Mock id='130861477845072'>\nmonkeypatch = <_pytest.monkeypatch.MonkeyPatch object at 0x77048fe6d400>\nrequest    = <Mock id='130861477845360'>\nresponse   = <Mock id='130861477845408'>\n\nr2e_tests/test_1.py:108: AssertionError\n_ test_access_logger_atoms[%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\"-extra1] _\n\nself = <Mock name='mock.info' id='130861477103216'>\nargs = ('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\"',)\nkwargs = {'extra': {'first_request_line': 'GET /path HTTP/1.1', 'process_id': '<42>', 'remote_address': '127.0.0.2', 'request_header': {'H1': 'a', 'H2': 'b'}, ...}}\nexpected = call('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\"', extra={'first...request_time_micro': '3141593', 'response_size': 42, 'response_status': 200, 'request_header': {'H1': 'a', 'H2': 'b'}})\nactual = call('127.0.0.2 [02/Jan/2025:03:21:44 +0000] <42> GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"', extra={'remot...ime': '3', 'request_time_frac': '3.141593', 'request_time_micro': '3141593', 'request_header': {'H1': 'a', 'H2': 'b'}})\n_error_message = <function NonCallableMock.assert_called_with.<locals>._error_message at 0x77048fdace50>\ncause = None\n\n    def assert_called_with(self, /, *args, **kwargs):\n        \"\"\"assert that the last call was made with the specified arguments.\n    \n        Raises an AssertionError if the args and keyword args passed in are\n        different to the last call to the mock.\"\"\"\n        if self.call_args is None:\n            expected = self._format_mock_call_signature(args, kwargs)\n            actual = 'not called.'\n            error_message = ('expected call not found.\\nExpected: %s\\nActual: %s'\n                    % (expected, actual))\n            raise AssertionError(error_message)\n    \n        def _error_message():\n            msg = self._format_mock_failure_message(args, kwargs)\n            return msg\n        expected = self._call_matcher(_Call((args, kwargs), two=True))\n        actual = self._call_matcher(self.call_args)\n        if actual != expected:\n            cause = expected if isinstance(expected, Exception) else None\n>           raise AssertionError(_error_message()) from cause\nE           AssertionError: expected call not found.\nE           Expected: info('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\"', 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 +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'}})\nE           Actual: info('127.0.0.2 [02/Jan/2025:03:21:44 +0000] <42> GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"', extra={'remote_address': '127.0.0.2', 'request_start_time': '[02/Jan/2025:03:21:44 +0000]', 'process_id': '<42>', 'first_request_line': 'GET /path HTTP/1.1', 'response_status': 200, 'response_size': 42, 'request_time': '3', 'request_time_frac': '3.141593', 'request_time_micro': '3141593', 'request_header': {'H1': 'a', 'H2': 'b'}})\n\n_error_message = <function NonCallableMock.assert_called_with.<locals>._error_message at 0x77048fdace50>\nactual     = call('127.0.0.2 [02/Jan/2025:03:21:44 +0000] <42> GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"', extra={'remot...ime': '3', 'request_time_frac': '3.141593', 'request_time_micro': '3141593', 'request_header': {'H1': 'a', 'H2': 'b'}})\nargs       = ('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\"',)\ncause      = None\nexpected   = call('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\"', extra={'first...request_time_micro': '3141593', 'response_size': 42, 'response_status': 200, 'request_header': {'H1': 'a', 'H2': 'b'}})\nkwargs     = {'extra': {'first_request_line': 'GET /path HTTP/1.1', 'process_id': '<42>', 'remote_address': '127.0.0.2', 'request_header': {'H1': 'a', 'H2': 'b'}, ...}}\nself       = <Mock name='mock.info' id='130861477103216'>\n\n../../../../.local/share/uv/python/cpython-3.9.21-linux-x86_64-gnu/lib/python3.9/unittest/mock.py:907: AssertionError\n\nDuring handling of the above exception, another exception occurred:\n\nmonkeypatch = <_pytest.monkeypatch.MonkeyPatch object at 0x77048fdb8ee0>\nlog_format = '%a %t %P %r %s %b %T %Tf %D \"%{H1}i\" \"%{H2}i\"'\nexpected = '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\"'\nextra = {'first_request_line': 'GET /path HTTP/1.1', 'process_id': '<42>', 'remote_address': '127.0.0.2', 'request_header': {'H1': 'a', 'H2': 'b'}, ...}\n\n    @pytest.mark.skipif(\n        IS_PYPY,\n        reason=\"\"\"\n        Because of patching :py:class:`datetime.datetime`, under PyPy it\n        fails in :py:func:`isinstance` call in\n        :py:meth:`datetime.datetime.__sub__` (called from\n        :py:meth:`aiohttp.AccessLogger._format_t`):\n    \n        *** TypeError: isinstance() arg 2 must be a class, type, or tuple of classes and types\n    \n        (Pdb) from datetime import datetime\n        (Pdb) isinstance(now, datetime)\n        *** TypeError: isinstance() arg 2 must be a class, type, or tuple of classes and types\n        (Pdb) datetime.__class__\n        <class 'unittest.mock.MagicMock'>\n        (Pdb) isinstance(now, datetime.__class__)\n        False\n    \n        Ref: https://bitbucket.org/pypy/pypy/issues/1187/call-to-isinstance-in-__sub__-self-other\n        Ref: https://github.com/celery/celery/issues/811\n        Ref: https://stackoverflow.com/a/46102240/595220\n        \"\"\",\n    )\n    @pytest.mark.parametrize(\n        \"log_format,expected,extra\",\n        [\n            (\n                \"%t\",\n                \"[01/Jan/1843:00:29:56 +0800]\",\n                {\"request_start_time\": \"[01/Jan/1843:00:29:56 +0800]\"},\n            ),\n            (\n                '%a %t %P %r %s %b %T %Tf %D \"%{H1}i\" \"%{H2}i\"',\n                (\n                    \"127.0.0.2 [01/Jan/1843:00:29:56 +0800] <42> \"\n                    'GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"'\n                ),\n                {\n                    \"first_request_line\": \"GET /path HTTP/1.1\",\n                    \"process_id\": \"<42>\",\n                    \"remote_address\": \"127.0.0.2\",\n                    \"request_start_time\": \"[01/Jan/1843:00:29:56 +0800]\",\n                    \"request_time\": \"3\",\n                    \"request_time_frac\": \"3.141593\",\n                    \"request_time_micro\": \"3141593\",\n                    \"response_size\": 42,\n                    \"response_status\": 200,\n                    \"request_header\": {\"H1\": \"a\", \"H2\": \"b\"},\n                },\n            ),\n        ],\n    )\n    def test_access_logger_atoms(\n        monkeypatch: Any, log_format: Any, expected: Any, extra: Any\n    ) -> None:\n        class PatchedDatetime(datetime.datetime):\n            @staticmethod\n            def now(tz):\n                return datetime.datetime(1843, 1, 1, 0, 30, tzinfo=tz)\n    \n        monkeypatch.setattr(\"datetime.datetime\", PatchedDatetime)\n        monkeypatch.setattr(\"time.timezone\", -28800)\n        monkeypatch.setattr(\"os.getpid\", lambda: 42)\n        mock_logger = mock.Mock()\n        access_logger = AccessLogger(mock_logger, log_format)\n        request = mock.Mock(\n            headers={\"H1\": \"a\", \"H2\": \"b\"},\n            method=\"GET\",\n            path_qs=\"/path\",\n            version=aiohttp.HttpVersion(1, 1),\n            remote=\"127.0.0.2\",\n        )\n        response = mock.Mock(headers={}, body_length=42, status=200)\n        access_logger.log(request, response, 3.1415926)\n        assert not mock_logger.exception.called, mock_logger.exception.call_args\n    \n>       mock_logger.info.assert_called_with(expected, extra=extra)\nE       AssertionError: expected call not found.\nE       Expected: info('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\"', 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 +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'}})\nE       Actual: info('127.0.0.2 [02/Jan/2025:03:21:44 +0000] <42> GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"', extra={'remote_address': '127.0.0.2', 'request_start_time': '[02/Jan/2025:03:21:44 +0000]', 'process_id': '<42>', 'first_request_line': 'GET /path HTTP/1.1', 'response_status': 200, 'response_size': 42, 'request_time': '3', 'request_time_frac': '3.141593', 'request_time_micro': '3141593', 'request_header': {'H1': 'a', 'H2': 'b'}})\nE       \nE       pytest introspection follows:\nE       \nE       Args:\nE       assert ('127.0.0.2 [...593 \"a\" \"b\"',) == ('127.0.0.2 [...593 \"a\" \"b\"',)\nE         At index 0 diff: '127.0.0.2 [02/Jan/2025:03:21:44 +0000] <42> GET /path HTTP/1.1 200 42 3 3.141593 3141593 \"a\" \"b\"' != '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\"'\nE         Full diff:\nE           (\nE         -  '127.0.0.2 [01/Jan/1843:00:29:56 +0800] <42> GET /path HTTP/1.1 200 42 3 '\nE         ?               ^     ^^^    ----------\nE         +  '127.0.0.2 [02/Jan/2025:03:21:44 +0000] <42> GET /path HTTP/1.1 200 42 3 '\nE         ?               ^     ^^^^^^  +++++++\nE            '3.141593 3141593 \"a\" \"b\"',,\nE           )\nE       Kwargs:\nE       assert {'extra': {'f...': 'b'}, ...}} == {'extra': {'f...': 'b'}, ...}}\nE         Differing items:\nE         {'extra': {'first_request_line': 'GET /path HTTP/1.1', 'process_id': '<42>', 'remote_address': '127.0.0.2', 'request_header': {'H1': 'a', 'H2': 'b'}, ...}} != {'extra': {'first_request_line': 'GET /path HTTP/1.1', 'process_id': '<42>', 'remote_address': '127.0.0.2', 'request_header': {'H1': 'a', 'H2': 'b'}, ...}}\nE         Full diff:\nE           {\nE            'extra': {'first_request_line': 'GET /path HTTP/1.1',\nE                      'process_id': '<42>',\nE                      'remote_address': '127.0.0.2',...\nE         \nE         ...Full output truncated (11 lines hidden), use '-vv' to show\n\nPatchedDatetime = <class 'r2e_tests.test_1.test_access_logger_atoms.<locals>.PatchedDatetime'>\naccess_logger = <aiohttp.web_log.AccessLogger object at 0x77048fdb8af0>\nexpected   = '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\"'\nextra      = {'first_request_line': 'GET /path HTTP/1.1', 'process_id': '<42>', 'remote_address': '127.0.0.2', 'request_header': {'H1': 'a', 'H2': 'b'}, ...}\nlog_format = '%a %t %P %r %s %b %T %Tf %D \"%{H1}i\" \"%{H2}i\"'\nmock_logger = <Mock id='130861477104224'>\nmonkeypatch = <_pytest.monkeypatch.MonkeyPatch object at 0x77048fdb8ee0>\nrequest    = <Mock id='130861477104656'>\nresponse   = <Mock id='130861477103936'>\n\nr2e_tests/test_1.py:108: AssertionError\n==================================== PASSES ====================================\n____________________ test_logger_does_nothing_when_disabled ____________________\n------------------------------ Captured log call -------------------------------\nINFO     test.aiohttp.log:web_log.py:209 <Mock name='mock_response.body_length' id='130861477844064'>\n\n---------- coverage: platform linux, python 3.9.21-final-0 -----------\nName                                     Stmts   Miss Branch BrPart  Cover\n--------------------------------------------------------------------------\naiohttp/__init__.py                         27      8      2      1    69%\naiohttp/abc.py                              90      2      0      0    98%\naiohttp/base_protocol.py                    66     36     22      3    38%\naiohttp/client.py                          488    242    178     48    44%\naiohttp/client_exceptions.py               135     57     16      1    52%\naiohttp/client_proto.py                    149     50     54     19    59%\naiohttp/client_reqrep.py                   650    304    280     59    45%\naiohttp/client_ws.py                       206    166     64      0    15%\naiohttp/compression_utils.py                65     34     14      0    39%\naiohttp/connector.py                       711    419    309     45    33%\naiohttp/cookiejar.py                       256    165    116     10    27%\naiohttp/formdata.py                         93     76     46      0    12%\naiohttp/hdrs.py                             90      0      0      0   100%\naiohttp/helpers.py                         511    262    176     22    41%\naiohttp/http.py                             11      0      2      0   100%\naiohttp/http_exceptions.py                  51     21      6      0    53%\naiohttp/http_parser.py                     476    382    176      1    15%\naiohttp/http_websocket.py                  385    285    152      0    19%\naiohttp/http_writer.py                     118     44     50     13    53%\naiohttp/locks.py                            24     16      4      0    29%\naiohttp/log.py                               7      0      0      0   100%\naiohttp/multipart.py                       562    455    232      0    14%\naiohttp/payload.py                         219    107     56      1    43%\naiohttp/payload_streamer.py                 29     10      4      0    70%\naiohttp/pytest_plugin.py                   167     56     42      8    65%\naiohttp/resolver.py                         68     47     22      0    23%\naiohttp/streams.py                         393    245    142     11    30%\naiohttp/tcp_helpers.py                      19      2      6      3    80%\naiohttp/test_utils.py                      313    118     52     11    58%\naiohttp/tracing.py                         191     69     32      0    69%\naiohttp/typedefs.py                         23      0      0      0   100%\naiohttp/web.py                             116     81     52      0    22%\naiohttp/web_app.py                         301    102     74     20    61%\naiohttp/web_exceptions.py                  151     22      6      0    82%\naiohttp/web_fileresponse.py                141    118     50      0    12%\naiohttp/web_log.py                         100      1     20      2    98%\naiohttp/web_middlewares.py                  55     35     20      0    27%\naiohttp/web_protocol.py                    343    151    157     39    46%\naiohttp/web_request.py                     435    245    128      7    36%\naiohttp/web_response.py                    474    256    206     31    37%\naiohttp/web_routedef.py                    106     46     10      0    55%\naiohttp/web_runner.py                      218     70     36     10    64%\naiohttp/web_server.py                       38      5      6      1    82%\naiohttp/web_urldispatcher.py               708    362    161     20    43%\naiohttp/web_ws.py                          316    254    106      0    15%\naiohttp/worker.py                          126    126     30      0     0%\ntests/__init__.py                            0      0      0      0   100%\ntests/conftest.py                          105    105     16      0     0%\ntests/test_base_protocol.py                198    198      2      0     0%\ntests/test_circular_imports.py              31     31     15      0     0%\ntests/test_classbasedview.py                39     39      0      0     0%\ntests/test_client_connection.py             94     94      2      0     0%\ntests/test_client_exceptions.py            183    183     14      0     0%\ntests/test_client_fingerprint.py            59     59      0      0     0%\ntests/test_client_functional.py           2188   2188     70      0     0%\ntests/test_client_proto.py                  99     99      0      0     0%\ntests/test_client_request.py               769    769     18      0     0%\ntests/test_client_response.py              469    469      2      0     0%\ntests/test_client_session.py               482    482     23      0     0%\ntests/test_client_ws.py                    415    415      2      0     0%\ntests/test_client_ws_functional.py         585    585     14      0     0%\ntests/test_connector.py                   1516   1516     76      0     0%\ntests/test_cookiejar.py                    332    332     22      0     0%\ntests/test_flowcontrol_streams.py          100    100      0      0     0%\ntests/test_formdata.py                      72     72      6      0     0%\ntests/test_helpers.py                      429    429     14      0     0%\ntests/test_http_exceptions.py              109    109     10      0     0%\ntests/test_http_parser.py                  785    785     40      0     0%\ntests/test_http_writer.py                  182    182     10      0     0%\ntests/test_imports.py                       31     31      6      0     0%\ntests/test_locks.py                         39     39      0      0     0%\ntests/test_loop.py                          36     36      0      0     0%\ntests/test_multipart.py                    747    747     22      0     0%\ntests/test_multipart_helpers.py            446    446      0      0     0%\ntests/test_payload.py                       94     94      0      0     0%\ntests/test_proxy.py                        285    285      0      0     0%\ntests/test_proxy_functional.py             472    472     22      0     0%\ntests/test_pytest_plugin.py                 27     27      0      0     0%\ntests/test_resolver.py                     176    176     12      0     0%\ntests/test_route_def.py                    210    210      0      0     0%\ntests/test_run_app.py                      460    460     24      0     0%\ntests/test_streams.py                     1071   1071     40      0     0%\ntests/test_tcp_helpers.py                   52     52      2      0     0%\ntests/test_test_utils.py                   242    242      6      0     0%\ntests/test_tracing.py                       48     48      0      0     0%\ntests/test_urldispatch.py                  844    844     24      0     0%\ntests/test_web_app.py                      454    454      6      0     0%\ntests/test_web_cli.py                       75     75      0      0     0%\ntests/test_web_exceptions.py               157    157     22      0     0%\ntests/test_web_functional.py              1520   1520     36      0     0%\ntests/test_web_log.py                      115    115      0      0     0%\ntests/test_web_middleware.py               266    266     12      0     0%\ntests/test_web_request.py                  490    490      8      0     0%\ntests/test_web_request_handler.py           40     40      0      0     0%\ntests/test_web_response.py                 817    817      4      0     0%\ntests/test_web_runner.py                   146    146      4      0     0%\ntests/test_web_sendfile.py                  76     76      0      0     0%\ntests/test_web_sendfile_functional.py      634    634     18      0     0%\ntests/test_web_server.py                   160    160      0      0     0%\ntests/test_web_urldispatcher.py            306    306     14      0     0%\ntests/test_web_websocket.py                304    304      4      0     0%\ntests/test_web_websocket_functional.py     542    542     16      0     0%\ntests/test_websocket_handshake.py          152    152     12      0     0%\ntests/test_websocket_parser.py             300    300     12      0     0%\ntests/test_websocket_writer.py              68     68      0      0     0%\ntests/test_worker.py                       191    191      4      0     0%\n--------------------------------------------------------------------------\nTOTAL                                    31555  26886   4003    386    15%\n\n============================= slowest 10 durations =============================\n0.01s teardown r2e_tests/test_1.py::test_contextvars_logger[pyloop]\n\n(9 durations < 0.005s hidden.  Use -vv to show these durations.)\n=========================== short test summary info ============================\nPASSED r2e_tests/test_1.py::test_access_logger_format\nPASSED r2e_tests/test_1.py::test_access_logger_dicts\nPASSED r2e_tests/test_1.py::test_access_logger_unix_socket\nPASSED r2e_tests/test_1.py::test_logger_no_message\nPASSED r2e_tests/test_1.py::test_logger_internal_error\nPASSED r2e_tests/test_1.py::test_logger_no_transport\nPASSED r2e_tests/test_1.py::test_logger_abc\nPASSED r2e_tests/test_1.py::test_contextvars_logger[pyloop]\nPASSED r2e_tests/test_1.py::test_logger_does_nothing_when_disabled\nFAILED r2e_tests/test_1.py::test_access_logger_atoms[%t-[01/Jan/1843:00:29:56 +0800]-extra0]\nFAILED r2e_tests/test_1.py::test_access_logger_atoms[%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\"-extra1]\n========================= 2 failed, 9 passed in 3.04s ==========================\n",
    "old_commit_res_stderr": ""
}
CHANGES/3853.feature aiohttp/web_log.py tests/test_web_log.py
We are currently solving the following issue within our repository. Here is the issue text:
--- BEGIN ISSUE ---
[ISSUE]
**Title:** Access logs use UTC time without timezone, causing discrepancies in log entries

**Description:**
When generating access logs, the system records timestamps using UTC without including timezone information. This leads to inconsistencies, especially when tests expect logs to use local time with the appropriate timezone.

For example, a test case expects the access log entry to have a timestamp like `[01/Jan/1843:00:29:56 +0800]`, indicating local time with timezone offset. However, the current implementation logs the timestamp as `[01/Jan/1843:00:29:56 +0000]`, which is in UTC without reflecting the local timezone.

```python
# Example of log formatting in the current implementation
now = datetime.datetime.utcnow()
start_time = now - datetime.timedelta(seconds=time)
log_entry = start_time.strftime("[%d/%b/%Y:%H:%M:%S +0000]")
```

**Expected Behavior:**
Access logs should record timestamps using the local time along with the correct timezone information. For instance, the log entry should appear as `[01/Jan/1843:00:29:56 +0800]`, accurately reflecting the server's local timezone.

**Actual Behavior:**
Currently, access logs are recorded in UTC without any timezone offset, resulting in entries like `[01/Jan/1843:00:29:56 +0000]`. This discrepancy causes tests that validate log formats against local time with timezone to fail.

[/ISSUE]
--- END ISSUE ---

Below are some code segments, each from a relevant file. One or more of these files may contain bugs.

--- BEGIN FILE ---
```
### aiohttp/web_log.py
import datetime
import functools
import logging
import os
import re
from collections import namedtuple
from typing import Any, Callable, Dict, Iterable, List, Tuple  # noqa

from .abc import AbstractAccessLogger
from .web_request import BaseRequest
from .web_response import StreamResponse

KeyMethod = namedtuple("KeyMethod", "key method")


class AccessLogger(AbstractAccessLogger):
    """Helper object to log access.

    Usage:
        log = logging.getLogger("spam")
        log_format = "%a %{User-Agent}i"
        access_logger = AccessLogger(log, log_format)
        access_logger.log(request, response, time)

    Format:
        %%  The percent sign
        %a  Remote IP-address (IP-address of proxy if using reverse proxy)
        %t  Time when the request was started to process
        %P  The process ID of the child that serviced the request
        %r  First line of request
        %s  Response status code
        %b  Size of response in bytes, including HTTP headers
        %T  Time taken to serve the request, in seconds
        %Tf Time taken to serve the request, in seconds with floating fraction
            in .06f format
        %D  Time taken to serve the request, in microseconds
        %{FOO}i  request.headers['FOO']
        %{FOO}o  response.headers['FOO']
        %{FOO}e  os.environ['FOO']

    """

    LOG_FORMAT_MAP = {
        "a": "remote_address",
        "t": "request_start_time",
        "P": "process_id",
        "r": "first_request_line",
        "s": "response_status",
        "b": "response_size",
        "T": "request_time",
        "Tf": "request_time_frac",
        "D": "request_time_micro",
        "i": "request_header",
        "o": "response_header",
    }

    LOG_FORMAT = '%a %t "%r" %s %b "%{Referer}i" "%{User-Agent}i"'
    FORMAT_RE = re.compile(r"%(\{([A-Za-z0-9\-_]+)\}([ioe])|[atPrsbOD]|Tf?)")
    CLEANUP_RE = re.compile(r"(%[^s])")
    _FORMAT_CACHE: Dict[str, Tuple[str, List[KeyMethod]]] = {}

    def __init__(self, logger: logging.Logger, log_format: str = LOG_FORMAT) -> None:
        """Initialise the logger.

        logger is a logger object to be used for logging.
        log_format is a string with apache compatible log format description.

        """
        super().__init__(logger, log_format=log_format)

        _compiled_format = AccessLogger._FORMAT_CACHE.get(log_format)
        if not _compiled_format:
            _compiled_format = self.compile_format(log_format)
            AccessLogger._FORMAT_CACHE[log_format] = _compiled_format

        self._log_format, self._methods = _compiled_format

    def compile_format(self, log_format: str) -> Tuple[str, List[KeyMethod]]:
        """Translate log_format into form usable by modulo formatting

        All known atoms will be replaced with %s
        Also methods for formatting of those atoms will be added to
        _methods in appropriate order

        For example we have log_format = "%a %t"
        This format will be translated to "%s %s"
        Also contents of _methods will be
        [self._format_a, self._format_t]
        These method will be called and results will be passed
        to translated string format.

        Each _format_* method receive 'args' which is list of arguments
        given to self.log

        Exceptions are _format_e, _format_i and _format_o methods which
        also receive key name (by functools.partial)

        """
        # list of (key, method) tuples, we don't use an OrderedDict as users
        # can repeat the same key more than once
        methods = list()

        for atom in self.FORMAT_RE.findall(log_format):
            if atom[1] == "":
                format_key1 = self.LOG_FORMAT_MAP[atom[0]]
                m = getattr(AccessLogger, "_format_%s" % atom[0])
                key_method = KeyMethod(format_key1, m)
            else:
                format_key2 = (self.LOG_FORMAT_MAP[atom[2]], atom[1])
                m = getattr(AccessLogger, "_format_%s" % atom[2])
                key_method = KeyMethod(format_key2, functools.partial(m, atom[1]))

            methods.append(key_method)

        log_format = self.FORMAT_RE.sub(r"%s", log_format)
        log_format = self.CLEANUP_RE.sub(r"%\1", log_format)
        return log_format, methods

    @staticmethod
    def _format_i(
        key: str, request: BaseRequest, response: StreamResponse, time: float
    ) -> str:
        if request is None:
            return "(no headers)"

        # suboptimal, make istr(key) once
        return request.headers.get(key, "-")

    @staticmethod
    def _format_o(
        key: str, request: BaseRequest, response: StreamResponse, time: float
    ) -> str:
        # suboptimal, make istr(key) once
        return response.headers.get(key, "-")

    @staticmethod
    def _format_a(request: BaseRequest, response: StreamResponse, time: float) -> str:
        if request is None:
            return "-"
        ip = request.remote
        return ip if ip is not None else "-"

    @staticmethod
    def _format_t(request: BaseRequest, response: StreamResponse, time: float) -> str:
        now = datetime.datetime.utcnow()
        start_time = now - datetime.timedelta(seconds=time)
        return start_time.strftime("[%d/%b/%Y:%H:%M:%S +0000]")

    @staticmethod
    def _format_P(request: BaseRequest, response: StreamResponse, time: float) -> str:
        return "<%s>" % os.getpid()

    @staticmethod
    def _format_r(request: BaseRequest, response: StreamResponse, time: float) -> str:
        if request is None:
            return "-"
        return "{} {} HTTP/{}.{}".format(
            request.method,
            request.path_qs,
            request.version.major,
            request.version.minor,
        )

    @staticmethod
    def _format_s(request: BaseRequest, response: StreamResponse, time: float) -> int:
        return response.status

    @staticmethod
    def _format_b(request: BaseRequest, response: StreamResponse, time: float) -> int:
        return response.body_length

    @staticmethod
    def _format_T(request: BaseRequest, response: StreamResponse, time: float) -> str:
        return str(round(time))

    @staticmethod
    def _format_Tf(request: BaseRequest, response: StreamResponse, time: float) -> str:
        return "%06f" % time

    @staticmethod
    def _format_D(request: BaseRequest, response: StreamResponse, time: float) -> str:
        return str(round(time * 1000000))

    def _format_line(
        self, request: BaseRequest, response: StreamResponse, time: float
    ) -> Iterable[Tuple[str, Callable[[BaseRequest, StreamResponse, float], str]]]:
        return [(key, method(request, response, time)) for key, method in self._methods]

    def log(self, request: BaseRequest, response: StreamResponse, time: float) -> None:
        if not self.logger.isEnabledFor(logging.INFO):
            # Avoid formatting the log line if it will not be emitted.
            return
        try:
            fmt_info = self._format_line(request, response, time)

            values = list()
            extra = dict()
            for key, value in fmt_info:
                values.append(value)

                if key.__class__ is str:
                    extra[key] = value
                else:
                    k1, k2 = key  # type: ignore[misc]
                    dct = extra.get(k1, {})  # type: ignore[var-annotated,has-type]
                    dct[k2] = value  # type: ignore[index,has-type]
                    extra[k1] = dct  # type: ignore[has-type,assignment]

            self.logger.info(self._log_format % tuple(values), extra=extra)
        except Exception:
            self.logger.exception("Error in logging")

```
--- END FILE ---

Please first localize the bug based on the issue statement, and then generate *SEARCH/REPLACE* edits to fix the issue.

Every *SEARCH/REPLACE* edit must use this format:
1. The file path
2. The start of search block: <<<<<<< SEARCH
3. A contiguous chunk of lines to search for in the existing source code
4. The dividing line: =======
5. The lines to replace into the source code
6. The end of the replace block: >>>>>>> REPLACE

Here is an example:

```python
### mathweb/flask/app.py
<<<<<<< SEARCH
from flask import Flask
=======
import math
from flask import Flask
>>>>>>> REPLACE
```
</solution>

Please note that the *SEARCH/REPLACE* edit REQUIRES PROPER INDENTATION. If you would like to add the line '        print(x)', you must fully write that out, with all those spaces before the code!
Wrap each *SEARCH/REPLACE* edit in a code block as shown in the example above. If you have multiple *SEARCH/REPLACE* edits, use a separate code block for each one.
[ISSUE]
**Title:** Access logs use UTC time without timezone, causing discrepancies in log entries

**Description:**
When generating access logs, the system records timestamps using UTC without including timezone information. This leads to inconsistencies, especially when tests expect logs to use local time with the appropriate timezone.

For example, a test case expects the access log entry to have a timestamp like `[01/Jan/1843:00:29:56 +0800]`, indicating local time with timezone offset. However, the current implementation logs the timestamp as `[01/Jan/1843:00:29:56 +0000]`, which is in UTC without reflecting the local timezone.

```python
# Example of log formatting in the current implementation
now = datetime.datetime.utcnow()
start_time = now - datetime.timedelta(seconds=time)
log_entry = start_time.strftime("[%d/%b/%Y:%H:%M:%S +0000]")
```

**Expected Behavior:**
Access logs should record timestamps using the local time along with the correct timezone information. For instance, the log entry should appear as `[01/Jan/1843:00:29:56 +0800]`, accurately reflecting the server's local timezone.

**Actual Behavior:**
Currently, access logs are recorded in UTC without any timezone offset, resulting in entries like `[01/Jan/1843:00:29:56 +0000]`. This discrepancy causes tests that validate log formats against local time with timezone to fail.

[/ISSUE]
{
    "test_access_logger_format": "PASSED",
    "test_access_logger_atoms[%t-[01/Jan/1843:00:29:56 +0800]-extra0]": "PASSED",
    "test_access_logger_atoms[%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\"-extra1]": "PASSED",
    "test_access_logger_dicts": "PASSED",
    "test_access_logger_unix_socket": "PASSED",
    "test_logger_no_message": "PASSED",
    "test_logger_internal_error": "PASSED",
    "test_logger_no_transport": "PASSED",
    "test_logger_abc": "PASSED",
    "test_contextvars_logger[pyloop]": "PASSED",
    "test_logger_does_nothing_when_disabled": "PASSED"
}
diff --git a/aiohttp/web_log.py b/aiohttp/web_log.py
index abc0bf9a..633e9e3a 100644
--- a/aiohttp/web_log.py
+++ b/aiohttp/web_log.py
@@ -3,6 +3,7 @@ import functools
 import logging
 import os
 import re
+import time as time_mod
 from collections import namedtuple
 from typing import Any, Callable, Dict, Iterable, List, Tuple  # noqa
 
@@ -142,9 +143,10 @@ class AccessLogger(AbstractAccessLogger):
 
     @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:

{"aiohttp/web_log.py": "import datetime\nimport functools\nimport logging\nimport os\nimport re\nfrom collections import namedtuple\nfrom typing import Any, Callable, Dict, Iterable, List, Tuple  # noqa\n\nfrom .abc import AbstractAccessLogger\nfrom .web_request import BaseRequest\nfrom .web_response import StreamResponse\n\nKeyMethod = namedtuple(\"KeyMethod\", \"key method\")\n\n\nclass AccessLogger(AbstractAccessLogger):\n    \"\"\"Helper object to log access.\n\n    Usage:\n        log = logging.getLogger(\"spam\")\n        log_format = \"%a %{User-Agent}i\"\n        access_logger = AccessLogger(log, log_format)\n        access_logger.log(request, response, time)\n\n    Format:\n        %%  The percent sign\n        %a  Remote IP-address (IP-address of proxy if using reverse proxy)\n        %t  Time when the request was started to process\n        %P  The process ID of the child that serviced the request\n        %r  First line of request\n        %s  Response status code\n        %b  Size of response in bytes, including HTTP headers\n        %T  Time taken to serve the request, in seconds\n        %Tf Time taken to serve the request, in seconds with floating fraction\n            in .06f format\n        %D  Time taken to serve the request, in microseconds\n        %{FOO}i  request.headers['FOO']\n        %{FOO}o  response.headers['FOO']\n        %{FOO}e  os.environ['FOO']\n\n    \"\"\"\n\n    LOG_FORMAT_MAP = {\n        \"a\": \"remote_address\",\n        \"t\": \"request_start_time\",\n        \"P\": \"process_id\",\n        \"r\": \"first_request_line\",\n        \"s\": \"response_status\",\n        \"b\": \"response_size\",\n        \"T\": \"request_time\",\n        \"Tf\": \"request_time_frac\",\n        \"D\": \"request_time_micro\",\n        \"i\": \"request_header\",\n        \"o\": \"response_header\",\n    }\n\n    LOG_FORMAT = '%a %t \"%r\" %s %b \"%{Referer}i\" \"%{User-Agent}i\"'\n    FORMAT_RE = re.compile(r\"%(\\{([A-Za-z0-9\\-_]+)\\}([ioe])|[atPrsbOD]|Tf?)\")\n    CLEANUP_RE = re.compile(r\"(%[^s])\")\n    _FORMAT_CACHE: Dict[str, Tuple[str, List[KeyMethod]]] = {}\n\n    def __init__(self, logger: logging.Logger, log_format: str = LOG_FORMAT) -> None:\n        \"\"\"Initialise the logger.\n\n        logger is a logger object to be used for logging.\n        log_format is a string with apache compatible log format description.\n\n        \"\"\"\n        super().__init__(logger, log_format=log_format)\n\n        _compiled_format = AccessLogger._FORMAT_CACHE.get(log_format)\n        if not _compiled_format:\n            _compiled_format = self.compile_format(log_format)\n            AccessLogger._FORMAT_CACHE[log_format] = _compiled_format\n\n        self._log_format, self._methods = _compiled_format\n\n    def compile_format(self, log_format: str) -> Tuple[str, List[KeyMethod]]:\n        \"\"\"Translate log_format into form usable by modulo formatting\n\n        All known atoms will be replaced with %s\n        Also methods for formatting of those atoms will be added to\n        _methods in appropriate order\n\n        For example we have log_format = \"%a %t\"\n        This format will be translated to \"%s %s\"\n        Also contents of _methods will be\n        [self._format_a, self._format_t]\n        These method will be called and results will be passed\n        to translated string format.\n\n        Each _format_* method receive 'args' which is list of arguments\n        given to self.log\n\n        Exceptions are _format_e, _format_i and _format_o methods which\n        also receive key name (by functools.partial)\n\n        \"\"\"\n        # list of (key, method) tuples, we don't use an OrderedDict as users\n        # can repeat the same key more than once\n        methods = list()\n\n        for atom in self.FORMAT_RE.findall(log_format):\n            if atom[1] == \"\":\n                format_key1 = self.LOG_FORMAT_MAP[atom[0]]\n                m = getattr(AccessLogger, \"_format_%s\" % atom[0])\n                key_method = KeyMethod(format_key1, m)\n            else:\n                format_key2 = (self.LOG_FORMAT_MAP[atom[2]], atom[1])\n                m = getattr(AccessLogger, \"_format_%s\" % atom[2])\n                key_method = KeyMethod(format_key2, functools.partial(m, atom[1]))\n\n            methods.append(key_method)\n\n        log_format = self.FORMAT_RE.sub(r\"%s\", log_format)\n        log_format = self.CLEANUP_RE.sub(r\"%\\1\", log_format)\n        return log_format, methods\n\n    @staticmethod\n    def _format_i(\n        key: str, request: BaseRequest, response: StreamResponse, time: float\n    ) -> str:\n        if request is None:\n            return \"(no headers)\"\n\n        # suboptimal, make istr(key) once\n        return request.headers.get(key, \"-\")\n\n    @staticmethod\n    def _format_o(\n        key: str, request: BaseRequest, response: StreamResponse, time: float\n    ) -> str:\n        # suboptimal, make istr(key) once\n        return response.headers.get(key, \"-\")\n\n    @staticmethod\n    def _format_a(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        if request is None:\n            return \"-\"\n        ip = request.remote\n        return ip if ip is not None else \"-\"\n\n    @staticmethod\n    def _format_t(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        now = datetime.datetime.utcnow()\n        start_time = now - datetime.timedelta(seconds=time)\n        return start_time.strftime(\"[%d/%b/%Y:%H:%M:%S +0000]\")\n\n    @staticmethod\n    def _format_P(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return \"<%s>\" % os.getpid()\n\n    @staticmethod\n    def _format_r(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        if request is None:\n            return \"-\"\n        return \"{} {} HTTP/{}.{}\".format(\n            request.method,\n            request.path_qs,\n            request.version.major,\n            request.version.minor,\n        )\n\n    @staticmethod\n    def _format_s(request: BaseRequest, response: StreamResponse, time: float) -> int:\n        return response.status\n\n    @staticmethod\n    def _format_b(request: BaseRequest, response: StreamResponse, time: float) -> int:\n        return response.body_length\n\n    @staticmethod\n    def _format_T(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return str(round(time))\n\n    @staticmethod\n    def _format_Tf(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return \"%06f\" % time\n\n    @staticmethod\n    def _format_D(request: BaseRequest, response: StreamResponse, time: float) -> str:\n        return str(round(time * 1000000))\n\n    def _format_line(\n        self, request: BaseRequest, response: StreamResponse, time: float\n    ) -> Iterable[Tuple[str, Callable[[BaseRequest, StreamResponse, float], str]]]:\n        return [(key, method(request, response, time)) for key, method in self._methods]\n\n    def log(self, request: BaseRequest, response: StreamResponse, time: float) -> None:\n        if not self.logger.isEnabledFor(logging.INFO):\n            # Avoid formatting the log line if it will not be emitted.\n            return\n        try:\n            fmt_info = self._format_line(request, response, time)\n\n            values = list()\n            extra = dict()\n            for key, value in fmt_info:\n                values.append(value)\n\n                if key.__class__ is str:\n                    extra[key] = value\n                else:\n                    k1, k2 = key  # type: ignore[misc]\n                    dct = extra.get(k1, {})  # type: ignore[var-annotated,has-type]\n                    dct[k2] = value  # type: ignore[index,has-type]\n                    extra[k1] = dct  # type: ignore[has-type,assignment]\n\n            self.logger.info(self._log_format % tuple(values), extra=extra)\n        except Exception:\n            self.logger.exception(\"Error in logging\")\n"}
A user will ask you to solve a task. You should first draft your thinking process (inner monologue). Then, generate the solution.

Your response format must follow the template below:
<think>
Your thoughts or/and draft, like working through an exercise on scratch paper. Be as casual and as long as you want until you are confident to generate a correct solution.
</think>
<solution>
Final solution presented to the user.
</solution>
system
We are currently solving the following issue within our repository. Here is the issue text:
--- BEGIN ISSUE ---
[ISSUE]
**Title:** Access logs use UTC time without timezone, causing discrepancies in log entries

**Description:**
When generating access logs, the system records timestamps using UTC without including timezone information. This leads to inconsistencies, especially when tests expect logs to use local time with the appropriate timezone.

For example, a test case expects the access log entry to have a timestamp like `[01/Jan/1843:00:29:56 +0800]`, indicating local time with timezone offset. However, the current implementation logs the timestamp as `[01/Jan/1843:00:29:56 +0000]`, which is in UTC without reflecting the local timezone.

```python
# Example of log formatting in the current implementation
now = datetime.datetime.utcnow()
start_time = now - datetime.timedelta(seconds=time)
log_entry = start_time.strftime("[%d/%b/%Y:%H:%M:%S +0000]")
```

**Expected Behavior:**
Access logs should record timestamps using the local time along with the correct timezone information. For instance, the log entry should appear as `[01/Jan/1843:00:29:56 +0800]`, accurately reflecting the server's local timezone.

**Actual Behavior:**
Currently, access logs are recorded in UTC without any timezone offset, resulting in entries like `[01/Jan/1843:00:29:56 +0000]`. This discrepancy causes tests that validate log formats against local time with timezone to fail.

[/ISSUE]
--- END ISSUE ---

Below are some code segments, each from a relevant file. One or more of these files may contain bugs.

--- BEGIN FILE ---
```
### aiohttp/web_log.py
import datetime
import functools
import logging
import os
import re
from collections import namedtuple
from typing import Any, Callable, Dict, Iterable, List, Tuple  # noqa

from .abc import AbstractAccessLogger
from .web_request import BaseRequest
from .web_response import StreamResponse

KeyMethod = namedtuple("KeyMethod", "key method")


class AccessLogger(AbstractAccessLogger):
    """Helper object to log access.

    Usage:
        log = logging.getLogger("spam")
        log_format = "%a %{User-Agent}i"
        access_logger = AccessLogger(log, log_format)
        access_logger.log(request, response, time)

    Format:
        %%  The percent sign
        %a  Remote IP-address (IP-address of proxy if using reverse proxy)
        %t  Time when the request was started to process
        %P  The process ID of the child that serviced the request
        %r  First line of request
        %s  Response status code
        %b  Size of response in bytes, including HTTP headers
        %T  Time taken to serve the request, in seconds
        %Tf Time taken to serve the request, in seconds with floating fraction
            in .06f format
        %D  Time taken to serve the request, in microseconds
        %{FOO}i  request.headers['FOO']
        %{FOO}o  response.headers['FOO']
        %{FOO}e  os.environ['FOO']

    """

    LOG_FORMAT_MAP = {
        "a": "remote_address",
        "t": "request_start_time",
        "P": "process_id",
        "r": "first_request_line",
        "s": "response_status",
        "b": "response_size",
        "T": "request_time",
        "Tf": "request_time_frac",
        "D": "request_time_micro",
        "i": "request_header",
        "o": "response_header",
    }

    LOG_FORMAT = '%a %t "%r" %s %b "%{Referer}i" "%{User-Agent}i"'
    FORMAT_RE = re.compile(r"%(\{([A-Za-z0-9\-_]+)\}([ioe])|[atPrsbOD]|Tf?)")
    CLEANUP_RE = re.compile(r"(%[^s])")
    _FORMAT_CACHE: Dict[str, Tuple[str, List[KeyMethod]]] = {}

    def __init__(self, logger: logging.Logger, log_format: str = LOG_FORMAT) -> None:
        """Initialise the logger.

        logger is a logger object to be used for logging.
        log_format is a string with apache compatible log format description.

        """
        super().__init__(logger, log_format=log_format)

        _compiled_format = AccessLogger._FORMAT_CACHE.get(log_format)
        if not _compiled_format:
            _compiled_format = self.compile_format(log_format)
            AccessLogger._FORMAT_CACHE[log_format] = _compiled_format

        self._log_format, self._methods = _compiled_format

    def compile_format(self, log_format: str) -> Tuple[str, List[KeyMethod]]:
        """Translate log_format into form usable by modulo formatting

        All known atoms will be replaced with %s
        Also methods for formatting of those atoms will be added to
        _methods in appropriate order

        For example we have log_format = "%a %t"
        This format will be translated to "%s %s"
        Also contents of _methods will be
        [self._format_a, self._format_t]
        These method will be called and results will be passed
        to translated string format.

        Each _format_* method receive 'args' which is list of arguments
        given to self.log

        Exceptions are _format_e, _format_i and _format_o methods which
        also receive key name (by functools.partial)

        """
        # list of (key, method) tuples, we don't use an OrderedDict as users
        # can repeat the same key more than once
        methods = list()

        for atom in self.FORMAT_RE.findall(log_format):
            if atom[1] == "":
                format_key1 = self.LOG_FORMAT_MAP[atom[0]]
                m = getattr(AccessLogger, "_format_%s" % atom[0])
                key_method = KeyMethod(format_key1, m)
            else:
                format_key2 = (self.LOG_FORMAT_MAP[atom[2]], atom[1])
                m = getattr(AccessLogger, "_format_%s" % atom[2])
                key_method = KeyMethod(format_key2, functools.partial(m, atom[1]))

            methods.append(key_method)

        log_format = self.FORMAT_RE.sub(r"%s", log_format)
        log_format = self.CLEANUP_RE.sub(r"%\1", log_format)
        return log_format, methods

    @staticmethod
    def _format_i(
        key: str, request: BaseRequest, response: StreamResponse, time: float
    ) -> str:
        if request is None:
            return "(no headers)"

        # suboptimal, make istr(key) once
        return request.headers.get(key, "-")

    @staticmethod
    def _format_o(
        key: str, request: BaseRequest, response: StreamResponse, time: float
    ) -> str:
        # suboptimal, make istr(key) once
        return response.headers.get(key, "-")

    @staticmethod
    def _format_a(request: BaseRequest, response: StreamResponse, time: float) -> str:
        if request is None:
            return "-"
        ip = request.remote
        return ip if ip is not None else "-"

    @staticmethod
    def _format_t(request: BaseRequest, response: StreamResponse, time: float) -> str:
        now = datetime.datetime.utcnow()
        start_time = now - datetime.timedelta(seconds=time)
        return start_time.strftime("[%d/%b/%Y:%H:%M:%S +0000]")

    @staticmethod
    def _format_P(request: BaseRequest, response: StreamResponse, time: float) -> str:
        return "<%s>" % os.getpid()

    @staticmethod
    def _format_r(request: BaseRequest, response: StreamResponse, time: float) -> str:
        if request is None:
            return "-"
        return "{} {} HTTP/{}.{}".format(
            request.method,
            request.path_qs,
            request.version.major,
            request.version.minor,
        )

    @staticmethod
    def _format_s(request: BaseRequest, response: StreamResponse, time: float) -> int:
        return response.status

    @staticmethod
    def _format_b(request: BaseRequest, response: StreamResponse, time: float) -> int:
        return response.body_length

    @staticmethod
    def _format_T(request: BaseRequest, response: StreamResponse, time: float) -> str:
        return str(round(time))

    @staticmethod
    def _format_Tf(request: BaseRequest, response: StreamResponse, time: float) -> str:
        return "%06f" % time

    @staticmethod
    def _format_D(request: BaseRequest, response: StreamResponse, time: float) -> str:
        return str(round(time * 1000000))

    def _format_line(
        self, request: BaseRequest, response: StreamResponse, time: float
    ) -> Iterable[Tuple[str, Callable[[BaseRequest, StreamResponse, float], str]]]:
        return [(key, method(request, response, time)) for key, method in self._methods]

    def log(self, request: BaseRequest, response: StreamResponse, time: float) -> None:
        if not self.logger.isEnabledFor(logging.INFO):
            # Avoid formatting the log line if it will not be emitted.
            return
        try:
            fmt_info = self._format_line(request, response, time)

            values = list()
            extra = dict()
            for key, value in fmt_info:
                values.append(value)

                if key.__class__ is str:
                    extra[key] = value
                else:
                    k1, k2 = key  # type: ignore[misc]
                    dct = extra.get(k1, {})  # type: ignore[var-annotated,has-type]
                    dct[k2] = value  # type: ignore[index,has-type]
                    extra[k1] = dct  # type: ignore[has-type,assignment]

            self.logger.info(self._log_format % tuple(values), extra=extra)
        except Exception:
            self.logger.exception("Error in logging")

```
--- END FILE ---

Please first localize the bug based on the issue statement, and then generate *SEARCH/REPLACE* edits to fix the issue.

Every *SEARCH/REPLACE* edit must use this format:
1. The file path
2. The start of search block: <<<<<<< SEARCH
3. A contiguous chunk of lines to search for in the existing source code
4. The dividing line: =======
5. The lines to replace into the source code
6. The end of the replace block: >>>>>>> REPLACE

Here is an example:

```python
### mathweb/flask/app.py
<<<<<<< SEARCH
from flask import Flask
=======
import math
from flask import Flask
>>>>>>> REPLACE
```
</solution>

Please note that the *SEARCH/REPLACE* edit REQUIRES PROPER INDENTATION. If you would like to add the line '        print(x)', you must fully write that out, with all those spaces before the code!
Wrap each *SEARCH/REPLACE* edit in a code block as shown in the example above. If you have multiple *SEARCH/REPLACE* edits, use a separate code block for each one.
user