Since upgrading to Spring Boot 2.6.X (in my case: 2.6.1), I have multiple projects that now have failing unit-tests on Windows that cannot start EmbeddedKafka, that do run with Linux
There is multiple errors, but this is the first one thrown
...
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.6.1)
2021-12-09 16:15:00.300 INFO 13864 --- [ main] k.utils.Log4jControllerRegistration$ : Registered kafka:type=kafka.Log4jController MBean
2021-12-09 16:15:00.420 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer :
2021-12-09 16:15:00.420 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer : ______ _
2021-12-09 16:15:00.420 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer : |___ / | |
2021-12-09 16:15:00.420 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer : / / ___ ___ | | __ ___ ___ _ __ ___ _ __
2021-12-09 16:15:00.420 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer : / / / _ \ / _ \ | |/ / / _ \ / _ \ | '_ \ / _ \ | '__|
2021-12-09 16:15:00.420 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer : / /__ | (_) | | (_) | | < | __/ | __/ | |_) | | __/ | |
2021-12-09 16:15:00.420 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer : /_____| \___/ \___/ |_|\_\ \___| \___| | .__/ \___| |_|
2021-12-09 16:15:00.420 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer : | |
2021-12-09 16:15:00.420 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer : |_|
2021-12-09 16:15:00.420 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer :
2021-12-09 16:15:00.422 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer : Server environment:zookeeper.version=3.6.3--6401e4ad2087061bc6b9f80dec2d69f2e3c8660a, built on 04/08/2021 16:35 GMT
2021-12-09 16:15:00.422 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer : Server environment:host.name=host.docker.internal
2021-12-09 16:15:00.422 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer : Server environment:java.version=11.0.11
2021-12-09 16:15:00.422 INFO 13864 --- [ main] o.a.zookeeper.server.ZooKeeperServer : Server environment:java.vendor=AdoptOpenJDK
...
2021-12-09 16:15:01.015 INFO 13864 --- [nelReaper-Fetch] lientQuotaManager$ThrottledChannelReaper : [ThrottledChannelReaper-Fetch]: Starting
2021-12-09 16:15:01.015 INFO 13864 --- [lReaper-Produce] lientQuotaManager$ThrottledChannelReaper : [ThrottledChannelReaper-Produce]: Starting
2021-12-09 16:15:01.016 INFO 13864 --- [lReaper-Request] lientQuotaManager$ThrottledChannelReaper : [ThrottledChannelReaper-Request]: Starting
2021-12-09 16:15:01.017 INFO 13864 --- [trollerMutation] lientQuotaManager$ThrottledChannelReaper : [ThrottledChannelReaper-ControllerMutation]: Starting
2021-12-09 16:15:01.037 INFO 13864 --- [ main] kafka.log.LogManager : Loading logs from log dirs ArraySeq(C:\Users\ddrop\AppData\Local\Temp\spring.kafka.bf8e2b62-a1f2-4092-b292-a15e35bd31ad18378079390566696446)
2021-12-09 16:15:01.040 INFO 13864 --- [ main] kafka.log.LogManager : Attempting recovery for all logs in C:\Users\ddrop\AppData\Local\Temp\spring.kafka.bf8e2b62-a1f2-4092-b292-a15e35bd31ad18378079390566696446 since no clean shutdown file was found
2021-12-09 16:15:01.043 INFO 13864 --- [ main] kafka.log.LogManager : Loaded 0 logs in 6ms.
2021-12-09 16:15:01.043 INFO 13864 --- [ main] kafka.log.LogManager : Starting log cleanup with a period of 300000 ms.
2021-12-09 16:15:01.045 INFO 13864 --- [ main] kafka.log.LogManager : Starting log flusher with a default period of 9223372036854775807 ms.
2021-12-09 16:15:01.052 INFO 13864 --- [ main] kafka.log.LogCleaner : Starting the log cleaner
2021-12-09 16:15:01.059 INFO 13864 --- [leaner-thread-0] kafka.log.LogCleaner : [kafka-log-cleaner-thread-0]: Starting
2021-12-09 16:15:01.224 INFO 13864 --- [name=forwarding] k.s.BrokerToControllerRequestThread : [BrokerToControllerChannelManager broker=0 name=forwarding]: Starting
2021-12-09 16:15:01.325 INFO 13864 --- [ main] kafka.network.ConnectionQuotas : Updated connection-accept-rate max connection creation rate to 2147483647
2021-12-09 16:15:01.327 INFO 13864 --- [ main] kafka.network.Acceptor : Awaiting socket connections on localhost:63919.
2021-12-09 16:15:01.345 INFO 13864 --- [ main] kafka.network.SocketServer : [SocketServer listenerType=ZK_BROKER, nodeId=0] Created data-plane acceptor and processors for endpoint : ListenerName(PLAINTEXT)
2021-12-09 16:15:01.350 INFO 13864 --- [0 name=alterIsr] k.s.BrokerToControllerRequestThread : [BrokerToControllerChannelManager broker=0 name=alterIsr]: Starting
2021-12-09 16:15:01.364 INFO 13864 --- [eaper-0-Produce] perationPurgatory$ExpiredOperationReaper : [ExpirationReaper-0-Produce]: Starting
2021-12-09 16:15:01.364 INFO 13864 --- [nReaper-0-Fetch] perationPurgatory$ExpiredOperationReaper : [ExpirationReaper-0-Fetch]: Starting
2021-12-09 16:15:01.365 INFO 13864 --- [0-DeleteRecords] perationPurgatory$ExpiredOperationReaper : [ExpirationReaper-0-DeleteRecords]: Starting
2021-12-09 16:15:01.365 INFO 13864 --- [r-0-ElectLeader] perationPurgatory$ExpiredOperationReaper : [ExpirationReaper-0-ElectLeader]: Starting
2021-12-09 16:15:01.374 INFO 13864 --- [rFailureHandler] k.s.ReplicaManager$LogDirFailureHandler : [LogDirFailureHandler]: Starting
2021-12-09 16:15:01.390 INFO 13864 --- [ main] kafka.zk.KafkaZkClient : Creating /brokers/ids/0 (is it secure? false)
2021-12-09 16:15:01.400 INFO 13864 --- [ main] kafka.zk.KafkaZkClient : Stat of the created znode at /brokers/ids/0 is: 25,25,1639062901396,1639062901396,1,0,0,72059919267528704,204,0,25
2021-12-09 16:15:01.400 INFO 13864 --- [ main] kafka.zk.KafkaZkClient : Registered broker 0 at path /brokers/ids/0 with addresses: PLAINTEXT://localhost:63919, czxid (broker epoch): 25
2021-12-09 16:15:01.410 ERROR 13864 --- [ main] kafka.server.BrokerMetadataCheckpoint : Failed to write meta.properties due to
java.nio.file.AccessDeniedException: C:\Users\ddrop\AppData\Local\Temp\spring.kafka.bf8e2b62-a1f2-4092-b292-a15e35bd31ad18378079390566696446
at java.base/sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:89) ~[na:na]
at java.base/sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:103) ~[na:na]
at java.base/sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:108) ~[na:na]
Reproduceable via spring Initializr + adding "Spring Kafka": https://start.spring.io/#!type=maven-project&language=java&platformVersion=2.6.1&packaging=jar&jvmVersion=11&groupId=com.example&artifactId=demo&name=demo&description=Demo%20project%20for%20Spring%20Boot&packageName=com.example.demo&dependencies=kafka
And then have following test-class to execute:
package com.example.demo;
import org.junit.jupiter.api.Test;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.kafka.test.context.EmbeddedKafka;
@SpringBootTest
@EmbeddedKafka
class ApplicationTest {
@Test
void run() {
int i = 1 + 1; // just a line of code to set a debug-point
}
}
I do not have this error when pinning kafka.version to 2.8.1 in pom.xml’s properties.
It seems like the cause is in Kafka itself, but I have a hard time figuring out if it is spring-kafka intitializing Kafka via EmbeddedKafka incorrectly or if Kafka itself is the culrit here.
Anyone has an idea? Am I missing a test-parameter to set?
>Solution :
Known bug on the Apache Kafka side. Nothing to do from Spring perspective.
See more info here: https://github.com/spring-projects/spring-kafka/discussions/2027.
And here: https://issues.apache.org/jira/browse/KAFKA-13391
You need to wait until Apache Kafka 3.0.1 or don’t use embedded Kafka and just rely on the Testcontainers, for example, or fully external Apache Kafka broker.