JDK 23 new console is causing a serious regression in startup

[geoand]

Description

When using the rest-json quickstart, on my machine I see the following numbers for startup:

• 500ms for JDK 21
• 580ms in 23
• 650ms in Leyden premain branch (based on JDK 24)

The regressions from 23 to 24 can be reversed by setting -Djdk.console=java.base.
We should do that as the first thing in our generated main (unless the user has already set such a property).

P.S. @dmlloyd spotted the JLine issue by looking at the allocation flamegraphs I produced:

21:

24:

Implementation ideas

No response

[geoand]

@dmlloyd also proposed:

we might be able to modify logmanager to automatically set the property before initializing the console

which also makes sense

[dmlloyd]

I've opened https://issues.redhat.com/browse/LOGMGR-354 with this idea.

[geoand]

🙏

[geoand]

It turns out that using -Djdk.console=java.base gets us back to JDK 21 levels of startup time when using JDK 23, so we probably want to incorporate it sooner rather than later @dmlloyd.

Here is an allocation framegraph for JDK 23:

[gsmet]

Is this with dev mode or plain startup?

I have a vague recollection @Karm opened an issue to determine if the new console could allow us to get rid of Jansi and friends.

[geoand]

Is this with dev mode or plain startup?

All the flamegraphs are from prod mode startup

[dmlloyd]

Would you be able/willing to try jboss-logging/jboss-logmanager#491 to see if it fixes the issue?

[geoand]

Sure, let me give it a shot

[geoand]

The fix doesn't make a difference on its own unfortunately.

From what I can tell, LoggingSetupRecorder#isColorEnabled is getting called earlier and due to it's call to QuarkusConsole#hasColorSupport() is forcing the instantiation of the JLine console.

In addition to your change to the LogManager, I had to apply the following patch to Quarkus:

diff --git a/bom/application/pom.xml b/bom/application/pom.xml
index e9ab40adbf5..a912e55218e 100644
--- a/bom/application/pom.xml
+++ b/bom/application/pom.xml
@@ -157,7 +157,7 @@
         <dekorate.version>4.1.4</dekorate.version> <!-- Please check with Java Operator SDK team before updating -->
         <maven-invoker.version>3.2.0</maven-invoker.version>
         <awaitility.version>4.2.2</awaitility.version>
-        <jboss-logmanager.version>3.0.6.Final</jboss-logmanager.version>
+        <jboss-logmanager.version>3.1.0.Final-SNAPSHOT</jboss-logmanager.version>
         <flyway.version>10.21.0</flyway.version>
         <yasson.version>3.0.4</yasson.version>
         <!-- liquibase-mongodb is not released everytime with liquibase anymore, but the two versions need to be compatible -->
diff --git a/core/devmode-spi/pom.xml b/core/devmode-spi/pom.xml
index 377814ec671..52e75de8980 100644
--- a/core/devmode-spi/pom.xml
+++ b/core/devmode-spi/pom.xml
@@ -15,6 +15,10 @@
     <description>SPI classes for Quarkus Development mode.</description>
 
     <dependencies>
+        <dependency>
+            <groupId>org.jboss.logmanager</groupId>
+            <artifactId>jboss-logmanager</artifactId>
+        </dependency>
     </dependencies>
 
 </project>
diff --git a/core/devmode-spi/src/main/java/io/quarkus/dev/console/QuarkusConsole.java b/core/devmode-spi/src/main/java/io/quarkus/dev/console/QuarkusConsole.java
index a659d432428..98b493d81e9 100644
--- a/core/devmode-spi/src/main/java/io/quarkus/dev/console/QuarkusConsole.java
+++ b/core/devmode-spi/src/main/java/io/quarkus/dev/console/QuarkusConsole.java
@@ -11,6 +11,7 @@
 import java.util.concurrent.LinkedBlockingDeque;
 import java.util.function.BiPredicate;
 import java.util.function.Consumer;
+import java.util.logging.ConsoleHandler;
 
 public abstract class QuarkusConsole {
 
@@ -108,6 +109,9 @@ public static boolean hasColorSupport() {
         if (Boolean.getBoolean(FORCE_COLOR_SUPPORT)) {
             return true; //assume the IDE run window has color support
         }
+        // force some initialization
+        //noinspection ResultOfMethodCallIgnored
+        org.jboss.logmanager.handlers.ConsoleHandler.hasConsole();
         if (IS_WINDOWS) {
             // On Windows without a known good emulator
             // TODO: optimally we would check if Win32 getConsoleMode has

After using your PR for the log manager and the patch above, the JLine console completely went away

[geoand]

That said, the PR itself is totally valid, we just need to do more in Quarkus to make the problem dissapear

[dmlloyd]

Since dev mode pertains specifically to the console, maybe we should just set the property there (edit: somewhere very early) as well. That would avoid the dependency (there's nothing special about the logmanager fix that merits the dependency, it's just setting the property).

[geoand]

The class I changed is actually part of the prod jar (which is what I've been testing).

But yeah, we can certainly just apply the property in the same manner somewhere early

[geoand]

diff --git a/bom/application/pom.xml b/bom/application/pom.xml
index e9ab40adbf5..a912e55218e 100644
--- a/bom/application/pom.xml
+++ b/bom/application/pom.xml
@@ -157,7 +157,7 @@
         <dekorate.version>4.1.4</dekorate.version> <!-- Please check with Java Operator SDK team before updating -->
         <maven-invoker.version>3.2.0</maven-invoker.version>
         <awaitility.version>4.2.2</awaitility.version>
-        <jboss-logmanager.version>3.0.6.Final</jboss-logmanager.version>
+        <jboss-logmanager.version>3.1.0.Final-SNAPSHOT</jboss-logmanager.version>
         <flyway.version>10.21.0</flyway.version>
         <yasson.version>3.0.4</yasson.version>
         <!-- liquibase-mongodb is not released everytime with liquibase anymore, but the two versions need to be compatible -->
diff --git a/core/devmode-spi/src/main/java/io/quarkus/dev/console/QuarkusConsole.java b/core/devmode-spi/src/main/java/io/quarkus/dev/console/QuarkusConsole.java
index a659d432428..8f1a0072288 100644
--- a/core/devmode-spi/src/main/java/io/quarkus/dev/console/QuarkusConsole.java
+++ b/core/devmode-spi/src/main/java/io/quarkus/dev/console/QuarkusConsole.java
@@ -104,7 +104,16 @@ public synchronized static void uninstallRedirects() {
         redirectsInstalled = false;
     }
 
+    private static void checkAndSetJdkConsole() {
+        // the JLine console in JDK 23+ causes significant startup slowdown, so we avoid it unless the user opted into it
+        String res = System.getProperty("jdk.console");
+        if (res == null) {
+            System.setProperty("jdk.console", "java.base");
+        }
+    }
+
     public static boolean hasColorSupport() {
+        checkAndSetJdkConsole();
         if (Boolean.getBoolean(FORCE_COLOR_SUPPORT)) {
             return true; //assume the IDE run window has color support
         }

works as well

[dmlloyd]

Simpler is better! I like it.

[geoand]

💪🏽

[Karm]

oracle/graal#9884
#43912
#43777
oracle/graal#9727

[geoand]

Thanks @Karm !

[geoand]

@dmlloyd has a new version with your changes been released?

[dmlloyd]

No, not yet, as far as I'm aware. @jamezp WDYT about a release?

[jamezp]

No, not yet, as far as I'm aware. @jamezp WDYT about a release?

I'm on PTO today through Monday, but I can do a release on Tuesday.

[geoand]

Thanks folks!

[geoand]

I opened #44796

[geoand]

@zakkak @jerboaa I am wondering if you guys have any idea how this could be remedied in the JDK itself.
It seems to me that given the desire of the JDK to improve startup times (as evident by the existence and work on Leyden), this change is a large step backwards on that front.

[geoand]

With the introduction of #44796, to see the difference the console makes you need to take the rest-json quickstart and start with no flags and with -Djdk.console=jdk.internal.le (for the new console)

[jerboaa]

@geoand Thanks for the heads-up. I take it's a regression caused by https://bugs.openjdk.org/browse/JDK-8308591? If so the CSR has this piece of information:

JLine implementation no longer spawns native commands with the fix to JDK-8306983, it is desirable to make the JLine
implementation the default Console provider. By lazily instantiating JLine instance, the performance regression can be
improved down from >4% (as in JDK-8299137) to 2%.

If we have a good and reliable benchmark showing the regression then I'll report this upstream. But probably next year as I don't have the cycles to do it this week. I suppose the claim would be a ~16% regression for this particular quarkus app (is this the dev-console or something else)? That sounds serious enough to warrant a report.

[geoand]

Thanks @jerboaa !

The example I mentioned above is a very simple REST application.

The regression we are seeing is in production mode, so there is no dev console.
The reason it shows up in Quarkus is because our logging grabs hold of the console at startup