[ 
https://issues.apache.org/jira/browse/KAFKA-18498?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Bill Bejeck updated KAFKA-18498:
--------------------------------
    Affects Version/s: 4.1.0

> 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
>    Affects Versions: 4.1.0
>            Reporter: Matthias J. Sax
>            Assignee: Bill Bejeck
>            Priority: Critical
>             Fix For: 4.1.0
>
>
> 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)

Reply via email to