Non recoverable exception while writing to InfluxDB ERROR

Elastic Stack Logstash
1

Hi,

I am trying to send data from logstash to influxdb through logstash_output_influxdb plugin.
the plugin version is 5.0.5 and logstash version is 6.2.3. I see the below error :

 [2019-04-09T15:09:33,095][WARN ][logstash.outputs.influxdb] Non recoverable exception while writing to InfluxDB 
\{:exception=>#<InfluxDB::Error: {"error":"unable to parse 'logstash,host=localhost username=\"admin\",
site=\"test\",timestamp_local=\"20190409120930\",resource_type=\"/users/admin\",timestamp=1554811770000i,
@timestamp=2019-04-09T19:09:32.368Z,repo=\"api\",resource_path=\"/users/admin\",
message=\"20190409120930|14|REQUEST|***.**.**.***|admin|GET|/users/admin|HTTP/1.1|200|0\",
duration=\"14\",clientip=\"***.**.**.***\",@version=\"1\",statuscode=\"200\",bytes=\"0\",
timestamp_object=2019-04-09T12:09:30.000Z,type=\"request\",env=\"stage\",requesttype=\"REQUEST\",
resource=\"/users/admin\",resource_name=\"admin\",method=\"GET\",protocol=\"HTTP/1.1\" 1554836972368': invalid number"}
>}
{
            "username" => "admin",
                "site" => "test",
     "timestamp_local" => "20190409120930",
       "resource_type" => "/users/admin",
                "host" => "localhost",
           "timestamp" => 1554811770000,
          "@timestamp" => 2019-04-09T19:09:32.368Z,
                "repo" => "api",
       "resource_path" => "/users/admin",
             "message" => "20190409120930|14|REQUEST|***.**.**.***|admin|GET|/users/admin|HTTP/1.1|200|0",
            "duration" => "14",
            "clientip" => "***.**.**.***",
            "@version" => "1",
          "statuscode" => "200",
               "bytes" => "0",
    "timestamp_object" => 2019-04-09T12:09:30.000Z,
                "type" => "request",
                 "env" => "stage",
         "requesttype" => "REQUEST",
            "resource" => "/users/admin",
       "resource_name" => "admin",
              "method" => "GET",
            "protocol" => "HTTP/1.1"
}

My logstash config :

    input {
  kafka {
    id => "kafka1"
    group_id => "logstash"
    bootstrap_servers => ["localhost:9092"]
    topics => ["request.log"]
    consumer_threads => 2
    type => "request"
  }
}
###################################
filter {
  if [type] == "request" {
    if "/api/test" in [message] { drop{ } }
    else {
        grok {
          # Enable multiple matchers
          break_on_match => false

          match => { "message" => "%{DATA:timestamp_local}\|%{NUMBER:duration}\|%{WORD:requesttype}\|%{IP:clientip}\|%{DATA:username}\|%{WORD:method}\|%{DATA:resource}\|%{DATA:protocol}\|%{NUMBER:statuscode}\|%{NUMBER:bytes}" }

          # Extract repo and path
          match => { "resource" => "/%{DATA:repo}/%{GREEDYDATA:resource_path}"}

          # Extract resource name
          match => { "resource_path" => "(?<resource_name>[^/]+$)" }

          # Extract file extension
          match => { "resource_path" => "(?<resource_type>[^.]+$)" }
        }
    }

     #Parse date field
      date {
        timezone => "UTC"
        match => [ "timestamp_local" , "yyyyMMddHHmmss" ]
        target => "timestamp_object"
      }
  }
ruby {
    code => "event.set('timestamp', event.get('timestamp_object').to_i * 1000)"
  }
}

#############################
output {
  if [type] == "request" {
    influxdb {
      codec => json
      host => "***.*.*.*"
      db => "logstash_test"
      port => 8086
      use_event_fields_for_data_points => true
      exclude_fields => ["logstash"]
    }
  stdout { codec => rubydebug }
}
}
2

If you look at the code for the filter, an influxdb event looks like this

# cpu_load_short,host=server01,region=us-west value=0.64 1434055562000000000
#  ^ measurement  ^ tags (optional)            ^ fields   ^ timestamp (optional)

For the influxdb output, the default value of measurement is "logstash". You can set the measurement option on the output to change that.

This is what is getting sent

logstash,host=localhost username="admin",site="test"[...] 1554836972368

I am unable to understand the code that extracts tags, but the default value for the send_as_tags option on the output is ["host"]. And the value of the trailing timestamp exactly matches @timestamp.

So far so good. The structure of the message in the buffer looks OK. So what could produce the 'invalid number' message? timestamp=1554811770000i looks like a candidate. That is not a valid number in any language I am familiar with. The strange thing is, when I run

 Hash[ event.to_hash.map do |k,v|
     [event.sprintf(k), (String === v ? event.sprintf(v) : v)]
 end ]

(which is effectively what the output does), I do not get the trailing i, so I cannot explain why it is happening. However, I suggest you try this and see if the error goes away.

mutate { remove_field => ["timestamp"] }
3

Hey,

thanks for looking into it. I did apply the filter but looks like the error persists.Below is the latest set of errors

Non recoverable exception while writing to InfluxDB {:exception=>#<InfluxDB::Error: {"error":"unable to parse 'logstash,host=localhost clientip=\"***.**.**.***\",type=\"request\",timestamp_local=\"20190410151523\",resource_type=\"storageinfo\",resource_name=\"storageinfo\",repo=\"api\",resource=\"/api/storageinfo\",@version=\"1\",username=\"admin\",requesttype=\"REQUEST\",statuscode=\"200\",resource_path=\"storageinfo\",method=\"GET\",duration=\"62\",env=\"stage\",@timestamp=2019-04-10T19:15:25.030Z,bytes=\"0\",timestamp_object=2019-04-10T15:15:23.000Z,message=\"20190410151523|62|REQUEST|***.**.**.***|admin|GET|/api/storageinfo|HTTP/1.1|200|0\",site=\"RTP\",protocol=\"HTTP/1.1\" 1554923725030': invalid number"}
Non recoverable exception while writing to InfluxDB {:exception=>#<InfluxDB::Error: {"error":"unable to parse 'logstash,host=localhost clientip=\"***.**.**.***\",type=\"request\",timestamp_local=\"20190410151521\",resource_type=\"storageinfo\",resource_name=\"storageinfo\",repo=\"api\",resource=\"/api/storageinfo\",@version=\"1\",username=\"admin\",requesttype=\"REQUEST\",statuscode=\"200\",resource_path=\"storageinfo\",method=\"GET\",duration=\"61\",env=\"stage\",@timestamp=2019-04-10T19:15:23.947Z,bytes=\"0\",timestamp_object=2019-04-10T15:15:21.000Z,message=\"20190410151521|61|REQUEST|***.**.**.***|admin|GET|/api/storageinfo|HTTP/1.1|200|0\",site=\"RTP\",protocol=\"HTTP/1.1\" 1554923723947': invalid number"}
4

Get rid of that mutate+remove fields, we can do this with the exclude_fields option on the output. Start off with only sending "method"

exclude_fields => [ "host", "clientip", "statuscode", "site", "repo", "bytes", "timestamp_object", "@timestamp", "username", "resource_path", "path", "duration", "@version", "requesttype", "timestamp", "protocol", "resource_name", "resource_type", "env", "timestamp_local", "type", "message", "resource" ]

If that works, remove fields from the exclude_fields array one at a time and see where it blows up.

I didn't notice that @timestamp is on the exclusion list by default. That would make timestamp_object another candidate for the problem since it is the only other field that is not a string.

5

Thank you ! you are a life saver :slightly_smiling_face:

Turns out that there are 3 fields that are causing the errors: @timestamp,timestamp_object and timestamp.

I am not sure why influxdb plugin is erroring out for timestamps though.

6

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