Failing JUnits on Windows #25

mariankassovic · 2017-06-08T09:31:53Z

Running JUnit EphemeralKafkaBrokerTest on Windows is failing:

11:08:19.131 [onPool-worker-1] WARN     k.server.BrokerMetadataCheckpoint - No meta.properties file under dir C:\Users\KASSOV~1.MAR\AppData\Local\Temp\kafka_junit2358289997418960258\meta.properties
11:08:19.764 [onPool-worker-1] WARN     k.server.BrokerMetadataCheckpoint - No meta.properties file under dir C:\Users\KASSOV~1.MAR\AppData\Local\Temp\kafka_junit2358289997418960258\meta.properties
11:08:19.961 [d | kafka-junit] WARN  o.apache.kafka.clients.NetworkClient - Error while fetching metadata with correlation id 1 : {test-topic=LEADER_NOT_AVAILABLE}
11:08:20.096 [d | kafka-junit] WARN  o.apache.kafka.clients.NetworkClient - Error while fetching metadata with correlation id 3 : {test-topic=LEADER_NOT_AVAILABLE}
11:08:23.019 [main           ] ERROR     c.g.c.kafka.EphemeralKafkaBroker - Failed to clean-up Kafka
java.nio.file.FileSystemException: C:\Users\KASSOV~1.MAR\AppData\Local\Temp\kafka_junit2358289997418960258\test-topic-0\00000000000000000000.timeindex: The process cannot access the file because it is being used by another process.
	at sun.nio.fs.WindowsException.translateToIOException(Unknown Source)
	at sun.nio.fs.WindowsException.rethrowAsIOException(Unknown Source)
	at sun.nio.fs.WindowsException.rethrowAsIOException(Unknown Source)
	at sun.nio.fs.WindowsFileSystemProvider.implDelete(Unknown Source)
	at sun.nio.fs.AbstractFileSystemProvider.deleteIfExists(Unknown Source)
	at java.nio.file.Files.deleteIfExists(Unknown Source)
	at com.github.charithe.kafka.EphemeralKafkaBroker$1.visitFile(EphemeralKafkaBroker.java:171)
	at com.github.charithe.kafka.EphemeralKafkaBroker$1.visitFile(EphemeralKafkaBroker.java:1)
	at java.nio.file.Files.walkFileTree(Unknown Source)
	at java.nio.file.Files.walkFileTree(Unknown Source)
	at com.github.charithe.kafka.EphemeralKafkaBroker.stopBroker(EphemeralKafkaBroker.java:168)
	at com.github.charithe.kafka.EphemeralKafkaBroker.stop(EphemeralKafkaBroker.java:147)
	at com.github.charithe.kafka.EphemeralKafkaBrokerTest.testReadAndWrite(EphemeralKafkaBrokerTest.java:112)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:86)
	at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:459)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:678)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:382)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:192)
11:08:23.563 [main           ] ERROR             kafka.server.KafkaServer - Fatal error during KafkaServer shutdown.
java.lang.IllegalStateException: Kafka server is still starting up, cannot shut down!
	at kafka.server.KafkaServer.shutdown(KafkaServer.scala:575)
	at kafka.server.KafkaServerStartable.shutdown(KafkaServerStartable.scala:51)
	at com.github.charithe.kafka.EphemeralKafkaBroker.stopBroker(EphemeralKafkaBroker.java:158)
	at com.github.charithe.kafka.EphemeralKafkaBroker.stop(EphemeralKafkaBroker.java:147)
	at com.github.charithe.kafka.EphemeralKafkaBrokerTest.testStartAndStop(EphemeralKafkaBrokerTest.java:68)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:86)
	at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:459)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:678)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:382)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:192)

There has to be some issue with statitcs since next run ends differenly

11:12:32.587 [onPool-worker-1] WARN     k.server.BrokerMetadataCheckpoint - No meta.properties file under dir C:\Users\KASSOV~1.MAR\AppData\Local\Temp\kafka_junit3765302414122141202\meta.properties
11:12:33.143 [onPool-worker-1] WARN     k.server.BrokerMetadataCheckpoint - No meta.properties file under dir C:\Users\KASSOV~1.MAR\AppData\Local\Temp\kafka_junit3765302414122141202\meta.properties
11:12:33.413 [d | kafka-junit] WARN  o.apache.kafka.clients.NetworkClient - Error while fetching metadata with correlation id 1 : {test-topic=LEADER_NOT_AVAILABLE}
11:12:33.565 [d | kafka-junit] WARN  o.apache.kafka.clients.NetworkClient - Error while fetching metadata with correlation id 3 : {test-topic=LEADER_NOT_AVAILABLE}
11:12:34.751 [onPool-worker-1] WARN     k.server.BrokerMetadataCheckpoint - No meta.properties file under dir C:\Users\KASSOV~1.MAR\AppData\Local\Temp\kafka_junit4699908709488809068\meta.properties
11:12:34.822 [main           ] ERROR             kafka.server.KafkaServer - [Kafka Server 1], Fatal error during KafkaServer shutdown.
java.lang.IllegalStateException: Kafka server is still starting up, cannot shut down!
	at kafka.server.KafkaServer.shutdown(KafkaServer.scala:575)
	at kafka.server.KafkaServerStartable.shutdown(KafkaServerStartable.scala:51)

This might not be obvious on Linux platform. I suppose that there is some resource leak that keeps directory file handle open.

The text was updated successfully, but these errors were encountered:

charithe · 2017-06-08T18:33:42Z

Thanks for reporting the issue. Unfortunately I can't provide support for the Windows platform. If you know how to fix the problem, please send a PR and I'll be happy to accept it.

mariankassovic · 2017-06-09T09:28:08Z

I have only a small improvement - add awaitShutdown() call in EphemeralKafkaBroker method stopBroker before trying to delete Kafka log directory.

  private void stopBroker() {
        try {
            if (kafkaServer != null) {
                LOGGER.info("Shutting down Kafka Server");
                kafkaServer.shutdown();
                kafkaServer.awaitShutdown();
            }

Unfortunately it does not solve the problem completely, since it looks like Kafka does not close topic properly on shutdown :-( Tests run green, but temp folder clean-up is failing...

charithe · 2017-06-09T16:39:27Z

Yes, I remember reading that Windows creates exclusive locks on files whereas Unix-like systems don't. This is probably something to do with that. I'll mark this as up-for-grabs so that someone with knowledge of Windows (and access to a Windows machine) can pick it up and work on it.

eximius313 · 2018-03-22T12:41:07Z

I'm also suffering from this:

2018-03-22 13:36:28.080 ERROR 5828 --- [       Thread-8] org.apache.kafka.test.TestUtils          : Error deleting C:\Users\X\AppData\Local\Temp\kafka-5223924343707963804

java.nio.file.FileSystemException: C:\Users\X\AppData\Local\Temp\kafka-5223924343707963804\version-2\log.1: The process cannot access the file because it is being used by another process.

	at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:86) ~[na:1.8.0_144]
	at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97) ~[na:1.8.0_144]
	at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:102) ~[na:1.8.0_144]
	at sun.nio.fs.WindowsFileSystemProvider.implDelete(WindowsFileSystemProvider.java:269) ~[na:1.8.0_144]
	at sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103) ~[na:1.8.0_144]
	at java.nio.file.Files.delete(Files.java:1126) ~[na:1.8.0_144]
	at org.apache.kafka.common.utils.Utils$1.visitFile(Utils.java:630) ~[kafka-clients-1.0.1.jar:na]
	at org.apache.kafka.common.utils.Utils$1.visitFile(Utils.java:619) ~[kafka-clients-1.0.1.jar:na]
	at java.nio.file.Files.walkFileTree(Files.java:2670) ~[na:1.8.0_144]
	at java.nio.file.Files.walkFileTree(Files.java:2742) ~[na:1.8.0_144]
	at org.apache.kafka.common.utils.Utils.delete(Utils.java:619) ~[kafka-clients-1.0.1.jar:na]
	at org.apache.kafka.test.TestUtils$1.run(TestUtils.java:184) ~[kafka-clients-1.0.1-test.jar:na]

2018-03-22 13:36:28.091 ERROR 5828 --- [      Thread-11] org.apache.kafka.test.TestUtils          : Error deleting C:\Users\X\AppData\Local\Temp\kafka-5049848438722543295

java.nio.file.FileSystemException: C:\Users\X\AppData\Local\Temp\kafka-5049848438722543295\version-2\log.1: The process cannot access the file because it is being used by another process.

	at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:86) ~[na:1.8.0_144]
	at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97) ~[na:1.8.0_144]
	at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:102) ~[na:1.8.0_144]
	at sun.nio.fs.WindowsFileSystemProvider.implDelete(WindowsFileSystemProvider.java:269) ~[na:1.8.0_144]
	at sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103) ~[na:1.8.0_144]
	at java.nio.file.Files.delete(Files.java:1126) ~[na:1.8.0_144]
	at org.apache.kafka.common.utils.Utils$1.visitFile(Utils.java:630) ~[kafka-clients-1.0.1.jar:na]
	at org.apache.kafka.common.utils.Utils$1.visitFile(Utils.java:619) ~[kafka-clients-1.0.1.jar:na]
	at java.nio.file.Files.walkFileTree(Files.java:2670) ~[na:1.8.0_144]
	at java.nio.file.Files.walkFileTree(Files.java:2742) ~[na:1.8.0_144]
	at org.apache.kafka.common.utils.Utils.delete(Utils.java:619) ~[kafka-clients-1.0.1.jar:na]
	at org.apache.kafka.test.TestUtils$1.run(TestUtils.java:184) ~[kafka-clients-1.0.1-test.jar:na]

carlislefox · 2018-04-03T15:01:03Z

Also experiencing this issue

2018-04-03 15:56:25.652 ERROR 4816 --- [ Thread-4] org.apache.kafka.test.TestUtils : Error deleting C:\Users\stewalia\AppData\Local\Temp\kafka-7101259950782722212

java.nio.file.FileSystemException: C:\Users\stewalia\AppData\Local\Temp\kafka-7101259950782722212\product-0\00000000000000000000.index: The process cannot access the file because it is being used by another process.

    at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:86)
    at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97)
    at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:102)
    at sun.nio.fs.WindowsFileSystemProvider.implDelete(WindowsFileSystemProvider.java:269)
    at sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103)
    at java.nio.file.Files.delete(Files.java:1126)
    at org.apache.kafka.common.utils.Utils$2.visitFile(Utils.java:591)
    at org.apache.kafka.common.utils.Utils$2.visitFile(Utils.java:580)
    at java.nio.file.Files.walkFileTree(Files.java:2670)
    at java.nio.file.Files.walkFileTree(Files.java:2742)
    at org.apache.kafka.common.utils.Utils.delete(Utils.java:580)
    at org.apache.kafka.test.TestUtils$1.run(TestUtils.java:182)

cyriljoui · 2018-04-11T08:51:48Z

Hi

We were facing the same issue.
However it is a no blocking issue (in our case), the real issue may when we use Helper.produceStrings

in this.produce() ... it should be better to call .get() to be sure that message was really produced (sync)

public <K, V> void produce(String topic, KafkaProducer<K, V> producer, Map<K, V> data) {
    data.forEach((k, v) -> {
        producer.send(new ProducerRecord(topic, k, v));
    });
    producer.flush();
}

    protected <K, V> void produce(String topic, KafkaProducer<K, V> producer, Map<K, V> data) {
        data.forEach((k, v) -> {
            try {
                producer.send(new ProducerRecord(topic, k, v)).get();
            } catch (InterruptedException e) {
               throw new RuntimeException(e);
            } catch (ExecutionException e) {
                throw new RuntimeException(e);
            }
        });
        producer.flush();
    }

Could you please give more details about how do you implement your tests? which methods, classes do you use to consume / produce messages?

silaev · 2019-06-14T13:08:25Z

faced the same issue, as a workaround added the following to a Gradle clean task:

import org.apache.tools.ant.taskdefs.condition.Os

clean {
    if (Os.isFamily(Os.FAMILY_WINDOWS)) {
        def tempDir = System.getProperties().getProperty("java.io.tmpdir")
        def ft = fileTree(tempDir) {
            include 'kafka-*'
            exclude 'kafka-logs'
        }
        ft.visit {
            FileVisitDetails fvd ->
                println "deleted kafka temp folder: " + tempDir + fvd.name
                delete fvd.file
        }
    }
}

mjiderhamn · 2022-01-27T15:46:55Z

This problem prevents me from upgrading as well. My error message is slightly different however

ERROR kafka.server.BrokerMetadataCheckpoint - Failed to write meta.properties due to
java.nio.file.AccessDeniedException: C:\Users\Maji\AppData\Local\Temp\kafka_junit16787608145441309316

mjiderhamn · 2022-01-27T15:58:43Z

At least in my case, the issue seems to be with Kafka itself https://issues.apache.org/jira/browse/KAFKA-13390 = apache/kafka#11426

charithe added the help wanted label Jun 9, 2017

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Failing JUnits on Windows #25

Failing JUnits on Windows #25

mariankassovic commented Jun 8, 2017 •

edited

charithe commented Jun 8, 2017

mariankassovic commented Jun 9, 2017

charithe commented Jun 9, 2017

eximius313 commented Mar 22, 2018

carlislefox commented Apr 3, 2018

cyriljoui commented Apr 11, 2018

silaev commented Jun 14, 2019 •

edited

mjiderhamn commented Jan 27, 2022

mjiderhamn commented Jan 27, 2022

Failing JUnits on Windows #25

Failing JUnits on Windows #25

Comments

mariankassovic commented Jun 8, 2017 • edited

charithe commented Jun 8, 2017

mariankassovic commented Jun 9, 2017

charithe commented Jun 9, 2017

eximius313 commented Mar 22, 2018

carlislefox commented Apr 3, 2018

cyriljoui commented Apr 11, 2018

silaev commented Jun 14, 2019 • edited

mjiderhamn commented Jan 27, 2022

mjiderhamn commented Jan 27, 2022

mariankassovic commented Jun 8, 2017 •

edited

silaev commented Jun 14, 2019 •

edited