feat: JSON logging

yarn-project/aztec/src/cli/cli.ts

@@ -7,6 +7,7 @@ import { createPXERpcServer } from '@aztec/pxe';
 import { Command } from 'commander';
 import http from 'http';
 
+import { setupConsoleJsonLog } from '../logging.js';
 import { createSandbox } from '../sandbox.js';
 import { github, splash } from '../splash.js';
 import { aztecStartOptions } from './aztec_start_options.js';
@@ -36,6 +37,11 @@ export function injectAztecCommands(program: Command, userLog: LogFn, debugLogge
   startCmd.helpInformation = printAztecStartHelpText;
 
   startCmd.action(async options => {
+    // setup json logging
+    if (['1', 'true', 'TRUE'].includes(process.env.LOG_JSON ?? '')) {
+      setupConsoleJsonLog();
+    }
+
     // list of 'stop' functions to call when process ends
     const signalHandlers: Array<() => Promise<void>> = [];
     let services: ServerList = [];
@@ -112,7 +118,7 @@ export function injectAztecCommands(program: Command, userLog: LogFn, debugLogge
 
       const httpServer = http.createServer(app.callback());
       httpServer.listen(options.port);
-      userLog(`Aztec Server listening on port ${options.port}`);
+      debugLogger.info(`Aztec Server listening on port ${options.port}`);
     }
   });
 

yarn-project/aztec/src/logging.ts

@@ -1,4 +1,4 @@
-import { onLog } from '@aztec/foundation/log';
+import { onLog, setLevel } from '@aztec/foundation/log';
 
 import * as path from 'path';
 import * as process from 'process';
@@ -10,7 +10,7 @@ const CURRENT_LOG_FILE_NAME = 'aztec.debug.log';
 const LOG_DIR = 'log';
 
 /** Creates a winston logger that logs everything to a local rotating file */
-function createWinstonLogger() {
+function createWinstonLocalFileLogger() {
   // See https://www.npmjs.com/package/winston-daily-rotate-file#user-content-options
   const transport: DailyRotateFile = new DailyRotateFile({
     filename: 'aztec-%DATE%.debug.log',
@@ -30,15 +30,34 @@ function createWinstonLogger() {
   });
 }
 
+/** Creates a winston logger that logs everything to stdout in json format */
+function createWinstonJsonStdoutLogger() {
+  return winston.createLogger({
+    level: process.env.LOG_LEVEL ?? 'info',
+    transports: [new winston.transports.Console({ format: format.combine(format.timestamp(), format.json()) })],
+  });
+}
+
 /**
  * Hooks to all log statements and outputs them to a local rotating file.
  * @returns Output log name.
  */
 export function setupFileDebugLog() {
-  const logger = createWinstonLogger();
-  onLog((level, namespace, message, data) => {
-    logger.log({ ...data, level, namespace, message });
+  const logger = createWinstonLocalFileLogger();
+  onLog((level, module, message, data) => {
+    logger.log({ ...data, level, module, message });
   });
   const workdir = process.env.HOST_WORKDIR ?? process.cwd();
   return path.join(workdir, LOG_DIR, CURRENT_LOG_FILE_NAME);
 }
+
+/**
+ * Silences the foundation stdout logger and funnels all logs through a winston JSON logger.
+ */
+export function setupConsoleJsonLog() {
+  const logger = createWinstonJsonStdoutLogger();
+  setLevel('silent');
+  onLog((level, module, message, data) => {
+    logger.log({ ...data, level, module, message });
+  });
+}

yarn-project/aztec/terraform/bot/main.tf

@@ -172,7 +172,8 @@ resource "aws_ecs_task_definition" "aztec-bot" {
         { name = "PXE_PROVER_ENABLED", value = tostring(var.PROVING_ENABLED) },
         { name = "NETWORK", value = var.DEPLOY_TAG },
         { name = "BOT_FLUSH_SETUP_TRANSACTIONS", value = tostring(var.BOT_FLUSH_SETUP_TRANSACTIONS) },
-        { name = "BOT_MAX_PENDING_TXS", value = tostring(var.BOT_MAX_PENDING_TXS) }
+        { name = "BOT_MAX_PENDING_TXS", value = tostring(var.BOT_MAX_PENDING_TXS) },
+        { name = "LOG_JSON", value = "1" }
       ]
       logConfiguration = {
         logDriver = "awslogs"

yarn-project/aztec/terraform/node/main.tf

@@ -356,6 +356,10 @@ resource "aws_ecs_task_definition" "aztec-node" {
           name  = "LOG_LEVEL"
           value = "info"
         },
+        {
+          name  = "LOG_JSON",
+          value = "1"
+        },
         {
           name  = "NETWORK_NAME",
           value = "${var.DEPLOY_TAG}"

yarn-project/aztec/terraform/prover-node/main.tf

@@ -171,6 +171,7 @@ resource "aws_ecs_task_definition" "aztec-prover-node" {
         // General
         { name = "NODE_ENV", value = "production" },
         { name = "LOG_LEVEL", value = "verbose" },
+        { name = "LOG_JSON", value = "1" },
         { name = "DEBUG", value = "aztec:*,-json-rpc:json_proxy:*,-aztec:avm_simulator:*" },
         { name = "DEPLOY_TAG", value = var.DEPLOY_TAG },
         { name = "NETWORK_NAME", value = "${var.DEPLOY_TAG}" },

yarn-project/aztec/terraform/prover/main.tf

@@ -284,6 +284,10 @@ resource "aws_ecs_task_definition" "aztec-proving-agent" {
       {
         "name": "NETWORK_NAME",
         "value": "${var.DEPLOY_TAG}"
+      },
+      { 
+        "name": "LOG_JSON", 
+        "value": "1" 
       }
     ],
     "logConfiguration": {

yarn-project/aztec/terraform/pxe/main.tf

@@ -150,6 +150,10 @@ resource "aws_ecs_task_definition" "aztec-pxe" {
         {
           name  = "PXE_PROVER_ENABLED"
           value = tostring(var.PROVING_ENABLED)
+        },
+        {
+          name  = "LOG_JSON"
+          value = "1"
         }
       ]
       mountPoints = [

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

@@ -78,6 +78,7 @@ export type EnvVar =
   | 'PROVER_TEST_DELAY_MS'
   | 'TX_PROVIDER_NODE_URL'
   | 'TXE_PORT'
+  | 'LOG_JSON'
   | 'BOT_PXE_URL'
   | 'BOT_PRIVATE_KEY'
   | 'BOT_RECIPIENT_ENCRYPTION_SECRET'

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

@@ -12,7 +12,7 @@ const DefaultLogLevel = process.env.NODE_ENV === 'test' ? ('silent' as const) :
 export type LogLevel = (typeof LogLevels)[number];
 
 const envLogLevel = process.env.LOG_LEVEL?.toLowerCase() as LogLevel;
-export const currentLevel = LogLevels.includes(envLogLevel) ? envLogLevel : DefaultLogLevel;
+export let currentLevel = LogLevels.includes(envLogLevel) ? envLogLevel : DefaultLogLevel;
 
 const namespaces = process.env.DEBUG ?? 'aztec:*';
 debug.enable(namespaces);
@@ -65,6 +65,11 @@ export function onLog(handler: LogHandler) {
   logHandlers.push(handler);
 }
 
+/** Overrides current log level. */
+export function setLevel(level: LogLevel) {
+  currentLevel = level;
+}
+
 /**
  * Logs args to npm debug if enabled or log level is debug, console.error otherwise.
  * @param debug - Instance of npm debug.