terricain / sanic-json-logging Goto Github PK
View Code? Open in Web Editor NEWJSON Logging for Sanic
License: Apache License 2.0
JSON Logging for Sanic
License: Apache License 2.0
The bot created this issue to inform you that pyup.io has been set up on this repo.
Once you have closed it, the bot will open pull requests for updates as soon as they are available.
Sanic version 19.6.2
Simple API app with GET methods, JSON responses
Default setup of sanic_json_logging.
I get:
--- Logging error ---
Traceback (most recent call last):
File "/usr/local/Cellar/python/3.7.4_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/logging/init.py", line 1025, in emit
msg = self.format(record)
File "/usr/local/Cellar/python/3.7.4_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/logging/init.py", line 869, in format
return fmt.format(record)
File "/Users/mark/ibis/devel/src/publicapi-server/venv/lib/python3.7/site-packages/sanic_json_logging/formatters.py", line 167, in format
ip = record.request.headers.get('X-Forwarded-For', record.request.ip)
AttributeError: 'str' object has no attribute 'headers'
on every request. Am I running an incompatible version of Sanic? Why would record.request
be a string object in this case?
Thanks - I've been wanting JSON access logs for AWS and Elasticsearch as well, appreciate you building a library for this!
Using this in a microservice architecture, the User-Agent
header is not always sent. The JSONReqFormatter
has a hard coded expectation that User-Agent
is in the request headers. So if User-Agent
isn't passed it throws.
USed your package for one of the projects and this error came up
File /usr/local/lib/python3.6/site-packages/sanic_json_logging/init.py, line 48, in log_json_pre
current_task.context['req_id'] = req_id
What can i do to fix it?
TypeError: 'Context' object does not support item assignment while handling path
if hasattr(record.response, 'body'):
message['length'] = len(record.response.body)
else:
message['length'] = -1
Do
request['req_id'] = str(uuid.uuid4())
request['req_start'] = time.perf_counter()
And the equiv in response middleware
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'
Hi there!
I'm wondering if there's a way to grab the request ID within the context of a request handler. This would be great for being able to forward the request ID, as I make requests to other services, so that I can follow the entire request trace path.
I tried looking through the req object that gets handed through to a handler, but I couldn't find the req_id anywhere.
Thanks!
Hi. Maybe I'm doing something wrong, but it doesn't want to work for for me.
Here is what I get when I use disable_json_access_log=False
setup_json_logging(app, disable_json_access_log=False, configure_task_local_storage=False)
{"timestamp": "2021-12-07T13:42:05.399182Z", "level": "INFO", "method": "GET", "type": "access", "path": "/test", "remote": "127.0.0.1:44290", "user_agent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:94.0) Gecko/20100101 Firefox/94.0", "host": "localhost:8000", "response_time": 0.0, "req_id": "50aea029-7e0b-4c77-8eba-d3066077012f", "logger": "sanic.access", "worker": 18340, "status_code": 200, "length": 4}
--- Logging error ---
Traceback (most recent call last):
File "/home/dave/.pyenv/versions/3.9.0/lib/python3.9/logging/__init__.py", line 1079, in emit
msg = self.format(record)
File "/home/dave/.pyenv/versions/3.9.0/lib/python3.9/logging/__init__.py", line 923, in format
return fmt.format(record)
File "/home/dave/.local/share/virtualenvs/sanic-f0iRZCxx/lib/python3.9/site-packages/sanic_json_logging/formatters.py", line 174, in format
ip = record.request.headers.get("X-Forwarded-For", record.request.ip)
AttributeError: 'str' object has no attribute 'headers'
Call stack:
File "/home/dave/work/projects/test/sanic/app.py", line 12, in <module>
app.run(
File "/home/dave/.local/share/virtualenvs/sanic-f0iRZCxx/lib/python3.9/site-packages/sanic/app.py", line 1051, in run
serve_single(server_settings)
File "/home/dave/.local/share/virtualenvs/sanic-f0iRZCxx/lib/python3.9/site-packages/sanic/server/runners.py", line 199, in serve_single
serve(**server_settings)
File "/home/dave/.local/share/virtualenvs/sanic-f0iRZCxx/lib/python3.9/site-packages/sanic/server/runners.py", line 150, in serve
loop.run_forever()
File "connection_task", line 15, in connection_task
from sanic.http import Http, Stage
File "/home/dave/.local/share/virtualenvs/sanic-f0iRZCxx/lib/python3.9/site-packages/sanic/http.py", line 146, in http1
await self.protocol.request_handler(self.request)
File "handle_request", line 100, in handle_request
"_future_routes",
File "/home/dave/.local/share/virtualenvs/sanic-f0iRZCxx/lib/python3.9/site-packages/sanic/response.py", line 122, in send
await self.stream.send(data, end_stream=end_stream)
File "http1_response_header", line 68, in http1_response_header
HEADER_CEILING = 16_384
File "/home/dave/.local/share/virtualenvs/sanic-f0iRZCxx/lib/python3.9/site-packages/sanic/http.py", line 477, in log_response
access_logger.info("", extra=extra)
Message: ''
Arguments: ()
cat Pipfile
[[source]]
url = "https://pypi.org/simple"
verify_ssl = true
name = "pypi"
[packages]
sanic = "==21.9.3"
sanic-json-logging = "==4.1.2"
[requires]
python_version = "3.9"(sanic)
cat app.py
from sanic_json_logging import setup_json_logging
from sanic import Sanic, response
app = Sanic(name="test")
setup_json_logging(app, disable_json_access_log=False, configure_task_local_storage=False)
@app.route("/test")
def health(request):
return response.text("test")
if __name__ == "__main__":
app.run(
host="0.0.0.0",
port=8000,
debug=True,
auto_reload=True,
access_log=True,
)
pipenv shell
pipenv install
python app.py
In another terminal curl localhost:8000/test
or browser localhost:8000/test
disable_json_access_log=False
When I use disable_json_access_log=False
then I have logs in format I need, but there is an error
When I use disable_json_access_log=True
it doesn't look like I want
The goal to have all logs in json
format (including access logs)
Could you help me to fix it?
You can also notice the error on the auto closed pull requests:
"Scheduled weekly dependency update for week 20-26" (an example: https://travis-ci.com/github/terrycain/sanic-json-logging/builds/174516490)
`
tests/test_basic.py::test_json_access_logging_no_ua Exception occurred while handling uri: 'http://127.0.0.1:53599/test_get'
Traceback (most recent call last):
File "/home/travis/virtualenv/python3.6.7/lib/python3.6/site-packages/sanic/app.py", line 907, in handle_request
request, request_name=name
File "/home/travis/virtualenv/python3.6.7/lib/python3.6/site-packages/sanic/app.py", line 1265, in _run_request_middleware
response = await response
File "/home/travis/build/terrycain/sanic-json-logging/sanic_json_logging/init.py", line 41, in log_json_pre
request['req_id'] = req_id
TypeError: 'Request' object does not support item assignment
`
Using the code right from the examples/simple.py
:
import logging
import sanic.response
import sanic.request
from sanic_json_logging import setup_json_logging, NoAccessLogSanic
app = NoAccessLogSanic('app1')
setup_json_logging(app)
logger = logging.getLogger('root')
async def log():
logger.info('some informational message')
@app.route("/endpoint1", methods=['GET'])
async def endpoint1(request: sanic.request.Request) -> sanic.response.BaseHTTPResponse:
await log()
return sanic.response.text('')
app.run()
I have the following project (using poetry):
[tool.poetry]
name = "nal"
version = "0.1.0"
description = ""
authors = ["Aaron <[email protected]>"]
[tool.poetry.dependencies]
python = "^3.7"
sanic = "^19.6"
sanic_json_logging = "^1.3"
[tool.poetry.dev-dependencies]
pytest = "^3.0"
[build-system]
requires = ["poetry>=0.12"]
build-backend = "poetry.masonry.api"
When I run the project, everything starts up just fine:
⇒ poetry run python -m nal.main
[2019-07-09 08:01:30 -0600] [20986] [INFO] Goin' Fast @ http://127.0.0.1:8000
{"timestamp": "2019-07-09T14:01:30.924731Z", "level": "INFO", "message": "Goin' Fast @ http://127.0.0.1:8000", "type": "log", "logger": "sanic.root", "filename": "app.py", "lineno": 1383}
[2019-07-09 08:01:30 -0600] [20986] [INFO] Starting worker [20986]
{"timestamp": "2019-07-09T14:01:30.926515Z", "level": "INFO", "message": "Starting worker [20986]", "type": "log", "logger": "sanic.root", "filename": "server.py", "lineno": 802}
But when I send a request (using httpie):
⇒ http :8000/endpoint1
HTTP/1.1 200 OK
Connection: keep-alive
Content-Length: 0
Content-Type: text/plain; charset=utf-8
Keep-Alive: 5
I still get the access logs:
{
"timestamp": "2019-07-09T14:02:23.807338Z",
"level": "INFO",
"message": "some informational message",
"type": "log",
"logger": "root",
"filename": "main.py",
"lineno": 16,
"req_id": "4efb221f-a142-4604-b593-d8e72a69faa6"
}
{
"timestamp": "2019-07-09T14:02:23.807491Z",
"level": "INFO",
"method": "GET",
"path": "/endpoint1",
"remote": "127.0.0.1:51702",
"user_agent": "HTTPie/1.0.2",
"host": "localhost:8000",
"response_time": 0,
"req_id": "28f6ae3d-0e31-4573-819f-4cb852939ee8",
"logger": "sanic.access",
"status_code": 200,
"length": 0,
"type": "access"
}
I would expect that all the access logs are disabled since I'm using NoAccessLogSanic
and all.
A declarative, efficient, and flexible JavaScript library for building user interfaces.
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
An Open Source Machine Learning Framework for Everyone
The Web framework for perfectionists with deadlines.
A PHP framework for web artisans
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
Some thing interesting about web. New door for the world.
A server is a program made to process requests and deliver data to clients.
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
Some thing interesting about visualization, use data art
Some thing interesting about game, make everyone happy.
We are working to build community through open source technology. NB: members must have two-factor auth.
Open source projects and samples from Microsoft.
Google ❤️ Open Source for everyone.
Alibaba Open Source for everyone
Data-Driven Documents codes.
China tencent open source team.