[
https://issues.apache.org/jira/browse/KAFKA-13714?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17509379#comment-17509379
]
John Roesler commented on KAFKA-13714:
--------------------------------------
Another:
{code:java}
verifyStore[cache=true, log=true, supplier=TIME_ROCKS_KV, kind=PAPI]
java.lang.AssertionError:
Result:StateQueryResult{partitionResults={0=SucceededQueryResult{result=org.apache.kafka.streams.state.internals.MeteredKeyValueStore$MeteredKeyValueTimestampedIterator@72e789cb,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 87900ns,
Handled in class
org.apache.kafka.streams.state.internals.ChangeLoggingTimestampedKeyValueBytesStore
via WrappedStateStore in 366097ns, Handled in class
org.apache.kafka.streams.state.internals.CachingKeyValueStore in 373038ns,
Handled in class
org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore with
serdes org.apache.kafka.streams.state.StateSerdes@627d8516 in 400408ns],
position=Position{position={input-topic={0=1}}}},
1=SucceededQueryResult{result=org.apache.kafka.streams.state.internals.MeteredKeyValueStore$MeteredKeyValueTimestampedIterator@7c1812b3,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 27551ns,
Handled in class
org.apache.kafka.streams.state.internals.ChangeLoggingTimestampedKeyValueBytesStore
via WrappedStateStore in 406916ns, Handled in class
org.apache.kafka.streams.state.internals.CachingKeyValueStore in 413227ns,
Handled in class
org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore with
serdes org.apache.kafka.streams.state.StateSerdes@5c10285a in 427044ns],
position=Position{position={input-topic={1=1}}}}}, globalResult=null}
Expected: is <[1, 2, 3]>
but: was <[1, 3]>
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
at
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.shouldHandleRangeQuery(IQv2StoreIntegrationTest.java:1140)
at
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.shouldHandleRangeQueries(IQv2StoreIntegrationTest.java:818)
at
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.verifyStore(IQv2StoreIntegrationTest.java:782)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
at
org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at
org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at
org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
at org.junit.runners.Suite.runChild(Suite.java:128)
at org.junit.runners.Suite.runChild(Suite.java:27)
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
at
org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
at
org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.runTestClass(JUnitTestClassExecutor.java:110)
at
org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:58)
at
org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:38)
at
org.gradle.api.internal.tasks.testing.junit.AbstractJUnitTestClassProcessor.processTestClass(AbstractJUnitTestClassProcessor.java:62)
at
org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
at
org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at
org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:33)
at
org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:94)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at
org.gradle.api.internal.tasks.testing.worker.TestWorker$2.run(TestWorker.java:176)
at
org.gradle.api.internal.tasks.testing.worker.TestWorker.executeAndMaintainThreadName(TestWorker.java:129)
at
org.gradle.api.internal.tasks.testing.worker.TestWorker.execute(TestWorker.java:100)
at
org.gradle.api.internal.tasks.testing.worker.TestWorker.execute(TestWorker.java:60)
at
org.gradle.process.internal.worker.child.ActionExecutionWorker.execute(ActionExecutionWorker.java:56)
at
org.gradle.process.internal.worker.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:133)
at
org.gradle.process.internal.worker.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:71)
at
worker.org.gradle.process.internal.worker.GradleWorkerMain.run(GradleWorkerMain.java:69)
at
worker.org.gradle.process.internal.worker.GradleWorkerMain.main(GradleWorkerMain.java:74)
{code}
{code:java}
[2022-03-19 23:50:05,329] INFO Generating test cases according to random seed:
5012730987561423151
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest:361)
[2022-03-19 23:50:06,811] INFO [Producer clientId=producer-1] Instantiated an
idempotent producer. (org.apache.kafka.clients.producer.KafkaProducer:532)
[2022-03-19 23:50:06,834] INFO [Producer clientId=producer-1] Resetting the
last seen epoch of partition input-topic-0 to 0 since the associated topicId
changed from null to ANuKr3aBTJCCZBfX79TG7g
(org.apache.kafka.clients.Metadata:402)
[2022-03-19 23:50:06,834] INFO [Producer clientId=producer-1] Resetting the
last seen epoch of partition input-topic-1 to 0 since the associated topicId
changed from null to ANuKr3aBTJCCZBfX79TG7g
(org.apache.kafka.clients.Metadata:402)
[2022-03-19 23:50:06,836] INFO [Producer clientId=producer-1] Cluster ID:
qwcb5jSAR96EM7WpRlrwaQ (org.apache.kafka.clients.Metadata:287)
[2022-03-19 23:50:06,844] INFO [Producer clientId=producer-1] ProducerId set to
0 with epoch 0
(org.apache.kafka.clients.producer.internals.TransactionManager:545)
[2022-03-19 23:50:06,895] INFO [Producer clientId=producer-1] Closing the Kafka
producer with timeoutMillis = 9223372036854775807 ms.
(org.apache.kafka.clients.producer.KafkaProducer:1207)
[2022-03-19 23:50:06,936] WARN Using an OS temp directory in the state.dir
property can cause failures with writing the checkpoint file due to the fact
that this directory can be cleared by the OS. Resolved state.dir:
[/tmp/kafka-1417619087209305644]
(org.apache.kafka.streams.processor.internals.StateDirectory:138)
[2022-03-19 23:50:06,937] INFO No process id found on disk, got fresh process
id 9bee9275-4579-415c-adac-6aa6bbb0e5b1
(org.apache.kafka.streams.processor.internals.StateDirectory:213)
[2022-03-19 23:50:06,952] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1]
Kafka Streams version: test-version (org.apache.kafka.streams.KafkaStreams:912)
[2022-03-19 23:50:06,953] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1]
Kafka Streams commit ID: test-commit-ID
(org.apache.kafka.streams.KafkaStreams:913)
[2022-03-19 23:50:06,960] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
Creating restore consumer client
(org.apache.kafka.streams.processor.internals.StreamThread:346)
[2022-03-19 23:50:06,982] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
Creating thread producer client
(org.apache.kafka.streams.processor.internals.StreamThread:105)
[2022-03-19 23:50:06,984] INFO [Producer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-producer]
Instantiated an idempotent producer.
(org.apache.kafka.clients.producer.KafkaProducer:532)
[2022-03-19 23:50:06,989] INFO [Producer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-producer]
Cluster ID: qwcb5jSAR96EM7WpRlrwaQ (org.apache.kafka.clients.Metadata:287)
[2022-03-19 23:50:06,990] INFO [Producer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-producer]
ProducerId set to 1 with epoch 0
(org.apache.kafka.clients.producer.internals.TransactionManager:545)
[2022-03-19 23:50:06,990] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
Creating consumer client
(org.apache.kafka.streams.processor.internals.StreamThread:397)
[2022-03-19 23:50:06,999] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer]
Cooperative rebalancing protocol is enabled now
(org.apache.kafka.streams.processor.internals.assignment.AssignorConfiguration:126)
[2022-03-19 23:50:07,016] WARN stream-thread [Test worker] Failed to delete
state store directory of
/tmp/kafka-1417619087209305644/app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725
for it is not empty
(org.apache.kafka.streams.processor.internals.StateDirectory:422)
[2022-03-19 23:50:07,017] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1]
State transition from CREATED to REBALANCING
(org.apache.kafka.streams.KafkaStreams:345)
[2022-03-19 23:50:07,017] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1]
Started 1 stream threads (org.apache.kafka.streams.KafkaStreams:1316)
[2022-03-19 23:50:07,017] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
Starting (org.apache.kafka.streams.processor.internals.StreamThread:539)
[2022-03-19 23:50:07,018] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
State transition from CREATED to STARTING
(org.apache.kafka.streams.processor.internals.StreamThread:233)
[2022-03-19 23:50:07,018] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Subscribed to topic(s): input-topic
(org.apache.kafka.clients.consumer.KafkaConsumer:968)
[2022-03-19 23:50:07,024] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Resetting the last seen epoch of partition input-topic-0 to 0 since the
associated topicId changed from null to ANuKr3aBTJCCZBfX79TG7g
(org.apache.kafka.clients.Metadata:402)
[2022-03-19 23:50:07,024] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Resetting the last seen epoch of partition input-topic-1 to 0 since the
associated topicId changed from null to ANuKr3aBTJCCZBfX79TG7g
(org.apache.kafka.clients.Metadata:402)
[2022-03-19 23:50:07,025] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Cluster ID: qwcb5jSAR96EM7WpRlrwaQ (org.apache.kafka.clients.Metadata:287)
[2022-03-19 23:50:07,122] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
Processed 0 total records, ran 0 punctuators, and committed 0 total tasks
since the last update
(org.apache.kafka.streams.processor.internals.StreamThread:838)
[2022-03-19 23:50:07,127] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Discovered group coordinator localhost:46203 (id: 2147483647 rack: null)
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:879)
[2022-03-19 23:50:07,128] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
(Re-)joining group
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:548)
[2022-03-19 23:50:07,151] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Request joining group due to: need to re-join with the given member-id:
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer-bd3b269b-273d-4b10-94cd-03a661115166
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1032)
[2022-03-19 23:50:07,152] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
(Re-)joining group
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:548)
[2022-03-19 23:50:07,160] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Successfully joined group with generation Generation{generationId=1,
memberId='app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer-bd3b269b-273d-4b10-94cd-03a661115166',
protocol='stream'}
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:609)
[2022-03-19 23:50:07,164] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer]
Skipping the repartition topic validation since there are no repartition
topics. (org.apache.kafka.streams.processor.internals.RepartitionTopics:75)
[2022-03-19 23:50:07,167] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer]
All members participating in this rebalance:
9bee9275-4579-415c-adac-6aa6bbb0e5b1:
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer-bd3b269b-273d-4b10-94cd-03a661115166].
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:620)
[2022-03-19 23:50:07,172] INFO Decided on assignment:
{9bee9275-4579-415c-adac-6aa6bbb0e5b1=[activeTasks: ([0_0, 0_1]) standbyTasks:
([]) prevActiveTasks: ([]) prevStandbyTasks: ([]) changelogOffsetTotalsByTask:
([]) taskLagTotals: ([]) capacity: 1 assigned: 2]} with no followup probing
rebalance.
(org.apache.kafka.streams.processor.internals.assignment.HighAvailabilityTaskAssignor:96)
[2022-03-19 23:50:07,172] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer]
Assigned tasks [0_1, 0_0] including stateful [] to clients as:
9bee9275-4579-415c-adac-6aa6bbb0e5b1=[activeTasks: ([0_0, 0_1]) standbyTasks:
([])].
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:638)
[2022-03-19 23:50:07,176] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer]
Client 9bee9275-4579-415c-adac-6aa6bbb0e5b1 per-consumer assignment:
prev owned active {}
prev owned standby
{app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer-bd3b269b-273d-4b10-94cd-03a661115166=[]}
assigned active
{app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer-bd3b269b-273d-4b10-94cd-03a661115166=[0_1,
0_0]}
revoking active {}
assigned standby {}
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:847)
[2022-03-19 23:50:07,176] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer]
Finished stable assignment of tasks, no followup rebalances required.
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:866)
[2022-03-19 23:50:07,177] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Finished assignment for group at generation 1:
{app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer-bd3b269b-273d-4b10-94cd-03a661115166=Assignment(partitions=[input-topic-0,
input-topic-1], userDataSize=135)}
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:691)
[2022-03-19 23:50:07,190] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Successfully synced group in generation Generation{generationId=1,
memberId='app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer-bd3b269b-273d-4b10-94cd-03a661115166',
protocol='stream'}
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:784)
[2022-03-19 23:50:07,191] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Updating assignment with
Assigned partitions: [input-topic-0,
input-topic-1]
Current owned partitions: []
Added partitions (assigned - owned): [input-topic-0,
input-topic-1]
Revoked partitions (owned - assigned): []
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:422)
[2022-03-19 23:50:07,191] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Notifying assignor about the new Assignment(partitions=[input-topic-0,
input-topic-1], userDataSize=135)
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:294)
[2022-03-19 23:50:07,191] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer]
No followup rebalance was requested, resetting the rebalance schedule.
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:1345)
[2022-03-19 23:50:07,192] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
Handle new assignment with:
New active tasks: [0_1, 0_0]
New standby tasks: []
Existing active tasks: []
Existing standby tasks: []
(org.apache.kafka.streams.processor.internals.TaskManager:273)
[2022-03-19 23:50:07,205] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Adding newly assigned partitions: input-topic-0, input-topic-1
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:306)
[2022-03-19 23:50:07,205] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
State transition from STARTING to PARTITIONS_ASSIGNED
(org.apache.kafka.streams.processor.internals.StreamThread:233)
[2022-03-19 23:50:07,213] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Found no committed offset for partition input-topic-0
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1436)
[2022-03-19 23:50:07,213] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Found no committed offset for partition input-topic-1
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1436)
[2022-03-19 23:50:07,223] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Resetting offset for partition input-topic-0 to position
FetchPosition{offset=0, offsetEpoch=Optional.empty,
currentLeader=LeaderAndEpoch{leader=Optional[localhost:46203 (id: 0 rack:
null)], epoch=0}}.
(org.apache.kafka.clients.consumer.internals.SubscriptionState:399)
[2022-03-19 23:50:07,223] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Resetting offset for partition input-topic-1 to position
FetchPosition{offset=0, offsetEpoch=Optional.empty,
currentLeader=LeaderAndEpoch{leader=Optional[localhost:46203 (id: 0 rack:
null)], epoch=0}}.
(org.apache.kafka.clients.consumer.internals.SubscriptionState:399)
[2022-03-19 23:50:07,232] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_0] State store kv-store is not logged and hence would not be restored
(org.apache.kafka.streams.processor.internals.ProcessorStateManager:244)
[2022-03-19 23:50:07,232] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_0] Initialized
(org.apache.kafka.streams.processor.internals.StreamTask:240)
[2022-03-19 23:50:07,234] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_1] State store kv-store is not logged and hence would not be restored
(org.apache.kafka.streams.processor.internals.ProcessorStateManager:244)
[2022-03-19 23:50:07,234] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_1] Initialized
(org.apache.kafka.streams.processor.internals.StreamTask:240)
[2022-03-19 23:50:07,236] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Found no committed offset for partition input-topic-0
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1436)
[2022-03-19 23:50:07,237] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_0] Restored and ready to run
(org.apache.kafka.streams.processor.internals.StreamTask:265)
[2022-03-19 23:50:07,238] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Found no committed offset for partition input-topic-1
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1436)
[2022-03-19 23:50:07,239] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_1] Restored and ready to run
(org.apache.kafka.streams.processor.internals.StreamTask:265)
[2022-03-19 23:50:07,239] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
Restoration took 34 ms for all tasks [0_0, 0_1]
(org.apache.kafka.streams.processor.internals.StreamThread:862)
[2022-03-19 23:50:07,239] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
State transition from PARTITIONS_ASSIGNED to RUNNING
(org.apache.kafka.streams.processor.internals.StreamThread:233)
[2022-03-19 23:50:07,240] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1]
State transition from REBALANCING to RUNNING
(org.apache.kafka.streams.KafkaStreams:345)
[2022-03-19 23:50:07,240] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Requesting the log end offset for input-topic-0 in order to compute lag
(org.apache.kafka.clients.consumer.KafkaConsumer:2265)
[2022-03-19 23:50:07,242] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725]
Requesting the log end offset for input-topic-1 in order to compute lag
(org.apache.kafka.clients.consumer.KafkaConsumer:2265)
[2022-03-19 23:50:07,320] INFO handled query:
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@621f89b8
: FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store
(class org.apache.kafka.streams.state.internals.RocksDBWindowStore) doesn't
know how to execute the given query
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@621f89b8).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[], position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,320] INFO handled query:
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@621f89b8
: FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store
(class org.apache.kafka.streams.state.internals.RocksDBWindowStore) doesn't
know how to execute the given query
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@621f89b8).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[], position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,322] INFO handled query:
org.apache.kafka.streams.query.KeyQuery@37c2eacb :
FailedQueryResult{failureReason=NOT_UP_TO_BOUND, failure='For store partition
0, the current position Position{position={}} is not yet up to the bound
PositionBound{position=Position{position={input-topic={0=1, 1=1}}}}',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBWindowStore in 63428ns],
position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,323] INFO handled query:
org.apache.kafka.streams.query.KeyQuery@37c2eacb :
FailedQueryResult{failureReason=NOT_UP_TO_BOUND, failure='For store partition
1, the current position Position{position={}} is not yet up to the bound
PositionBound{position=Position{position={input-topic={0=1, 1=1}}}}',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBWindowStore in 11858ns],
position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,423] INFO handled query:
org.apache.kafka.streams.query.KeyQuery@37c2eacb :
FailedQueryResult{failureReason=NOT_UP_TO_BOUND, failure='For store partition
0, the current position Position{position={}} is not yet up to the bound
PositionBound{position=Position{position={input-topic={0=1, 1=1}}}}',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBWindowStore in 25735ns],
position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,423] INFO handled query:
org.apache.kafka.streams.query.KeyQuery@37c2eacb :
FailedQueryResult{failureReason=NOT_UP_TO_BOUND, failure='For store partition
1, the current position Position{position={}} is not yet up to the bound
PositionBound{position=Position{position={input-topic={0=1, 1=1}}}}',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBWindowStore in 11002ns],
position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,462] INFO put data
\x00\x00\x00\x01\x00\x00\x01\x7F\xA5\xA9$\xC0\x00\x00\x00\x00 @ null
(org.apache.kafka.streams.state.internals.RocksDBStore:370)
[2022-03-19 23:50:07,462] INFO put position
\x00\x00\x00\x01\x00\x00\x01\x7F\xA5\xA9$\xC0\x00\x00\x00\x00 @ null
(org.apache.kafka.streams.state.internals.RocksDBStore:374)
[2022-03-19 23:50:07,462] INFO put data
\x00\x00\x00\x03\x00\x00\x01\x7F\xA5\xA9$\xC0\x00\x00\x00\x00 @ null
(org.apache.kafka.streams.state.internals.RocksDBStore:370)
[2022-03-19 23:50:07,462] INFO put position
\x00\x00\x00\x03\x00\x00\x01\x7F\xA5\xA9$\xC0\x00\x00\x00\x00 @ null
(org.apache.kafka.streams.state.internals.RocksDBStore:374)
[2022-03-19 23:50:07,465] INFO put data
\x00\x00\x00\x00\x00\x00\x01\x7F\xA5\xA9$\xC0\x00\x00\x00\x00 @ null
(org.apache.kafka.streams.state.internals.RocksDBStore:370)
[2022-03-19 23:50:07,466] INFO put position
\x00\x00\x00\x00\x00\x00\x01\x7F\xA5\xA9$\xC0\x00\x00\x00\x00 @ null
(org.apache.kafka.streams.state.internals.RocksDBStore:374)
[2022-03-19 23:50:07,466] INFO put data
\x00\x00\x00\x02\x00\x00\x01\x7F\xA5\xA9$\xC0\x00\x00\x00\x00 @ null
(org.apache.kafka.streams.state.internals.RocksDBStore:370)
[2022-03-19 23:50:07,466] INFO put position
\x00\x00\x00\x02\x00\x00\x01\x7F\xA5\xA9$\xC0\x00\x00\x00\x00 @ null
(org.apache.kafka.streams.state.internals.RocksDBStore:374)
[2022-03-19 23:50:07,524] INFO handled query:
org.apache.kafka.streams.query.KeyQuery@37c2eacb :
FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store (class
org.apache.kafka.streams.state.internals.RocksDBWindowStore) doesn't know how
to execute the given query (org.apache.kafka.streams.query.KeyQuery@37c2eacb).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBWindowStore in 49274ns],
position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,524] INFO handled query:
org.apache.kafka.streams.query.KeyQuery@37c2eacb :
FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store (class
org.apache.kafka.streams.state.internals.RocksDBWindowStore) doesn't know how
to execute the given query (org.apache.kafka.streams.query.KeyQuery@37c2eacb).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBWindowStore in 17003ns],
position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,525] INFO successful result for partition 0 Handled in
class org.apache.kafka.streams.state.internals.MeteredWindowStore in 361193ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,525] INFO successful result for partition 1 Handled in
class org.apache.kafka.streams.state.internals.MeteredWindowStore in 239158ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,526] INFO handled query:
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@7e75bf2d
: FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store
(class org.apache.kafka.streams.state.internals.RocksDBWindowStore) doesn't
know how to execute the given query
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@7e75bf2d).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBWindowStore in 10055ns],
position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,526] INFO handled query:
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@7e75bf2d
: FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store
(class org.apache.kafka.streams.state.internals.RocksDBWindowStore) doesn't
know how to execute the given query
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@7e75bf2d).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBWindowStore in 5301ns],
position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,526] INFO successful result for partition 0 Handled in
class org.apache.kafka.streams.state.internals.MeteredWindowStore in 200384ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,526] INFO successful result for partition 1 Handled in
class org.apache.kafka.streams.state.internals.MeteredWindowStore in 165632ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,536] INFO handled query:
WindowKeyQuery{key=\x00\x00\x00\x02, timeFrom=Optional[2022-03-20T04:50:00Z],
timeTo=Optional[2022-03-20T04:50:00Z]} :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.WindowStoreIteratorWrapper$WrappedWindowStoreIterator@451f87af,
executionInfo=[], position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,538] INFO handled query:
WindowKeyQuery{key=\x00\x00\x00\x02, timeFrom=Optional[2022-03-20T04:50:00Z],
timeTo=Optional[2022-03-20T04:50:00Z]} :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.WindowStoreIteratorWrapper$WrappedWindowStoreIterator@2e3cdec2,
executionInfo=[], position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,541] INFO handled query:
WindowKeyQuery{key=\x00\x00\x00\x02,
timeFrom=Optional[2022-03-20T04:49:59.999Z],
timeTo=Optional[2022-03-20T04:49:59.999Z]} :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.WindowStoreIteratorWrapper$WrappedWindowStoreIterator@377008df,
executionInfo=[], position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,541] INFO handled query:
WindowKeyQuery{key=\x00\x00\x00\x02,
timeFrom=Optional[2022-03-20T04:49:59.999Z],
timeTo=Optional[2022-03-20T04:49:59.999Z]} :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.WindowStoreIteratorWrapper$WrappedWindowStoreIterator@540dbda9,
executionInfo=[], position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,542] INFO handled query:
WindowKeyQuery{key=\x00\x00\x03\xE7, timeFrom=Optional[2022-03-20T04:50:00Z],
timeTo=Optional[2022-03-20T04:50:00Z]} :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.WindowStoreIteratorWrapper$WrappedWindowStoreIterator@6d4c273c,
executionInfo=[], position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,542] INFO handled query:
WindowKeyQuery{key=\x00\x00\x03\xE7, timeFrom=Optional[2022-03-20T04:50:00Z],
timeTo=Optional[2022-03-20T04:50:00Z]} :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.WindowStoreIteratorWrapper$WrappedWindowStoreIterator@5a67e962,
executionInfo=[], position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,543] INFO handled query:
WindowKeyQuery{key=\x00\x00\x03\xE7,
timeFrom=Optional[2022-03-20T04:49:59.999Z],
timeTo=Optional[2022-03-20T04:49:59.999Z]} :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.WindowStoreIteratorWrapper$WrappedWindowStoreIterator@64bfd6fd,
executionInfo=[], position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,543] INFO handled query:
WindowKeyQuery{key=\x00\x00\x03\xE7,
timeFrom=Optional[2022-03-20T04:49:59.999Z],
timeTo=Optional[2022-03-20T04:49:59.999Z]} :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.WindowStoreIteratorWrapper$WrappedWindowStoreIterator@2ab2710,
executionInfo=[], position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,544] INFO handled query:
WindowRangeQuery{key=Optional.empty, timeFrom=Optional[2022-03-20T04:50:00Z],
timeTo=Optional[2022-03-20T04:50:00Z]} :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.WindowStoreIteratorWrapper$WrappedKeyValueIterator@149f5761,
executionInfo=[], position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,545] INFO handled query:
WindowRangeQuery{key=Optional.empty, timeFrom=Optional[2022-03-20T04:50:00Z],
timeTo=Optional[2022-03-20T04:50:00Z]} :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.WindowStoreIteratorWrapper$WrappedKeyValueIterator@1f193686,
executionInfo=[], position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,546] INFO handled query:
WindowRangeQuery{key=Optional.empty,
timeFrom=Optional[2022-03-20T04:49:59.999Z],
timeTo=Optional[2022-03-20T04:49:59.999Z]} :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.WindowStoreIteratorWrapper$WrappedKeyValueIterator@1d25c1c,
executionInfo=[], position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,546] INFO handled query:
WindowRangeQuery{key=Optional.empty,
timeFrom=Optional[2022-03-20T04:49:59.999Z],
timeTo=Optional[2022-03-20T04:49:59.999Z]} :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.WindowStoreIteratorWrapper$WrappedKeyValueIterator@de88ac6,
executionInfo=[], position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,547] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1]
State transition from RUNNING to PENDING_SHUTDOWN
(org.apache.kafka.streams.KafkaStreams:345)
[2022-03-19 23:50:07,548] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
Informed to shut down
(org.apache.kafka.streams.processor.internals.StreamThread:1103)
[2022-03-19 23:50:07,548] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
State transition from RUNNING to PENDING_SHUTDOWN
(org.apache.kafka.streams.processor.internals.StreamThread:233)
[2022-03-19 23:50:07,548] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1]
Shutting down 1 stream threads (org.apache.kafka.streams.KafkaStreams:1363)
[2022-03-19 23:50:07,576] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
Shutting down (org.apache.kafka.streams.processor.internals.StreamThread:1117)
[2022-03-19 23:50:07,581] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_0] Suspended RUNNING
(org.apache.kafka.streams.processor.internals.StreamTask:1229)
[2022-03-19 23:50:07,581] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_0] Suspended running
(org.apache.kafka.streams.processor.internals.StreamTask:300)
[2022-03-19 23:50:07,583] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-restore-consumer,
groupId=null] Unsubscribed all topics or patterns and assigned partitions
(org.apache.kafka.clients.consumer.KafkaConsumer:1077)
[2022-03-19 23:50:07,588] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_0] Closing record collector clean
(org.apache.kafka.streams.processor.internals.RecordCollectorImpl:268)
[2022-03-19 23:50:07,588] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_0] Closed clean
(org.apache.kafka.streams.processor.internals.StreamTask:524)
[2022-03-19 23:50:07,588] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_1] Suspended RUNNING
(org.apache.kafka.streams.processor.internals.StreamTask:1229)
[2022-03-19 23:50:07,588] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_1] Suspended running
(org.apache.kafka.streams.processor.internals.StreamTask:300)
[2022-03-19 23:50:07,589] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-restore-consumer,
groupId=null] Unsubscribed all topics or patterns and assigned partitions
(org.apache.kafka.clients.consumer.KafkaConsumer:1077)
[2022-03-19 23:50:07,592] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_1] Closing record collector clean
(org.apache.kafka.streams.processor.internals.RecordCollectorImpl:268)
[2022-03-19 23:50:07,592] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
task [0_1] Closed clean
(org.apache.kafka.streams.processor.internals.StreamTask:524)
[2022-03-19 23:50:07,593] INFO [Producer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-producer]
Closing the Kafka producer with timeoutMillis = 9223372036854775807 ms.
(org.apache.kafka.clients.producer.KafkaProducer:1207)
[2022-03-19 23:50:07,596] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1-restore-consumer,
groupId=null] Unsubscribed all topics or patterns and assigned partitions
(org.apache.kafka.clients.consumer.KafkaConsumer:1077)
[2022-03-19 23:50:07,601] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
State transition from PENDING_SHUTDOWN to DEAD
(org.apache.kafka.streams.processor.internals.StreamThread:233)
[2022-03-19 23:50:07,601] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1-StreamThread-1]
Shutdown complete
(org.apache.kafka.streams.processor.internals.StreamThread:1152)
[2022-03-19 23:50:07,601] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1]
Shutdown 1 stream threads complete (org.apache.kafka.streams.KafkaStreams:1381)
[2022-03-19 23:50:07,604] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1]
State transition from PENDING_SHUTDOWN to NOT_RUNNING
(org.apache.kafka.streams.KafkaStreams:345)
[2022-03-19 23:50:07,604] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725-9bee9275-4579-415c-adac-6aa6bbb0e5b1]
Streams client stopped completely (org.apache.kafka.streams.KafkaStreams:1447)
[2022-03-19 23:50:07,605] INFO stream-thread [Test worker] Deleting task
directory 0_0 for 0_0 as user calling cleanup.
(org.apache.kafka.streams.processor.internals.StateDirectory:553)
[2022-03-19 23:50:07,605] INFO stream-thread [Test worker] Deleting task
directory 0_1 for 0_1 as user calling cleanup.
(org.apache.kafka.streams.processor.internals.StateDirectory:553)
[2022-03-19 23:50:07,606] WARN stream-thread [Test worker] Failed to delete
state store directory of
/tmp/kafka-1417619087209305644/app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-false-ROCKS_WINDOW-PAPI-262000725
for it is not empty
(org.apache.kafka.streams.processor.internals.StateDirectory:422)
[2022-03-19 23:50:07,615] WARN Using an OS temp directory in the state.dir
property can cause failures with writing the checkpoint file due to the fact
that this directory can be cleared by the OS. Resolved state.dir:
[/tmp/kafka-1551948438810143662]
(org.apache.kafka.streams.processor.internals.StateDirectory:138)
[2022-03-19 23:50:07,616] INFO No process id found on disk, got fresh process
id d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4
(org.apache.kafka.streams.processor.internals.StateDirectory:213)
[2022-03-19 23:50:07,620] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4]
Kafka Streams version: test-version (org.apache.kafka.streams.KafkaStreams:912)
[2022-03-19 23:50:07,620] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4]
Kafka Streams commit ID: test-commit-ID
(org.apache.kafka.streams.KafkaStreams:913)
[2022-03-19 23:50:07,621] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
Creating restore consumer client
(org.apache.kafka.streams.processor.internals.StreamThread:346)
[2022-03-19 23:50:07,623] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
Creating thread producer client
(org.apache.kafka.streams.processor.internals.StreamThread:105)
[2022-03-19 23:50:07,624] INFO [Producer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-producer]
Instantiated an idempotent producer.
(org.apache.kafka.clients.producer.KafkaProducer:532)
[2022-03-19 23:50:07,627] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
Creating consumer client
(org.apache.kafka.streams.processor.internals.StreamThread:397)
[2022-03-19 23:50:07,629] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer]
Cooperative rebalancing protocol is enabled now
(org.apache.kafka.streams.processor.internals.assignment.AssignorConfiguration:126)
[2022-03-19 23:50:07,629] INFO [Producer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-producer]
Cluster ID: qwcb5jSAR96EM7WpRlrwaQ (org.apache.kafka.clients.Metadata:287)
[2022-03-19 23:50:07,629] INFO [Producer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-producer]
ProducerId set to 2 with epoch 0
(org.apache.kafka.clients.producer.internals.TransactionManager:545)
[2022-03-19 23:50:07,631] WARN stream-thread [Test worker] Failed to delete
state store directory of
/tmp/kafka-1551948438810143662/app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073
for it is not empty
(org.apache.kafka.streams.processor.internals.StateDirectory:422)
[2022-03-19 23:50:07,631] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4]
State transition from CREATED to REBALANCING
(org.apache.kafka.streams.KafkaStreams:345)
[2022-03-19 23:50:07,631] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4]
Started 1 stream threads (org.apache.kafka.streams.KafkaStreams:1316)
[2022-03-19 23:50:07,631] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
Starting (org.apache.kafka.streams.processor.internals.StreamThread:539)
[2022-03-19 23:50:07,631] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
State transition from CREATED to STARTING
(org.apache.kafka.streams.processor.internals.StreamThread:233)
[2022-03-19 23:50:07,631] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Subscribed to topic(s): input-topic
(org.apache.kafka.clients.consumer.KafkaConsumer:968)
[2022-03-19 23:50:07,634] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Resetting the last seen epoch of partition input-topic-0 to 0 since the
associated topicId changed from null to ANuKr3aBTJCCZBfX79TG7g
(org.apache.kafka.clients.Metadata:402)
[2022-03-19 23:50:07,634] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Resetting the last seen epoch of partition input-topic-1 to 0 since the
associated topicId changed from null to ANuKr3aBTJCCZBfX79TG7g
(org.apache.kafka.clients.Metadata:402)
[2022-03-19 23:50:07,634] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Cluster ID: qwcb5jSAR96EM7WpRlrwaQ (org.apache.kafka.clients.Metadata:287)
[2022-03-19 23:50:07,634] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Discovered group coordinator localhost:46203 (id: 2147483647 rack: null)
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:879)
[2022-03-19 23:50:07,634] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
(Re-)joining group
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:548)
[2022-03-19 23:50:07,637] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Request joining group due to: need to re-join with the given member-id:
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer-7cea7a32-99f7-447a-b398-7a4edebb6228
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1032)
[2022-03-19 23:50:07,637] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
(Re-)joining group
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:548)
[2022-03-19 23:50:07,638] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Successfully joined group with generation Generation{generationId=1,
memberId='app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer-7cea7a32-99f7-447a-b398-7a4edebb6228',
protocol='stream'}
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:609)
[2022-03-19 23:50:07,638] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer]
Skipping the repartition topic validation since there are no repartition
topics. (org.apache.kafka.streams.processor.internals.RepartitionTopics:75)
[2022-03-19 23:50:07,639] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer]
All members participating in this rebalance:
d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4:
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer-7cea7a32-99f7-447a-b398-7a4edebb6228].
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:620)
[2022-03-19 23:50:07,639] INFO Decided on assignment:
{d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4=[activeTasks: ([0_0, 0_1]) standbyTasks:
([]) prevActiveTasks: ([]) prevStandbyTasks: ([]) changelogOffsetTotalsByTask:
([]) taskLagTotals: ([]) capacity: 1 assigned: 2]} with no followup probing
rebalance.
(org.apache.kafka.streams.processor.internals.assignment.HighAvailabilityTaskAssignor:96)
[2022-03-19 23:50:07,639] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer]
Assigned tasks [0_1, 0_0] including stateful [] to clients as:
d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4=[activeTasks: ([0_0, 0_1]) standbyTasks:
([])].
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:638)
[2022-03-19 23:50:07,639] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer]
Client d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4 per-consumer assignment:
prev owned active {}
prev owned standby
{app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer-7cea7a32-99f7-447a-b398-7a4edebb6228=[]}
assigned active
{app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer-7cea7a32-99f7-447a-b398-7a4edebb6228=[0_1,
0_0]}
revoking active {}
assigned standby {}
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:847)
[2022-03-19 23:50:07,640] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer]
Finished stable assignment of tasks, no followup rebalances required.
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:866)
[2022-03-19 23:50:07,640] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Finished assignment for group at generation 1:
{app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer-7cea7a32-99f7-447a-b398-7a4edebb6228=Assignment(partitions=[input-topic-0,
input-topic-1], userDataSize=135)}
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:691)
[2022-03-19 23:50:07,642] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Successfully synced group in generation Generation{generationId=1,
memberId='app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer-7cea7a32-99f7-447a-b398-7a4edebb6228',
protocol='stream'}
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:784)
[2022-03-19 23:50:07,642] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Updating assignment with
Assigned partitions: [input-topic-0,
input-topic-1]
Current owned partitions: []
Added partitions (assigned - owned): [input-topic-0,
input-topic-1]
Revoked partitions (owned - assigned): []
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:422)
[2022-03-19 23:50:07,642] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Notifying assignor about the new Assignment(partitions=[input-topic-0,
input-topic-1], userDataSize=135)
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:294)
[2022-03-19 23:50:07,642] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer]
No followup rebalance was requested, resetting the rebalance schedule.
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:1345)
[2022-03-19 23:50:07,642] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
Handle new assignment with:
New active tasks: [0_1, 0_0]
New standby tasks: []
Existing active tasks: []
Existing standby tasks: []
(org.apache.kafka.streams.processor.internals.TaskManager:273)
[2022-03-19 23:50:07,643] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Adding newly assigned partitions: input-topic-0, input-topic-1
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:306)
[2022-03-19 23:50:07,643] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
State transition from STARTING to PARTITIONS_ASSIGNED
(org.apache.kafka.streams.processor.internals.StreamThread:233)
[2022-03-19 23:50:07,644] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Found no committed offset for partition input-topic-0
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1436)
[2022-03-19 23:50:07,644] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Found no committed offset for partition input-topic-1
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1436)
[2022-03-19 23:50:07,647] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Resetting offset for partition input-topic-0 to position
FetchPosition{offset=0, offsetEpoch=Optional.empty,
currentLeader=LeaderAndEpoch{leader=Optional[localhost:46203 (id: 0 rack:
null)], epoch=0}}.
(org.apache.kafka.clients.consumer.internals.SubscriptionState:399)
[2022-03-19 23:50:07,647] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Resetting offset for partition input-topic-1 to position
FetchPosition{offset=0, offsetEpoch=Optional.empty,
currentLeader=LeaderAndEpoch{leader=Optional[localhost:46203 (id: 0 rack:
null)], epoch=0}}.
(org.apache.kafka.clients.consumer.internals.SubscriptionState:399)
[2022-03-19 23:50:07,765] INFO Opening store kv-store in regular mode
(org.apache.kafka.streams.state.internals.RocksDBTimestampedStore:100)
[2022-03-19 23:50:07,767] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_0] State store kv-store is not logged and hence would not be restored
(org.apache.kafka.streams.processor.internals.ProcessorStateManager:244)
[2022-03-19 23:50:07,768] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_0] Initialized
(org.apache.kafka.streams.processor.internals.StreamTask:240)
[2022-03-19 23:50:07,791] INFO Opening store kv-store in regular mode
(org.apache.kafka.streams.state.internals.RocksDBTimestampedStore:100)
[2022-03-19 23:50:07,792] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_1] State store kv-store is not logged and hence would not be restored
(org.apache.kafka.streams.processor.internals.ProcessorStateManager:244)
[2022-03-19 23:50:07,792] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_1] Initialized
(org.apache.kafka.streams.processor.internals.StreamTask:240)
[2022-03-19 23:50:07,794] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Found no committed offset for partition input-topic-0
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1436)
[2022-03-19 23:50:07,795] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_0] Restored and ready to run
(org.apache.kafka.streams.processor.internals.StreamTask:265)
[2022-03-19 23:50:07,797] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Found no committed offset for partition input-topic-1
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1436)
[2022-03-19 23:50:07,798] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_1] Restored and ready to run
(org.apache.kafka.streams.processor.internals.StreamTask:265)
[2022-03-19 23:50:07,798] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
Restoration took 154 ms for all tasks [0_0, 0_1]
(org.apache.kafka.streams.processor.internals.StreamThread:862)
[2022-03-19 23:50:07,798] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
State transition from PARTITIONS_ASSIGNED to RUNNING
(org.apache.kafka.streams.processor.internals.StreamThread:233)
[2022-03-19 23:50:07,798] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4]
State transition from REBALANCING to RUNNING
(org.apache.kafka.streams.KafkaStreams:345)
[2022-03-19 23:50:07,799] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Requesting the log end offset for input-topic-0 in order to compute lag
(org.apache.kafka.clients.consumer.KafkaConsumer:2265)
[2022-03-19 23:50:07,799] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073]
Requesting the log end offset for input-topic-1 in order to compute lag
(org.apache.kafka.clients.consumer.KafkaConsumer:2265)
[2022-03-19 23:50:07,799] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
Processed 0 total records, ran 0 punctuators, and committed 0 total tasks
since the last update
(org.apache.kafka.streams.processor.internals.StreamThread:838)
[2022-03-19 23:50:07,808] INFO put data \x00\x00\x00\x00 @
Position{position={}}
(org.apache.kafka.streams.state.internals.RocksDBStore:370)
[2022-03-19 23:50:07,808] INFO put position \x00\x00\x00\x00 @
Position{position={input-topic={0=0}}}
(org.apache.kafka.streams.state.internals.RocksDBStore:374)
[2022-03-19 23:50:07,809] INFO put data \x00\x00\x00\x01 @
Position{position={}}
(org.apache.kafka.streams.state.internals.RocksDBStore:370)
[2022-03-19 23:50:07,809] INFO put position \x00\x00\x00\x01 @
Position{position={input-topic={1=0}}}
(org.apache.kafka.streams.state.internals.RocksDBStore:374)
[2022-03-19 23:50:07,809] INFO put data \x00\x00\x00\x02 @
Position{position={input-topic={0=0}}}
(org.apache.kafka.streams.state.internals.RocksDBStore:370)
[2022-03-19 23:50:07,809] INFO put position \x00\x00\x00\x02 @
Position{position={input-topic={0=1}}}
(org.apache.kafka.streams.state.internals.RocksDBStore:374)
[2022-03-19 23:50:07,809] INFO put data \x00\x00\x00\x03 @
Position{position={input-topic={1=0}}}
(org.apache.kafka.streams.state.internals.RocksDBStore:370)
[2022-03-19 23:50:07,809] INFO put position \x00\x00\x00\x03 @
Position{position={input-topic={1=1}}}
(org.apache.kafka.streams.state.internals.RocksDBStore:374)
[2022-03-19 23:50:07,832] INFO handled query:
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@616b241a
: FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store
(class org.apache.kafka.streams.state.internals.RocksDBTimestampedStore)
doesn't know how to execute the given query
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@616b241a).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[], position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,832] INFO handled query:
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@616b241a
: FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store
(class org.apache.kafka.streams.state.internals.RocksDBTimestampedStore)
doesn't know how to execute the given query
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@616b241a).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[], position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,833] INFO handled query:
org.apache.kafka.streams.query.KeyQuery@b8e246c :
SucceededQueryResult{result=null, executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 132181ns],
position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,833] INFO handled query:
org.apache.kafka.streams.query.KeyQuery@7cb2651f :
SucceededQueryResult{result=[B@4441d567, executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 28820ns],
position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,833] INFO successful result for partition 0 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@1f387978 in 484751ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,834] INFO successful result for partition 1 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@3e1624c7 in 277654ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,834] INFO handled query:
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@62b969c4
: FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store
(class org.apache.kafka.streams.state.internals.RocksDBTimestampedStore)
doesn't know how to execute the given query
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@62b969c4).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 9983ns],
position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,834] INFO handled query:
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@62b969c4
: FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store
(class org.apache.kafka.streams.state.internals.RocksDBTimestampedStore)
doesn't know how to execute the given query
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@62b969c4).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 7863ns],
position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,834] INFO successful result for partition 0 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
in 188536ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,834] INFO successful result for partition 1 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
in 185679ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,835] INFO handled query:
org.apache.kafka.streams.query.KeyQuery@48535004 :
SucceededQueryResult{result=[B@610df783, executionInfo=[],
position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,835] INFO handled query:
org.apache.kafka.streams.query.KeyQuery@f3fcd59 :
SucceededQueryResult{result=null, executionInfo=[],
position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,836] INFO handled query:
org.apache.kafka.streams.query.RangeQuery@592238c5 :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.RocksDBRangeIterator@1aa99005,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 65016ns],
position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,837] INFO handled query:
org.apache.kafka.streams.query.RangeQuery@a20b94b :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.RocksDBRangeIterator@6ee8dcd3,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 36725ns],
position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,837] INFO successful result for partition 0 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@1f387978 in 680104ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,837] INFO successful result for partition 1 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@3e1624c7 in 253113ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,838] INFO handled query:
org.apache.kafka.streams.query.RangeQuery@1cc9cfb2 :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.RocksDBRangeIterator@16073fa8,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 34736ns],
position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,838] INFO handled query:
org.apache.kafka.streams.query.RangeQuery@3bead518 :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.RocksDBRangeIterator@cfbc8e8,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 33252ns],
position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,838] INFO successful result for partition 0 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@1f387978 in 293289ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,839] INFO successful result for partition 1 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@3e1624c7 in 245750ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,839] INFO handled query:
org.apache.kafka.streams.query.RangeQuery@7918c7f8 :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.RocksDBRangeIterator@14379273,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 31449ns],
position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,839] INFO handled query:
org.apache.kafka.streams.query.RangeQuery@1c504e66 :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.RocksDBRangeIterator@17740dae,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 25217ns],
position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,839] INFO successful result for partition 0 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@1f387978 in 241064ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,840] INFO successful result for partition 1 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@3e1624c7 in 217152ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,840] INFO handled query:
org.apache.kafka.streams.query.RangeQuery@2257fadf :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.RocksDbIterator@3c6aa04a,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 46914ns],
position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,840] INFO handled query:
org.apache.kafka.streams.query.RangeQuery@5c82cd4f :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.RocksDbIterator@7144655b,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 24911ns],
position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:07,841] INFO successful result for partition 0 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@1f387978 in 248926ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,841] INFO successful result for partition 1 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@3e1624c7 in 212110ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:07,841] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4]
State transition from RUNNING to PENDING_SHUTDOWN
(org.apache.kafka.streams.KafkaStreams:345)
[2022-03-19 23:50:07,842] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
Informed to shut down
(org.apache.kafka.streams.processor.internals.StreamThread:1103)
[2022-03-19 23:50:07,842] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
State transition from RUNNING to PENDING_SHUTDOWN
(org.apache.kafka.streams.processor.internals.StreamThread:233)
[2022-03-19 23:50:07,842] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4]
Shutting down 1 stream threads (org.apache.kafka.streams.KafkaStreams:1363)
[2022-03-19 23:50:07,910] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
Shutting down (org.apache.kafka.streams.processor.internals.StreamThread:1117)
[2022-03-19 23:50:07,922] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_0] Suspended RUNNING
(org.apache.kafka.streams.processor.internals.StreamTask:1229)
[2022-03-19 23:50:07,922] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_0] Suspended running
(org.apache.kafka.streams.processor.internals.StreamTask:300)
[2022-03-19 23:50:07,923] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-restore-consumer,
groupId=null] Unsubscribed all topics or patterns and assigned partitions
(org.apache.kafka.clients.consumer.KafkaConsumer:1077)
[2022-03-19 23:50:07,929] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_0] Closing record collector clean
(org.apache.kafka.streams.processor.internals.RecordCollectorImpl:268)
[2022-03-19 23:50:07,929] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_0] Closed clean
(org.apache.kafka.streams.processor.internals.StreamTask:524)
[2022-03-19 23:50:07,930] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_1] Suspended RUNNING
(org.apache.kafka.streams.processor.internals.StreamTask:1229)
[2022-03-19 23:50:07,930] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_1] Suspended running
(org.apache.kafka.streams.processor.internals.StreamTask:300)
[2022-03-19 23:50:07,931] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-restore-consumer,
groupId=null] Unsubscribed all topics or patterns and assigned partitions
(org.apache.kafka.clients.consumer.KafkaConsumer:1077)
[2022-03-19 23:50:07,937] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_1] Closing record collector clean
(org.apache.kafka.streams.processor.internals.RecordCollectorImpl:268)
[2022-03-19 23:50:07,937] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
task [0_1] Closed clean
(org.apache.kafka.streams.processor.internals.StreamTask:524)
[2022-03-19 23:50:07,938] INFO [Producer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-producer]
Closing the Kafka producer with timeoutMillis = 9223372036854775807 ms.
(org.apache.kafka.clients.producer.KafkaProducer:1207)
[2022-03-19 23:50:07,942] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1-restore-consumer,
groupId=null] Unsubscribed all topics or patterns and assigned partitions
(org.apache.kafka.clients.consumer.KafkaConsumer:1077)
[2022-03-19 23:50:07,951] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
State transition from PENDING_SHUTDOWN to DEAD
(org.apache.kafka.streams.processor.internals.StreamThread:233)
[2022-03-19 23:50:07,951] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4-StreamThread-1]
Shutdown complete
(org.apache.kafka.streams.processor.internals.StreamThread:1152)
[2022-03-19 23:50:07,951] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4]
Shutdown 1 stream threads complete (org.apache.kafka.streams.KafkaStreams:1381)
[2022-03-19 23:50:07,954] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4]
State transition from PENDING_SHUTDOWN to NOT_RUNNING
(org.apache.kafka.streams.KafkaStreams:345)
[2022-03-19 23:50:07,955] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073-d89b1ba3-71d0-4a4c-b1c0-9fbaa8cf66a4]
Streams client stopped completely (org.apache.kafka.streams.KafkaStreams:1447)
[2022-03-19 23:50:07,955] INFO stream-thread [Test worker] Deleting task
directory 0_0 for 0_0 as user calling cleanup.
(org.apache.kafka.streams.processor.internals.StateDirectory:553)
[2022-03-19 23:50:07,956] INFO stream-thread [Test worker] Deleting task
directory 0_1 for 0_1 as user calling cleanup.
(org.apache.kafka.streams.processor.internals.StateDirectory:553)
[2022-03-19 23:50:07,958] WARN stream-thread [Test worker] Failed to delete
state store directory of
/tmp/kafka-1551948438810143662/app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-false-false-TIME_ROCKS_KV-PAPI--1355308073
for it is not empty
(org.apache.kafka.streams.processor.internals.StateDirectory:422)
[2022-03-19 23:50:07,964] WARN Using an OS temp directory in the state.dir
property can cause failures with writing the checkpoint file due to the fact
that this directory can be cleared by the OS. Resolved state.dir:
[/tmp/kafka-7263456774646140643]
(org.apache.kafka.streams.processor.internals.StateDirectory:138)
[2022-03-19 23:50:07,964] INFO No process id found on disk, got fresh process
id 19351a20-e312-4bc9-b72d-719388794adc
(org.apache.kafka.streams.processor.internals.StateDirectory:213)
[2022-03-19 23:50:07,968] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc]
Kafka Streams version: test-version (org.apache.kafka.streams.KafkaStreams:912)
[2022-03-19 23:50:07,968] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc]
Kafka Streams commit ID: test-commit-ID
(org.apache.kafka.streams.KafkaStreams:913)
[2022-03-19 23:50:07,969] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
Creating restore consumer client
(org.apache.kafka.streams.processor.internals.StreamThread:346)
[2022-03-19 23:50:07,972] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
Creating thread producer client
(org.apache.kafka.streams.processor.internals.StreamThread:105)
[2022-03-19 23:50:07,973] INFO [Producer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-producer]
Instantiated an idempotent producer.
(org.apache.kafka.clients.producer.KafkaProducer:532)
[2022-03-19 23:50:07,976] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
Creating consumer client
(org.apache.kafka.streams.processor.internals.StreamThread:397)
[2022-03-19 23:50:07,979] INFO [Producer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-producer]
Cluster ID: qwcb5jSAR96EM7WpRlrwaQ (org.apache.kafka.clients.Metadata:287)
[2022-03-19 23:50:07,979] INFO [Producer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-producer]
ProducerId set to 3 with epoch 0
(org.apache.kafka.clients.producer.internals.TransactionManager:545)
[2022-03-19 23:50:07,979] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer]
Cooperative rebalancing protocol is enabled now
(org.apache.kafka.streams.processor.internals.assignment.AssignorConfiguration:126)
[2022-03-19 23:50:07,982] WARN stream-thread [Test worker] Failed to delete
state store directory of
/tmp/kafka-7263456774646140643/app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935
for it is not empty
(org.apache.kafka.streams.processor.internals.StateDirectory:422)
[2022-03-19 23:50:07,982] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc]
State transition from CREATED to REBALANCING
(org.apache.kafka.streams.KafkaStreams:345)
[2022-03-19 23:50:07,982] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc]
Started 1 stream threads (org.apache.kafka.streams.KafkaStreams:1316)
[2022-03-19 23:50:07,983] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
Starting (org.apache.kafka.streams.processor.internals.StreamThread:539)
[2022-03-19 23:50:07,983] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
State transition from CREATED to STARTING
(org.apache.kafka.streams.processor.internals.StreamThread:233)
[2022-03-19 23:50:07,983] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Subscribed to topic(s): input-topic
(org.apache.kafka.clients.consumer.KafkaConsumer:968)
[2022-03-19 23:50:07,986] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Resetting the last seen epoch of partition input-topic-0 to 0 since the
associated topicId changed from null to ANuKr3aBTJCCZBfX79TG7g
(org.apache.kafka.clients.Metadata:402)
[2022-03-19 23:50:07,986] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Resetting the last seen epoch of partition input-topic-1 to 0 since the
associated topicId changed from null to ANuKr3aBTJCCZBfX79TG7g
(org.apache.kafka.clients.Metadata:402)
[2022-03-19 23:50:07,986] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Cluster ID: qwcb5jSAR96EM7WpRlrwaQ (org.apache.kafka.clients.Metadata:287)
[2022-03-19 23:50:07,986] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Discovered group coordinator localhost:46203 (id: 2147483647 rack: null)
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:879)
[2022-03-19 23:50:07,987] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
(Re-)joining group
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:548)
[2022-03-19 23:50:07,989] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Request joining group due to: need to re-join with the given member-id:
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer-22292bd9-6e1c-40e1-8839-60958045aebc
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1032)
[2022-03-19 23:50:07,989] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
(Re-)joining group
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:548)
[2022-03-19 23:50:07,990] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Successfully joined group with generation Generation{generationId=1,
memberId='app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer-22292bd9-6e1c-40e1-8839-60958045aebc',
protocol='stream'}
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:609)
[2022-03-19 23:50:07,991] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer]
Skipping the repartition topic validation since there are no repartition
topics. (org.apache.kafka.streams.processor.internals.RepartitionTopics:75)
[2022-03-19 23:50:08,016] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer]
All members participating in this rebalance:
19351a20-e312-4bc9-b72d-719388794adc:
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer-22292bd9-6e1c-40e1-8839-60958045aebc].
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:620)
[2022-03-19 23:50:08,016] WARN Unable to assign 1 of 1 standby tasks for task
[0_0]. There is not enough available capacity. You should increase the number
of application instances to maintain the requested number of standby replicas.
(org.apache.kafka.streams.processor.internals.assignment.DefaultStandbyTaskAssignor:59)
[2022-03-19 23:50:08,017] WARN Unable to assign 1 of 1 standby tasks for task
[0_1]. There is not enough available capacity. You should increase the number
of application instances to maintain the requested number of standby replicas.
(org.apache.kafka.streams.processor.internals.assignment.DefaultStandbyTaskAssignor:59)
[2022-03-19 23:50:08,017] INFO Decided on assignment:
{19351a20-e312-4bc9-b72d-719388794adc=[activeTasks: ([0_0, 0_1]) standbyTasks:
([]) prevActiveTasks: ([]) prevStandbyTasks: ([]) changelogOffsetTotalsByTask:
([]) taskLagTotals: ([0_0=0, 0_1=0]) capacity: 1 assigned: 2]} with no followup
probing rebalance.
(org.apache.kafka.streams.processor.internals.assignment.HighAvailabilityTaskAssignor:96)
[2022-03-19 23:50:08,017] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer]
Assigned tasks [0_1, 0_0] including stateful [0_1, 0_0] to clients as:
19351a20-e312-4bc9-b72d-719388794adc=[activeTasks: ([0_0, 0_1]) standbyTasks:
([])].
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:638)
[2022-03-19 23:50:08,018] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer]
Client 19351a20-e312-4bc9-b72d-719388794adc per-consumer assignment:
prev owned active {}
prev owned standby
{app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer-22292bd9-6e1c-40e1-8839-60958045aebc=[]}
assigned active
{app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer-22292bd9-6e1c-40e1-8839-60958045aebc=[0_1,
0_0]}
revoking active {}
assigned standby {}
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:847)
[2022-03-19 23:50:08,018] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer]
Finished stable assignment of tasks, no followup rebalances required.
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:866)
[2022-03-19 23:50:08,018] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Finished assignment for group at generation 1:
{app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer-22292bd9-6e1c-40e1-8839-60958045aebc=Assignment(partitions=[input-topic-0,
input-topic-1], userDataSize=135)}
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:691)
[2022-03-19 23:50:08,020] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Successfully synced group in generation Generation{generationId=1,
memberId='app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer-22292bd9-6e1c-40e1-8839-60958045aebc',
protocol='stream'}
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:784)
[2022-03-19 23:50:08,020] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Updating assignment with
Assigned partitions: [input-topic-0,
input-topic-1]
Current owned partitions: []
Added partitions (assigned - owned): [input-topic-0,
input-topic-1]
Revoked partitions (owned - assigned): []
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:422)
[2022-03-19 23:50:08,020] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Notifying assignor about the new Assignment(partitions=[input-topic-0,
input-topic-1], userDataSize=135)
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:294)
[2022-03-19 23:50:08,020] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer]
No followup rebalance was requested, resetting the rebalance schedule.
(org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:1345)
[2022-03-19 23:50:08,020] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
Handle new assignment with:
New active tasks: [0_1, 0_0]
New standby tasks: []
Existing active tasks: []
Existing standby tasks: []
(org.apache.kafka.streams.processor.internals.TaskManager:273)
[2022-03-19 23:50:08,022] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Adding newly assigned partitions: input-topic-0, input-topic-1
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:306)
[2022-03-19 23:50:08,022] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
State transition from STARTING to PARTITIONS_ASSIGNED
(org.apache.kafka.streams.processor.internals.StreamThread:233)
[2022-03-19 23:50:08,023] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Found no committed offset for partition input-topic-0
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1436)
[2022-03-19 23:50:08,023] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Found no committed offset for partition input-topic-1
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1436)
[2022-03-19 23:50:08,025] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Resetting offset for partition input-topic-0 to position
FetchPosition{offset=0, offsetEpoch=Optional.empty,
currentLeader=LeaderAndEpoch{leader=Optional[localhost:46203 (id: 0 rack:
null)], epoch=0}}.
(org.apache.kafka.clients.consumer.internals.SubscriptionState:399)
[2022-03-19 23:50:08,025] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Resetting offset for partition input-topic-1 to position
FetchPosition{offset=0, offsetEpoch=Optional.empty,
currentLeader=LeaderAndEpoch{leader=Optional[localhost:46203 (id: 0 rack:
null)], epoch=0}}.
(org.apache.kafka.clients.consumer.internals.SubscriptionState:399)
[2022-03-19 23:50:08,092] INFO Opening store kv-store in regular mode
(org.apache.kafka.streams.state.internals.RocksDBTimestampedStore:100)
[2022-03-19 23:50:08,093] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
task [0_0] State store kv-store did not find checkpoint offset, hence would
default to the starting offset at changelog
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-0
(org.apache.kafka.streams.processor.internals.ProcessorStateManager:267)
[2022-03-19 23:50:08,093] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
task [0_0] Initialized
(org.apache.kafka.streams.processor.internals.StreamTask:240)
[2022-03-19 23:50:08,101] INFO Opening store kv-store in regular mode
(org.apache.kafka.streams.state.internals.RocksDBTimestampedStore:100)
[2022-03-19 23:50:08,102] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
task [0_1] State store kv-store did not find checkpoint offset, hence would
default to the starting offset at changelog
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-1
(org.apache.kafka.streams.processor.internals.ProcessorStateManager:267)
[2022-03-19 23:50:08,102] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
task [0_1] Initialized
(org.apache.kafka.streams.processor.internals.StreamTask:240)
[2022-03-19 23:50:08,107] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-restore-consumer,
groupId=null] Subscribed to partition(s):
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-0,
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-1
(org.apache.kafka.clients.consumer.KafkaConsumer:1123)
[2022-03-19 23:50:08,107] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-restore-consumer,
groupId=null] Seeking to EARLIEST offset of partition
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-0
(org.apache.kafka.clients.consumer.internals.SubscriptionState:642)
[2022-03-19 23:50:08,107] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-restore-consumer,
groupId=null] Seeking to EARLIEST offset of partition
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-1
(org.apache.kafka.clients.consumer.internals.SubscriptionState:642)
[2022-03-19 23:50:08,110] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-restore-consumer,
groupId=null] Resetting the last seen epoch of partition
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-0
to 0 since the associated topicId changed from null to 5kaYD7hoSk2iMdnDtONsNw
(org.apache.kafka.clients.Metadata:402)
[2022-03-19 23:50:08,110] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-restore-consumer,
groupId=null] Resetting the last seen epoch of partition
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-1
to 0 since the associated topicId changed from null to 5kaYD7hoSk2iMdnDtONsNw
(org.apache.kafka.clients.Metadata:402)
[2022-03-19 23:50:08,110] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-restore-consumer,
groupId=null] Cluster ID: qwcb5jSAR96EM7WpRlrwaQ
(org.apache.kafka.clients.Metadata:287)
[2022-03-19 23:50:08,112] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-restore-consumer,
groupId=null] Resetting offset for partition
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-0
to position FetchPosition{offset=0, offsetEpoch=Optional.empty,
currentLeader=LeaderAndEpoch{leader=Optional[localhost:46203 (id: 0 rack:
null)], epoch=0}}.
(org.apache.kafka.clients.consumer.internals.SubscriptionState:399)
[2022-03-19 23:50:08,112] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-restore-consumer,
groupId=null] Resetting offset for partition
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-1
to position FetchPosition{offset=0, offsetEpoch=Optional.empty,
currentLeader=LeaderAndEpoch{leader=Optional[localhost:46203 (id: 0 rack:
null)], epoch=0}}.
(org.apache.kafka.clients.consumer.internals.SubscriptionState:399)
[2022-03-19 23:50:08,183] INFO handled query:
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@7d0614f
: FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store
(class org.apache.kafka.streams.state.internals.RocksDBTimestampedStore)
doesn't know how to execute the given query
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@7d0614f).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[], position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:08,184] INFO handled query:
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@7d0614f
: FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store
(class org.apache.kafka.streams.state.internals.RocksDBTimestampedStore)
doesn't know how to execute the given query
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@7d0614f).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[], position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:08,214] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
Finished restoring changelog
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-0
to store kv-store with a total number of 0 records
(org.apache.kafka.streams.processor.internals.StoreChangelogReader:609)
[2022-03-19 23:50:08,214] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
Finished restoring changelog
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-1
to store kv-store with a total number of 0 records
(org.apache.kafka.streams.processor.internals.StoreChangelogReader:609)
[2022-03-19 23:50:08,215] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
Processed 0 total records, ran 0 punctuators, and committed 0 total tasks
since the last update
(org.apache.kafka.streams.processor.internals.StreamThread:838)
[2022-03-19 23:50:08,219] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Found no committed offset for partition input-topic-0
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1436)
[2022-03-19 23:50:08,220] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
task [0_0] Restored and ready to run
(org.apache.kafka.streams.processor.internals.StreamTask:265)
[2022-03-19 23:50:08,222] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Found no committed offset for partition input-topic-1
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:1436)
[2022-03-19 23:50:08,223] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
task [0_1] Restored and ready to run
(org.apache.kafka.streams.processor.internals.StreamTask:265)
[2022-03-19 23:50:08,224] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
Restoration took 202 ms for all tasks [0_0, 0_1]
(org.apache.kafka.streams.processor.internals.StreamThread:862)
[2022-03-19 23:50:08,224] INFO stream-thread
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1]
State transition from PARTITIONS_ASSIGNED to RUNNING
(org.apache.kafka.streams.processor.internals.StreamThread:233)
[2022-03-19 23:50:08,224] INFO stream-client
[app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc]
State transition from REBALANCING to RUNNING
(org.apache.kafka.streams.KafkaStreams:345)
[2022-03-19 23:50:08,224] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Requesting the log end offset for input-topic-0 in order to compute lag
(org.apache.kafka.clients.consumer.KafkaConsumer:2265)
[2022-03-19 23:50:08,225] INFO [Consumer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-consumer,
groupId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935]
Requesting the log end offset for input-topic-1 in order to compute lag
(org.apache.kafka.clients.consumer.KafkaConsumer:2265)
[2022-03-19 23:50:08,286] INFO handled query:
org.apache.kafka.streams.query.KeyQuery@6b667cb3 :
SucceededQueryResult{result=null, executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 96988ns],
position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:08,287] INFO successful result for partition 0 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@627d8516 in 1007193ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:08,288] INFO successful result for partition 1 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@5c10285a in 195818ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:08,288] INFO handled query:
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@6f38a289
: FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store
(class org.apache.kafka.streams.state.internals.RocksDBTimestampedStore)
doesn't know how to execute the given query
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@6f38a289).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 24606ns],
position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:08,289] INFO handled query:
org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@6f38a289
: FailedQueryResult{failureReason=UNKNOWN_QUERY_TYPE, failure='This store
(class org.apache.kafka.streams.state.internals.RocksDBTimestampedStore)
doesn't know how to execute the given query
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest$UnknownQuery@6f38a289).
Contact the store maintainer if you need support for a new query type.',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 16029ns],
position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:08,289] INFO successful result for partition 0 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
in 472241ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:08,289] INFO successful result for partition 1 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
in 489708ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:08,290] INFO handled query:
org.apache.kafka.streams.query.KeyQuery@61e3cf4d :
SucceededQueryResult{result=null, executionInfo=[],
position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:08,291] INFO handled query:
org.apache.kafka.streams.query.RangeQuery@3cec79d3 :
FailedQueryResult{failureReason=NOT_UP_TO_BOUND, failure='For store partition
0, the current position Position{position={}} is not yet up to the bound
PositionBound{position=Position{position={input-topic={0=1, 1=1}}}}',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 41763ns],
position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:08,292] INFO handled query:
org.apache.kafka.streams.query.RangeQuery@64b70919 :
FailedQueryResult{failureReason=NOT_UP_TO_BOUND, failure='For store partition
1, the current position Position{position={}} is not yet up to the bound
PositionBound{position=Position{position={input-topic={0=1, 1=1}}}}',
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 34303ns],
position=Position{position={}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:08,338] INFO put data \x00\x00\x00\x01 @
Position{position={}}
(org.apache.kafka.streams.state.internals.RocksDBStore:370)
[2022-03-19 23:50:08,338] INFO put position \x00\x00\x00\x01 @
Position{position={input-topic={1=1}}}
(org.apache.kafka.streams.state.internals.RocksDBStore:374)
[2022-03-19 23:50:08,342] INFO [Producer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-producer]
Resetting the last seen epoch of partition
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-0
to 0 since the associated topicId changed from null to 5kaYD7hoSk2iMdnDtONsNw
(org.apache.kafka.clients.Metadata:402)
[2022-03-19 23:50:08,342] INFO [Producer
clientId=app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-19351a20-e312-4bc9-b72d-719388794adc-StreamThread-1-producer]
Resetting the last seen epoch of partition
app-org.apache.kafka.streams.integration.IQv2StoreIntegrationTest-true-true-TIME_ROCKS_KV-PAPI-440178935-kv-store-changelog-1
to 0 since the associated topicId changed from null to 5kaYD7hoSk2iMdnDtONsNw
(org.apache.kafka.clients.Metadata:402)
[2022-03-19 23:50:08,344] INFO put data \x00\x00\x00\x03 @
Position{position={input-topic={1=1}}}
(org.apache.kafka.streams.state.internals.RocksDBStore:370)
[2022-03-19 23:50:08,344] INFO put position \x00\x00\x00\x03 @
Position{position={input-topic={1=1}}}
(org.apache.kafka.streams.state.internals.RocksDBStore:374)
[2022-03-19 23:50:08,347] INFO put data \x00\x00\x00\x00 @
Position{position={}}
(org.apache.kafka.streams.state.internals.RocksDBStore:370)
[2022-03-19 23:50:08,347] INFO put position \x00\x00\x00\x00 @
Position{position={input-topic={0=1}}}
(org.apache.kafka.streams.state.internals.RocksDBStore:374)
[2022-03-19 23:50:08,426] INFO handled query:
org.apache.kafka.streams.query.RangeQuery@3157e4c0 :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.RocksDBRangeIterator@4e31c3ec,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 87900ns],
position=Position{position={input-topic={0=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:08,426] INFO put data \x00\x00\x00\x02 @
Position{position={input-topic={0=1}}}
(org.apache.kafka.streams.state.internals.RocksDBStore:370)
[2022-03-19 23:50:08,426] INFO put position \x00\x00\x00\x02 @
Position{position={input-topic={0=1}}}
(org.apache.kafka.streams.state.internals.RocksDBStore:374)
[2022-03-19 23:50:08,426] INFO handled query:
org.apache.kafka.streams.query.RangeQuery@328902d5 :
SucceededQueryResult{result=org.apache.kafka.streams.state.internals.RocksDBRangeIterator@6eaa21d8,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 27551ns],
position=Position{position={input-topic={1=1}}}}
(org.apache.kafka.streams.state.internals.StoreQueryUtils:140)
[2022-03-19 23:50:08,427] INFO successful result for partition 0 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@627d8516 in 400408ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:08,427] INFO successful result for partition 1 Handled in
class org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore
with serdes org.apache.kafka.streams.state.StateSerdes@5c10285a in 427044ns
(org.apache.kafka.streams.integration.utils.IntegrationTestUtils:182)
[2022-03-19 23:50:08,428] ERROR Failed assertion
(org.apache.kafka.streams.integration.IQv2StoreIntegrationTest:811)
java.lang.AssertionError:
Result:StateQueryResult{partitionResults={0=SucceededQueryResult{result=org.apache.kafka.streams.state.internals.MeteredKeyValueStore$MeteredKeyValueTimestampedIterator@72e789cb,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 87900ns,
Handled in class
org.apache.kafka.streams.state.internals.ChangeLoggingTimestampedKeyValueBytesStore
via WrappedStateStore in 366097ns, Handled in class
org.apache.kafka.streams.state.internals.CachingKeyValueStore in 373038ns,
Handled in class
org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore with
serdes org.apache.kafka.streams.state.StateSerdes@627d8516 in 400408ns],
position=Position{position={input-topic={0=1}}}},
1=SucceededQueryResult{result=org.apache.kafka.streams.state.internals.MeteredKeyValueStore$MeteredKeyValueTimestampedIterator@7c1812b3,
executionInfo=[Handled in class
org.apache.kafka.streams.state.internals.RocksDBTimestampedStore in 27551ns,
Handled in class
org.apache.kafka.streams.state.internals.ChangeLoggingTimestampedKeyValueBytesStore
via WrappedStateStore in 406916ns, Handled in class
org.apache.kafka.streams.state.internals.CachingKeyValueStore in 413227ns,
Handled in class
org.apache.kafka.streams.state.internals.MeteredTimestampedKeyValueStore with
serdes org.apache.kafka.streams.state.StateSerdes@5c10285a in 427044ns],
position=Position{position={input-topic={1=1}}}}}, globalResult=null}
Expected: is <[1, 2, 3]>
but: was <[1, 3]> {code}
> Flaky test IQv2StoreIntegrationTest
> -----------------------------------
>
> Key: KAFKA-13714
> URL: https://issues.apache.org/jira/browse/KAFKA-13714
> Project: Kafka
> Issue Type: Bug
> Components: streams
> Affects Versions: 3.2.0
> Reporter: John Roesler
> Priority: Blocker
>
> I have observed multiple consistency violations in the
> IQv2StoreIntegrationTest. Since this is the first release of IQv2, and it's
> apparently a major flaw in the feature, we should not release with this bug
> outstanding. Depending on the time-table, we may want to block the release or
> pull the feature until the next release.
>
> The first observation I have is from 23 Feb 2022. So far all observations
> point to the range query in particular, and all observations have been for
> RocksDB stores, including RocksDBStore, TimestampedRocksDBStore, and the
> windowed store built on RocksDB segments.
> For reference, range queries were implemented on 16 Feb 2022:
> [https://github.com/apache/kafka/commit/b38f6ba5cc989702180f5d5f8e55ba20444ea884]
> The window-specific range query test has also failed once that I have seen.
> That feature was implemented on 2 Jan 2022:
> [https://github.com/apache/kafka/commit/b8f1cf14c396ab04b8968a8fa04d8cf67dd3254c]
>
> Here are some stack traces I have seen:
> {code:java}
> verifyStore[cache=true, log=true, supplier=ROCKS_KV, kind=PAPI]
> java.lang.AssertionError:
> Expected: is <[1, 2, 3]>
> but: was <[1, 2]>
> at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
> at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:6)
> at
> org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.shouldHandleRangeQuery(IQv2StoreIntegrationTest.java:1125)
> at
> org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.shouldHandleRangeQueries(IQv2StoreIntegrationTest.java:803)
> at
> org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.verifyStore(IQv2StoreIntegrationTest.java:776)
> {code}
> {code:java}
> verifyStore[cache=true, log=true, supplier=TIME_ROCKS_KV, kind=PAPI]
> java.lang.AssertionError:
> Expected: is <[1, 2, 3]>
> but: was <[1, 3]>
> at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
> at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:6)
> at
> org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.shouldHandleRangeQuery(IQv2StoreIntegrationTest.java:1131)
> at
> org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.shouldHandleRangeQueries(IQv2StoreIntegrationTest.java:809)
> at
> org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.verifyStore(IQv2StoreIntegrationTest.java:778)
> {code}
> {code:java}
> verifyStore[cache=true, log=true, supplier=ROCKS_KV, kind=PAPI]
> java.lang.AssertionError:
> Result:StateQueryResult{partitionResults={0=SucceededQueryResult{result=org.apache.kafka.streams.state.internals.MeteredKeyValueStore$MeteredKeyValueTimestampedIterator@35025a0a,
> executionInfo=[], position=Position{position={input-topic={0=1}}}},
> 1=SucceededQueryResult{result=org.apache.kafka.streams.state.internals.MeteredKeyValueStore$MeteredKeyValueTimestampedIterator@38732364,
> executionInfo=[], position=Position{position={input-topic={1=1}}}}},
> globalResult=null}
> Expected: is <[1, 2, 3]>
> but: was <[1, 2]>
> at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
> at
> org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.shouldHandleRangeQuery(IQv2StoreIntegrationTest.java:1129)
> at
> org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.shouldHandleRangeQueries(IQv2StoreIntegrationTest.java:807)
> at
> org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.verifyStore(IQv2StoreIntegrationTest.java:780)
> {code}
> {code:java}
> verifyStore[cache=true, log=false, supplier=ROCKS_WINDOW, kind=DSL]
> java.lang.AssertionError:
> Result:StateQueryResult{partitionResults={0=SucceededQueryResult{result=org.apache.kafka.streams.state.internals.MeteredWindowedKeyValueIterator@2a32fb6,
> executionInfo=[], position=Position{position={input-topic={0=1}}}},
> 1=SucceededQueryResult{result=org.apache.kafka.streams.state.internals.MeteredWindowedKeyValueIterator@6107165,
> executionInfo=[], position=Position{position={input-topic={1=1}}}}},
> globalResult=null}
> Expected: is <[0, 1, 2, 3]>
> but: was <[0, 2, 3]>
> at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
> at
> org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.shouldHandleWindowRangeQuery(IQv2StoreIntegrationTest.java:1234)
> at
> org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.shouldHandleWindowRangeQueries(IQv2StoreIntegrationTest.java:880)
> at
> org.apache.kafka.streams.integration.IQv2StoreIntegrationTest.verifyStore(IQv2StoreIntegrationTest.java:793)
> {code}
>
> Some observations:
> * After I added the whole query result to the failure message, we can see
> that the results are always past the desired position, even though they don't
> include all the data that should have been present in that position.
> * All the observed failures have happened with caching=true, but that it
> probably a red herring, since range queries skip the cache (cf
> fe72187cb15bf7dcc16e8630ed379e979c101151)
> * For a while, I thought that it might be a thread visibility problem with
> the iterators, since the missing record was always at the end of the range
> for some partition, but the window range failure is missing record 1, which
> is at the beginning of the range in partition 1.
> I have been able to reproduce the failure locally, but only occasionally. I
> made some hacks to narrow down the space of possibilities:
> [https://github.com/vvcephei/kafka/commit/2a0776e52e378f1c59e98f352e3fa4f79c55842d]
> I didn't have success running that one test until failure in IDEA. It has
> never failed for me in IDEA, even after thousands of attempts. In my testing
> branch, I added a loop to repeat one test configuration a thousand times in
> Gradle, but it still didn't fail reliably.
> I also added a test to specifically check that RocksDB is giving the desired
> serialization both in one thread and across threads, and that test passes for
> me. My next thought is to expand that Tmp test to do the same with the
> RocksDBIterator class, or maybe just with a standalone RocksDBStore to see if
> we can reproduce it.
--
This message was sent by Atlassian Jira
(v8.20.1#820001)
