From 8fb32419627bb46f71e2dc36d783633a3c0c9157 Mon Sep 17 00:00:00 2001 From: Alan Rominger Date: Wed, 21 Aug 2024 15:22:20 -0400 Subject: [PATCH] Review comments on timeout middleware --- .../lib/middleware/logging/log_request.py | 5 +++++ docs/logging.md | 17 +++++++++++++++++ test_app/apps.py | 8 -------- test_app/urls.py | 1 + test_app/uwsgi.ini | 7 +++++-- test_app/views.py | 15 +++++++++++---- 6 files changed, 39 insertions(+), 14 deletions(-) diff --git a/ansible_base/lib/middleware/logging/log_request.py b/ansible_base/lib/middleware/logging/log_request.py index 7f858f330..53b3d9874 100644 --- a/ansible_base/lib/middleware/logging/log_request.py +++ b/ansible_base/lib/middleware/logging/log_request.py @@ -1,9 +1,13 @@ +import signal import logging import traceback import uuid from ansible_base.lib.logging import thread_local +import signal + + logger = logging.getLogger(__name__) @@ -17,6 +21,7 @@ def handle_signal(cls, *args): def __init__(self, get_response): self.get_response = get_response + signal.signal(signal.SIGSYS, LogTracebackMiddleware.handle_signal) def __call__(self, request): t_id = str(uuid.uuid4()) diff --git a/docs/logging.md b/docs/logging.md index 76dbdd4e0..4f70ddd65 100644 --- a/docs/logging.md +++ b/docs/logging.md @@ -52,3 +52,20 @@ LOGGING = { ``` After that, the request ID should automatically show up in logs, when the header is passed in. + +## Logging Stack on Timeout + +django-ansible-base provides machinery to print the stack trace when a request times out. +To do this, you will need to: + +1. Set uwsgi params similar to that in `test_app/uwsgi.ini`. +2. Add `ansible_base.lib.middleware.logging.LogTracebackMiddleware` to `MIDDLEWARE` setting + +You can try to test this with test_app by running the docker compose server (so it runs with uwsgi), +and then visiting http://localhost:8000/api/v1/timeout_view/ and viewing the logs. +Within those logs, you should be able to see the culprit: + +``` +test_app-1 | File "/src/test_app/views.py", line 185, in timeout_view +test_app-1 | time.sleep(60*10) # 10 minutes +``` diff --git a/test_app/apps.py b/test_app/apps.py index a249774b7..763546847 100644 --- a/test_app/apps.py +++ b/test_app/apps.py @@ -1,14 +1,6 @@ -import signal - from django.apps import AppConfig -from ansible_base.lib.middleware.logging import LogTracebackMiddleware - class TestAppConfig(AppConfig): default_auto_field = 'django.db.models.BigAutoField' name = 'test_app' - - def ready(self): - super().ready() - signal.signal(signal.SIGSYS, LogTracebackMiddleware.handle_signal) diff --git a/test_app/urls.py b/test_app/urls.py index 3a49a87fb..e45530a7b 100644 --- a/test_app/urls.py +++ b/test_app/urls.py @@ -19,6 +19,7 @@ re_path(r"^admin/", admin.site.urls, name="admin"), path('api/v1/', include(resource_api_urls)), path('api/v1/', views.api_root), + path('api/v1/timeout_view/', views.timeout_view, name='test-timeout-view'), path('login/', include('rest_framework.urls')), path("__debug__/", include("debug_toolbar.urls")), ] diff --git a/test_app/uwsgi.ini b/test_app/uwsgi.ini index 09d3528db..e6f9f31e3 100644 --- a/test_app/uwsgi.ini +++ b/test_app/uwsgi.ini @@ -8,12 +8,15 @@ vacuum = true # Log to stdout logto = /dev/stdout +log-master = true #disable-logging = true # Increase buffer size buffer-size = 32768 -# Other recommended settings +# Give signal 6 to work with LogTracebackMiddleware http-timeout = 60 harakiri = 60 - +harakiri-graceful-timeout = 50 +harakiri-graceful-signal = 31 +py-call-osafterfork = true diff --git a/test_app/views.py b/test_app/views.py index 978a2dc0f..1e352aa0f 100644 --- a/test_app/views.py +++ b/test_app/views.py @@ -1,3 +1,4 @@ +import time import logging from itertools import chain @@ -160,7 +161,7 @@ def api_root(request, format=None): # want '^users/$' [name='user-list'] # do not want '^users/(?P[^/.]+)/organizations/$' [name='user-organizations-list'], if '-list' in url.name and url.pattern._regex.count('/') == 1: - list_endpoints[url.name.removesuffix('-list')] = get_relative_url(url.name, request=request, format=format) + list_endpoints[url.name.removesuffix('-list')] = get_relative_url(url.name) from ansible_base.api_documentation.urls import api_version_urls as docs_urls from ansible_base.authentication.urls import api_version_urls as authentication_urls @@ -168,16 +169,22 @@ def api_root(request, format=None): for url in docs_urls + authentication_urls[1:]: if isinstance(url, URLPattern): try: - list_endpoints[url.name] = get_relative_url(url.name, request=request, format=format) + list_endpoints[url.name] = get_relative_url(url.name) except NoReverseMatch: pass - list_endpoints['service-index'] = get_relative_url('service-index-root', request=request, format=format) - list_endpoints['role-metadata'] = get_relative_url('role-metadata', request=request, format=format) + list_endpoints['service-index'] = get_relative_url('service-index-root') + list_endpoints['role-metadata'] = get_relative_url('role-metadata') + list_endpoints['timeout-view'] = get_relative_url('test-timeout-view') return Response(list_endpoints) +@api_view(['GET']) +def timeout_view(request, format=None): + time.sleep(60*10) # 10 minutes + + class MultipleFieldsViewSet(TestAppViewSet): serializer_class = serializers.MultipleFieldsModelSerializer