[
https://issues.apache.org/jira/browse/KAFKA-18498?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Bill Bejeck reassigned KAFKA-18498:
-----------------------------------
Assignee: Bill Bejeck
> Kafka Streams main thread does not release lock
> -----------------------------------------------
>
> Key: KAFKA-18498
> URL: https://issues.apache.org/jira/browse/KAFKA-18498
> Project: Kafka
> Issue Type: Bug
> Components: streams
> Reporter: Matthias J. Sax
> Assignee: Bill Bejeck
> Priority: Critical
>
> We merged [https://github.com/apache/kafka/pull/16922] which seems to
> introduce a regression bug, not releasing a lock properly.
> We saw a failing system test (timed out) with the following (relevant logs)
> {code:java}
> [2024-12-19 02:45:29,637] DEBUG stream-thread [main] standby-task [1_0]
> Acquired state directory lock
> (org.apache.kafka.streams.processor.internals.StandbyTask)
> [2024-12-19 02:45:29,655] INFO Opening store
> KSTREAM-AGGREGATE-STATE-STORE-0000000014 in regular mode
> (org.apache.kafka.streams.state.internals.RocksDBTimestampedStore)
> [2024-12-19 02:45:29,656] DEBUG [RocksDB Metrics Recorder for
> KSTREAM-AGGREGATE-STATE-STORE-0000000014] Adding metrics recorder of task 1_0
> to metrics recording trigger
> (org.apache.kafka.streams.state.internals.metrics.RocksDBMetricsRecorder)
> [2024-12-19 02:45:29,656] DEBUG [RocksDB Metrics Recorder for
> KSTREAM-AGGREGATE-STATE-STORE-0000000014] Adding value providers for store
> KSTREAM-AGGREGATE-STATE-STORE-0000000014 of task 1_0
> (org.apache.kafka.streams.state.internals.metrics.RocksDBMetricsRecorder)
> [2024-12-19 02:45:29,656] DEBUG stream-client
> [EosTest-6cef0eeb-642f-446b-ada7-35c3d7f7121c] Registered state store
> KSTREAM-AGGREGATE-STATE-STORE-0000000014 to its state manager
> (org.apache.kafka.streams.processor.internals.ProcessorStateManager)
> [2024-12-19 02:45:29,675] INFO Opening store
> KSTREAM-AGGREGATE-STATE-STORE-0000000018 in regular mode
> (org.apache.kafka.streams.state.internals.RocksDBTimestampedStore)
> [2024-12-19 02:45:29,675] DEBUG [RocksDB Metrics Recorder for
> KSTREAM-AGGREGATE-STATE-STORE-0000000018] Adding metrics recorder of task 1_0
> to metrics recording trigger
> (org.apache.kafka.streams.state.internals.metrics.RocksDBMetricsRecorder)
> [2024-12-19 02:45:29,675] DEBUG [RocksDB Metrics Recorder for
> KSTREAM-AGGREGATE-STATE-STORE-0000000018] Adding value providers for store
> KSTREAM-AGGREGATE-STATE-STORE-0000000018 of task 1_0
> (org.apache.kafka.streams.state.internals.metrics.RocksDBMetricsRecorder)
> [2024-12-19 02:45:29,676] DEBUG stream-client
> [EosTest-6cef0eeb-642f-446b-ada7-35c3d7f7121c] Registered state store
> KSTREAM-AGGREGATE-STATE-STORE-0000000018 to its state manager
> (org.apache.kafka.streams.processor.internals.ProcessorStateManager)
> [2024-12-19 02:45:29,676] DEBUG stream-thread [main] standby-task [1_0]
> Registered state stores
> (org.apache.kafka.streams.processor.internals.StandbyTask)
> [2024-12-19 02:45:29,676] INFO stream-client
> [EosTest-6cef0eeb-642f-446b-ada7-35c3d7f7121c] State store
> KSTREAM-AGGREGATE-STATE-STORE-0000000014 initialized from checkpoint with
> offset null at changelog
> EosTest-KSTREAM-AGGREGATE-STATE-STORE-0000000014-changelog-0
> (org.apache.kafka.streams.processor.internals.ProcessorStateManager)
> [2024-12-19 02:45:29,676] INFO stream-client
> [EosTest-6cef0eeb-642f-446b-ada7-35c3d7f7121c] State store
> KSTREAM-AGGREGATE-STATE-STORE-0000000018 initialized from checkpoint with
> offset null at changelog
> EosTest-KSTREAM-AGGREGATE-STATE-STORE-0000000018-changelog-0
> (org.apache.kafka.streams.processor.internals.ProcessorStateManager)
> [2024-12-19 02:45:29,676] DEBUG stream-thread [main] standby-task [1_0]
> Initialized state stores
> (org.apache.kafka.streams.processor.internals.StandbyTask)
> [2024-12-19 02:45:29,676] INFO stream-thread [main] standby-task [1_0]
> Initialized (org.apache.kafka.streams.processor.internals.StandbyTask)
> [...]
> [2024-12-19 02:45:32,328] INFO stream-thread [main] standby-task [1_0]
> Suspended running (org.apache.kafka.streams.processor.internals.StandbyTask)
> [2024-12-19 02:45:32,328] ERROR stream-thread [main] standby-task [1_0]
> Failed to acquire lock while closing the state store for STANDBY task 1_0
> (org.apache.kafka.streams.processor.internals.StandbyTask)
> [2024-12-19 02:45:32,328] INFO stream-thread [main] standby-task [1_0] Closed
> clean (org.apache.kafka.streams.processor.internals.StandbyTask)
> [...]
> [2024-12-19 02:45:32,374] INFO stream-thread
> [EosTest-6cef0eeb-642f-446b-ada7-35c3d7f7121c-StreamThread-1] Handle new
> assignment with:
> New active tasks: [1_0, 1_3, 0_2]
> New standby tasks: [0_4, 1_4, 0_3, 0_1, 1_2, 1_1, 0_0]
> Existing active tasks: []
> Existing standby tasks: [0_4, 1_4, 0_3, 0_1, 1_2, 0_0, 1_1]
> (org.apache.kafka.streams.processor.internals.TaskManager)
> [2024-12-19 02:45:32,376] DEBUG stream-thread
> [EosTest-6cef0eeb-642f-446b-ada7-35c3d7f7121c-StreamThread-1] stream-task
> [1_0] Created state store manager for task 1_0
> (org.apache.kafka.streams.processor.internals.ProcessorStateManager)
> [...]
> [2024-12-19 02:45:32,562] INFO stream-thread
> [EosTest-6cef0eeb-642f-446b-ada7-35c3d7f7121c-StreamThread-1] Encountered
> lock exception. Reattempting locking the state in the next iteration. Error
> message was: stream-thread
> [EosTest-6cef0eeb-642f-446b-ada7-35c3d7f7121c-StreamThread-1] task [1_0]
> Failed to lock the state directory for task 1_0
> (org.apache.kafka.streams.processor.internals.TaskManager) {code}
> The last log line keeps repeating...
> I am going to revert the PR for 4.0 release, and we should fix forward on
> `trunk`.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
