# Time delay between logstash and elasticsearch

**URL:** <https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749>\
**Category:** Logstash\
**Created:** [April 13, 2020, 9:31am UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749 "2020-04-13T09:31:51Z")\
**Posts on this page:** 13\
**Page:** 1

<div class="post-metadata">

**Author:** ![honglei](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/honglei/32/66084_2.png) [@honglei](https://discuss.elastic.co/u/honglei)\
**Post date:** [April 13, 2020, 9:31am UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749/1 "2020-04-13T09:31:52Z")

</div>

My current pipeline is:  
filebeat-\>Logstash-\>ES(3 nodes).

Filebeat and Logstash are deployed in the kubernetes cluster, both of the them are version-7.6.2.  
ES is deployed as a container on a virtual machine, images version is [amazon/opendistro-for-elasticsearch:1.6.0]

I found that the logs on ES have a delay of about 7~8 minutes.

 ![Screenshot from 2020-04-13 17-10-28](https://us1.discourse-cdn.com/elastic/original/3X/9/c/9c1e3a90acc883a82c289206fbfb7ad83372d36a.png)

Logstash config:

```auto
 inputs:
    main: |-
      input {
        beats {
          port => 5044
        }
      }

  filters:
    # main: |-
    # filter {
    # }

  outputs:
    main: |-
      output {
        elasticsearch {
          hosts => ["${ELASTICSEARCH_HOST}:${ELASTICSEARCH_PORT}"]
          manage_template => false
          index => "XXX_%{+YYYY.MM.dd}"
          user => "XXXX"
          password => "XXX"
          ilm_enabled => false
        }
      }

```

more infomation about logstash:

```auto
$ cat logstash.yml 
config.reload.automatic: true
http.host: 0.0.0.0
http.port: 9600
path.config: /usr/share/logstash/pipeline
path.data: /usr/share/logstash/data
queue.checkpoint.writes: 1
queue.drain: true
queue.max_bytes: 1gb
queue.type: persisted

$ curl -XGET 'localhost:9600/_node/stats/os?pretty'
{
  "host" : "log-logstash-0",
  "version" : "7.6.2",
  "http_address" : "0.0.0.0:9600",
  "id" : "9a699ca0-63ff-4d4c-bfda-6c1672603009",
  "name" : "log-logstash-0",
  "ephemeral_id" : "cacf7e7a-0a5e-426b-93d1-b50d72037c07",
  "status" : "green",
  "snapshot" : false,
  "pipeline" : {
    "workers" : 2,
    "batch_size" : 125,
    "batch_delay" : 50
  },
  "os" : {
    "cgroup" : {
      "cpu" : {
        "cfs_quota_micros" : 200000,
        "stat" : {
          "time_throttled_nanos" : 10805873439,
          "number_of_times_throttled" : 198,
          "number_of_elapsed_periods" : 699951
        },
        "control_group" : "/",
        "cfs_period_micros" : 100000
      },
      "cpuacct" : {
        "usage_nanos" : 3358394995977,
        "control_group" : "/"
      }
    }
  }
}

```

According to prometheus indicators, logstash has a low load(cpu: 0.035, memory: 1GB).  
I also made a pressure test on ES, the throughput is about 6000/s.

How can I figure out where the problem currently resides?

---

<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:** [April 13, 2020, 2:32pm UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749/2 "2020-04-13T14:32:34Z")

</div>

Are you setting @timestamp to a value from the log or the ingest time? If ingest time, compare @timestamp to the value in the log.

What is the index refresh\_interval?

If you have Kibana monitoring enabled, what is the indexing latency? Monitoring for logstash, if enabled, also has event latency.

Are you using ntp everywhere?

---

<div class="post-metadata">

**Author:** ![Christian\_Dahlqvist](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/christian_dahlqvist/32/4617_2.png) [@Christian\_Dahlqvist](https://discuss.elastic.co/u/Christian_Dahlqvist)\
**Post date:** [April 13, 2020, 3:44pm UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749/3 "2020-04-13T15:44:17Z")

</div>

> [@honglei](#):
>
> queue.checkpoint.writes: 1

It seems you have set this to ensure as high durability as possible. Note that this also will result in increased disk I/O and potentially lower throughput as a result. Does the storage you are using for the Logstash node have capacity to handle this or might it be a bottleneck?

---

<div class="post-metadata">

**Author:** ![honglei](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/honglei/32/66084_2.png) [@honglei](https://discuss.elastic.co/u/honglei)\
**Post date:** [April 14, 2020, 2:19am UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749/4 "2020-04-14T02:19:29Z")

</div>

@rugenl Thanks for your reply

> [@"rugenl](#):
>
> Are you setting @timestamp to a value from the log or the ingest time? If ingest time, compare @timestamp to the value in the log.

I'm setting @timestamp to a value from the ingest time. The ingest time is about 3 seconds slower than the log time

> [@"rugenl](#):
>
> What is the index refresh\_interval?

The index refresh\_interval is not specified, Use the default value(1s).

```auto
GET <index>/_settings?pretty
{
  "XXX" : {
    "settings" : {
      "index" : {
        "creation_date" : "1586822809255",
        "number_of_shards" : "1",
        "number_of_replicas" : "1",
        "uuid" : "t3dhllx5SfG2XzKakS-RSw",
        "version" : {
          "created" : "7060199"
        },
        "provided_name" : "XXX"
      }
    }
  }
}

```

> [@"rugenl](#):
>
> If you have Kibana monitoring enabled, what is the indexing latency? Monitoring for logstash, if enabled, also has event latency.

We did not enable monitoring.

> [@"rugenl](#):
>
> Are you using ntp everywhere?

Yes.

---

<div class="post-metadata">

**Author:** ![honglei](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/honglei/32/66084_2.png) [@honglei](https://discuss.elastic.co/u/honglei)\
**Post date:** [April 14, 2020, 3:09am UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749/5 "2020-04-14T03:09:37Z")

</div>

> [@honglei](#):
>
> > [@honglei](#):
> >
> > queue.checkpoint.writes: 1
> 
> It seems you have set this to ensure as high durability as possible. Note that this also will result in increased disk I/O and potentially lower throughput as a result. Does the storage you are using for the Logstash node have capacity to handle this or might it be a bottleneck?

@Christian_Dahlqvist Thanks for your reply.  
The value of iowait is 6.5% ~ 7.5 on Logstash node. Disk write speed is 80KB/s and read speed is 20KB/S, so I think the disk is not the bottleneck.

BTW: A few days after Logstash restarts, the problem will reproduce. The problem will not reproduce immediately.  
I have 4 kubernetes clusters, I restarted logstash on one of the clusters two days ago, but the problem has not been reproduced.

---

<div class="post-metadata">

**Author:** ![Christian\_Dahlqvist](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/christian_dahlqvist/32/4617_2.png) [@Christian\_Dahlqvist](https://discuss.elastic.co/u/Christian_Dahlqvist)\
**Post date:** [April 14, 2020, 5:55am UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749/6 "2020-04-14T05:55:03Z")

</div>

That much iowait could be noticeable. Are you monitoring iowait so you can see whether the amount of iowait varies over time? Does this behaviour change if you increase the write checkpoint size?

---

<div class="post-metadata">

**Author:** ![honglei](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/honglei/32/66084_2.png) [@honglei](https://discuss.elastic.co/u/honglei)\
**Post date:** [April 14, 2020, 8:26am UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749/7 "2020-04-14T08:26:55Z")

</div>

> [@Christian\_Dahlqvist](#):
>
> That much iowait could be noticeable. Are you monitoring iowait so you can see whether the amount of iowait varies over time? Does this behaviour change if you increase the write checkpoint size?

@Christian_Dahlqvist Thanks for your advise.I changed the value of queue.checkpoint.writes from 1 to 1024. The value of iowait is significantly lower than before.  
But the logs on ES still have a delay of about 7~8 minutes.

 ![Screenshot from 2020-04-14 16-26-20](https://us1.discourse-cdn.com/elastic/original/3X/7/1/71f135cd9eda45ae22cd221fa99b333db6423e4f.png)

---

<div class="post-metadata">

**Author:** ![Christian\_Dahlqvist](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/christian_dahlqvist/32/4617_2.png) [@Christian\_Dahlqvist](https://discuss.elastic.co/u/Christian_Dahlqvist)\
**Post date:** [April 14, 2020, 8:31am UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749/8 "2020-04-14T08:31:13Z")

</div>

> [@honglei](#):
>
> "time\_throttled\_nanos" : 10805873439,

Why is it reporting being throttled? How much resurces does it have available? Is the time synchronized across the hosts/pods?

---

<div class="post-metadata">

**Author:** ![honglei](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/honglei/32/66084_2.png) [@honglei](https://discuss.elastic.co/u/honglei)\
**Post date:** [April 14, 2020, 8:48am UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749/9 "2020-04-14T08:48:20Z")

</div>

> [@Christian\_Dahlqvist](#):
>
> Why is it reporting being throttled? How much resurces does it have available? Is the time synchronized across the hosts/pods?

Host resource: 4Core / 16G MEM  
Pod resource: 2Core / 2G MEM

Time is synchronized across the hosts/pods.

```auto
$ date; sudo docker exec 0723956d651b date
Tue Apr 14 16:43:04 CST 2020
Tue Apr 14 08:43:04 UTC 2020

```

---

<div class="post-metadata">

**Author:** ![Christian\_Dahlqvist](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/christian_dahlqvist/32/4617_2.png) [@Christian\_Dahlqvist](https://discuss.elastic.co/u/Christian_Dahlqvist)\
**Post date:** [April 14, 2020, 8:52am UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749/10 "2020-04-14T08:52:11Z")

</div>

Are all pods running on this host, including the application generating logs and Elasticsearch?

If so, what does CPU usage on the underlying host look like?

---

<div class="post-metadata">

**Author:** ![honglei](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/honglei/32/66084_2.png) [@honglei](https://discuss.elastic.co/u/honglei)\
**Post date:** [April 14, 2020, 9:04am UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749/11 "2020-04-14T09:04:03Z")

</div>

> [@Christian\_Dahlqvist](#):
>
> Are all pods running on this host, including the application generating logs and Elasticsearch?

No, filebeat, logstash and application pods are on the same host.  
The Elasticsearch cluster is outside the k8s cluster.

The architecture is as follows:  
 ![elk](https://us1.discourse-cdn.com/elastic/original/3X/6/f/6fdc3d534cb7b9502a8c7a4e33d9cda73c095bad.jpeg)

---

<div class="post-metadata">

**Author:** ![honglei](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/honglei/32/66084_2.png) [@honglei](https://discuss.elastic.co/u/honglei)\
**Post date:** [April 14, 2020, 3:20pm UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749/12 "2020-04-14T15:20:13Z")

</div>

I have tuned logstash performance with follow configuration:

```auto
$ cat logstash.yml 
......
pipeline.batch.delay: 100
pipeline.batch.size: 250
pipeline.workers: 4
queue.checkpoint.writes: 4096
......

```

Now it looks like there is no delay, the amount of iowait has decreased.  
Thanks for your help.  
@Christian_Dahlqvist  
@rugenl

---

<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:** [May 12, 2020, 3:20pm UTC](https://discuss.elastic.co/t/time-delay-between-logstash-and-elasticsearch/227749/13 "2020-05-12T15:20:20Z")

</div>

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