chore(preview service): improve logging (#2900)

* chore(preview service): improve logging

* use correct logging syntax in test

packages/preview-service/src/clients/puppeteer.ts

@@ -49,16 +49,33 @@ export const puppeteerClientFactory = async (deps: {
           let messageText = message.text()
           if (messageText.startsWith('data:image'))
             messageText = messageText.substring(0, 200).concat('...')
-          logger.debug(`${message.type().substring(0, 3).toUpperCase()} ${messageText}`)
+          logger.debug(
+            {
+              puppeteerMessageType: message.type().substring(0, 3).toUpperCase()
+            },
+            `{puppeteerMessageType} ${messageText}`
+          )
         })
-        .on('pageerror', ({ message }) => {
-          logger.error(message)
+        .on('pageerror', (error) => {
+          logger.error(error, 'Puppeteer page encountered an error.')
         })
         .on('response', (response) =>
-          logger.info(`${response.status()} ${response.url()}`)
+          logger.info(
+            {
+              response: {
+                headers: response.headers(),
+                status: response.status(),
+                statusText: response.statusText()
+              }
+            },
+            'Response received from puppeteer page'
+          )
         )
         .on('requestfailed', (request) =>
-          logger.error(`${request.failure()?.errorText} ${request.url()}`)
+          logger.error(
+            { err: request.failure()?.errorText, puppeteerPageUrl: request.url() },
+            'Request sent to puppeteer page failed'
+          )
         )
 
       const evaluationResult: unknown = await page.evaluate(script, args)

packages/preview-service/src/observability/expressLogging.ts

@@ -21,6 +21,9 @@ export const loggingExpressMiddleware = pinoHttp({
   // and we don't really care about 3xx stuff
   // all the user related 4xx responses are treated as info
   customLogLevel: (req, res, error) => {
+    if (req.url?.startsWith('/metrics')) {
+      return 'debug'
+    }
     if (res.statusCode >= 400 && res.statusCode < 500) {
       return 'info'
     } else if (res.statusCode >= 500 || error) {

packages/preview-service/tests/acceptance/acceptance.spec.ts

@@ -7,6 +7,7 @@ import { promises as fs } from 'fs'
 import { spawn } from 'child_process'
 import { OBJECTS_TABLE_NAME } from '#/migrations/migrations.js'
 import type { Angle } from '@/domain/domain.js'
+import { testLogger as logger } from '@/observability/logging.js'
 
 describe.sequential('Acceptance', () => {
   describe.sequential('Run the preview-service image in docker', () => {
@@ -36,7 +37,10 @@ describe.sequential('Acceptance', () => {
       async ({ context }) => {
         const { db } = context
         const dbName = inject('dbName')
-        console.log('Running test in database: %s', dbName)
+        logger.info(
+          { databaseName: dbName },
+          'Running test in database: {databaseName}'
+        )
         // load data
         const streamId = cryptoRandomString({ length: 10 })
         const objectId = cryptoRandomString({ length: 10 })