backstage / backstage

Backstage is an open framework for building developer portals
https://backstage.io/
Apache License 2.0
26.61k stars 5.46k forks source link

πŸ› Bug Report: New Backends cannot replace logger / customize logging #24619

Closed vonjones closed 1 week ago

vonjones commented 2 weeks ago

πŸ“œ Description

The new backend mechanism has a Root Logger Service. Unlike the prior mechanism, the new one does not allow you to create your own logger prior to backend initialization. This hinders our ability to add transforms. This doesn’t seem possible presently.

πŸ‘ Expected behavior

I should be able to customize logging formats as is necessary for my hosting environmentl.

πŸ‘Ž Actual Behavior with Screenshots

The new mechanism cannot be extended by:

πŸ‘Ÿ Reproduction steps

NA

πŸ“ƒ Provide the context for the Bug.

Here's what I'm specifically trying to do in my use case. We host our Backstage as a Cloud Run in Google Cloud. Within Google, the logger info levels are not correctly reflecting in the Cloud Run log views. This is because Google expects a field named severity while Backstage uses winston which uses a field named level. My change moves the level value into a severity field. This makes the logging render correctly, making it easier to scroll to find errors.

So when viewing logs, we now see:

image

Previously only the HTTP request log entries that originate from Cloud Run were correctly classified, and standard logging appeared as a *, like this

image

This implies that one cannot skim logs to search for errors, as you can when working locally.

So here's how I was doing this with the prior backends

// src/packages/backend/src/index.ts
...
import {
  ...
  createRootLogger,
} from '@backstage/backend-common';
...
import * as winston from 'winston';
import { format } from 'winston';
import { WinstonLogger } from '@backstage/backend-app-api';

// It's suggested that you set `jsonPayload.type` and jsonPayload.plugin as a summary field in logs explorer.
// Ref: https://cloud.google.com/logging/docs/view/logs-explorer-interface#add_summary_fields
function initializeLogging() {
  // Ref: https://github.com/backstage/backstage/blob/master/packages/backend-common/src/logging/createRootLogger.ts#L100
  // Ref: https://github.com/winstonjs/winston/issues/1432#issuecomment-659316062
  // Ref: https://github.com/winstonjs/winston?tab=readme-ov-file#formats
  const transformSpecialFields = format((info, _opts) => {
    // When running locally during development, colorFormat relies on the level field, and the
    // plugin field is natively first. But in the cloud we use JSON structured logging, and we need
    // the field name to be severity.
    if (process.env.NODE_ENV === 'production') {
      // Ref: https://cloud.google.com/run/docs/logging#special-fields
      // Ref: https://cloud.google.com/logging/docs/agent/ops-agent/configuration#special-fields
      // Ref: https://cloud.google.com/logging/docs/structured-logging#structured_logging_special_fields

      info.severity = info.level; // to make Cloud Run logging pick up the severity levels

      // @ts-ignore: TS error is "The operand of a 'delete' operator must be optional." While level
      // is a clearly required field in a logging message, here we are removing it only for the
      // final process of writing the logs, and it's redundant with severity. Since the production
      // implementation is to convert to JSON and interpretation is handled by GCP, nothing
      // downstream will break by removing the level field.
      delete info.level;
    }
    return info;
  });

  const getRedacter = (() => {
    let redacter: ReturnType<typeof WinstonLogger.redacter> | undefined =
      undefined;
    return () => {
      if (!redacter) {
        redacter = WinstonLogger.redacter();
      }
      return redacter;
    };
  })();

  createRootLogger({
    format: winston.format.combine(
      transformSpecialFields(),
      getRedacter().format,
      process.env.NODE_ENV === 'production'
        ? winston.format.json()
        : WinstonLogger.colorFormat(),
    ),
  });
}

async function main() {
  initializeLogging();

...

So I'd actually be even happier with the ability to be able to pass logging transforms into the initialization of the logging system.

πŸ–₯️ Your Environment

OS: Darwin 23.4.0 - darwin/x64 node: v20.10.0 yarn: 1.22.19 cli: 0.26.2 (installed) backstage: 1.25.2

Dependencies: @backstage/app-defaults 1.5.3 @backstage/backend-app-api 0.6.2, 0.7.1 @backstage/backend-common 0.21.6, 0.21.7 @backstage/backend-defaults 0.2.17 @backstage/backend-dev-utils 0.1.4 @backstage/backend-openapi-utils 0.1.10, 0.1.9 @backstage/backend-plugin-api 0.6.16, 0.6.17 @backstage/backend-tasks 0.5.21, 0.5.22 @backstage/catalog-client 1.6.3, 1.6.4 @backstage/catalog-model 1.4.5 @backstage/cli-common 0.1.13 @backstage/cli-node 0.2.4, 0.2.5 @backstage/cli 0.26.2 @backstage/config-loader 1.7.0, 1.8.0 @backstage/config 1.2.0 @backstage/core-app-api 1.12.3 @backstage/core-compat-api 0.2.3, 0.2.4 @backstage/core-components 0.14.5 @backstage/core-plugin-api 1.9.1, 1.9.2 @backstage/dev-utils 1.0.30 @backstage/errors 1.2.4 @backstage/eslint-plugin 0.1.6 @backstage/frontend-plugin-api 0.6.3, 0.6.4 @backstage/integration-aws-node 0.1.12 @backstage/integration-react 1.1.25, 1.1.26 @backstage/integration 1.10.0, 1.9.1 @backstage/plugin-api-docs-module-protoc-gen-doc 0.1.6 @backstage/plugin-api-docs 0.11.3 @backstage/plugin-app-backend 0.3.64 @backstage/plugin-app-node 0.1.16 @backstage/plugin-auth-backend-module-atlassian-provider 0.1.8 @backstage/plugin-auth-backend-module-aws-alb-provider 0.1.8 @backstage/plugin-auth-backend-module-gcp-iap-provider 0.2.11 @backstage/plugin-auth-backend-module-github-provider 0.1.13 @backstage/plugin-auth-backend-module-gitlab-provider 0.1.13 @backstage/plugin-auth-backend-module-google-provider 0.1.13 @backstage/plugin-auth-backend-module-microsoft-provider 0.1.11 @backstage/plugin-auth-backend-module-oauth2-provider 0.1.13 @backstage/plugin-auth-backend-module-oauth2-proxy-provider 0.1.9 @backstage/plugin-auth-backend-module-oidc-provider 0.1.7 @backstage/plugin-auth-backend-module-okta-provider 0.0.9 @backstage/plugin-auth-backend 0.22.3 @backstage/plugin-auth-node 0.4.11, 0.4.12 @backstage/plugin-auth-react 0.0.3 @backstage/plugin-catalog-backend-module-github 0.5.7 @backstage/plugin-catalog-backend-module-scaffolder-entity-model 0.1.14 @backstage/plugin-catalog-backend 1.21.0 @backstage/plugin-catalog-common 1.0.22 @backstage/plugin-catalog-graph 0.4.3 @backstage/plugin-catalog-import 0.10.9 @backstage/plugin-catalog-node 1.11.0, 1.11.1 @backstage/plugin-catalog-react 1.11.2, 1.11.3 @backstage/plugin-catalog 1.18.2 @backstage/plugin-events-backend-module-github 0.2.3 @backstage/plugin-events-backend 0.3.4 @backstage/plugin-events-node 0.3.3, 0.3.2 @backstage/plugin-home-react 0.1.11 @backstage/plugin-home 0.7.2 @backstage/plugin-org 0.6.23 @backstage/plugin-permission-common 0.7.13 @backstage/plugin-permission-node 0.7.27, 0.7.28 @backstage/plugin-permission-react 0.4.21, 0.4.22 @backstage/plugin-proxy-backend 0.4.14 @backstage/plugin-scaffolder-backend-module-azure 0.1.8 @backstage/plugin-scaffolder-backend-module-bitbucket-cloud 0.1.6 @backstage/plugin-scaffolder-backend-module-bitbucket-server 0.1.6 @backstage/plugin-scaffolder-backend-module-bitbucket 0.2.6 @backstage/plugin-scaffolder-backend-module-gerrit 0.1.8 @backstage/plugin-scaffolder-backend-module-gitea 0.1.6 @backstage/plugin-scaffolder-backend-module-github 0.2.6, 0.2.7 @backstage/plugin-scaffolder-backend-module-gitlab 0.3.2 @backstage/plugin-scaffolder-backend 1.22.3 @backstage/plugin-scaffolder-common 1.5.1 @backstage/plugin-scaffolder-node 0.4.2, 0.4.3 @backstage/plugin-scaffolder-react 1.8.3 @backstage/plugin-scaffolder 1.19.2 @backstage/plugin-search-backend-module-catalog 0.1.21 @backstage/plugin-search-backend-module-pg 0.5.25 @backstage/plugin-search-backend-module-techdocs 0.1.21 @backstage/plugin-search-backend-node 1.2.20 @backstage/plugin-search-backend 1.5.6 @backstage/plugin-search-common 1.2.11 @backstage/plugin-search-react 1.7.10, 1.7.9 @backstage/plugin-search 1.4.9 @backstage/plugin-techdocs-backend 1.10.3 @backstage/plugin-techdocs-module-addons-contrib 1.1.8 @backstage/plugin-techdocs-node 1.12.2 @backstage/plugin-techdocs-react 1.2.2 @backstage/plugin-techdocs 1.10.3 @backstage/plugin-user-settings 0.8.4 @backstage/release-manifests 0.0.11 @backstage/test-utils 1.5.3 @backstage/theme 0.5.2, 0.5.3 @backstage/types 1.1.1 @backstage/version-bridge 1.0.7, 1.0.8 ✨ Done in 1.27s.

πŸ‘€ Have you spent some time to check if this bug has been raised before?

🏒 Have you read the Code of Conduct?

Are you willing to submit PR?

No, but I'm happy to collaborate on a PR with someone else

aramissennyeydd commented 1 week ago

πŸ‘‹ , you should be able to override the default rootLogger or logger like so,

import {
  coreServices,
  createServiceFactory,
} from '@backstage/backend-plugin-api';

export const myRootLogger = createServiceFactory({
  service: coreServices.rootLogger,
  deps: {
    // my custom deps
  },
  async factory({ // my deps }) {
    // initialize my custom logging.
  }
})

The rootLogger implementation is here, and there's already an override that you can reference here. Then you just install this as you would any plugin using the backend.add synxtax.

edit: more details here

vonjones commented 1 week ago

Thanks so much for your suggestion. That did fix the concern. I'll close the ticket

For those who may look back at this, here is my working code to support GCP Cloud Run logging with the severity field, for the new Backstage backend mechanism:

// packages/backend/src/services/myRootLogger.ts
import {
  coreServices,
  createServiceFactory,
} from '@backstage/backend-plugin-api';
import {
  WinstonLogger,
  createConfigSecretEnumerator,
} from '@backstage/backend-app-api';
import { transports, format } from 'winston';
import * as winston from 'winston';

  // This replaces the default rootLogger implementation with a custom one. The rootLogger
  // implementation is
  // [here](https://github.com/aramissennyeydd/backstage/blob/8288fb6458a5a676685e73cca57cbba66a30c463/packages/backend-app-api/src/services/implementations/rootLogger/rootLoggerServiceFactory.ts#L26).
  // There's already an override that you can reference
  // [here](https://github.com/aramissennyeydd/backstage/blob/8288fb6458a5a676685e73cca57cbba66a30c463/packages/backend-dynamic-feature-service/src/schemas/rootLoggerServiceFactory.ts#L29).
  // Then you just install this as you would any plugin using the backend.add synxtax.
  export const myRootLogger = createServiceFactory(() => ({
  service: coreServices.rootLogger,
  deps: {
    config: coreServices.rootConfig,
  },
  async factory({ config }) {
    // Our custom rootLogger corrects a problem when running in GCP Cloud Run, where GCP expects a
    // severity field rather than a level field. Without this, GCP puts a star (`*`) in the severity
    // field. This implies that one cannot skim logs to search for errors, as you can when working
    // locally.

    // Ref: https://cloud.google.com/run/docs/logging#special-fields
    // Ref: https://cloud.google.com/logging/docs/agent/ops-agent/configuration#special-fields
    // Ref: https://cloud.google.com/logging/docs/structured-logging#structured_logging_special_fields

    // Ref: https://github.com/winstonjs/winston/issues/1432#issuecomment-659316062
    // Ref: https://github.com/winstonjs/winston?tab=readme-ov-file#formats
    const transformSpecialFields = format((info, _opts) => {
      // When running locally during development, colorFormat relies on the level field, and the
      // plugin field is natively first. But in the cloud we use JSON structured logging, and we
      // need the field name to be severity.
      if (process.env.NODE_ENV === 'production') {

        info.severity = info.level; // to make Cloud Run logging pick up the severity levels

        // @ts-ignore: TS error is "The operand of a 'delete' operator must be optional." While
        // level is a clearly required field in a logging message, here we are removing it only for
        // the final process of writing the logs, and it's now redundant with severity. Since the
        // production implementation is to convert to JSON and interpretation is handled by GCP,
        // nothing downstream will break by removing the level field.
        delete info.level;
      }
      return info;
    });

    const logger = WinstonLogger.create({
      meta: {
        service: 'backstage',
      },
      level: process.env.LOG_LEVEL || 'info',
      format:
        // the customization
        winston.format.combine(
          transformSpecialFields(),
          process.env.NODE_ENV === 'production'
            ? format.json()
            : WinstonLogger.colorFormat(),
        ),
      transports: [new transports.Console()],
    });

    const secretEnumerator = await createConfigSecretEnumerator({ logger });
    logger.addRedactions(secretEnumerator(config));
    config.subscribe?.(() => logger.addRedactions(secretEnumerator(config)));

    return logger;
  },
}));
// packages/backend/src/index.ts
import { myRootLogger } from './services/myRootLogger';
...
const backend = createBackend();
backend.add(myRootLogger);
backend.add(import('@backstage/plugin-app-backend/alpha'));
...