Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Ability to use contextvars in logger #3804

Merged
merged 1 commit into from Jul 12, 2019
Merged
Changes from all commits
Commits
File filter...
Filter file types
Jump to…
Jump to file or symbol
Failed to load files and symbols.

Always

Just for now

added ability to use contextvars in logger

  • Loading branch information
hh-h committed May 27, 2019
commit a89226d9dc796bcad3b806c02d5cbd73e5f7539f
@@ -0,0 +1 @@
Added ability to use contextvars in logger
@@ -141,6 +141,7 @@ Kay Zheng
Kimmo Parviainen-Jalanko
Kirill Klenov
Kirill Malovitsa
Konstantin Valetov
Kyrylo Perevozchikov
Lars P. Søndergaard
Louis-Philippe Huberdeau
@@ -12,6 +12,7 @@
Awaitable,
Callable,
Optional,
Tuple,
Type,
Union,
cast,
@@ -399,6 +400,33 @@ def _process_keepalive(self) -> None:
self._keepalive_handle = self._loop.call_later(
self.KEEPALIVE_RESCHEDULE_DELAY, self._process_keepalive)

async def _handle_request(self,
request: BaseRequest,
start_time: float,
) -> Tuple[StreamResponse, bool]:
assert self._request_handler is not None
try:
resp = await self._request_handler(request)
except HTTPException as exc:
resp = Response(status=exc.status,
reason=exc.reason,
text=exc.text,
headers=exc.headers)
reset = await self.finish_response(request, resp, start_time)
except asyncio.CancelledError:
raise
except asyncio.TimeoutError as exc:
self.log_debug('Request handler timed out.', exc_info=exc)
resp = self.handle_error(request, 504)
reset = await self.finish_response(request, resp, start_time)
except Exception as exc:
resp = self.handle_error(request, 500, exc)
reset = await self.finish_response(request, resp, start_time)
else:
reset = await self.finish_response(request, resp, start_time)

return resp, reset

async def start(self) -> None:
"""Process incoming request.
@@ -440,27 +468,12 @@ def _process_keepalive(self) -> None:
try:
# a new task is used for copy context vars (#3406)
task = self._loop.create_task(
self._request_handler(request))
self._handle_request(request, start))
try:
resp = await task
except HTTPException as exc:
resp = Response(status=exc.status,
reason=exc.reason,
text=exc.text,
headers=exc.headers)
reset = await self.finish_response(request, resp, start)
resp, reset = await task
except asyncio.CancelledError:
self.log_debug('Ignored premature client disconnection')
break
except asyncio.TimeoutError as exc:
self.log_debug('Request handler timed out.', exc_info=exc)
resp = self.handle_error(request, 504)
reset = await self.finish_response(request, resp, start)
except Exception as exc:
resp = self.handle_error(request, 500, exc)
reset = await self.finish_response(request, resp, start)
else:
reset = await self.finish_response(request, resp, start)

# Drop the processed task from asyncio.Task.all_tasks() early
del task
@@ -5,10 +5,17 @@

import pytest

from aiohttp import web
from aiohttp.abc import AbstractAccessLogger, AbstractAsyncAccessLogger
from aiohttp.helpers import PY_37
from aiohttp.web_log import AccessLogger
from aiohttp.web_response import Response

try:
from contextvars import ContextVar
except ImportError:
ContextVar = None

IS_PYPY = platform.python_implementation() == 'PyPy'


@@ -214,3 +221,31 @@ class Logger(AbstractAsyncAccessLogger):
resp = await cli.get('/path/to', headers={'Accept': 'text/html'})
assert resp.status == 200
assert msg == '/path/to: 200'


@pytest.mark.skipif(not PY_37,
reason="contextvars support is required")
async def test_contextvars_logger(aiohttp_server, aiohttp_client):
VAR = ContextVar('VAR')

async def handler(request):
return web.Response()

async def middleware(request, handler):
VAR.set("uuid")
return await handler(request)

msg = None

class Logger(AbstractAccessLogger):
def log(self, request, response, time):
nonlocal msg
msg = 'contextvars: {}'.format(VAR.get())

app = web.Application(middlewares=[middleware])
app.router.add_get('/', handler)
server = await aiohttp_server(app, access_log_class=Logger)
client = await aiohttp_client(server)
resp = await client.get('/')
assert 200 == resp.status
assert msg == 'contextvars: uuid'
@@ -362,7 +362,7 @@ def close():
b'GET / HTTP/1.1\r\n'
b'Host: example.com\r\n'
b'Content-Length: 0\r\n\r\n')
await asyncio.sleep(0)
await asyncio.sleep(0.01)
This conversation was marked as resolved by webknjaz

This comment has been minimized.

Copy link
@webknjaz

webknjaz Jul 7, 2019

Member

Doesn't seem related.

This comment has been minimized.

Copy link
@hh-h

hh-h Jul 7, 2019

Author Contributor

Otherwise some tests are failing, my guess it's because I had to await one more task, so 0 is not enough.


# with exception
request_handler.side_effect = handle_with_error()
@@ -373,7 +373,7 @@ def close():

assert srv._task_handler

await asyncio.sleep(0)
await asyncio.sleep(0.01)

await srv._task_handler
assert normal_completed
@@ -585,7 +585,7 @@ def test_keep_alive_timeout_nondefault(make_srv) -> None:
b'GET / HTTP/1.1\r\n'
b'Host: example.org\r\n'
b'Content-Length: 0\r\n\r\n')
await asyncio.sleep(0)
await asyncio.sleep(0.01)

assert request_handler.called
assert request_handler.call_args[0][0].content == streams.EMPTY_PAYLOAD
@@ -702,7 +702,7 @@ def test_rudimentary_transport(srv) -> None:
b'GET / HTTP/1.1\r\n'
b'Host: example.com\r\n'
b'Content-Length: 0\r\n\r\n')
await asyncio.sleep(0)
await asyncio.sleep(0.01)

# second

@@ -720,7 +720,7 @@ def test_rudimentary_transport(srv) -> None:
b'GET / HTTP/1.1\r\n'
b'Host: example.com\r\n'
b'Content-Length: 0\r\n\r\n')
await asyncio.sleep(0)
await asyncio.sleep(0.01)

assert srv._task_handler is not None

@@ -835,4 +835,4 @@ def test_data_received_force_close(srv) -> None:
writer.write(b"x")
writer.close()
await asyncio.sleep(0.1)
logger.debug.assert_called_with('Ignored premature client disconnection 2')
logger.debug.assert_called_with('Ignored premature client disconnection.')
This conversation was marked as resolved by webknjaz

This comment has been minimized.

Copy link
@webknjaz

webknjaz Jul 7, 2019

Member

How is this related to the contextvars change?

This comment has been minimized.

Copy link
@hh-h

hh-h Jul 7, 2019

Author Contributor

This fixed tests, because I extracted some logic into _handle_request

This comment has been minimized.

Copy link
@hh-h
@@ -89,7 +89,7 @@
with pytest.raises(client.ClientPayloadError):
await resp.read()

logger.debug.assert_called_with('Ignored premature client disconnection ')
logger.debug.assert_called_with('Ignored premature client disconnection')
This conversation was marked as resolved by webknjaz

This comment has been minimized.

Copy link
@webknjaz

webknjaz Jul 7, 2019

Member

unrelated

This comment has been minimized.

Copy link
@hh-h

hh-h Jul 7, 2019

Author Contributor

see my comment above



async def test_raw_server_not_http_exception_debug(aiohttp_raw_server,
ProTip! Use n and p to navigate between commits in a pull request.
You can’t perform that action at this time.