Loki: entry out of order' for stream

[vishnubraj]

i am forwarding logs from fluentd to loki..
i am getting below mentioned error in loki. both the servers are having NTP configured and it is sync.

level=warn ts=2020-04-05T16:39:22.772490867Z caller=grpc_logging.go:38 method=/logproto.Pusher/Push duration=6.996248ms err="rpc error: code = Code(400) desc = entry with timestamp 2020-04-05 16:39:11 +0000 UTC ignored, reason: 'entry out of order' for stream: {env=\"dev\"},\nentry with timestamp 2020-04-05 16:39:12 +0000 UTC ignored, reason: 'entry out of order' for stream: {env=\"dev\"},\nentry with timestamp 2020-04-05 16:39:12 +0000 UTC ignored, reason: 'entry out of order' for stream: {env=\"dev\"},\nentry with timestamp 2020-04-05 16:39:12 +0000 UTC ignored, reason: 'entry out of order' for stream: {env=\"dev\"},\nentry with timestamp 2020-04-05 16:39:12 +0000 UTC ignored, reason: 'entry out of order' for stream: {env=\"dev\"},\nentry with timestamp 2020-04-05 16:39:12 +0000 UTC ignored, reason: 'entry out of order' for stream: {env=\"dev\"},\nentry with timestamp 2020-04-05 16:39:12.771213579 +0000 UTC ignored, reason: 'entry out of order' for stream: {env=\"dev\"},\nentry with timestamp 2020-04-05 16:39:13 +0000 UTC ignored, reason: 'entry out of order' for stream: {env=\"dev\"},\nentry with timestamp 2020-04-05 16:39:13 +0000 UTC ignored, reason: 'entry out of order' for stream: {env=\"dev\"},\nentry with timestamp 2020-04-05 16:39:13 +0000 UTC ignored, reason: 'entry out of order' for stream: {env=\"dev\"},\ntotal ignored: 26 out of 1524" msg="gRPC\n

below mentioned in my loki config..

auth_enabled: false

server:
  http_listen_port: 3100
  http_listen_address: 10.3.1.144

ingester:
  lifecycler:
    address: 10.3.1.144
    ring:
      kvstore:
        store: etcd
        etcd:
          endpoints: ["10.3.0.206:2380"]
      replication_factor: 1
    final_sleep: 0s
  chunk_idle_period: 5m
  chunk_retain_period: 30s

schema_config:
  configs:
  - from: 2020-03-20
    store: cassandra
    object_store: cassandra
    schema: v11
    index:
      prefix: logs_
      period: 168h

storage_config:
  cassandra:
    addresses: 10.3.1.48
    auth: false
    keyspace: lokiindex


limits_config:
  enforce_metric_name: false
  reject_old_samples: true
  reject_old_samples_max_age: 168h

chunk_store_config:
  max_look_back_period: 0

table_manager:
  chunk_tables_provisioning:
    inactive_read_throughput: 0
    inactive_write_throughput: 0
    provisioned_read_throughput: 0
    provisioned_write_throughput: 0
  index_tables_provisioning:
    inactive_read_throughput: 0
    inactive_write_throughput: 0
    provisioned_read_throughput: 0
    provisioned_write_throughput: 0
  retention_deletes_enabled: false
  retention_period: 0

[yeya24]

We are getting a lot of these errors as well.

[owen-d]

It looks like the label set (stream) in question only has one label: {env="dev"}. It seems like you have two servers; is it possible they're using the same {env="dev"} stream? That would account for these errors regardless of NTP or not. As a rule of thumb, the same stream should not be processed by multiple agents (promtail or fluent). I'd suggest an instance_id or hostname label to partition these.

[cyriltovena]

https://github.com/grafana/loki/tree/master/docs/clients/fluentd#multi-worker-usage

[jcdauchy-moodys]

@owen-d Thanks for the clarification, so if I understand correctly, we cannot send the same set of Labels from 2 different locations (here 2 fluent-bit clients) ?

So if we want to do so, we need to add one more label to differentiate the 2 clients.

[owen-d]

Exactly. This generally seems to be in line with usage patterns we see: it's nice to be able to distinguish logs from replica A from those of replica B.

[yangvipguang]

@owen-d I have the same error with fluentd bit agent .

But the instance="crm-core-5b7d5886c-7v2gr is unique. So what's wrong with loki?

[sbaier1]

yeah this doesn't really seem resolved. even when implementing what you are hinting at here and in the documentation (partitioning by specifying not only pod ID but also the node's hostname) i am still seeing this error.

So the root cause for this problem doesn't appear to be logs being sent from separate hosts.

[thomaspeitz]

Same happening using loki together with s3 or filesystem and filebeat as log shipper.

level=warn ts=2020-12-14T10:02:39.378422625Z caller=grpc_logging.go:38 method=/logproto.Pusher/Push duration=2.566245ms err="rpc error: code = Code(400) desc = entry with timestamp 2020-12-14 10:00:10.130678528 +0000 UTC ignored, reason: 'entry out of order' for stream: {app=\"cluster-autoscaler\", container=\"cluster-autoscaler\", filename=\"/var/log/pods/kube-system_cluster-autoscaler-748c997bff-7nxbv_379c5865-f1bc-4548-8a01-e7279336b304/cluster-autoscaler/3.log\", job=\"kube-system/cluster-autoscaler\", namespace=\"kube-system\", pod=\"cluster-autoscaler-748c997bff-7nxbv\", pod_template_hash=\"748c997bff\", stage=\"staging\", stream=\"stderr\"},\nentry with timestamp 2020-12-14 10:00:10.1306888 +0000 UTC ignored, reason: 'entry out of order' for stream: {app=\"cluster-autoscaler\", container=\"cluster-autoscaler\", filename=\"/var/log/pods/kube-system_cluster-autoscaler-748c997bff-7nxbv_379c5865-f1bc-4548-8a01-e7279336b304/cluster-autoscaler/3.log\", job=\"kube-system/cluster-autoscaler\", namespace=\"kube-system\", pod=\"cluster-autoscaler-748c997bff-7nxbv\", pod_template_hash=\"748c997bff\", stage=\"staging\", stream=\"stderr\"},\nentry with timestamp 2020-12-14 10:00:10.130785285 +0000 UTC ignored, reason: 'entry out of order' for stream: {app=\"cluster-autoscaler\", container=\"cluster-autoscaler\", filename=\"/var/log/pods/kube-system_cluster-autoscaler-748c997bff-7nxbv_379c5865-f1bc-4548-8a01-e7279336b304/cluster-autoscaler/3.log\", job=\"kube-system/cluster-autoscaler\", namespace=\"kube-system\", pod=\"cluster-autoscaler-748c997bff-7nxbv\", pod_template_hash=\"748c997bff\", stage=\"staging\", stream=\"stderr\"},\nentry with timestamp 2020-12-14 10:00:10.130848959 +0000 UTC ignored, reason: 'entry out of order' for stream: {app=\"cluster-autoscaler\", container=\"cluster-autoscaler\", filename=\"/var/log/pods/kube-system_cluster-autoscaler-748c997bff-7nxbv_379c5865-f1bc-4548-8a01-e7279336b304/cluster-autoscaler/3.log\", job=\"kube-system/cluster-autoscaler\", namespace=\"kube-system\", pod=\"cluster-autoscaler-748c997bff-7nxbv\", pod_template_hash=\"748c997bff\", stage=\"staging\", stream=\"stderr\"},\nentry with timestamp 2020-12-14 10:00:10.130855055 +0000 UTC ignored, reason: 'entry out of order' for stream: {app=\"cluster-autoscaler\", container=\"cluster-autoscaler\", filename=\"/var/log/pods/kube-system_cluster-autoscaler-748c997bff-7nxbv_379c5865-f1bc-4548-8a01-e7279336b304/cluster-autoscaler/3.log\", job=\"kube-system/cluster-autoscaler\", namespace=\"kube-system\", pod=\"cluster-autoscaler-748c997bff-7nxbv\", pod_template_hash=\"748c997bff\", stage=\"staging\", stream=\"stderr\"},\nentry with timestamp 2020-12-14 10:00:10.131377212 +0000 UTC ignored, reason: 'entry out of order' for stream: {app=\"cluster-autoscaler\", container=\"cluster-autoscaler\", filename=\"/var/log/pods/kube-system_cluster-autoscaler-748c997bff-7nxbv_379c5865-f1bc-4548-8a01-e7279336b304/cluster-autoscaler/3.log\", job=\"kube-system/cluster-autoscaler\", namespace=\"kube-system\", pod=\"cluster-autoscaler-748c997bff-7nxbv\", pod_template_hash=\"748c997bff\", stage=\"staging\", stream=\"stderr\"},\nentry with timestamp 2020-12-14 10:00:10.131809082 +0000 UTC ignored, reason: 'entry out of order' for stream: {app=\"cluster-autoscaler\", container=\"cluster-autoscaler\", filename=\"/var/log/pods/kube-system_cluster-autoscaler-748c997bff-7nxbv_379c5865-f1bc-4548-8a01-e7279336b304/cluster-autoscaler/3.log\", job=\"kube-system/cluster-autoscaler\", namespace=\"kube-system\", pod=\"cluster-autoscaler-748c997bff-7nxbv\", pod_template_hash=\"748c997bff\", stage=\"staging\", stream=\"stderr\"},\nentry with timestamp 2020-12-14 10:00:10.132337781 +0000 UTC ignored, reason: 'entry out of order' for stream: {app=\"cluster-autoscaler\", container=\"cluster-autoscaler\", filename=\"/var/log/pods/kube-system_cluster-autoscaler-748c997bff-7nxbv_379c5865-f1bc-4548-8a01-e7279336b304/cluster-autoscaler/3.log\", job=\"kube-system/cluster-autoscaler\", namespace=\"kube-system\", pod=\"cluster-autoscaler-748c997bff-7nxbv\", pod_template_hash=\"748c997bff\", stage=\"staging\", stream=\"stderr\"},\nentry with timestamp 2020-12-14 10:00:10.132345547 +0000 UTC ignored, reason: 'entry out of order' for stream: {app=\"cluster-autoscaler\", container=\"cluster-autoscaler\", filename=\"/var/log/pods/kube-system_cluster-autoscaler-748c997bff-7nxbv_379c5865-f1bc-4548-8a01-e7279336b304/cluster-autoscaler/3.log\", job=\"kube-system/cluster-autoscaler\", namespace=\"kube-system\", pod=\"cluster-autoscaler-748c997bff-7nxbv\", pod_template_hash=\"748c997bff\", stage=\"staging\", stream=\"stderr\"},\nentry with timestamp 2020-12-14 10:00:10.132848338 +0000 UTC ignored, reason: 'entry out of order' for stream: {app=\"cluster-autoscaler\", container=\"cluster-autoscaler\", filename=\"/var/log/pods/kube-system_cluster-autoscaler-748c997bff-7nxbv_379c5865-f1bc-4548-8a01-e7279336b304/cluster-autoscaler/3.log\", job=\"kube-system/cluster-autoscaler\", namespace=\"kube-system\", pod=\"cluster-autoscaler-748c997bff-7nxbv\", pod_template_hash=\"748c997bff\", stage=\"staging\", stream=\"stderr\"},\ntotal ignored: 642 out of 1295" msg="gRPC\n"