fix(logger): prevent overwriting standard keys (#3553)

Author: dreamorosi

docs/core/logger.md

@@ -52,6 +52,9 @@ These settings will be used across all logs emitted:
 | **Logging level** | Sets how verbose Logger should be, from the most verbose to the least verbose (no logs)                          | `POWERTOOLS_LOG_LEVEL`          | `INFO`              | `DEBUG`, `INFO`, `WARN`, `ERROR`, `CRITICAL`, `SILENT` | `ERROR`             | `logLevel`            |
 | **Sample rate**   | Probability that a Lambda invocation will print all the log items regardless of the log level setting            | `POWERTOOLS_LOGGER_SAMPLE_RATE` | `0`                 | `0.0` to `1.0`                                         | `0.1`               | `sampleRateValue`     |
 
+???+ info
+    When `POWERTOOLS_DEV` environment variable is present and set to `"true"` or `"1"`, Logger will pretty-print log messages for easier readability. We recommend to use this setting only when debugging on local environments.
+
 See all environment variables in the [Environment variables](../index.md/#environment-variables) section.
 Check API docs to learn more about [Logger constructor options](https://docs.powertools.aws.dev/lambda/typescript/latest/api/types/_aws_lambda_powertools_logger.types.ConstructorOptions.html){target="_blank"}.
 
@@ -91,8 +94,8 @@ Your Logger will include the following keys to your structured logging (default
 | **xray_trace_id**: `string` | `1-5759e988-bd862e3fe1be46a994272793`                                                                            | X-Ray Trace ID. This value is always presented in Lambda environment, whether [tracing is enabled](https://docs.aws.amazon.com/lambda/latest/dg/services-xray.html){target="_blank"} or not. Logger will always log this value. |
 | **error**: `Object`         | `{ name: "Error", location: "/my-project/handler.ts:18", message: "Unexpected error #1", stack: "[stacktrace]"}` | Optional - An object containing information about the Error passed to the logger                                                                                                                                                |
 
-???+ info
-    When `POWERTOOLS_DEV` environment variable is present and set to `"true"` or `"1"`, Logger will pretty-print log messages for easier readability. We recommend to use this setting only when debugging on local environments.
+???+ note
+    If you emit a log message with a key that matches one of `level`, `message`, `sampling_rate`, `service`, or `timestamp`, the Logger will log a warning message and ignore the key.
 
 ### Capturing Lambda context info
 
@@ -211,6 +214,8 @@ You can append additional keys using either mechanism:
 * Append **temporary keys** to all future log messages via the `appendKeys()` method until `resetKeys()` is called
 * Set **Persistent keys** for the logger instance via the `persistentKeys` constructor option or the `appendPersistentKeys()` method
 
+To prevent you from accidentally overwriting some of the [standard keys](#standard-structured-keys), we will log a warning message and ignore the key if you try to overwrite them.
+
 #### Extra keys
 
 You can append additional data to a single log item by passing objects as additional parameters.

packages/logger/src/Logger.ts

@@ -9,7 +9,7 @@ import type {
 import type { Context, Handler } from 'aws-lambda';
 import merge from 'lodash.merge';
 import { EnvironmentVariablesService } from './config/EnvironmentVariablesService.js';
-import { LogJsonIndent, LogLevelThreshold } from './constants.js';
+import { LogJsonIndent, LogLevelThreshold, ReservedKeys } from './constants.js';
 import type { LogFormatter } from './formatter/LogFormatter.js';
 import type { LogItem } from './formatter/LogItem.js';
 import { PowertoolsLogFormatter } from './formatter/PowertoolsLogFormatter.js';
@@ -25,7 +25,11 @@ import type {
   LogLevel,
   LoggerInterface,
 } from './types/Logger.js';
-import type { PowertoolsLogData } from './types/logKeys.js';
+import type {
+  LogKeys,
+  PowertoolsLogData,
+  UnformattedAttributes,
+} from './types/logKeys.js';
 
 /**
  * The Logger utility provides an opinionated logger with output structured as JSON for AWS Lambda.
@@ -131,7 +135,7 @@ class Logger extends Utility implements LoggerInterface {
   /**
    * Temporary log attributes that can be appended with `appendKeys()` method.
    */
-  private temporaryLogAttributes: LogAttributes = {};
+  private temporaryLogAttributes: LogKeys = {};
   /**
    * Buffer used to store logs until the logger is initialized.
    *
@@ -205,38 +209,34 @@ class Logger extends Utility implements LoggerInterface {
   }
 
   /**
-   * Add the given persistent attributes (key-value pairs) to all log items generated by this Logger instance.
-   *
-   * @deprecated This method is deprecated and will be removed in the future major versions, please use {@link appendPersistentKeys()} instead.
-   *
-   * @param attributes - The attributes to add to all log items.
+   * @deprecated This method is deprecated and will be removed in the future major versions, please use {@link appendPersistentKeys() `appendPersistentKeys()`} instead.
    */
-  public addPersistentLogAttributes(attributes: LogAttributes): void {
+  public addPersistentLogAttributes(attributes: LogKeys): void {
     this.appendPersistentKeys(attributes);
   }
 
   /**
    * Add the given temporary attributes (key-value pairs) to all log items generated by this Logger instance.
    *
+   * If the key already exists in the attributes, it will be overwritten. If the key is one of `level`, `message`, `sampling_rate`,
+   * `service`, or `timestamp` we will log a warning and drop the value.
+   *
    * @param attributes - The attributes to add to all log items.
    */
-  public appendKeys(attributes: LogAttributes): void {
-    for (const attributeKey of Object.keys(attributes)) {
-      this.#keys.set(attributeKey, 'temp');
-    }
-    merge(this.temporaryLogAttributes, attributes);
+  public appendKeys(attributes: LogKeys): void {
+    this.#appendKeys(attributes, 'temp');
   }
 
   /**
    * Add the given persistent attributes (key-value pairs) to all log items generated by this Logger instance.
    *
+   * If the key already exists in the attributes, it will be overwritten. If the key is one of `level`, `message`, `sampling_rate`,
+   * `service`, or `timestamp` we will log a warning and drop the value.
+   *
    * @param attributes - The attributes to add to all log items.
    */
-  public appendPersistentKeys(attributes: LogAttributes): void {
-    for (const attributeKey of Object.keys(attributes)) {
-      this.#keys.set(attributeKey, 'persistent');
-    }
-    merge(this.persistentLogAttributes, attributes);
+  public appendPersistentKeys(attributes: LogKeys): void {
+    this.#appendKeys(attributes, 'persistent');
   }
 
   /**
@@ -514,15 +514,13 @@ class Logger extends Utility implements LoggerInterface {
 
   /**
    * @deprecated This method is deprecated and will be removed in the future major versions. Use {@link removePersistentKeys()} instead.
-   *
-   * @param keys - The keys to remove.
    */
   public removePersistentLogAttributes(keys: string[]): void {
     this.removePersistentKeys(keys);
   }
 
   /**
-   * Remove all temporary log attributes added with `appendKeys()` method.
+   * Remove all temporary log attributes added with {@link appendKeys() `appendKeys()`} method.
    */
   public resetKeys(): void {
     for (const key of Object.keys(this.temporaryLogAttributes)) {
@@ -553,14 +551,9 @@ class Logger extends Utility implements LoggerInterface {
   }
 
   /**
-   * Set the given attributes (key-value pairs) to all log items generated by this Logger instance.
-   * Note: this replaces the pre-existing value.
-   *
-   * @deprecated This method is deprecated and will be removed in the future major versions, please use {@link appendPersistentKeys()} instead.
-   *
-   * @param attributes - The attributes to set.
+   * @deprecated This method is deprecated and will be removed in the future major versions, please use {@link appendPersistentKeys() `appendPersistentKeys()`} instead.
    */
-  public setPersistentLogAttributes(attributes: LogAttributes): void {
+  public setPersistentLogAttributes(attributes: LogKeys): void {
     this.persistentLogAttributes = attributes;
   }
 
@@ -666,6 +659,25 @@ class Logger extends Utility implements LoggerInterface {
     merge(this.powertoolsLogData, attributes);
   }
 
+  /**
+   * Shared logic for adding keys to the logger instance.
+   *
+   * @param attributes - The attributes to add to the log item.
+   * @param type - The type of the attributes to add.
+   */
+  #appendKeys(attributes: LogKeys, type: 'temp' | 'persistent'): void {
+    for (const attributeKey of Object.keys(attributes)) {
+      if (this.#checkReservedKeyAndWarn(attributeKey) === false) {
+        this.#keys.set(attributeKey, type);
+      }
+    }
+    if (type === 'temp') {
+      merge(this.temporaryLogAttributes, attributes);
+    } else {
+      merge(this.persistentLogAttributes, attributes);
+    }
+  }
+
   private awsLogLevelShortCircuit(selectedLogLevel?: string): boolean {
     const awsLogLevel = this.getEnvVarsService().getAwsLogLevel();
     if (this.isValidLogLevel(awsLogLevel)) {
@@ -688,70 +700,118 @@ class Logger extends Utility implements LoggerInterface {
 
   /**
    * Create a log item and populate it with the given log level, input, and extra input.
-   *
-   * We start with creating an object with base attributes managed by Powertools.
-   * Then we create a second object with persistent attributes provided by customers either
-   * directly to the log entry or through initial configuration and `appendKeys` method.
-   *
-   * Once we have the two objects, we pass them to the formatter that will apply the desired
-   * formatting to the log item.
-   *
-   * @param logLevel - The log level of the log item to be printed
-   * @param input - The main input of the log item, this can be a string or an object with additional attributes
-   * @param extraInput - Additional attributes to be added to the log item
    */
   protected createAndPopulateLogItem(
     logLevel: number,
     input: LogItemMessage,
     extraInput: LogItemExtraInput
   ): LogItem {
-    let message = '';
-    let otherInput: { [key: string]: unknown } = {};
-    if (typeof input === 'string') {
-      message = input;
-    } else {
-      const { message: inputMessage, ...rest } = input;
-      message = inputMessage;
-      otherInput = rest;
-    }
-
-    // create base attributes
     const unformattedBaseAttributes = {
       logLevel: this.getLogLevelNameFromNumber(logLevel),
       timestamp: new Date(),
-      message,
       xRayTraceId: this.envVarsService.getXrayTraceId(),
       ...this.getPowertoolsLogData(),
+      message: '',
     };
+    const additionalAttributes = this.#createAdditionalAttributes();
+
+    this.#processMainInput(
+      input,
+      unformattedBaseAttributes,
+      additionalAttributes
+    );
+    this.#processExtraInput(extraInput, additionalAttributes);
+
+    return this.getLogFormatter().formatAttributes(
+      unformattedBaseAttributes,
+      additionalAttributes
+    );
+  }
+
+  /**
+   * Create additional attributes from persistent and temporary keys
+   */
+  #createAdditionalAttributes(): LogAttributes {
+    const attributes: LogAttributes = {};
 
-    const additionalAttributes: LogAttributes = {};
-    // gradually add additional attributes picking only the last added for each key
     for (const [key, type] of this.#keys) {
-      if (type === 'persistent') {
-        additionalAttributes[key] = this.persistentLogAttributes[key];
-      } else {
-        additionalAttributes[key] = this.temporaryLogAttributes[key];
+      if (!this.#checkReservedKeyAndWarn(key)) {
+        attributes[key] =
+          type === 'persistent'
+            ? this.persistentLogAttributes[key]
+            : this.temporaryLogAttributes[key];
       }
     }
 
-    // if the main input is not a string, then it's an object with additional attributes, so we merge it
-    merge(additionalAttributes, otherInput);
-    // then we merge the extra input attributes (if any)
+    return attributes;
+  }
+
+  /**
+   * Process the main input message and add it to the attributes
+   */
+  #processMainInput(
+    input: LogItemMessage,
+    baseAttributes: UnformattedAttributes,
+    additionalAttributes: LogAttributes
+  ): void {
+    if (typeof input === 'string') {
+      baseAttributes.message = input;
+      return;
+    }
+
+    const { message, ...rest } = input;
+    baseAttributes.message = message;
+
+    for (const [key, value] of Object.entries(rest)) {
+      if (!this.#checkReservedKeyAndWarn(key)) {
+        additionalAttributes[key] = value;
+      }
+    }
+  }
+
+  /**
+   * Process extra input items and add them to additional attributes
+   */
+  #processExtraInput(
+    extraInput: LogItemExtraInput,
+    additionalAttributes: LogAttributes
+  ): void {
     for (const item of extraInput) {
-      const attributes: LogAttributes =
-        item instanceof Error
-          ? { error: item }
-          : typeof item === 'string'
-            ? { extra: item }
-            : item;
-
-      merge(additionalAttributes, attributes);
+      if (item instanceof Error) {
+        additionalAttributes.error = item;
+      } else if (typeof item === 'string') {
+        additionalAttributes.extra = item;
+      } else {
+        this.#processExtraObject(item, additionalAttributes);
+      }
     }
+  }
 
-    return this.getLogFormatter().formatAttributes(
-      unformattedBaseAttributes,
-      additionalAttributes
-    );
+  /**
+   * Process an extra input object and add its properties to additional attributes
+   */
+  #processExtraObject(
+    item: Record<string, unknown>,
+    additionalAttributes: LogAttributes
+  ): void {
+    for (const [key, value] of Object.entries(item)) {
+      if (!this.#checkReservedKeyAndWarn(key)) {
+        additionalAttributes[key] = value;
+      }
+    }
+  }
+
+  /**
+   * Check if a given key is reserved and warn the user if it is.
+   *
+   * @param key - The key to check
+   */
+  #checkReservedKeyAndWarn(key: string): boolean {
+    if (ReservedKeys.includes(key)) {
+      this.warn(`The key "${key}" is a reserved key and will be dropped.`);
+      return true;
+    }
+    return false;
   }
 
   /**
@@ -1090,7 +1150,7 @@ class Logger extends Utility implements LoggerInterface {
   private setPowertoolsLogData(
     serviceName?: ConstructorOptions['serviceName'],
     environment?: ConstructorOptions['environment'],
-    persistentKeys: ConstructorOptions['persistentKeys'] = {}
+    persistentKeys?: ConstructorOptions['persistentKeys']
   ): void {
     this.addToPowertoolsLogData({
       awsRegion: this.getEnvVarsService().getAwsRegion(),
@@ -1104,7 +1164,7 @@ class Logger extends Utility implements LoggerInterface {
         this.getEnvVarsService().getServiceName() ||
         this.getDefaultServiceName(),
     });
-    this.appendPersistentKeys(persistentKeys);
+    persistentKeys && this.appendPersistentKeys(persistentKeys);
   }
 }
 

packages/logger/src/constants.ts

@@ -37,4 +37,17 @@ const LogLevelThreshold = {
   SILENT: 28,
 } as const;
 
-export { LogJsonIndent, LogLevel, LogLevelThreshold };
+/**
+ * Reserved keys that are included in every log item when using the default log formatter.
+ *
+ * These keys are reserved and cannot be overwritten by custom log attributes.
+ */
+const ReservedKeys = [
+  'level',
+  'message',
+  'sampling_rate',
+  'service',
+  'timestamp',
+];
+
+export { LogJsonIndent, LogLevel, LogLevelThreshold, ReservedKeys };

packages/logger/src/formatter/LogItem.ts

@@ -23,7 +23,7 @@ class LogItem {
    * @param params - The parameters for the LogItem.
    */
   public constructor(params: { attributes: LogAttributes }) {
-    this.addAttributes(params.attributes);
+    this.setAttributes(params.attributes);
   }
 
   /**
@@ -50,7 +50,7 @@ class LogItem {
    * This operation removes empty keys from the log item, see {@link removeEmptyKeys | removeEmptyKeys()} for more information.
    */
   public prepareForPrint(): void {
-    this.setAttributes(this.removeEmptyKeys(this.getAttributes()));
+    this.attributes = this.removeEmptyKeys(this.getAttributes());
   }
 
   /**