TRAC-40-adding-debug-logs-secret-masking

.circleci/config.yml

@@ -125,7 +125,7 @@ jobs:
     environment:
       - TZ: Asia/Jerusalem
       - NODE_OPTIONS: --max_old_space_size=1500
-    resource_class: medium+
+    resource_class: large
     working_directory: ~/lumigo-node
     steps:
       - run:
@@ -150,13 +150,13 @@ jobs:
       - run:
           name: check types
           command: npm run check-types
+      - run:
+          name: eslint
+          command: npm run lint
       - run:
           name: test
           command: npm test
           no_output_timeout: 15m
-      - run:
-          name: eslint
-          command: npm run lint
 
   deploy:
     <<: *defaults

src/utils.test.js

@@ -34,6 +34,7 @@ import {
   LUMIGO_SUPPORT_LARGE_INVOCATIONS,
   removeLumigoFromError,
   removeLumigoFromStacktrace,
+  LUMIGO_SECRET_MASKING_DEBUG,
 } from './utils';
 
 describe('utils', () => {
@@ -248,6 +249,12 @@ describe('utils', () => {
     expect(utils.isDebug()).toBe(true);
   });
 
+  test('isSecretMaskingDebug -> ENV VAR', () => {
+    expect(utils.isSecretMaskingDebug()).toBe(false);
+    process.env.LUMIGO_SECRET_MASKING_DEBUG = 'TRUE';
+    expect(utils.isSecretMaskingDebug()).toBe(true);
+  });
+
   test('isLambdaWrapped', () => {
     expect(utils.isLambdaWrapped()).toBe(false);
     process.env.LUMIGO_IS_WRAPPED = 'TRUE';

src/utils.ts

@@ -33,6 +33,8 @@ export const LUMIGO_SECRET_MASKING_REGEX_HTTP_QUERY_PARAMS =
 export const LUMIGO_SECRET_MASKING_REGEX_ENVIRONMENT = 'LUMIGO_SECRET_MASKING_REGEX_ENVIRONMENT';
 export const LUMIGO_SECRET_MASKING_ALL_MAGIC = 'all';
 
+export const LUMIGO_SECRET_MASKING_DEBUG = 'LUMIGO_SECRET_MASKING_DEBUG';
+
 export const LUMIGO_SECRET_MASKING_EXACT_PATH = 'LUMIGO_SECRET_MASKING_EXACT_PATH';
 export const LUMIGO_WHITELIST_KEYS_REGEXES = 'LUMIGO_WHITELIST_KEYS_REGEXES';
 export const LUMIGO_SUPPORT_LARGE_INVOCATIONS = 'LUMIGO_SUPPORT_LARGE_INVOCATIONS';
@@ -50,6 +52,18 @@ export const OMITTING_KEYS_REGEXES = [
   'Authorization',
 ];
 
+export const BYPASS_MASKING_KEYS = [
+  LUMIGO_SECRET_MASKING_REGEX,
+  LUMIGO_SECRET_MASKING_REGEX_BACKWARD_COMP,
+  LUMIGO_SECRET_MASKING_REGEX_HTTP_REQUEST_BODIES,
+  LUMIGO_SECRET_MASKING_REGEX_HTTP_REQUEST_HEADERS,
+  LUMIGO_SECRET_MASKING_REGEX_HTTP_RESPONSE_BODIES,
+  LUMIGO_SECRET_MASKING_REGEX_HTTP_RESPONSE_HEADERS,
+  LUMIGO_SECRET_MASKING_REGEX_ENVIRONMENT,
+  LUMIGO_SECRET_MASKING_REGEX_HTTP_QUERY_PARAMS,
+  LUMIGO_SECRET_MASKING_EXACT_PATH,
+];
+
 export const LUMIGO_EVENT_KEY = '_lumigo';
 export const STEP_FUNCTION_UID_KEY = 'step_function_uid';
 export const GET_KEY_DEPTH_ENV_KEY = 'LUMIGO_KEY_DEPTH';
@@ -339,6 +353,8 @@ export const isWarm = (): boolean =>
 export const isDebug = (): boolean =>
   validateEnvVar(DEBUG_FLAG) || TracerGlobals.getTracerInputs().debug;
 
+export const isSecretMaskingDebug = (): boolean => validateEnvVar(LUMIGO_SECRET_MASKING_DEBUG);
+
 export const isLambdaWrapped = (): boolean => validateEnvVar(WRAPPED_FLAG);
 
 export const shouldPropagateW3C = (): boolean => !validateEnvVar(LUMIGO_PROPAGATE_W3C, 'FALSE');
@@ -423,6 +439,8 @@ export const setSwitchOff = () => (process.env['LUMIGO_SWITCH_OFF'] = 'TRUE');
 
 export const setDebug = () => (process.env['LUMIGO_DEBUG'] = 'TRUE');
 
+export const setSecretMaskingDebug = () => (process.env['LUMIGO_SECRET_MASKING_DEBUG'] = 'TRUE');
+
 export const unsetDebug = () => (process.env['LUMIGO_DEBUG'] = undefined);
 
 export const setTimeoutTimerDisabled = () => (process.env[TIMEOUT_ENABLE_FLAG] = 'FALSE');

src/utils/payloadStringify.js

@@ -17,6 +17,8 @@ import {
   OMITTING_KEYS_REGEXES,
   parseJsonFromEnvVar,
   safeExecute,
+  BYPASS_MASKING_KEYS,
+  isSecretMaskingDebug,
 } from '../utils';
 import { runOneTimeWrapper } from './functionUtils';
 
@@ -32,6 +34,11 @@ const keyToRegexes = (
   backwardCompRegexEnvVarName = LUMIGO_SECRET_MASKING_REGEX_BACKWARD_COMP,
   regexesEnvVarName = LUMIGO_SECRET_MASKING_REGEX
 ) => {
+  logSecretMaskingDebug(logger, 'Getting key to omit regexes', {
+    regexesList,
+    backwardCompRegexEnvVarName,
+    regexesEnvVarName,
+  });
   const fallbackRegexesList = regexesList;
 
   const tryParseEnvVar = (envVarName) => {
@@ -162,6 +169,16 @@ function innerPathScrubbing(input, secretPaths, uniquePaths, currentPath) {
   return input;
 }
 
+function logSecretMaskingDebug(logger, message, additionalData) {
+  if (isSecretMaskingDebug()) {
+    if (additionalData) {
+      logger.debug(message, additionalData);
+    } else {
+      logger.debug(message);
+    }
+  }
+}
+
 export const payloadStringify = (
   payload,
   maxPayloadSize = getEventEntitySize(),
@@ -258,16 +275,25 @@ const invalidMaskingRegexWarning = runOneTimeWrapper((e) => {
 });
 
 const shallowMaskByRegex = (payload, regexes) => {
+  logSecretMaskingDebug(logger, 'Shallow masking payload by regexes', {
+    payloadKeys: Object.keys(payload),
+    regexes,
+  });
   regexes = regexes || keyToOmitRegexes();
   if (isString(payload)) {
+    logSecretMaskingDebug(logger, 'Shallow masking string payload');
     return payload;
   }
   if (typeof payload !== 'object') {
     logger.warn('Failed to mask payload, payload is not an object or string', payload);
     return payload;
   }
   return Object.keys(payload).reduce((acc, key) => {
-    if (keyContainsRegex(regexes, key)) {
+    if (BYPASS_MASKING_KEYS.includes(key)) {
+      logSecretMaskingDebug(logger, 'Skipping masking of a Lumigo env-var', key);
+      acc[key] = payload[key];
+    } else if (keyContainsRegex(regexes, key)) {
+      logSecretMaskingDebug(logger, 'Shallow masking key', key);
       acc[key] = SCRUBBED_TEXT;
     } else {
       acc[key] = payload[key];
@@ -277,6 +303,10 @@ const shallowMaskByRegex = (payload, regexes) => {
 };
 
 export const shallowMask = (context, payload) => {
+  logSecretMaskingDebug(logger, 'Shallow masking payload', {
+    context,
+    payloadKeys: Object.keys(payload),
+  });
   let givenSecretRegexes = null;
   if (context === 'environment') {
     givenSecretRegexes = getEnvVarsMaskingRegex();
@@ -295,10 +325,15 @@ export const shallowMask = (context, payload) => {
   }
 
   if (givenSecretRegexes === LUMIGO_SECRET_MASKING_ALL_MAGIC) {
+    logSecretMaskingDebug(logger, 'Shallow masking payload with LUMIGO_SECRET_MASKING_ALL_MAGIC');
     return SCRUBBED_TEXT;
   } else if (givenSecretRegexes) {
+    logSecretMaskingDebug(logger, 'Shallow masking payload with given regexes', {
+      givenSecretRegexes,
+    });
     try {
       givenSecretRegexes = JSON.parse(givenSecretRegexes);
+      logSecretMaskingDebug(logger, 'Parsed given regexes', { givenSecretRegexes });
       givenSecretRegexes = givenSecretRegexes.map((x) => new RegExp(x, 'i'));
     } catch (e) {
       invalidMaskingRegexWarning(e);

src/utils/payloadStringify.test.js

@@ -3,6 +3,7 @@ import {
   LUMIGO_SECRET_MASKING_ALL_MAGIC,
   LUMIGO_SECRET_MASKING_EXACT_PATH,
   LUMIGO_SECRET_MASKING_REGEX,
+  OMITTING_KEYS_REGEXES,
   LUMIGO_SECRET_MASKING_REGEX_BACKWARD_COMP,
   LUMIGO_SECRET_MASKING_REGEX_HTTP_REQUEST_BODIES,
   LUMIGO_WHITELIST_KEYS_REGEXES,
@@ -298,6 +299,23 @@ describe('payloadStringify', () => {
     expect(shallowMask('requestBody', { a: 'b', aXy: 'bla' })).toEqual({ a: 'b', aXy: '****' });
   });
 
+  test('shallowMask -> requestBody -> regex -> bypass', () => {
+    const regex = '[".*X.*"]';
+    process.env[LUMIGO_SECRET_MASKING_REGEX] = regex;
+
+    expect(
+      shallowMask('environment', {
+        LUMIGO_SECRET_MASKING_REGEX: regex,
+        a: 'b',
+        aXy: 'some secret',
+      })
+    ).toEqual({
+      LUMIGO_SECRET_MASKING_REGEX: regex,
+      a: 'b',
+      aXy: '****',
+    });
+  });
+
   test('shallowMask -> requestBody -> fallback', () => {
     expect(shallowMask('requestBody', { a: 'b', password: 'bla' })).toEqual({
       a: 'b',
@@ -313,7 +331,13 @@ describe('payloadStringify', () => {
     utils.setDebug();
     TracerGlobals.setTracerInputs({});
     expect(shallowMask('requestBody', 1)).toEqual(1);
-    expect(ConsoleWritesForTesting.getLogs()).toEqual([
+
+    // Filter logs to only include WARNING logs
+    const warningLogs = ConsoleWritesForTesting.getLogs().filter((log) =>
+      log.msg.includes('WARNING')
+    );
+
+    expect(warningLogs).toEqual([
       {
         msg: '#LUMIGO# - WARNING - "Failed to mask payload, payload is not an object or string"',
         obj: '1',
@@ -325,11 +349,16 @@ describe('payloadStringify', () => {
     utils.setDebug();
     TracerGlobals.setTracerInputs({});
     expect(shallowMask('other', { a: 'b', password: 1234 })).toEqual({ a: 'b', password: '****' });
-    expect(ConsoleWritesForTesting.getLogs()).toEqual([
-      {
+
+    // Filter logs to only include WARNING logs
+    const warningLogs = ConsoleWritesForTesting.getLogs().filter((log) =>
+      log.msg.includes('WARNING')
+    );
+
+    expect(warningLogs).toEqual([
+      expect.objectContaining({
         msg: '#LUMIGO# - WARNING - "Unknown context for shallowMask"',
-        obj: '"other"',
-      },
+      }),
     ]);
   });
 
@@ -338,7 +367,12 @@ describe('payloadStringify', () => {
     process.env[LUMIGO_SECRET_MASKING_REGEX] = '["a(a"]';
     expect(shallowMask('requestBody', { a: 'b', aa: 'bla' })).toEqual({ a: 'b', aa: 'bla' });
 
-    expect(ConsoleWritesForTesting.getLogs()).toEqual([
+    // Filter logs to only include WARNING logs
+    const warningLogs = ConsoleWritesForTesting.getLogs().filter((log) =>
+      log.msg.includes('WARNING')
+    );
+
+    expect(warningLogs).toEqual([
       expect.objectContaining({
         msg: '#LUMIGO# - WARNING - "Failed to parse the given masking regex"',
       }),
@@ -348,6 +382,23 @@ describe('payloadStringify', () => {
     ]);
   });
 
+  test('shallowMask -> LUMIGO_SECRET_MASKING_DEBUG', () => {
+    utils.setDebug();
+    utils.setSecretMaskingDebug();
+
+    expect(shallowMask('requestBody', { a: 'b' })).toEqual({ a: 'b' });
+
+    const debugLogs = ConsoleWritesForTesting.getLogs().filter((log) => log.msg.includes('DEBUG'));
+
+    expect(debugLogs).toEqual(
+      expect.arrayContaining([
+        expect.objectContaining({
+          msg: '#LUMIGO# - DEBUG - "Shallow masking payload"',
+        }),
+      ])
+    );
+  });
+
   test.each`
     envVarValue                                                                | event                                                                                                                                                                                                                                                                                                                                                                                                                          | expectedResults
     ${['["object.foo"]']}                                                      | ${[{ secret: { key: 'value' } }, { object: { foo: 'value' } }]}                                                                                                                                                                                                                                                                                                                                                                | ${JSON.stringify([{ secret: '****' }, { object: { foo: '****' } }])}