Deadlock between `KafkaBinderMetrics.close()` and the offset-lag task on context shutdown
メンテナーはふだん 1 日以内に返信
まだ誰も着手していません。
評価
- 難易度
- 4/5
- 見積もり時間
- 3〜5日
- 初心者へのやさしさ
- 55/100
- issue の種類
- バグ
- 明瞭さ
- 明確に書かれている
- 活発さ
- 活発
- 領域
- backend, performance
調査の方向性
Start with KafkaBinderMetrics.close(), stop(), findTotalTopicGroupLag(), and createConsumerFactory(); the issue gives the relevant lock and map operations and a reproducible Maven test in a gist. Read the existing lifecycle and offset lag tests, then run the reproduction with mvn test. Done means shutdown returns reliably and the deadlock check no longer finds the reported cycle.
索引モデルが issue の本文から書いたものです。
説明
Version: spring-cloud-stream-binder-kafka 5.0.4 (the class is identical on main). Java 25.
Describe the issue
On application-context shutdown, KafkaBinderMetrics.close() can deadlock with the scheduled offset-lag task. When that happens the JVM never exits.
We hit this in CI. The Gradle test worker calls System.exit() after the tests finish. SpringApplicationShutdownHook then blocks forever in KafkaBinderMetrics.close(), and the build hangs until the pipeline timeout. In our case that is 8 out of 9 full runs on one build host.
The cycle (line numbers from 5.0.4 / main):
| close() (shutdown thread) | offset-lag task (scheduler thread) |
|---|---|
consumerFactoryLock.lock() (L294) |
|
metadataConsumers.computeIfAbsent(group, ...) (L209): holds the CHM bin lock |
|
→ createConsumerFactory(): defaultConsumerFactory == null → consumerFactoryLock.lock() (L255): blocks. lock() is not interruptible, so shutdownNow() does not help. |
|
scheduler.shutdownNow(), awaitTermination(offsetLagMetricsInterval) times out |
|
finally: metadataConsumers.clear() (L313): waits for the CHM bin lock held by the task → deadlock |
The cycle needs the task's first createConsumerFactory() call to coincide with close(). That is, the binding was created shortly before shutdown, which is common with short-lived test contexts.
It looks like the cycle came from two changes: GH-3062 started calling close() from stop(), and it moved metadataConsumers.clear() into the locked section. #3014 replaced synchronized with ReentrantLock.
Thread dump from CI (Spring Boot app, Gradle test worker)
Found one Java-level deadlock:
"pool-15-thread-1":
waiting for ownable synchronizer 0x00000000e30d4008, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
which is held by "SpringApplicationShutdownHook"
"SpringApplicationShutdownHook":
waiting to lock monitor 0x00007fda7000a2b0 (object 0x00000000e4e193d0, a java.util.concurrent.ConcurrentHashMap$ReservationNode),
which is held by "pool-15-thread-2"
"pool-15-thread-2":
waiting for ownable synchronizer 0x00000000e30d4008, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
which is held by "SpringApplicationShutdownHook"
"SpringApplicationShutdownHook":
at java.util.concurrent.ConcurrentHashMap.clear(ConcurrentHashMap.java:1214)
- waiting to lock <0x00000000e4e193d0> (a java.util.concurrent.ConcurrentHashMap$ReservationNode)
at org.springframework.cloud.stream.binder.kafka.KafkaBinderMetrics.close(KafkaBinderMetrics.java:305)
at org.springframework.cloud.stream.binder.kafka.KafkaBinderMetrics.stop(KafkaBinderMetrics.java:321)
at org.springframework.context.support.DefaultLifecycleProcessor.doStop(DefaultLifecycleProcessor.java:476)
...
at org.springframework.cloud.stream.binder.DefaultBinderFactory.stop(DefaultBinderFactory.java:163)
...
at org.springframework.boot.SpringApplicationShutdownHook.run(SpringApplicationShutdownHook.java:116)
"pool-15-thread-2":
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:323)
at org.springframework.cloud.stream.binder.kafka.KafkaBinderMetrics.createConsumerFactory(KafkaBinderMetrics.java:247)
at org.springframework.cloud.stream.binder.kafka.KafkaBinderMetrics.lambda$findTotalTopicGroupLag$4(KafkaBinderMetrics.java:211)
at java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1724)
- locked <0x00000000e4e193d0> (a java.util.concurrent.ConcurrentHashMap$ReservationNode)
at org.springframework.cloud.stream.binder.kafka.KafkaBinderMetrics.findTotalTopicGroupLag(KafkaBinderMetrics.java:209)
at org.springframework.cloud.stream.binder.kafka.KafkaBinderMetrics.computeUnconsumedMessages(KafkaBinderMetrics.java:198)
at org.springframework.cloud.stream.binder.kafka.KafkaBinderMetrics.lambda$bindTo$0(KafkaBinderMetrics.java:163)
...
(The CI line numbers are from an earlier 4.x/5.0.x release; the code path is the same.)
To Reproduce
Minimal Maven project (pom.xml + a single JUnit test, no broker needed) that fails deterministically on 5.0.4: https://gist.github.com/rafallezanko/1ba280839b3a229f1afb6c06289070ee
Put the test file under src/test/java/org/springframework/cloud/stream/binder/kafka/ (it is in that package because getTopicsInUse() is package-private), then run:
mvn test
The only test hook is a SimpleMeterRegistry whose remove() waits until the lag task is queued on consumerFactoryLock. close() calls remove() while holding that lock, so the hook just widens the race window. The test fails because stop() does not return within 15 s, and ThreadMXBean.findDeadlockedThreads() reports the same two threads as above.
Note: the scheduler threads are non-daemon, so the forked test JVM also does not exit after the failure. That is the same symptom we see in CI.
Expected behavior
close() / stop() always completes, and the JVM can exit.
Possible fix (suggestion)
- Do not call
metadataConsumers.clear()(or close the consumers) while holdingconsumerFactoryLock. Or release the lock beforeawaitTermination. - And/or do not create the consumer factory inside the
computeIfAbsentmapping function. CallcreateConsumerFactory()first, thencomputeIfAbsent(group, g -> factory.createConsumer(...)).
Workaround
Deny the gauge so the lag task is never scheduled:
management.metrics.enable.spring.cloud.stream.binder.kafka.offset=false (or a MeterFilter.deny for spring.cloud.stream.binder.kafka.offset).
- 主要言語
- Java
- スター
- 1.1k
- フォーク
- 651
- 平均マージ
- 2日 15時間
- マージ済み PR(30日)
- 8
環境構築
このプロジェクトには開発コンテナ、Dockerfile、コントリビューションガイドがありません。まず README を読み、一般的な手順ははじめてのコントリビューションガイドを参照してください。
はじめの一歩
- issue を最後まで読み、次にプロジェクトのコントリビューションガイドを読みます。
- 着手することを issue にコメントします — 二人が同じ作業をするのを防げます。
- リポジトリをフォークし、ブランチを切って変更します。
- issue 番号を参照したプルリクエストを送ります。
spring-cloud/spring-cloud-stream のほかの issue
-
Kafka binder health-check consumer failures return DOWN without logging the exception対応中かも @Sanskar121543 が 1 日前に担当しました。 オープン
難易度 2/5 1〜3時間 初心者へのやさしさ 25/100
spring-cloud/spring-cloud-stream#3329 ·
メンテナーはふだん 1 日以内に返信
-
Kafka pollable consumers lose ConsumerFactory listeners when max.poll.records is greater than oneオープン
難易度 4/5 3〜5日 初心者へのやさしさ 55/100
spring-cloud/spring-cloud-stream#3324 · コメント 2 件 ·
メンテナーはふだん 1 日以内に返信
-
難易度 3/5 1〜2日 初心者へのやさしさ 74/100
spring-cloud/spring-cloud-stream#3316 ·
メンテナーはふだん 1 日以内に返信
-
StreamBridge removing BindingProperties leads to wrong destination in ProvisioningProvider再び着手できるかも @olegz が 60 日前に担当しましたが、オープン中のプルリクエストはありません。 オープンbug
spring-cloud/spring-cloud-stream#3257 · コメント 6 件 · リアクション 2 件 · 担当者 1 名 ·
メンテナーはふだん 1 日以内に返信
-
StreamBridge's hashProducerProperties produces hash collisions across different binding names, causing Partition key cannot be null再び着手できるかも このイシューのプルリクエストはマージされずにクローズされました。 オープン
難易度 4/5 3〜5日 初心者へのやさしさ 48/100
spring-cloud/spring-cloud-stream#3242 · コメント 2 件 ·
メンテナーはふだん 1 日以内に返信
spring-cloud/spring-cloud-stream の issue をすべて見る
似ている issue
-
難易度 2/5 1〜3時間 初心者へのやさしさ 68/100
-
[Bug]: NetworkPolicyOperator removes finalizers added by the EKS network policy controller, which adds them back再び着手できるかも このイシューのプルリクエストはマージされずにクローズされました。 オープンbug needs-triage
難易度 2/5 1〜3時間 初心者へのやさしさ 82/100
strimzi/strimzi-kafka-operator#13360 · コメント 5 件 ·
メンテナーはふだん 1 日以内に返信
-
bug javascript
難易度 2/5 1〜3時間 初心者へのやさしさ 72/100
メンテナーはふだん 1 日以内に返信
-
難易度 2/5 1〜3時間 初心者へのやさしさ 77/100
NationalSecurityAgency/ghidra#10149 ·
メンテナーはふだん 2 日以内に返信
-
難易度 2/5 1〜3時間 初心者へのやさしさ 90/100
yegor256/antlr2ebnf-maven-plugin#155 ·
メンテナーはふだん 1 日以内に返信