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

[trentm]

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.

[trentm]

I'm not sure if that shows up in filebeat logs,

Yes, for example, these log statements:

log.info({ service: 'hi' }, 'service in fields')
log.info({ event: 'hi' }, 'event in fields')

yielding (currently) these log records:

{"log.level":"info","@timestamp":"2021-03-23T19:18:00.793Z","process":{"pid":60565},"host":{"hostname":"pink.local"},"service":"hi","ecs":{"version":"1.6.0"},"message":"service in fields"}
{"log.level":"info","@timestamp":"2021-03-23T19:18:00.794Z","process":{"pid":60565},"host":{"hostname":"pink.local"},"event":"hi","ecs":{"version":"1.6.0"},"message":"event in fields"}

result in this in the filebeat log:

2021-03-23T12:18:10.615-0700    WARN    [elasticsearch] elasticsearch/client.go:408 Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0x2f443840, ext:63752123880, loc:(*time.Location)(nil)}, Meta:null, Fields:{"agent":{"ephemeral_id":"a61be671-76e2-4b78-8d15-664d0560c81a","hostname":"pink.local","id":"b03f7253-b0fb-466b-83c3-8cedce1060dd","name":"pink.local","type":"filebeat","version":"7.12.0"},"ecs":{"version":"1.6.0"},"host":{"architecture":"x86_64","hostname":"pink.local","id":"DF529BD4-274A-53F1-A84E-7F85AFD59258",...,"input":{"type":"log"},"log":{"file":{"path":"/var/log/trentm.log"},"level":"info","offset":6582},"message":"service in fields","process":{"pid":60565},"service":"hi"}, Private:file.State{Id:"native::19530632-16777221", PrevId:"", Finished:false, Fileinfo:(*os.fileStat)(0xc000ad8820), Source:"/var/log/trentm.log", Offset:6771, Timestamp:time.Time{wall:0xc00ead7f6441e7f8, ext:140553425980, loc:(*time.Location)(0x8a4b140)}, TTL:-1, Type:"log", Meta:map[string]string(nil), FileStateOS:file.StateOS{Inode:0x12a0388, Device:0x1000005}, IdentifierName:"native"}, TimeSeries:false}, Flags:0x1, Cache:publisher.EventCache{m:common.MapStr(nil)}} (status=400): {"type":"mapper_parsing_exception","reason":"object mapping for [service] tried to parse field [service] as object, but found a concrete value"}
2021-03-23T12:18:10.615-0700    WARN    [elasticsearch] elasticsearch/client.go:408 Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0x2f537a80, ext:63752123880, loc:(*time.Location)(nil)}, Meta:null, Fields:{"agent":{"ephemeral_id":"a61be671-76e2-4b78-8d15-664d0560c81a","hostname":"pink.local","id":"b03f7253-b0fb-466b-83c3-8cedce1060dd","name":"pink.local","type":"filebeat","version":"7.12.0"},"ecs":{"version":"1.6.0"},"event":"hi","host":{"architecture":"x86_64","hostname":"pink.local","id":"DF529BD4-274A-53F1-A84E-7F85AFD59258",...,"input":{"type":"log"},"log":{"file":{"path":"/var/log/trentm.log"},"level":"info","offset":6771},"message":"event in fields","process":{"pid":60565}}, Private:file.State{Id:"native::19530632-16777221", PrevId:"", Finished:false, Fileinfo:(*os.fileStat)(0xc000ad8820), Source:"/var/log/trentm.log", Offset:6956, Timestamp:time.Time{wall:0xc00ead7f6441e7f8, ext:140553425980, loc:(*time.Location)(0x8a4b140)}, TTL:-1, Type:"log", Meta:map[string]string(nil), FileStateOS:file.StateOS{Inode:0x12a0388, Device:0x1000005}, IdentifierName:"native"}, TimeSeries:false}, Flags:0x1, Cache:publisher.EventCache{m:common.MapStr(nil)}} (status=400): {"type":"mapper_parsing_exception","reason":"object mapping for [event] tried to parse field [event] as object, but found a concrete value"}

Or, for short:

...status=400... object mapping for [service] tried to parse field [service] as object, but found a concrete value"}
...status=400... object mapping for [event] tried to parse field [event] as object, but found a concrete value"}

[lukeelmers]

In Kibana's logging system, we use TypeScript to prevent situations like this (we have a set of typedefs for ECS exposed from core). TS will prevent folks from providing any values that aren't ECS-compliant when logging something from Kibana, but they can still override this via a generic type parameter that extends from ECS:

logger.warn('some message', { ...some ECS-compliant metadata });

interface MyCustomMeta extends Ecs {
  customField: boolean;
}

logger.warn<MyCustomMetadata>('some message', { customField: true, ...some ECS-compliant metadata });

Of course, this only works for us because most of Kibana is already written in TypeScript, and it probably doesn't make sense for a lib like ecs-logging.

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

We've discussed moving in this direction eventually as well. Kibana's audit logging implementation currently uses a dedicated kibana namespace for any custom ECS fields. Eventually we may try doing this with all of our logs as it would make maintenance much easier; it's just a tricky thing to manage with a plugin-based architecture like ours where things are so spread out.

[felixbarny]

It's a tricky one. I think we don't want to penalize legitimate use cases of adding ECS-compliant additional properties, such as log.info({ 'event.outcome': 'success' }, 'it worked!').

To make constructing ECS-compliant objects easier, we could generate ECS TypeScript interfaces.

But ideally, we'd still allow adding arbitrary structured metadata to logs. Conflicts are definitely a concern, however. Maybe we could map dynamic fields as flattened rather than object by default.

[rdifrango]

Per @trentm moving #97 here as additional requirements:

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"
}

[felixbarny]

I have recently been thinking about this again and have discussed with other teams within Elastic. Here's what we came up with:

• Elasticsearch could automatically apply mappings for ECS fields. This means that logs with custom fields that conflict with ECS fields would be rejected so that they don't corrupt the mapping. All non-ECS fields will be mapped as runtime fields by default. This ensures custom fields can't cause mapping conflicts. The tradeoff is that searching on these fields would be slower. But users can customize the mapping to start indexing specific fields. See also https://github.com/elastic/elasticsearch/issues/85692
• Logs that can't be indexed (for example due to a mapping conflict or because the ingest pipeline threw an exception) will be put into a dead letter queue. This queue is searchable (fields are runtime mapped) and the events in the queue can be replayed. See also https://github.com/elastic/elasticsearch/issues/86170

I think this would reconcile the requirements to easily add custom fields but avoid conflicts and data loss.

Adding typescript types for ECS is still a good idea but orthogonal.

[felixbarny]

Also related: https://github.com/elastic/elasticsearch/issues/88777

[pushred]

I'm a user who stumbled on this thread after implementing a number of ECS fields in my logs using ecs-format-pino and a Pino mixin to expand the fields and handle some that do not work out of the box in my case, an AWS Lambda application. This includes fields such as event, http, and url that the library adds now in some cases.

From what I see in the source event.dataset will be added into an existing event object if it already exists:

https://github.com/elastic/ecs-logging-nodejs/blob/08cbec44c00aaeed2f27871d1766e89ac3847520/loggers/pino/index.js#L185-L186

service has similar handling. Not sure if I am overlooking something where this wouldn't address the original examples and some cases in my own implementation.

Before I proceed any further I wanted to ask whether users should not be implementing ECS fields on their own, when using this library? Or we should do so only if accepting the risk that logs may not be ingested due to a conflict? I'm unsure what the conflict would be exactly with the above handling though. Seems like something that should be in the docs.

In my case I am tempted to derive my own formatter from this project to avoid any possibility of conflict while being able to enrich our logs with as much ECS metadata as we can. From what has been discussed in this thread it appears that the original intent of this library was to abstract ECS away.

[trentm]

@pushred This library hasn't made a clear decision on this. I think -- it has been a while, I'd have to look again -- some of the ecs-logging-... libraries for other languages have done something like put all user log record fields under some top-level field to avoid any possible conflicts with ECS fields or with the ECS schema.

Currently the ecs-logging-nodejs formatters are punting on the problem: while they attempt to be careful when they add fields to (a) follow the ECS schema and (b) not blow away any data added by the user; there is still the issue that if a user adds, say, cloud: "this is a string" field... it conflicts with https://www.elastic.co/guide/en/ecs/current/ecs-cloud.html and some part of an ECS document formatting pipeline could reject/drop the document.

Punting on the issue is poor. I haven't had a chance for a while to wade back into this and try to decide whether these formatters should:

1. put all/most user fields under a top-level "custom." or "label." namespace (See notes at https://www.elastic.co/guide/en/ecs-logging/overview/current/intro.html#_custom_fields)
2. Document that it is the user's responsibility to have their fields either match ECS fields or ensure custom fields don't conflict -- whether with custom. or label. prefixing or other things like Capitalization or Proper Names as mentioned at https://www.elastic.co/guide/en/ecs/master/ecs-custom-fields-in-ecs.html#_capitalization
3. Or provide config options to support both ways. @pushred You sound like a user that is fine handling option (2). For many users, I'd expect needing to grok the many ECS fields would be too much. As well, there is a potential APM agent feature to automatically re-format an application's logger formatters to ECS format (opt-in). That feature would require something like (1) to avoid conflicts automatically.

[pushred]

Got it, thanks for the update and summary. In my case I was forced to add some fields — client http url user_agent — that I knew wouldn't be supported out of the box in my Lambda use case. And I was aware of ECS and opted to follow that spec rather than define something altogether new. event was more aspirational, I think that I will defer usage of that to a time where a need is more evident and my team can decide whether they want to use it.

For these fields that can be populated when convertReqRes is enabled it would be my preference that I could set those fields in an explicit way, for my case where I don't have requests/responses represented as instances of http.IncomingMessage and http.ServiceResponse but still have most if not all the same data and want it defined in ECS fields rather than a custom namespace that would vary from non-Lambda services. But that is probably a Lambda-specific issue. I'll open an issue about that.