GitHub App: track debug logs as info (#12352)

We are experiencing some delays sometimes, this should be useful to
pinpoint the problem.

Author: stsewd

readthedocs/oauth/tasks.py

@@ -281,7 +281,7 @@ def handle(self):
             log.debug("Unsupported event")
             raise ValueError(f"Unsupported event: {self.event}")
 
-        log.debug("Handling event")
+        log.info("Handling event")
         self.event_handlers[self.event]()
 
     def _handle_installation_event(self):
@@ -743,12 +743,17 @@ def _get_or_create_installation(self, sync_repositories_on_create: bool = True):
 
 
 @app.task(queue="web")
-def handle_github_app_webhook(data: dict, event: str):
+def handle_github_app_webhook(data: dict, event: str, event_id: str = "unknown"):
     """
     Handle GitHub App webhooks asynchronously.
 
     :param data: The webhook payload data.
     :param event: The event type of the webhook.
     """
+    structlog.contextvars.bind_contextvars(
+        event=event,
+        event_id=event_id,
+    )
+    log.info("Handling GitHub App webhook")
     handler = GitHubAppWebhookHandler(data, event)
     handler.handle()

readthedocs/oauth/views.py

@@ -36,19 +36,24 @@ def post(self, request):
         installation_id = request.data.get("installation", {}).get("id", "unknown")
         action = request.data.get("action", "unknown")
         event = self.request.headers.get(GITHUB_EVENT_HEADER)
+        # Unique identifiers for the event, useful to keep track of the event for debugging.
+        # https://docs.github.com/en/webhooks/webhook-events-and-payloads#delivery-headers.
+        event_id = self.request.headers.get("X-GitHub-Delivery", "unknown")
         structlog.contextvars.bind_contextvars(
             installation_id=installation_id,
             action=action,
             event=event,
+            event_id=event_id,
         )
         if event not in GitHubAppWebhookHandler(request.data, event).event_handlers:
-            log.debug("Unsupported event")
+            log.info("Unsupported event")
             raise ValidationError(f"Unsupported event: {event}")
 
-        log.debug("Handling event")
+        log.info("Handling event")
         handle_github_app_webhook.delay(
             data=request.data,
             event=event,
+            event_id=event_id,
         )
         return Response(status=200)