elastic/ecs-logging-nodejs

ecs-logging-nodejs

This set of libraries allows you to transform your application logs to structured logs that comply with the Elastic Common Schema (ECS). In combination with filebeat you can send your logs directly to Elasticsearch and leverage Kibana's Logs app to inspect all logs in one single place.

Please see the Node.js ECS logging documentation.

Supported logging frameworks

• Pino via @elastic/ecs-pino-format (docs, changelog)
• Winston via @elastic/ecs-winston-format (docs, changelog)
• Morgan via @elastic/ecs-morgan-format (docs, changelog)

Links

• Introduction to ECS blog post.
• Logs UI blog post.

License

This software is licensed under the Apache 2 license.

ecs-logging-nodejs's Issues

Support for Request | Response Body

Currently the formatting library does not capture request.body and response.body which might be useful at times.
ECS though supports these fields in http.request.body.content and http.response.body.content.

add support for service.node.name

See elastic/ecs-logging#61 which added service.node.name to the spec.

Add custom token data to @elastic/ecs-morgan-format

Hello,
I would like to add custom data so that it gets added to the final formatter for @elastic/ecs-morgan-format

Is it possible ?

why `type: ['string', 'number']` for fields of type "keyword"?

@delvedor Why in create-schema.js is a type: keyword converted to a JSON Schema type { type: ['string', 'number'] }?

https://github.com/elastic/ecs-logging-js/blob/15dc5f813f8a19bd0eb54fd48674240acfe4a0f7/utils/create-schema.js#L86-L87

This, for example, allows log.level, log.logger, @timestamp and others to be a number. Is this a compromise with some fields given as type "keyword" that should be allowed to be numbers?

Logging an object that contains 'response' key crashes things.

If you have a "response" field in the object that you are logging, you end up wtih:

(node:83383) UnhandledPromiseRejectionWarning: TypeError: res.getHeaders is not a function
    at formatHttpResponse (/Users/bone/git/snapyr-io-plane/src/processes/http/node_modules/@elastic/ecs-helpers/http-formatters.js:84:21)
    at Format.ecsFormat (/Users/bone/git/snapyr-io-plane/src/processes/http/node_modules/@elastic/ecs-winston-format/index.js:42:5)
    at DerivedLogger._transform (/Users/bone/git/snapyr-io-plane/node_modules/winston/lib/winston/logger.js:305:29)
    at DerivedLogger.Transform._read (/Users/bone/git/snapyr-io-plane/node_modules/readable-stream/lib/_stream_transform.js:177:10)
    at DerivedLogger.Transform._write (/Users/bone/git/snapyr-io-plane/node_modules/readable-stream/lib/_stream_transform.js:164:83)
    at doWrite (/Users/bone/git/snapyr-io-plane/node_modules/readable-stream/lib/_stream_writable.js:409:139)
    at writeOrBuffer (/Users/bone/git/snapyr-io-plane/node_modules/readable-stream/lib/_stream_writable.js:398:5)
    at DerivedLogger.Writable.write (/Users/bone/git/snapyr-io-plane/node_modules/readable-stream/lib/_stream_writable.js:307:11)
    at DerivedLogger.log (/Users/bone/git/snapyr-io-plane/node_modules/winston/lib/winston/logger.js:244:14)
    at DerivedLogger.<computed> [as debug] (/Users/bone/git/snapyr-io-plane/node_modules/winston/lib/winston/create-logger.js:95:19)
(Use `node --trace-warnings ...` to show where the warning was created)

Because the code expects that to be a Response. (even when its not)

There should be better error handling and warnings if response is a key, but is not a response object.

Using pino logger with ECS format does not log custom attributes

I'm using the following code to return a pino logger instance. I want to log a custom 'name' attribute but I don't seem to get it to work. No errors. It just does not log the 'name' attribute. Everything else is working as expected. Is this the correct way to create a logger instance?

return pino(
      ecs(),
      pino.destination({
          dest: dest, 
          mkdir: true,
          sync: false
      }),
      { name: 'My Project' } // it does not work
 );

But if I change the code and remove the ECS function, it starts working as expected:

return pino(
      { name: 'My Project' },
      pino.destination({
          dest: dest, 
          mkdir: true,
          sync: false
      })
 );

docs: add ecs-logging-js to the Elastic doc build

To do

• Move docs to asciidoc #44
• Open PR in elastic/docs to add to the build elastic/docs#2048
• Open infra ticket to add the elasticsearch/ci docs check to this repo – see link in the timeline below
• Add the elasticsearch/ci docs webhook to the repo
• Remove content from readme and link to published docs

Ping me when you're ready for this step and I can help you out!

add support for `service.version` and `service.environment` with apmInstrumentation

service.version, at least, has been added to the ecs-logging spec:
https://github.com/elastic/ecs-logging/blob/d8ee4d4ba5853a10425ac21f41a5ff04f84b355b/spec/spec.json#L88-L96
with the comment that:

When an APM agent is active, it should auto-configure it if not already set.

The spec will be sync'd here with #120.

Then ecs-logging-java added support for service.version and service.environment:

• elastic/ecs-logging-java#168
• elastic/ecs-logging-java#184

Should the node.js ecs-logging libs do the same?

add `convertReqRes` boolean option; make req/res conversion off by default

The current version of the winston and pino ecs-logging formatters automatically handle logging of req, res, request, and response extra fields: converting them from HTTP request and response objects to ECS HTTP, URL, and User agent fields.

This ticket is proposing a BREAKING CHANGE to this while these packages are still in pre-1.x beta:

1. Turn this off by default and provide a convertReqRes: true boolean option to turn it on.
2. Only handle req and res as special.

My understanding is the main idea for specially handling HTTP request/response objects stems from:

• req/res serializers in pino and Bunyan, and in the
• arguably also from req/res handling in many of the provided morgan formats

The argument for making this configurable is to handle the case where a user wants to log req/res but not for an HTTP request or response. The main argument for turning off req/res handling by default is that the req/res handlers in pino and Bunyan are also off by default. As well, having the option to turn on an extra feature feels a little more discoverable... but one could go either way on that.

The argument for only supporting req / res and not request / response is the prevalent usage of just req / res in pino and Bunyan. All examples of logging in code docs for Node.js frameworks that I could find use the short "req" and "res". I would prefer to start these libraries without multiple ways to perform the same thing. If there is a strong use case brought up for them, a separate ticket could discuss re-adding them.

Exception: morgan

Morgan is explicitly "HTTP request logger middleware for node.js". It doesn't provide logging methods for the app developer to even pass in extra fields. It doesn't make sense to have the default @elastic/ecs-morgan-format not render request and response fields.

Logging an object that contains an 'event' key, crashes things.

When trying to log an object that has "event":"processed" as a key, things bomb with a:

/Users/bone/git/snapyr-io-plane/node_modules/@elastic/ecs-winston-format/index.js:105
      ecsFields.event.dataset = serviceName + '.log'
                              ^
TypeError: Cannot create property 'dataset' on string 'processed'

I think you want to add "event" as a reserved field here:
https://github.com/elastic/ecs-logging-nodejs/blob/master/loggers/winston/index.js#L38

Because you depend on it here:
https://github.com/elastic/ecs-logging-nodejs/blob/master/loggers/winston/index.js#L104

And if there are conflicts, you probably want to handle them in an else statement here:
https://github.com/elastic/ecs-logging-nodejs/blob/master/loggers/winston/index.js#L78

There, you could at the very least log.Warn about it. Ideally, maybe even chose a different fieldName to put event information.

[bug] ecs-winston-format not compiling due to expression in ambient context and missing import

Currently running Typescript 4.x, WInston 3.x.x and ecs-winston-format 1.3.x;

There is an error to do with expressions in a declaration file. I think it has something to do with this breaking change.

Below is the error:
{
"resource": "ecs-logging-nodejs/loggers/winston/index.d.ts",
"owner": "typescript",
"code": "2714",
"severity": 8,
"message": "The expression of an export assignment must be an identifier or qualified name in an ambient context.",
"source": "ts",
"startLineNumber": 30,
"startColumn": 10,
"endLineNumber": 30,
"endColumn": 43
}

Furthermore, I also get a missing import error as Winston has no exported member "Format". Below is the error:
{
"resource": "ecs-logging-nodejs/loggers/winston/index.d.ts",
"owner": "typescript",
"code": "2724",
"severity": 8,
"message": "'"winston"' has no exported member named 'Format'. Did you mean 'format'?",
"source": "ts",
"startLineNumber": 1,
"startColumn": 15,
"endLineNumber": 1,
"endColumn": 21
}

Ability to exclude Authorization header parameters from log

Hi,

Is there a way to not output request Authorization header parameters (ex: the value of the Authorization Basic parameter) in log depending on the log level ?

Regards

Trace Ids not added on uncaught exceptions - ecsFormat()?

Trace Ids not added on uncaught exceptions?

When using ECSFormat with winston I don't have TraceIds (transaction.id e etc...) information in uncaught Exceptions.
elastic/apm-agent-nodejs#2730

import { createLogger, format, transports } from 'winston';
import ecsFormat from '@elastic/ecs-winston-format';

const consoleOptions = {
    level: 'info',
    handleExceptions: true,
    format: ecsFormat(),
};

const consoleTransport = new transports.Console(consoleOptions);

const logger = createLogger({
    exitOnError: true,
    transports: [
        consoleTransport,
    ]
});

INFO:

{"@timestamp":"2022-05-27T19:10:13.556Z","log.level":"info","message":"testing info with winston logger","ecs":{"version":"1.6.0"},"event":{"dataset":"example_normal.log"},"trace":{"id":"e477cd64384c8c0f78cc00787ee622d4"},"transaction":{"id":"8c9cc366b48425c0"},"service":{"name":"example_normal","environment":"local"},"test2":"test2"}

UNCAUGHT EXCEPTION:

{"@timestamp":"2022-05-27T19:10:13.563Z","log.level":"error","message":"uncaughtException: a is not defined\nReferenceError: a is not defined\n    at file:///home/user/code/logs-nodejs-lib/examples/example_normal.js:19:1\n    at ModuleJob.run (node:internal/modules/esm/module_job:195:25)\n    at async Promise.all (index 0)\n    at async ESMLoader.import (node:internal/modules/esm/loader:337:24)\n    at async loadESM (node:internal/process/esm_loader:88:5)\n    at async handleMainPromise (node:internal/modules/run_main:61:12)","ecs":{"version":"1.6.0"},"event":{"dataset":"example_normal.log"},"trace":{},"service":{"name":"example_normal","environment":"local"},"error":{"message":"a is not defined"},"stack":"ReferenceError: a is not defined\n    at file:///home/user/code/logs-nodejs-lib/examples/example_normal.js:19:1\n    at ModuleJob.run (node:internal/modules/esm/module_job:195:25)\n    at async Promise.all (index 0)\n    at async ESMLoader.import (node:internal/modules/esm/loader:337:24)\n    at async loadESM (node:internal/process/esm_loader:88:5)\n    at async handleMainPromise (node:internal/modules/run_main:61:12)","exception":true,"date":"Fri May 27 2022 16:10:13 GMT-0300 (Brasilia Standard Time)","process":{"pid":359643,"uid":1000,"gid":1000,"cwd":"/home/user/code/logs-nodejs-lib/examples","execPath":"/usr/local/bin/node","version":"v16.14.0","argv":["/usr/local/bin/node","/home/user/code/logs-nodejs-lib/examples/example_normal.js"],"memoryUsage":{"rss":60342272,"heapTotal":19537920,"heapUsed":14871160,"external":2825769,"arrayBuffers":317453}},"os":{"loadavg":[1.61,1.57,1.91],"uptime":110849.91}}

Exception when logging response headers

Hi,

I'm trying to log the response headers, but an exception is raised by ecs formatter. This is my code:

const winston = require('winston');
const express = require('express');
const ecsFormat = require('@elastic/ecs-winston-format');

const app = express();
app.use(express.json());

const logger = winston.createLogger({
    format: ecsFormat(),
    transports: [
        new winston.transports.Console()
    ]
});

app.get('/', (req, res) => {
  logger.info(res.getHeaders());
  res.end();
});

app.listen(5000);

This is the exception:

TypeError: str.toString is not a function
at $asString (eval at build (F:\Projects\jstest\node_modules\fast-json-stringify\index.js:147:20), <anonymous>:106:15)
    at $main (eval at build (F:\Projects\jstest\node_modules\fast-json-stringify\index.js:147:20), <anonymous>:223:17)
    at Format.ecsTransform [as transform] (F:\Projects\jstest\node_modules\@elastic\ecs-winston-format\index.js:183:19)
    at DerivedLogger._transform (F:\Projects\jstest\node_modules\winston\lib\winston\logger.js:305:29)
    at DerivedLogger._read (F:\Projects\jstest\node_modules\readable-stream\lib\_stream_transform.js:177:10)
    at DerivedLogger._write (F:\Projects\jstest\node_modules\readable-stream\lib\_stream_transform.js:164:83)
    at doWrite (F:\Projects\jstest\node_modules\readable-stream\lib\_stream_writable.js:405:139)
    at writeOrBuffer (F:\Projects\jstest\node_modules\readable-stream\lib\_stream_writable.js:394:5)
    at DerivedLogger.write (F:\Projects\jstest\node_modules\readable-stream\lib\_stream_writable.js:303:11)
    at DerivedLogger.info (F:\Projects\jstest\node_modules\winston\lib\winston\create-logger.js:81:14)
    at <anonymous> (F:\Projects\jstest\test.ts:16)

The object returned by getHeaders() is not an Object. It has only the fields, without any prototype. So calling toString() on it raises this exception.

JSON.stringify works on this object just fine.

A possible workaround is to pass {...res.getHeaders()}.

"ecsFormat is not a function" when using elastic-apm-node

Hi 👋

While adding elastic logging to a Node.js Application I encountered an Error using it together with ecs-pino-nodejs.

Error stack:

TypeError: ecsFormat is not a function
    at Object.createLogger (/Users/****/devPers/git/elk-pino-bug/node_modules/elastic-apm-node/lib/logging.js:142:8)
    at new Config (/Users/****/devPers/git/elk-pino-bug/node_modules/elastic-apm-node/lib/config.js:260:27)
    at config (/Users/****/devPers/git/elk-pino-bug/node_modules/elastic-apm-node/lib/config.js:222:10)
    at Agent._config (/Users/****/devPers/git/elk-pino-bug/node_modules/elastic-apm-node/lib/agent.js:145:16)
    at new Agent (/Users/****/devPers/git/elk-pino-bug/node_modules/elastic-apm-node/lib/agent.js:38:8)
    at Object.<anonymous> (/Users/****/devPers/git/elk-pino-bug/node_modules/elastic-apm-node/index.js:5:18)

How to Reproduce:
index.js:

const ecsFormat = require('@elastic/ecs-pino-format')
const pino = require('pino')
const ElasticAPM = require('elastic-apm-node')

const apm = ElasticAPM.start({
	serviceName: 'serviceName',
})

const logger = pino({ ...ecsFormat({ convertReqRes: true, convertErr: true, apmIntegration: true }) })

logger.info("Test")

Run with node index.js
Installed Packages:

• @elastic/ecs-pino-format v.1.1.1
• elastic-apm-node v3.14.0
• pino v6.11.3
  Running Node 14.15.5

Interestingly enough I can work around that issue using an Alias dependency. If I install ecs-pino-format like this:
npm i ecs-pino-format@npm:@elastic/ecs-pino-format

And change line 1 to
const ecsFormat = require('ecs-pino-format')

It runs perfectly.

I'm not sure if it's an issue with elastic-apm-node, the pino-logger itself, or I configured something wrong.
Could someone assist me with this issue?

Support content for body

Is possible to add support for body content for request and response based on new spec?

Request body content

Response body content

When i try to add it manually the content is not sent, I assume it has something to do with the stringify serializer?

url.full coming from req instead of ecs

ecs-logging-nodejs/helpers/lib/http-formatters.js

Line 59 in 26aaa6a

ecs.url.full = (socket && socket.encrypted ? 'https://' : 'http://') + headers.host + url

It looks like url attribute is being set with information from req instead of ecs like the rest of the attributes. This is causing full to reflect a different address than domain in our environment. Would this be more appropriate?

ecs.url.full = (socket && socket.encrypted ? 'https://' : 'http://') + ecs.headers.host + ecs.url.path

need a solution for conflicts between ECS specified fields and user-logged fields

ECS specifies a lot of top-level fields. Currently the node.js ecs-logging loggers in this repo do not, in general, deal with conflicts between a user-specified field and the ECS specified field types, e.g.:

log.info({http: "yes", event: true, cloud: "aws"}, "these http, event, and cloud fields conflict with ECS")

If there is a conflict, my understanding is that the log record(s) will fail to be imported into Elasticsearch. I'm not sure if that shows up in filebeat logs, but it is certainly downstream of the app doing the logging.

We need a solution for this. Some early thoughts:

We could just document the issue and not deal with conflicts in the library. This is somewhat what the ecs-logging docs say about custom fields. Having the logging libraries work through all logged custom fields and guarding against conflicts isn't practical: it would be expensive/slow and brings up the question of whether to move or drop conflicting fields (silently or with warnings) or make that configurable.

Leaving it to the user of the ecs-logging lib can be onerous on the user. Some users, more engaged with ECS, might be happy to take on the burden of handling ECS fields. Most users, probably not. The case is more of a problem with proposed/possible automatic configuration of an apps logging to do ecs-logging. In this case the app developer may not be involved, so definitely cannot accept the responsibility of using ECS-conformant fields.

Another option would be to have the node.js ecs-logging libs put all user-provided fields under a labels: {...} or custom: {...} namespace. I vaguely recall that the .NET ecs-logging libs do this (not sure which name they use).

Another option would be to have a configurable mode for that. At least for node.js ecs-logging libs that would provide a migration path from the current v1.x versions that do not do namespacing.

Support for other frameworks that not expose raw request at req.raw.req

Hello guys:

After jump from previous version (0.1...0.2) to 1.0 i found that my REQ object isn't logged anymore...
Digger into the code, i found that the expected shape of the req object (IncomingMessage) is now: req -> raw-> req , and other frameworks, like fastify, expose that at req -> raw directly.

I have a fix to support this (and possibly others (?) frameworks), let me know to send PR.

thx

http-formatters remoteAddress/remotePort doesn't function as expected

formatHttpRequest does not appear to reliably determine the client IP address/port. The fields that are being used, remoteAddress/remotePort, do not appear to be in the API docs https://nodejs.org/docs/latest-v14.x/api/http.html.

This results in most fields in the logs generated being undefined:

It appears more likely that req.socket.remoteAddress and req.socket.remotePort should be being used here. Additionally, it would be useful to have a way to determine the real IP address and use that when NodeJS is behind a proxy.

Perhaps something along these lines to try to determine the best IP address to use:

  ecs.client = ecs.client || {}
  // if req.ip exists from framework (Express, etc.) defer to that http://expressjs.com/en/4x/api.html
  if (req.ip) {
    ecs.client.address = req.ip;
  } else if (req.headers['x-forwarded-for']) {
    ecs.client.address = req.headers['x-forwarded-for'].split(",")[0];
  } else if (req.socket && req.socket.remoteAddress) {
    ecs.client.address = req.socket.remoteAddress;
  }

update formatHttpRequest and formatHttpResponse to handle *client* req and res

Currently formatHttpRequest and formatHttpResponse handle server-side request and response objects (from node core and some of the http frameworks). It would be nice to support the client-side request and response objects:

• client-side request is a
  http.ClientRequest returned from http.request() and http.get()
• client-side response is a
  http.IncomingMessage returned from the "response" event of a client http.request()

Normally I'm opposed to DWIM'ing, but it would be nice if it could be managed here without gross heuristics and ambiguity. Node core docs (and likely lots of community docs) commonly refer to both server-side and client-side requests and responses as req and res. Just logging those variables as is would be nice.

One potential issue is if this blows up to a desire to support many varying "client request" and "client response" objects from Node-land http client libraries. I don't know if that would be the case.

FWIW, some minor prior art is handling for client_req and client_res log record fields in Bunyan and client_req and client_res serializers for Bunyan in the restify-clients package.

Winston has unexpected output when using default meta

Example code

import winston from 'winston'
import ecsFormat  from '@elastic/ecs-winston-format'

const logger = winston.createLogger({
    level: 'info',
    format: ecsFormat(),
    defaultMeta: { service: "Service Name" },
    transports: [
        new winston.transports.Console()
    ],
  });

 logger.info('Unable to connect to ElasticSearch')

Output

{"@timestamp":"2021-02-11T01:45:57.337Z","log.level":"error","message":"Unable to connect to ElasticSearch","ecs":{"version":"1.6.0"},"service":{"0":"S","1":"e","2":"r","3":"v","4":"i","5":"c","6":"e","7":" ","8":"N","9":"a","10":"m","11":"e"}} 

Expected

{"@timestamp":"2021-02-11T01:45:57.337Z","log.level":"error","message":"Unable to connect to ElasticSearch","ecs":{"version":"1.6.0"},"service":{"Service Name"}} 

As you can see above when using defaultmeta the object value is serialized even if it is a string. Any quick fix I can put in place to solve this?

ecs-pino-format with convertReqRes wrong http field format

Hi,

I am using NestJS with nestjs-pino and I am trying to set up ecsFormat({ convertReqRes: true }). Logging of request and response works, but format is odd.
If this is meant for nestjs-pino i am sorry just let me know. Thank you

Versions I am using:
Node: 14.17.3
npm: 7.23.0
nestjs: latest setup
@elastic/ecs-pino-format: 1.3.0
nestjs-pino: 2.2.0
pino-http: 5.7.0

Usage

@Module({
    imports: [
        LoggerModule.forRoot({
            pinoHttp: { ...ecsFormat({ convertReqRes: true }) },
        }),
    ],
})
export class AppModule {}

In this picture, you can see ecsFormat with convertReqRes set to false behaves as expected with req and res logged in their separate fields.

In this picture, convertReqRes was set to true. As you can see response field is in HTTP, but req is not and the log is missing url and user_agent fields (maybe others as well).

Expected behavior

Correct format as shown in elastic/pino-http-logging

Thank you for your response, please let me know if this does not belong here.

Possible incorrect JSON representation of log.level for Pino log format

Using v1.3.0 of ecs-pino-format, I get the following output for a message:

{
  "log.level": "info",
  "@timestamp": "2021-08-26T14:45:06.489Z",
  "labels": {
    "env": "prod",
    "app": "test"
  },
  "service": {
    "name": "test"
  },
  "tags": [
    "audit"
  ],
  "ecs": {
    "version": "1.6.0"
  },
  "message": "Hello world"
}

But, it seems like log.level should be an Object instead of a string key, like:

{
  "log": {
    "level": "info"
  },
  "@timestamp": "2021-08-26T14:46:10.475Z",
  "labels": {
    "env": "prod",
    "app": "test"
  },
  "service": {
    "name": "test"
  },
  "tags": [
    "audit"
  ],
  "ecs": {
    "version": "1.6.0"
  },
  "message": "Hello world"
}

Below is the example program in TypeScript I was using to test:

import ecsFormat from "@elastic/ecs-pino-format";
import pino from "pino";

const log = pino({
  base: {
    labels: {
      env: "prod",
      app: "test",
    },
    service: {
      name: "test",
    },
    tags: ["audit"],
  },
  ...ecsFormat(),
});

log.info("Hello world");

http-formatters - socket not available

I have an instance where socket is not available from the request, therefore the following test fails within the http-formatters.js:

ecs.url.full = (socket.encrypted ? 'https://' : 'http://') + headers.host + url

Can this be updated to test for the existence of socket?

ecs.url.full = (socket && socket.encrypted ? 'https://' : 'http://') + headers.host + url

Can I help? :champagne:

Hi @trentm and other contributors !

I noticed some momentum around Node repositories in the @elastic organization, mostly this one and https://github.com/elastic/apm-agent-nodejs and I just wanted to propose my help. I've contributed already (elastic/apm-agent-nodejs#1909, elastic/apm-nodejs-http-client#117) and I do have a strong understanding of Elasticsearch concepts through more than 5 years using it in production, mostly with Node backends.

@stordata we're in the process of improving the observability of our apps (better logs, more detailed APM transactions, wider distributed tracing, etc.) and we'll be using use https://github.com/elastic/ecs-logging-js soon.

So, should you need any help making it towards a 1.0 release, just ask !

Regards,
David

formatHttpRequest sets url.path incorrectly

According to the ECS guide, url.path should be:

Path of the request, such as "/search".

However, formatHttpRequest sets url.path to the full url excluding the query and/or anchor:

  var hasQuery = url.indexOf('?')
  var hasAnchor = url.indexOf('#')
  if (hasQuery > -1 && hasAnchor > -1) {
    ecs.url.path = url.slice(0, hasQuery)
    ecs.url.query = url.slice(hasQuery + 1, hasAnchor)
    ecs.url.fragment = url.slice(hasAnchor + 1)
  } else if (hasQuery > -1) {
    ecs.url.path = url.slice(0, hasQuery)
    ecs.url.query = url.slice(hasQuery + 1)
  } else if (hasAnchor > -1) {
    ecs.url.path = url.slice(0, hasAnchor)
    ecs.url.fragment = url.slice(hasAnchor + 1)
  } else {
    ecs.url.path = url
  }

e.g. for the url "http://www.example.com/index.html?foo=bar", url.path will be set to "http://www.example.com/index.html", but it should be set to "/index.html".

"elasticApm.isStarted is not a function" crash while using @elastic/ecs-pino-format from elastic-apm-node

During the process of moving the Elastic APM agent over to using pino and this @elastic/ecs-pino-format package, we hit this crash:

/app/node_modules/@elastic/ecs-pino-format/index.js:55
  const apm = elasticApm && elasticApm.isStarted() ? elasticApm : null
                                       ^

TypeError: elasticApm.isStarted is not a function
    at createEcsPinoOptions (/app/node_modules/@elastic/ecs-pino-format/index.js:55:40)
    at Object.createLogger (/app/node_modules/elastic-apm-node/lib/logging.js:143:8)
    at new Config (/app/node_modules/elastic-apm-node/lib/config.js:243:27)
    at config (/app/node_modules/elastic-apm-node/lib/config.js:213:10)
    at Agent._config (/app/node_modules/elastic-apm-node/lib/agent.js:133:16)
    at new Agent (/app/node_modules/elastic-apm-node/lib/agent.js:39:8)
    at Object.<anonymous> (/app/node_modules/elastic-apm-node/index.js:5:18)
    at Module._compile (internal/modules/cjs/loader.js:1138:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1158:10)
    at Module.load (internal/modules/cjs/loader.js:986:32)

The reason is that the guarded import of the apm agent:

try {
  elasticApm = require('elastic-apm-node')
} catch (ex) {
  // Silently ignore.
}

results in elasticApm === {}, because this check is done before "elastic-apm-node" is loaded: require.cache includes:

  '/app/node_modules/elastic-apm-node/lib/agent.js': Module {
    id: '/app/node_modules/elastic-apm-node/lib/agent.js',
    path: '/app/node_modules/elastic-apm-node/lib',
    exports: {},
    parent: Module {
      id: '/app/node_modules/elastic-apm-node/index.js',
      path: '/app/node_modules/elastic-apm-node',
      exports: {},
      parent: [Module],
      filename: '/app/node_modules/elastic-apm-node/index.js',
      loaded: false,
      children: [Array],
      paths: [Array]
    },
    filename: '/app/node_modules/elastic-apm-node/lib/agent.js',
    loaded: false,
    children: [ [Module], [Module], [Module], [Module], [Module] ],
    paths: [
      '/app/node_modules/elastic-apm-node/lib/node_modules',
      '/app/node_modules/elastic-apm-node/node_modules',
      '/app/node_modules',
      '/node_modules'
    ]
  },

Note loaded: false and hence exports: {}.

This should be a situation that can only be hit if the elastic APM agent itself (or one the deps that it loads) uses ecs-pino-format. I'd like to fix this with two changes:

1. improve that guard to handle the loaded: false case
2. provide a config option to explicitly disable the APM integration with ecs-pino-format usage. I'll do this part in a separate PR. -> #62

Remove .log suffix from default event.dataset

Implement elastic/ecs-logging#63 for the nodejs ecs-logging libs.

rename repo to ecs-logging-nodejs

I'd like to rename this repo from ecs-logging-js to ecs-logging-nodejs. ECS-based structured logging for the browser with, AFAIK, no meaningful transport into the Stack, doesn't have value. Of the 3 current logging frameworks supported it is possible to use one (maybe two with a shoehorn) in the browser, but it really isn't their focus. The focus is node.js usage.

url is used instead of originalUrl in http-foramtters helper functions

I used morgan with ecsFormat to record http requests in elasticsearch, but the url field is not accurate.

app.use("/base", router);
router.get("/:service", (req, res, next) => {...})

In this example, req.url is /:service and req.originalUrl is /base/:service, because req.url is changed when the router is mounted to /base. formatHttpRequest helper function uses req.url when formatting url, so that baseUrl is ignored. It should use req.originalUrl instead of req.url.

Use safe-stable-stringify for perf and to support circular refs

The winston package updated it's stringification tool to fast-safe-stringify a while back at Jun 11, 2018.

I introduced here: #57. In it's PR I raised a this as a separate issue in one comment with notes. Pulling those in here for easy read:

When I attempt to use req and res as part of the formatting meta data I get a new error:
Sample express controller method:

  public async logging(req: Request, res: Response) {
    logger.info("Log endpoint activated", {
      req,
      res,
      labels: {
        transactionId: res.locals?.transactionId,
      },
    });
  }

Result:

TypeError: Converting circular structure to JSON
--> starting at object with constructor 'Socket'
| property '_writableState' -> object with constructor 'WritableState'
| property 'afterWriteTickInfo' -> object with constructor 'Object'
--- property 'stream' closes the circle

at JSON.stringify (<anonymous>)
at $main (eval at build (express-common/node_modules/fast-json-stringify/index.js:162:20), <anonymous>:345:51)
at Format.ecsStringifyTransform [as transform] (express-common/ecs-logging-nodejs/loggers/winston/index.js:149:19)

I tracked the cause down to:

function ecsStringifyTransform (info, opts) {
  info[MESSAGE] = stringify(info)
  return info
}

Where info contains Symbol(splat) which is {req: IncomingMessage, res: ServerResponse, labels: Object}, but there's a circular piece inside the req at several places because that's just Express. A little research showed me Use fast-safe-stringify for perf and to support circular refs #35 in winstonjs/winston changed their internal serialization agent to handle circular structure by moving to fast-safe-stringify. I checked the common helpers in this package and it looks like you're still using fast-json-stringify. Maybe that's somehow responsible for the difference?

A quick test swapping:

export const defaultOptions: LoggerOptions = {
  exitOnError: false,
  level: defaultLevel,
  format: format.combine(
    ecsFields({ convertReqRes: true }),
    new WinstonRedactFormatter({
      paths: ["http.request.headers.authorization"],
    }),
    // ecsStringify() // Bypass the ecsStringify
   format.json() // Use the winston standard json formatter
  ),
  transports: [new winston.transports.Console()],
};

Did indeed serial manage to output the correct format to the transporter:

{"labels":{"transactionId":"0c91f790-8083-44da-ac4d-91eedb51a130"},"message":"Log endpoint activated","@timestamp":"2021-04-08T14:49:59.724Z","log.level":"error","ecs":{"version":"1.6.0"},"http":{"version":"1.1","request":{"method":"GET","headers":{"host":"127.0.0.1:62723","accept-encoding":"gzip, deflate","user-agent":"node-superagent/3.8.3","authorization":"[REDACTED]","connection":"close"}},"response":{"status_code":200,"headers":{"x-powered-by":"Express","access-control-allow-origin":"*"}}},"url":{"full":"http://127.0.0.1:62723/logging-info","path":"/logging-info","domain":"127.0.0.1"},"client":{"address":"::ffff:127.0.0.1","ip":"::ffff:127.0.0.1","port":62724},"user_agent":{"original":"node-superagent/3.8.3"}}

Hiding sensitive request data when using convertReqRes

I'm currently using { convertReqRes: true } to fill out the ECS fields. Lovely addition, thanks for it!
But, I do have one problem. I've got some headers that shouldn't slip through to my Kibana users, such as authorization: bearer {token}.

I've got my own formatter for Winston I'm using after this one, and I can see the data you've produced at info Symbol(message), but not message. I can't actually get into Symbol(message), as it's private by design. How should I get that data obscured or removed?

event.id -> http.request.id in `formatHttpRequest`

ECS 1.9.0 formalizes http.request.id: https://github.com/elastic/ecs/releases/tag/v1.9.0

Currently formatHttpRequest will map req.id to event.id. That isn't documented or in the tests. Judgement call if that mandates a breaking change to remove.

rare test failure in CI: "tracing integration works"

We sometimes (but rarely) get this test hang/error when running in CI.
I haven't yet seen it in local dev.

> @elastic/[email protected] test /var/lib/jenkins/workspace/nodejs_ecs-logging-js-mbp_master/src/go.elastic.co/apm/ecs-logging-js/loggers/winston
> standard && tap --100 --timeout ${TAP_TIMEOUT:-10} test/*.test.js

TAP version 13
not ok 1 - test/apm.test.js # time=300096.871ms
  ---
  env: {}
  file: test/apm.test.js
  timeout: 300000
  command: /usr/local/bin/node
  args:
    - -r
    - /var/lib/jenkins/workspace/nodejs_ecs-logging-js-mbp_master/src/go.elastic.co/apm/ecs-logging-js/loggers/winston/node_modules/esm/esm.js
    - test/apm.test.js
  stdio:
    - 0
    - pipe
    - 2
  cwd: /var/lib/jenkins/workspace/nodejs_ecs-logging-js-mbp_master/src/go.elastic.co/apm/ecs-logging-js/loggers/winston
  failures:
    - tapError: no plan
  exitCode: null
  signal: SIGTERM
  ...
{
    # Subtest: tracing integration works
        ok 1 - should not error
        ok 2 - apmServerUrl: http://localhost:34201
        ok 3 - should be equal
        ok 4 - first listening log line has "address"
        ok 5 - should not error
        ok 6 - appUrl: http://localhost:38745
        ok 7 - should not error
        ok 8 - logObj is ECS valid
        ok 9 - should be equal
        ok 10 - should be equal
        ok 11 - should be equal
        ok 12 - empty stderr from app
        ok 13 - app exited 0
        ok 14 - traceObjs[0] is metadata
        ok 15 - traceObjs[1] is transaction
        ok 16 - traceObjs[2] is span
        ok 17 - trace.id matches
        ok 18 - transaction.id matches
        ok 19 - span.id matches
        ok 20 - should be equal
        ok 21 - should be equal
        not ok 22 - timeout!
          ---
          signal: SIGTERM
          handles:
            - type: Server
              events:
                - request
                - connection
              connectionKey: 6::::0
          expired: TAP
          stack: |
            emit (node_modules/signal-exit/index.js:78:11)
            process.listener (node_modules/signal-exit/index.js:92:7)
          test: tracing integration works
          ...
        
        1..22
        # failed 1 of 22 tests
    not ok 1 - tracing integration works # time=297190.283ms
    
    # test count(1) != plan(null)
    # failed 2 test
}

consider using `URL` for parsing in helpers.formatHttpRequest

Currently formatHttpRequest is manually doing URL parsing. I think using the standard url.URL for parsing would fix potential issues with weird URLs.

Also, in the case of a hapi request object, there is an already parsed request.url available. Express request objects might have the same thing. Not sure about other frameworks (e.g. fastify).

Winston error handling is incompatible with ecs-winston-format error handling

Winston allows error to be passed directly to a log message https://github.com/winstonjs/logform#errors, like winston.error(new Error()), while ecs-winston-format requires errors to be added to the ecs-specific err field, like winston.errror({ err : new Error() })

This has two side effects. The minor one is that one must refactor its own code to match the ecs guidelines. The more annoying side effect is that this will not work with Winston's special Exception https://github.com/winstonjs/winston#exceptions and Rejection https://github.com/winstonjs/winston#handling-uncaught-promise-rejections-with-winston handlers
These handlers will log errors via Winston's default error handling and cannot be refactored to use the special ecs handling. As such, those errors don't show up correctly in Elasticsearch, making them harder to detect.

Please make ecs-winston-format compatible with default winston error handling.

change formatError to not set `ecsFields.err` if the given `err` isn't an Error

Currently formatError in the helpers package does this:

function formatError (ecsFields, err) {
  if (!(err instanceof Error)) {
    ecsFields.err = err  // <--- this line
    return
  }

I.e. if err is an Error, then it will fill in ecsFields.error. Otherwise it will set ecsFields.err. But "err" isn't a spec'd ECS field, so it shouldn't do that. It should be up to the callers to handle this. This would also better match formatHttpRequest and formatHttpResponse which do not set ecsFields.req or .res if they cannot process the given value.

This will be a breaking change.

Setting message to empty string breaks formatting with pino-pretty

Hey there, I've just updated to version 1.1.0 (pino ) and it seems the change to set an empty message property breaks formatting.

I'm also using pino-pretty to format logs.

The issues seems to be here:

      const lastObj = this.lastObj
      const lastMsg = this.lastMsg
      const errorProps = null

      const formatters = lastLogger[formattersSym]
      const formattedObj = formatters.log ? formatters.log(lastObj) : lastObj 

      const messageKey = lastLogger[messageKeySym]
      if (lastMsg && formattedObj && !formattedObj.hasOwnProperty(messageKey)) {
        formattedObj[messageKey] = lastMsg
      }

lastObj is passed to the ecs log formatter which then sets a message property on it to empty string

the comment about the line above indicates the message as empty string is set because a message is not present on the object. However, from the code above, message has been separated from the rest of the log object and is not passed into the log formatter at all.

Also from the description of how the log formatter works - the message is intentionally not passed in.

The end result is that when the if statement runs if (lastMsg && formattedObj && !formattedObj.hasOwnProperty(messageKey)) {...} it always returns true because formattedObj now does have a message property.

Simple test case:

using the examples/express-simple.js in this repo - install pino-pretty and set prettyPrint: true on the logger config:

const log = pino({ ...ecsFormat({ convertReqRes: true }), prettyPrint: true })

then when running node express-simple.js you should see something like this (note message regarding the server listening is missing):

[timestamp] INFO:
    ecs: {
      "version": "1.6.0"
    }
    process: {
      "pid": ...
    }
    host: {
      "hostname": "..."
    }

I'm not 100% sure if this is a pino-pretty issue or an ecs format issue - but the update to 1.1.0 seems to have broken what was working so thought I'd raise it here.

consider parsing Forwarded/X-Real-Ip/X-Forwarded-For headers to client.ip

Currently helpers.formatHttpRequest mainly uses req.socket.remoteAddress for the "client.ip" ECS field. It could consider using some of the HTTP request headers (esp. X-Forwarded-For) to set this. If using Express, then req.ip is used which sometimes will use X-Forwarded-For, depending on user configuration.

Namespace defaultMeta with either labels or tags.

I noticed when I was working with the ECS NodeJS loggers that Metadata fields weren't name spaced.

I can see one of three scenario's:

1. Make the default namespace be labels per [https://www.elastic.co/guide/en/ecs/current/ecs-base.html](Base Fields)
2. Make the default namespace be tags per [https://www.elastic.co/guide/en/ecs/current/ecs-base.html](Base Fields)
3. Allow for a customized namespace via a configuration parameter.

Here's an example configuration:

const logger = winston.createLogger({
   format: ecsFormat(),
   level: "debug",
   defaultMeta: {
      defaultMeta: {
         'environment': 'dev'
      }
   },
   transports: [
      new winston.transports.Console()
   ]
})

and a resulting output:

{
   "@timestamp": "2021-08-20T15:43:32.147Z",
   "log.level": "debug",
   "message": "Example with the default Meta Data fields.",
   "ecs": {
      "version": "1.6.0"
   },
   "environment": "dev"
}

`http.request.id` field from ECS 1.9

When ECS 1.9 comes out it will have a http.request.id field (elastic/ecs#1208) which some of the logging libs in this repo will want to consider.

node:16 docker run in the CI uses node8

See Trent's comment -> #111 (comment)

I tried to reproduce the error locally with:

docker run --rm -ti -v $(pwd):/app node:16 /bin/bash
$ cd /app
$ .ci/run-install.sh
$ .ci/run-test.sh

but it worked

[@elastic/ecs-pino-format] support for pino 7+

It appears that @elastic/ecs-pino-format does not work with pino 7+

add support for tracing fields

The ECS log formatters should detect usage of Elastic APM (the elastic-apm-node package) and add tracing fields (https://www.elastic.co/guide/en/ecs/current/ecs-tracing.html) to log records if there is an active trace.

doubt: are there plans to add type definitions?

Are there plans to add type definitions?

Uncaught Error: Cannot find module 'morgan'

To reproduce this issue

npm install morgan
npm install @elastic/ecs-morgan-format

then in node

ip-192-168-178-30:webservice loretoparisi$ node
Welcome to Node.js v14.17.3.
Type ".help" for more information.
> const morgan = require('morgan');
undefined
> morgan
[Function: morgan] {
  compile: [Function: compile],
  format: [Function: format],
  token: [Function: token],
  combined: ':remote-addr - :remote-user [:date[clf]] ":method :url HTTP/:http-version" :status :res[content-length] ":referrer" ":user-agent"',
  common: ':remote-addr - :remote-user [:date[clf]] ":method :url HTTP/:http-version" :status :res[content-length]',
  default: [Getter/Setter],
  short: ':remote-addr :remote-user :method :url HTTP/:http-version :status :res[content-length] - :response-time ms',
  tiny: ':method :url :status :res[content-length] - :response-time ms',
  dev: [Function: developmentFormatLine],
  url: [Function: getUrlToken],
  method: [Function: getMethodToken],
  'response-time': [Function: getResponseTimeToken],
  'total-time': [Function: getTotalTimeToken],
  date: [Function: getDateToken],
  status: [Function: getStatusToken],
  referrer: [Function: getReferrerToken],
  'remote-addr': [Function: getip],
  'remote-user': [Function: getRemoteUserToken],
  'http-version': [Function: getHttpVersionToken],
  'user-agent': [Function: getUserAgentToken],
  req: [Function: getRequestToken],
  res: [Function: getResponseHeader]
}
> const ecsFormat = require('@elastic/ecs-morgan-format')
Uncaught Error: Cannot find module 'morgan'
Require stack:
- /node_modules/@elastic/ecs-morgan-format/index.js
- <repl>
    at Function.Module._resolveFilename (internal/modules/cjs/loader.js:902:15)
    at Function.Module._load (internal/modules/cjs/loader.js:746:27)
    at Module.require (internal/modules/cjs/loader.js:974:19)
    at require (internal/modules/cjs/helpers.js:92:18) {
  code: 'MODULE_NOT_FOUND',
  requireStack: [
    '/node_modules/@elastic/ecs-morgan-format/index.js',
    '<repl>'
  ]
}
> 

and the same happens in a express app.

I have both morgan and @elastic/ecs-morgan-format installed in node_modules folder.

update loggers to use the bool retval of formatError, formatHttpRequest, and formatHttpResponse

Now that formatError, formatHttpRequest, and formatHttpResponse return a bool for whether they processed the field, the loggers should use that to pass through unprocessed fields on the log record. Currently logging a req field that isn't an HTTP request will (a) blow up in v1.0.0, (b) silently drop the "req" field in v1.1.0. I think a future version should log that req field unchanged.

[@elastic/ecs-winston-format] Missing `triple-beam` dependency

loggers/winston/index.js file use triple-beam dependency that's not included in package.json dependencies:

...
const { MESSAGE } = require('triple-beam')
...

Steps to reproduce

1. yarn init -y
2. yarn set version berry
3. yarn add @elastic/ecs-winston-format winston
4. Create index.js file

const winston = require('winston')
const ecsFormat = require('@elastic/ecs-winston-format')

const logger = winston.createLogger({
  level: 'info',
  format: ecsFormat(),
  transports: [
    new winston.transports.Console()
  ]
})

logger.info('test1')

5. yarn node index

C:\test-ecs-winston\.pnp.cjs:10188
    throw firstError;
    ^

Error: @elastic/ecs-winston-format tried to access triple-beam, but it isn't declared in its dependencies; this makes the require call ambiguous and unsound.

Required package: triple-beam
Required by: @elastic/ecs-winston-format@npm:1.3.1 (via C:\test-ecs-winston\.yarn\cache\@elastic-ecs-winston-format-npm-1.3.1-8fc543f859-49a7767c64.zip\node_modules\@elastic\ecs-winston-format\)

Require stack:
- C:\test-ecs-winston\.yarn\cache\@elastic-ecs-winston-format-npm-1.3.1-8fc543f859-49a7767c64.zip\node_modules\@elastic\ecs-winston-format\index.js
- C:\test-ecs-winston\index.js
    at Function.external_module_.Module._resolveFilename (C:\test-ecs-winston\.pnp.cjs:10187:55)       
    at Function.external_module_.Module._load (C:\test-ecs-winston\.pnp.cjs:9986:48)
    at Module.require (internal/modules/cjs/loader.js:957:19)
    at require (internal/modules/cjs/helpers.js:88:18)
    at Object.<anonymous> (C:\test-ecs-winston\.yarn\cache\@elastic-ecs-winston-format-npm-1.3.1-8fc543f859-49a7767c64.zip\node_modules\@elastic\ecs-winston-format\index.js:20:21)
    at Module._compile (internal/modules/cjs/loader.js:1068:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1097:10)
    at Module.load (internal/modules/cjs/loader.js:933:32)
    at Function.external_module_.Module._load (C:\test-ecs-winston\.pnp.cjs:10036:14)
    at Module.require (internal/modules/cjs/loader.js:957:19)

Workaround

Add in .yarnrc.yml:

packageExtensions:
  '@elastic/ecs-winston-format@*':
    dependencies:
      triple-beam: '*'

Run yarn.

notes on using express-winston and @elastic/ecs-winston-format

I did some exploration of using @elastic/ecs-winston-format here with the express-winston middleware package. I'll collect notes here in case they are useful for:

1. anyone that wants to use these two modules together; and
2. possible future dev work to integrate support and/or docs for this.

Currently I'm not proposing integrating docs about using express-winston with @elastic/ecs-winston-format because I don't think it is a very satisfying integration (at least not yet).