Skip to content

Plaintext slow logs with multiline causing problems when parsing #38080

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
pgomulka opened this issue Jan 31, 2019 · 3 comments · Fixed by #38081
Closed

Plaintext slow logs with multiline causing problems when parsing #38080

pgomulka opened this issue Jan 31, 2019 · 3 comments · Fixed by #38081
Labels
:Core/Infra/Logging Log management and logging utilities v6.7.0 v7.0.0-beta1

Comments

@pgomulka
Copy link
Contributor

pgomulka commented Jan 31, 2019

In order to keep the parsing logic consistent across docker and standard deployments, Beats is distinguishing the type of logs (JSON or plaintext) by the first character in a line.
If the first character is '{' then the JSON logging will be applied, otherwise the plaintext one.

Slow logs contain source field which wraps the json. When the index.indexing.slowlog.reformat: false is set, it will print the JSON as the user provided. Could be that the first line being \n.
The plaintext log will end up like this:

[2018-07-04T21:51:30,411][INFO ][index.indexing.slowlog.index] [v_VJhjV] [metricbeat-6.3.0-2018.07.04/VLKxBLvUSYuIMKzpacGjRg] took[1.7ms], took_millis[1], type[doc], id[s01HZ2QBk9jw4gtgaFtn], routing[], source[
{
  "@timestamp":"2018-07-04T21:27:30.730Z",
  "metricset":{
    "name":"network",
    "module":"system",
    "rtt":7264},
    "system":{
      "network":{
        "name":"lo0",
        "in":{
          "errors":0,
          "dropped":0,
          "bytes":77666873,
          "packets":244595},
          "out":{
            "packets":244595,
            "bytes":77666873,
            "errors":0,
            "dropped":0
          }
        }
      },
      "beat":{
        "name":"Rados-MacBook-Pro.local",
        "hostname":"Rados-MacBook-Pro.local",
        "version":"6.3.0"
      },
      "host":{
        "name":"Rados-MacBook-Pro.local"
      }
    }]

This is causing problems for beats, as previously mentioned the first character in a line being { means it will try parse it as a JSON

The easiet approach will be to remove the \n at the beginning so that the first { ends up on the previous line

[2018-07-04T21:51:30,411][INFO ][index.indexing.slowlog.index] [v_VJhjV] [metricbeat-6.3.0-2018.07.04/VLKxBLvUSYuIMKzpacGjRg] took[1.7ms], took_millis[1], type[doc], id[s01HZ2QBk9jw4gtgaFtn], routing[], source[{
  "@timestamp":"2018-07-04T21:27:30.730Z",
...
...
}

The other approach would be to escape the JSON, but that would make it leas readable. Even less readable in *.json logs (escaping twice)

We should also schedule work to extract these fields into top level JSON fields in *.json logs

the original discussion on beats PR
https://github.com/elastic/beats/pull/10447/files#r252512969

@pgomulka pgomulka added the :Core/Infra/Logging Log management and logging utilities label Jan 31, 2019
@pgomulka pgomulka self-assigned this Jan 31, 2019
@elasticmachine
Copy link
Collaborator

Pinging @elastic/es-core-infra

@pgomulka
Copy link
Contributor Author

@ycombinator should we back port this to 6.x?

@ycombinator
Copy link
Contributor

I think it would be nice if we could backport it to 6.x (6.7.0). That way Filebeat 7.0 (where this issue really comes into play; see https://github.com/elastic/beats/pull/10447/files#r252512969) could work successfully with ES 6.7.0 logs as well.

pgomulka added a commit that referenced this issue Feb 1, 2019
The '{' as a first character in log line is causing problems for beats when parsing plaintext logs. This can happen if the submitted document has an additional '\n' at the beginning and we are not reformatting. 
Trimming the source part of a SlogLog solves that and keeps the logs readable.

closes #38080
pgomulka added a commit to pgomulka/elasticsearch that referenced this issue Feb 1, 2019
The '{' as a first character in log line is causing problems for beats when parsing plaintext logs. This can happen if the submitted document has an additional '\n' at the beginning and we are not reformatting. 
Trimming the source part of a SlogLog solves that and keeps the logs readable.

closes elastic#38080
pgomulka added a commit that referenced this issue Feb 1, 2019
The '{' as a first character in log line is causing problems for beats when parsing plaintext logs. This can happen if the submitted document has an additional '\n' at the beginning and we are not reformatting.
Trimming the source part of a SlogLog solves that and keeps the logs readable.

relates #38080
backport #38081
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
:Core/Infra/Logging Log management and logging utilities v6.7.0 v7.0.0-beta1
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants