H-1397: Better logging, error handling in the Node API (#3930)

apps/hash-api/src/graphql/create-apollo-server.ts

@@ -99,14 +99,7 @@ export const createApolloServer = ({
             executionDidStart: async ({ request }) => {
               const scope = Sentry.getCurrentScope();
 
-              const user: Express.Request["user"] = ctx.context.user;
-              scope.setUser({
-                id: ctx.context.authentication.actorId,
-                email: user?.emails[0],
-                username: user?.shortname ?? "public",
-              });
-
-              scope.setExtras({
+              scope.setContext("graphql", {
                 query: request.query,
                 variables: request.variables,
               });

apps/hash-api/src/index.ts

@@ -5,7 +5,7 @@ import {
   realtimeSyncEnabled,
   waitOnResource,
 } from "@local/hash-backend-utils/environment";
-import express, { raw } from "express";
+import express, { ErrorRequestHandler, raw } from "express";
 
 // eslint-disable-next-line import/order
 import { initSentry } from "./sentry";
@@ -40,6 +40,7 @@ import {
   addKratosAfterRegistrationHandler,
   createAuthMiddleware,
 } from "./auth/create-auth-handlers";
+import { getActorIdFromRequest } from "./auth/get-actor-id";
 import { setupBlockProtocolExternalServiceMethodProxy } from "./block-protocol-external-service-method-proxy";
 import { RedisCache } from "./cache";
 import {
@@ -146,15 +147,33 @@ const main = async () => {
     logger.error(`Could not start StatsD client: ${err}`);
   }
 
-  // Configure the Express server
+  // Configure Sentry error / trace handling
   app.use(
     Sentry.Handlers.requestHandler({
       ip: true,
-      user: ["emails", "shortname"],
     }),
   );
+  app.use(Sentry.Handlers.tracingHandler());
+
   app.use(cors(CORS_CONFIG));
 
+  // Add logging of requests
+  app.use((req, res, next) => {
+    const requestId = nanoid();
+    res.set("x-hash-request-id", requestId);
+    logger.info({
+      requestId,
+      method: req.method,
+      ip: req.ip,
+      path: req.path,
+      message: "request",
+      userAgent: req.headers["user-agent"],
+      graphqlClient: req.headers["apollographql-client-name"],
+    });
+
+    next();
+  });
+
   const redisHost = getRequiredEnv("HASH_REDIS_HOST");
   const redisPort = parseInt(getRequiredEnv("HASH_REDIS_PORT"), 10);
 
@@ -224,6 +243,39 @@ const main = async () => {
   const authMiddleware = createAuthMiddleware({ logger, context });
   app.use(authMiddleware);
 
+  /**
+   * Add scope to Sentry, now the user has been checked.
+   * We could set some of this scope earlier, but it doesn't get picked up for GraphQL requests for some reason
+   * if the middleware comes earlier.
+   */
+  app.use((req, _res, next) => {
+    const scope = Sentry.getCurrentScope();
+
+    // Clear the scope and breadcrumbs – requests seem to bleed into each other otherwise
+    scope.clear();
+    scope.clearBreadcrumbs();
+
+    /**
+     * Sentry automatically populates a 'Headers' object, but for some reason it doesn't do this for GraphQL requests.
+     * This might be something to do with how Sentry hooks into fetch that doesn't play nicely with ApolloServer,
+     * or how we're loading it.
+     */
+    const userAgent = req.header("user-agent");
+    const origin = req.header("origin");
+    const ip = req.ip;
+
+    scope.setContext("request", { ip, origin, userAgent });
+
+    const user = req.user;
+    scope.setUser({
+      id: getActorIdFromRequest(req),
+      email: user?.emails[0],
+      username: user?.shortname ?? "public",
+    });
+
+    next();
+  });
+
   // Create an email transporter
   const emailTransporter =
     isTestEnv || isDevEnv || process.env.HASH_EMAIL_TRANSPORTER === "dummy"
@@ -387,8 +439,6 @@ const main = async () => {
   app.get("/oauth/linear/callback", rateLimiter, oAuthLinearCallback);
   app.post("/webhooks/linear", linearWebhook);
 
-  app.use(Sentry.Handlers.tracingHandler());
-
   /**
    * This middleware MUST:
    * 1. Come AFTER all non-error controllers
@@ -405,6 +455,14 @@ const main = async () => {
     }),
   );
 
+  // Fallback error handler for errors that haven't been caught and sent as a response already
+  const errorHandler: ErrorRequestHandler = (err, _req, res, _next) => {
+    Sentry.captureException(err);
+
+    res.status(500).send(err.message);
+  };
+  app.use(errorHandler);
+
   // Create the HTTP server.
   // Note: calling `close` on a `http.Server` stops new connections, but it does not
   // close active connections. This can result in the server hanging indefinitely. We

apps/hash-api/src/storage/aws-s3-storage-provider.ts

@@ -116,6 +116,8 @@ export class AwsS3StorageProvider implements UploadableStorageProvider {
         forcePathStyle: fileStorageForcePathStyle,
         region: fileStorageRegion,
       });
+      // eslint-disable-next-line no-console -- temporary debug log
+      console.log("Constructed new client");
     }
 
     const command = new GetObjectCommand({

apps/hash-api/src/storage/index.ts

@@ -211,6 +211,9 @@ export const setupFileDownloadProxyHandler = (
       },
     );
 
+    // eslint-disable-next-line no-console -- temporary debug log
+    console.log({ fileEntity });
+
     if (!fileEntity) {
       res.status(404).json({
         error: `Could not find file entity ${entityId} with edition timestamp ${editionTimestamp}, either it does not exist or you do not have permission to access it.`,
@@ -265,6 +268,8 @@ export const setupFileDownloadProxyHandler = (
           return;
         }
       }
+      // eslint-disable-next-line no-console -- temporary debug log
+      console.log({ storageProvider });
 
       presignUrl = await storageProvider.presignDownload({
         entity: fileEntity,
@@ -290,6 +295,9 @@ export const setupFileDownloadProxyHandler = (
       }
     }
 
+    // eslint-disable-next-line no-console -- temporary debug log
+    console.log({ presignUrl });
+
     res.redirect(presignUrl);
   });
 };

infra/terraform/hash/prod-usea1.tfvars

@@ -47,7 +47,7 @@ hash_api_env_vars = [
   { name = "FRONTEND_URL", secret = false, value = "https://app.hash.ai" },
   { name = "API_ORIGIN", secret = false, value = "https://app-api.hash.ai" },
 
-  { name = "LOG_LEVEL", secret = false, value = "debug" },
+  { name = "LOG_LEVEL", secret = false, value = "info" },
 
   { name = "FILE_UPLOAD_PROVIDER", secret = false, value = "AWS_S3" },