Skip to content

Commit

Permalink
chore: prefer dotted field names; drop ".log" suffix on event.dataset
Browse files Browse the repository at this point in the history
- 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.

Closes: #95
  • Loading branch information
trentm committed Oct 14, 2023
1 parent 2a6ea19 commit 1f67743
Show file tree
Hide file tree
Showing 23 changed files with 256 additions and 448 deletions.
2 changes: 1 addition & 1 deletion docs/intro.asciidoc
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@ popular web frameworks. A minimal log record includes the following fields:
"@timestamp": "2021-01-13T21:32:38.095Z",
"log.level": "info",
"message": "hi",
"ecs": {"version":"1.6.0"}
"ecs.version": "1.6.0"
}
----

Expand Down
22 changes: 6 additions & 16 deletions docs/morgan.asciidoc
Original file line number Diff line number Diff line change
Expand Up @@ -85,9 +85,7 @@ similar to the following:
"@timestamp": "2021-01-16T00:03:23.279Z",
"log.level": "info",
"message": "::1 - - [16/Jan/2021:00:03:23 +0000] \"GET / HTTP/1.1\" 200 13 \"-\" \"curl/7.64.1\"",
"ecs": {
"version": "1.6.0"
},
"ecs.version": "1.6.0",
"http": {
"version": "1.1",
"request": {
Expand Down Expand Up @@ -178,19 +176,11 @@ For example, running https://github.com/elastic/ecs-logging-nodejs/blob/main/log
----
% node examples/express-with-apm.js | jq .
{
...
"event": {
"dataset": "express-with-elastic-apm.log"
},
"trace": {
"id": "e097193afa9ac221017b45a1f674601c"
},
"transaction": {
"id": "c6aa5b47e01bad72"
},
"service": {
"name": "express-with-elastic-apm"
}
// The same fields as before, plus:
"trace.id": "e097193afa9ac221017b45a1f674601c",
"transaction.id": "c6aa5b47e01bad72",
"service.name": "express-with-elastic-apm",
"event.dataset": "express-with-elastic-apm"
}
----

Expand Down
45 changes: 17 additions & 28 deletions docs/pino.asciidoc
Original file line number Diff line number Diff line change
Expand Up @@ -68,8 +68,8 @@ Running this will produce log output similar to the following:

[source,cmd]
----
{"log.level":"info","@timestamp":"2021-01-19T22:51:12.142Z","ecs":{"version":"1.6.0"},"process":{"pid":82240},"host":{"hostname":"pink.local"},"message":"Hello world"}
{"log.level":"warn","@timestamp":"2021-01-19T22:51:12.143Z","ecs":{"version":"1.6.0"},"process":{"pid":82240},"host":{"hostname":"pink.local"},"module":"foo","message":"From child"}
{"log.level":"info","@timestamp":"2023-10-14T02:07:47.901Z","process.pid":56645,"host.hostname":"pink.local","ecs.version":"1.6.0","message":"Hello world"}
{"log.level":"warn","@timestamp":"2023-10-14T02:07:47.901Z","process.pid":56645,"host.hostname":"pink.local","ecs.version":"1.6.0","module":"foo","message":"From child"}
----

[float]
Expand Down Expand Up @@ -159,22 +159,17 @@ For example:
... # run 'curl http://localhost:3000/'
{
"log.level": "info",
"@timestamp": "2021-01-19T22:58:59.649Z",
"ecs": {
"version": "1.6.0"
},
"process": {
"pid": 82670
},
"host": {
"hostname": "pink.local"
},
"@timestamp": "2023-10-14T02:10:14.477Z",
"process.pid": 56697,
"host.hostname": "pink.local",
"ecs.version": "1.6.0",
"http": {
"version": "1.1",
"request": {
"method": "GET",
"headers": {
"host": "localhost:3000",
"user-agent": "curl/8.1.2",
"accept": "*/*"
}
},
Expand All @@ -189,8 +184,13 @@ For example:
"full": "http://localhost:3000/",
"path": "/"
},
"client": {
"address": "::ffff:127.0.0.1",
"ip": "::ffff:127.0.0.1",
"port": 49504
},
"user_agent": {
"original": "curl/7.64.1"
"original": "curl/8.1.2"
},
"message": "handled request"
}
Expand Down Expand Up @@ -220,21 +220,10 @@ 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.log"
},
"trace": {
"id": "a1c23e04d7174462f330f5921c8f036d"
},
"transaction": {
"id": "2550c4c267d4dd53"
},
"span": {
"id": "16a8704258dbc328"
},
"service.name": "http-with-elastic-apm",
"event.dataset": "http-with-elastic-apm",
"trace.id": "79de6da334efae17ad43758573d57f1c",
"transaction.id": "8bf944f94b72c54d",
...
----

Expand Down
44 changes: 19 additions & 25 deletions docs/winston.asciidoc
Original file line number Diff line number Diff line change
Expand Up @@ -78,8 +78,8 @@ Running this script (available https://github.com/elastic/ecs-logging-nodejs/blo
[source,cmd]
----
% node examples/basic.js
{"@timestamp":"2021-01-13T21:32:38.095Z","log.level":"info","message":"hi","ecs":{"version":"1.6.0"}}
{"@timestamp":"2021-01-13T21:32:38.096Z","log.level":"error","message":"oops there is a problem","ecs":{"version":"1.6.0"},"foo":"bar"}
{"@timestamp":"2023-10-14T02:14:17.302Z","log.level":"info","message":"hi","ecs.version":"1.6.0"}
{"@timestamp":"2023-10-14T02:14:17.304Z","log.level":"error","message":"oops there is a problem","ecs.version":"1.6.0","foo":"bar"}
----

The formatter handles serialization to JSON, so you don't need to add the
Expand Down Expand Up @@ -120,14 +120,12 @@ will yield (pretty-printed for readability):
"@timestamp": "2021-01-26T17:25:07.983Z",
"log.level": "info",
"message": "oops",
"ecs": {
"version": "1.6.0"
},
"error": {
"type": "Error",
"message": "boom",
"stack_trace": "Error: boom\n at Object.<anonymous> (..."
}
},
"ecs.version": "1.6.0"
}
----

Expand Down Expand Up @@ -189,18 +187,16 @@ For https://github.com/elastic/ecs-logging-nodejs/blob/main/loggers/winston/exam
% node examples/http.js | jq . # using jq for pretty printing
... # run 'curl http://localhost:3000/'
{
"@timestamp": "2021-01-13T22:00:07.442Z",
"@timestamp": "2023-10-14T02:15:54.768Z",
"log.level": "info",
"message": "handled request",
"ecs": {
"version": "1.6.0"
},
"http": {
"version": "1.1",
"request": {
"method": "GET",
"headers": {
"host": "localhost:3000",
"user-agent": "curl/8.1.2",
"accept": "*/*"
}
},
Expand All @@ -215,9 +211,15 @@ For https://github.com/elastic/ecs-logging-nodejs/blob/main/loggers/winston/exam
"path": "/",
"full": "http://localhost:3000/"
},
"client": {
"address": "::ffff:127.0.0.1",
"ip": "::ffff:127.0.0.1",
"port": 49538
},
"user_agent": {
"original": "curl/7.64.1"
}
"original": "curl/8.1.2"
},
"ecs.version": "1.6.0"
}
----

Expand All @@ -239,19 +241,11 @@ For example, running https://github.com/elastic/ecs-logging-nodejs/blob/main/log
----
% node examples/http-with-elastic-apm.js | jq .
...
"event": {
"dataset": "http-with-elastic-apm.log"
},
"trace": {
"id": "74631535a02bbe6a07c298b28c7443f4"
},
"transaction": {
"id": "505400b77aba4d9a"
},
"service": {
"name": "http-with-elastic-apm"
}
...
"service.name": "http-with-elastic-apm",
"event.dataset": "http-with-elastic-apm",
"trace.id": "7fd75f0f33ff49aba85d060b46dcad7e",
"transaction.id": "6c97c7c1b468fa05"
}
----

These IDs match trace data reported by the APM agent.
Expand Down
11 changes: 11 additions & 0 deletions loggers/morgan/CHANGELOG.md
Original file line number Diff line number Diff line change
@@ -1,5 +1,16 @@
# @elastic/ecs-morgan-format Changelog

## Unreleased

- 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))

## v1.1.0

- Update @elastic/ecs-helpers@1.1.0 to get more robust HTTP req and res
Expand Down
9 changes: 5 additions & 4 deletions loggers/morgan/examples/express-with-apm.js
Original file line number Diff line number Diff line change
Expand Up @@ -22,17 +22,18 @@
//
// If usage of Elastic APM is detected (i.e. the "elastic-apm-node" package
// is being used), then log records will include trace identifiers, e.g.:
// "trace": { "id": "678f2a0189f259baf2ea17db8af5a4d0" },
// "transaction": { "id": "1cc6339964575165" },
// "span": { "id": "f72c52ceda81777a" },
// "trace.id": "678f2a0189f259baf2ea17db8af5a4d0",
// "transaction.id": "1cc6339964575165",
// "span.id": "f72c52ceda81777a",
// to correlate log and trace data in Kibana.

/* eslint-disable-next-line no-unused-vars */
const apm = require('elastic-apm-node').start({
serviceName: 'express-with-elastic-apm',
centralConfig: false,
captureExceptions: false,
metricsInterval: 0
metricsInterval: '0s',
logLevel: 'warn' // avoid APM agent log preamble
})

const app = require('express')()
Expand Down
32 changes: 10 additions & 22 deletions loggers/morgan/index.js
Original file line number Diff line number Diff line change
Expand Up @@ -45,7 +45,7 @@ try {
// 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.log" for correlation in Kibana
// - "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.
Expand Down Expand Up @@ -82,21 +82,17 @@ function ecsFormat (opts) {
apm = elasticApm
}

let serviceField
let eventField
const extraFields = {}
if (apm) {
// https://github.com/elastic/apm-agent-nodejs/pull/1949 is adding
// getServiceName() in v3.11.0. Fallback to private `apm._conf`.
// istanbul ignore next
const serviceName = apm.getServiceName
? apm.getServiceName()
? apm.getServiceName() // added in elastic-apm-node@3.11.0
: apm._conf.serviceName
// A mis-configured APM Agent can be "started" but not have a
// "serviceName".
// A mis-configured APM Agent can be "started" but not have a "serviceName".
// istanbul ignore else
if (serviceName) {
serviceField = { name: serviceName }
eventField = { dataset: serviceName + '.log' }
extraFields['service.name'] = serviceName
extraFields['event.dataset'] = serviceName
}
}

Expand All @@ -105,25 +101,17 @@ function ecsFormat (opts) {
'@timestamp': new Date().toISOString(),
'log.level': res.statusCode < 500 ? 'info' : 'error',
message: fmt(token, req, res),
ecs: { version }
}

if (serviceField) {
ecsFields.service = serviceField
}
if (eventField) {
ecsFields.event = eventField
'ecs.version': version,
...extraFields
}

// https://www.elastic.co/guide/en/ecs/current/ecs-tracing.html
if (apm) {
const tx = apm.currentTransaction
// istanbul ignore else
if (tx) {
ecsFields.trace = ecsFields.trace || {}
ecsFields.trace.id = tx.traceId
ecsFields.transaction = ecsFields.transaction || {}
ecsFields.transaction.id = tx.id
ecsFields['trace.id'] = tx.traceId
ecsFields['transaction.id'] = tx.id
// Not including `span.id` because the way morgan logs (on the HTTP
// Response "finished" event), any spans during the request handler
// are no longer active.
Expand Down
8 changes: 4 additions & 4 deletions loggers/morgan/test/apm.test.js
Original file line number Diff line number Diff line change
Expand Up @@ -132,10 +132,10 @@ test('tracing integration works', t => {
t.ok(traceObjs[0].metadata, 'traceObjs[0] is metadata')
t.ok(traceObjs[1].transaction, 'traceObjs[1] is transaction')
const tx = traceObjs[1].transaction
t.equal(logObjs[0].trace.id, tx.trace_id, 'trace.id matches')
t.equal(logObjs[0].transaction.id, tx.id, 'transaction.id matches')
t.equal(logObjs[0].service.name, 'test-apm')
t.equal(logObjs[0].event.dataset, 'test-apm.log')
t.equal(logObjs[0]['trace.id'], tx.trace_id, 'trace.id matches')
t.equal(logObjs[0]['transaction.id'], tx.id, 'transaction.id matches')
t.equal(logObjs[0]['service.name'], 'test-apm')
t.equal(logObjs[0]['event.dataset'], 'test-apm')
finish()
}
}
Expand Down
11 changes: 11 additions & 0 deletions loggers/pino/CHANGELOG.md
Original file line number Diff line number Diff line change
@@ -1,5 +1,16 @@
# @elastic/ecs-pino-format Changelog

## Unreleased

- 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))

## v1.3.0

- TypeScript types. ([#82](https://github.com/elastic/ecs-logging-nodejs/pull/82))
Expand Down
9 changes: 5 additions & 4 deletions loggers/pino/examples/http-with-elastic-apm.js
Original file line number Diff line number Diff line change
Expand Up @@ -22,17 +22,18 @@
//
// If usage of Elastic APM is detected (i.e. the "elastic-apm-node" package
// is being used), then log records will include trace identifiers, e.g.:
// "trace": { "id": "678f2a0189f259baf2ea17db8af5a4d0" },
// "transaction": { "id": "1cc6339964575165" },
// "span": { "id": "f72c52ceda81777a" },
// "trace.id": "678f2a0189f259baf2ea17db8af5a4d0",
// "transaction.id": "1cc6339964575165",
// "span.id": "f72c52ceda81777a",
// to correlate log and trace data in Kibana.

/* eslint-disable-next-line no-unused-vars */
const apm = require('elastic-apm-node').start({
serviceName: 'http-with-elastic-apm',
centralConfig: false,
captureExceptions: false,
metricsInterval: 0
metricsInterval: '0s',
logLevel: 'warn' // avoid APM agent log preamble
})

const http = require('http')
Expand Down
2 changes: 1 addition & 1 deletion loggers/pino/index.d.ts
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,7 @@ interface Config {
* fields:
*
* - "service.name" - the configured serviceName in the agent
* - "event.dataset" - set to "$serviceName.log" for correlation in Kibana
* - "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
*
Expand Down
Loading

0 comments on commit 1f67743

Please sign in to comment.