Restarts are slow when using spring-boot-devtools and spring-boot-docker-compose

[joshlong]

not sure if this is a bug but it's interesting. you can see it in (in)action here https://github.com/spring-tips/development-containers-with-docker-compose-and-testcontainers

[wilkinsona]

We call docker compose ps twice during a restart – once for hasRunningServices() and once for getRunningServices() – and it isn't particularly quick. With a single service running, time docker compose ps shows a total time of roughly 0.5 seconds on the first call. Subsequent calls are quicker at around 0.15 seconds. Perhaps we can rework things so that we make a single call to docker compose ps.

[wilkinsona]

Creating a new DockerCli instance is also quite slow, in particular the calls to getDockerCommand(this.processRunner) and getDockerComposeCommand(this.processRunner). Each takes ~0.3s. We may be able to cache these in static fields so that they're reused across restarts.

Waiting for the services to be ready is also rather slow even though, in this case, there's only a single service. When checking that Postgres is ready, the read timeout in TcpConnectServiceReadinessCheck pops and it this point we determine that the service is ready. This accounts for 0.2s of the restart time.

[wilkinsona]

https://github.com/wilkinsona/spring-boot/tree/gh-35435 addresses the things described above other than the readiness check.

[philwebb]

Doing three devtools restarts...

Before:

2023-05-17T15:52:53.275-07:00  INFO 63496 --- [  restartedMain] com.example.demo.DemoApplication         : Started DemoApplication in 2.101 seconds (process running for 19.261)
2023-05-17T15:52:58.933-07:00  INFO 63496 --- [  restartedMain] com.example.demo.DemoApplication         : Started DemoApplication in 1.185 seconds (process running for 24.919)
2023-05-17T15:53:03.614-07:00  INFO 63496 --- [  restartedMain] com.example.demo.DemoApplication         : Started DemoApplication in 1.21 seconds (process running for 29.6)

After:

2023-05-17T15:54:36.074-07:00  INFO 63657 --- [  restartedMain] com.example.demo.DemoApplication         : Started DemoApplication in 0.704 seconds (process running for 10.27)
2023-05-17T15:54:46.307-07:00  INFO 63657 --- [  restartedMain] com.example.demo.DemoApplication         : Started DemoApplication in 0.717 seconds (process running for 20.503)
2023-05-17T15:54:55.442-07:00  INFO 63657 --- [  restartedMain] com.example.demo.DemoApplication         : Started DemoApplication in 0.632 seconds (process running for 29.638)