add log enhancers (#193)

README.md

@@ -1,6 +1,6 @@
 # logger component
 
-Simple stdout & stderr logger component. Prints JSON when `NODE_ENV=production`
+Simple stdout & stderr logger component.
 
 ## Config
 
@@ -13,13 +13,58 @@ Using the LOG_LEVEL value provided by the IConfigComponent, the following scale
 Eg:
 
 ```typescript
-const config: IConfigComponent =
-  createConfigComponent({ ...process.env, LOG_LEVEL: "INFO" })
+const config: IConfigComponent = createConfigComponent({ ...process.env, LOG_LEVEL: 'INFO' })
 
 const loggerComponent = createLogComponent({ config })
-const logger = getLogger("Test")
+const logger = getLogger('Test')
 
-logger.info("log some info") // This will be logged
-logger.warn("log some warn") // This will be logged
-logger.debug("log some debug") // This will NOT be logged
+logger.info('log some info') // This will be logged
+logger.warn('log some warn') // This will be logged
+logger.debug('log some debug') // This will NOT be logged
+```
+
+## Logger enhancers can be configured
+
+```ts
+// Datadog enhancer
+const tracer = require('dd-trace')
+const formats = require('dd-trace/ext/formats')
+
+// enhances the "extra" field of each log to add new data. in this case
+// dd.trace_id and dd.span_id will be added
+function enhancer(extra) {
+  var enhancedObject = extra || {}
+  const time = new Date().toISOString()
+
+  const span = tracer.scope().active()
+  if (span) {
+    tracer.inject(span.context(), formats.LOG, enhancedObject)
+  }
+  return enhancedObject
+}
+
+// in initComponents(), pass the enhancer
+const logs = createJsonLogComponent({}, enhancer)
+```
+
+## The loggers generate metrics, use them like this:
+
+```ts
+// metrics.ts
+import { validateMetricsDeclaration } from '@well-known-components/metrics'
+import { metricDeclarations as logsMetricsDeclarations } from '@well-known-components/logger'
+
+export const metricDeclarations = {
+  // ...otherMetrics,
+  ...logsMetricsDeclarations
+}
+
+// type assertions
+validateMetricsDeclaration(metricDeclarations)
+```
+
+```ts
+// in initComponents(), pass the metrics component to the component
+
+const logs = createJsonLogComponent({ metrics })
 ```

etc/logger.api.md

@@ -10,15 +10,19 @@ import { IMetricsComponent } from '@well-known-components/interfaces';
 import { ITracerComponent } from '@well-known-components/interfaces';
 
 // Warning: (ae-forgotten-export) The symbol "LoggerComponents" needs to be exported by the entry point index.d.ts
+// Warning: (ae-forgotten-export) The symbol "EnricherFunction" needs to be exported by the entry point index.d.ts
 //
 // @public
-export function createConsoleLogComponent(components: LoggerComponents): Promise<ILoggerComponent>;
+export function createConsoleLogComponent(components: LoggerComponents, enricher?: EnricherFunction): Promise<ILoggerComponent>;
 
 // @public
-export function createJsonLogComponent(components: LoggerComponents): Promise<ILoggerComponent>;
+export function createJsonLogComponent(components: LoggerComponents, enricher?: EnricherFunction): Promise<ILoggerComponent>;
 
 // @public
-export function createLogComponent(components: LoggerComponents): Promise<ILoggerComponent>;
+export function createLogComponent(components: LoggerComponents, enricher?: EnricherFunction): Promise<ILoggerComponent>;
+
+// @public
+export function createLogfmtLogComponent(components: LoggerComponents, enricher?: EnricherFunction): Promise<ILoggerComponent>;
 
 // @public
 export const metricDeclarations: IMetricsComponent.MetricsRecordDefinition<"wkc_logger_logs_total">;

package.json

@@ -35,5 +35,6 @@
   },
   "files": [
     "dist"
-  ]
+  ],
+  "dependencies": {}
 }

src/helpers.ts

@@ -2,9 +2,9 @@ import {
   ILoggerComponent,
   IMetricsComponent,
   IConfigComponent,
-  ITracerComponent,
-} from "@well-known-components/interfaces"
-import { metricDeclarations } from "./metrics"
+  ITracerComponent
+} from '@well-known-components/interfaces'
+import { metricDeclarations } from './metrics'
 
 /**
  * @public
@@ -36,19 +36,31 @@ export type ILoggerConfigComponent = {
 /**
  * @public
  */
-export type LogLevel = "ALL" | "LOG" | "DEBUG" | "INFO" | "WARN" | "ERROR" | "OFF"
+export type LogLevel = 'ALL' | 'LOG' | 'DEBUG' | 'INFO' | 'WARN' | 'ERROR' | 'OFF'
+
+/**
+ * This function may be provided to enrich the "extra" properties of a log.
+ * The funcitonality is useful for scenarios in which the structured log requires
+ * some special fields for traceability reasons.
+ *
+ * The enricher function must return a new "extra" object.
+ *
+ * @public
+ */
+export type EnricherFunction = (extra: any) => any
 
 /**
  * Creates a scoped logger component using a LogLineFunction function.
  * @public
  */
 export async function createGenericLogComponent(
   components: LoggerComponents,
-  print: LogLineFunction
+  print: LogLineFunction,
+  enricher?: EnricherFunction
 ): Promise<ILoggerComponent> {
   const levelsEnum = { ALL: 0, LOG: 1, DEBUG: 2, INFO: 4, WARN: 8, ERROR: 16, OFF: 1 | 2 | 4 | 8 | 16 }
 
-  let minLogLevel: LogLevel = "ALL"
+  let minLogLevel: LogLevel = 'ALL'
   let numericMinLevel = levelsEnum[minLogLevel] || 0
 
   function setLogLevel(level: LogLevel) {
@@ -58,16 +70,18 @@ export async function createGenericLogComponent(
     }
   }
 
+  const enrichExtra = enricher ?? ((a) => a)
+
   // set ALL log level by default
-  setLogLevel("ALL")
+  setLogLevel('ALL')
 
   if (components.config) {
     try {
       // if a config component is provided, we try to get the LOG_LEVEL config
-      const newLevel = await components.config.getString("LOG_LEVEL")
+      const newLevel = await components.config.getString('LOG_LEVEL')
       if (newLevel) setLogLevel(newLevel as LogLevel)
     } catch (error: any) {
-      print(components, "ERROR", "LOG_LEVEL", error.toString(), error)
+      print(components, 'ERROR', 'LOG_LEVEL', error.toString(), error)
     }
   }
 
@@ -81,51 +95,51 @@ export async function createGenericLogComponent(
     getLogger(loggerName: string) {
       return {
         log(message: string, extra?: Record<string, string | number>) {
-          if (shouldPrint("LOG")) {
-            print(components, "LOG", loggerName, message, extra)
+          if (shouldPrint('LOG')) {
+            print(components, 'LOG', loggerName, message, enrichExtra(extra))
           }
         },
         warn(message: string, extra?: Record<string, string | number>) {
-          if (shouldPrint("WARN")) {
-            print(components, "WARNING", loggerName, message, extra)
+          if (shouldPrint('WARN')) {
+            print(components, 'WARNING', loggerName, message, enrichExtra(extra))
           }
         },
         info(message: string, extra?: Record<string, string | number>) {
-          if (shouldPrint("INFO")) {
-            print(components, "INFO", loggerName, message, extra)
+          if (shouldPrint('INFO')) {
+            print(components, 'INFO', loggerName, message, enrichExtra(extra))
           }
         },
         debug(message: string, extra?: Record<string, string | number>) {
-          if (shouldPrint("DEBUG")) {
-            print(components, "DEBUG", loggerName, message, extra)
+          if (shouldPrint('DEBUG')) {
+            print(components, 'DEBUG', loggerName, message, enrichExtra(extra))
           }
         },
         error(error: string | Error, extra?: Record<string, string | number>) {
-          if (shouldPrint("ERROR")) {
+          if (shouldPrint('ERROR')) {
             let message = `${error}`
             let printTrace = true
 
-            if (error instanceof Error && "stack" in error && typeof error.stack == "string") {
+            if (error instanceof Error && 'stack' in error && typeof error.stack == 'string') {
               if (error.stack!.includes(error.message)) {
                 message = error.stack
                 printTrace = false
               }
             }
 
-            print(components, "ERROR", loggerName, message, extra || error)
+            print(components, 'ERROR', loggerName, message, enrichExtra(extra) || error)
             if (printTrace) {
               console.trace()
             }
           }
-        },
+        }
       }
-    },
+    }
   }
 }
 
 // @internal
 export function incrementMetric(components: LoggerComponents, loggerName: string, level: string) {
   if (components.metrics) {
-    components.metrics.increment("wkc_logger_logs_total", { logger: loggerName, level })
+    components.metrics.increment('wkc_logger_logs_total', { logger: loggerName, level })
   }
 }

src/index.ts

@@ -1,8 +1,9 @@
-import { ILoggerComponent } from "@well-known-components/interfaces"
-import { printCloudwatch } from "./cloudwatch-printer"
-import { printConsole } from "./console-printer"
-import { createGenericLogComponent, LoggerComponents } from "./helpers"
-import { metricDeclarations } from "./metrics"
+import { ILoggerComponent } from '@well-known-components/interfaces'
+import { printJson } from './json-printer'
+import { printConsole } from './console-printer'
+import { createGenericLogComponent, EnricherFunction, LoggerComponents } from './helpers'
+import { metricDeclarations } from './metrics'
+import { printLogfmt } from './logfmt-printer'
 
 export { metricDeclarations }
 
@@ -11,23 +12,45 @@ export { metricDeclarations }
  * and json logger for NODE_ENV=production
  * @public
  */
-export async function createLogComponent(components: LoggerComponents): Promise<ILoggerComponent> {
-  return createConsoleLogComponent(components)
+export async function createLogComponent(
+  components: LoggerComponents,
+  enricher?: EnricherFunction
+): Promise<ILoggerComponent> {
+  return createConsoleLogComponent(components, enricher)
 }
 
 /**
  * Creates a scoped logger component to print a readable output to the stderr
+ *
  * @public
  */
-export async function createConsoleLogComponent(components: LoggerComponents): Promise<ILoggerComponent> {
-  return createGenericLogComponent(components, printConsole)
+export async function createConsoleLogComponent(
+  components: LoggerComponents,
+  enricher?: EnricherFunction
+): Promise<ILoggerComponent> {
+  return createGenericLogComponent(components, printConsole, enricher)
 }
 
 /**
  * Creates a scoped logger component to print JSON to the stderr.
  * Useful for cloudwatch and other logging services.
  * @public
  */
-export async function createJsonLogComponent(components: LoggerComponents): Promise<ILoggerComponent> {
-  return createGenericLogComponent(components, printCloudwatch)
+export async function createJsonLogComponent(
+  components: LoggerComponents,
+  enricher?: EnricherFunction
+): Promise<ILoggerComponent> {
+  return createGenericLogComponent(components, printJson, enricher)
+}
+
+/**
+ * Creates a scoped logger component to print logfmt to the stderr.
+ * Useful for cloudwatch and other logging services.
+ * @public
+ */
+export async function createLogfmtLogComponent(
+  components: LoggerComponents,
+  enricher?: EnricherFunction
+): Promise<ILoggerComponent> {
+  return createGenericLogComponent(components, printLogfmt, enricher)
 }

src/cloudwatch-printer.ts → src/json-printer.ts

@@ -1,9 +1,9 @@
-import { incrementMetric, LoggerComponents, LogLineFunction } from "./helpers"
+import { incrementMetric, LoggerComponents, LogLineFunction } from './helpers'
 
 /**
  * @internal
  */
-export const printCloudwatch: LogLineFunction = (
+export const printJson: LogLineFunction = (
   components: LoggerComponents,
   kind: string,
   loggerName: string,
@@ -14,15 +14,15 @@ export const printCloudwatch: LogLineFunction = (
 
   const logline = {
     timestamp: new Date().toISOString(),
-    kind,
-    system: loggerName,
+    level: kind,
+    logger: loggerName,
     message,
-    extra,
-    traceId: trace?.traceId,
-    parentId: trace?.parentId,
+    traceId: trace?.traceId || undefined,
+    parentId: trace?.parentId || undefined,
+    ...extra
   }
 
   incrementMetric(components, loggerName, kind)
 
-  return process.stderr.write(JSON.stringify(logline) + "\n")
+  return process.stderr.write(JSON.stringify(logline) + '\n')
 }

src/logfmt-printer.ts

@@ -0,0 +1,54 @@
+import { incrementMetric, LoggerComponents, LogLineFunction } from './helpers'
+
+/**
+ * https://brandur.org/logfmt
+ * @internal
+ */
+export const printLogfmt: LogLineFunction = (
+  components: LoggerComponents,
+  kind: string,
+  loggerName: string,
+  message: string,
+  extra: any
+) => {
+  incrementMetric(components, loggerName, kind)
+
+  const structuredLog = {
+    date: new Date().toISOString(),
+    level: kind,
+    logger: loggerName,
+    msg: message,
+    ...extra
+  }
+
+  return process.stderr.write(logfmt(structuredLog))
+}
+
+function logfmt(data: Record<string, any>) {
+  var line = ''
+
+  for (var key in data) {
+    var value = data[key]
+    var is_null = false
+    if (value == null) {
+      is_null = true
+      value = ''
+    } else if (typeof value == 'object') {
+      value = JSON.stringify(value)
+    } else {
+      value = value.toString()
+
+      var needs_quoting = value.indexOf(' ') > -1 || value.indexOf('=') > -1
+      var needs_escaping = value.indexOf('"') > -1 || value.indexOf('\\') > -1
+
+      if (needs_escaping) value = value.replace(/["\\]/g, '\\$&')
+      if (needs_quoting || needs_escaping) value = '"' + value + '"'
+      if (value === '' && !is_null) value = '""'
+    }
+
+    line += key + '=' + value + ' '
+  }
+
+  //trim traling space
+  return line.substring(0, line.length - 1)
+}