Make it easier to tell that DevTools restart has been disabled due to HotSwapAgent being present

[danielpgross]

Testing using a simple spring-boot starter generated by initializr: Download starter

With identical JDKs and maven versions, devtools works fine on Ubuntu 16.04 but does not work on macOS 10.13.6. The symptoms are:

1. The main thread is called main instead of restartedMain.
2. The application does not restart automatically (even though it should) upon changes to files in the classpath.

I have tested this going back to older versions and determined that the first version in which this broke is 1.5.3.

To reproduce:

1. Download starter
2. Unzip the starter and cd into the unzipped directory.
3. Run mvn spring-boot:run

Testcases below:
macOS

$ mvn -v
Apache Maven 3.5.4 (1edded0938998edf8bf061f1ceb3cfdeccf443fe; 2018-06-17T14:33:14-04:00)
Maven home: /usr/local/Cellar/maven/3.5.4/libexec
Java version: 1.8.0_181, vendor: Oracle Corporation, runtime: /Library/Java/JavaVirtualMachines/jdk1.8.0_181.jdk/Contents/Home/jre
Default locale: en_CA, platform encoding: UTF-8
OS name: "mac os x", version: "10.13.6", arch: "x86_64", family: "mac"

[INFO] --- spring-boot-maven-plugin:1.5.16.RELEASE:run (default-cli) @ demo ---
[INFO] Attaching agents: []
09:24:58.767 [main] DEBUG org.springframework.boot.devtools.settings.DevToolsSettings - Included patterns for restart : []
09:24:58.770 [main] DEBUG org.springframework.boot.devtools.settings.DevToolsSettings - Excluded patterns for restart : [/spring-boot-starter/target/classes/, /spring-boot-autoconfigure/target/classes/, /spring-boot-starter-[\w-]+/, /spring-boot/target/classes/, /spring-boot-actuator/target/classes/, /spring-boot-devtools/target/classes/]
09:24:58.771 [main] DEBUG org.springframework.boot.devtools.restart.ChangeableUrls - Matching URLs for reloading : [file:/Users/danielgross/volatile/Downloads/demo-1516/demo/target/classes/]

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::       (v1.5.16.RELEASE)

2018-09-17 09:24:59.169  INFO 7807 --- [           main] com.example.demo.DemoApplication         : Starting DemoApplication on daniel with PID 7807 (/Users/danielgross/volatile/Downloads/demo-1516/demo/target/classes started by danielgross in /Users/danielgross/volatile/Downloads/demo-1516/demo)
2018-09-17 09:24:59.170  INFO 7807 --- [           main] com.example.demo.DemoApplication         : No active profile set, falling back to default profiles: default
2018-09-17 09:24:59.217  INFO 7807 --- [           main] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@49c43f4e: startup date [Mon Sep 17 09:24:59 EDT 2018]; root of context hierarchy
2018-09-17 09:24:59.694  INFO 7807 --- [           main] o.s.b.d.a.OptionalLiveReloadServer       : LiveReload server is running on port 35729
2018-09-17 09:24:59.717  INFO 7807 --- [           main] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
2018-09-17 09:24:59.730  INFO 7807 --- [           main] com.example.demo.DemoApplication         : Started DemoApplication in 0.989 seconds (JVM running for 1.268)
2018-09-17 09:24:59.731  INFO 7807 --- [       Thread-6] s.c.a.AnnotationConfigApplicationContext : Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@49c43f4e: startup date [Mon Sep 17 09:24:59 EDT 2018]; root of context hierarchy
2018-09-17 09:24:59.733  INFO 7807 --- [       Thread-6] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans on shutdown

Ubuntu

$ mvn -v
Apache Maven 3.5.4 (1edded0938998edf8bf061f1ceb3cfdeccf443fe; 2018-06-17T18:33:14Z)
Maven home: /opt/apache-maven
Java version: 1.8.0_181, vendor: Oracle Corporation, runtime: /usr/lib/jvm/java-8-oracle/jre
Default locale: en_US, platform encoding: ANSI_X3.4-1968
OS name: "linux", version: "4.4.0-1065-aws", arch: "amd64", family: "unix"

[INFO] --- spring-boot-maven-plugin:1.5.16.RELEASE:run (default-cli) @ demo ---
[INFO] Attaching agents: []
13:28:13.786 [main] DEBUG org.springframework.boot.devtools.settings.DevToolsSettings - Included patterns for restart : []
13:28:13.795 [main] DEBUG org.springframework.boot.devtools.settings.DevToolsSettings - Excluded patterns for restart : [/spring-boot-starter/target/classes/, /spring-boot-autoconfigure/target/classes/, /spring-boot-starter-[\w-]+/, /spring-boot/target/classes/, /spring-boot-actuator/target/classes/, /spring-boot-devtools/target/classes/]
13:28:13.795 [main] DEBUG org.springframework.boot.devtools.restart.ChangeableUrls - Matching URLs for reloading : [file:/home/ubuntu/demo/target/classes/]

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::       (v1.5.16.RELEASE)

2018-09-17 13:28:14.384  INFO 11885 --- [  restartedMain] com.example.demo.DemoApplication         : Starting DemoApplication on demo with PID 11885 (/home/ubuntu/demo/target/classes started by ubuntu in /home/ubuntu/demo)
2018-09-17 13:28:14.388  INFO 11885 --- [  restartedMain] com.example.demo.DemoApplication         : No active profile set, falling back to default profiles: default
2018-09-17 13:28:14.541  INFO 11885 --- [  restartedMain] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@3832139c: startup date [Mon Sep 17 13:28:14 UTC 2018]; root of context hierarchy
2018-09-17 13:28:15.815  INFO 11885 --- [  restartedMain] o.s.b.d.a.OptionalLiveReloadServer       : LiveReload server is running on port 35729
2018-09-17 13:28:15.871  INFO 11885 --- [  restartedMain] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
2018-09-17 13:28:15.909  INFO 11885 --- [  restartedMain] com.example.demo.DemoApplication         : Started DemoApplication in 2.081 seconds (JVM running for 2.643)
2018-09-17 13:28:15.918  INFO 11885 --- [       Thread-8] s.c.a.AnnotationConfigApplicationContext : Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@3832139c: startup date [Mon Sep 17 13:28:14 UTC 2018]; root of context hierarchy
2018-09-17 13:28:15.923  INFO 11885 --- [       Thread-8] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans on shutdown

[bclozel]

I'm also running macOS 10.13.6 and it works fine.

I've just tried with my local maven version as well as the wrapper:

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::       (v1.5.16.RELEASE)

2018-09-17 15:55:01.329  INFO 3677 --- [  restartedMain] com.example.demo.DemoApplication         : Starting DemoApplication on Brians-MacBook-Pro.local with PID 3677 (/Users/bclozel/workspace/demo/target/classes started by bclozel in /Users/bclozel/workspace/demo)
2018-09-17 15:55:01.330  INFO 3677 --- [  restartedMain] com.example.demo.DemoApplication         : No active profile set, falling back to default profiles: default
2018-09-17 15:55:01.382  INFO 3677 --- [  restartedMain] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@1f905801: startup date [Mon Sep 17 15:55:01 CEST 2018]; root of context hierarchy
2018-09-17 15:55:01.938  INFO 3677 --- [  restartedMain] o.s.b.d.a.OptionalLiveReloadServer       : LiveReload server is running on port 35729
2018-09-17 15:55:01.958  INFO 3677 --- [  restartedMain] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
2018-09-17 15:55:01.969  INFO 3677 --- [  restartedMain] com.example.demo.DemoApplication         : Started DemoApplication in 1.009 seconds (JVM running for 1.323)
2018-09-17 15:55:01.976  INFO 3677 --- [       Thread-8] s.c.a.AnnotationConfigApplicationContext : Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@1f905801: startup date [Mon Sep 17 15:55:01 CEST 2018]; root of context hierarchy
2018-09-17 15:55:01.979  INFO 3677 --- [       Thread-8] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans on shutdown

➜  demo java -version
openjdk version "1.8.0_181"
OpenJDK Runtime Environment (Zulu 8.31.0.1-macosx) (build 1.8.0_181-b02)
OpenJDK 64-Bit Server VM (Zulu 8.31.0.1-macosx) (build 25.181-b02, mixed mode)

Could you try a couple of things:

• ./mvnw dependency:purge-local-repository
• then ./mvnw spring-boot:run

[danielpgross]

Thanks for the quick response!
Just tried that, but the result is the same as before:

$ ./mvnw dependency:purge-local-repository
/Users/danielgross/Downloads/demo-1516/demo
Downloading https://repo1.maven.org/maven2/org/apache/maven/apache-maven/3.5.4/apache-maven-3.5.4-bin.zip

... (snip) ...

[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 15.758 s
[INFO] Finished at: 2018-09-17T10:46:54-04:00
[INFO] ------------------------------------------------------------------------

$ ./mvnw spring-boot:run
/Users/danielgross/Downloads/demo-1516/demo
[INFO] Scanning for projects...
[INFO] 
[INFO] --------------------------< com.example:demo >--------------------------
[INFO] Building demo 0.0.1-SNAPSHOT
[INFO] --------------------------------[ jar ]---------------------------------
[INFO] 
[INFO] >>> spring-boot-maven-plugin:1.5.16.RELEASE:run (default-cli) > test-compile @ demo >>>
[INFO] 
[INFO] --- maven-resources-plugin:2.7:resources (default-resources) @ demo ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 1 resource
[INFO] Copying 0 resource
[INFO] 
[INFO] --- maven-compiler-plugin:3.1:compile (default-compile) @ demo ---
[INFO] Changes detected - recompiling the module!
[INFO] Compiling 1 source file to /Users/danielgross/volatile/Downloads/demo-1516/demo/target/classes
[INFO] 
[INFO] --- maven-resources-plugin:2.7:testResources (default-testResources) @ demo ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] skip non existing resourceDirectory /Users/danielgross/volatile/Downloads/demo-1516/demo/src/test/resources
[INFO] 
[INFO] --- maven-compiler-plugin:3.1:testCompile (default-testCompile) @ demo ---
[INFO] Changes detected - recompiling the module!
[INFO] Compiling 1 source file to /Users/danielgross/volatile/Downloads/demo-1516/demo/target/test-classes
[INFO] 
[INFO] <<< spring-boot-maven-plugin:1.5.16.RELEASE:run (default-cli) < test-compile @ demo <<<
[INFO] 
[INFO] 
[INFO] --- spring-boot-maven-plugin:1.5.16.RELEASE:run (default-cli) @ demo ---
[INFO] Attaching agents: []
10:47:00.374 [main] DEBUG org.springframework.boot.devtools.settings.DevToolsSettings - Included patterns for restart : []
10:47:00.377 [main] DEBUG org.springframework.boot.devtools.settings.DevToolsSettings - Excluded patterns for restart : [/spring-boot-starter/target/classes/, /spring-boot-autoconfigure/target/classes/, /spring-boot-starter-[\w-]+/, /spring-boot/target/classes/, /spring-boot-actuator/target/classes/, /spring-boot-devtools/target/classes/]
10:47:00.377 [main] DEBUG org.springframework.boot.devtools.restart.ChangeableUrls - Matching URLs for reloading : [file:/Users/danielgross/volatile/Downloads/demo-1516/demo/target/classes/]

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::       (v1.5.16.RELEASE)

2018-09-17 10:47:00.750  INFO 8474 --- [           main] com.example.demo.DemoApplication         : Starting DemoApplication on daniel with PID 8474 (/Users/danielgross/volatile/Downloads/demo-1516/demo/target/classes started by danielgross in /Users/danielgross/volatile/Downloads/demo-1516/demo)
2018-09-17 10:47:00.751  INFO 8474 --- [           main] com.example.demo.DemoApplication         : No active profile set, falling back to default profiles: default
2018-09-17 10:47:00.802  INFO 8474 --- [           main] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@49c43f4e: startup date [Mon Sep 17 10:47:00 EDT 2018]; root of context hierarchy
2018-09-17 10:47:01.329  INFO 8474 --- [           main] o.s.b.d.a.OptionalLiveReloadServer       : LiveReload server is running on port 35729
2018-09-17 10:47:01.353  INFO 8474 --- [           main] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
2018-09-17 10:47:01.365  INFO 8474 --- [           main] com.example.demo.DemoApplication         : Started DemoApplication in 1.018 seconds (JVM running for 1.315)
2018-09-17 10:47:01.366  INFO 8474 --- [       Thread-6] s.c.a.AnnotationConfigApplicationContext : Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@49c43f4e: startup date [Mon Sep 17 10:47:00 EDT 2018]; root of context hierarchy
2018-09-17 10:47:01.367  INFO 8474 --- [       Thread-6] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans on shutdown
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 3.820 s
[INFO] Finished at: 2018-09-17T10:47:01-04:00
[INFO] ------------------------------------------------------------------------

[wilkinsona]

It sounds like the Restarter has been disabled which can be done with a system property. If you can debug your application when it's launched, it would be interesting to know what's happening in this code:

spring-boot/spring-boot-devtools/src/main/java/org/springframework/boot/devtools/restart/RestartApplicationListener.java

Lines 59 to 72 in c39bc39

	private void onApplicationStartingEvent(ApplicationStartingEvent event) {
	// It's too early to use the Spring environment but we should still allow
	// users to disable restart using a System property.
	String enabled = System.getProperty(ENABLED_PROPERTY);
	if (enabled == null || Boolean.parseBoolean(enabled)) {
	String[] args = event.getArgs();
	DefaultRestartInitializer initializer = new DefaultRestartInitializer();
	boolean restartOnInitialize = !AgentReloader.isActive();
	Restarter.initialize(args, false, initializer, restartOnInitialize);
	}
	else {
	Restarter.disable();
	}
	}

[danielpgross]

I was able to run the debugger and from what I can see, the Restarter actually is being initialized (it is not disabled). See below:

[bclozel]

This is a wild guess, but do you happen to have JRebel configured on that JVM?

In gh-3095, we've updated the restarter to not restart the application if you have a reloading agent like JRebel - but the livereload server is still available.

If that's the case, this is way older than v1.5.3 and is not OS-dependent; it's just your local setup.