Reload of dev-services broken #20197

knutwannheden · 2021-09-16T09:32:49Z

Describe the bug

When the Quarkus application is restarted in the dev-mode and a dev-service also needs to be restarted, the application can after the restart no longer access the newly started dev-service.

I debugged this in the case of a PostgreSQL database, where I explicitly set the property quarkus.datasource.devservices.image-name in application.properties to cause the dev-service to be force-restarted (which in itself may be a separate bug). The Docker container is properly restarted (listening on a new port) and the new configuration is correctly exposed using RunTimeConfigurationDefaultBuildItem instances. But when the application is restarted and ends up in io.quarkus.deployment.steps.ConfigGenerationBuildStep#generateConfigClass() the method immediately returns as liveReloadBuildItem.isLiveReload() evaluates to true. Consequently the RunTimeConfigurationDefaultBuildItem instances have no effect and the Quarkus application attempts to access the database using the old port rather than the new port.

Expected behavior

The Quarkus application should after a restart in dev-mode be able to access any restarted dev-services.

Actual behavior

The dev-services get restarted and will typically be listening on new ports, but the restarted Quarkus application will try to access the dev-service on the ports it used before the restart, which then fails.

11:19:36.278 ERROR [io.qu.de.de.IsolatedDevModeMain] (Aesh InputStream Reader) Failed to start quarkus: java.lang.RuntimeException: java.lang.RuntimeException: Failed to start quarkus
        at io.quarkus.dev.appstate.ApplicationStateNotification.waitForApplicationStart(ApplicationStateNotification.java:51)
        at io.quarkus.runner.bootstrap.StartupActionImpl.runMainClass(StartupActionImpl.java:109)
        at io.quarkus.deployment.dev.IsolatedDevModeMain.restartApp(IsolatedDevModeMain.java:227)
        at io.quarkus.deployment.dev.IsolatedDevModeMain.restartCallback(IsolatedDevModeMain.java:208)
        at io.quarkus.deployment.dev.RuntimeUpdatesProcessor.doScan(RuntimeUpdatesProcessor.java:499)
        at io.quarkus.deployment.console.ConsoleStateManager.forceRestart(ConsoleStateManager.java:136)
        at io.quarkus.deployment.console.ConsoleStateManager.lambda$installBuiltins$0(ConsoleStateManager.java:98)
        at io.quarkus.deployment.console.ConsoleStateManager$1.accept(ConsoleStateManager.java:73)
        at io.quarkus.deployment.console.ConsoleStateManager$1.accept(ConsoleStateManager.java:46)
        at io.quarkus.deployment.console.AeshConsole.lambda$setup$1(AeshConsole.java:199)
        at org.aesh.terminal.EventDecoder.accept(EventDecoder.java:118)
        at org.aesh.terminal.EventDecoder.accept(EventDecoder.java:31)
        at org.aesh.terminal.io.Decoder.write(Decoder.java:133)
        at org.aesh.readline.tty.terminal.TerminalConnection.openBlocking(TerminalConnection.java:216)
        at org.aesh.readline.tty.terminal.TerminalConnection.openBlocking(TerminalConnection.java:203)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.RuntimeException: Failed to start quarkus
        at io.quarkus.runner.ApplicationImpl.doStart(ApplicationImpl.zig:1377)
        at io.quarkus.runtime.Application.start(Application.java:101)
        at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:101)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:66)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:42)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:119)
        at io.quarkus.runner.GeneratedMain.main(GeneratedMain.zig:29)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.quarkus.runner.bootstrap.StartupActionImpl$1.run(StartupActionImpl.java:98)
        ... 1 more
Caused by: org.flywaydb.core.internal.exception.FlywaySqlException: Unable to obtain connection from database: Connection to localhost:49248 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL State  : 08001
Error Code : 0
Message    : Connection to localhost:49248 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.

        at org.flywaydb.core.internal.jdbc.JdbcUtils.openConnection(JdbcUtils.java:66)
        at org.flywaydb.core.internal.jdbc.JdbcConnectionFactory.<init>(JdbcConnectionFactory.java:68)
        at org.flywaydb.core.Flyway.execute(Flyway.java:502)
        at org.flywaydb.core.Flyway.migrate(Flyway.java:168)
        at io.quarkus.flyway.runtime.FlywayRecorder.doStartActions(FlywayRecorder.java:75)
        at io.quarkus.deployment.steps.FlywayProcessor$createBeansAndStartActions-1520831253.deploy_0(FlywayProcessor$createBeansAndStartActions-1520831253.zig:84)
        at io.quarkus.deployment.steps.FlywayProcessor$createBeansAndStartActions-1520831253.deploy(FlywayProcessor$createBeansAndStartActions-1520831253.zig:40)
        at io.quarkus.runner.ApplicationImpl.doStart(ApplicationImpl.zig:1086)
        ... 12 more
Caused by: org.postgresql.util.PSQLException: Connection to localhost:49248 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
        at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:303)
        at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:51)
        at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:223)
        at org.postgresql.Driver.makeConnection(Driver.java:465)
        at org.postgresql.Driver.connect(Driver.java:264)
        at io.agroal.pool.ConnectionFactory.createConnection(ConnectionFactory.java:204)
        at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:470)
        at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:452)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at io.agroal.pool.util.PriorityScheduledExecutor.beforeExecute(PriorityScheduledExecutor.java:68)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1126)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        ... 1 more
Caused by: java.net.ConnectException: Connection refused: connect
        at java.base/java.net.PlainSocketImpl.waitForConnect(Native Method)
        at java.base/java.net.PlainSocketImpl.socketConnect(PlainSocketImpl.java:107)
        at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:399)
        at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:242)
        at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:224)
        at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:403)
        at java.base/java.net.Socket.connect(Socket.java:609)
        at org.postgresql.core.PGStream.createSocket(PGStream.java:231)
        at org.postgresql.core.PGStream.<init>(PGStream.java:95)
        at org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:98)
        at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:213)
        ... 12 more

How to Reproduce?

Create a Quarkus application with a PostgreSQL database and a simple Flyway migration script
Set quarkus.datasource.devservices.image-name=postgres:13 and quarkus.flyway.migrate-at-start=true in application.properties
Start the application in dev-mod
Force-restart the application using the keyboard shortcut s
Now an exception should be visible in the console

Output of `uname -a` or `ver`

MSYS_NT-10.0-22000 WIN10-KNUT 3.1.7-340.x86_64 2020-10-23 13:08 UTC x86_64 Msys

Output of `java -version`

openjdk version "11.0.9" 2020-10-20 LTS OpenJDK Runtime Environment Zulu11.43+22-SA (build 11.0.9+11-LTS) OpenJDK 64-Bit Server VM Zulu11.43+22-SA (build 11.0.9+11-LTS, mixed mode)

GraalVM version (if different from Java)

No response

Quarkus version or git rev

2.2.2.Final

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

Maven 3.8.1

Additional information

No response

The text was updated successfully, but these errors were encountered:

quarkus-bot · 2021-09-16T09:32:51Z

/cc @stuartwdouglas

machi1990 · 2021-09-16T09:35:29Z

I think this is a duplicate of #17069 which will be fixed by #19046

knutwannheden · 2021-09-16T09:45:12Z

Yes, looks like it.

knutwannheden · 2021-09-16T09:47:26Z

I will investigate the problem with the setting of the image name causing a reload a bit further and possibly report an issue for that.

knutwannheden · 2021-09-16T18:01:26Z

For the other issue I filed #20214.

machi1990 · 2021-09-16T19:23:37Z

Thanks @knutwannheden, I'll be marking this as duplicate and close it.

knutwannheden added the kind/bug Something isn't working label Sep 16, 2021

quarkus-bot bot added the area/devservices label Sep 16, 2021

machi1990 added the triage/duplicate This issue or pull request already exists label Sep 16, 2021

machi1990 closed this as completed Sep 16, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Reload of dev-services broken #20197

Reload of dev-services broken #20197

knutwannheden commented Sep 16, 2021

quarkus-bot bot commented Sep 16, 2021

machi1990 commented Sep 16, 2021

knutwannheden commented Sep 16, 2021

knutwannheden commented Sep 16, 2021

knutwannheden commented Sep 16, 2021

machi1990 commented Sep 16, 2021

Reload of dev-services broken #20197

Reload of dev-services broken #20197

Comments

knutwannheden commented Sep 16, 2021

Describe the bug

Expected behavior

Actual behavior

How to Reproduce?

Output of uname -a or ver

Output of java -version

GraalVM version (if different from Java)

Quarkus version or git rev

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

Additional information

quarkus-bot bot commented Sep 16, 2021

machi1990 commented Sep 16, 2021

knutwannheden commented Sep 16, 2021

knutwannheden commented Sep 16, 2021

knutwannheden commented Sep 16, 2021

machi1990 commented Sep 16, 2021

Output of `uname -a` or `ver`

Output of `java -version`

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