Allow Logstash to write its logs in JSON format #4820

jordansissel · 2016-03-15T21:48:56Z

This is made available by a --log-in-json flag. Default is false.
When false, the old behavior [1] is used.

When true, JSON logs are emitted.

[1] The old behavior is realy two things. First, using Object#inspect to
serialize. Second, to color the output if the IO is a tty.

For #1569

suyograo · 2016-03-15T22:15:28Z

logstash-core/lib/logstash/runner.rb

@@ -90,6 +90,10 @@ class LogStash::Runner < Clamp::Command
    I18n.t("logstash.web_api.flag.http_port"),
    :attribute_name => :web_api_http_port, :default => 9600

+  option ["--[no-]log-in-json"], :flag,


Thoughts about renaming this flag to --logger.format to make it future proof for setting.yml? This way it translates easily to yml.. See #4499 /cc @jsvd

to be consistent, this pr should add the flag according to the current state of master. right now it should use "-", but if it happens to be merged after logstash.yml, then the pr needs to be changed

jordansissel · 2016-04-18T20:05:23Z

Rebased.

jordansissel · 2016-04-18T20:07:00Z

Hand-test that it still works post-rebase:

% bin/logstash --log-in-json -f /tmp/nonexistant
{"timestamp":"2016-04-17T10:46:13.551000-0700","message":"No config files found: /tmp/nonexistant\nCan you make sure this path is a logstash config file?","level":"error"}

suyograo · 2016-04-18T20:07:00Z

logstash-core/lib/logstash/runner.rb

@@ -102,6 +102,10 @@ class LogStash::Runner < Clamp::Command
    I18n.t("logstash.runner.flag.allow-env"),
    :attribute_name => :allow_env, :default => false

+  option ["--[no-]log-in-json"], :flag,
+         I18n.t("logstash.agent.flag.log-in-json"),


Translation missing in yml file?

Will fix this. Good catch.

jordansissel · 2016-04-20T18:03:08Z

Added tests

jordansissel · 2016-04-20T18:07:45Z

Added help text:

    --[no-]log-in-json            Specify that Logstash should write its own logs in JSON form - one
                                  event per line. If false, Logstash will log using Ruby's
                                  Object#inspect (not easy to machine-parse)
                                   (default: false)

jordansissel · 2016-04-20T18:15:00Z

Squashed to a single commit.

ph · 2016-04-20T19:04:23Z

@jordansissel I saw we are targeting this for 5.0 But I am wondering if we should merge it in 2.3.X as an experimental flag?

jordansissel · 2016-04-20T19:07:42Z

@ph I'd be ok merging this into 2.3 and 2.x as a flag that defaults to the old behavior. We can have a new PR later that enables JSON by default in master. Thoughts?

jordansissel · 2016-04-20T19:08:28Z

http://build-eu-00.elastic.co/job/Logstash_PR/2671/testReport/ -- Failing tests seem unrelated to this PR.

ph · 2016-04-20T19:21:24Z

@jordansissel
yes +1 to making this this teh default logging mode in 5.0
+1 Make it a flag for 2.X 2.3.

ph · 2016-04-20T19:22:39Z

@jordansissel Yes the faillure are unrelated. I think its time to make a PR on flores with https://github.com/logstash-plugins/logstash-input-beats/blob/master/spec/support/flores_extensions.rb#L29 ;)

jordansissel · 2016-04-20T19:33:37Z

@ph ok cool. I'll target this for 2.x, 2.4, 5.0, and master

jordansissel · 2016-04-20T19:53:47Z

Summarizing some offline discussion between @ph, @suyograo, and myself.

Given this is a new feature, we'll target this to Logstash 2.4.0 insetad of 2.3.2 because it's a feature, not a bug fix.

jordansissel · 2016-04-20T19:53:57Z

Merge targets: 2.x, 2.4, 5.0, master

ph · 2016-04-21T14:59:07Z

@jordansissel I found our first serialization errors when running logstash in debug mode.

{"timestamp":"2016-04-21T10:58:04.833000-0400","message":"* Environment: development","level":"debug","file":"logstash/webserver.rb","line":"55","method":"log"}
LogStash::Json::GeneratorError: Cannot serialize instance of: LogStash::Json::GeneratorError
      jruby_dump at /Users/ph/es/logstash/logstash-core/lib/logstash/json.rb:52
              << at /Users/ph/es/logstash/logstash-core/lib/logstash/logging/json.rb:14
              << at /Users/ph/es/logstash/vendor/bundle/jruby/1.9/gems/cabin-0.8.1/lib/cabin/subscriber.rb:10
         publish at /Users/ph/es/logstash/vendor/bundle/jruby/1.9/gems/cabin-0.8.1/lib/cabin/channel.rb:196
            each at org/jruby/RubyHash.java:1342
         publish at /Users/ph/es/logstash/vendor/bundle/jruby/1.9/gems/cabin-0.8.1/lib/cabin/channel.rb:193
     synchronize at org/jruby/ext/thread/Mutex.java:149
         publish at /Users/ph/es/logstash/vendor/bundle/jruby/1.9/gems/cabin-0.8.1/lib/cabin/channel.rb:192
            _log at /Users/ph/es/logstash/vendor/bundle/jruby/1.9/gems/cabin-0.8.1/lib/cabin/mixins/logger.rb:113
  log_with_level at /Users/ph/es/logstash/vendor/bundle/jruby/1.9/gems/cabin-0.8.1/lib/cabin/mixins/logger.rb:90
           fatal at /Users/ph/es/logstash/vendor/bundle/jruby/1.9/gems/cabin-0.8.1/lib/cabin/mixins/logger.rb:75
         execute at /Users/ph/es/logstash/logstash-core/lib/logstash/runner.rb:231
             run at /Users/ph/es/logstash/vendor/bundle/jruby/1.9/gems/clamp-0.6.5/lib/clamp/command.rb:67
             run at /Users/ph/es/logstash/vendor/bundle/jruby/1.9/gems/clamp-0.6.5/lib/clamp/command.rb:132
          (root) at /Users/ph/es/logstash/lib/bootstrap/environment.rb:72

ph · 2016-05-06T18:42:49Z

rakelib/test.rake

+      out = File.new("/dev/null", "a")
+      logger.subscribe(LogStash::Logging::JSON.new(out))
+      logger.level = :debug
+    end


This will surely fails on windows, we can make it cross platform if we can create a dummy io object that implement the minimal interface to be an IO object but doesn't actually write anything to disk.

OR we can use this, which will make a null stream, I believe it will work on windows but I havent tested it?

File.open(File::NULL, "w")

I am a bit confused, why we need this code and the code in spec_helper?

Agreed. this setup_json_logging was an older implementation of what is now in spec_helper.

I removed it now.

ph · 2016-05-09T13:18:26Z

Changes LGTM, small comment concerning the use of /dev/null, I think we can go ahead with this.
@jordansissel Running the all plugins tests will probably discover some other issues in the plugins for the serialization that we need to fix.

andrewvc · 2016-05-09T16:34:51Z

Regarding the serialization to_s issue @ph and @guyboertje have been discussing I think

recursing is fine but we should never call inspect. Inspect can:

Generate massive output by accident
Leak passwords if they're linked in the object graph (this has happened multiple times!)

Ultimately we should strive for a whitelist approach to log inclusion IMHO. I wouldn't even mind it if we traversed plain ruby Hash and Array objects, invoking .to_s on everything else.

guyboertje · 2016-05-09T17:27:27Z

Just so people know what JrJackson does do...
It knows how the serialize the following:
String
Float
BigDecimal
Time
Array
Hash
Fixnum
Bignum
Date
Symbol
Struct
TrueClass
FalseClass
(I will be adding Exception/Error and Class)

If it finds an object class not in the above list then it tries to invoke these methods, in order, on the object:
to_json_data
to_time
to_h
to_hash
to_a
to_json

Why to_json last?
Because, for the best performance, I do not want a JSON string in this case, I want JSON data structures so Jackson can continue with caching and memoising. This is why to_json_data is first - I want an object author to give me a data structure.
When authors write a to_json method, they very often will write:

def to_json
  JSON.dump(some_structure)
end

This will suspend the JrJackson session, call the JSON library, and return a string for JrJackson to append.

ph · 2016-05-09T19:53:34Z

LGTM @jordansissel

This is made available by a new `--log-in-json` flag. Default is false. When false, the old behavior [1] is used. When true, JSON logs are emitted. [1] The old behavior is realy two things. First, using Object#inspect to serialize. Second, to color the output if the IO is a tty. Fixes #1569

Use an internal subscriber to verify that JSON output is valid JSON. The purpose is to catch any json serialization errors that would occur while logging. Also had to update a few logger calls to log values that could be serialized (Class instances and similar, at this time, fail to serialize to JSON).

elasticsearch-bot · 2016-05-09T19:56:03Z

Jordan Sissel merged this into the following branches!

Branch	Commits
master	`af41218`, `f241dd8`, `07887f8`
5.0	`755e4b5`, `3fa057e`, `682194b`

This is made available by a new `--log-in-json` flag. Default is false. When false, the old behavior [1] is used. When true, JSON logs are emitted. [1] The old behavior is realy two things. First, using Object#inspect to serialize. Second, to color the output if the IO is a tty. Fixes #1569 Fixes #4820

Use an internal subscriber to verify that JSON output is valid JSON. The purpose is to catch any json serialization errors that would occur while logging. Also had to update a few logger calls to log values that could be serialized (Class instances and similar, at this time, fail to serialize to JSON). Fixes #4820

Fixes #4820

Use an internal subscriber to verify that JSON output is valid JSON. The purpose is to catch any json serialization errors that would occur while logging. Also had to update a few logger calls to log values that could be serialized (Class instances and similar, at this time, fail to serialize to JSON). Fixes #4820

Fixes #4820

jordansissel · 2016-05-09T19:58:19Z

I need to backport this PR by hand to 2.x for 2.4. Will open a separate PR for it.

This is made available by a --log-in-json flag. Default is false. When false, the old behavior [1] is used. When true, JSON logs are emitted. [1] The old behavior is realy two things. First, using Object#inspect to serialize. Second, to color the output if the IO is a tty. For #1569 This is a manual backport of PR #4820 into the 2.x branch.

This is made available by a --log-in-json flag. Default is false. When false, the old behavior [1] is used. When true, JSON logs are emitted. [1] The old behavior is realy two things. First, using Object#inspect to serialize. Second, to color the output if the IO is a tty. For #1569 This is a manual backport of PR #4820 into the 2.x branch. Fixes #5277

jordansissel · 2016-05-10T19:25:14Z

Backport to 2.4 done in #5277.

joshuaspence · 2016-07-14T21:19:23Z

Will Logstash 2.4 be released any time soon?

suyograo · 2016-07-14T21:26:18Z

@joshuaspence yes, target is to release it in Aug.

jordansissel changed the title ~~Allow Logstash to write its logs in JSON format~~ [WIP] Allow Logstash to write its logs in JSON format Mar 15, 2016

jordansissel added needs tests work in progress labels Mar 15, 2016

suyograo reviewed Mar 15, 2016
View reviewed changes

suyograo added the manageability label Mar 23, 2016

suyograo added the v5.0.0-alpha2 label Apr 18, 2016

jordansissel force-pushed the feature/log-in-json branch from 86e2a41 to b804686 Compare April 18, 2016 20:04

suyograo reviewed Apr 18, 2016
View reviewed changes

jordansissel removed the needs tests label Apr 20, 2016

jordansissel force-pushed the feature/log-in-json branch from b804686 to b23393d Compare April 20, 2016 18:03

jordansissel removed the work in progress label Apr 20, 2016

jordansissel changed the title ~~[WIP] Allow Logstash to write its logs in JSON format~~ Allow Logstash to write its logs in JSON format Apr 20, 2016

jordansissel force-pushed the feature/log-in-json branch from ffffac8 to 0335747 Compare April 20, 2016 18:14

suyograo assigned ph Apr 20, 2016

jordansissel added v2.3.2 and removed v2.3.2 labels Apr 20, 2016

ph reviewed May 6, 2016
View reviewed changes

jordansissel force-pushed the feature/log-in-json branch from 1fc388c to b7399f8 Compare May 9, 2016 19:50

jordansissel added 3 commits May 9, 2016 12:55

Include ci/reporter so bin/rpsec works for me.

619f1eb

jordansissel force-pushed the feature/log-in-json branch from b7399f8 to 619f1eb Compare May 9, 2016 19:55

elasticsearch-bot pushed a commit that referenced this pull request May 9, 2016

Include ci/reporter so bin/rpsec works for me.

682194b

Fixes #4820

elasticsearch-bot closed this in af41218 May 9, 2016

elasticsearch-bot pushed a commit that referenced this pull request May 9, 2016

Include ci/reporter so bin/rpsec works for me.

07887f8

Fixes #4820

This was referenced May 10, 2016

Backport/json logging pr 4820 #5276

Closed

Allow Logstash to write its logs in JSON format #5277

Closed

jordansissel mentioned this pull request May 10, 2016

Internal logging: A return to JSON #1569

Closed

suyograo deleted the feature/log-in-json branch May 11, 2016 15:50

ph mentioned this pull request Aug 24, 2016

Migrate Logstash to Log4j2 Logging #5651

Merged

dedemorton mentioned this pull request Aug 30, 2016

Add log-in-json to CLI topic #5841

Closed

Allow Logstash to write its logs in JSON format #4820

Allow Logstash to write its logs in JSON format #4820

Uh oh!

Conversation

jordansissel commented Mar 15, 2016 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jordansissel commented Apr 18, 2016

Uh oh!

jordansissel commented Apr 18, 2016

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jordansissel commented Apr 20, 2016

Uh oh!

jordansissel commented Apr 20, 2016

Uh oh!

jordansissel commented Apr 20, 2016

Uh oh!

ph commented Apr 20, 2016

Uh oh!

jordansissel commented Apr 20, 2016

Uh oh!

jordansissel commented Apr 20, 2016

Uh oh!

ph commented Apr 20, 2016

Uh oh!

ph commented Apr 20, 2016

Uh oh!

jordansissel commented Apr 20, 2016 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jordansissel commented Apr 20, 2016

Uh oh!

jordansissel commented Apr 20, 2016

Uh oh!

ph commented Apr 21, 2016

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

ph commented May 9, 2016

Uh oh!

andrewvc commented May 9, 2016

Uh oh!

guyboertje commented May 9, 2016

Uh oh!

ph commented May 9, 2016

Uh oh!

elasticsearch-bot commented May 9, 2016

Uh oh!

jordansissel commented May 9, 2016

Uh oh!

jordansissel commented May 10, 2016

Uh oh!

joshuaspence commented Jul 14, 2016

Uh oh!

suyograo commented Jul 14, 2016

Uh oh!

Uh oh!

jordansissel commented Mar 15, 2016 •

edited

Loading

jordansissel commented Apr 20, 2016 •

edited

Loading