chore: Log correlation in traces in google cloud (#11276)

Adds a google cloud logger config so that logs trace and span ids use
the required naming for correlation.

Replaces #11019

Fixes #10937

yarn-project/end-to-end/src/fixtures/get_acvm_config.ts

@@ -1,4 +1,5 @@
 import { type Logger } from '@aztec/aztec.js';
+import { parseBooleanEnv } from '@aztec/foundation/config';
 import { randomBytes } from '@aztec/foundation/crypto';
 
 import { promises as fs } from 'fs';
@@ -23,7 +24,7 @@ export async function getACVMConfig(logger: Logger): Promise<
   | undefined
 > {
   try {
-    if (['1', 'true'].includes(ACVM_FORCE_WASM)) {
+    if (parseBooleanEnv(ACVM_FORCE_WASM)) {
       return undefined;
     }
     const acvmBinaryPath = ACVM_BINARY_PATH ? ACVM_BINARY_PATH : `../../noir/${NOIR_RELEASE_DIR}/acvm`;

yarn-project/foundation/src/config/index.ts

@@ -1,6 +1,6 @@
 import { type EnvVar } from './env_var.js';
 
-export { EnvVar } from './env_var.js';
+export { type EnvVar } from './env_var.js';
 
 export interface ConfigMapping {
   env?: EnvVar;
@@ -102,7 +102,7 @@ export function optionalNumberConfigHelper(): Pick<ConfigMapping, 'parseEnv'> {
 export function booleanConfigHelper(
   defaultVal = false,
 ): Required<Pick<ConfigMapping, 'parseEnv' | 'defaultValue' | 'isBoolean'> & { parseVal: (val: string) => boolean }> {
-  const parse = (val: string | boolean) => (typeof val === 'boolean' ? val : ['1', 'true', 'TRUE'].includes(val));
+  const parse = (val: string | boolean) => (typeof val === 'boolean' ? val : parseBooleanEnv(val));
   return {
     parseEnv: parse,
     parseVal: parse,
@@ -111,6 +111,11 @@ export function booleanConfigHelper(
   };
 }
 
+/** Parses an env var as boolean. Returns true only if value is 1, true, or TRUE. */
+export function parseBooleanEnv(val: string | undefined): boolean {
+  return val !== undefined && ['1', 'true', 'TRUE'].includes(val);
+}
+
 /**
  * Safely parses a number from a string.
  * If the value is not a number or is not a safe integer, the default value is returned.

yarn-project/foundation/src/log/gcloud-logger-config.ts

@@ -0,0 +1,71 @@
+import { type pino } from 'pino';
+
+/* eslint-disable camelcase */
+
+const GOOGLE_CLOUD_TRACE_ID = 'logging.googleapis.com/trace';
+const GOOGLE_CLOUD_SPAN_ID = 'logging.googleapis.com/spanId';
+const GOOGLE_CLOUD_TRACE_SAMPLED = 'logging.googleapis.com/trace_sampled';
+
+/**
+ * Pino configuration for google cloud observability. Tweaks message and timestamp,
+ * adds trace context attributes, and injects severity level.
+ * Adapted from https://cloud.google.com/trace/docs/setup/nodejs-ot#config-structured-logging.
+ */
+export const GoogleCloudLoggerConfig = {
+  messageKey: 'message',
+  // Same as pino.stdTimeFunctions.isoTime but uses "timestamp" key instead of "time"
+  timestamp(): string {
+    return `,"timestamp":"${new Date(Date.now()).toISOString()}"`;
+  },
+  formatters: {
+    log(object: Record<string, unknown>): Record<string, unknown> {
+      // Add trace context attributes following Cloud Logging structured log format described
+      // in https://cloud.google.com/logging/docs/structured-logging#special-payload-fields
+      const { trace_id, span_id, trace_flags, ...rest } = object;
+
+      if (trace_id && span_id) {
+        return {
+          [GOOGLE_CLOUD_TRACE_ID]: trace_id,
+          [GOOGLE_CLOUD_SPAN_ID]: span_id,
+          [GOOGLE_CLOUD_TRACE_SAMPLED]: trace_flags ? trace_flags === '01' : undefined,
+          trace_flags, // Keep the original trace_flags for otel-pino-stream
+          ...rest,
+        };
+      }
+      return object;
+    },
+    level(label: string, level: number): object {
+      // Inspired by https://github.com/pinojs/pino/issues/726#issuecomment-605814879
+      // Severity labels https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#LogSeverity
+      let severity: string;
+
+      switch (label as pino.Level | keyof typeof customLevels) {
+        case 'trace':
+        case 'debug':
+          severity = 'DEBUG';
+          break;
+        case 'verbose':
+        case 'info':
+          severity = 'INFO';
+          break;
+        case 'warn':
+          severity = 'WARNING';
+          break;
+        case 'error':
+          severity = 'ERROR';
+          break;
+        case 'fatal':
+          severity = 'CRITICAL';
+          break;
+        default:
+          severity = 'DEFAULT';
+          break;
+      }
+
+      return { severity, level };
+    },
+  },
+} satisfies pino.LoggerOptions;
+
+// Define custom logging levels for pino. Duplicate from pino-logger.ts.
+const customLevels = { verbose: 25 };

yarn-project/foundation/src/log/pino-logger.ts

@@ -5,6 +5,8 @@ import { type Writable } from 'stream';
 import { inspect } from 'util';
 
 import { compactArray } from '../collection/array.js';
+import { type EnvVar, parseBooleanEnv } from '../config/index.js';
+import { GoogleCloudLoggerConfig } from './gcloud-logger-config.js';
 import { getLogLevelFromFilters, parseEnv } from './log-filters.js';
 import { type LogLevel } from './log-levels.js';
 import { type LogData, type LogFn } from './log_fn.js';
@@ -86,46 +88,14 @@ const [logLevel, logFilters] = parseEnv(process.env.LOG_LEVEL, defaultLogLevel);
 // Define custom logging levels for pino.
 const customLevels = { verbose: 25 };
 
-// inspired by https://github.com/pinojs/pino/issues/726#issuecomment-605814879
-const levelToSeverityFormatter = (label: string, level: number): object => {
-  // Severity labels https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#LogSeverity
-  let severity: string;
-
-  switch (label as pino.Level | keyof typeof customLevels) {
-    case 'trace':
-    case 'debug':
-      severity = 'DEBUG';
-      break;
-    case 'verbose':
-    case 'info':
-      severity = 'INFO';
-      break;
-    case 'warn':
-      severity = 'WARNING';
-      break;
-    case 'error':
-      severity = 'ERROR';
-      break;
-    case 'fatal':
-      severity = 'CRITICAL';
-      break;
-    default:
-      severity = 'DEFAULT';
-      break;
-  }
-
-  return { severity, level };
-};
-
-const useGcloudObservability = process.env.USE_GCLOUD_OBSERVABILITY === 'true';
+// Global pino options, tweaked for google cloud if running there.
+const useGcloudObservability = parseBooleanEnv(process.env['USE_GCLOUD_OBSERVABILITY' satisfies EnvVar]);
 const pinoOpts: pino.LoggerOptions<keyof typeof customLevels> = {
   customLevels,
-  messageKey: useGcloudObservability ? 'message' : 'msg',
+  messageKey: 'msg',
   useOnlyCustomLevels: false,
   level: logLevel,
-  formatters: {
-    level: levelToSeverityFormatter,
-  },
+  ...(useGcloudObservability ? GoogleCloudLoggerConfig : {}),
 };
 
 export const levels = {
@@ -145,7 +115,7 @@ export const pinoPrettyOpts = {
   customLevels: 'fatal:60,error:50,warn:40,info:30,verbose:25,debug:20,trace:10',
   customColors: 'fatal:bgRed,error:red,warn:yellow,info:green,verbose:magenta,debug:blue,trace:gray',
   minimumLevel: 'trace' as const,
-  singleLine: !['1', 'true'].includes(process.env.LOG_MULTILINE ?? ''),
+  singleLine: !parseBooleanEnv(process.env['LOG_MULTILINE' satisfies EnvVar]),
 };
 
 const prettyTransport: pino.TransportTargetOptions = {
@@ -167,7 +137,8 @@ const stdioTransport: pino.TransportTargetOptions = {
 // would mean that all child loggers created before the telemetry-client is initialized would not have
 // this transport configured. Note that the target is defined as the export in the telemetry-client,
 // since pino will load this transport separately on a worker thread, to minimize disruption to the main loop.
-const otlpEndpoint = process.env.OTEL_EXPORTER_OTLP_LOGS_ENDPOINT;
+const otlpEndpoint = process.env['OTEL_EXPORTER_OTLP_LOGS_ENDPOINT' satisfies EnvVar];
+const otlpEnabled = !!otlpEndpoint && !useGcloudObservability;
 const otelOpts = { levels };
 const otelTransport: pino.TransportTargetOptions = {
   target: '@aztec/telemetry-client/otel-pino-stream',
@@ -185,10 +156,10 @@ function makeLogger() {
     return pino(pinoOpts, pino.destination(2));
   } else {
     // Regular nodejs with transports on worker thread, using pino-pretty for console logging if LOG_JSON
-    // is not set, and an optional OTLP transport if the OTLP endpoint is provided.
+    // is not set, and an optional OTLP transport if the OTLP endpoint is set.
     const targets: pino.TransportSingleOptions[] = compactArray([
-      ['1', 'true', 'TRUE'].includes(process.env.LOG_JSON ?? '') ? stdioTransport : prettyTransport,
-      otlpEndpoint ? otelTransport : undefined,
+      parseBooleanEnv(process.env.LOG_JSON) ? stdioTransport : prettyTransport,
+      otlpEnabled ? otelTransport : undefined,
     ]);
     return pino(pinoOpts, pino.transport({ targets, levels: levels.values }));
   }
@@ -203,7 +174,7 @@ logger.verbose(
     ...logFilters.reduce((accum, [module, level]) => ({ ...accum, [`log.${module}`]: level }), {}),
   },
   isNode
-    ? `Logger initialized with level ${logLevel}` + (otlpEndpoint ? ` with OTLP exporter to ${otlpEndpoint}` : '')
+    ? `Logger initialized with level ${logLevel}` + (otlpEnabled ? ` with OTLP exporter to ${otlpEndpoint}` : '')
     : `Browser console logger initialized with level ${logLevel}`,
 );
 

yarn-project/pxe/src/config/index.ts

@@ -4,6 +4,7 @@ import {
   booleanConfigHelper,
   getConfigFromMappings,
   numberConfigHelper,
+  parseBooleanEnv,
 } from '@aztec/foundation/config';
 import { type DataStoreConfig, dataConfigMappings } from '@aztec/kv-store/config';
 import { type Network } from '@aztec/types/network';
@@ -99,7 +100,7 @@ export const allPxeConfigMappings: ConfigMappingsType<CliPXEOptions & PXEService
   ...dataConfigMappings,
   proverEnabled: {
     env: 'PXE_PROVER_ENABLED',
-    parseEnv: (val: string) => ['1', 'true', 'TRUE'].includes(val) || !!process.env.NETWORK,
+    parseEnv: (val: string) => parseBooleanEnv(val) || !!process.env.NETWORK,
     description: 'Enable real proofs',
     isBoolean: true,
   },

yarn-project/telemetry-client/src/config.ts

@@ -1,4 +1,4 @@
-import { type ConfigMappingsType, getConfigFromMappings } from '@aztec/foundation/config';
+import { type ConfigMappingsType, booleanConfigHelper, getConfigFromMappings } from '@aztec/foundation/config';
 
 export interface TelemetryClientConfig {
   useGcloudObservability: boolean;
@@ -18,8 +18,7 @@ export const telemetryClientConfigMappings: ConfigMappingsType<TelemetryClientCo
   useGcloudObservability: {
     env: 'USE_GCLOUD_OBSERVABILITY',
     description: 'Whether to use GCP observability',
-    defaultValue: false,
-    parseEnv: (val: string) => val === 'true',
+    ...booleanConfigHelper(false),
   },
   metricsCollectorUrl: {
     env: 'OTEL_EXPORTER_OTLP_METRICS_ENDPOINT',

yarn-project/telemetry-client/src/otel.ts

@@ -1,7 +1,7 @@
 import { type LogData, type Logger, addLogDataHandler } from '@aztec/foundation/log';
 
-import { MetricExporter } from '@google-cloud/opentelemetry-cloud-monitoring-exporter';
-import { TraceExporter } from '@google-cloud/opentelemetry-cloud-trace-exporter';
+import { MetricExporter as GoogleCloudMetricExporter } from '@google-cloud/opentelemetry-cloud-monitoring-exporter';
+import { TraceExporter as GoogleCloudTraceExporter } from '@google-cloud/opentelemetry-cloud-trace-exporter';
 import {
   DiagConsoleLogger,
   DiagLogLevel,
@@ -237,17 +237,17 @@ export class OpenTelemetryClient implements TelemetryClient {
     });
   }
 
-  public static getGcloudClientFactory(config: TelemetryClientConfig): OpenTelemetryClientFactory {
+  private static getGcloudClientFactory(config: TelemetryClientConfig): OpenTelemetryClientFactory {
     return (resource: IResource, log: Logger) => {
       const tracerProvider = new NodeTracerProvider({
         resource,
-        spanProcessors: [new BatchSpanProcessor(new TraceExporter({ resourceFilter: /.*/ }))],
+        spanProcessors: [new BatchSpanProcessor(new GoogleCloudTraceExporter({ resourceFilter: /.*/ }))],
       });
 
       tracerProvider.register();
 
       const meterProvider = OpenTelemetryClient.createMeterProvider(resource, {
-        exporter: new MetricExporter(),
+        exporter: new GoogleCloudMetricExporter(),
         exportTimeoutMillis: config.otelExportTimeoutMs,
         exportIntervalMillis: config.otelCollectIntervalMs,
       });
@@ -256,7 +256,7 @@ export class OpenTelemetryClient implements TelemetryClient {
     };
   }
 
-  public static getCustomClientFactory(config: TelemetryClientConfig): OpenTelemetryClientFactory {
+  private static getCustomClientFactory(config: TelemetryClientConfig): OpenTelemetryClientFactory {
     return (resource: IResource, log: Logger) => {
       const tracerProvider = new NodeTracerProvider({
         resource,