search

quarkusio / quarkus

Quarkus: Supersonic Subatomic Java.
https://quarkus.io
Apache License 2.0
13.58k stars 2.63k forks source link

quarkus update deadlocks, perhaps between OutputEventTransformer and ThrottlingOutputEventListener #41022

Open sken130 opened 3 months ago

sken130 commented 3 months ago

Describe the bug

I was trying to update Quarkus from 3.5.3 to latest (3.11.1 at the time of this report)

OS: Windows Server 2019 Datacenter Java version running the quarkus update command: 18.0.2.1 and 21.0.2 Gradle version: 8.8

build.gradle:

import io.quarkus.gradle.tasks.QuarkusDev
import org.gradle.api.tasks.JavaExec

plugins {
//    kotlin("jvm") version "1.9.22"
//    kotlin("plugin.allopen") version "1.9.22"
    //kotlin("plugin.serialization") version "1.9.22"
    id "io.quarkus"
    id "org.jetbrains.kotlin.jvm" version "1.9.23"
    id "org.jetbrains.kotlin.plugin.allopen" version "1.9.23"
}

repositories {
    mavenCentral()
    mavenLocal()
    maven { url 'https://jitpack.io' }
}

//val quarkusPlatformGroupId: String by project
//val quarkusPlatformArtifactId: String by project
//val quarkusPlatformVersion: String by project

dependencies {
    implementation "io.quarkus:quarkus-config-yaml"
    implementation enforcedPlatform("${quarkusPlatformGroupId}:${quarkusPlatformArtifactId}:${quarkusPlatformVersion}")
    implementation "com.fasterxml.jackson.module:jackson-module-kotlin:2.15.3"
    implementation "io.quarkiverse.quinoa:quarkus-quinoa:2.2.1"
    implementation "io.quarkus:quarkus-resteasy-reactive-jackson"
//    implementation "io.quarkus:quarkus-resteasy-reactive"
    implementation "io.quarkus:quarkus-kotlin"
//    implementation "io.quarkus:quarkus-hibernate-orm-panache"
    implementation "io.quarkus:quarkus-hibernate-orm-panache-kotlin"
//    implementation "io.quarkus:quarkus-hibernate-reactive-panache-kotlin"
//    implementation "io.quarkus:quarkus-reactive-pg-client"
    implementation "io.quarkus:quarkus-jdbc-postgresql"
//    implementation "io.quarkus:quarkus-resteasy-reactive-kotlin-serialization"
    implementation "org.jetbrains.kotlin:kotlin-stdlib-jdk8"
    implementation "io.quarkus:quarkus-arc"
//    implementation "io.quarkus:quarkus-hibernate-orm"
    testImplementation "io.quarkus:quarkus-junit5"
    testImplementation "io.rest-assured:rest-assured"
    implementation "com.github.ntrrgc:ts-generator:1.1.1"
    implementation "com.azure:azure-sdk-bom:1.2.19"
    implementation("com.azure:azure-ai-formrecognizer:4.1.4")
    implementation("org.hjson:hjson:3.1.0")
    implementation("org.apache.pdfbox:pdfbox:3.0.2")
    implementation("com.azure:azure-ai-openai:1.0.0-beta.8")
}

group "org.xxxxx.yyyyy"
version "0.1.0"

java {
    sourceCompatibility = JavaVersion.VERSION_17
    targetCompatibility = JavaVersion.VERSION_17
}

tasks.quarkusDev {
    workingDirectory = rootProject.projectDir
}

test {
    systemProperty "java.util.logging.manager", "org.jboss.logmanager.LogManager"
}
allOpen {
    annotation("jakarta.ws.rs.Path")
    annotation("jakarta.enterprise.context.ApplicationScoped")
    annotation("jakarta.persistence.Entity")
    annotation("io.quarkus.test.junit.QuarkusTest")
}

compileKotlin {
    kotlinOptions.jvmTarget = JavaVersion.VERSION_17
    kotlinOptions.javaParameters = true
}

compileTestKotlin {
    kotlinOptions.jvmTarget = JavaVersion.VERSION_17
}

// Run command: ./gradlew generateTypeScriptJsonInterfaces --stacktrace --info
task (generateTypeScriptJsonInterfaces, type: JavaExec) {
    group = 'Execution'
    description = 'Generates TypeScript interface definitions based on Kotlin data definitions'

    classpath = sourceSets.main.runtimeClasspath
    mainClass = 'org.xxxxx.typescript.TypeScriptInterfaceGenerator'

    // If you need to pass arguments to the main method
    args project.projectDir.canonicalPath
    // dependsOn 'build'
}

Relevant final Java command from Task Manager/Process Explorer: "C:\Program Files\Eclipse Adoptium\jdk-21.0.2.13-hotspot/bin/java.exe" "-Xmx64m" "-Xms64m" "-Dorg.gradle.appname=gradlew" -classpath "C:\path\to\project\\gradle\wrapper\gradle-wrapper.jar" org.gradle.wrapper.GradleWrapperMain --console plain --stacktrace --init-script C:\Users\xxxxx\AppData\Local\Temp\2\openrewrite-init14975923088595330686gradle rewriteRun

Console output with Java 21:

C:\path\to\project>quarkus update --verbose
C:\path\to\project\gradlew.bat -PquarkusPluginVersion=3.10.2 --console plain --no-daemon --stacktrace quarkusUpdate

To honour the JVM settings for this build a single-use Daemon process will be forked. For more on this, please refer to https://docs.gradle.org/8.8/userguide/gradle_daemon.html#sec:disabling_the_daemon in the Gradle documentation.
Daemon will be stopped at the end of the build

> Task :quarkusUpdate
quarkusUpdate is experimental, its options and output might change in future versions
Looking for the newly published extensions in registry.quarkus.io
Detected project Java version: 17
Detected project Java version: 17
Instructions to update this project from '3.5.3' to '3.11.1':
Recommended Quarkus platform BOM updates:
Update: io.quarkus.platform:quarkus-bom:pom:3.5.3 -> 3.8.5

Extensions from io.quarkus.platform:quarkus-bom:

Resolved io.quarkus:quarkus-updates-recipes:1.0.17 with 8 recipe(s) to update from 3.5.3 to 3.11.1 (initially made for OpenRewrite GRADLE plugin version: 6.12.0)
OpenRewrite recipe generated: C:\Users\xxxxx\AppData\Local\Temp\2\quarkus-project-recipe-6485720557256403423.yaml

 ------------------------------------------------------------------------
Executing:
C:\path\to\project\gradlew.bat --console plain --stacktrace --init-script C:\Users\xxxxx\AppData\Local\Temp\2\openrewrite-init14975923088595330686gradle rewriteRun

C:\path\to\project>Terminate batch job (Y/N)?

Console output using Java 18:

C:\path\to\project\gradlew.bat -PquarkusPluginVersion=3.10.2 --console plain --no-daemon --stacktrace quarkusUpdate

To honour the JVM settings for this build a single-use Daemon process will be forked. For more on this, please refer to https://docs.gradle.org/8.8/userguide/gradle_daemon.html#sec:disabling_the_daemon in the Gradle documentation.
Daemon will be stopped at the end of the build

> Task :quarkusUpdate
quarkusUpdate is experimental, its options and output might change in future versions
Detected project Java version: 17
Detected project Java version: 17
Instructions to update this project from '3.5.3' to '3.11.1':
Recommended Quarkus platform BOM updates:
Update: io.quarkus.platform:quarkus-bom:pom:3.5.3 -> 3.8.5

Extensions from io.quarkus.platform:quarkus-bom:

Resolved io.quarkus:quarkus-updates-recipes:1.0.17 with 8 recipe(s) to update from 3.5.3 to 3.11.1 (initially made for OpenRewrite GRADLE plugin version: 6.12.0)
OpenRewrite recipe generated: C:\Users\xxxxx\AppData\Local\Temp\2\quarkus-project-recipe-8294057836996843624.yaml

 ------------------------------------------------------------------------
Executing:
C:\path\to\project\gradlew.bat --console plain --stacktrace --init-script C:\Users\xxxxx\AppData\Local\Temp\2\openrewrite-init13390202174499012034gradle rewriteRun

C:\path\to\project>Terminate batch job (Y/N)? y

Thread dumps are attached too.

threaddumps-20240606.zip

The most relevant stack trace:

"main" #1 [15016] prio=5 os_prio=0 cpu=1156.25ms elapsed=158.96s tid=0x000001cd2fc57c50 nid=15016 waiting for monitor entry  [0x0000005e95efd000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.gradle.internal.logging.console.ThrottlingOutputEventListener.onOutput(ThrottlingOutputEventListener.java:79)
    - waiting to lock <0x00000000fe809200> (a java.lang.Object)
    at java.lang.invoke.LambdaForm$DMH/0x000001cd4d120000.invokeInterface(java.base@21.0.2/LambdaForm$DMH)
    at java.lang.invoke.LambdaForm$MH/0x000001cd4d134000.invoke(java.base@21.0.2/LambdaForm$MH)
    at java.lang.invoke.Invokers$Holder.invokeExact_MT(java.base@21.0.2/Invokers$Holder)
    at jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl(java.base@21.0.2/DirectMethodHandleAccessor.java:154)
    at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(java.base@21.0.2/DirectMethodHandleAccessor.java:103)
    at java.lang.reflect.Method.invoke(java.base@21.0.2/Method.java:580)
    at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
    at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
    at org.gradle.internal.event.AbstractBroadcastDispatch.dispatch(AbstractBroadcastDispatch.java:43)
    at org.gradle.internal.event.BroadcastDispatch$SingletonDispatch.dispatch(BroadcastDispatch.java:268)
    at org.gradle.internal.event.BroadcastDispatch$SingletonDispatch.dispatch(BroadcastDispatch.java:170)
    at org.gradle.internal.event.ListenerBroadcast.dispatch(ListenerBroadcast.java:148)
    at org.gradle.internal.event.ListenerBroadcast.dispatch(ListenerBroadcast.java:37)
    at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:94)
    at jdk.proxy1.$Proxy0.onOutput(jdk.proxy1/Unknown Source)
    at org.gradle.internal.logging.sink.OutputEventTransformer.invokeListener(OutputEventTransformer.java:113)
    - locked <0x00000000fe807f20> (a java.lang.Object)
    at org.gradle.internal.logging.sink.OutputEventTransformer.onOutput(OutputEventTransformer.java:90)
    at org.gradle.internal.logging.sink.OutputEventRenderer.onOutput(OutputEventRenderer.java:435)
    at org.gradle.internal.logging.sink.OutputEventListenerManager$1.onOutput(OutputEventListenerManager.java:36)
    at org.gradle.launcher.daemon.client.DaemonClient.monitorBuild(DaemonClient.java:259)
    at org.gradle.launcher.daemon.client.DaemonClient.executeBuild(DaemonClient.java:212)
    at org.gradle.launcher.daemon.client.DaemonClient.execute(DaemonClient.java:162)
    at org.gradle.launcher.daemon.client.DaemonClient.execute(DaemonClient.java:98)
    at org.gradle.launcher.cli.RunBuildAction.run(RunBuildAction.java:57)
    at org.gradle.internal.Actions$RunnableActionAdapter.execute(Actions.java:167)
    at org.gradle.launcher.cli.DefaultCommandLineActionFactory$ParseAndBuildAction.execute(DefaultCommandLineActionFactory.java:261)
    at org.gradle.launcher.cli.DefaultCommandLineActionFactory$ParseAndBuildAction.execute(DefaultCommandLineActionFactory.java:232)
    at org.gradle.launcher.cli.DebugLoggerWarningAction.execute(DebugLoggerWarningAction.java:74)
    at org.gradle.launcher.cli.DebugLoggerWarningAction.execute(DebugLoggerWarningAction.java:30)
    at org.gradle.launcher.cli.WelcomeMessageAction.execute(WelcomeMessageAction.java:96)
    at org.gradle.launcher.cli.WelcomeMessageAction.execute(WelcomeMessageAction.java:40)
    at org.gradle.launcher.cli.NativeServicesInitializingAction.execute(NativeServicesInitializingAction.java:55)
    at org.gradle.launcher.cli.NativeServicesInitializingAction.execute(NativeServicesInitializingAction.java:29)
    at org.gradle.launcher.cli.ExceptionReportingAction.execute(ExceptionReportingAction.java:41)
    at org.gradle.launcher.cli.ExceptionReportingAction.execute(ExceptionReportingAction.java:26)
    at org.gradle.launcher.cli.DefaultCommandLineActionFactory$WithLogging.execute(DefaultCommandLineActionFactory.java:365)
    at org.gradle.launcher.Main.doAction(Main.java:35)
    at org.gradle.launcher.bootstrap.EntryPoint.run(EntryPoint.java:51)
    at java.lang.invoke.DirectMethodHandle$Holder.invokeVirtual(java.base@21.0.2/DirectMethodHandle$Holder)
    at java.lang.invoke.LambdaForm$MH/0x000001cd4d016800.invoke(java.base@21.0.2/LambdaForm$MH)
    at java.lang.invoke.Invokers$Holder.invokeExact_MT(java.base@21.0.2/Invokers$Holder)
    at jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl(java.base@21.0.2/DirectMethodHandleAccessor.java:154)
    at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(java.base@21.0.2/DirectMethodHandleAccessor.java:103)
    at java.lang.reflect.Method.invoke(java.base@21.0.2/Method.java:580)
    at org.gradle.launcher.bootstrap.ProcessBootstrap.runNoExit(ProcessBootstrap.java:60)
    at org.gradle.launcher.bootstrap.ProcessBootstrap.run(ProcessBootstrap.java:37)
    at java.lang.invoke.LambdaForm$DMH/0x000001cd4d008400.invokeStatic(java.base@21.0.2/LambdaForm$DMH)
    at java.lang.invoke.LambdaForm$MH/0x000001cd4d009c00.invoke(java.base@21.0.2/LambdaForm$MH)
    at java.lang.invoke.LambdaForm$MH/0x000001cd4d00a000.invokeExact_MT(java.base@21.0.2/LambdaForm$MH)
    at jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl(java.base@21.0.2/DirectMethodHandleAccessor.java:155)
    at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(java.base@21.0.2/DirectMethodHandleAccessor.java:103)
    at java.lang.reflect.Method.invoke(java.base@21.0.2/Method.java:580)
    at org.gradle.launcher.GradleMain.main(GradleMain.java:34)
    at java.lang.invoke.LambdaForm$DMH/0x000001cd4d004400.invokeStatic(java.base@21.0.2/LambdaForm$DMH)
    at java.lang.invoke.LambdaForm$MH/0x000001cd4d008000.invoke(java.base@21.0.2/LambdaForm$MH)
    at java.lang.invoke.Invokers$Holder.invokeExact_MT(java.base@21.0.2/Invokers$Holder)
    at jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl(java.base@21.0.2/DirectMethodHandleAccessor.java:154)
    at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(java.base@21.0.2/DirectMethodHandleAccessor.java:103)
    at java.lang.reflect.Method.invoke(java.base@21.0.2/Method.java:580)
    at org.gradle.wrapper.BootstrapMainStarter.start(BootstrapMainStarter.java:35)
    at org.gradle.wrapper.WrapperExecutor.execute(WrapperExecutor.java:103)
    at org.gradle.wrapper.GradleWrapperMain.main(GradleWrapperMain.java:66)

   Locked ownable synchronizers:
    - None

......

"pool-1-thread-1" #24 [15704] prio=5 os_prio=0 cpu=0.00ms elapsed=158.19s tid=0x000001cd4ba084d0 nid=15704 runnable  [0x0000005e974fe000]
   java.lang.Thread.State: RUNNABLE
    at java.io.FileOutputStream.writeBytes(java.base@21.0.2/Native Method)
    at java.io.FileOutputStream.write(java.base@21.0.2/FileOutputStream.java:367)
    at java.io.BufferedOutputStream.flushBuffer(java.base@21.0.2/BufferedOutputStream.java:125)
    at java.io.BufferedOutputStream.implFlush(java.base@21.0.2/BufferedOutputStream.java:252)
    at java.io.BufferedOutputStream.flush(java.base@21.0.2/BufferedOutputStream.java:240)
    at java.io.PrintStream.implWrite(java.base@21.0.2/PrintStream.java:645)
    at java.io.PrintStream.write(java.base@21.0.2/PrintStream.java:623)
    at sun.nio.cs.StreamEncoder.writeBytes(java.base@21.0.2/StreamEncoder.java:309)
    at sun.nio.cs.StreamEncoder.implFlushBuffer(java.base@21.0.2/StreamEncoder.java:405)
    at sun.nio.cs.StreamEncoder.implFlush(java.base@21.0.2/StreamEncoder.java:410)
    at sun.nio.cs.StreamEncoder.lockedFlush(java.base@21.0.2/StreamEncoder.java:214)
    at sun.nio.cs.StreamEncoder.flush(java.base@21.0.2/StreamEncoder.java:201)
    at java.io.OutputStreamWriter.flush(java.base@21.0.2/OutputStreamWriter.java:262)
    at org.gradle.internal.logging.text.StreamBackedStandardOutputListener.onOutput(StreamBackedStandardOutputListener.java:49)
    at org.gradle.internal.logging.text.StreamingStyledTextOutput.doAppend(StreamingStyledTextOutput.java:55)
    at org.gradle.internal.logging.text.AbstractStyledTextOutput.text(AbstractStyledTextOutput.java:82)
    at org.gradle.internal.logging.console.StyledTextOutputBackedRenderer$OutputEventTextOutputImpl.doLineText(StyledTextOutputBackedRenderer.java:90)
    at org.gradle.internal.logging.text.AbstractLineChoppingStyledTextOutput$StateContext.flushLineText(AbstractLineChoppingStyledTextOutput.java:131)
    at org.gradle.internal.logging.text.AbstractLineChoppingStyledTextOutput$3.execute(AbstractLineChoppingStyledTextOutput.java:197)
    at org.gradle.internal.logging.text.AbstractLineChoppingStyledTextOutput$3.execute(AbstractLineChoppingStyledTextOutput.java:193)
    at org.gradle.internal.logging.text.AbstractLineChoppingStyledTextOutput.doAppend(AbstractLineChoppingStyledTextOutput.java:44)
    at org.gradle.internal.logging.text.AbstractStyledTextOutput.text(AbstractStyledTextOutput.java:82)
    at org.gradle.internal.logging.events.StyledTextOutputEvent.render(StyledTextOutputEvent.java:80)
    at org.gradle.internal.logging.console.StyledTextOutputBackedRenderer.onOutput(StyledTextOutputBackedRenderer.java:69)
    at org.gradle.internal.logging.sink.ErrorOutputDispatchingListener.onOutput(ErrorOutputDispatchingListener.java:41)
    at org.gradle.internal.logging.sink.GroupingProgressLogEventGenerator.onUngroupedOutput(GroupingProgressLogEventGenerator.java:145)
    at org.gradle.internal.logging.sink.GroupingProgressLogEventGenerator.handleOutput(GroupingProgressLogEventGenerator.java:108)
    at org.gradle.internal.logging.sink.GroupingProgressLogEventGenerator.onOutput(GroupingProgressLogEventGenerator.java:74)
    at org.gradle.internal.logging.console.BuildLogLevelFilterRenderer.onOutput(BuildLogLevelFilterRenderer.java:41)
    at org.gradle.internal.logging.console.AbstractUserInputRenderer.onOutput(AbstractUserInputRenderer.java:59)
    at org.gradle.internal.logging.console.ThrottlingOutputEventListener.renderNow(ThrottlingOutputEventListener.java:105)
    at org.gradle.internal.logging.console.ThrottlingOutputEventListener.onOutput(ThrottlingOutputEventListener.java:87)
    - locked <0x00000000fe809200> (a java.lang.Object)
    at org.gradle.internal.logging.console.ThrottlingOutputEventListener$1.run(ThrottlingOutputEventListener.java:66)
    at java.util.concurrent.Executors$RunnableAdapter.call(java.base@21.0.2/Executors.java:572)
    at java.util.concurrent.FutureTask.runAndReset(java.base@21.0.2/FutureTask.java:358)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(java.base@21.0.2/ScheduledThreadPoolExecutor.java:305)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@21.0.2/ThreadPoolExecutor.java:1144)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@21.0.2/ThreadPoolExecutor.java:642)
    at java.lang.Thread.runWith(java.base@21.0.2/Thread.java:1596)
    at java.lang.Thread.run(java.base@21.0.2/Thread.java:1583)

   Locked ownable synchronizers:
    - <0x00000000fc40b3c0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
    - <0x00000000fc40b4a0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
    - <0x00000000fe808ab8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
    - <0x00000000fe8117a8> (a java.util.concurrent.ThreadPoolExecutor$Worker)

Expected behavior

The quarkus update should have a response, no matter succeeded or failed.

Actual behavior

It's hung, and seems waiting forever.

How to Reproduce?

Run quarkus update --verbose in console

Output of uname -a or ver

No response

Output of java -version

18.0.2.1 and 21.0.2

Quarkus version or git rev

3.5.3

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

Gradle 8.8

Additional information

No response

quarkus-bot[bot] commented 3 months ago

/cc @geoand (kotlin)

geoand commented 3 months ago

Can try again with Java 17 or 21? Java 18 is not supported. I doubt the Java version will change anything, I just want to be sure.

sken130 commented 3 months ago

The result is the same using Java 21. Attached are more thread dumps. threaddumps-20240607.zip

I will also edit the issue to include the most relevant part of stack trace.

geoand commented 3 months ago

Thanks for checking.

From the stacktrace, it looks like a Gradle bug instead of a Quarkus one.

geoand commented 3 months ago

@gsmet do we know anyone from Gradle that can have a look at this?