fix(logging): ensure metadata is present in logging context (#4968)

packages/fileimport-service/src/controller/filesApi.ts

@@ -19,35 +19,41 @@ export async function downloadFile({
   destination: string
   logger: Logger
 }) {
+  const boundLogger = logger.child({
+    fileId,
+    streamId
+  })
   try {
     fs.mkdirSync(path.dirname(destination), { recursive: true })
   } catch (e) {
     throw ensureError(e, 'Unknown error while creating directory')
   }
 
-  logger.info(
-    { destinationFile: destination },
-    'Downloading file {fileId} from {streamId} to {destinationFile}'
+  const downloadUrl = new URL(
+    `/api/stream/${streamId}/blob/${fileId}`,
+    speckleServerUrl
+  )
+
+  boundLogger.info(
+    { destinationFile: destination, downloadUrl: downloadUrl.toString() },
+    'Downloading file {fileId} (project: {streamId}) from ${downloadUrl} to {destinationFile}'
   )
 
   let response
   try {
-    response = await fetch(
-      `${speckleServerUrl}/api/stream/${streamId}/blob/${fileId}`,
-      {
-        headers: {
-          Authorization: `Bearer ${token}`
-        }
+    response = await fetch(downloadUrl.toString(), {
+      headers: {
+        Authorization: `Bearer ${token}`
       }
-    )
+    })
   } catch (e) {
     throw ensureError(e, 'Unknown error while fetching file')
   }
 
   if (response === undefined || !response.ok) {
-    logger.error(
-      { status: response?.status, statusText: response?.statusText },
-      'Failed to download file {fileId}. HTTP {status}: {statusText}'
+    boundLogger.error(
+      { downloadUrl, status: response?.status, statusText: response?.statusText },
+      'Failed to download file {fileId} from {downloadUrl}. HTTP {status}: {statusText}'
     )
     throw new Error(
       `Failed to download file ${fileId}. HTTP ${response?.status}: ${response?.statusText}`
@@ -61,13 +67,13 @@ export async function downloadFile({
 
   //handle errors
   writer.on('error', (err) => {
-    logger.error(ensureError(err), `Error writing file ${destination}`)
+    boundLogger.error(ensureError(err), `Error writing file ${destination}`)
     throw err
   })
 
   //handle completion
   writer.on('finish', () => {
-    logger.info(`File written to ${destination}`)
+    boundLogger.info(`File written to ${destination}`)
   })
 
   await pipeline(response.body, writer, { end: true })

packages/fileimport-service/src/nextGen/healthcheck.ts

@@ -13,8 +13,8 @@ export const startHealthCheckServer = (params: { logger: Logger }) => {
     }
   })
 
-  server.listen(9080, 'localhost', () => {
-    logger.info('Server running at http://localhost with endpoint /healthz')
+  server.listen(9080, '0.0.0.0', () => {
+    logger.info('Server running, listening to 0.0.0.0 and path /healthz')
   })
 
   return server

packages/fileimport-service/src/nextGen/jobProcessor.ts

@@ -124,9 +124,15 @@ export const jobProcessor = async ({
   } catch (err) {
     if (getAppState() === AppState.SHUTTINGDOWN) {
       // likely that the job was cancelled due to the service shutting down
-      logger.warn({ err, elapsed: getElapsed(), status: 'error' }, jobMessage)
+      logger.warn(
+        { err, jobId: job.jobId, elapsed: getElapsed(), status: 'error' },
+        jobMessage
+      )
     } else {
-      logger.error({ err, elapsed: getElapsed(), status: 'error' }, jobMessage)
+      logger.error(
+        { err, jobId: job.jobId, elapsed: getElapsed(), status: 'error' },
+        jobMessage
+      )
     }
 
     const reason = err instanceof Error ? err.stack ?? err.toString() : 'unknown error'

packages/server/modules/core/graph/plugins/logging.ts

@@ -137,12 +137,12 @@ export const loggingPluginFactory: (deps: {
         if (!importantError) {
           logger.info(
             { err: firstError },
-            '{graphql_operation_title} failed after {apollo_query_duration_ms} ms'
+            '{graphql_operation_name} failed after {apollo_query_duration_ms} ms'
           )
         } else {
           logger.error(
             { err: importantError },
-            '{graphql_operation_title} failed after {apollo_query_duration_ms} ms'
+            '{graphql_operation_name} failed after {apollo_query_duration_ms} ms'
           )
         }
       },