Hotswap fails with gradle, Intellij & Windows

[Agraphie]

Hi there,

I'm using a simple Spring Boot project (just web dependency to get a controller) with Intellij 2020.1, Gradle 6.4.1, Dcevm 11.0.7 and Windows 10. Hotswapping works exactly once and then never again. After doing changes a second time it get the following error

Execution failed for task ':compileJava'.
> Failed to clean up stale outputs

Couldn't delete C:\Users\u\IdeaProjects\demohotswap\build\classes\java\main\com\example\demo\DemoController.class

Seems like the Filewatcher is locking up the file and gradle cannot delete it anymore. If I choose the internal idea compiler to run via the following properties, hotswapping works without any issues.

Any ideas? Did this constellation with gradle ever work?

[Agraphie]

To give some update: I tried all (Dcevm) jdk versions and the last one which worked for me (without using the internal intellij compiler) is 11.0.6+1. Starting with 11.0.7+1 the hotswapping fails with the error above.

[skybber]

Are you using integrated HotswapAgent? You can find it in lib/hotswap/ folder. There is also version.properties file in hotswap-agent.jar

[Agraphie]

Thanks for the hint. I'm using the integrated HotSwap Agent. The last jdk which works is this https://github.com/TravaOpenJDK/trava-jdk-11-dcevm/releases/tag/dcevm-11.0.6%2B1 and the earliest one which doesn't work is this https://github.com/TravaOpenJDK/trava-jdk-11-dcevm/releases/tag/dcevm-11.0.7%2B1

I checked both their version.properties and for both the content is version=1.4.0. So I assume I need to raise an issue in the other repository?

[skybber]

It looks much more like DCEVM problem, but I'm not aware of any change related to file-lock in dcevm-11.0.7. Is it possible to detect which process locks the DemoController.class?

[Agraphie]

I did a heap dump and looked a bit around, but I don't really know what to look for... The only thing I can see with Resourcemonitor is that with version 11.0.6+1 nothing is locking the DemoController.class, while with 11.0.7+1 java.exe (who knew) is locking the file. Do you have an idea what I could look for?

[Agraphie]

I forgot to mention that there is a different output in the versions. In 11.0.6+1 this warning appears

WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.hotswap.agent.util.ReflectionHelper (file:/C:/Users/u/IdeaProjects/demohotswap123/jdk/dcevm-11.0.6+1/lib/hotswap/hotswap-agent.jar) to method com.sun.beans.util.Cache.clear()
WARNING: Please consider reporting this to the maintainers of org.hotswap.agent.util.ReflectionHelper
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release

But in 11.0.7+1 it's gone. Not sure if it's relevant...

[skybber]

It's OK, invalid access to com.sun.beans.util.Cache is fixed in 11.0.7

[Agraphie]

Hm then that won't be the issue. I mean I can upload a heap dump and maybe someone else has an idea what to look for?

[skybber]

You can try last dcevm11.0.7+4. If you use -XX:-AllowEnhancedClassRedefinition, then dcevm is turned off and the JVM works like standard JVM. Let's look what happens.

[Agraphie]

If I add that option with 11.0.7+4 I can rebuild the project multiple times without any error and get the usual hotswap capabilities of the jvm and idea. If I remove the option again I get the error again...

[skybber]

I forgot that '-XX:-AllowEnhancedClassRedefinition` turns off HotswapAgent. So any conclusion can be made about source of this problem...

[Agraphie]

Is it possible that the file watcher (or so) on Windows locks the file after it reloaded it once? When gradle then tries to delete the stale file it gets the exception above. Btw here are the debug outputs. Maybe it helps

HOTSWAP AGENT: 16:45:50.284 DEBUG (org.hotswap.agent.watch.nio.TreeWatcherNIO) - Watch event 'ENTRY_MODIFY' on 'C:\Users\u\IdeaProjects\demo\build\classes\java\main\com\example\demo\DemoController.class' --> com\example\demo\DemoController.class
HOTSWAP AGENT: 16:45:50.284 DEBUG (org.hotswap.agent.watch.nio.TreeWatcherNIO) - Watch event 'ENTRY_DELETE' on 'C:\Users\u\IdeaProjects\demo\build\classes\java\main\com\example\demo\DemoController.class' --> com\example\demo\DemoController.class
HOTSWAP AGENT: 16:45:50.284 DEBUG (org.hotswap.agent.watch.nio.TreeWatcherNIO) - Watch event 'ENTRY_MODIFY' on 'C:\Users\u\IdeaProjects\demo\build\classes\java\main\com\example\demo' --> com\example\demo
HOTSWAP AGENT: 16:45:50.401 DEBUG (org.hotswap.agent.watch.nio.TreeWatcherNIO) - Watch event 'ENTRY_CREATE' on 'C:\Users\u\IdeaProjects\demo\build\classes\java\main\com\example\demo\DemoController.class' --> com\example\demo\DemoController.class
HOTSWAP AGENT: 16:45:50.402 DEBUG (org.hotswap.agent.watch.nio.TreeWatcherNIO) - Watch event 'ENTRY_MODIFY' on 'C:\Users\u\IdeaProjects\demo\build\classes\java\main\com\example\demo\DemoController.class' --> com\example\demo\DemoController.class
HOTSWAP AGENT: 16:45:50.402 DEBUG (org.hotswap.agent.watch.nio.TreeWatcherNIO) - Watch event 'ENTRY_MODIFY' on 'C:\Users\u\IdeaProjects\demo\build\classes\java\main\com\example\demo\DemoController.class' --> com\example\demo\DemoController.class
HOTSWAP AGENT: 16:45:50.420 DEBUG (org.hotswap.agent.watch.nio.TreeWatcherNIO) - Watch event 'ENTRY_MODIFY' on 'C:\Users\u\IdeaProjects\demo\build\classes\java\main\com\example\demo' --> com\example\demo
HOTSWAP AGENT: 16:45:50.437 DEBUG (org.hotswap.agent.annotation.handler.WatchEventCommand) - Executing resource changed method watchReload on class org.hotswap.agent.plugin.hotswapper.HotswapperPlugin for event WatchFileEvent on path C:\Users\u\IdeaProjects\demo\build\classes\java\main\com\example\demo\DemoController.class for event ENTRY_MODIFY
HOTSWAP AGENT: 16:45:50.438 DEBUG (org.hotswap.agent.plugin.hotswapper.HotswapperPlugin) - Class com.example.demo.DemoController will be reloaded from URL file:/C:/Users/u/IdeaProjects/demo/build/classes/java/main/com/example/demo/DemoController.class
HOTSWAP AGENT: 16:45:50.547 DEBUG (org.hotswap.agent.command.impl.SchedulerImpl) - Executing pluginManager.hotswap([class com.example.demo.DemoController])
HOTSWAP AGENT: 16:45:50.549 RELOAD (org.hotswap.agent.config.PluginManager) - Reloading classes [com.example.demo.DemoController] (autoHotswap)
HOTSWAP AGENT: 16:45:50.549 DEBUG (org.hotswap.agent.annotation.handler.WatchEventCommand) - Executing resource changed method watchReload on class org.hotswap.agent.plugin.hotswapper.HotswapperPlugin for event WatchFileEvent on path C:\Users\u\IdeaProjects\demo\build\classes\java\main\com\example\demo\DemoController.class for event ENTRY_MODIFY
HOTSWAP AGENT: 16:45:50.549 DEBUG (org.hotswap.agent.annotation.handler.WatchEventCommand) - Executing resource changed method watchReload on class org.hotswap.agent.plugin.hotswapper.HotswapperPlugin for event WatchFileEvent on path C:\Users\u\IdeaProjects\demo\build\classes\java\main\com\example\demo\DemoController.class for event ENTRY_MODIFY
HOTSWAP AGENT: 16:45:50.549 DEBUG (org.hotswap.agent.plugin.hotswapper.HotswapperPlugin) - Class com.example.demo.DemoController will be reloaded from URL file:/C:/Users/u/IdeaProjects/demo/build/classes/java/main/com/example/demo/DemoController.class
HOTSWAP AGENT: 16:45:50.549 DEBUG (org.hotswap.agent.annotation.handler.WatchEventCommand) - Executing resource changed method watchReload on class org.hotswap.agent.plugin.hotswapper.HotswapperPlugin for event WatchFileEvent on path C:\Users\u\IdeaProjects\demo\build\classes\java\main\com\example\demo\DemoController.class for event ENTRY_CREATE
HOTSWAP AGENT: 16:45:50.549 DEBUG (org.hotswap.agent.plugin.hotswapper.HotswapperPlugin) - Class com.example.demo.DemoController will be reloaded from URL file:/C:/Users/u/IdeaProjects/demo/build/classes/java/main/com/example/demo/DemoController.class
HOTSWAP AGENT: 16:45:50.550 DEBUG (org.hotswap.agent.plugin.hotswapper.HotswapperPlugin) - Class com.example.demo.DemoController will be reloaded from URL file:/C:/Users/u/IdeaProjects/demo/build/classes/java/main/com/example/demo/DemoController.class
HOTSWAP AGENT: 16:45:50.550 DEBUG (org.hotswap.agent.plugin.jdk.JdkPlugin) - Flushing com.example.demo.DemoController from com.sun.beans.introspect.ClassInfo cache
HOTSWAP AGENT: 16:45:50.551 DEBUG (org.hotswap.agent.plugin.jdk.JdkPlugin) - Flushing com.example.demo.DemoController from introspector
HOTSWAP AGENT: 16:45:50.553 DEBUG (org.hotswap.agent.plugin.jdk.JdkPlugin) - Flushing com.example.demo.DemoController from ObjectStreamClass caches
HOTSWAP AGENT: 16:45:50.629 DEBUG (org.hotswap.agent.plugin.jdk.JdkPlugin) - Flushing com.example.demo.DemoController from com.sun.beans.introspect.ClassInfo cache
HOTSWAP AGENT: 16:45:50.631 DEBUG (org.hotswap.agent.plugin.jdk.JdkPlugin) - Flushing com.example.demo.DemoController from introspector
HOTSWAP AGENT: 16:45:50.632 DEBUG (org.hotswap.agent.plugin.jdk.JdkPlugin) - Flushing com.example.demo.DemoController from ObjectStreamClass caches
HOTSWAP AGENT: 16:45:50.739 DEBUG (org.hotswap.agent.config.PluginManager) - ... reloaded classes [com.example.demo.DemoController] (autoHotswap)
HOTSWAP AGENT: 16:45:50.906 DEBUG (org.hotswap.agent.command.impl.SchedulerImpl) - Executing pluginManager.hotswap([class com.example.demo.DemoController])
HOTSWAP AGENT: 16:45:50.906 RELOAD (org.hotswap.agent.config.PluginManager) - Reloading classes [com.example.demo.DemoController] (autoHotswap)
HOTSWAP AGENT: 16:45:50.915 DEBUG (org.hotswap.agent.plugin.jdk.JdkPlugin) - Flushing com.example.demo.DemoController from com.sun.beans.introspect.ClassInfo cache
HOTSWAP AGENT: 16:45:50.917 DEBUG (org.hotswap.agent.plugin.jdk.JdkPlugin) - Flushing com.example.demo.DemoController from introspector
HOTSWAP AGENT: 16:45:50.918 DEBUG (org.hotswap.agent.plugin.jdk.JdkPlugin) - Flushing com.example.demo.DemoController from ObjectStreamClass caches
HOTSWAP AGENT: 16:45:51.078 DEBUG (org.hotswap.agent.config.PluginManager) - ... reloaded classes [com.example.demo.DemoController] (autoHotswap)

And after the second change and build

HOTSWAP AGENT: 16:45:58.432 DEBUG (org.hotswap.agent.watch.nio.TreeWatcherNIO) - Watch event 'ENTRY_MODIFY' on 'C:\Users\u\IdeaProjects\demo\build\classes\java\main\com\example\demo\DemoController.class' --> com\example\demo\DemoController.class
HOTSWAP AGENT: 16:45:58.566 DEBUG (org.hotswap.agent.annotation.handler.WatchEventCommand) - Executing resource changed method watchReload on class org.hotswap.agent.plugin.hotswapper.HotswapperPlugin for event WatchFileEvent on path C:\Users\u\IdeaProjects\demo\build\classes\java\main\com\example\demo\DemoController.class for event ENTRY_MODIFY
HOTSWAP AGENT: 16:45:58.566 DEBUG (org.hotswap.agent.plugin.hotswapper.HotswapperPlugin) - Class com.example.demo.DemoController will be reloaded from URL file:/C:/Users/u/IdeaProjects/demo/build/classes/java/main/com/example/demo/DemoController.class
HOTSWAP AGENT: 16:45:58.673 DEBUG (org.hotswap.agent.command.impl.SchedulerImpl) - Executing pluginManager.hotswap([class com.example.demo.DemoController])
HOTSWAP AGENT: 16:45:58.674 RELOAD (org.hotswap.agent.config.PluginManager) - Reloading classes [com.example.demo.DemoController] (autoHotswap)
HOTSWAP AGENT: 16:45:58.682 DEBUG (org.hotswap.agent.plugin.jdk.JdkPlugin) - Flushing com.example.demo.DemoController from com.sun.beans.introspect.ClassInfo cache
HOTSWAP AGENT: 16:45:58.685 DEBUG (org.hotswap.agent.plugin.jdk.JdkPlugin) - Flushing com.example.demo.DemoController from introspector
HOTSWAP AGENT: 16:45:58.686 DEBUG (org.hotswap.agent.plugin.jdk.JdkPlugin) - Flushing com.example.demo.DemoController from ObjectStreamClass caches
HOTSWAP AGENT: 16:45:58.752 DEBUG (org.hotswap.agent.config.PluginManager) - ... reloaded classes [com.example.demo.DemoController] (autoHotswap)

[cdalexndr]

The file is locked by the running app (DCEVM java.exe) so IDE has no relation to this issue.

Investigated with Process Explorer(SysInternals) to find file lock handle and process. There were 4 identical file locks. My related issue: https://github.com/gradle/gradle/issues/14538 Using dcevm-11.0.8+1