search

canonical / loki-k8s-operator

https://charmhub.io/loki-k8s
Apache License 2.0
10 stars 16 forks source link

Loki responds with "invalid chunk checksum" #465

Closed cbartz closed 2 weeks ago

cbartz commented 1 month ago

Bug Description

We have a Grafana dashboard that uses Loki queries.

Today (and in the past https://matrix.to/#/!nHXpRkcSNJHlHdUGbQ:ubuntu.com/$5ZtI4_oARaV2Dlzz6UonBQ6-vSX62d31PXPZhBDKFUg?via=ubuntu.com&via=matrix.org) a lot of panels were not rendered because Loki responded with "invalid chunk checksum size".

Screenshot from 2024-10-15 08-28-09

Changing the timerange made the dashboard work again.

There were failing liveness probes in that timerange:

  Warning  Unhealthy     97m                     kubelet          (combined from similar events): Readiness probe failed: Get "http://192.168.102.212:38814/v1/health?level=ready": dial tcp 192.168.102.212:38814: i/o timeout (Client.Timeout exceeded while awaiting headers)
  Normal   Killing       41m (x14 over 4d4h)     kubelet          Container loki failed liveness probe, will be restarted
  Warning  Unhealthy     41m (x14 over 4d4h)     kubelet          Liveness probe failed: Get "http://192.168.102.212:38813/v1/health?level=alive": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
  Warning  Unhealthy     41m (x33 over 4d4h)     kubelet          Readiness probe failed: Get "http://192.168.102.212:38813/v1/health?level=ready": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
  Normal   Created       41m (x15 over 4d23h)    kubelet          Created container loki
  Normal   Pulled        41m (x15 over 4d23h)    kubelet          Container image "registry.jujucharms.com/charm/ayt4gaga2x20gye32qthgygevco13qgq6rfff/loki-image@sha256:b53452382346d2447e17ec27663be71cf0fedfc12e5d227f79591347c4c43b14" already present on machine
  Normal   Started       41m (x15 over 4d23h)    kubelet          Started container loki

(https://pastebin.canonical.com/p/Hqphq85CyS/)

To Reproduce

Usual COS deployment.

Environment

loki                  2.9.5    active      1  loki-k8s              latest/stable  145  10.87.145.140  no

juju 3.1.8

:~$ kubectl version
Client Version: v1.31.1
Kustomize Version: v5.4.2
Server Version: v1.26.15
WARNING: version difference between client (1.31) and server (1.26) exceeds the supported minor version skew of +/-1

Relevant log output

kubectl logs loki-0 -c loki

2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.742263171Z caller=batch.go:718 org_id=fake traceID=50f35e6d6bafd28a msg="error fetching chunks" err="invalid chunk checksum"
2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.742264013Z caller=batch.go:718 org_id=fake traceID=50f35e6d6bafd28a msg="error fetching chunks" err="invalid chunk checksum"
2024-10-15T05:50:08.837Z [loki] level=warn ts=2024-10-15T05:50:08.742446446Z caller=grpc_logging.go:78 method=/logproto.Querier/QuerySample duration=6.244842ms err="invalid chunk checksum" msg=gRPC
2024-10-15T05:50:08.837Z [loki] level=warn ts=2024-10-15T05:50:08.742452387Z caller=grpc_logging.go:78 method=/logproto.Querier/QuerySample duration=6.188204ms err="invalid chunk checksum" msg=gRPC
2024-10-15T05:50:08.837Z [loki] level=info ts=2024-10-15T05:50:08.742843675Z caller=metrics.go:160 component=querier org_id=fake traceID=50f35e6d6bafd28a latency=fast query="count by (flavor)(sum by(instance, flavor)(max_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" | unwrap idle_runners[7200s])) == 0 ) / count by (flavor)(sum by(instance, flavor)(count_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" [7200s])))" query_hash=3861148486 query_type=metric range_type=instant length=0s start_delta=8.742838545s end_delta=8.742838706s step=0s duration=7.604411ms status=500 limit=100 returned_lines=0 throughput=0B total_bytes=0B total_bytes_structured_metadata=0B lines_per_second=0 total_lines=0 post_filter_lines=0 total_entries=0 store_chunks_download_time=0s queue_time=144.883µs splits=0 shards=0 chunk_refs_fetch_time=0s cache_chunk_req=0 cache_chunk_hit=0 cache_chunk_bytes_stored=0 cache_chunk_bytes_fetched=0 cache_chunk_download_time=0s cache_index_req=0 cache_index_hit=0 cache_index_download_time=0s cache_stats_results_req=0 cache_stats_results_hit=0 cache_stats_results_download_time=0s cache_result_req=0 cache_result_hit=0 cache_result_download_time=0s
2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.744520522Z caller=retry.go:73 org_id=fake traceID=50f35e6d6bafd28a msg="error processing request" try=0 query="count by (flavor)(sum by(instance, flavor)(max_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" | unwrap idle_runners[7200s])) == 0 ) / count by (flavor)(sum by(instance, flavor)(count_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" [7200s])))" err="rpc error: code = Code(500) desc = 2 errors: rpc error: code = Unknown desc = invalid chunk checksum; rpc error: code = Unknown desc = invalid chunk checksum\n"
2024-10-15T05:50:08.837Z [loki] level=info ts=2024-10-15T05:50:08.745167411Z caller=engine.go:232 component=querier org_id=fake traceID=50f35e6d6bafd28a msg="executing query" type=instant query="count by (flavor)(sum by(instance, flavor)(max_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" | unwrap idle_runners[7200s])) == 0 ) / count by (flavor)(sum by(instance, flavor)(count_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" [7200s])))" query_hash=3861148486
2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.747588992Z caller=batch.go:718 org_id=fake traceID=50f35e6d6bafd28a msg="error fetching chunks" err="invalid chunk checksum"
2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.747670526Z caller=batch.go:718 org_id=fake traceID=50f35e6d6bafd28a msg="error fetching chunks" err="invalid chunk checksum"
2024-10-15T05:50:08.837Z [loki] level=warn ts=2024-10-15T05:50:08.747700392Z caller=grpc_logging.go:78 duration=1.960462ms method=/logproto.Querier/QuerySample err="invalid chunk checksum" msg=gRPC
2024-10-15T05:50:08.837Z [loki] level=warn ts=2024-10-15T05:50:08.747758582Z caller=grpc_logging.go:78 method=/logproto.Querier/QuerySample duration=2.110685ms err="invalid chunk checksum" msg=gRPC
2024-10-15T05:50:08.837Z [loki] level=info ts=2024-10-15T05:50:08.748261649Z caller=metrics.go:160 component=querier org_id=fake traceID=50f35e6d6bafd28a latency=fast query="count by (flavor)(sum by(instance, flavor)(max_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" | unwrap idle_runners[7200s])) == 0 ) / count by (flavor)(sum by(instance, flavor)(count_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" [7200s])))" query_hash=3861148486 query_type=metric range_type=instant length=0s start_delta=8.748254887s end_delta=8.748255016s step=0s duration=2.886406ms status=500 limit=100 returned_lines=0 throughput=0B total_bytes=0B total_bytes_structured_metadata=0B lines_per_second=0 total_lines=0 post_filter_lines=0 total_entries=0 store_chunks_download_time=0s queue_time=45.616µs splits=0 shards=0 chunk_refs_fetch_time=0s cache_chunk_req=0 cache_chunk_hit=0 cache_chunk_bytes_stored=0 cache_chunk_bytes_fetched=0 cache_chunk_download_time=0s cache_index_req=0 cache_index_hit=0 cache_index_download_time=0s cache_stats_results_req=0 cache_stats_results_hit=0 cache_stats_results_download_time=0s cache_result_req=0 cache_result_hit=0 cache_result_download_time=0s
2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.748695646Z caller=retry.go:73 org_id=fake traceID=50f35e6d6bafd28a msg="error processing request" try=1 query="count by (flavor)(sum by(instance, flavor)(max_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" | unwrap idle_runners[7200s])) == 0 ) / count by (flavor)(sum by(instance, flavor)(count_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" [7200s])))" err="rpc error: code = Code(500) desc = 2 errors: rpc error: code = Unknown desc = invalid chunk checksum; rpc error: code = Unknown desc = invalid chunk checksum\n"
2024-10-15T05:50:08.837Z [loki] level=info ts=2024-10-15T05:50:08.74919121Z caller=engine.go:232 component=querier org_id=fake traceID=50f35e6d6bafd28a msg="executing query" type=instant query="count by (flavor)(sum by(instance, flavor)(max_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" | unwrap idle_runners[7200s])) == 0 ) / count by (flavor)(sum by(instance, flavor)(count_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" [7200s])))" query_hash=3861148486
2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.751408145Z caller=batch.go:718 org_id=fake traceID=50f35e6d6bafd28a msg="error fetching chunks" err="invalid chunk checksum"
2024-10-15T05:50:08.837Z [loki] level=warn ts=2024-10-15T05:50:08.751492213Z caller=grpc_logging.go:78 duration=1.857218ms method=/logproto.Querier/QuerySample err="invalid chunk checksum" msg=gRPC
2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.75192056Z caller=batch.go:718 org_id=fake traceID=50f35e6d6bafd28a msg="error fetching chunks" err="invalid chunk checksum"
2024-10-15T05:50:08.837Z [loki] level=warn ts=2024-10-15T05:50:08.752024576Z caller=grpc_logging.go:78 method=/logproto.Querier/QuerySample duration=2.361188ms err="invalid chunk checksum" msg=gRPC
2024-10-15T05:50:08.837Z [loki] level=info ts=2024-10-15T05:50:08.752239392Z caller=metrics.go:160 component=querier org_id=fake traceID=50f35e6d6bafd28a latency=fast query="count by (flavor)(sum by(instance, flavor)(max_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" | unwrap idle_runners[7200s])) == 0 ) / count by (flavor)(sum by(instance, flavor)(count_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" [7200s])))" query_hash=3861148486 query_type=metric range_type=instant length=0s start_delta=8.752235644s end_delta=8.752235773s step=0s duration=2.92488ms status=500 limit=100 returned_lines=0 throughput=0B total_bytes=0B total_bytes_structured_metadata=0B lines_per_second=0 total_lines=0 post_filter_lines=0 total_entries=0 store_chunks_download_time=0s queue_time=23.273µs splits=0 shards=0 chunk_refs_fetch_time=0s cache_chunk_req=0 cache_chunk_hit=0 cache_chunk_bytes_stored=0 cache_chunk_bytes_fetched=0 cache_chunk_download_time=0s cache_index_req=0 cache_index_hit=0 cache_index_download_time=0s cache_stats_results_req=0 cache_stats_results_hit=0 cache_stats_results_download_time=0s cache_result_req=0 cache_result_hit=0 cache_result_download_time=0s
2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.752497297Z caller=retry.go:73 org_id=fake traceID=50f35e6d6bafd28a msg="error processing request" try=2 query="count by (flavor)(sum by(instance, flavor)(max_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" | unwrap idle_runners[7200s])) == 0 ) / count by (flavor)(sum by(instance, flavor)(count_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" [7200s])))" err="rpc error: code = Code(500) desc = 2 errors: rpc error: code = Unknown desc = invalid chunk checksum; rpc error: code = Unknown desc = invalid chunk checksum\n"
2024-10-15T05:50:08.837Z [loki] level=info ts=2024-10-15T05:50:08.753013008Z caller=engine.go:232 component=querier org_id=fake traceID=50f35e6d6bafd28a msg="executing query" type=instant query="count by (flavor)(sum by(instance, flavor)(max_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" | unwrap idle_runners[7200s])) == 0 ) / count by (flavor)(sum by(instance, flavor)(count_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" [7200s])))" query_hash=3861148486
2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.755402518Z caller=batch.go:718 org_id=fake traceID=50f35e6d6bafd28a msg="error fetching chunks" err="invalid chunk checksum"
2024-10-15T05:50:08.837Z [loki] level=warn ts=2024-10-15T05:50:08.755497898Z caller=grpc_logging.go:78 method=/logproto.Querier/QuerySample duration=1.962797ms err="invalid chunk checksum" msg=gRPC
2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.755811819Z caller=batch.go:718 org_id=fake traceID=50f35e6d6bafd28a msg="error fetching chunks" err="invalid chunk checksum"
2024-10-15T05:50:08.837Z [loki] level=warn ts=2024-10-15T05:50:08.755949629Z caller=grpc_logging.go:78 method=/logproto.Querier/QuerySample duration=2.430548ms err="invalid chunk checksum" msg=gRPC
2024-10-15T05:50:08.837Z [loki] level=info ts=2024-10-15T05:50:08.756250896Z caller=metrics.go:160 component=querier org_id=fake traceID=50f35e6d6bafd28a latency=fast query="count by (flavor)(sum by(instance, flavor)(max_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" | unwrap idle_runners[7200s])) == 0 ) / count by (flavor)(sum by(instance, flavor)(count_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" [7200s])))" query_hash=3861148486 query_type=metric range_type=instant length=0s start_delta=8.756245165s end_delta=8.756245325s step=0s duration=3.076043ms status=500 limit=100 returned_lines=0 throughput=0B total_bytes=0B total_bytes_structured_metadata=0B lines_per_second=0 total_lines=0 post_filter_lines=0 total_entries=0 store_chunks_download_time=0s queue_time=39.254µs splits=0 shards=0 chunk_refs_fetch_time=0s cache_chunk_req=0 cache_chunk_hit=0 cache_chunk_bytes_stored=0 cache_chunk_bytes_fetched=0 cache_chunk_download_time=0s cache_index_req=0 cache_index_hit=0 cache_index_download_time=0s cache_stats_results_req=0 cache_stats_results_hit=0 cache_stats_results_download_time=0s cache_result_req=0 cache_result_hit=0 cache_result_download_time=0s
2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.756521056Z caller=retry.go:73 org_id=fake traceID=50f35e6d6bafd28a msg="error processing request" try=3 query="count by (flavor)(sum by(instance, flavor)(max_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" | unwrap idle_runners[7200s])) == 0 ) / count by (flavor)(sum by(instance, flavor)(count_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" [7200s])))" err="rpc error: code = Code(500) desc = 2 errors: rpc error: code = Unknown desc = invalid chunk checksum; rpc error: code = Unknown desc = invalid chunk checksum\n"
2024-10-15T05:50:08.837Z [loki] level=info ts=2024-10-15T05:50:08.757001941Z caller=engine.go:232 component=querier org_id=fake traceID=50f35e6d6bafd28a msg="executing query" type=instant query="count by (flavor)(sum by(instance, flavor)(max_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" | unwrap idle_runners[7200s])) == 0 ) / count by (flavor)(sum by(instance, flavor)(count_over_time({filename=\"/var/log/github-runner-metrics.log\"} | json event=\"event\",idle_runners=\"idle_runners\",flavor=\"flavor\" | event=\"reconciliation\" [7200s])))" query_hash=3861148486
2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.759631353Z caller=batch.go:718 org_id=fake traceID=50f35e6d6bafd28a msg="error fetching chunks" err="invalid chunk checksum"
2024-10-15T05:50:08.837Z [loki] level=warn ts=2024-10-15T05:50:08.759715732Z caller=grpc_logging.go:78 method=/logproto.Querier/QuerySample duration=2.10808ms err="invalid chunk checksum" msg=gRPC
2024-10-15T05:50:08.837Z [loki] level=error ts=2024-10-15T05:50:08.760088303Z caller=batch.go:718 org_id=fake traceID=50f35e6d6bafd28a msg="error fetching chunks" err="invalid chunk checksum"
2024-10-15T05:50:08.837Z [loki] level=warn ts=2024-10-15T05:50:08.760217497Z caller=grpc_logging.go:78 method=/logproto.Querier/QuerySample duration=2.652365ms err="invalid chunk checksum" msg=gRPC

Additional context

No response

Abuelodelanada commented 3 weeks ago

Hi @cbartz

Please, may we have an screenshot for the Loki Dashboad as well as the content of the Loki config file?

cbartz commented 2 weeks ago

@Abuelodelanada Sure image

The dashboard definition: https://github.com/canonical/github-runner-operator/blob/b9dce2243310ef2c627fe7244b62824e5d44b541/src/grafana_dashboards/metrics.json

Loki charm config :

juju config loki cpu='10000'
juju config loki memory='2Gi'
juju config loki retention-period='30'
juju config loki trust='True'

Loki config

~$ kubectl exec loki-0 -c loki -it -- bash
root@loki-0:/# cat /etc/loki/loki-local-config.yaml 
auth_enabled: false
chunk_store_config:
  chunk_cache_config:
    embedded_cache:
      enabled: true
common:
  path_prefix: /loki
  replication_factor: 1
  ring:
    instance_addr: loki-0.loki-endpoints.prod-cos-k8s-ps6-is-charms.svc.cluster.local
    kvstore:
      store: inmemory
  storage:
    filesystem:
      chunks_directory: /loki/chunks
      rules_directory: /loki/rules
compactor:
  retention_enabled: true
  shared_store: filesystem
  working_directory: /loki/compactor
frontend:
  compress_responses: true
  max_outstanding_per_tenant: 8192
ingester:
  wal:
    dir: /loki/chunks/wal
    enabled: true
    flush_on_shutdown: true
limits_config:
  ingestion_burst_size_mb: 15.0
  ingestion_rate_mb: 4.0
  per_stream_rate_limit: 4MB
  per_stream_rate_limit_burst: 15MB
  retention_period: 30d
  split_queries_by_interval: '0'
querier:
  max_concurrent: 20
query_range:
  parallelise_shardable_queries: false
  results_cache:
    cache:
      embedded_cache:
        enabled: true
ruler:
  alertmanager_url: http://alertmanager-0.alertmanager-endpoints.prod-cos-k8s-ps6-is-charms.svc.cluster.local:9093
  enable_alertmanager_v2: true
  external_url: https://cos-ps6.is-devops.canonical.com/prod-cos-k8s-ps6-is-charms-loki-0
schema_config:
  configs:
  - from: '2020-10-24'
    index:
      period: 24h
      prefix: index_
    object_store: filesystem
    schema: v11
    store: boltdb-shipper
server:
  http_listen_address: 0.0.0.0
  http_listen_port: 3100
storage_config:
  boltdb_shipper:
    active_index_directory: /loki/boltdb-shipper-active
    cache_location: /loki/boltdb-shipper-cache
    shared_store: filesystem
  filesystem:
    directory: /loki/chunks
target: all
Abuelodelanada commented 2 weeks ago

It feels like this is a Loki (workload) bug:

Can you confirm that the chunks files in the Loki workload container are all non-zero size? If you do not have empty chunks, then perhaps deleting the time-range for when the error occurs may "solve" the issue.

https://grafana.com/docs/loki/latest/reference/loki-http-api/#request-log-deletion

This also can be "solved" once the chunks are deleted due to the retention period.

Besides this issue seems to be fixed in a newer version of Loki that we might update to

Closing it, feel free to re-open if something new occurs.