Closed tkramarczyk-vgw closed 8 months ago
Once an exception is thrown in KafkaListener, the records are retried, however, every new poll starts using the same traceId.
At the beginning every batch processing is instrumented with a new traceId:
[trace_id=ea183b2234da006e22b90741d03ba550, trace_flags=01, span_id=ddd9e45f221e04f4] 10:56:50.299 INFO c.e.k.KafkaTracingListener1Application: consumed [aaa-aaa] [trace_id=5e569f0325ed6e3325e269062cca1ab8, trace_flags=01, span_id=4e69a18c3728f1f4] 10:56:58.228 INFO c.e.k.KafkaTracingListener1Application: consumed [bbb-bbb]
Then, for the 3rd operation in the given example we throw an exception:
[trace_id=dc73c698e8bb5f03dcecfbf22d586c5d, trace_flags=01, span_id=238f3e5a10892eca] 10:57:01.979 INFO c.e.k.KafkaTracingListener1Application: consumed [ccc-ccc] [trace_id=dc73c698e8bb5f03dcecfbf22d586c5d, trace_flags=01, span_id=238f3e5a10892eca] 10:57:01.982 ERROR c.e.k.KafkaTracingListener1Application: Error!
Then we see that it's being retried with a new traceId:
[trace_id=1f63157677fef738bde3f5dc24190262, trace_flags=01, span_id=16ca9fde6264ce48] 10:57:02.009 INFO c.e.k.KafkaTracingListener1Application: consumed [ccc-ccc]
However, every new poll and records will keep using the same traceId:
[trace_id=1f63157677fef738bde3f5dc24190262, trace_flags=01, span_id=16ca9fde6264ce48] 10:58:41.943 INFO c.e.k.KafkaTracingListener1Application: consumed [ddd-ddd] [trace_id=1f63157677fef738bde3f5dc24190262, trace_flags=01, span_id=16ca9fde6264ce48] 10:58:45.180 INFO c.e.k.KafkaTracingListener1Application: consumed [eee-eee] [trace_id=1f63157677fef738bde3f5dc24190262, trace_flags=01, span_id=16ca9fde6264ce48] 10:58:49.236 INFO c.e.k.KafkaTracingListener1Application: consumed [fff-fff]
Once an exception happend, there are logs printed from SupportabilityMetrics:
DEBUG io.opentelemetry.javaagent.shaded.instrumentation.api.internal.SupportabilityMetrics - Suppressed Spans by 'io.opentelemetry.spring-kafka-2.7' (CONSUMER) : 1
Same behaviour is not observed when using single listener.
Here's a simple one-file application:
private val logger = KotlinLogging.logger {} @SpringBootApplication class KafkaTracingListener1Application fun main(args: Array<String>) { runApplication<KafkaTracingListener1Application>(*args) } @Component class BatchListener { var counter = 0 @KafkaListener(topics = ["myTopic"]) fun consume(events: List<ConsumerRecord<String, String>>) { logger.info { "consumed ${events.map { it.key() + "-" + it.value() }}" } counter++ if (counter == 3) { logger.error { "Error!" } throw RuntimeException("sth went wrong") } } }
And its configuration:
spring: kafka: bootstrap-servers: localhost:9092 listener: type: batch consumer: group-id: ${spring.application.name} key-deserializer: org.apache.kafka.common.serialization.StringDeserializer value-deserializer: org.apache.kafka.common.serialization.StringDeserializer properties: security: protocol: PLAINTEXT
Every batch of records gets a new traceid
After an exception is thrown, traceId is not reset.
2.1.0
Java agent: Manifest-Version: 1.0 Implementation-Title: javaagent Implementation-Version: 2.1.0 ...
Spring: id("org.springframework.boot") version "3.2.3" id("io.spring.dependency-management") version "1.1.4"
Run on: JDK 17
No response
@tkramarczyk-vgw could you provide the full sample application as a github repo or zip
@laurit here's the repo: https://github.com/tkramarczyk-vgw/kafka-batch-listener-otel-bug
Describe the bug
Once an exception is thrown in KafkaListener, the records are retried, however, every new poll starts using the same traceId.
At the beginning every batch processing is instrumented with a new traceId:
Then, for the 3rd operation in the given example we throw an exception:
Then we see that it's being retried with a new traceId:
However, every new poll and records will keep using the same traceId:
Once an exception happend, there are logs printed from SupportabilityMetrics:
Same behaviour is not observed when using single listener.
Steps to reproduce
Here's a simple one-file application:
And its configuration:
Expected behavior
Every batch of records gets a new traceid
Actual behavior
After an exception is thrown, traceId is not reset.
Javaagent or library instrumentation version
2.1.0
Environment
Java agent: Manifest-Version: 1.0 Implementation-Title: javaagent Implementation-Version: 2.1.0 ...
Spring: id("org.springframework.boot") version "3.2.3" id("io.spring.dependency-management") version "1.1.4"
Run on: JDK 17
Additional context
No response