googleapis / nodejs-logging-winston

Node.js client integration between Stackdriver Logging and Winston.
https://cloud.google.com/logging/
Apache License 2.0
104 stars 50 forks source link

Diffrences in log entry structure with different modes of redirectToStdout (missing resource.labels.function_name when redirectToStdout:true) #791

Open evil-shrike opened 1 year ago

evil-shrike commented 1 year ago

I have a lib, that uses winston for logging, which I want to use inside my cloud function and integrate its logging with Cloud Logging. So inside the lib I check whether it's running in Cloud and if so I create a winston logger with LoggingWinston transport:

export function createLogger() {
  if (process.env.K_SERVICE) {
    // we're in Google Cloud (Run/Functions)
    return createCloudLogger();
  } else {
    return createConsoleLogger();
  }
}

where createCloudLogger is:

export function createCloudLogger() {
  const cloudLogger = winston.createLogger({
    level: LOG_LEVEL,
    format: format.combine(
      format((info) => {
        info.trace = process.env.TRACE_ID;
        info[LOGGING_TRACE_KEY] = process.env.TRACE_ID;
        return info;
      })(),
    ),
    defaultMeta: getDefaultMetadataForTracing(),
    transports: [
      new LoggingWinston({
        projectId: process.env.GCP_PROJECT,
        labels: {
          component: <string>process.env.LOG_COMPONENT,
        },
        logName: "mylog",
        resource: {
          labels: {
            function_name: <string>process.env.K_SERVICE,
          },
          type: "cloud_function",
        },
        useMessageField: false,
        redirectToStdout: false,
      }),
    ],
  });
  return cloudLogger;
}

Please note I specify redirectToStdout: false. It worked fine in general but recently I've noticed that in logs there're a lot of entries like this: DEFAULT 2023-04-17T11:03:56.398817Z Exception from a finished function: Error: Total timeout of API google.logging.v2.LoggingServiceV2 exceeded 60000 milliseconds before any response was received.

and sometime they are even turned into error:

Error: Total timeout of API google.logging.v2.LoggingServiceV2 exceeded 60000 milliseconds before any response was received.
    at repeat (/workspace/node_modules/google-gax/build/src/normalCalls/retries.js:66:31)
    at Timeout._onTimeout (/workspace/node_modules/google-gax/build/src/normalCalls/retries.js:101:25)
    at listOnTimeout (node:internal/timers:559:17)
    at processTimers (node:internal/timers:502:7)

in the related bug https://github.com/googleapis/nodejs-logging/issues/1185 it's suggested to turn on stdout writing. So I changed redirectToStdout to true. Unfortunately the result isn't the same.

Here's a log entry with redirectToStdout: false: image

Here's a log entry with redirectToStdout: true: image

there are very similar but redirectToStdout: true resource.labels.function_name goes to jsonPayload instead of to the root object as with redirectToStdout: false. Which results in missing label (chip) with function name on the log entry.

cindy-peng commented 1 week ago

Hi @evil-shrike, I am wondering are you still running into this issue? If so, do you mind providing a latest repro?