Implement structured logging using pino

.env.example

@@ -117,4 +117,10 @@ SETUP_LINK_EXPIRY_DAYS=3
 # SSO_TRACES_DISABLE=true
 # SSO_TRACES_REDACT=true
 # traces ttl in hours
-# SSO_TRACES_TTL=1
+# SSO_TRACES_TTL=1
+
+# Logger options
+# Log file to write to
+LOG_FILE=
+# Log levels - "fatal" | "error" | "warn" | "info" (default) | "debug" | "trace"
+LOG_LEVEL=

e2e/support/fixtures/sso-page.ts

@@ -1,6 +1,8 @@
 import { type Page, type Locator, expect } from '@playwright/test';
 import { adminPortalSSODefaults } from '@lib/env';
 
+export const GENERIC_ERR_STRING = 'Something wrong happened. Please contact your administrator.';
+
 const ADMIN_PORTAL_TENANT = adminPortalSSODefaults.tenant;
 export const ADMIN_PORTAL_PRODUCT = adminPortalSSODefaults.product;
 
@@ -105,6 +107,8 @@ export class SSOPage {
     }
     // submit the form
     await this.saveConnection.click();
+    // check if the added connection appears in the connection list
+    await expect(this.page.getByText(ssoName)).toBeVisible();
     this.connections = [...this.connections, ssoName];
   }
 

e2e/ui/Enterprise SSO/error.spec.ts

@@ -1,5 +1,5 @@
 import { test as baseTest, expect, request } from '@playwright/test';
-import { ADMIN_PORTAL_PRODUCT, Portal, SSOPage } from 'e2e/support/fixtures';
+import { ADMIN_PORTAL_PRODUCT, GENERIC_ERR_STRING, Portal, SSOPage } from 'e2e/support/fixtures';
 
 type MyFixtures = {
   ssoPage: SSOPage;
@@ -72,10 +72,8 @@ test('OAuth2 wrapper + SAML provider + inactive connection', async ({ ssoPage, p
   // Wait for browser to redirect to error page
   await page.waitForURL((url) => url.origin === baseURL && url.pathname === '/error');
   // Assert error text
-  await expect(
-    page.getByText('SSO error: SSO connection is deactivated. Please contact your administrator.')
-  ).toBeVisible();
-  errorMessages.push('SSO connection is deactivated. Please contact your administrator.');
+  await expect(page.getByText(`SSO error: ${GENERIC_ERR_STRING}`)).toBeVisible();
+  errorMessages.push('SSO connection is deactivated.');
 });
 
 test('OAuth2 wrapper + OIDC provider + wrong redirectUrl', async ({ ssoPage, page, baseURL }, testInfo) => {
@@ -118,10 +116,8 @@ test('OAuth2 wrapper + OIDC provider + inactive connection', async ({ ssoPage, p
   // Wait for browser to redirect to error page
   await page.waitForURL((url) => url.origin === baseURL && url.pathname === '/error');
   // Assert error text
-  await expect(
-    page.getByText('SSO error: SSO connection is deactivated. Please contact your administrator.')
-  ).toBeVisible();
-  errorMessages.push('SSO connection is deactivated. Please contact your administrator.');
+  await expect(page.getByText(`SSO error: ${GENERIC_ERR_STRING}`)).toBeVisible();
+  errorMessages.push('SSO connection is deactivated.');
 });
 
 test('SSO Tracer inspect', async ({ page }) => {

e2e/ui/Identity Federation/error.spec.ts

@@ -1,5 +1,5 @@
 import { test as baseTest, expect, request } from '@playwright/test';
-import { ADMIN_PORTAL_PRODUCT, Portal, SSOPage } from 'e2e/support/fixtures';
+import { ADMIN_PORTAL_PRODUCT, GENERIC_ERR_STRING, Portal, SSOPage } from 'e2e/support/fixtures';
 import { IdentityFederationPage } from 'e2e/support/fixtures/identity-federation';
 
 type MyFixtures = {
@@ -93,7 +93,8 @@ test('SAML Federated app + Wrong ACS url', async ({ baseURL, page, portal, samlF
   // Wait for browser to redirect to error page
   await page.waitForURL((url) => url.origin === baseURL && url.pathname === '/error');
   // Assert error text
-  await expect(page.getByText("SSO error: Assertion Consumer Service URL doesn't match.")).toBeVisible();
+  await expect(page.getByText(`SSO error: ${GENERIC_ERR_STRING}`)).toBeVisible();
+
   errorMessages.push("Assertion Consumer Service URL doesn't match.");
   await portal.doCredentialsLogin();
   await portal.isLoggedIn();
@@ -130,10 +131,8 @@ test('SAML Federated app + inactive SSO connection', async ({
   // Wait for browser to redirect to error page
   await page.waitForURL((url) => url.origin === baseURL && url.pathname === '/error');
   // Assert error text
-  await expect(
-    page.getByText('SSO error: SSO connection is deactivated. Please contact your administrator.')
-  ).toBeVisible();
-  errorMessages.push('SSO connection is deactivated. Please contact your administrator.');
+  await expect(page.getByText(`SSO error: ${GENERIC_ERR_STRING}`)).toBeVisible();
+  errorMessages.push('SSO connection is deactivated.');
   await portal.doCredentialsLogin();
   await portal.isLoggedIn();
 
@@ -205,10 +204,8 @@ test('OIDC Federated app + inactive SSO connection', async ({
   // Wait for browser to redirect to error page
   await page.waitForURL((url) => url.origin === baseURL && url.pathname === '/error');
   // Assert error text
-  await expect(
-    page.getByText('SSO error: SSO connection is deactivated. Please contact your administrator.')
-  ).toBeVisible();
-  errorMessages.push('SSO connection is deactivated. Please contact your administrator.');
+  await expect(page.getByText(`SSO error: ${GENERIC_ERR_STRING}`)).toBeVisible();
+  errorMessages.push('SSO connection is deactivated.');
   await portal.doCredentialsLogin();
   await portal.isLoggedIn();
 

ee/identity-federation/api/oidc/idp-login/[fedAppId].ts

@@ -3,6 +3,7 @@ import { NextApiRequest, NextApiResponse } from 'next';
 import jackson from '@lib/jackson';
 import { OIDCIdPInitiatedReq } from '@boxyhq/saml-jackson';
 import { setErrorCookie } from '@lib/utils';
+import { logger } from '@lib/logger';
 
 export default async function handler(req: NextApiRequest, res: NextApiResponse) {
   try {
@@ -28,7 +29,7 @@ export default async function handler(req: NextApiRequest, res: NextApiResponse)
       res.redirect(302, redirect_url);
     }
   } catch (err: any) {
-    console.error('OIDC IDP initiated login error:', err);
+    logger.error(err, 'OIDC IdP initiated login error');
     const { message, statusCode = 500 } = err;
     // set error in cookie redirect to error page
     setErrorCookie(res, { message, statusCode }, { path: '/error' });

ee/identity-federation/api/sso.ts

@@ -2,6 +2,7 @@ import type { NextApiRequest, NextApiResponse } from 'next';
 
 import jackson from '@lib/jackson';
 import { setErrorCookie } from '@lib/utils';
+import { logger } from '@lib/logger';
 
 type SAMLRequest = {
   SAMLRequest: string;
@@ -28,7 +29,7 @@ export default async function handler(req: NextApiRequest, res: NextApiResponse)
         res.status(405).json({ error: { message: `Method ${method} Not Allowed` } });
     }
   } catch (err: any) {
-    console.error('authorize error:', err);
+    logger.error(err, 'SAML Federation authorize error');
     const { message, statusCode = 500 } = err;
     setErrorCookie(res, { message, statusCode }, { path: '/error' });
     res.redirect(302, '/error');

lib/env.ts

@@ -136,8 +136,14 @@ const adminPortalSSODefaults = {
   defaultRedirectUrl: `${externalUrl}/admin/auth/idp-login`,
 };
 
+const loggerOptions = {
+  file: process.env.LOG_FILE,
+  level: process.env.LOG_LEVEL,
+};
+
 export { adminPortalSSODefaults };
 export { retraced as retracedOptions };
 export { terminus as terminusOptions };
 export { apiKeys };
 export { jacksonOptions };
+export { loggerOptions };

lib/jackson.ts

@@ -3,13 +3,23 @@ import type { SAMLJackson } from '@boxyhq/saml-jackson';
 import jackson from '@boxyhq/saml-jackson';
 import { jacksonOptions } from '@lib/env';
 import '@lib/metrics';
+import { logger } from './logger';
 
 const g = global as any;
 
+const jacksonOptionsWithLogger = {
+  ...jacksonOptions,
+  logger: {
+    info: (msg: string, err?: any) => logger.info(err, msg),
+    error: (msg: string, err?: any) => logger.error(err, msg),
+    warn: (msg: string, err?: any) => logger.warn(err, msg),
+  },
+};
+
 export default async function init() {
   if (!g.jacksonInstance) {
     g.jacksonInstance = new Promise((resolve, reject) => {
-      jackson(jacksonOptions).then(resolve).catch(reject);
+      jackson(jacksonOptionsWithLogger).then(resolve).catch(reject);
     });
   }
 

lib/logger.ts

@@ -0,0 +1,51 @@
+import pino, { type Logger } from 'pino';
+import fs from 'fs';
+import { loggerOptions } from '@lib/env';
+
+const isDevelopment = process.env.NODE_ENV !== 'production';
+const g = global as any;
+
+// Custom error serializer for production that omits stack traces
+const productionErrorSerializer = ({
+  message,
+  statusCode = 500,
+  internalError,
+}: Error & { statusCode?: number; internalError?: string }) => {
+  // stack trace is intentionally omitted
+  const err: any = { message, statusCode };
+  if (internalError) {
+    err.internalError = internalError;
+  }
+  return err;
+};
+
+export function initLogger(logFile?: string, logLevel?: string): Logger {
+  if (logFile) {
+    return pino(fs.createWriteStream(logFile));
+  }
+
+  return pino({
+    level: logLevel || 'info',
+    timestamp: () => `,"time":"${new Date().toISOString()}"`,
+    transport: isDevelopment
+      ? {
+          target: 'pino-pretty',
+          options: {
+            colorize: true,
+          },
+        }
+      : undefined,
+    serializers: {
+      err: isDevelopment ? pino.stdSerializers.err : productionErrorSerializer,
+    },
+  });
+}
+
+function initLoggerFromEnv(): Logger {
+  if (!g.loggerInstance) {
+    g.loggerInstance = initLogger(loggerOptions.file, loggerOptions.level);
+  }
+  return g.loggerInstance;
+}
+
+export const logger = initLoggerFromEnv();

lib/nextAuthAdapter.ts

@@ -3,13 +3,14 @@ import DB from 'npm/src/db/db';
 import { jacksonOptions } from './env';
 import type { AdapterUser, VerificationToken } from 'next-auth/adapters';
 import defaultDb from 'npm/src/db/defaultDb';
+import { logger } from './logger';
 
 const g = global as any;
 
 export async function initNextAuthDB(): Promise<Storable> {
   if (!g.adminAuthStore) {
     const _opts = defaultDb(jacksonOptions);
-    const db = await DB.new(_opts.db);
+    const db = await DB.new({ db: _opts.db, logger });
     g.adminAuthStore = db.store('admin:auth');
   }
   return g.adminAuthStore as Storable;

npm/src/controller/analytics.ts

@@ -1,4 +1,9 @@
-import { IConnectionAPIController, IDirectorySyncController, Storable } from '../typings';
+import {
+  IConnectionAPIController,
+  IDirectorySyncController,
+  JacksonOptionWithRequiredLogger,
+  Storable,
+} from '../typings';
 import Mixpanel, { type Event } from 'mixpanel';
 import { randomUUID } from 'crypto';
 
@@ -11,13 +16,15 @@ export class AnalyticsController {
   directorySyncController: IDirectorySyncController;
   client: Mixpanel.Mixpanel;
   anonymousId: string;
+  private opts: JacksonOptionWithRequiredLogger;
 
-  constructor({ analyticsStore, connectionAPIController, directorySyncController }) {
+  constructor({ opts, analyticsStore, connectionAPIController, directorySyncController }) {
     this.analyticsStore = analyticsStore;
     this.client = Mixpanel.init('1028494897a5520b90e7344344060fa7');
     this.connectionAPIController = connectionAPIController;
     this.directorySyncController = directorySyncController;
     this.anonymousId = '';
+    this.opts = opts;
   }
 
   public async init(): Promise<void> {
@@ -80,7 +87,7 @@ export class AnalyticsController {
         this.analyticsStore.put(sentKey, new Date().toISOString());
       });
     } catch (err) {
-      console.error('Error sending analytics', err);
+      this.opts.logger.error('Error sending analytics', err);
     }
   }
 }

npm/src/controller/error.ts

@@ -3,12 +3,16 @@ import { ApiError } from '../typings';
 export class JacksonError extends Error {
   public name: string;
   public statusCode: number;
+  public internalError?: string;
 
-  constructor(message: string, statusCode = 500) {
+  constructor(message: string, statusCode = 500, internalError: string = '') {
     super(message);
 
     this.name = this.constructor.name;
     this.statusCode = statusCode;
+    if (internalError) {
+      this.internalError = internalError;
+    }
 
     Error.captureStackTrace(this, this.constructor);
   }