micronaut-projects / micronaut-kafka

Integration between Micronaut and Apache Kafka
Apache License 2.0
85 stars 106 forks source link

Corrupted message in Kafka using Java 11 with native #152

Closed ivangfr closed 4 years ago

ivangfr commented 4 years ago

Task List

Actual Behaviour

Hi, I've migrated my graalvm-quarkus-micronaut-springboot to Java 11. All seems to work fine except for the Micronaut Producer-Consumer example.

Before, both Producer and Consumer were using Java version 1.8 (in build.gradle) and oracle/graalvm-ce:20.0.0-java8 as base image for the native images. This configuration was working fine.

Then, I updated Producer and Consumer to Java version 11 and oracle/graalvm-ce:20.0.0-java11 as base image. I am able to build the application's native docker images but, at runtime, I have the errors below. It seems that the messages are been corrupted somehow.

Logs

Expected Behaviour

The message should be produced and consumed correctly as done using Java 8

Steps to Reproduce

Environment Information

Example Application

graemerocher commented 4 years ago

Thanks we will investigate

gradinac commented 4 years ago

I have managed to reproduce the issue locally. I've tweaked the NewsClient to send in batch mode - this resulted in the messages getting stored on the topic but it would complain about a bad CRC during retrieval. @graemerocher Could this be related to the following substitution: https://github.com/micronaut-projects/micronaut-kafka/blob/47aaeb59a22059393f553d908586f640ba2ca9e6/kafka/src/main/java/io/micronaut/configuration/kafka/graal/KafkaSubstitutions.java#L41 From what I've seen, this will only get triggered when using Java 9+, which would explain why it works on 8 and not on 11. It expects to get a CRC32C implementation, but this would supply CRC32.

graemerocher commented 4 years ago

@gradinac thanks for looking into it, it does seems to be the case let me try push a patch and hopefully @ivangfr can provide feedback on the snapshot

graemerocher commented 4 years ago

@gradinac what do you think about this approach? https://github.com/micronaut-projects/micronaut-kafka/pull/153

gradinac commented 4 years ago

@graemerocher No problem at all! Hopefully it will solve the issue. If not, I'll dig a bit further. As for #153 I think this would be the proper approach to fixing it.

ivangfr commented 4 years ago

Sure @graemerocher I will try it using the snapshot and I let you guys know.

graemerocher commented 4 years ago

Wait a bit the snapshot is not published yet

graemerocher commented 4 years ago

Ok the snapshot is published

graemerocher commented 4 years ago

@ivangfr were you able to verify the issue is resolved with the snapshot?

ivangfr commented 4 years ago

@graemerocher I am having a problem to build the native image

cd producer-api && ./docker-build.sh native && cd ..
Sending build context to Docker daemon  26.78MB
Step 1/10 : FROM oracle/graalvm-ce:20.0.0-java11 as graalvm
 ---> 364d0bb387bd
Step 2/10 : RUN gu install native-image
 ---> Running in bed8a465e0c3
Downloading: Component catalog from www.graalvm.org
Processing Component: Native Image
Downloading: Component native-image: Native Image  from github.com
Installing new component: Native Image (org.graalvm.native-image, version 20.0.0)
Refreshed alternative links in /usr/bin/
Removing intermediate container bed8a465e0c3
 ---> 429860ef0443
Step 3/10 : COPY build/libs/producer-api-*-all.jar /home/app/producer-api/build/libs/producer-api.jar
 ---> 79a1d3e9b26e
Step 4/10 : WORKDIR /home/app/producer-api
 ---> Running in f3e7a846c390
Removing intermediate container f3e7a846c390
 ---> d90789be648a
Step 5/10 : RUN native-image --no-server -cp build/libs/producer-api.jar
 ---> Running in cfc7b062d1a2
[producer-api:28]    classlist:  33,370.09 ms,  1.20 GB
[producer-api:28]        (cap):   9,058.38 ms,  1.20 GB
WARNING: Could not resolve io.netty.channel.epoll.EpollChannelOption for reflection configuration.
WARNING: Could not resolve io.netty.channel.kqueue.KQueueChannelOption for reflection configuration.
[producer-api:28]        setup:  27,921.67 ms,  1.20 GB
Warning: class initialization of class io.micronaut.http.bind.binders.ContinuationArgumentBinder$Companion failed with exception java.lang.NoClassDefFoundError: kotlin/TypeCastException. This class will be initialized at run time because option --allow-incomplete-classpath is used for image building. Use the option --initialize-at-run-time=io.micronaut.http.bind.binders.ContinuationArgumentBinder$Companion to explicitly request delayed initialization of this class.
[producer-api:28]   (typeflow): 397,826.93 ms,  6.22 GB
[producer-api:28]    (objects): 134,681.33 ms,  6.22 GB
[producer-api:28]   (features):  22,714.30 ms,  6.22 GB
[producer-api:28]     analysis: 573,373.93 ms,  6.22 GB
[producer-api:28]     (clinit):   3,160.25 ms,  6.22 GB
[producer-api:28]     universe:  14,572.85 ms,  6.22 GB
[producer-api:28]      (parse):  36,707.21 ms,  6.22 GB
[producer-api:28]     (inline):  20,949.72 ms,  6.22 GB
[producer-api:28]    (compile): 246,946.48 ms,  6.22 GB
[producer-api:28]      compile: 312,422.13 ms,  6.22 GB
[producer-api:28]        image:  19,407.59 ms,  6.22 GB
Error: Image build request failed with exit status 137
The command '/bin/sh -c native-image --no-server -cp build/libs/producer-api.jar' returned a non-zero code: 137
16 minutes and 43 seconds elapsed.

That is the producer-api...

I have in build.gradle

...
dependencies {
   ...
   implementation("io.micronaut.kafka:micronaut-kafka:SNAPSHOT")
   ...
}
...
java {
    sourceCompatibility = JavaVersion.toVersion('11')
    targetCompatibility = JavaVersion.toVersion('11')
}

In Dockerfile.native

#FROM oracle/graalvm-ce:20.0.0-java8 as graalvm
# For JDK 11
FROM oracle/graalvm-ce:20.0.0-java11 as graalvm
graemerocher commented 4 years ago

exit status exit status 137 indicates out of memory error. You need to allocate more memory to your Docker install

graemerocher commented 4 years ago

Note you will need a reference to the Kafka snapshot:

implementation("io.micronaut.kafka:micronaut-kafka:2.1.0.BUILD-SNAPSHOT")

And make sure you change enforcedPlatform to platform for the micronaut-bom

ivangfr commented 4 years ago

Thanks @graemerocher . I fixed the wrong reference version to micronaut-kafka that I had and gave 16GB (instead of 8GB) to docker.

I've just compiled the producer-api. This time, the compilation finished successfully. It also starts ok.

However, once the 1st request comes, it's throwing the following exception

» docker run --rm --name micronaut-producer-api-native \
        -p 9103:8080 -e KAFKA_HOST=kafka -e ZIPKIN_HOST=zipkin \
        --network producer-consumer_default \
        docker.mycompany.com/micronaut-producer-api-native:1.0.0
./producer-api: /usr/lib/libstdc++.so.6: no version information available (required by ./producer-api)
12:52:20.454 [main] INFO  io.micronaut.runtime.Micronaut - Startup completed in 146ms. Server Running: http://2a6f74f8e1a2:8080
12:52:42.294 [nioEventLoopGroup-1-2] INFO  c.m.producerapi.rest.NewsController - Sending News message: id=d09505e6-362a-46ae-b5f4-5297a1629664, News(id=d09505e6-362a-46ae-b5f4-5297a1629664, source=Micronaut Blog, title=Micronaut Framework & GraalVM)
12:52:42.300 [nioEventLoopGroup-1-2] INFO  o.a.k.c.producer.ProducerConfig - ProducerConfig values:
    acks = 1
    batch.size = 16384
    bootstrap.servers = [kafka:9092]
    buffer.memory = 33554432
    client.dns.lookup = default
    client.id = producer-1
    compression.type = none
    connections.max.idle.ms = 540000
    delivery.timeout.ms = 120000
    enable.idempotence = false
    interceptor.classes = []
    key.serializer = class org.apache.kafka.common.serialization.StringSerializer
    linger.ms = 0
    max.block.ms = 60000
    max.in.flight.requests.per.connection = 5
    max.request.size = 1048576
    metadata.max.age.ms = 300000
    metadata.max.idle.ms = 300000
    metric.reporters = [io.micronaut.configuration.kafka.metrics.ProducerKafkaMetricsReporter]
    metrics.num.samples = 2
    metrics.recording.level = INFO
    metrics.sample.window.ms = 30000
    partitioner.class = class org.apache.kafka.clients.producer.internals.DefaultPartitioner
    receive.buffer.bytes = 32768
    reconnect.backoff.max.ms = 1000
    reconnect.backoff.ms = 50
    request.timeout.ms = 30000
    retries = 2147483647
    retry.backoff.ms = 100
    sasl.client.callback.handler.class = null
    sasl.jaas.config = null
    sasl.kerberos.kinit.cmd = /usr/bin/kinit
    sasl.kerberos.min.time.before.relogin = 60000
    sasl.kerberos.service.name = null
    sasl.kerberos.ticket.renew.jitter = 0.05
    sasl.kerberos.ticket.renew.window.factor = 0.8
    sasl.login.callback.handler.class = null
    sasl.login.class = null
    sasl.login.refresh.buffer.seconds = 300
    sasl.login.refresh.min.period.seconds = 60
    sasl.login.refresh.window.factor = 0.8
    sasl.login.refresh.window.jitter = 0.05
    sasl.mechanism = GSSAPI
    security.protocol = PLAINTEXT
    security.providers = null
    send.buffer.bytes = 131072
    ssl.cipher.suites = null
    ssl.enabled.protocols = [TLSv1.2]
    ssl.endpoint.identification.algorithm = https
    ssl.key.password = null
    ssl.keymanager.algorithm = SunX509
    ssl.keystore.location = null
    ssl.keystore.password = null
    ssl.keystore.type = JKS
    ssl.protocol = TLSv1.2
    ssl.provider = null
    ssl.secure.random.implementation = null
    ssl.trustmanager.algorithm = PKIX
    ssl.truststore.location = null
    ssl.truststore.password = null
    ssl.truststore.type = JKS
    transaction.timeout.ms = 60000
    transactional.id = null
    value.serializer = class io.micronaut.configuration.kafka.serde.JsonSerde

12:52:42.486 [kafka-producer-network-thread | producer-1] WARN  o.apache.kafka.clients.NetworkClient - [Producer clientId=producer-1] Error while fetching metadata with correlation id 1 : {micronaut.news.json=LEADER_NOT_AVAILABLE}
12:52:42.486 [kafka-producer-network-thread | producer-1] INFO  org.apache.kafka.clients.Metadata - [Producer clientId=producer-1] Cluster ID: Fn1_wLG2Qq6E1EBQX2d2Xg
12:52:42.622 [kafka-producer-network-thread | producer-1] WARN  o.apache.kafka.clients.NetworkClient - [Producer clientId=producer-1] Error while fetching metadata with correlation id 3 : {micronaut.news.json=LEADER_NOT_AVAILABLE}
12:52:42.728 [kafka-producer-network-thread | producer-1] ERROR o.a.k.c.producer.internals.Sender - [Producer clientId=producer-1] Uncaught error in kafka producer I/O thread:
io.micronaut.core.reflect.exception.InstantiationException: Could not instantiate type [java.util.zip.CRC32C]: No class found for name: java.util.zip.CRC32C
    at io.micronaut.core.reflect.InstantiationUtils.instantiate(InstantiationUtils.java:236)
    at org.apache.kafka.common.utils.Crc32C$Java9ChecksumFactory.create(KafkaSubstitutions.java:52)
    at org.apache.kafka.common.utils.Crc32C.create(Crc32C.java:77)
    at org.apache.kafka.common.utils.Crc32C.compute(Crc32C.java:71)
    at org.apache.kafka.common.record.DefaultRecordBatch.writeHeader(DefaultRecordBatch.java:479)
    at org.apache.kafka.common.record.MemoryRecordsBuilder.writeDefaultBatchHeader(MemoryRecordsBuilder.java:366)
    at org.apache.kafka.common.record.MemoryRecordsBuilder.close(MemoryRecordsBuilder.java:320)
    at org.apache.kafka.clients.producer.internals.ProducerBatch.close(ProducerBatch.java:407)
    at org.apache.kafka.clients.producer.internals.RecordAccumulator.drainBatchesForOneNode(RecordAccumulator.java:619)
    at org.apache.kafka.clients.producer.internals.RecordAccumulator.drain(RecordAccumulator.java:646)
    at org.apache.kafka.clients.producer.internals.Sender.sendProducerData(Sender.java:357)
    at org.apache.kafka.clients.producer.internals.Sender.runOnce(Sender.java:323)
    at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:239)
    at java.lang.Thread.run(Thread.java:834)
    at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:527)
    at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
Caused by: io.micronaut.core.reflect.exception.InstantiationException: No class found for name: java.util.zip.CRC32C
    at io.micronaut.core.reflect.InstantiationUtils.lambda$instantiate$8(InstantiationUtils.java:234)
    at java.util.Optional.orElseThrow(Optional.java:408)
    at io.micronaut.core.reflect.InstantiationUtils.instantiate(InstantiationUtils.java:234)
    ... 15 common frames omitted
graemerocher commented 4 years ago

Ok interesting. Can probably be worked around by adding @TypeHint(java.util.zip.CRC32C.class)

I wonder why https://github.com/micronaut-projects/micronaut-kafka/blob/master/kafka/src/main/java/io/micronaut/configuration/kafka/graal/KafkaSubstitutions.java#L40 is not working

Stand by let me try a few things

graemerocher commented 4 years ago

@ivangfr I went through the steps to reproduce the issue with your sample and https://github.com/micronaut-projects/micronaut-kafka/commit/014b1f86b05c0a72ad707b7cd37b79cf936e6f93 seems to fix it

I had to apply the following patch to get it working in your example (which assumes using mavenLocal() otherwise you will need to add the snapshot repo):

Subject: [PATCH] Use micronaut 2.0 rc1 and kafka snapshot

---
 .../consumer-api/build.gradle                 | 25 ++++++++++++-------
 .../src/main/docker/Dockerfile.native         |  4 +--
 .../producer-api/build.gradle                 | 25 ++++++++++++-------
 .../src/main/docker/Dockerfile.native         |  4 +--
 4 files changed, 36 insertions(+), 22 deletions(-)

diff --git a/producer-consumer/micronaut-producer-consumer/consumer-api/build.gradle b/producer-consumer/micronaut-producer-consumer/consumer-api/build.gradle
index afbf4a9..5358f2d 100644
--- a/producer-consumer/micronaut-producer-consumer/consumer-api/build.gradle
+++ b/producer-consumer/micronaut-producer-consumer/consumer-api/build.gradle
@@ -10,6 +10,7 @@ group "com.mycompany.consumerapi"

 repositories {
     jcenter()
+    mavenLocal()
 }

 configurations {
@@ -18,11 +19,17 @@ configurations {
 }

 ext {
-    set('micronautVersion', '2.0.0.M3')
+    set('micronautVersion', '2.0.0.RC1')
     set('lombokVersion', '1.18.12')
     set('logbackVersion', '1.2.3')
 }

+configurations.all {
+    resolutionStrategy {
+        force "io.micronaut.kafka:micronaut-kafka:2.1.0.BUILD-SNAPSHOT"
+    }
+}
+
 dependencies {
     //-- IMPORTANT!
     //  Lombok annotation processor must place before the Micronaut processors in the build configuration
@@ -30,31 +37,31 @@ dependencies {
     compileOnly("org.projectlombok:lombok:$lombokVersion")
     annotationProcessor("org.projectlombok:lombok:$lombokVersion")
     //--
-    annotationProcessor(enforcedPlatform("io.micronaut:micronaut-bom:$micronautVersion"))
+    annotationProcessor(platform("io.micronaut:micronaut-bom:$micronautVersion"))
     annotationProcessor("io.micronaut:micronaut-inject-java")
     annotationProcessor("io.micronaut:micronaut-validation")
     annotationProcessor("io.micronaut:micronaut-graal")
-    compileOnly(enforcedPlatform("io.micronaut:micronaut-bom:$micronautVersion"))
+    compileOnly(platform("io.micronaut:micronaut-bom:$micronautVersion"))
     compileOnly("org.graalvm.nativeimage:svm")
-    implementation(enforcedPlatform("io.micronaut:micronaut-bom:$micronautVersion"))
+    implementation(platform("io.micronaut:micronaut-bom:$micronautVersion"))
     implementation("io.micronaut:micronaut-management")
-    implementation("io.micronaut.configuration:micronaut-micrometer-core")
+    implementation("io.micronaut.micrometer:micronaut-micrometer-core")
     implementation("io.opentracing.brave:brave-opentracing")
     implementation("io.micronaut:micronaut-tracing")
-    implementation("io.micronaut.configuration:micronaut-micrometer-registry-prometheus")
+    implementation("io.micronaut.micrometer:micronaut-micrometer-registry-prometheus")
     implementation("io.micronaut:micronaut-inject")
     implementation("io.micronaut:micronaut-validation")
     implementation("io.micronaut:micronaut-runtime")
     implementation("io.micronaut:micronaut-http-server-netty")
     implementation("io.micronaut:micronaut-http-client")
-    implementation("io.micronaut.kafka:micronaut-kafka")
+    implementation("io.micronaut.kafka:micronaut-kafka:2.1.0.BUILD-SNAPSHOT")
     implementation("io.micronaut.cache:micronaut-cache-caffeine")
     runtimeOnly("io.zipkin.brave:brave-instrumentation-http")
     runtimeOnly("io.zipkin.reporter2:zipkin-reporter")
     runtimeOnly("ch.qos.logback:logback-classic:$logbackVersion")
-    testAnnotationProcessor(enforcedPlatform("io.micronaut:micronaut-bom:$micronautVersion"))
+    testAnnotationProcessor(platform("io.micronaut:micronaut-bom:$micronautVersion"))
     testAnnotationProcessor("io.micronaut:micronaut-inject-java")
-    testImplementation(enforcedPlatform("io.micronaut:micronaut-bom:$micronautVersion"))
+    testImplementation(platform("io.micronaut:micronaut-bom:$micronautVersion"))
     testImplementation("org.junit.jupiter:junit-jupiter-api")
     testImplementation("io.micronaut.test:micronaut-test-junit5")
     testRuntimeOnly("org.junit.jupiter:junit-jupiter-engine")
diff --git a/producer-consumer/micronaut-producer-consumer/consumer-api/src/main/docker/Dockerfile.native b/producer-consumer/micronaut-producer-consumer/consumer-api/src/main/docker/Dockerfile.native
index 08c605b..83bb4d9 100644
--- a/producer-consumer/micronaut-producer-consumer/consumer-api/src/main/docker/Dockerfile.native
+++ b/producer-consumer/micronaut-producer-consumer/consumer-api/src/main/docker/Dockerfile.native
@@ -1,6 +1,6 @@
-FROM oracle/graalvm-ce:20.0.0-java8 as graalvm
+#FROM oracle/graalvm-ce:20.0.0-java8 as graalvm
 # For JDK 11
-#FROM oracle/graalvm-ce:20.0.0-java11 as graalvm
+FROM oracle/graalvm-ce:20.0.0-java11 as graalvm
 RUN gu install native-image

 COPY build/libs/consumer-api-*-all.jar /home/app/consumer-api/build/libs/consumer-api.jar
diff --git a/producer-consumer/micronaut-producer-consumer/producer-api/build.gradle b/producer-consumer/micronaut-producer-consumer/producer-api/build.gradle
index fa86250..3d0bd23 100644
--- a/producer-consumer/micronaut-producer-consumer/producer-api/build.gradle
+++ b/producer-consumer/micronaut-producer-consumer/producer-api/build.gradle
@@ -10,6 +10,7 @@ group "com.mycompany.producerapi"

 repositories {
     jcenter()
+    mavenLocal()
 }

 configurations {
@@ -18,11 +19,17 @@ configurations {
 }

 ext {
-    set('micronautVersion', '2.0.0.M3')
+    set('micronautVersion', '2.0.0.RC1')
     set('lombokVersion', '1.18.12')
     set('logbackVersion', '1.2.3')
 }

+configurations.all {
+    resolutionStrategy {
+        force "io.micronaut.kafka:micronaut-kafka:2.1.0.BUILD-SNAPSHOT"
+    }
+}
+
 dependencies {
     //-- IMPORTANT!
     //  Lombok annotation processor must place before the Micronaut processors in the build configuration
@@ -30,31 +37,31 @@ dependencies {
     compileOnly("org.projectlombok:lombok:$lombokVersion")
     annotationProcessor("org.projectlombok:lombok:$lombokVersion")
     //--
-    annotationProcessor(enforcedPlatform("io.micronaut:micronaut-bom:$micronautVersion"))
+    annotationProcessor(platform("io.micronaut:micronaut-bom:$micronautVersion"))
     annotationProcessor("io.micronaut:micronaut-inject-java")
     annotationProcessor("io.micronaut:micronaut-validation")
     annotationProcessor("io.micronaut:micronaut-graal")
-    compileOnly(enforcedPlatform("io.micronaut:micronaut-bom:$micronautVersion"))
+    compileOnly(platform("io.micronaut:micronaut-bom:$micronautVersion"))
     compileOnly("org.graalvm.nativeimage:svm")
-    implementation(enforcedPlatform("io.micronaut:micronaut-bom:$micronautVersion"))
+    implementation(platform("io.micronaut:micronaut-bom:$micronautVersion"))
     implementation("io.micronaut:micronaut-management")
-    implementation("io.micronaut.configuration:micronaut-micrometer-core")
+    implementation("io.micronaut.micrometer:micronaut-micrometer-core")
     implementation("io.opentracing.brave:brave-opentracing")
     implementation("io.micronaut:micronaut-tracing")
-    implementation("io.micronaut.configuration:micronaut-micrometer-registry-prometheus")
+    implementation("io.micronaut.micrometer:micronaut-micrometer-registry-prometheus")
     implementation("io.micronaut:micronaut-inject")
     implementation("io.micronaut:micronaut-validation")
     implementation("io.micronaut:micronaut-runtime")
     implementation("io.micronaut:micronaut-http-server-netty")
     implementation("io.micronaut:micronaut-http-client")
-    implementation("io.micronaut.kafka:micronaut-kafka")
+    implementation("io.micronaut.kafka:micronaut-kafka:2.1.0.BUILD-SNAPSHOT")
     implementation("io.micronaut.cache:micronaut-cache-caffeine")
     runtimeOnly("io.zipkin.brave:brave-instrumentation-http")
     runtimeOnly("io.zipkin.reporter2:zipkin-reporter")
     runtimeOnly("ch.qos.logback:logback-classic:$logbackVersion")
-    testAnnotationProcessor(enforcedPlatform("io.micronaut:micronaut-bom:$micronautVersion"))
+    testAnnotationProcessor(platform("io.micronaut:micronaut-bom:$micronautVersion"))
     testAnnotationProcessor("io.micronaut:micronaut-inject-java")
-    testImplementation(enforcedPlatform("io.micronaut:micronaut-bom:$micronautVersion"))
+    testImplementation(platform("io.micronaut:micronaut-bom:$micronautVersion"))
     testImplementation("org.junit.jupiter:junit-jupiter-api")
     testImplementation("io.micronaut.test:micronaut-test-junit5")
     testRuntimeOnly("org.junit.jupiter:junit-jupiter-engine")
diff --git a/producer-consumer/micronaut-producer-consumer/producer-api/src/main/docker/Dockerfile.native b/producer-consumer/micronaut-producer-consumer/producer-api/src/main/docker/Dockerfile.native
index c05986d..16b43d7 100644
--- a/producer-consumer/micronaut-producer-consumer/producer-api/src/main/docker/Dockerfile.native
+++ b/producer-consumer/micronaut-producer-consumer/producer-api/src/main/docker/Dockerfile.native
@@ -1,6 +1,6 @@
-FROM oracle/graalvm-ce:20.0.0-java8 as graalvm
+#FROM oracle/graalvm-ce:20.0.0-java8 as graalvm
 # For JDK 11
-#FROM oracle/graalvm-ce:20.0.0-java11 as graalvm
+FROM oracle/graalvm-ce:20.0.0-java11 as graalvm
 RUN gu install native-image

 COPY build/libs/producer-api-*-all.jar /home/app/producer-api/build/libs/producer-api.jar
-- 
2.24.3 (Apple Git-128)
ivangfr commented 4 years ago

Perfect @graemerocher ! I am looking forward to 2.0.0 final release.