You are viewing a plain text version of this content. The canonical link for it is here.
Posted to jira@kafka.apache.org by "Maksim Zinal (Jira)" <ji...@apache.org> on 2022/01/17 14:00:00 UTC
[jira] [Comment Edited] (KAFKA-2170) 10 LogTest cases failed for file.renameTo failed under windows
[ https://issues.apache.org/jira/browse/KAFKA-2170?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17477226#comment-17477226 ]
Maksim Zinal edited comment on KAFKA-2170 at 1/17/22, 1:59 PM:
---------------------------------------------------------------
I've created a quick patch which seems to fix the issue on my system and on the Kafka version I use (2.8.0).
I believe that the reason of lock failures is the use of RandomAccessFile Java API to open the files in some cases, while in other cases FileChannel.open() is used instead. When opening files with RandomAccessFile under Windows, FILE_SHARE_DELETE flag is not set, which leads to "access denied" errors when trying to rename or delete the open files. FileChannel.open() sets the FILE_SHARE_DELETE by default, as I checked on JDK 8 and 11.
Here's the link to the branch based on tag 2.8.0: [https://github.com/zinal/kafka/tree/2.8.0_KAFKA-1194|[https://github.com/zinal/kafka/tree/2.8.0_KAFKA-1194].]
Here are the exact changes implemented: [https://github.com/zinal/kafka/compare/2.8.0...zinal:2.8.0_KAFKA-1194] (plus jcenter and grgit stuff needed to run the build).
was (Author: JIRAUSER283716):
I've created a quick patch which seems to fix the issue on my system and on the Kafka version I use (2.8.0).
I believe that the reason of lock failures are related to using RandomAccessFile Java API to open the files in some cases, while in other cases FileChannel.open() is used instead. When opening files with RandomAccessFile under Windows, FILE_SHARE_DELETE flag is not set, which leads to "access denied" errors when trying to rename or delete the open files. FileChannel.open() sets the FILE_SHARE_DELETE by default, as I checked on JDK 8 and 11.
Here's the link to the branch based on tag 2.8.0: [https://github.com/zinal/kafka/tree/2.8.0_KAFKA-1194|[https://github.com/zinal/kafka/tree/2.8.0_KAFKA-1194].]
Here are the exact changes implemented: [https://github.com/zinal/kafka/compare/2.8.0...zinal:2.8.0_KAFKA-1194] (plus jcenter and grgit stuff needed to run the build).
> 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
> Priority: Major
> Labels: windows
>
> 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
(v8.20.1#820001)