feat: more correlation fields: service.version, service.environment, service.node.name

These are retrieved from an active APM agent, if apmIntegration is
enabled. As well, config options for overriding these (and service.name)
have been added.

Closes: #121
Closes: #87
Refs: elastic/apm-agent-nodejs#3195

Author: trentm

docs/winston.asciidoc

@@ -30,7 +30,7 @@ const winston = require('winston')
 const ecsFormat = require('@elastic/ecs-winston-format')
 
 const logger = winston.createLogger({
-  format: ecsFormat(), <1>
+  format: ecsFormat(/* options */), <1>
   transports: [
     new winston.transports.Console()
   ]
@@ -63,7 +63,7 @@ const ecsFormat = require('@elastic/ecs-winston-format')
 
 const logger = winston.createLogger({
   level: 'info',
-  format: ecsFormat(), <1>
+  format: ecsFormat(/* options */), <1>
   transports: [
     new winston.transports.Console()
   ]
@@ -72,6 +72,7 @@ const logger = winston.createLogger({
 logger.info('hi')
 logger.error('oops there is a problem', { foo: 'bar' })
 ----
+<1> See available options <<winston-ref,below>>.
 
 Running this script (available https://github.com/elastic/ecs-logging-nodejs/blob/main/loggers/winston/examples/basic.js[here]) will produce log output similar to the following:
 
@@ -226,14 +227,21 @@ For https://github.com/elastic/ecs-logging-nodejs/blob/main/loggers/winston/exam
 
 [float]
 [[winston-apm]]
-=== Integration with APM Tracing
+=== Log Correlation with APM
 
 This ECS log formatter integrates with https://www.elastic.co/apm[Elastic APM].
 If your Node app is using the {apm-node-ref}/intro.html[Node.js Elastic APM Agent],
-then fields are added to log records that {ecs-ref}/ecs-tracing.html[identify an active trace] and the configured service name
-({ecs-ref}/ecs-service.html["service.name"] and {ecs-ref}/ecs-event.html["event.dataset"]).
-These fields allow cross linking between traces and logs in Kibana and support
-log anomaly detection.
+then a number of fields are added to log records to correlate between APM
+services or traces and logging data:
+
+- Log statements (e.g. `logger.info(...)`) called when there is a current
+  tracing span will include {ecs-ref}/ecs-tracing.html[tracing fields] --
+  `trace.id`, `transaction.id`, `span.id`.
+- A number of service identifier fields determined by or configured on the APM
+  agent allow cross-linking between services and logs in Kibana --
+  `service.name`, `service.version`, `service.environment`, `service.node.name`.
+- `event.dataset` enables {observability-guide}/inspect-log-anomalies.html[log
+  rate anomaly detection] in the Elastic Observability app.
 
 For example, running https://github.com/elastic/ecs-logging-nodejs/blob/main/loggers/winston/examples/http-with-elastic-apm.js[examples/http-with-elastic-apm.js] and `curl -i localhost:3000/` results in a log record with the following:
 
@@ -242,7 +250,9 @@ For example, running https://github.com/elastic/ecs-logging-nodejs/blob/main/log
 % node examples/http-with-elastic-apm.js | jq .
 ...
   "service.name": "http-with-elastic-apm",
-  "event.dataset": "http-with-elastic-apm",
+  "service.version": "1.4.0",
+  "service.environment": "development",
+  "event.dataset": "http-with-elastic-apm"
   "trace.id": "7fd75f0f33ff49aba85d060b46dcad7e",
   "transaction.id": "6c97c7c1b468fa05"
 }
@@ -261,3 +271,22 @@ const logger = winston.createLogger({
 })
 ----
 
+[float]
+[[winston-ref]]
+=== Reference
+
+[float]
+[[winston-ref-ecsFormat]]
+==== `ecsFormat([options])`
+
+* `options` +{type-object}+ The following options are supported:
+** `convertErr` +{type-boolean}+ Whether to convert a logged `err` field to ECS error fields. *Default:* `true`.
+** `convertReqRes` +{type-boolean}+ Whether to logged `req` and `res` HTTP request and response fields to ECS HTTP, User agent, and URL fields. *Default:* `false`.
+** `apmIntegration` +{type-boolean}+ Whether to enable APM agent integration. *Default:* `true`.
+** `serviceName` +{type-string}+ A "service.name" value. If specified this overrides any value from an active APM agent.
+** `serviceVersion` +{type-string}+ A "service.version" value. If specified this overrides any value from an active APM agent.
+** `serviceEnvironment` +{type-string}+ A "service.environment" value. If specified this overrides any value from an active APM agent.
+** `serviceNodeName` +{type-string}+ A "service.node.name" value. If specified this overrides any value from an active APM agent.
+** `eventDataset` +{type-string}+ A "event.dataset" value. If specified this overrides the default of using `${serviceVersion}`.
+
+Create a formatter for winston that emits in ECS Logging format.

loggers/winston/CHANGELOG.md

@@ -2,12 +2,22 @@
 
 ## Unreleased
 
+- Add `service.version`, `service.environment`, and `service.node.name` log
+  correlation fields, automatically inferred from an active APM agent. As
+  well, the following `ecsFormat` configuration options have been added for
+  overriding these and existing correlation fields: `serviceName`,
+  `serviceVersion`, `serviceEnvironment`, `serviceNodeName`.
+  (https://github.com/elastic/apm-agent-nodejs/issues/3195,
+  https://github.com/elastic/ecs-logging-nodejs/issues/121,
+  https://github.com/elastic/ecs-logging-nodejs/issues/87)
+
 - Change to adding dotted field names (`"ecs.version": "1.6.0"`), rather than
   namespaced fields (`"ecs": {"version": "1.6.0"}`) for most fields. This is
   supported by the ecs-logging spec, and arguably preferred in the ECS logging
   docs. It is also what the ecs-logging-java libraries do. The resulting output
   is slightly shorter, and accidental collisions with user fields is less
   likely.
+
 - Stop adding ".log" suffix to `event.dataset` field.
   ([#95](https://github.com/elastic/ecs-logging-nodejs/issues/95))
 

loggers/winston/README.md

@@ -29,7 +29,7 @@ const ecsFormat = require('@elastic/ecs-winston-format')
 
 const logger = winston.createLogger({
   level: 'info',
-  format: ecsFormat(),
+  format: ecsFormat(/* options */),
   transports: [
     new winston.transports.Console()
   ]

loggers/winston/index.d.ts

@@ -6,25 +6,44 @@ interface Config {
    * Default true.
    */
   convertErr?: boolean;
+
   /**
    * Whether to convert logged `req` and `res` HTTP request and response fields
    * to ECS HTTP, User agent, and URL fields. Default false.
    */
   convertReqRes?: boolean;
+
   /**
    * Whether to automatically integrate with
    * Elastic APM (https://github.com/elastic/apm-agent-nodejs). If a started
    * APM agent is detected, then log records will include the following
    * fields:
    *
-   * - "service.name" - the configured serviceName in the agent
-   * - "event.dataset" - set to "$serviceName" for correlation in Kibana
    * - "trace.id", "transaction.id", and "span.id" - if there is a current
    *   active trace when the log call is made
    *
+   * and also the following fields, if not already specified in this config:
+   *
+   * - "service.name" - the configured `serviceName` in the agent
+   * - "service.version" - the configured `serviceVersion` in the agent
+   * - "service.environment" - the configured `environment` in the agent
+   * - "service.node.name" - the configured `serviceNodeName` in the agent
+   * - "event.dataset" - set to `${serviceName}` for correlation in Kibana
+   *
    * Default true.
    */
   apmIntegration?: boolean;
+
+  /** Specify "service.name" field. Defaults to a value from the APM agent, if available. */
+  serviceName?: string;
+  /** Specify "service.version" field. Defaults to a value from the APM agent, if available. */
+  serviceVersion?: string;
+  /** Specify "service.environment" field. Defaults to a value from the APM agent, if available. */
+  serviceEnvironment?: string;
+  /** Specify "service.node.name" field. Defaults to a value from the APM agent, if available. */
+  serviceNodeName?: string;
+  /** Specify "event.dataset" field. Defaults `${serviceName}`. */
+  eventDataset?: string;
 }
 
 declare function ecsFormat(opts?: Config): Logform.Format;

loggers/winston/index.js

@@ -45,39 +45,18 @@ const reservedFields = {
   res: true
 }
 
-// Create a Winston format for ecs-logging output.
-//
-// @param {Object} opts - Optional.
-//    - {Boolean} opts.convertErr - Whether to convert a logged `err` field
-//      to ECS error fields. Default true.
-//    - {Boolean} opts.convertReqRes - Whether to convert logged `req` and `res`
-//      HTTP request and response fields to ECS HTTP, User agent, and URL
-//      fields. Default false.
-//    - {Boolean} opts.apmIntegration - Whether to automatically integrate with
-//      Elastic APM (https://github.com/elastic/apm-agent-nodejs). If a started
-//      APM agent is detected, then log records will include the following
-//      fields:
-//        - "service.name" - the configured serviceName in the agent
-//        - "event.dataset" - set to "$serviceName" for correlation in Kibana
-//        - "trace.id", "transaction.id", and "span.id" - if there is a current
-//          active trace when the log call is made
-//      Default true.
+/**
+ * Create a Winston format for ecs-logging output.
+ *
+ * @param {import('logform').TransformableInfo} info
+ * @param {Config} opts - See index.d.ts.
+ */
 function ecsTransform (info, opts) {
-  let convertErr = true
-  let convertReqRes = false
-  let apmIntegration = true
-  // istanbul ignore else
-  if (opts) {
-    if (hasOwnProperty.call(opts, 'convertErr')) {
-      convertErr = opts.convertErr
-    }
-    if (hasOwnProperty.call(opts, 'convertReqRes')) {
-      convertReqRes = opts.convertReqRes
-    }
-    if (hasOwnProperty.call(opts, 'apmIntegration')) {
-      apmIntegration = opts.apmIntegration
-    }
-  }
+  // istanbul ignore next
+  opts = opts || {}
+  const convertErr = opts.convertErr != null ? opts.convertErr : true
+  const convertReqRes = opts.convertReqRes != null ? opts.convertReqRes : false
+  const apmIntegration = opts.apmIntegration != null ? opts.apmIntegration : true
 
   const ecsFields = {
     '@timestamp': new Date().toISOString(),
@@ -100,19 +79,62 @@ function ecsTransform (info, opts) {
     apm = elasticApm
   }
 
-  // istanbul ignore else
-  if (apm) {
-    // Set "service.name" and "event.dataset" from APM conf.
+  // Set a number of correlation fields from (a) the given options or (b) an
+  // APM agent, if there is one running.
+  let serviceName = opts.serviceName
+  if (serviceName == null && apm) {
     // istanbul ignore next
-    const serviceName = apm.getServiceName
+    serviceName = (apm.getServiceName
       ? apm.getServiceName() // added in [email protected]
-      : apm._conf.serviceName // fallback to private `_conf`
-    // A mis-configured APM Agent can be "started" but not have a "serviceName".
-    if (serviceName) {
-      ecsFields['service.name'] = serviceName
-      ecsFields['event.dataset'] = serviceName
-    }
+      : apm._conf.serviceName) // fallback to private `_conf`
+  }
+  if (serviceName) {
+    ecsFields['service.name'] = serviceName
+  }
+
+  let serviceVersion = opts.serviceVersion
+  if (serviceVersion == null && apm) {
+    // istanbul ignore next
+    serviceVersion = (apm.getServiceVersion
+      ? apm.getServiceVersion() // added in elastic-apm-node@...
+      : apm._conf.serviceVersion) // fallback to private `_conf`
+  }
+  if (serviceVersion) {
+    ecsFields['service.version'] = serviceVersion
+  }
+
+  let serviceEnvironment = opts.serviceEnvironment
+  if (serviceEnvironment == null && apm) {
+    // istanbul ignore next
+    serviceEnvironment = (apm.getServiceEnvironment
+      ? apm.getServiceEnvironment() // added in elastic-apm-node@...
+      : apm._conf.environment) // fallback to private `_conf`
+  }
+  if (serviceEnvironment) {
+    ecsFields['service.environment'] = serviceEnvironment
+  }
+
+  let serviceNodeName = opts.serviceNodeName
+  if (serviceNodeName == null && apm) {
+    // istanbul ignore next
+    serviceNodeName = (apm.getServiceNodeName
+      ? apm.getServiceNodeName() // added in elastic-apm-node@...
+      : apm._conf.serviceNodeName) // fallback to private `_conf`
+  }
+  if (serviceNodeName) {
+    ecsFields['service.node.name'] = serviceNodeName
+  }
 
+  let eventDataset = opts.eventDataset
+  if (eventDataset == null && serviceName) {
+    eventDataset = serviceName
+  }
+  if (eventDataset) {
+    ecsFields['event.dataset'] = eventDataset
+  }
+
+  // istanbul ignore else
+  if (apm) {
     // https://www.elastic.co/guide/en/ecs/current/ecs-tracing.html
     const tx = apm.currentTransaction
     if (tx) {

loggers/winston/test/apm.test.js

@@ -79,7 +79,12 @@ test('tracing integration works', t => {
       [
         path.join(__dirname, 'serve-one-http-req-with-apm.js'),
         apmServerUrl
-      ]
+      ],
+      {
+        env: Object.assign({}, process.env, {
+          ELASTIC_APM_SERVICE_NODE_NAME: 'serviceNodeNameFromEnv'
+        })
+      }
     )
     let handledFirstLogLine = false
     app.stdout.pipe(split(JSON.parse)).on('data', function (logObj) {
@@ -135,8 +140,11 @@ test('tracing integration works', t => {
       t.equal(logObjs[0]['trace.id'], span.trace_id, 'trace.id matches')
       t.equal(logObjs[0]['transaction.id'], span.transaction_id, 'transaction.id matches')
       t.equal(logObjs[0]['span.id'], span.id, 'span.id matches')
-      t.equal(logObjs[0]['service.name'], 'test-apm', 'service.name matches')
-      t.equal(logObjs[0]['event.dataset'], 'test-apm', 'event.dataset matches')
+      t.equal(logObjs[0]['service.name'], 'test-apm', 'service.name')
+      t.equal(logObjs[0]['service.version'], 'override-serviceVersion', 'service.version')
+      t.equal(logObjs[0]['service.environment'], 'development', 'service.environment')
+      t.equal(logObjs[0]['service.node.name'], 'serviceNodeNameFromEnv', 'service.node.name')
+      t.equal(logObjs[0]['event.dataset'], 'test-apm', 'event.dataset')
       finish()
     }
   }

loggers/winston/test/basic.test.js

@@ -277,3 +277,26 @@ test('convertErr=false allows passing through err=<non-Error>', t => {
   t.equal(rec.error, undefined, 'no rec.error is set')
   t.end()
 })
+
+test('can configure correlation fields', t => {
+  const cap = new CaptureTransport()
+  const logger = winston.createLogger({
+    format: ecsFormat({
+      serviceName: 'override-serviceName',
+      serviceVersion: 'override-serviceVersion',
+      serviceEnvironment: 'override-serviceEnvironment',
+      serviceNodeName: 'override-serviceNodeName',
+      eventDataset: 'override-eventDataset'
+    }),
+    transports: [cap]
+  })
+  logger.info('hi')
+
+  const rec = cap.records[0]
+  t.equal(rec['service.name'], 'override-serviceName')
+  t.equal(rec['service.version'], 'override-serviceVersion')
+  t.equal(rec['service.environment'], 'override-serviceEnvironment')
+  t.equal(rec['service.node.name'], 'override-serviceNodeName')
+  t.equal(rec['event.dataset'], 'override-eventDataset')
+  t.end()
+})

loggers/winston/test/serve-one-http-req-with-apm.js

@@ -44,7 +44,10 @@ const http = require('http')
 const ecsFormat = require('../') // @elastic/ecs-winston-format
 const winston = require('winston')
 
-const ecsOpts = { convertReqRes: true }
+const ecsOpts = {
+  convertReqRes: true,
+  serviceVersion: 'override-serviceVersion'
+}
 if (disableApmIntegration) {
   ecsOpts.apmIntegration = false
 }