Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Reading footer of parquet file: error in rang e read from s3 backend 416 Requested Range Not Satisfiable #4166

Closed
RobbanHoglund opened this issue Oct 10, 2024 · 8 comments · Fixed by #4256

Comments

@RobbanHoglund
Copy link

Describe the bug
Fails to fetch parquet objects from S3/Minio and get this error

level=warn ts=2024-10-10T12:12:25.647736726Z caller=server.go:2171 trace_id_unsampled=1fb525ccad3e46d6 msg="GET /api/search?q=%7B%7D&limit=20&spss=3&start=1728560545&end=1728562345 (500) 82.201572ms Response: \"reading footer of parquet file: error in rang
e read from s3 backend, bucket: tempo, objName: single-tenant/2f672840-f2cf-4348-a88a-e790bdfd4e95/data.parquet: 416 Requested Range Not Satisfiable\\n\" ws: false; Accept: application/json, text/plain, */*; Accept-Encoding: gzip, deflate; Accept-Language:
 en-GB,en-US;q=0.9,en;q=0.8,sv;q=0.7; User-Agent: Grafana/11.2.0; X-Forwarded-For: 10.98.37.156, 10.98.37.156, 10.39.34.196; X-Grafana-Org-Id: 1; X-Grafana-Referer: http://grafana.secondary.monitor.swedbank.test:3000/explore?schemaVersion=1&panes=%7B%22auq
%22:%7B%22datasource%22:%22adzvazqauaxvke%22,%22queries%22:%5B%7B%22refId%22:%22A%22,%22datasource%22:%7B%22type%22:%22tempo%22,%22uid%22:%22adzvazqauaxvke%22%7D,%22queryType%22:%22traceqlSearch%22,%22limit%22:20,%22tableType%22:%22traces%22,%22filters%22:
%5B%7B%22id%22:%22f531af88%22,%22operator%22:%22%3D%22,%22scope%22:%22span%22%7D%5D%7D%5D,%22range%22:%7B%22from%22:%22now-1h%22,%22to%22:%22now%22%7D%7D,%22qmp%22:%7B%22datasource%22:%22adzvazqauaxvke%22,%22queries%22:%5B%7B%22query%22:%226707b7fe2e1655e5
08238b8af5ea5948%22,%22queryType%22:%22traceql%22,%22refId%22:%22A%22,%22limit%22:20,%22tableType%22:%22traces%22%7D%5D,%22range%22:%7B%22from%22:%221728557049341%22,%22to%22:%221728560649341%22%7D%7D%7D&orgId=1; ""

To Reproduce
Steps to reproduce the behavior:

  1. Start Tempo 2.6.0 with more or less default config.
    This is our config:

server:
  http_listen_port: 3100
  grpc_listen_port: 4310
  log_format: logfmt
  log_level: info

distributor:
  receivers:
    otlp:
      protocols:
        grpc:
          endpoint: 0.0.0.0:4317
        http:
          endpoint: 0.0.0.0:4318
  ring:
    kvstore:
      store: memberlist
    instance_interface_names:
      - ens160

compactor:
  compaction:
    block_retention: 48h
  ring:
    kvstore:
      store: memberlist
    instance_interface_names:
      - ens160

memberlist:
  abort_if_cluster_join_fails: false
  bind_port: 4311
  #bind_addr: []
  advertise_port: 4311
  cluster_label: ${CLUSTER_NAME}
  cluster_label_verification_disabled: false
  join_members:
    - ${SERVER_1}.sbcore.net:4311
    - ${SERVER_2}.sbcore.net:4311
    - ${SERVER_3}.sbcore.net:4311

metrics_generator:
  ring:
    kvstore:
      store: memberlist
    instance_interface_names:
      - ens160
  storage:
    path: /sb/env/data/mon/tempo/wal
  traces_storage:
    path: /sb/env/data/mon/tempo/traces
storage:
  trace:
    backend: s3
    s3:
      access_key: ${MINIO_USER}
      secret_key: ${MINIO_PW}
      bucket: tempo
      endpoint: localhost:7000
      insecure: true
    wal:
      path: /sb/env/data/mon/tempo/wal
querier:
  frontend_worker:
    frontend_address: 127.0.0.1:4310

overrides:
  defaults:
    metrics_generator:
      processors: 
        - service-graphs
        - span-metrics

usage_report:
  reporting_enabled: false

auth_enabled: false
multitenancy_enabled: false

Environment:

  • Bare-metal, 3 servers with Tempo 2.6.0 standalone (scalable-single-binary) with Minio sidekick loadbalancer
  • Minio storage cluster MinIO VERSION 2024-10-02T17:50:41Z.
  • Bash scripts for installation and startup

Additional Context

This is how the files are organized in the tempo machine

p986_ga8632123_t@lx79590:/sb/env/logs/mon/tempo$ du -ah /sb/env/data/mon/tempo/
0       /sb/env/data/mon/tempo/wal/blocks/single-tenant
0       /sb/env/data/mon/tempo/wal/blocks
0       /sb/env/data/mon/tempo/wal/single-tenant/wal/00000000
0       /sb/env/data/mon/tempo/wal/single-tenant/wal
0       /sb/env/data/mon/tempo/wal/single-tenant/lock
0       /sb/env/data/mon/tempo/wal/single-tenant
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000001
4.0K    /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/meta.json
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000002
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000003
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000004
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000005
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000006
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000007
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000008
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000009
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000010
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000011
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000012
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000013
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000014
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000015
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000016
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000017
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000018
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000019
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000020
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000021
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000022
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000023
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000024
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000025
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000026
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000027
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000028
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000029
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000030
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000031
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000032
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000033
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000034
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000035
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000036
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000037
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000038
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000039
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000040
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000041
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000042
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000043
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000044
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000045
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000046
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000047
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000048
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000049
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000050
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000051
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000052
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000053
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000054
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000055
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000056
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000057
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000058
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000059
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000060
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000061
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000062
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000063
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000064
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000065
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000066
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000067
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000068
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000069
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000070
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000071
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000072
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000073
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000074
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000075
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000076
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000077
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000078
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000079
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000080
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000081
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000082
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000083
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000084
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000085
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000086
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000087
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000088
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000089
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000090
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000091
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000092
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000093
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000094
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000095
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000096
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000097
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000098
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000099
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000100
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000101
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000102
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000103
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000104
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000105
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000106
28K     /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000107
0       /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4/0000000108
3.0M    /sb/env/data/mon/tempo/wal/2f30f97e-d8bd-4adf-a24d-ad402b301b65+single-tenant+vParquet4
3.0M    /sb/env/data/mon/tempo/wal
0       /sb/env/data/mon/tempo/traces/single-tenant/blocks
0       /sb/env/data/mon/tempo/traces/single-tenant
0       /sb/env/data/mon/tempo/traces
3.0M    /sb/env/data/mon/tempo/

tempo.log

Image

@joe-elliott
Copy link
Member

I have not seen this particular error and suggests a corrupt block. The block has a meta.json file with two relevant fields:

Image

The "size" field should be the exact size in bytes of the data.parquet file. Is this the case? The footer size is just how far back into the file that is read to get the footer.

If the data.parquet file is not corrupt then it would technically be possible to rebuild the meta.json and bloom filters by replaying the data, but I don't think we've written code to do that. It may be also interesting to try to open the data parquet in an external tool like:

https://github.com/stoewer/parquet-cli

to see if the parquet file itself is corrupt or the meta.json is just wrong.

Unless you are just in the mood to deep dive the issue, the easiest fix would be to simply remove the block.

@shashankjb
Copy link

Hii I am facing the similar issue where size field in meta.json is misconfigured with the size of data.parquet. Any idea or suggestion to fix this ?

@joe-elliott
Copy link
Member

  • What version of Tempo are you using?
  • Are you also using MinIO like the original issue?
  • Any other details you can share such as the data.parquet size, meta.json values?
  • Any analysis, insight, guesses, or observations to help us narrow down what might be the cause?

Technically you can just delete the block and lose the traces, but I'm surprised we're getting reports of this. We have 10s of millions of blocks in our backends and I don't think we've ever seen this.

@shashankjb
Copy link

shashankjb commented Oct 22, 2024

Hii
Tempo version: 2.5.0
we are not using minio for data storing we use aws s3 bucket.
data.parquet file size: 381mb
meta.json:

{"format":"vParquet3","blockID":"000530a5-1e4e-4528-82be 1ac71b093f4f", "minID":"AAApWFvHR6oWqYAmXy4FLA==", "maxID":"///4AfCcpyAPH9fOSh+3ag==",
"tenantID":"single-tenant",
"startTime":"2024-10-13T04:48:58Z",
"endTime":"2024-10-13T04:54:37Z",
"totalObjects":1272275,
"size":405146024,
"compactionLevel":0,
"encoding":"none",
"indexPageSize":0,
"totalRecords":5,
"dataEncoding":"",
"bloomShards":15,
"footerSize":101768}

One thing we noticed that we had lots of compactor restart after changing few changes in compactor it became stable and then this issue started.

Config.yaml:

cache:
caches:

  • memcached:
    consistent_hash: true
    host: 'tempo-distributed-memcached'
    service: memcached-client
    timeout: 500ms
    roles:
    • parquet-footer
    • bloom
    • frontend-search
      compactor:
      compaction:
      block_retention: 360h
      compacted_block_retention: 12h
      compaction_cycle: 10m
      compaction_window: 1h
      max_block_bytes: 13421772800
      max_compaction_objects: 500000
      max_time_per_tenant: 5m
      retention_concurrency: 5
      v2_in_buffer_bytes: 20971520
      v2_out_buffer_bytes: 20971520
      v2_prefetch_traces_count: 250
      ring:
      kvstore:
      store: memberlist
      distributor:
      receivers:
      otlp:
      protocols:
      grpc:
      endpoint: 0.0.0.0:4317
      http:
      endpoint: 0.0.0.0:4318
      ring:
      kvstore:
      store: memberlist
      ingester:
      lifecycler:
      ring:
      kvstore:
      store: memberlist
      replication_factor: 3
      tokens_file_path: /var/tempo/tokens.json
      memberlist:
      abort_if_cluster_join_fails: false
      bind_addr: []
      bind_port: 7946
      gossip_interval: 1s
      gossip_nodes: 2
      gossip_to_dead_nodes_time: 30s
      join_members:
  • dns+tempo-distributed-gossip-ring:7946
    leave_timeout: 5s
    left_ingesters_timeout: 5m
    max_join_backoff: 1m
    max_join_retries: 10
    min_join_backoff: 1s
    node_name: ""
    packet_dial_timeout: 5s
    packet_write_timeout: 5s
    pull_push_interval: 30s
    randomize_node_name: true
    rejoin_interval: 0s
    retransmit_factor: 2
    stream_timeout: 10s
    metrics_generator:
    metrics_ingestion_time_range_slack: 30s
    processor:
    service_graphs:
    dimensions: []
    histogram_buckets:
    • 0.1
    • 0.2
    • 0.4
    • 0.8
    • 1.6
    • 3.2
    • 6.4
    • 12.8
      max_items: 10000
      wait: 10s
      workers: 10
      span_metrics:
      dimensions: []
      histogram_buckets:
    • 0.002
    • 0.004
    • 0.008
    • 0.016
    • 0.032
    • 0.064
    • 0.128
    • 0.256
    • 0.512
    • 1.02
    • 2.05
    • 4.1
      registry:
      collection_interval: 15s
      external_labels: {}
      stale_duration: 15m
      ring:
      kvstore:
      store: memberlist
      storage:
      path: /var/tempo/wal
      remote_write:
    • url:
      remote_write_add_org_id_header: true
      remote_write_flush_deadline: 1m
      traces_storage:
      path: /var/tempo/traces
      multitenancy_enabled: false
      overrides:
      per_tenant_override_config: /runtime-config/overrides.yaml
      querier:
      frontend_worker:
      frontend_address: tempo-distributed-query-frontend-discovery:9095
      grpc_client_config:
      max_send_msg_size: 134217728
      max_concurrent_queries: 20
      search:
      external_backend: null
      external_endpoints: []
      external_hedge_requests_at: 8s
      external_hedge_requests_up_to: 2
      prefer_self: 10
      query_timeout: 30s
      trace_by_id:
      query_timeout: 10s
      query_frontend:
      max_outstanding_per_tenant: 2000
      max_retries: 2
      search:
      concurrent_jobs: 1000
      target_bytes_per_job: 104857600
      trace_by_id:
      query_shards: 50
      server:
      grpc_server_max_recv_msg_size: 134217728
      grpc_server_max_send_msg_size: 134217728
      http_listen_port: 3100
      http_server_read_timeout: 30s
      http_server_write_timeout: 30s
      log_format: logfmt
      log_level: info
      storage:
      trace:
      backend: s3
      blocklist_poll: 5m
      local:
      path: /var/tempo/traces
      pool:
      max_workers: 400
      queue_depth: 20000
      s3:
      access_key: null
      bucket:
      endpoint:
      insecure: false
      region: us-east-1
      secret_key: null
      wal:
      path: /var/tempo/wal
      usage_report:
      reporting_enabled: true

@mdisibio
Copy link
Contributor

Hi everyone, this was also reported at https://community.grafana.com/t/error-reading-footer-of-parquet-file/133954 The commonality of it and the original issue was using minio, but the next report above is s3. Still related as all use the same minio s3 client.

@joe-elliott
Copy link
Member

joe-elliott commented Oct 29, 2024

We have now seen this issue occur on a level 0 block. We believe this is caused when an ingester flushes a partially completed block. Can those folks who have seen this issue help confirm?

  • Please check if the compactionLevel is 0 in the affected blocks
  • Please search your ingester logs for the block guid and post ALL log lines in which the guid is found. There should only be a few and they will look something like:
2024-10-29 12:20:02.158 | level=info ts=2024-10-29T12:20:02.158141568Z caller=flush.go:311 msg="flushing block" userid=xxxxxx block=474ece6a-dd7e-4363-a2be-02df4f992cec 
2024-10-29 12:20:02.151 | level=info ts=2024-10-29T12:20:02.150841088Z caller=flush.go:262 msg="block completed" userid=xxxxxx blockID=474ece6a-dd7e-4363-a2be-02df4f992cec duration=1.800768504s |  
2024-10-29 12:20:00.350 | level=info ts=2024-10-29T12:20:00.350072186Z caller=flush.go:255 msg="completing block" userid=xxxxxx blockID=474ece6a-dd7e-4363-a2be-02df4f992cec |  
2024-10-29 12:19:52.547 | level=info ts=2024-10-29T12:19:52.546922192Z caller=flush.go:179 msg="head block cut. enqueueing flush op" userid=xxxxxx block=474ece6a-dd7e-4363-a2be-02df4f992cec

@joe-elliott
Copy link
Member

Sharing what we have seen to preserve thoughts while they are fresh and to see if this coincides with what others are seeing.

  • Wal block is cut and a flush operation is enqueued
  • Block completion starts
  • SIGINT is received and the process shuts down without completing block
  • Block is reloaded as a local block which should only happen if completion was successful
  • The meta.json indicates data.parquet should be ~74MB but it's only ~8MB.
2024-10-29 09:03:33.862 | level=info ts=2024-10-29T09:03:33.862633237Z caller=flush.go:311 msg="flushing block" userid=xxxxxx block=ca04fddc-c841-4835-a192-e4ce67688796 
2024-10-29 09:03:33.039 | level=info ts=2024-10-29T09:03:33.039742382Z caller=instance.go:637 msg="reloaded local block" tenantID=xxxxxx block=ca04fddc-c841-4835-a192-e4ce67688796 flushed=0001-01-01T00:00:00Z 
2024-10-29 08:53:10.086 | level=info ts=2024-10-29T08:53:10.086045847Z caller=app.go:236 msg="=== received SIGINT/SIGTERM ===\n*** exiting"
2024-10-29 08:53:03.391 | level=info ts=2024-10-29T08:53:03.390907765Z caller=flush.go:255 msg="completing block" userid=xxxxxx blockID=ca04fddc-c841-4835-a192-e4ce67688796 
2024-10-29 08:52:54.998 | level=info ts=2024-10-29T08:52:54.998214457Z caller=flush.go:179 msg="head block cut. enqueueing flush op" userid=xxxxxx block=ca04fddc-c841-4835-a192-e4ce67688796

On startup there is no indication this block exists as completing/wal block which suggests the block was completed and was removed without this line being logged. In addition the completion was only done partially. The meta.json was written, but the block was not entirely flushed to disk which suggests a bug in this logic.

@joe-elliott
Copy link
Member

After further research we have determined this was caused by a node failure in one of our clusters. As the ingester was going down the disk was failing and the ingester was unable to shutdown cleanly. The disk on startup was in an unknown state.

To fix we intend to do better validation checking on startup and, in particular, test for this case where the data.parquet file is strangely truncated. If you are seeing this issue we would recommend checking that the ingester is cleanly shutting down. You should see a log line like this when the ingester receives SIGINT:

2024-10-29 08:53:10.086 | level=info ts=2024-10-29T08:53:10.086045847Z caller=app.go:236 msg="=== received SIGINT/SIGTERM ===\n*** exiting"

and a second line like this to confirm it has completely shut down:

level=info ts=2024-10-30T19:03:20.790588396Z caller=app.go:209 msg="Tempo stopped"

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants