archivematica / Issues

Issues repository for the Archivematica project
GNU Affero General Public License v3.0
16 stars 1 forks source link

Problem: AJAX middleware does not send exceptions to logger #1353

Closed sevein closed 3 years ago

sevein commented 7 years ago

AJAXSimpleExceptionResponseMiddleware captures exceptions and injects the traceback in the response body when the application is running in debug mode and the request is considered AJAX (aka XMLHttpRequest). I think the goal was to add visibility to the error for web developers that can easily look up the content of a response via the web developer tools - instead of using the terminal to watch a log file.

The problem is that the event should also be logged. Django won't do that if the function defined in the middleware returns a HTTP request.

Slange-Mhath commented 3 years ago

I am quite sure this issue exists no longer. I wrote a small unhandled exception inside the dashboard and it got logged.

sevein commented 3 years ago

@Slange-Mhath, I think this issue is reproducible only when we're making requests via XMLHttpRequest, e.g. when starting a new transfer from the transfer browser widget under the Transfer tab. If you raised and exception when hitting /api/v2beta/package/ (components.api.views.package), the error is included in the server response but it's not logged.

I haven't tested but something like the following could work:

 class AJAXSimpleExceptionResponseMiddleware(MiddlewareMixin):
     def process_exception(self, request, exception):
         if not settings.DEBUG or not request.is_ajax():
             return
         (exc_type, exc_info, tb) = sys.exc_info()
+        tracebacks = traceback.format_tb(tb)
+        logger.error(
+            "Processing exception %s at %s. Traceback %s",
+            exception,
+            request.path,
+            tracebacks,
+        )
         response = "%s\n" % exc_type.__name__
         response += "%s\n\n" % exc_info
         response += "TRACEBACK:\n"
-        for tb in traceback.format_tb(tb):
+        for tb in tracebacks:
             response += "%s\n" % tb
         return HttpResponseServerError(response)
replaceafill commented 3 years ago

I confirmed I can see a fake/custom exception (with message nooo) from the middleware class in the dashboard logs:

archivematica-dashboard_1        | ERROR     2021-06-25 14:27:28  archivematica.dashboard:common:process_exception:47:  Processing exception nooo at /api/v2beta/package/. Traceback ['  File "/usr/local/lib/python3.6/dist-packages/django/core/handlers/base.py", line 185, in _get_response\n    response = wrapped_callback(request, *callback_args, **callback_kwargs)\n', '  File "/usr/local/lib/python3.6/dist-packages/django/views/decorators/csrf.py", line 58, in wrapped_view\n    return view_func(*args, **kwargs)\n', '  File "/src/src/dashboard/src/components/api/views.py", line 102, in wrapper\n    result = func(request, *args, **kwargs)\n', '  File "/src/src/dashboard/src/components/api/views.py", line 826, in package\n    return _package_create(request)\n', '  File "/src/src/dashboard/src/components/api/views.py", line 855, in _package_create\n    raise Exception("nooo")\n']