Openshift extension fails to deploy when on RHEL

[fedinskiy]

Describe the bug

I have an application(resteasy, two endpoints) which I wan to deploy to Openshift via quarkus-openshift extension. After an update to 3.2.0.CR2, the deployment process succeeds on Fedora and fails on RHEL 8 with "Connection was closed" error. This happens robustly.

Expected behavior

Successful deployment as for 3.1.0.Final and on Fedora

Actual behavior

[ERROR] 	[error]: Build step io.quarkus.container.image.openshift.deployment.OpenshiftProcessor#openshiftBuildFromJar threw an exception: io.fabric8.kubernetes.client.KubernetesClientException: Connection was closed
[ERROR] 	at io.fabric8.kubernetes.client.dsl.internal.OperationSupport.waitForResult(OperationSupport.java:520)
[ERROR] 	at io.fabric8.kubernetes.client.dsl.internal.OperationSupport.handleResponse(OperationSupport.java:535)
[ERROR] 	at io.fabric8.kubernetes.client.dsl.internal.OperationSupport.handleGet(OperationSupport.java:478)
[ERROR] 	at io.fabric8.kubernetes.client.dsl.internal.BaseOperation.handleGet(BaseOperation.java:741)
[ERROR] 	at io.fabric8.kubernetes.client.dsl.internal.BaseOperation.requireFromServer(BaseOperation.java:185)
[ERROR] 	at io.fabric8.kubernetes.client.dsl.internal.BaseOperation.get(BaseOperation.java:141)
[ERROR] 	at io.fabric8.kubernetes.client.dsl.internal.BaseOperation.get(BaseOperation.java:92)
[ERROR] 	at io.quarkus.container.image.openshift.deployment.OpenshiftProcessor.openshiftBuild(OpenshiftProcessor.java:462)
[ERROR] 	at io.quarkus.container.image.openshift.deployment.OpenshiftProcessor.lambda$openshiftBuild$10(OpenshiftProcessor.java:429)
[ERROR] 	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
[ERROR] 	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
[ERROR] 	at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:177)
[ERROR] 	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1655)
[ERROR] 	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
[ERROR] 	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
[ERROR] 	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
[ERROR] 	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
[ERROR] 	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
[ERROR] 	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497)
[ERROR] 	at io.quarkus.container.image.openshift.deployment.OpenshiftProcessor.openshiftBuild(OpenshiftProcessor.java:429)
[ERROR] 	at io.quarkus.container.image.openshift.deployment.OpenshiftProcessor.createContainerImage(OpenshiftProcessor.java:388)
[ERROR] 	at io.quarkus.container.image.openshift.deployment.OpenshiftProcessor.openshiftBuildFromJar(OpenshiftProcessor.java:285)
[ERROR] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[ERROR] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[ERROR] 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[ERROR] 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[ERROR] 	at io.quarkus.deployment.ExtensionLoader$3.execute(ExtensionLoader.java:909)
[ERROR] 	at io.quarkus.builder.BuildContext.run(BuildContext.java:282)
[ERROR] 	at org.jboss.threads.ContextHandler$1.runWith(ContextHandler.java:18)
[ERROR] 	at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
[ERROR] 	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
[ERROR] 	at java.base/java.lang.Thread.run(Thread.java:829)
[ERROR] 	at org.jboss.threads.JBossThread.run(JBossThread.java:501)
[ERROR] Caused by: io.vertx.core.http.HttpClosedException: Connection was closed

How to Reproduce?

1. git clone https://github.com/fedinskiy/reproducer -b opeshift-extension-rhel-disconnect
2. oc new-project rhel-disconnect && cd reproducer
3. mvn package -Dquarkus.kubernetes.deploy=true -Dquarkus.openshift.expose=true -Dquarkus.openshift.route.expose=true -Dquarkus.application.name=app -Dquarkus.kubernetes-client.trust-certs=true -Dquarkus.kubernetes.deployment-target=openshift fails
4. mvn package -Dquarkus.kubernetes.deploy=true -Dquarkus.openshift.expose=true -Dquarkus.openshift.route.expose=true -Dquarkus.application.name=app -Dquarkus.kubernetes-client.trust-certs=true -Dquarkus.kubernetes.deployment-target=openshift -Dquarkus.platform.version=3.1.0.Final succeeds (in another project)

Output of uname -a or ver

4.18.0-477.13.1.el8_8.x86_64

Output of java -version

11.0.13, vendor: Red Hat, Inc

GraalVM version (if different from Java)

No response

Quarkus version or git rev

3.2.0.CR2

Build tool (ie. output of mvnw --version or gradlew --version)

Apache Maven 3.8.6 (84538c9988a25aec085021c365c560670ad80f63)

Additional information

oc version(same on both Fedora and RHEL):

Client Version: 4.13.0-202305312300.p0.g05d83ef.assembly.stream-05d83ef
Kustomize Version: v4.5.7
Kubernetes Version: v1.26.5+7a891f0

[quarkus-bot]

/cc @Sgitario (kubernetes), @geoand (kubernetes,openshift), @iocanel (kubernetes,openshift)

[rsvoboda]

@iocanel any idea what it could be connected with? We don't see this with Quarkus 3.1 and older.

[fedinskiy]

Update: 3.1.2.Final is not affected by this bug, so whatever is the root cause it was not backported.

RHEL9[1] is not affected

[1]

Apache Maven 3.8.6 (84538c9988a25aec085021c365c560670ad80f63)
Maven home: /opt/apache-maven-3.8.6
Java version: 11.0.13, vendor: Red Hat, Inc., runtime: /qa/tools/opt/x86_64/openjdk-11.0.13.0.8
Default locale: en, platform encoding: UTF-8
OS name: "linux", version: "5.14.0-284.11.1.el9_2.x86_64", arch: "amd64", family: "unix"

[iocanel]

My guess is that the message is misleading. Possibly due to something stalling the build till it timeout. In the past I've seen similar messages when Builder imagestream is missing etc.

[rsvoboda]

@fedinskiy, so the problem is with 3.2.0.CR1 / Quarkus main and RHEL 8?

[fedinskiy]

@rsvoboda yes, Quarkus 3.2.0.CR1/main and RHEL 8.

[rsvoboda]

@iocanel @Sgitario this is blocking issue for RHBQ as product needs to be tested on RHEL8

[Sgitario]

@rsvoboda I'm trying to find an RHEL8 environment to reproduce this issue (please, contact me if you have one I could use).
In the meantime, I think this might be related to #34068. Could you test in Quarkus main by reverting this change? @fedinskiy @rsvoboda

@manusa does it ring any bell to you?
@fedinskiy when the timeout happens? after 1 min or after more time? Can you share the build logs as well?

[cmoulliard]

Is it possible to get the log of the pod doing the s2i build on ocp as error is taking place there ?

[rsvoboda]

In the meantime, I think this might be related to #34068. Could you test in Quarkus main by reverting this change? @fedinskiy @rsvoboda

Fedor is working on it.

[fedinskiy]

@Sgitario
There is no timeout per se.
It takes the build around 10 seconds to reach line 31 of the log(see below), then there is ~ 30 seconds wait period and then for 30 seconds there is a log output and almost immediate failure after the line 357 is shown.
RHEL8 machine details are in your Slack DMs

I will test with this change reverted and reach back to you.

@cmoulliard full test logs:
https://gist.github.com/fedinskiy/df9a586ad7a1a8995fc904e14c7ffb4a#file-full-txt

[cmoulliard]

full test logs:

Many thanks but I was talking about the log of the s2i pod created by openshift and doing the job. This is where the problem was taking place. As the build process failed (= timeout) then the java f8 client will get a timeout and will close theconnection but to know the root cause, it is needed to get the log of the pod @fedinskiy

[fedinskiy]

Build with reverted #34068 didn't work even on a fresh machine:

1. git clone https://github.com/quarkusio/quarkus
2. git revert 0c52b6f72f78b07541c00269a9184263a6567dda
3. mvn clean install -Dquickly -Dmp-test-modules -Prelocations -Dinsecure.repositories=WARN
4. (After steps 1&2 of the original reproducer): mvn package -Dquarkus.kubernetes.deploy=true -Dquarkus.openshift.expose=true -Dquarkus.openshift.route.expose=true -Dquarkus.application.name=app -Dquarkus.kubernetes-client.trust-certs=true -Dquarkus.kubernetes.deployment-target=openshift -Dquarkus.platform.version=999-SNAPSHOT

[fedinskiy]

@cmoulliard the error didn't happen on a s2i pod, but on host, where maven build was started.
s2i logs: https://gist.github.com/fedinskiy/df9a586ad7a1a8995fc904e14c7ffb4a#file-build-log

[fedinskiy]

@Sgitario since this behavior is not caused by #34068, maybe it is #33767 to blame?

[cmoulliard]

s2i logs

Many thanks. Your are right ;-)

According to the build initiated

Generating dockerfile with builder image registry.access.redhat.com/ubi8/openjdk-11@sha256:60b88d0608b870dea560d34e916446dacb9e2120ca90b853612eab4c7be9c38f
Adding transient rw bind mount for /run/secrets/rhsm
STEP 1/9: FROM registry.access.redhat.com/ubi8/openjdk-11@sha256:60b88d0608b870dea560d34e916446dacb9e2120ca90b853612eab4c7be9c38f
STEP 2/9: LABEL "io.openshift.build.source-location"="/tmp/build/inputs"       "io.openshift.s2i.destination"="/tmp"       "io.openshift.build.image"="registry.access.redhat.com/ubi8/openjdk-11@sha256:60b88d0608b870dea560d34e916446dacb9e2120ca90b853612eab4c7be9c38f"
STEP 3/9: ENV OPENSHIFT_BUILD_NAME="app-1"     OPENSHIFT_BUILD_NAMESPACE="rhel-fresh"
STEP 4/9: USER root
STEP 5/9: COPY upload/src /tmp/src
STEP 6/9: RUN chown -R 185:0 /tmp/src
STEP 7/9: USER 185
STEP 8/9: RUN /usr/local/s2i/assemble
INFO S2I source build with plain binaries detected
INFO Copying binaries from /tmp/src to /deployments ...

the error occurs here within the code during the execution of the method public void openshiftBuildFromJar(OpenshiftConfig openshiftConfig,: https://github.com/quarkusio/quarkus/blob/3.2.0.CR1/extensions/container-image/container-image-openshift/deployment/src/main/java/io/quarkus/container/image/openshift/deployment/OpenshiftProcessor.java#L238

[Sgitario]

@Sgitario since this behavior is not caused by #34068, maybe it is #33767 to blame?

Yes, please let us know if without #34068 and #33767, the issue is gone.

[fedinskiy]

It is not #33767, since running tests with Quarkus fea1aee[1] works

[1]fea1aee

[fedinskiy]

It looks like 69682b3 is not affected, so whatever update brought this change it was after the seventh of June

[fedinskiy]

At the same time, 0fcfc8b is affected, so the change was brought somewhere from 8 to 14 of June
UPD: 65aad80 is affected and fea1aee is not, so it is June 12 or 13.
UPD2: e6a01b5 is not affected

[Sgitario]

This is definitely a timeout issue that I think it's more related to the OpenShift instance in use than the RHEL system. Actually, my first attempt using RHEL 8 and a fresh OCP instance worked fine.

What's happening is that the OpenShift instance is closing a connection after a timeout and the Fabric8 Kubernetes Client connection is gone. However, this does not mean that the build failed and we should recover from it. I will submit a pull request for fixing once I do a few more tests.

Note that I still think the bump of Kubernetes Client by #34068 and #33767 is the root cause of the issue: @manusa

[Sgitario]

#34374 should fix this issue.
@fedinskiy feel free to try it out as well.

[fedinskiy]

@Sgitario it seems to be a working solution, thank you!