Python应用程序出错，如何读取日志文件

Question

我是一名Rails开发人员，正在尝试安装一个名为Liveblog的开源应用程序

台式机一切正常，但他们也提供了iOS和安卓系统的移动应用程序，我不能用它来处理错误。

我使用nginx记录post请求，这是日志。

{\"username\":\"xxxxx\",\"password\":\"xxxxx\"}
37.117.49.57 - - [24/Dec/2018:16:59:20 +0100] "POST /api/auth HTTP/1.1" 500 157 "-" "Live Blog Reporter/org.sourcefabric.LiveBlogReporter (22; OS Version 12.1.2 (Build 16C101))" "-"

包含user和pass的散列参数看起来不错。

在应用程序日志中，我有以下错误：

Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 | ERROR:eve:Exception on /api/auth [POST]
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 | Traceback (most recent call last):
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/app.py", line 1817, in wsgi_app
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     response = self.full_dispatch_request()
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/app.py", line 1477, in full_dispatch_request
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     rv = self.handle_user_exception(e)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/app.py", line 1381, in handle_user_exception
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     reraise(exc_type, exc_value, tb)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/_compat.py", line 33, in reraise
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     raise value
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/app.py", line 1475, in full_dispatch_request
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     rv = self.dispatch_request()
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/app.py", line 1461, in dispatch_request
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return self.view_functions[rule.endpoint](**req.view_args)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/endpoints.py", line 56, in collections_endpoint
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     response = post(resource)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/methods/common.py", line 284, in rate_limited
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return f(*args, **kwargs)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/auth.py", line 79, in decorated
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return f(*args, **kwargs)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/methods/common.py", line 1040, in decorated
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     r = f(resource, **combined_args)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/methods/post.py", line 40, in post
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return post_internal(resource, payl, skip_validation=False)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/methods/post.py", line 245, in post_internal
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     getattr(app, "on_insert_%s" % resource)(documents)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/events/events.py", line 77, in __call__
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     f(*a, **kw)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/src/superdesk-core/apps/auth/service.py", line 34, in on_create
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     user = self.authenticate(doc)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/src/superdesk-core/apps/auth/service.py", line 30, in authenticate
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     raise NotImplementedError()
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 | NotImplementedError
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 | ERROR:superdesk.errors:HTTP Exception 500 has been raised:
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 | [2018-12-24 16:59:20 +0100] [20670] [ERROR] Error handling request /api/auth
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 | Traceback (most recent call last):
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/app.py", line 1817, in wsgi_app
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     response = self.full_dispatch_request()
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/app.py", line 1477, in full_dispatch_request
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     rv = self.handle_user_exception(e)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/app.py", line 1381, in handle_user_exception
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     reraise(exc_type, exc_value, tb)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/_compat.py", line 33, in reraise
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     raise value
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/app.py", line 1475, in full_dispatch_request
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     rv = self.dispatch_request()
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/app.py", line 1461, in dispatch_request
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return self.view_functions[rule.endpoint](**req.view_args)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/endpoints.py", line 56, in collections_endpoint
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     response = post(resource)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/methods/common.py", line 284, in rate_limited
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return f(*args, **kwargs)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/auth.py", line 79, in decorated
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return f(*args, **kwargs)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/methods/common.py", line 1040, in decorated
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     r = f(resource, **combined_args)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/methods/post.py", line 40, in post
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return post_internal(resource, payl, skip_validation=False)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/methods/post.py", line 245, in post_internal
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     getattr(app, "on_insert_%s" % resource)(documents)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/events/events.py", line 77, in __call__
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     f(*a, **kw)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/src/superdesk-core/apps/auth/service.py", line 34, in on_create
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     user = self.authenticate(doc)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/src/superdesk-core/apps/auth/service.py", line 30, in authenticate
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     raise NotImplementedError()
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 | NotImplementedError
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 | During handling of the above exception, another exception occurred:
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 | Traceback (most recent call last):
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/gunicorn/workers/sync.py", line 135, in handle
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     self.handle_request(listener, req, client, addr)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/gunicorn/workers/sync.py", line 176, in handle_request
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     respiter = self.wsgi(environ, resp.start_response)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/flaskapp.py", line 1033, in __call__
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return super(Eve, self).__call__(environ, start_response)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/app.py", line 1836, in __call__
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return self.wsgi_app(environ, start_response)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/app.py", line 1820, in wsgi_app
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     response = self.make_response(self.handle_exception(e))
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/flask/app.py", line 1410, in handle_exception
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return handler(e)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/src/superdesk-core/superdesk/factory/app.py", line 136, in server_error_handler
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return client_error_handler(return_error)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/src/superdesk-core/superdesk/factory/app.py", line 126, in client_error_handler
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return send_response(None, (error.to_dict(), None, None, error.status_code))
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/render.py", line 57, in decorated
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     r = f(*args, **kwargs)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/render.py", line 96, in send_response
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return _prepare_response(resource, *response if response else [None])
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/render.py", line 150, in _prepare_response
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     rendered = globals()[renderer](dct)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/render.py", line 303, in render_json
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     sort_keys=config.JSON_SORT_KEYS)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/simplejson/__init__.py", line 399, in dumps
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     **kw).encode(obj)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/simplejson/encoder.py", line 296, in encode
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     chunks = self.iterencode(o, _one_shot=True)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/simplejson/encoder.py", line 378, in iterencode
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return _iterencode(o, 0)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/io/mongo/mongo.py", line 57, in default
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return super(MongoJSONEncoder, self).default(obj)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/eve/io/base.py", line 36, in default
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     return json.JSONEncoder.default(self, obj)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |   File "/opt/liveblog/env/lib/python3.5/site-packages/simplejson/encoder.py", line 273, in default
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 |     o.__class__.__name__)
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 | TypeError: Object of type NotImplementedError is not JSON serializable
Dec 24 16:59:20 liveblog sh[20638]: 16:59:20 rest.1 | POST None status=500 time=0s size=0b

在Rails日志错误中，我可以理解问题出在哪里，在这里我不能理解python中的路由是如何工作的，所以我无法调试这个问题。日志中是否有任何提示可以用来开始调试？

Answer 1

Traceback (most recent call last): =>解释了这一点，您可以查看回溯的最后一行，以检查哪行代码引发(抛出)了异常。

如果运行时值未记录在异常本身中，则在该行中添加调试器断点。

在您的示例中：raise NotImplementedError()是在/src/superdesk-core/apps/auth/service.py", line 30中抛出的手动异常。