# Logs time 6 hours behind local time

**URL:** <https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679>\
**Category:** Metrics\
**Created:** [February 23, 2019, 7:05pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679 "2019-02-23T19:05:51Z")\
**Posts on this page:** 20\
**Page:** 1

<div class="post-metadata">

**Author:** ![rugenl](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rugenl/32/12887_2.png) [@rugenl](https://discuss.elastic.co/u/rugenl)\
**Post date:** [February 23, 2019, 7:05pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/1 "2019-02-23T19:05:51Z")

</div>

I just started investigating logs. I setup filebeat on my elastic cluster and enabled the elasticsearch and logstash modules. The data is there, but the log time is -6 hours from local.

For example @timestamp is February 23rd 2019, 05:41:30.460, event.created is February 23rd 2019, 11:41:31.059 and the log record starts with [2019-02-23T11:41:30,460].

Not ironically, I'm US/Central time zone, we we are -6 offset now.

Is this a bug or a configuration issue? If configuration, what component?

Thanks

---

<div class="post-metadata">

**Author:** ![weltenwort](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/weltenwort/32/53885_2.png) [@weltenwort](https://discuss.elastic.co/u/weltenwort)\
**Post date:** [February 25, 2019, 10:22am UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/2 "2019-02-25T10:22:40Z")

</div>

Hi @rugenl,

this sounds like you are being affected by [elastic/beats#9756](https://github.com/elastic/beats/issues/9756). A fix should have been added in version 6.6 that adds the `var.convert_timezone` setting also for the `elasticsearch` and `logstash` modules.

---

<div class="post-metadata">

**Author:** ![rugenl](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rugenl/32/12887_2.png) [@rugenl](https://discuss.elastic.co/u/rugenl)\
**Post date:** [February 25, 2019, 1:27pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/3 "2019-02-25T13:27:22Z")

</div>

Like this?

> ```
> - module: logstash
> # logs
> log:
> enabled: true
> 
> # Set custom paths for the log files. If left empty,
> # Filebeat will choose the paths depending on your OS.
> #var.paths:
> var.convert_timezone: true
> 
> ```

Even at 6.6.1 I get: invalid config: yaml: line 16: did not find expected key

---

<div class="post-metadata">

**Author:** ![weltenwort](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/weltenwort/32/53885_2.png) [@weltenwort](https://discuss.elastic.co/u/weltenwort)\
**Post date:** [February 25, 2019, 2:56pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/4 "2019-02-25T14:56:50Z")

</div>

That is curious. I just tried to reproduce it, but I did not get the error you described:

1. Download Filebeat 6.6.1
2. run `./filebeat modules enable logstash`
3. edit `modules.d/logstash.yml` to contain:

```auto
- module: logstash
  # logs
  log:
    enabled: true

    # Set custom paths for the log files. If left empty,
    # Filebeat will choose the paths depending on your OS.
    #var.paths:

    # Convert the timestamp to UTC. Requires Elasticsearch >= 6.1.
    var.convert_timezone: true

```

4. run `./filebeat test config`

Can you double-check your version by running `./filebeat version`?

---

<div class="post-metadata">

**Author:** ![rugenl](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rugenl/32/12887_2.png) [@rugenl](https://discuss.elastic.co/u/rugenl)\
**Post date:** [February 25, 2019, 7:46pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/5 "2019-02-25T19:46:52Z")

</div>

Verified 6.6.1, filebeat test config doesn't give errors, but it fails when ran.

```
> # filebeat version
> filebeat version 6.6.1 (amd64), libbeat 6.6.1 [928f5e3f35fe28c1bd73513ff1cc89406eb212a6 built 2019-02-13 16:12:26 +0000 UTC]
> # filebeat run
> Exiting: 1 error: invalid config: yaml: line 16: did not find expected key
> # filebeat test config
> Config OK
```

---

<div class="post-metadata">

**Author:** ![rugenl](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rugenl/32/12887_2.png) [@rugenl](https://discuss.elastic.co/u/rugenl)\
**Post date:** [February 26, 2019, 3:18pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/6 "2019-02-26T15:18:00Z")

</div>

The var.convert\_timezone works in the elasticsearch module, it fails in the logstash module.

---

<div class="post-metadata">

**Author:** ![rugenl](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rugenl/32/12887_2.png) [@rugenl](https://discuss.elastic.co/u/rugenl)\
**Post date:** [February 27, 2019, 11:11pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/7 "2019-02-27T23:11:32Z")

</div>

I found the problem, as shipped:

```
  # Slow logs
  slowlog:
   enabled: true

```

"enabled:" is only indented one space, when I copied the var. line from the first log, it was indented 2 spaces.

---

<div class="post-metadata">

**Author:** ![weltenwort](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/weltenwort/32/53885_2.png) [@weltenwort](https://discuss.elastic.co/u/weltenwort)\
**Post date:** [March 4, 2019, 3:01pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/8 "2019-03-04T15:01:10Z")

</div>

Oh, that's a difficult one to spot. Thanks for letting us know. Looks like it is already fixed in [10754](https://github.com/elastic/beats/pull/10754) but missed the 6.6.1 release.

Does that option fix your original time offset problem?

---

<div class="post-metadata">

**Author:** ![rugenl](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rugenl/32/12887_2.png) [@rugenl](https://discuss.elastic.co/u/rugenl)\
**Post date:** [March 4, 2019, 7:12pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/9 "2019-03-04T19:12:47Z")

</div>

It does for elasticsearch, but not for some reason, logstash data isn't getting ingested. They were working, not sure what has changed. Other problems bumped this down....

---

<div class="post-metadata">

**Author:** ![weltenwort](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/weltenwort/32/53885_2.png) [@weltenwort](https://discuss.elastic.co/u/weltenwort)\
**Post date:** [March 4, 2019, 7:20pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/10 "2019-03-04T19:20:49Z")

</div>

Let me know when you're returning to this topic and require assistance figuring that out.

---

<div class="post-metadata">

**Author:** ![rugenl](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rugenl/32/12887_2.png) [@rugenl](https://discuss.elastic.co/u/rugenl)\
**Post date:** [March 4, 2019, 7:27pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/11 "2019-03-04T19:27:42Z")

</div>

It looks like I'm getting different results on two different test stacks, both are elasticsearch 6.6.0, but different filebeat versions:

filebeat 6.6.1 (update from 6.6.0), elasticsearch time is OK, no logstash ingest.

Filebeat 6.6.0, time is still -6 hours.

I think filebeat setup (probably automatic) did load the proper pipelines on both stacks.

---

<div class="post-metadata">

**Author:** ![weltenwort](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/weltenwort/32/53885_2.png) [@weltenwort](https://discuss.elastic.co/u/weltenwort)\
**Post date:** [March 4, 2019, 7:41pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/12 "2019-03-04T19:41:58Z")

</div>

You can check the pipeline on your 6.6.1 stack by querying

```auto
curl -XGET http://${ES_HOST}:${ES_PORT}/_ingest/pipeline/filebeat-6.6.1-logstash-log-\*

```

Do either filebeat or elasticsearch print anything on the console related to ingest errors?

---

<div class="post-metadata">

**Author:** ![rugenl](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rugenl/32/12887_2.png) [@rugenl](https://discuss.elastic.co/u/rugenl)\
**Post date:** [March 4, 2019, 7:59pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/13 "2019-03-04T19:59:55Z")

</div>

Today's filebeat stats on the stack with filebeat 6.6.0  
 ![image](https://us1.discourse-cdn.com/elastic/original/3X/4/5/453a54529ffaf676861d9f320a0cb78e2e2e19bf.png)

Stopped filebeat, deleted the registry, upgrade filebeat to 6.6.1, restart filebeat and create a Kibana index pattern for filebeat-6.6.1-\*. First problem, there doesn't seem to be an @timestamp field, it's mapped, but doesn't exist in any data, switched to the event.created field.

The elasticsearch logs are there with the right time, no logstash data. I see pipeline stats on the nodes:

> ```
> "filebeat-6.6.1-logstash-log-pipeline-plain" : {
> "count" : 91,
> "time_in_millis" : 74,
> "current" : 0,
> "failed" : 0,
> "processors" : [
> {
> "grok" : {
> "count" : 91,
> "time_in_millis" : 0,
> "current" : 0,
> "failed" : 0
> }
> 
> ```

All the count fields are the same for all processors, of course different counts on each node.

The curl get of the pipeline looks OK.

---

<div class="post-metadata">

**Author:** ![rugenl](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rugenl/32/12887_2.png) [@rugenl](https://discuss.elastic.co/u/rugenl)\
**Post date:** [March 5, 2019, 1:15am UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/14 "2019-03-05T01:15:44Z")

</div>

Got a little more time, I don't see any errors in any of the logs.

We are still in development but are heading toward production in a month or two. This isn't a critical path, I was just researching the benefit of consolidating our logs instead of having to chase logs across all the nodes in a cluster. This does look promising 🙂

Thanks

---

<div class="post-metadata">

**Author:** ![weltenwort](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/weltenwort/32/53885_2.png) [@weltenwort](https://discuss.elastic.co/u/weltenwort)\
**Post date:** [March 5, 2019, 12:50pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/15 "2019-03-05T12:50:39Z")

</div>

If the `@timestamp` is missing, there must be something seriously wrong in the ingestion pipeline. Could you post such a malformed sample document for us to take a look at?

---

<div class="post-metadata">

**Author:** ![rugenl](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rugenl/32/12887_2.png) [@rugenl](https://discuss.elastic.co/u/rugenl)\
**Post date:** [March 5, 2019, 2:25pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/16 "2019-03-05T14:25:16Z")

</div>

> #! Deprecation: Field expansion matches too many fields, got: 1122. This will be limited starting with version 7.0 of Elasticsearch. The limit will be detemined by the `indices.query.bool.max_clause_count` setting which is currently set to 1024. You should look at lowering the maximum number of fields targeted by a query or increase the above limit while being aware that this can negatively affect your clusters performance.  
> {  
> "took" : 70,  
> "timed\_out" : false,  
> "\_shards" : {  
> "total" : 1,  
> "successful" : 1,  
> "skipped" : 0,  
> "failed" : 0  
> },  
> "hits" : {  
> "total" : 1304,  
> "max\_score" : 1.0,  
> "hits" : [  
> {  
> "\_index" : "filebeat-6.6.1-2019.03.04",  
> "\_type" : "doc",  
> "\_id" : "vOINSmkBRoWwD8qx5i6X",  
> "\_score" : 1.0,  
> "\_source" : {  
> "offset" : 0,  
> "log" : {  
> "file" : {  
> "path" : "/var/log/elasticsearch/elk-exp6.log"  
> },  
> "level" : "INFO"  
> },  
> "prospector" : {  
> "type" : "log"  
> },  
> "source" : "/var/log/elasticsearch/elk-exp6.log",  
> "message" : "creating index, cause [auto(bulk api)], templates [exp-shards, metricbeat-6.6.0], shards [1]/[0], mappings [doc]",  
> "fileset" : {  
> "module" : "elasticsearch",  
> "name" : "server"  
> },  
> "input" : {  
> "type" : "log"  
> },  
> "elasticsearch" : {  
> "server" : {  
> "component" : "o.e.c.m.MetaDataCreateIndexService"  
> },  
> "node" : {  
> "name" : "met-elk-exp6a"  
> },  
> "index" : {  
> "name" : "metricbeat-6.6.0-2019.03.04"  
> }  
> },  
> "service" : {  
> "name" : "elasticsearch"  
> },  
> "beat" : {  
> "hostname" : "met-elk-exp6a",  
> "timezone" : "-06:00",  
> "name" : "met-elk-exp6a",  
> "version" : "6.6.1"  
> },  
> "host" : {  
> "os" : {  
> "codename" : "Core",  
> "name" : "CentOS Linux",  
> "family" : "redhat",  
> "version" : "7 (Core)",  
> "platform" : "centos"  
> },  
> "containerized" : true,  
> "name" : "met-elk-exp6a",  
> "id" : "c90656fd991348499dd37b4c2f145caf",  
> "architecture" : "x86\_64"  
> },  
> "event" : {  
> "created" : "2019-03-04T18:53:37.739Z",  
> "dataset" : "elasticsearch.server"  
> }  
> }  
> },

---

<div class="post-metadata">

**Author:** ![rugenl](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rugenl/32/12887_2.png) [@rugenl](https://discuss.elastic.co/u/rugenl)\
**Post date:** [March 5, 2019, 2:32pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/17 "2019-03-05T14:32:22Z")

</div>

Unless the log formats change for elasticsearch and logstash between 6.6.0 and 6.6.1, maybe there is something wrong with the date filter.

Comparing the pipelines, I think the field: message is just order in the grok.

```
> $ diff 6.6.0.txt 6.6.1.txt 
> 2c2
> < "filebeat-6.6.0-logstash-log-pipeline-plain" : {
> ---
> > "filebeat-6.6.1-logstash-log-pipeline-plain" : {
> 15d14
> < "field" : "message",
> 23c22,23
> < ]
> ---
> > ],
> > "field" : "message"
> 38c38,39
> < "rename" : {
> ---
> > "date" : {
> > "field" : "logstash.log.timestamp",
> 39a41,49
> > "formats" : [
> > "ISO8601"
> > ],
> > "timezone" : "{{ event.timezone }}",
> > "ignore_failure" : true
> > }
> > },
> > {
> > "remove" : {
```

---

<div class="post-metadata">

**Author:** ![rugenl](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rugenl/32/12887_2.png) [@rugenl](https://discuss.elastic.co/u/rugenl)\
**Post date:** [March 5, 2019, 3:15pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/18 "2019-03-05T15:15:39Z")

</div>

I updated all elastic components to 6.6.1 on my single-node stack, no change in the filebeat 6.6.1 results. Just eliminating the version mismatch where I can.

---

<div class="post-metadata">

**Author:** ![cachedout](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/cachedout/32/38707_2.png) [@cachedout](https://discuss.elastic.co/u/cachedout)\
**Post date:** [March 5, 2019, 3:39pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/19 "2019-03-05T15:39:54Z")

</div>

Does any additional information come to light when setting `ignore_failure` to `false`?

---

<div class="post-metadata">

**Author:** ![rugenl](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rugenl/32/12887_2.png) [@rugenl](https://discuss.elastic.co/u/rugenl)\
**Post date:** [March 5, 2019, 4:26pm UTC](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679/20 "2019-03-05T16:26:44Z")

</div>

All that that did was change the counts in the pipeline, so I took out the on\_failure section. Now I'm getting the error below, no timezone?

> [2019-03-05T10:20:58,964][DEBUG][o.e.a.b.TransportBulkAction] [met-elk-exp6a] failed to execute pipeline [filebeat-6.6.1-logstash-log-pipeline-plain] for document [filebeat-6.6.1-2019.03.05/doc/null]  
> org.elasticsearch.ElasticsearchException: java.lang.IllegalArgumentException: java.lang.IllegalArgumentException: unable to parse date [2019-03-05T10:20:34,053]  
> at org.elasticsearch.ingest.CompoundProcessor.newCompoundProcessorException(CompoundProcessor.java:195) ~[elasticsearch-6.6.1.jar:6.6.1]  
> at org.elasticsearch.ingest.CompoundProcessor.execute(CompoundProcessor.java:134) ~[elasticsearch-6.6.1.jar:6.6.1]  
> at org.elasticsearch.ingest.Pipeline.execute(Pipeline.java:97) ~[elasticsearch-6.6.1.jar:6.6.1]  
> at org.elasticsearch.ingest.IngestService.innerExecute(IngestService.java:473) ~[elasticsearch-6.6.1.jar:6.6.1]  
> at org.elasticsearch.ingest.IngestService.access$100(IngestService.java:68) ~[elasticsearch-6.6.1.jar:6.6.1]  
> at org.elasticsearch.ingest.IngestService$4.doRun(IngestService.java:402) [elasticsearch-6.6.1.jar:6.6.1]  
> at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:759) [elasticsearch-6.6.1.jar:6.6.1]  
> at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-6.6.1.jar:6.6.1]  
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0\_191]  
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0\_191]  
> at java.lang.Thread.run(Thread.java:748) [?:1.8.0\_191]  
> Caused by: java.lang.IllegalArgumentException: java.lang.IllegalArgumentException: unable to parse date [2019-03-05T10:20:34,053]  
> ... 11 more  
> Caused by: java.lang.IllegalArgumentException: unable to parse date [2019-03-05T10:20:34,053]  
> at org.elasticsearch.ingest.common.DateProcessor.execute(DateProcessor.java:97) ~[?:?]  
> at org.elasticsearch.ingest.CompoundProcessor.execute(CompoundProcessor.java:124) ~[elasticsearch-6.6.1.jar:6.6.1]  
> ... 9 more  
> Caused by: java.lang.IllegalArgumentException: The datetime zone id '' is not recognised  
> at org.joda.time.DateTimeZone.forID(DateTimeZone.java:234) ~[joda-time-2.10.1.jar:2.10.1]  
> at org.elasticsearch.ingest.common.DateProcessor.newDateTimeZone(DateProcessor.java:69) ~[?:?]  
> at org.elasticsearch.ingest.common.DateProcessor.lambda$new$0(DateProcessor.java:64) ~[?:?]  
> at org.elasticsearch.ingest.common.DateProcessor.execute(DateProcessor.java:89) ~[?:?]  
> at org.elasticsearch.ingest.CompoundProcessor.execute(CompoundProcessor.java:124) ~[elasticsearch-6.6.1.jar:6.6.1]  
> ... 9 more

[Next page](https://discuss.elastic.co/t/logs-time-6-hours-behind-local-time/169679.md?page=2)