My tempo demo performance is not good, can you help me to see if there is something wrong with my configuration

[zhouyanbl]

Hello, my system is currently using jaeger, so I intend to read jaeger data from kafka and write to tempo. So far I've created a demo using docker compose.It runs on my laptop, so the configuration may not be high, but the current efficiency does seem too low.
I put as much data into kafka as possible, so you can think of kafka as always being full.

The resources I assigned to docker were 6 CPU and 8GB,other containers may take up a little, but not much.
The result of the test is that it can only handle about 1k spans per second. I don't think this is normal.

Most of the configurations come directly from example/local,this is my tempo conf

server:
  http_listen_port: 3200

distributor:
  receivers:                           # this configuration will listen on all ports and protocols that tempo is capable of.
    jaeger:                            # the receives all come from the OpenTelemetry collector.  more configuration information can
      protocols:                       # be found there: https://github.com/open-telemetry/opentelemetry-collector/tree/main/receiver
        thrift_http:                   #
        grpc:
        thrift_binary:
        thrift_compact:
    zipkin:
    otlp:
      protocols:
        http:
        grpc:
    opencensus:
    kafka:
      brokers: [kafka:9092]
      topic: tempo
      encoding: jaeger_json


ingester:
  max_block_duration: 5m               # cut the headblock when this much time passes. this is being set for demo purposes and should probably be left alone normally

compactor:
  compaction:
    block_retention: 24h                # overall Tempo trace retention. set for demo purposes

metrics_generator:
  registry:
    external_labels:
      source: tempo
      cluster: docker-compose
  storage:
    path: /tmp/tempo/generator/wal
    remote_write:
      - url: http://prometheus:9090/api/v1/write
        send_exemplars: true

storage:
  trace:
    backend: local                     # backend configuration to use
    wal:
      path: /tmp/tempo/wal             # where to store  the wal locally
    local:
      path: /tmp/tempo/blocks





overrides:
  metrics_generator_processors: [service-graphs, span-metrics] # enables metrics generator

dockerfile is like this:

  tempo:
    image: grafana/tempo:latest
    command: [ "-config.file=/etc/tempo.yaml" ]
    volumes:
      - ./conf/tempo/tempo.yaml:/etc/tempo.yaml
      - ./tempo-data:/tmp/tempo
    ports:
#      - "14268"  # jaeger ingest
      - "3200"   # tempo
#      - "9095:9095" # tempo grpc
#      - "4317:4317"  # otlp grpc
#      - "4318:4318"  # otlp http
#      - "9411:9411"   # zipkin
#      - "14250:14250" # jaeger grpc
    deploy:
      replicas: 1

  kafka:
    image: wurstmeister/kafka:latest
    depends_on:
      - zookeeper
    ports:
      - "9092:9092"
#      - "29092"
      - "9997"
    environment:
      KAFKA_BROKER_ID: 1
      KAFKA_ZOOKEEPER_CONNECT: zookeeper:2181
      KAFKA_LISTENERS: PLAINTEXT://kafka:9092
      KAFKA_ADVERTISED_LISTENERS: PLAINTEXT://172.24.49.34:9092
#      PLAINTEXT_HOST://localhost:9092
      KAFKA_LISTENER_SECURITY_PROTOCOL_MAP: PLAINTEXT:PLAINTEXT,PLAINTEXT_HOST:PLAINTEXT
      KAFKA_INTER_BROKER_LISTENER_NAME: PLAINTEXT
      KAFKA_OFFSETS_TOPIC_REPLICATION_FACTOR: 1
      KAFKA_CREATE_TOPICS: "tempo:1:1"
      JMX_PORT: 9997
      KAFKA_JMX_OPTS: -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Djava.rmi.server.hostname=kafka -Dcom.sun.management.jmxremote.rmi.port=9997

This is the monitor:

When I use only one tempo image,it has some logs like this

2023-08-21 20:04:34 ts=2023-08-21T12:04:34Z level=info msg="Starting consumer group" component=tempo partition=0
2023-08-21 20:04:34 level=warn ts=2023-08-21T12:04:34.953784087Z caller=grpc_logging.go:57 method=/tempopb.Pusher/PushBytesV2 duration=63.935µs err="rpc error: code = FailedPrecondition desc = LIVE_TRACES_EXCEEDED: max live traces exceeded for tenant single-tenant: per-user traces limit (local: 10000 global: 0 actual local: 10000) exceeded" msg=gRPC
2023-08-21 20:04:34 level=error ts=2023-08-21T12:04:34.953943728Z caller=rate_limited_logger.go:27 msg="pusher failed to consume trace data" err="rpc error: code = FailedPrecondition desc = LIVE_TRACES_EXCEEDED: max live traces exceeded for tenant single-tenant: per-user traces limit (local: 10000 global: 0 actual local: 10000) exceeded"

Then I added more tempo containers,only one of them has high CPU occupation,and it has logs like this.And the processing speed is even slower

2023-08-21 20:13:18 level=error ts=2023-08-21T12:13:18.09046516Z caller=rate_limited_logger.go:27 msg="pusher failed to consume trace data" err="rpc error: code = FailedPrecondition desc = LIVE_TRACES_EXCEEDED: max live traces exceeded for tenant single-tenant: per-user traces limit (local: 10000 global: 0 actual local: 10000) exceeded"
2023-08-21 20:13:20 level=error ts=2023-08-21T12:13:20.276792604Z caller=flush.go:166 org_id=single-tenant msg="failed to cut traces" err="error writing meta json: open /tmp/tempo/wal/c7cc223a-aafd-4060-89bf-844e7538381c+single-tenant+vParquet2/meta.json: no such file or directory"
2023-08-21 20:13:20 level=info ts=2023-08-21T12:13:20.615316022Z caller=registry.go:228 tenant=single-tenant msg="collecting metrics" active_series=0
2023-08-21 20:13:20 ts=2023-08-21T12:13:20Z level=info msg="Starting consumer group" component=tempo partition=0

And others has logs like this

2023-08-21 20:10:51 level=info ts=2023-08-21T12:10:51.129593815Z caller=lifecycler.go:614 msg="not loading tokens from file, tokens file path is empty"
2023-08-21 20:10:51 level=info ts=2023-08-21T12:10:51.129659707Z caller=lifecycler.go:643 msg="instance not found in ring, adding with no tokens" ring=ingester
2023-08-21 20:10:51 level=info ts=2023-08-21T12:10:51.129801816Z caller=lifecycler.go:483 msg="auto-joining cluster after timeout" ring=ingester
2023-08-21 20:10:53 level=info ts=2023-08-21T12:10:53.33263382Z caller=app.go:201 msg="Tempo started"
2023-08-21 20:15:51 level=info ts=2023-08-21T12:15:51.121510158Z caller=poller.go:130 msg="blocklist poll complete" seconds=0.000379065
2023-08-21 20:15:51 level=info ts=2023-08-21T12:15:51.126107157Z caller=poller.go:130 msg="blocklist poll complete" seconds=0.00031564

I would like to get some suggestions on how to improve the performance of the configuration, if you need more details please let me know.Thank you very much!

[joe-elliott]

The resources I assigned to docker were 6 CPU and 8GB,other containers may take up a little, but not much.

6 CPU is quite a lot for that kind of traffic. 8GB might be normal. Tempo can be memory hungry during the compaction and when the ingester cuts the wal block to a complete block.

There's a lot of ways we can go with this. My initial suggestions is going to be use tempo in a fully distributed mode. This will allow us to easily see where memory/cpu is being consumed. You can use the tempo-distributed helm chart or this distributed docker-compose.

And secondly, a common cause of higher resource usage, is large traces. Perhaps try to restrict trace size using:

overrides:
  max_bytes_per_trace: <some #>

[zhouyanbl]

I enabled 6 CPU cores for now, with 3 distributors accounting for approximately 400%, 3 ingesters and 1 compactor accounting for approximately 120%

[joe-elliott]

In my experience ingesters are the largest CPU and memory consumers. I find it odd that the ingesters are giving you fits. Are you connecting distributors directly to Kafka? We have seen issues with that in the past:

#1944

We recommend going kafka -> otel collector -> tempo

[zhouyanbl]

Thank you for your suggestion.
I think this may be because the test trace I constructed is very simple, so there is no need to spend a lot on ingesters？
I did connect distributors directly to kafka,and now I added otel collector between them,but performance has not improved.
2 otel collector accounting for 220% cpu cores,2 distributors accounting for 250% cores,and 3 ingesters accounting for about 100% cores.They don't take up much memory.
However,I find in other discuss,distributor should not cost so much resource,like this https://github.com/grafana/tempo/discussions/1946

Here is many error in otel collector like this:
2023-08-23 17:37:59 2023-08-23T09:37:59.767Z error exporterhelper/queued_retry.go:395 Exporting failed. The error is not retryable. Dropping data. {"kind": "exporter", "data_type": "traces", "name": "otlp", "error": "Permanent error: rpc error: code = FailedPrecondition desc = LIVE_TRACES_EXCEEDED: max live traces exceeded for tenant single-tenant: per-user traces limit (local: 10000 global: 0 actual local: 10000) exceeded", "dropped_items": 1}
and when I just use otel collector to pass data to another kafka,it consumes really fast.
So I think that implies that downstream, that tempo is the cause of the blockage?

And there is many error like this in distributors:
2023-08-23 17:56:37 level=error ts=2023-08-23T09:56:37.70298375Z caller=forwarder.go:89 msg="failed to push traces to queue" tenant=single-tenant err="failed to push data to queue for tenant=single-tenant and queue_name=metrics-generator: queue is full"

Many error in ingesters like this:
2023-08-23 17:56:23 level=warn ts=2023-08-23T09:56:23.690772504Z caller=grpc_logging.go:57 duration=93.041µs method=/tempopb.Pusher/PushBytesV2 err="rpc error: code = FailedPrecondition desc = LIVE_TRACES_EXCEEDED: max live traces exceeded for tenant single-tenant: per-user traces limit (local: 10000 global: 0 actual local: 10000) exceeded" msg=gRPC

All spans are simple like this:

{
	"traceId": "AAAAAAAAAABZaVYjMAgGyQ==",
	"spanId": "WWlWIzAIBsk=",
	"operationName": "test",
	"flags": 1,
	"startTime": "2023-08-23T08:31:20.451915Z",
	"duration": "0.001053s",
	"tags": [
		{
			"key": "sampler.type",
			"vStr": "const"
		},
		{
			"key": "sampler.param",
			"vType": "BOOL",
			"vBool": true
		},
		{
			"key": "seq",
			"vType": "INT64"
		},
		{
			"key": "counter",
			"vType": "INT64",
			"vInt64": "24"
		},
		{
			"key": "internal.span.format",
			"vStr": "proto"
		}
	],
	"process": {
		"serviceName": "zhouyan_grpc_sender",
		"tags": [
			{
				"key": "jaeger.version",
				"vStr": "Go-2.29.0"
			},
			{
				"key": "hostname",
				"vStr": "yanzhou-mac.local"
			},
			{
				"key": "ip",
				"vStr": "172.24.49.34"
			},
			{
				"key": "client-uuid",
				"vStr": "73582900c426fe43"
			}
		]
	}
}

Will it be helpful?If you need more details please let me know.Thank you very much!

[zhouyanbl]

@joe-elliott @mapno Hi all,I found a configuration item max_traces_per_user, and by turning it up and using otel collector my problems were solved. Thank you very much for your suggestions

[joe-elliott]

Nice work tracking it down!