# Silent error on date parsing

**URL:** <https://discuss.elastic.co/t/silent-error-on-date-parsing/320187>\
**Category:** Logstash\
**Created:** [November 30, 2022, 7:46pm UTC](https://discuss.elastic.co/t/silent-error-on-date-parsing/320187 "2022-11-30T19:46:00Z")\
**Posts on this page:** 5\
**Page:** 1

<div class="post-metadata">

**Author:** ![rfirpo](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rfirpo/32/114061_2.png) [@rfirpo](https://discuss.elastic.co/u/rfirpo)\
**Post date:** [November 30, 2022, 7:46pm UTC](https://discuss.elastic.co/t/silent-error-on-date-parsing/320187/1 "2022-11-30T19:46:00Z")

</div>

Logstash is silently dropping my logs after implementing a small modification in my grok filter.

The original filter looks like:

```auto
filter {
  if [internal][logtype] == "mycustomtype" {
    grok {
      match => {
        "message" => [
          '^\[%{DATA:dummy}\] %{LOGLEVEL:my.loglevel} \{%{DATA:my.source}\} - timestamp = %{DATA:timestamp}, status = %{DATA:my.status}, origin = %{DATA:my.origin}, extra_fields$'
        ]
      }
    }
    mutate {
      remove_field => ["dummy"]
    }
    date {
        match => ["timestamp" , "YYYY-MM-dd'T'HH:mm:ss.SSS"] #2022-04-26T08:27:33.279
        target => "@timestamp"
        remove_field => ["timestamp"]
        timezone => "Europe/Madrid"
    }
  }

```

The modification consists on swapping the order of the status and origin fields.  
The new filter has been thoroughly tested on the debugger, but is not working "on the field".

After some debugging, I could find that:

- The original filter does not drop the log, even if the match fails
- Any slight modification of the filter results in a drop
- I can get a matched log by using a filter for the fields up to the timestamp, none after, like ` ^\[%{DATA:dummy}\] %{LOGLEVEL:my.loglevel} \{%{DATA:my.source}\} - timestamp = %{DATA:timestamp}`
- I can avoid the drop by commenting out the `timezone` in the date section, and get logs with and without grok match

Could anyone provide a hint on this weird behavior?

In particular:

- Why the log is being dropped and the error silenced
- Why the original filter is working?

Thanks!

---

<div class="post-metadata">

**Author:** ![leandrojmp](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/leandrojmp/32/107231_2.png) [@leandrojmp](https://discuss.elastic.co/u/leandrojmp)\
**Post date:** [November 30, 2022, 7:54pm UTC](https://discuss.elastic.co/t/silent-error-on-date-parsing/320187/2 "2022-11-30T19:54:16Z")

</div>

Can you share your entire pipeline and a sample message?

Which filter you changed? The grok? the mutate? the Date filter?

> [@rfirpo](#):
>
> I can avoid the drop by commenting out the `timezone` in the date section, and get logs with and without grok match

If commenting the `timezone` option in the date filter fix your issue, this could mean that your logs are not being dropped, but being ingested with a wrong date and you may not be using a wide enough date range in the time filter to see it.

Can you add an extra output to write your logs to a file and see if they show up there?

---

<div class="post-metadata">

**Author:** ![rfirpo](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rfirpo/32/114061_2.png) [@rfirpo](https://discuss.elastic.co/u/rfirpo)\
**Post date:** [November 30, 2022, 8:42pm UTC](https://discuss.elastic.co/t/silent-error-on-date-parsing/320187/3 "2022-11-30T20:42:55Z")

</div>

Thanks @leandrojmp, this was the problem.  
Well, this and my misunderstanding on how the timezone is working.

So, examining the different timestamps I now see that:

- default `@timestamp` is shown in my local time (UTC+1), e.g. `Nov 30, 2022 @ 21:22:57.480`
- the timestamp I'm parsing is already in UTC, so `2022-11-30T20:22:57.472`
- when adding the `timezone` I'm creating a new field which does the opposite of what I though. Instead of showing me the parsed message in my timezone, it shows the parsed ts in UTC assuming the original message was in my local time, so `2022-11-30T19:22:57.472Z`

I was watching for the latest logs, and not realizing they were appearing with a ts two hours earlier. This certainly breaks causality! 😃

Thanks for your help!

P.S. It is still a mystery to me how the original filter was producing correct timestamps, but at this point is something I can live with.

---

<div class="post-metadata">

**Author:** ![leandrojmp](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/leandrojmp/32/107231_2.png) [@leandrojmp](https://discuss.elastic.co/u/leandrojmp)\
**Post date:** [November 30, 2022, 9:19pm UTC](https://discuss.elastic.co/t/silent-error-on-date-parsing/320187/4 "2022-11-30T21:19:16Z")

</div>

Timezones can be confusing sometimes.

If your timestamp is already in UTC, you should not use the `timezone` option in the `date` filter, this option is to inform the date filter that the date string that it will parse is from a different timezone from UTC.

If the date string already has a timezone offset, you also should not use the `timezone` option.

Elasticsearch only store dates in UTC and Kibana always convert back from UTC to your local timezone.

In Kibana you can check it looking at the json of the document, in the table view you will have the date converted to your local timezone, but in the json view you will have the value without convertion, which will be in UTC.

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [December 28, 2022, 9:19pm UTC](https://discuss.elastic.co/t/silent-error-on-date-parsing/320187/5 "2022-12-28T21:19:32Z")

</div>

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