LogStash::Json::GeneratorError when using mutate copy @timestamp

I was attempting to save off the timestamp that logstash saw an event
before mutating the event to use the event's parsed timestamp with the
date filter.

My first attempt was:

if [@timestamp] {
  mutate {
    copy => { "[@timestamp]" => "[logstash_timestamp]" }

Which resulted in the following error being logged contiuously.

[2018-02-09T13:59:53,412][ERROR][logstash.outputs.elasticsearch] An unknown error occurred sending a bulk request to Elasticsearch. We will retry indefinitely {:error_message=>"", :error_class=>"LogStash::Json::GeneratorError", :b
acktrace=>["/usr/share/logstash/logstash-core/lib/logstash/json.rb:52:in `jruby_dump'", "/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-output-elasticsearch-9.0.2-java/lib/logstash/outputs/elasticsearch/http_client.rb:115:in `block in bulk'", "org/jruby/RubyArray.java:2486:in `map'", "/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-output-elasticsearch-9.0.2-java/lib/logstash/outputs/elasticsearch/http_client.rb:115:in `block in bulk'", "org/jruby/RubyArray.java:1734:in `each'", "/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-output-elasticsearch-9.0.2-java/lib/logstash/outputs/elasticsearch/http_client.rb:113:in `bulk'", "/usr/share/logstash/v
endor/bundle/jruby/2.3.0/gems/logstash-output-elasticsearch-9.0.2-java/lib/logstash/outputs/elasticsearch/common.rb:232:in `safe_bulk'", "/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-output-elasticsearch-9.0.2-java/
lib/logstash/outputs/elasticsearch/common.rb:118:in `submit'", "/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-output-elasticsearch-9.0.2-java/lib/logstash/outputs/elasticsearch/common.rb:86:in `retrying_submit'", "/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-output-elasticsearch-9.0.2-java/lib/logstash/outputs/elasticsearch/common.rb:34:in `multi_receive'", "/usr/share/logstash/logstash-core/lib/logstash/output_delegator_strate
gies/shared.rb:13:in `multi_receive'", "/usr/share/logstash/logstash-core/lib/logstash/output_delegator.rb:49:in `multi_receive'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:538:in `block in output_batch'", "org/j
ruby/RubyHash.java:1343:in `each'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:536:in `output_batch'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:481:in `worker_loop'", "/usr/share/logstash/logsta
sh-core/lib/logstash/pipeline.rb:439:in `block in start_workers'"]}

To fix it, I changed the config to:

if [@timestamp] {
  mutate {
    add_field => { "logstash_timestamp" => "%{@timestamp}" }

This is in logstash 6.0.1 with the elasticsearch output plugin 9.0.2.

On the advice of Xylakant from #logstash@freenode I'm opening this
discussion. I don't have time to provide a minimal reproduction config but
I might be able to later. See the full conversation between us below.

<timvisher> i would like to save the timestamp that logstash saw an
            event at in the event and then utilize the date filter to
            set @timestamp to the date from the event. i have the date
            filter working but my initial attempt to using a mutate
            filter to `{ copy => { "[@timestamp]" =>
            "logstash_timestamp" } }` looks like it's generating json
            generator errors. anything clever i should be aware of?
<timvisher> yeah. remoeving that mutate filter and the json errors go
            away                                                  [09:03]
<Xylakant> i'd try mutate {add_field => { "logstash_timestamp" =>
           "@timestamp"} or something along those lines           [09:04]
<Xylakant> the timestamp field is somewhat special since it's a date
<timvisher> ah
<timvisher> for further context the json error is coming from the
            elasticsearch output plugin 9.0.2                     [09:05]
<timvisher> i'll try that
<timvisher> i'm currently hiding the copy behind an if statement. is
            there any reason to have the if statement? or can i rely on
            @timestamp always being set?
<Xylakant> err, interpolation for the @timestamp, so "%{timestamp}"
<Xylakant>  @timestamp is always set, if there's no timestamp set when
           logstash sees the document, it will add one            [09:06]
<Xylakant> obviously "%{@timestamp}"
<timvisher> actually i don't follow that last statement. oh ok
<Xylakant> narf, you get the meaning
<timvisher> now i do :)
<timvisher> heh
<Xylakant> the json error produced would be interesting           [09:08]
<timvisher> let me see if i can paste it somewhere
<Xylakant> I don't see a particular reason copy should cause this
<Xylakant> a gist or pastebin will do
<Xylakant> that's pretty devoid of real information :(            [09:11]
<Xylakant> what logstash version is that?                         [09:12]
<timvisher> 6.0.1                                                 [09:17]
<timvisher> is there something better i can turn on as far as logging?
<timvisher> fwiw the add_field version worked fine                [09:18]
<Xylakant> i think you could raise a ticket against logstash core,
           that's a problem in logstashs json generator           [09:20]
<Xylakant> i don't think there's much you could turn on in terms of
<timvisher> ok.
<Xylakant> the error is triggered here
           and the code is straightforward dump into  json generator
<Xylakant> the trace says line 52, but that line number changed
           somewhere between master and 6.0                       [09:22]
1 Like

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.