terricain / sanic-json-logging

JSON Logging for Sanic
Apache License 2.0
10 stars 4 forks source link

Type error with incoming request #100

Closed maxkrivich closed 3 years ago

maxkrivich commented 4 years ago

Here's a small example of my error, the most obvious solution is to use hasattr or .get, but I have not idea what going on underhood of this lib.

uvicorn server:app --host 0.0.0.0 --port 5000 --loop uvloop --workers 2 --reload                                                    mkryvy@MacBook-Pro
INFO:     Uvicorn running on http://0.0.0.0:5000 (Press CTRL+C to quit)
INFO:     Started reloader process [93864] using statreload
INFO:     Started server process [93866]
{"timestamp": "2020-07-29T21:53:18.149500Z", "level": "INFO", "message": "Started server process [93866]", "type": "log", "logger": "uvicorn.error", "worker": 93866, "filename": "main.py", "lineno": 405}
INFO:     Waiting for application startup.
{"timestamp": "2020-07-29T21:53:18.149989Z", "level": "INFO", "message": "Waiting for application startup.", "type": "log", "logger": "uvicorn.error", "worker": 93866, "filename": "on.py", "lineno": 22}
INFO:     Application startup complete.
{"timestamp": "2020-07-29T21:53:18.150262Z", "level": "INFO", "message": "Application startup complete.", "type": "log", "logger": "uvicorn.error", "worker": 93866, "filename": "on.py", "lineno": 34}
{"timestamp": "2020-07-29T21:53:22.634855Z", "level": "ERROR", "message": "Exception occurred in one of response middleware handlers", "type": "exception", "logger": "sanic.error", "worker": 93866, "filename": "app.py", "lineno": 984, "traceback": "Traceback (most recent call last):<br>  File \"/Users/mkryvy/.local/share/virtualenvs/echo_service-W3-tao-R/lib/python3.8/site-packages/sanic/app.py\", line 976, in handle_request<br>    response = await self._run_response_middleware(<br>  File \"/Users/mkryvy/.local/share/virtualenvs/echo_service-W3-tao-R/lib/python3.8/site-packages/sanic/app.py\", line 1281, in _run_response_middleware<br>    _response = await _response<br>  File \"/Users/mkryvy/.local/share/virtualenvs/echo_service-W3-tao-R/lib/python3.8/site-packages/sanic_json_logging/__init__.py\", line 79, in log_json_post<br>    if 'req_id' in request:<br>TypeError: argument of type 'Request' is not iterable", "req_id": "e564a655-0696-485d-b75b-a3e2e4e1155b"}
INFO:     127.0.0.1:53246 - "GET /ping HTTP/1.1" 200 OK

(REMARK: Looks like you are doing the check of attr not in a super-efficient way)

 78                 # Pre middleware doesnt run on exception
 79                 import pdb; pdb.set_trace()
 80  ->             if 'req_id' in request:
 81                     req_id = request.ctx.req_id
 82                     time_taken = time.perf_counter() - request.ctx.req_start
 83                 else:
 84                     req_id = str(uuid.uuid4())
 85                     time_taken = -1

From documentation of this method, it's hard to understand what request type is

(Pdb) type(request)
<class 'sanic.request.Request'>
(Pdb) dir(request)
['__class__', '__delattr__', '__dir__', '__doc__', '__eq__', '__format__', '__ge__', '__getattribute__', '__gt__', '__hash__', '__init__', '__init_subclass__', '__le__', '__lt__', '__module__', '__ne__', '__new__', '__reduce__', '__reduce_ex__', '__repr__', '__setattr__', '__sizeof__', '__slots__', '__str__', '__subclasshook__', '__weakref__', '_cookies', '_ip', '_parsed_url', '_port', '_remote_addr', '_socket', 'app', 'args', 'body', 'body_finish', 'body_init', 'body_push', 'conn_info', 'content_type', 'cookies', 'ctx', 'endpoint', 'files', 'form', 'forwarded', 'get_args', 'get_query_args', 'headers', 'host', 'ip', 'json', 'load_json', 'match_info', 'method', 'parsed_args', 'parsed_files', 'parsed_form', 'parsed_forwarded', 'parsed_json', 'parsed_not_grouped_args', 'path', 'port', 'query_args', 'query_string', 'raw_url', 'receive_body', 'remote_addr', 'scheme', 'server_name', 'server_path', 'server_port', 'socket', 'stream', 'token', 'transport', 'uri_template', 'url', 'url_for', 'version']
(Pdb) 'a' in request
*** TypeError: argument of type 'Request' is not iterable
(Pdb) request.ctx
namespace(req_id='f64b0384-2459-4178-84d1-db2d0737f38a', req_start=7.191887143)
(Pdb)

My env: Python 3.8

-i https://pypi.org/simple
aiofiles==0.5.0
certifi==2020.6.20
chardet==3.0.4
click==7.1.2; python_version >= '2.7' and python_version not in '3.0, 3.1, 3.2, 3.3, 3.4'
h11==0.9.0
h2==3.2.0
hpack==3.0.0
hstspreload==2020.7.29; python_version >= '3.6'
httptools==0.1.1; sys_platform != 'win32' and sys_platform != 'cygwin' and platform_python_implementation != 'PyPy'
httpx==0.11.1; python_version >= '3.6'
hyperframe==5.2.0
idna==2.10; python_version >= '2.7' and python_version not in '3.0, 3.1, 3.2, 3.3'
multidict==4.7.6; python_version >= '3.5'
rfc3986==1.4.0
sanic-json-logging==3.2.0
sanic==20.6.3
sniffio==1.1.0; python_version >= '3.5'
ujson==3.0.0
urllib3==1.25.10; python_version >= '2.7' and python_version not in '3.0, 3.1, 3.2, 3.3, 3.4' and python_version < '4'
uvicorn==0.11.7
uvloop==0.14.0
websockets==8.1; python_full_version >= '3.6.1'
maxkrivich commented 4 years ago

Tested on sanic==19.12.0 and it works, so just add compatibility with new sanic.

terricain commented 4 years ago

Ugh yeah I rushed that part the other day as it wasn't working with newer sanic, I'll fix the if statement on the weekend

BouweCeunen commented 3 years ago

This is still an issue I believe? There hasn't been a release after this date it seems.

terricain commented 3 years ago

Yeah my bad, it seems travis died. Will look into moving this to github actions

terricain commented 3 years ago

I've released 4.0.0 so that should solve things for you.