Review comments on timeout middleware

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())

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
+```

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)

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")),
 ]

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

test_app/views.py

@@ -1,3 +1,4 @@
+import time
 import logging
 from itertools import chain
 
@@ -160,24 +161,30 @@ def api_root(request, format=None):
         # want '^users/$' [name='user-list']
         # do not want '^users/(?P<pk>[^/.]+)/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
 
     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