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?
[09:02]
<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}"
obviously
<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
<timvisher>
https://gist.github.com/timvisher/f56e83eae1f4005c4b0b966edcf40816
[09:09]
<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
logging
<timvisher> ok.
<Xylakant> the error is triggered here
https://github.com/elastic/logstash/blob/master/logstash-core/lib/logstash/json.rb#L28
and the code is straightforward dump into json generator
[09:21]
<Xylakant> the trace says line 52, but that line number changed
somewhere between master and 6.0 [09:22]