Logstash: UNIX Epoch time not getting converted to readable format

Question

I have setup an ELK stack and I am trying to parse squid log entries.

And I am having a problem trying to convert the following UNIX/Epoc time as

1442469455.757

to a human readable format.

While trouble shooting I get the following error:

Received an event that has a different character encoding than you configured.

and this comes with a "_dateparsefailure" tag which means it failed.

I have used the following logstash filter

filter {
if [type] == "squid" {
        grok {
        patterns_dir   => [ "/etc/logstash/patterns" ]
        match => { message => "%{SQUID_LOG}" }
        }
        date {
          match => [ "timestamp", "UNIX" ]
        }
   }
}

The regex pattern defined to match the timestamp in the main pattern "%{SQUID_LOG}" is: (%{DATA:timestamp})

Please let me know if there is a permanent solution or a workaround for this.

Thanks in Advance.

UPDATE:

This seems to be caused by the extra space after the timestamp as mentioned below:

value=>"1438744871.647\\xA0\\xA0\\xA0\\xA0\\xA0", :exception=>"Invalid UNIX epoch value '1438744871.647\\xA0\\xA0\\xA0\\xA0\\xA0'", :config_parsers=>"UNIX", :config_locale=>"default=en_GB", :level=>:warn

Is there a way to get rid of those '\\xA0\\xA0\\xA0\\xA0\\xA0' after the timestamp ?

Config:

input { stdin { } }

filter {
        grok {
        match => { message => "((%{DATA:time_stamp}) (%{NUMBER:time_elapsed_ms}) (%{IPV4:client_ip}) (%{WORD:req_stat})/(%{INT:reply_code}) (%{INT:request_size}) (%{WORD:http_method}) (%{URIPROTO:request_protocol}://)?%{IPORHOST:request_hostname}(?::%{POSINT:port})?(?:%{URIPATHPARAM:uri_param}|) (%{USERNAME:user}) (%{WORD:squid_hierarchy})/(%{HOST:server}|-) (%{DATA:content_type}) (%{WORD:snaction}|-))" }
        add_tag => "NONU"
        }
        mutate {
        strip => [ "time_stamp" ]
        }
        date {
         match => [ "time_stamp", "UNIX" ]
        }
   }

output {
  stdout { codec => rubydebug }
}

Sample data:

1442469456.136      1 19.108.217.100 DENIED/407 3864 CONNECT fei.wsp.microsoft.com:443 - HIER_NONE/- text/html -

It seems to be related to unwanted space, please check my update. — Ajov Crowe, Oct 09 '15 at 12:19
Do *all* the log entries have 6 spaces after the timestamp, or is that just this line? — GregL, Oct 09 '15 at 12:54
Thanks, @GregL . The one with the SPACE filter did the job ! — Ajov Crowe, Oct 12 '15 at 05:07

GregL · Accepted Answer · 2015-10-09T15:02:40.950

If the errors are really being caused by the extra whitespace in the time_stamp field, you can use the mutate filter to strip it out. Your filter would then look like this:

filter {
  if [type] == "squid" {
    grok {
      patterns_dir   => [ "/etc/logstash/patterns" ]
      match => { message => "%{SQUID_LOG}" }
    }
    mutate {
      strip => ["time_stamp"]
    }
    date {
      match => [ "time_stamp", "UNIX" ]
    }
 }
}

Update

If all the log entries have exactly 6 extra spaces after the timestamp, update your grok pattern as follows. Note the extra spaces between time_stamp and time_epapsed_ms.

((%{DATA:time_stamp})      (%{NUMBER:time_elapsed_ms}) (%{IPV4:client_ip}) (%{WORD:req_stat})/(%{INT:reply_code}) (%{INT:request_size}) (%{WORD:http_method}) (%{URIPROTO:request_protocol}://)?%{IPORHOST:request_hostname}(?::%{POSINT:port})?(?:%{URIPATHPARAM:uri_param}|) (%{USERNAME:user}) (%{WORD:squid_hierarchy})/(%{HOST:server}|-) (%{DATA:content_type}) (%{WORD:snaction}|-))

If there's a possibility that it might be more or less than 6 spaces, the following should work.

((%{DATA:time_stamp})%{SPACE}(%{NUMBER:time_elapsed_ms}) (%{IPV4:client_ip}) (%{WORD:req_stat})/(%{INT:reply_code}) (%{INT:request_size}) (%{WORD:http_method}) (%{URIPROTO:request_protocol}://)?%{IPORHOST:request_hostname}(?::%{POSINT:port})?(?:%{URIPATHPARAM:uri_param}|) (%{USERNAME:user}) (%{WORD:squid_hierarchy})/(%{HOST:server}|-) (%{DATA:content_type}) (%{WORD:snaction}|-))

Thanks, Greg.But does not seem to be taking it out. I have updated the post with a sample data for reference. — Ajov Crowe, Oct 09 '15 at 12:30
Can you update your question with your full LS config, the full grok pattern and some sample log lines? — GregL, Oct 09 '15 at 12:35

score 1 · Answer 2 · answered Oct 09 '15 at 11:49

I suspect it is something in the parsing of SQUID_LOG (like a token missing or misplaced).

You could see more if you put your filter code in-between of:

input {
  file {
    path => "/opt/logstash/squid.log"
    type => "squid"
    start_position => "beginning"
    sincedb_path => "/dev/null"
  }
}

[filter]

output {
    stdout { codec => rubydebug }   
}

where /opt/logstash/squid.log is just a few problematic log lines.

With:

/opt/logstash/bin/logstash -f this_test_conf_file.conf

you are going to see on screen what it's happening.

Thanks, can you please check my new update and let me know if this can be fixed. — Ajov Crowe, Oct 09 '15 at 12:19

Logstash: UNIX Epoch time not getting converted to readable format

2 Answers2