elastic / logstash

Logstash - transport and process your logs, events, or other data
https://www.elastic.co/products/logstash
Other
14.1k stars 3.48k forks source link

logstash forgets data type #4450

Open runningman84 opened 8 years ago

runningman84 commented 8 years ago

I have two setups parsing sensu messages.

filebeat -> logstash1 -> gelf (Graylog) filebeat -> logstash1 -> rabbitmq <- logstash2 -> gelf (Graylog)

In the second setup the data type of a float value is represented as "0.363E0" in Graylog. In the first setup it is stored as 0.363.

The logstash2 instance is quite simple there is no filtering at all just, input rabbitmq output gelf.

The logstash1 instance parses sensu messages lile this using the json filter

{"timestamp":"2016-01-11T16:47:35.185132+0000","level":"info","message":"publishing check result","payload":{"client":"i-e41b056d","check":{"name":"cpu_metrics","issued":1452530854,"command":"metrics-cpu.rb --scheme :::scheme_prefix::::::name:::.cpu","type":"metric","subscribers":["linux"],"handlers":["metrics"],"interval":60,"occurrences":2,"executed":1452530854,"duration":0.363,"output":"sensu.sensu.i-e41b056d.cpu.total.user 2819546 1452530855\nsensu.sensu.i-e41b056d.cpu.total.nice 6686 1452530855\nsensu.sensu.i-e41b056d.cpu.total.system 488912 1452530855\nsensu.sensu.i-e41b056d.cpu.total.idle 41970433 1452530855\nsensu.sensu.i-e41b056d.cpu.total.iowait 16862 1452530855\nsensu.sensu.i-e41b056d.cpu.total.irq 40 1452530855\nsensu.sensu.i-e41b056d.cpu.total.softirq 10503 1452530855\nsensu.sensu.i-e41b056d.cpu.total.steal 57530 1452530855\nsensu.sensu.i-e41b056d.cpu.total.guest 0 1452530855\nsensu.sensu.i-e41b056d.cpu.total. 0 1452530855\nsensu.sensu.i-e41b056d.cpu.cpu0.user 2819546 1452530855\nsensu.sensu.i-e41b056d.cpu.cpu0.nice 6686 1452530855\nsensu.sensu.i-e41b056d.cpu.cpu0.system 488912 1452530855\nsensu.sensu.i-e41b056d.cpu.cpu0.idle 41970433 1452530855\nsensu.sensu.i-e41b056d.cpu.cpu0.iowait 16862 1452530855\nsensu.sensu.i-e41b056d.cpu.cpu0.irq 40 1452530855\nsensu.sensu.i-e41b056d.cpu.cpu0.softirq 10503 1452530855\nsensu.sensu.i-e41b056d.cpu.cpu0.steal 57530 1452530855\nsensu.sensu.i-e41b056d.cpu.cpu0.guest 0 1452530855\nsensu.sensu.i-e41b056d.cpu.cpu0. 0 1452530855\nsensu.sensu.i-e41b056d.cpu.intr 0 1452530855\nsensu.sensu.i-e41b056d.cpu.ctxt 125320448 1452530855\nsensu.sensu.i-e41b056d.cpu.btime 1452077217 1452530855\nsensu.sensu.i-e41b056d.cpu.processes 1102990 1452530855\nsensu.sensu.i-e41b056d.cpu.procs_running 2 1452530855\nsensu.sensu.i-e41b056d.cpu.procs_blocked 0 1452530855\nsensu.sensu.i-e41b056d.cpu.cpu_count 1 1452530855\n\n","status":0}}}

My filter config looks like this

    json {
      source => message
      target => "sensu"
      add_tag => "sensu_found"
    }

    if ("sensu_found" in [tags]) {
      mutate {
        add_field => ["short_message", "%{[sensu][message]}"]
        replace => { "severity" => "%{[sensu][level]}" }
        remove_field => [ "[sensu][level]", "[sensu][message]" ]
      }

      #2015-12-11T14:05:07.154701+0000
      date {
          match => [ "[sensu][timestamp]", "ISO8601" ]
          locale => "Locale.US"
          add_tag => ["timestamp_changed"]
          remove_field => [ "[sensu][timestamp]" ]
      }

      if([sensu][payload][check]) {
        mutate {
          rename => ["[sensu][payload][client]", "sensu_client"]
          rename => ["[sensu][payload][check][duration]", "sensu_check_duration"]
          rename => ["[sensu][payload][check][interval]", "sensu_check_interval"]
          rename => ["[sensu][payload][check][name]", "sensu_check_name"]
          rename => ["[sensu][payload][check][command]", "sensu_check_command"]
          rename => ["[sensu][payload][check][type]", "sensu_check_type"]
          rename => ["[sensu][payload][check][status]", "sensu_check_status"]
          rename => ["[sensu][payload][check][output]", "sensu_check_output"]
          rename => ["[sensu][payload][check][occurrences]", "sensu_check_occurrences"]
          convert => [ "sensu_check_duration", "float" ]
          convert => [ "sensu_check_interval", "integer" ]
          remove_field => [ "[sensu][payload]" ]
        }
      }

      if([sensu][event][check]) {
        mutate {
          convert => [ "[sensu][event][check][duration]", "float" ]
          convert => [ "[sensu][event][check][interval]", "integer" ]
          rename => ["[sensu][event][client][name]", "sensu_client"]
          rename => ["[sensu][event][check][duration]", "sensu_check_duration"]
          rename => ["[sensu][event][check][interval]", "sensu_check_interval"]
          rename => ["[sensu][event][check][name]", "sensu_check_name"]
          rename => ["[sensu][event][check][command]", "sensu_check_command"]
          rename => ["[sensu][event][check][type]", "sensu_check_type"]
          rename => ["[sensu][event][check][status]", "sensu_check_status"]
          rename => ["[sensu][event][check][output]", "sensu_check_output"]
          rename => ["[sensu][event][check][occurrences]", "sensu_check_occurrences"]
          rename => ["[sensu][event][check][history]", "sensu_check_history"]
          rename => ["[sensu][event][check][total_state_change]", "sensu_check_total_state_change"]
          rename => ["[sensu][event][id]", "sensu_event_id"]
          rename => ["[sensu][event][occurrences]", "sensu_event_occurrences"]
          convert => [ "sensu_event_occurrences", "integer" ]
          convert => [ "sensu_check_duration", "float" ]
          convert => [ "sensu_check_interval", "integer" ]
          rename => ["[sensu][event][action]", "sensu_event_action"]
          remove_field => [ "[sensu][event]" ]
        }
      }

Why is the data type changed here?

purbon commented 8 years ago

Thanks a lot for your time, Might this be due to internal conversions done in rabbit? I'm also wondering if both configs are the same as the one you proposed, can you share a simplified version of it?

closing this for now until we get more data, feedback and inputs to reopen.

adnan-panalytics commented 8 years ago

I am also having this issue with a similar setup. Input -> UDP. Output -> GELF. A simple float like "0.9999" in a rails application becomes "0.9999E0" in Graylog. This started happening after migration from 1.4.1 to 2.3.1. Also happens in 2.2.4 and 2.2.3. Is there a way this behaviour can be reversed?

colinsurprenant commented 8 years ago

I think this might be related to #5114 ?

adnan-panalytics commented 8 years ago

I checked the above issue. It seems to me that it is not related, but I maybe wrong. The issue I am referring to over here is "forced conversion to BigDecimal" which was not the case before. I would understand if logstash truncated the last few digits, unless specified in a specific format, but to make all floats -> BigDecimal and thereby breaking the GELF output plugin from graylog, seems a bit much. That is just my opinion. I am open to any kind of fix or workaround.

colinsurprenant commented 8 years ago

@adnan-panalytics could you share your config?

pschrammel commented 8 years ago
input {
  tcp {
    host => "0.0.0.0"
    port => 5229
    codec => json_lines
  }
}

input {
  udp {
    host => "0.0.0.0"
    port => 5228
    codec => json_lines
    add_field => { "short_message" => "" }
  }

}

output {
    gelf {
      chunksize => 1420

      host => '127.0.0.1'
      level => "INFO"
      port => 12201
      sender => "%{@host}"
      short_message => ""
      full_message => ""
    }
}

input {
  sqs {
    access_key_id => "xxx" 
    secret_access_key => "yyyy" 
    region => "eu-west-1"
    queue => "kapow_logging"
  }
}

filter {
  date {
    match => [ "kapow_timestamp", "YYYY-MM-dd HH:mm:ss" ]
    add_field => { "ts_kapow" => "added"}
  }
}
colinsurprenant commented 8 years ago

@pschrammel would you mind providing some explanations/details about this config?

adnan-panalytics commented 8 years ago

@colinsurprenant: Our config is pretty similar -

  1. We have a UDP and TCP input (mostly use the UDP input)
  2. The output is GELF - which is to say that it sends the message in a graylog consumable format.

Do let me know, if anything else is unclear.

stephenpaulger commented 8 years ago

I am experiencing this issue also and I think I can say with some certainty that issue lies in the gelf output.

input {
    gelf { 
        port => 12201
    }
}
output { 
    http { 
        headers => {"X-Insert-Key" => "***REMOVED KEY***"}
        content_type => "application/json"
            http_method => "post"
            url => "***REMOVED NEWRELIC INSIGHTS URL***"
    }
    gelf {
        host => "graylog_host"
    }
}

The data that is sent to new relic is a floating point number but data sent to graylog is a string like "0.2618057E1".

Prior to using logstash I was sending data to graylog directly and graylog accepted the data as floating point.

I hope this helps.

adnan-panalytics commented 8 years ago

You may be right, but from what I have found out, the gelf output plugin code is quite simple and straightforward. When you have a look at the code, nowhere do you find the conversion to bigdecimal (Also there have been no commits that seem have made this kind of change). But, when you look at the logstash codebase, there have been commits which change this behaviour and that is the reason I think that it needs to be fixed from logstash. Because the plugin was working with the previous versions of logstash, but doesn't with the latest ones (even though the plugin has not been changed all that much).

adnan-panalytics commented 8 years ago

@suyograo Does it need any more information? I am happy to provide anything else required, if this bug can be fixed. As this has lead to us abandoning floating point numbers and use workarounds for it.

@purbon Could you please re-open this issue?