[
https://issues.apache.org/jira/browse/KAFKA-2170?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15426278#comment-15426278
]
Harald Kirsch commented on KAFKA-2170:
--------------------------------------
The patch does not seem to work completely for compaction. I applied the patch
on 40b1dd3f495a59abef8a0cba5450526994c92c04, ran ./gradlew releaseTarGz and
unpacked on a windows 8.1. I ran the server with the following configs:
{noformat}
broker.id=0
listeners=PLAINTEXT://:9092
num.network.threads=3
num.io.threads=8
socket.send.buffer.bytes=102400
socket.receive.buffer.bytes=102400
socket.request.max.bytes=104857600
log.dirs=C:\\Users\\hk\\tmp\\kafka-data
num.partitions=1
num.recovery.threads.per.data.dir=1
log.retention.hours=168
log.segment.bytes=6000111
log.retention.check.interval.ms=300000
zookeeper.connect=hal.intranet.raytion.com:2181/kafka
zookeeper.connection.timeout.ms=6000
log.cleaner.enable=true
log.cleanup.policy=compact
log.cleaner.min.cleanable.ratio=0.01
log.cleaner.backoff.ms=15000
log.segment.delete.delay.ms=600
auto.create.topics.enable=false
{noformat}
Then I fed the same set of docs twice. The cleaner logged a successful
activity, but the folder now contains all {{.index.deleted}} files like this:
{noformat}
Mode LastWriteTime Length Name
---- ------------- ------ ----
-a--- 18.08.2016 12:33 0 00000000000000000000.index
----- 18.08.2016 12:33 176 00000000000000000000.index.deleted
-a--- 18.08.2016 12:33 0 00000000000000000000.log
-a--- 18.08.2016 12:33 0 00000000000000000023.index
----- 18.08.2016 12:33 192 00000000000000000023.index.deleted
-a--- 18.08.2016 12:33 583752 00000000000000000023.log
-a--- 18.08.2016 12:33 48 00000000000000000048.index
----- 18.08.2016 12:33 192 00000000000000000048.index.deleted
-a--- 18.08.2016 12:33 5844328 00000000000000000048.log
-a--- 18.08.2016 12:33 48 00000000000000000073.index
----- 18.08.2016 12:33 200 00000000000000000073.index.deleted
-a--- 18.08.2016 12:33 5494169 00000000000000000073.log
-a--- 18.08.2016 12:33 10485760 00000000000000000099.index
-a--- 18.08.2016 12:33 1529831 00000000000000000099.log
{noformat}
Then I fed the same set of messages a third time. As soon as the cleaner
started working thereafter, it bombed out like this:
{noformat}
[2016-08-18 13:10:43,254] ERROR [kafka-log-cleaner-thread-0], Error due to
(kafka.log.LogCleaner)
kafka.common.KafkaStorageException: Failed to change the index file suffix from
to .deleted for log segment 0
at kafka.log.LogSegment.kafkaStorageException$1(LogSegment.scala:263)
at kafka.log.LogSegment.changeFileSuffixes(LogSegment.scala:269)
at kafka.log.Log.kafka$log$Log$$asyncDeleteSegment(Log.scala:832)
at kafka.log.Log$$anonfun$replaceSegments$1.apply(Log.scala:878)
at kafka.log.Log$$anonfun$replaceSegments$1.apply(Log.scala:873)
at scala.collection.immutable.List.foreach(List.scala:318)
at kafka.log.Log.replaceSegments(Log.scala:873)
at kafka.log.Cleaner.cleanSegments(LogCleaner.scala:395)
at kafka.log.Cleaner$$anonfun$clean$4.apply(LogCleaner.scala:343)
at kafka.log.Cleaner$$anonfun$clean$4.apply(LogCleaner.scala:342)
at scala.collection.immutable.List.foreach(List.scala:318)
at kafka.log.Cleaner.clean(LogCleaner.scala:342)
at kafka.log.LogCleaner$CleanerThread.cleanOrSleep(LogCleaner.scala:237)
at kafka.log.LogCleaner$CleanerThread.doWork(LogCleaner.scala:215)
at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:63)
Caused by: java.nio.file.FileAlreadyExistsException:
C:\Users\hk\tmp\kafka-data\hktest-0\00000000000000000000.index ->
C:\Users\hk\tmp\kafka-data\hktest-0\00000000000000000000.index.deleted
at
sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:81)
at
sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97)
at sun.nio.fs.WindowsFileCopy.move(WindowsFileCopy.java:387)
at
sun.nio.fs.WindowsFileSystemProvider.move(WindowsFileSystemProvider.java:287)
at java.nio.file.Files.move(Files.java:1395)
at
org.apache.kafka.common.utils.Utils.atomicMoveWithFallback(Utils.java:670)
at kafka.log.OffsetIndex.renameTo(OffsetIndex.scala:364)
... 14 more
Suppressed: java.nio.file.AccessDeniedException:
C:\Users\hk\tmp\kafka-data\hktest-0\00000000000000000000.index ->
C:\Users\hk\tmp\kafka-data\hktest-0\00000000000000000000.index.deleted
at
sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:83)
at
sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97)
at sun.nio.fs.WindowsFileCopy.move(WindowsFileCopy.java:301)
at
sun.nio.fs.WindowsFileSystemProvider.move(WindowsFileSystemProvider.java:287)
at java.nio.file.Files.move(Files.java:1395)
at
org.apache.kafka.common.utils.Utils.atomicMoveWithFallback(Utils.java:667)
... 15 more
[2016-08-18 13:10:43,254] INFO [kafka-log-cleaner-thread-0], Stopped
(kafka.log.LogCleaner)
{noformat}
Let me know if I can help with further testing.
> 10 LogTest cases failed for file.renameTo failed under windows
> ---------------------------------------------------------------
>
> Key: KAFKA-2170
> URL: https://issues.apache.org/jira/browse/KAFKA-2170
> Project: Kafka
> Issue Type: Bug
> Components: log
> Affects Versions: 0.10.1.0
> Environment: Windows
> Reporter: Honghai Chen
> Assignee: Jay Kreps
>
> get latest code from trunk, then run test
> gradlew -i core:test --tests kafka.log.LogTest
> Got 10 cases failed for same reason:
> kafka.common.KafkaStorageException: Failed to change the log file suffix from
> to .deleted for log segment 0
> at kafka.log.LogSegment.changeFileSuffixes(LogSegment.scala:259)
> at kafka.log.Log.kafka$log$Log$$asyncDeleteSegment(Log.scala:756)
> at kafka.log.Log.kafka$log$Log$$deleteSegment(Log.scala:747)
> at kafka.log.Log$$anonfun$deleteOldSegments$1.apply(Log.scala:514)
> at kafka.log.Log$$anonfun$deleteOldSegments$1.apply(Log.scala:514)
> at scala.collection.immutable.List.foreach(List.scala:318)
> at kafka.log.Log.deleteOldSegments(Log.scala:514)
> at kafka.log.LogTest.testAsyncDelete(LogTest.scala:633)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
> at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:44)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:180)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:41)
> at org.junit.runners.ParentRunner$1.evaluate(ParentRunner.java:173)
> at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:69)
> at
> org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:48)
> at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at
> org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at
> org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at
> org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
> at
> org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
> at $Proxy2.processTestClass(Unknown Source)
> at
> org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:105)
> at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at
> org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at
> org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at
> org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:355)
> at
> org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:722)
>
>
> testCompactedTopicConstraints
> java.io.IOException: The requested operation cannot be performed on a file
> with a user-mapped section open
> at java.io.RandomAccessFile.setLength(Native Method)
> at kafka.log.OffsetIndex$$anonfun$resize$1.apply(OffsetIndex.scala:285)
> at kafka.log.OffsetIndex$$anonfun$resize$1.apply(OffsetIndex.scala:276)
> at kafka.utils.CoreUtils$.inLock(CoreUtils.scala:298)
> at kafka.log.OffsetIndex.resize(OffsetIndex.scala:276)
> at
> kafka.log.OffsetIndex$$anonfun$trimToValidSize$1.apply$mcV$sp(OffsetIndex.scala:265)
> at
> kafka.log.OffsetIndex$$anonfun$trimToValidSize$1.apply(OffsetIndex.scala:265)
> at
> kafka.log.OffsetIndex$$anonfun$trimToValidSize$1.apply(OffsetIndex.scala:265)
> at kafka.utils.CoreUtils$.inLock(CoreUtils.scala:298)
> at kafka.log.OffsetIndex.trimToValidSize(OffsetIndex.scala:264)
> at kafka.log.LogSegment.recover(LogSegment.scala:198)
> at kafka.log.Log.recoverLog(Log.scala:238)
> at kafka.log.Log.loadSegments(Log.scala:210)
> at kafka.log.Log.<init>(Log.scala:83)
> at kafka.log.LogTest.testCompactedTopicConstraints(LogTest.scala:370)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
> at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:44)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:180)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:41)
> at org.junit.runners.ParentRunner$1.evaluate(ParentRunner.java:173)
> at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:69)
> at
> org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:48)
> at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at
> org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at
> org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at
> org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
> at
> org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
> at $Proxy2.processTestClass(Unknown Source)
> at
> org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:105)
> at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at
> org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at
> org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at
> org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:355)
> at
> org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:722)
> LogTest. testAsyncDelete
> LogTest. testCompactedTopicConstraints
> LogTest. testCorruptLog
> LogTest. testIndexRebuild
> LogTest. testIndexResizingAtTruncation
> LogTest. testLogRecoversToCorrectOffset
> LogTest. testOpenDeletesObsoleteFiles
> LogTest. testReopenThenTruncate
> LogTest. testThatGarbageCollectingSegmentsDoesntChangeOffset
> LogTest. testTruncateTo
> Do we need call log.close and then call rename, and then reopen it?
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
