Log levels and objects do not show in Cloud Logging from Cloud Functions

[sshquack]

Environment details

• OS: macOS / Cloud Function
• Node.js version: 14.16 LTS
• npm version: 7.17
• @google-cloud/logging-winston version:

Steps to reproduce

I followed the quick start sample at https://cloud.google.com/logging/docs/setup/nodejs#using_winston and none of my log levels and objects show-up in Winston Cloud Logging from Cloud Functions.

1. Install winston and cloud logging winston using npm

dependencies: {
    "@google-cloud/logging": "^9.4.1",
    "@google-cloud/logging-winston": "^4.1.0",
    "winston": "^3.3.3"
    ...
}

2. Create a simple cloud function and add some Winston logs

import type { HttpFunction } from "@google-cloud/functions-framework/build/src/functions";
import { LoggingWinston } from "@google-cloud/logging-winston";
import winston from "winston";

const loggingWinston = new LoggingWinston();

export const logger = winston.createLogger({
 level: "info",
 transports: [new winston.transports.Console(), loggingWinston],
});

export const health: HttpFunction = async (_, res): Promise<void> => {
 const platformInfo = {
   versions: process.versions,
   arch: process.arch,
   platform: process.platform,
 };
 logger.info("platform info", platformInfo);

 logger.info({ key: "info", message: "info message" });
 logger.info("info message %o", { keyI: "info" });
 logger.warn("test warn message", { keyW: "warn" });
 logger.error("test error message", { keyE: "error" });
 logger.debug("test debug message", { keyD: "debug" });

 res.status(200).json({ status: "ok" });
};

3. Test the function locally using @google-cloud/functions-framework and it works as expected.

Serving function...
Function: v1HealthApi
Signature type: http
URL: http://localhost:8080/
{"structuredData":true,"versions":{"node":"14.17.0","v8":"8.4.371.23-node.63","uv":"1.41.0","zlib":"1.2.11","brotli":"1.0.9","ares":"1.17.1","modules":"83","nghttp2":"1.42.0","napi":"8","llhttp":"2.1.3","openssl":"1.1.1k","cldr":"38.1","icu":"68.2","tz":"2020d","unicode":"13.0"},"arch":"x64","platform":"darwin","level":"info","message":"platform info"}
{"key":"warn","level":"warn","message":"warn message"}
{"key":"error","level":"error","message":"error message"}
{"key":"info","level":"error","message":"info message"}

4. Test the function from Cloud Function console and check the logs. None of the logs show log levels or the meta objects
   

Please help!

[wrsenn]

Can confirm this is happening in @google-cloud/logging-winston version 4.0.5. This is a regression––it was working properly in previous versions, but I don't know how recently this began to occur.

[Jonathan-Navagis]

I tried this with 3.0.6 and it has the same effect

[wrsenn]

I don't think this is the first time the issue has surfaced, but I don't have the version numbers for when it last occurred.

[toninofox]

About the severity not reported properly in Stackdriver, I had to configure it manually using a format and a mapper from level to SD severity. This is because the severity information is not reported in the metadata of the log (issue reported here but I guess still existing #285)

const SeverityLookup = {
  default: 'DEFAULT',
  silly: 'DEFAULT',
  verbose: 'DEBUG',
  debug: 'DEBUG',
  http: 'NOTICE',
  info: 'INFO',
  warn: 'WARNING',
  error: 'ERROR',
};

const stackdriverFormat = winston.format((info) => {
  const { level, ...record } = info;
  record.severity = SeverityLookup[level] || SeverityLookup.default;
  return record;
});

const loggerOption = {
  transports: [
    new winston.transports.Console({
      format: winston.format.combine(
        stackdriverFormat(),
        winston.format.json(),
      ),
    }),
    new LoggingWinston(),
  ],
};
const logger = winston.createLogger(loggerOption);

[minherz]

It is possible that the observed behavior is a result of the execution of assignSeverityToEntries method.

[losalex]

@sshquack,
Thank you very much for filing an issue!
It appears that problem with dropped severity happens due to a bug in Cloud Functions logging stack and the bug to fix this issue already filed.

[wrsenn]

@toninofox suggestion fixed our problem (thank you!), but it also revealed that... we don't really need this library, at least not in our case. Explicitly setting the severity and formatting as JSON with the default transport gives us the same result, so for simpler applications, that may be all that's necessary.

This is actually perfect for us, as we're working with Cloud Run instances, and using this library sometimes results in log messages getting lost if they aren't all flushed by the time the instance dies/sleeps. In cases where there's a crash shortly after the container starts, we would never get messages and would be unable to diagnose the problem easily. The standard transport doesn't have this problem.