Provide opt-in flag to avoid fields name clash when log format is json

[andsel]

Release notes

Exposes log.format.json.fix_duplicate_message_fields flag to avoid collision of field names in log lines when log.format is JSON.

What does this PR do?

Adds log.format.json.fix_duplicate_message_fields feature flag to rename the clashing fields when json logging format (log.format) is selected.
In case two message fields clashes on structured log message, then the second is renamed attaching _1 suffix to the field name.
By default the feature is disabled and requires user to explicitly enable the behaviour.
The PR provides description of the flag only in the throuble shooting section, and not in general description of all the command line flags and settings (

logstash/docs/static/settings-file.asciidoc

Line 335 in 59bd376

| `log.format`

).
In this way the flag can be deprecated or dropped more easily and the behaviour enabled by default.

Why is it important/What is the impact to the user?

A user that enables json log format for their Logstash's logs could stumble on a problem to have two message fields in the same json document. Despite this is a valid json, is not common practice and could lead to confusion: which is the effective log message body and which is the field?
With this PR the user can choose to enable a stricter behaviour when encounter such problem.

Checklist

• My code follows the style guidelines of this project
• I have commented my code, particularly in hard-to-understand areas
• I have made corresponding changes to the documentation
• [ ] I have made corresponding change to the default configuration files (and/or docker env variables)
• I have added tests that prove my fix is effective or that my feature works

Author's Checklist

• road test

How to test this PR locally

1. run logstash with

bin/logstash -e "input {stdin{codec => json}} output{stdout{}}" --log.format json --log.format.json.fix_duplicate_message_fields true

2. type some invalid input to trigger https://github.com/logstash-plugins/logstash-codec-json/blob/d2b10edf9a63646e17e60de8c77b51ca81614c73/lib/logstash/codecs/json.rb#L84

{"name": [}

3. verify in console the json logs contains both message and message_1 fields.

{
   "level":"WARN",
   "loggerName":"logstash.codecs.jsonlines",
   "timeMillis":1710838609569,
   "thread":"[main]<stdin",
   "logEvent":{
      "message":"JSON parse error, original data now in message field",
      "message_1":"Unexpected close marker '}': expected ']' (for Array starting at [Source: (String)\"{\"name\": [}\"; line: 1, column: 10])\n at [Source: (String)\"{\"name\": [}\"; line: 1, column: 12]",
      "exception":"LogStash::Json::ParserError",
      "data":"{\"name\": [}"
   }
}

Related issues

• Closes json logging can log duplicate message fields #14335

Use cases

Screenshots

Logs

[andsel]

Notes

After discussion with team, the proposal is to avoid adding an extra layer, which potentially could be a breaking change.
Instead, postfix duplicated field names, so that message is the core message field, if there is a second clashing message field as log parameter, then rename it as message_1.
Make this feature enabled by feature flag.

[robbavey]

Some suggestions on naming

Plus, can we add the setting, and what it does to the logstash.yml and command-line docs pages?

[andsel]

@robbavey do you think we should also add the setting in the logstash.yml that we ship with the distribution:

logstash/config/logstash.yml

Line 316 in cc1eca9

# log.format: plain

Like we do for log.format ?

[robbavey]

do you think we should also add the setting in the logstash.yml that we ship with the distribution:

Yes, that's a great idea.

[robbavey]

LGTM, other than a couple of doc nits

[elastic-sonarqube]

Quality Gate passed

Kudos, no new issues were introduced!

0 New issues
0 Security Hotspots
No data about Coverage
0.0% Duplication on New Code

See analysis details on SonarQube

[edmocosta]

Although it's very unlikely to happen, wouldn't the static name message_1 be prone to value overrides in case some log, containing the message_1 key, is logged? for example: logger.info('this is test', :message => 'bar', :message_1' => 'foo') or logger.info('this is test', hash_with_messages_keys).

[andsel]

logger.info('this is test', :message => 'bar', :message_1' => 'foo')

It's possibile but little bit unrealistic given that those logger invocations come from code the inside Logstash code base.

logger.info('this is test', hash_with_messages_keys)

This could be a problem, where hash_with_messages_keys id something like

{ "message": "blalba", "message_1": "blabla 1" }

and it's out of code control.

In general, whatever policy we apply to avoid collision, for example move the duplicate field in some nested map, it is subject to this latest problem you are exposing, because maps can overlap on root names, but also on nested structures.

[elasticmachine]

💚 Build Succeeded

• Buildkite Build
• Commit: 0980772

History

• 💚 Build #1044 succeeded d6517e0
• 💚 Build #1043 succeeded da53b5c
• 💚 Build #1038 succeeded 706dd26
• 💚 Build #1037 succeeded 5852c4b
• 💚 Build #1036 succeeded 9237560
• 💚 Build #966 succeeded 0f108de

cc @andsel

[andsel]

@logstashmachine backport 8.14