Improve uncaught error handling, include configuration errors in logs (#227)

* Improve uncaught error handling

* Exit on uncaught error to avoid logging to stderr

* Make sure the configuration issues are logged

Author: Siegrift

packages/airnode-feed/src/index.ts

@@ -1,31 +1,38 @@
-import { go } from '@api3/promise-utils';
-
 import { initiateSignedApiUpdateLoops } from './fetch-beacon-data';
 import { initiateHeartbeatLoop } from './heartbeat';
 import { logger } from './logger';
 import { initializeState } from './state';
 import { loadConfig } from './validation/config';
 
+const setupUncaughtErrorHandler = () => {
+  // NOTE: From the Node.js docs:
+  //
+  // Installing an 'uncaughtExceptionMonitor' listener does not change the behavior once an 'uncaughtException' event is
+  // emitted. The process will still crash if no 'uncaughtException' listener is installed.
+  process.on('uncaughtExceptionMonitor', (error, origin) => {
+    logger.error('Uncaught exception.', error, { origin });
+  });
+
+  // We want to exit the process immediately to avoid Node.js to log the uncaught error to stderr.
+  process.on('uncaughtException', () => process.exit(1));
+  process.on('unhandledRejection', () => process.exit(1));
+};
+
 // Start the Airnode feed. All application errors should be handled by this function (or its callees) and any error from
 // this function is considered unexpected.
 const startAirnodeFeed = async () => {
-  const goConfig = await go(loadConfig);
-  if (!goConfig.success) {
-    // Note, that the error should not expose any sensitive information.
-    logger.error('Failed to load the configuration.', goConfig.error);
-    return;
-  }
-  initializeState(goConfig.data);
+  const config = await loadConfig();
+  if (!config) return;
+  initializeState(config);
 
   void initiateSignedApiUpdateLoops();
   initiateHeartbeatLoop();
 };
 
 const main = async () => {
-  const goStartAirnodeFeed = await go(startAirnodeFeed);
-  if (!goStartAirnodeFeed.success) {
-    logger.error('Could not start Airnode feed. Unexpected error occurred.', goStartAirnodeFeed.error);
-  }
+  setupUncaughtErrorHandler();
+
+  await startAirnodeFeed();
 };
 
 void main();

packages/airnode-feed/src/validation/config.ts

@@ -5,6 +5,8 @@ import { cwd } from 'node:process';
 import { go } from '@api3/promise-utils';
 import dotenv from 'dotenv';
 
+import { logger } from '../logger';
+
 import { configSchema } from './schema';
 import { interpolateSecrets, parseSecrets } from './utils';
 
@@ -24,6 +26,9 @@ export const loadConfig = async () => {
     return configSchema.parseAsync(interpolateSecrets(rawConfig, secrets));
   });
 
-  if (!goLoadConfig.success) throw new Error(`Unable to load configuration.`, { cause: goLoadConfig.error });
+  if (!goLoadConfig.success) {
+    logger.error(`Unable to load configuration.`, goLoadConfig.error);
+    return null;
+  }
   return goLoadConfig.data;
 };

packages/signed-api/src/config/config.test.ts

@@ -7,16 +7,16 @@ import type { AllowedAirnode } from '../schema';
 
 import * as configModule from './config';
 
-test('interpolates example config and secrets', () => {
+test('interpolates example config and secrets', async () => {
   jest
-    .spyOn(configModule, 'loadRawConfig')
+    .spyOn(configModule, 'loadRawConfigFromFilesystem')
     .mockReturnValue(JSON.parse(readFileSync(join(__dirname, '../../config/signed-api.example.json'), 'utf8')));
   jest
-    .spyOn(configModule, 'loadRawSecrets')
+    .spyOn(configModule, 'loadRawSecretsFromFilesystem')
     .mockReturnValue(dotenv.parse(readFileSync(join(__dirname, '../../config/secrets.example.env'), 'utf8')));
 
-  const config = configModule.loadConfigFromFilesystem();
+  const config = await configModule.loadConfig();
 
-  expect(config.endpoints[0]!.authTokens).toStrictEqual(['secret-endpoint-token']);
-  expect((config.allowedAirnodes[0] as AllowedAirnode).authTokens).toStrictEqual(['secret-airnode-token']);
+  expect(config!.endpoints[0]!.authTokens).toStrictEqual(['secret-endpoint-token']);
+  expect((config!.allowedAirnodes[0] as AllowedAirnode).authTokens).toStrictEqual(['secret-airnode-token']);
 });

packages/signed-api/src/config/config.ts

@@ -20,64 +20,86 @@ export const getConfig = (): Config => {
   return config;
 };
 
-export const loadAndCacheConfig = async (): Promise<Config> => {
-  const jsonConfig = await fetchConfig();
-  config = configSchema.parse(jsonConfig);
-  return config;
-};
-
 // When Signed API is built, the "/dist" file contains "src" folder and "package.json" and the config is expected to be
 // located next to the "/dist" folder. When run in development, the config is expected to be located next to the "src"
 // folder (one less import level). We resolve the config by CWD as a workaround. Since the Signed API is dockerized,
 // this is hidden from the user.
 const getConfigPath = () => join(cwd(), './config');
 
-export const loadRawConfig = () => JSON.parse(readFileSync(join(getConfigPath(), 'signed-api.json'), 'utf8'));
+export const loadRawConfigFromFilesystem = () =>
+  JSON.parse(readFileSync(join(getConfigPath(), 'signed-api.json'), 'utf8'));
 
-export const loadRawSecrets = () => dotenv.parse(readFileSync(join(getConfigPath(), 'secrets.env'), 'utf8'));
+export const loadRawSecretsFromFilesystem = () =>
+  dotenv.parse(readFileSync(join(getConfigPath(), 'secrets.env'), 'utf8'));
 
 export const loadConfigFromFilesystem = () => {
   const goLoadConfig = goSync(() => {
-    const rawSecrets = loadRawSecrets();
-    const rawConfig = loadRawConfig();
+    const rawSecrets = loadRawSecretsFromFilesystem();
+    const rawConfig = loadRawConfigFromFilesystem();
     const secrets = parseSecrets(rawSecrets);
-    return configSchema.parse(interpolateSecrets(rawConfig, secrets));
+    return interpolateSecrets(rawConfig, secrets);
   });
 
-  if (!goLoadConfig.success) throw new Error(`Unable to load configuration.`, { cause: goLoadConfig.error });
+  if (!goLoadConfig.success) {
+    logger.error(`Unable to load configuration.`, goLoadConfig.error);
+    return null;
+  }
   return goLoadConfig.data;
 };
 
-const fetchConfig = async (): Promise<any> => {
+export const loadNonValidatedConfig = async () => {
   const env = loadEnv();
   const source = env.CONFIG_SOURCE;
   switch (source) {
     case 'local': {
       return loadConfigFromFilesystem();
     }
     case 'aws-s3': {
-      return fetchConfigFromS3();
+      return loadConfigFromS3();
     }
   }
 };
 
-const fetchConfigFromS3 = async (): Promise<any> => {
-  const env = loadEnv();
-  const region = env.AWS_REGION!; // Validated by environment variables schema.
-  const s3 = new S3({ region });
-
-  const params = {
-    Bucket: env.AWS_S3_BUCKET_NAME,
-    Key: env.AWS_S3_BUCKET_PATH,
-  };
-
-  logger.info(`Fetching config from AWS S3 region.`, { region });
-  const res = await go(async () => s3.getObject(params), { retries: 1 });
-  if (!res.success) {
-    logger.error('Error fetching config from AWS S3.', res.error);
-    throw res.error;
+export const loadConfig = async () => {
+  if (config) return config;
+
+  const nonValidatedConfig = await loadNonValidatedConfig();
+  if (!nonValidatedConfig) return null;
+
+  const safeParsedConfig = configSchema.safeParse(nonValidatedConfig);
+  if (!safeParsedConfig.success) {
+    logger.error('Config failed validation.', safeParsedConfig.error);
+    return null;
+  }
+  return (config = safeParsedConfig.data);
+};
+
+const loadConfigFromS3 = async (): Promise<any> => {
+  const goFetchConfig = await go(async () => {
+    const env = loadEnv();
+    const region = env.AWS_REGION!; // Validated by environment variables schema.
+    const s3 = new S3({ region });
+
+    const params = {
+      Bucket: env.AWS_S3_BUCKET_NAME,
+      Key: env.AWS_S3_BUCKET_PATH,
+    };
+
+    logger.info(`Fetching config from AWS S3 region.`, { region });
+    const res = await go(async () => s3.getObject(params), { retries: 1 });
+    if (!res.success) {
+      logger.error('Error fetching config from AWS S3.', res.error);
+      return null;
+    }
+    logger.info('Config fetched successfully from AWS S3.');
+    const stringifiedConfig = await res.data.Body!.transformToString();
+    return JSON.parse(stringifiedConfig);
+  });
+
+  // Check whether the config returned a truthy response, because false response assumes an error has been handled.
+  if (!goFetchConfig.success || !goFetchConfig.data) {
+    logger.error('Unexpected error during fetching config from S3.', goFetchConfig.error);
+    return null;
   }
-  logger.info('Config fetched successfully from AWS S3.');
-  const stringifiedConfig = await res.data.Body!.transformToString();
-  return JSON.parse(stringifiedConfig);
+  return goFetchConfig.data;
 };

packages/signed-api/src/index.ts

@@ -1,22 +1,32 @@
 import { go } from '@api3/promise-utils';
 import z from 'zod';
 
-import { loadAndCacheConfig } from './config/config';
+import { loadConfig } from './config/config';
 import { logger } from './logger';
 import { DEFAULT_PORT, startServer } from './server';
 import { initializeVerifierPool } from './signed-data-verifier-pool';
 
+const setupUncaughtErrorHandler = () => {
+  // NOTE: From the Node.js docs:
+  //
+  // Installing an 'uncaughtExceptionMonitor' listener does not change the behavior once an 'uncaughtException' event is
+  // emitted. The process will still crash if no 'uncaughtException' listener is installed.
+  process.on('uncaughtExceptionMonitor', (error, origin) => {
+    logger.error('Uncaught exception.', error, { origin });
+  });
+
+  // We want to exit the process immediately to avoid Node.js to log the uncaught error to stderr.
+  process.on('uncaughtException', () => process.exit(1));
+  process.on('unhandledRejection', () => process.exit(1));
+};
+
 const portSchema = z.coerce.number().int().positive();
 
 // Start the Signed API. All application errors should be handled by this function (or its callees) and any error from
 // this function is considered unexpected.
 const startSignedApi = async () => {
-  const goConfig = await go(loadAndCacheConfig);
-  if (!goConfig.success) {
-    logger.error('Failed to load the configuration.', goConfig.error);
-    return;
-  }
-  const config = goConfig.data;
+  const config = await loadConfig();
+  if (!config) return;
   logger.info('Using configuration.', config);
 
   const goPool = await go(() => initializeVerifierPool());
@@ -45,10 +55,9 @@ const startSignedApi = async () => {
 };
 
 const main = async () => {
-  const goStartSignedApi = await go(startSignedApi);
-  if (!goStartSignedApi.success) {
-    logger.error('Could not start Signed API. Unexpected error occurred.', goStartSignedApi.error);
-  }
+  setupUncaughtErrorHandler();
+
+  await startSignedApi();
 };
 
 void main();

packages/signed-api/src/server.ts

@@ -65,11 +65,14 @@ export const startServer = (config: Config, port: number) => {
   // NOTE: The error handling middleware only catches synchronous errors. Request handlers logic should be wrapped in
   // try-catch and manually passed to next() in case of errors.
   app.use((err: any, _req: express.Request, res: express.Response, _next: express.NextFunction) => {
-    logger.error('An unexpected error occurred.', { err });
+    // For unhandled errors it's very beneficial to have the stack trace. It is possible that the value is not an error.
+    // It would be nice to know the stack trace in such cases as well.
+    const stack = err.stack ?? new Error('Unexpected non-error value encountered').stack;
+    logger.error('An unexpected handler error occurred.', { err, stack });
 
     res.status(err.status || 500).json({
       error: {
-        message: err.message || 'An unexpected error occurred.',
+        message: err.message || 'An unexpected handler error occurred.',
       },
     });
   });