Ingester fails with "error searching block" when "replication_factor" is set to 3

[jon-rei]

Describe the bug

Our ingester logs the following errors and warnings:

level=warn ts=2023-12-15T08:49:13.134664609Z caller=server.go:1184 method=/tempopb.Querier/FindTraceByID duration=9.793361ms msg=gRPC err="completeBlock.FindTraceByID failed: error reading row from backend: missing required field: 1:FIELD<I32>"
level=error ts=2023-12-15T08:52:13.142414816Z caller=instance_search.go:144 msg="error searching block" blockID=88645ed5-56d3-4054-a392-7b6aea7a2a34 err="error opening file /bitnami/grafana-tempo/data/wal/88645ed5-56d3-4054-a392-7b6aea7a2a34+single-tenant+vParquet3/0000000029: error opening parquet file: reading magic footer of parquet file: context canceled"

We run the Ingester with 3 replicas and replication_factor: 3. We used to run the Ingester with only 2 replicas and replication_factor: 1. If we change our current setup back to replication_factor 1 or even 2, the error is gone.

Currently we are a little bit confused by those errors. They are happening quite frequently but it does not seem to break anything.

To Reproduce At least reproducable in our environment throught all of our clusters:

1. Run Ingesters with 3 replicas and replication_factor: 1
2. Change replication_factor to 3

Expected behavior Running with replication_factor: 3 works.

Environment:

• Infrastructure: Kubernetes
• Deployment tool: bitnami helm chart
• Tempo v2.3.1

Additional Context We needed to tune the limits quite a lot.

configs

Overrides: ``` overrides: "*": max_traces_per_user: 5000000 ingestion_burst_size_bytes: 500000000 ingestion_rate_limit_bytes: 500000000 metrics_generator_processors: - service-graphs - span-metrics ``` Config: ``` usage_report: reporting_enabled: false multitenancy_enabled: false compactor: compaction: block_retention: 168h ring: kvstore: store: memberlist metrics_generator: processor: service_graphs: max_items: 100000 dimensions: - k8s.namespace.name span_metrics: dimensions: - k8s.namespace.name ring: kvstore: store: memberlist storage: path: {{ .Values.tempo.dataDir }}/wal remote_write: {{ include "common.tplvalues.render" (dict "value" .Values.metricsGenerator.remoteWrite "context" $) | nindent 6 }} distributor: ring: kvstore: store: memberlist receivers: ...snip query_frontend: max_outstanding_per_tenant: 3000 search: concurrent_jobs: 2000 querier: frontend_worker: frontend_address: {{ include "grafana-tempo.query-frontend.fullname" . }}-headless:{{ .Values.queryFrontend.service.ports.grpc }} grpc_client_config: max_send_msg_size: 500000000 trace_by_id: query_timeout: "60s" search: query_timeout: "120s" max_concurrent_queries: 50 ingester: lifecycler: ring: replication_factor: 3 kvstore: store: memberlist tokens_file_path: {{ .Values.tempo.dataDir }}/tokens.json memberlist: abort_if_cluster_join_fails: false join_members: - {{ include "grafana-tempo.gossip-ring.fullname" . }} overrides: per_tenant_override_config: /bitnami/grafana-tempo/conf/overrides.yaml server: http_server_read_timeout: "60s" http_server_write_timeout: "60s" http_listen_port: {{ .Values.tempo.containerPorts.web }} grpc_server_max_recv_msg_size: 500000000 grpc_server_max_send_msg_size: 500000000 storage: trace: backend: s3 s3: endpoint: ${BUCKET_HOST} bucket: ${BUCKET_NAME} access_key: ${AWS_ACCESS_KEY_ID} secret_key: ${AWS_SECRET_ACCESS_KEY} forcepathstyle: true insecure: true local: path: {{ .Values.tempo.dataDir }}/traces wal: path: {{ .Values.tempo.dataDir }}/wal cache: memcached memcached: consistent_hash: true host: {{ include "grafana-tempo.memcached.url" . }} service: memcache timeout: 500ms search: cache_control: footer: true column_index: true offset_index: true block: version: vParquet3 pool: max_workers: 100 cache_min_compaction_level: 1 cache_max_block_age: 48h ```

[joe-elliott]

Good catch. This is a innocuous error. In RF3 if the querier gets 2 responses it can be assured that it has received all spans for a trace (due to read/write quorum) and so it cancels the final request.

We should log context cancelled on query at the debug level in the ingester.

[github-actions[bot]]

This issue has been automatically marked as stale because it has not had any activity in the past 60 days. The next time this stale check runs, the stale label will be removed if there is new activity. The issue will be closed after 15 days if there is no new activity. Please apply keepalive label to exempt this Issue.