WatchDog crashes when file is out of sync

[Inventitech]

Stacktrace

Thread [main] (Suspended (breakpoint at line 103 in WatchDogUtils)) 
    owns: RunnableLock  (id=108)    
    WatchDogUtils.getContentForFileFromDisk(IFile) line: 103    
    DocumentCreator.createDocument(String, IFile) line: 36  
    ResourceAndResourceDeltaVisitor.visit(IResource, boolean) line: 88  
    ResourceAndResourceDeltaVisitor.visit(IResource) line: 59   
    Resource$2.visit(IResourceProxy) line: 120  
    Resource$1.visitElement(ElementTree, IPathRequestor, Object) line: 84   
    ElementTreeIterator.doIteration(DataTreeNode, IElementContentVisitor) line: 82  
    ElementTreeIterator.doIteration(DataTreeNode, IElementContentVisitor) line: 87  
    ElementTreeIterator.iterate(IElementContentVisitor) line: 122   
    WorkspaceRoot(Resource).accept(IResourceProxyVisitor, int, int) line: 94    
    WorkspaceRoot(Resource).accept(IResourceProxyVisitor, int) line: 52 
    WorkspaceRoot(Resource).accept(IResourceVisitor, int, int) line: 117    
    WorkspaceRoot(Resource).accept(IResourceVisitor) line: 105  
    WorkbenchListener.addStaticAnalysisListeners() line: 82 
    WorkbenchListener.attachListeners() line: 62    
    InitializationManager.<init>() line: 75 
    InitializationManager.getInstance() line: 84    
    StartupHandler.startWatchDog() line: 41 
    StartupUIThread.checkWhetherToStartWatchDog() line: 168 
    StartupUIThread.run() line: 60  
    RunnableLock.run(Display) line: 37  
    UISynchronizer(Synchronizer).runAsyncMessages(boolean) line: 182    
    Display.runAsyncMessages(boolean) line: 4577    
    Display.readAndDispatch() line: 4186    
    PartRenderingEngine$5.run() line: 1150  
    Realm.runWithDefault(Realm, Runnable) line: 336 
    PartRenderingEngine.run(MApplicationElement, IEclipseContext) line: 1039    
    E4Workbench.createAndRunUI(MApplicationElement) line: 153   
    Workbench.lambda$3(Display, WorkbenchAdvisor, int[]) line: 680  
    962700314.run() line: not available 
    Realm.runWithDefault(Realm, Runnable) line: 336 
    Workbench.createAndRunWorkbench(Display, WorkbenchAdvisor) line: 594    
    PlatformUI.createAndRunWorkbench(Display, WorkbenchAdvisor) line: 148   
    IDEApplication.start(IApplicationContext) line: 151 
    EclipseAppHandle.run(Object) line: 196  
    EclipseAppLauncher.runApplication(Object) line: 134 
    EclipseAppLauncher.start(Object) line: 104  
    EclipseStarter.run(Object) line: 388    
    EclipseStarter.run(String[], Runnable) line: 243    
    NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available [native method]  
    NativeMethodAccessorImpl.invoke(Object, Object[]) line: 62  
    DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 43  
    Method.invoke(Object, Object...) line: 498  
    Main.invokeFramework(String[], URL[]) line: 653 
    Main.basicRun(String[]) line: 590   
    Main.run(String[]) line: 1499   
    Main.main(String[]) line: 1472  

In a runtime workbench, this simply disables the plugin. Installed in Eclipse, WatchDog crashes. I (assume|hope) that is the cause of our bug. The problem is that the StaticAnalysis analyzer attaches to the IDE early-on, and the exception that the file contents are out of sync.

[Inventitech]

Investigating what the best way to fix this is ...

[Inventitech]

I tried to make the DocumentCreator more benign, unfortunately, to no avail.

WatchDog goes into a crazy infinite loop (it actually makes the mother Eclipse workbench non-reactive too, so was super-hard to debug) because it tries to get the document content via getContentForFileFromDisk(IFile file) over and over again. This is caused by ResourceAndResourceDeltaVisitor.visit(IResource resource, boolean shouldComputeDiff) being called again and again. Not sure why it is called like crazy

The solution was thus to remove the attachment of the static listeners, which immediately solves the problem.

Tim, as this is not in your intention, I would ask you to try and solve this, if you can and have some time free.

[Inventitech]

Oh, I guess I found the bug.

[Inventitech]

Unfortunately, I assume similar issues plague IntelliJ users ...

[TimvdLippe]

I am not the original author of the problematic getContentForFileFromDisk method, I was simply using it expecting it to work as intended. Therefore, I think you are the most experienced right now to be able to debug this issue.

You might be able to write a test for this behavior, based on this test: https://github.com/TestRoots/watchdog/blob/49259b3b4f378a92af1fd44213792297aa6d30b2/eclipse/tests/src/nl/tudelft/watchdog/eclipse/logic/ui/listeners/staticanalysis/MarkupModelListenerTest.java#L148-L160

Probably, if you alter the file before opening the editor, you would run into this behavior. For that, you probably need to not call this line: https://github.com/TestRoots/watchdog/blob/49259b3b4f378a92af1fd44213792297aa6d30b2/eclipse/tests/src/nl/tudelft/watchdog/eclipse/logic/ui/listeners/staticanalysis/MarkupModelListenerTest.java#L121 Then we have a nice regression test as well 😄

[Inventitech]

The problem is not really getContentForFileFromDisk. This only causes an exception in cases where the resource is out of sync, which typically does not happen. I happened to stumble across this because I was using a workspace I had copied.

The far more problematic case are deadlocks caused by ResourceAndResourceDeltaVisitor.visit being called in an infinite loop. It makes starting Eclipse impossible. This is related to a wrong return type of the visit function. My fix wasn't perfect yet as your tests showed, investigating ...

[TimvdLippe]

Per https://help.eclipse.org/neon/index.jsp?topic=%2Forg.eclipse.platform.doc.isv%2Freference%2Fapi%2Forg%2Feclipse%2Fcore%2Fresources%2FIResourceDeltaVisitor.html the true means that it will recurse through children. E.g. it will not stop at packages, but will also visit classes.

I am still confused as to why the out-of-syncness would trigger recursion in the visitor. Are we not catching an exception that is thrown in getContentForFileFromDisk?

[Inventitech]

Per https://help.eclipse.org/neon/index.jsp?topic=%2Forg.eclipse.platform.doc.isv%2Freference%2Fapi%2Forg%2Feclipse%2Fcore%2Fresources%2FIResourceDeltaVisitor.html the true means that it will recurse through children. E.g. it will not stop at packages, but will also visit classes.

It will run through jars and every other possibly class containing container. For large projects, this results in an amazingly long startup time. Originally I thought it was an endless loop because some resources were visited multiple times (e.g., /), but that's actually not the problem, the multi-visit stems from visiting different files subsequently.

[Inventitech]

I think the proper way to handle this is to adapt the tests which rely on non-opened files and keep the visitor returning false.

What do you think?

[TimvdLippe]

That seems like the wrong approach. We want to recurse into files, which the tests are also asserting. Removing this logic will mean that the implementation will be practically non-functional.

Instead, we should figure out what the source sets are and not visit any dependencies. We are not interested in them. E.g. add a check at https://github.com/TestRoots/watchdog/blob/49259b3b4f378a92af1fd44213792297aa6d30b2/eclipse/plugin/src/nl/tudelft/watchdog/eclipse/logic/ui/listeners/staticanalysis/ResourceAndResourceDeltaVisitor.java#L71 which asserts that any dependencies are not recursed into. Not sure how to do that just yet, that would require some System.out.println debugging to figure out how we can detect them.

[Inventitech]

OK, so in cases of big projects with lots of .classes or .javas we are then stuck with them same problem of very long startup times. Doesn't sound like a solution to me?

[Inventitech]

Oh, one more thing, would you point me to the logic that replicates this behavior for IntelliJ? Thanks!

[TimvdLippe]

OK, so in cases of big projects with lots of .classes or .javas we are then stuck with them same problem of very long startup times. Doesn't sound like a solution to me?

I am not aware of any other API in Eclipse that exposes what we need. If Eclipse does not implement a performant API, then I am not sure what else to do. You could potentially compute all markers later. E.g. collect all changed markers first, do the diffing later.

Oh, one more thing, would you point me to the logic that replicates this behavior for IntelliJ? Thanks!

Intellij has a completely different API. As I wrote down in my thesis, no diffing is required there. https://github.com/TestRoots/watchdog/blob/49259b3b4f378a92af1fd44213792297aa6d30b2/intellij/src/nl/tudelft/watchdog/intellij/logic/ui/listeners/staticanalysis/IntelliJMarkupModelListener.java#L163-L184 do the same as in Eclipse and is more performant.

[Inventitech]

I was initially not so happy about filtering out in visit because that wouldn't solve the reported IntelliJ problems. However, I have not encountered them myself and could not replicate them.

The great thing about the patch in visit is that it reduces Eclipse opening times on WatchDog itself from several hours on my machine to < 1 second. That seems pretty good, and we can keep the static analysis warnings in place. Moreover, all tests are green again :tada:

Let's hope that among our WatchDog users is no uber-project with millions of Java files embedded as source.

[TimvdLippe]

The tests are failing on the latest commit on master (https://travis-ci.org/TestRoots/watchdog/builds/440711210) Did I miss the patch you were talking about?

[Inventitech]

Still perfecting the patch locally, the build is very old.

[Inventitech]

Would be cool to run WD in a 'scaled' mode then and disable certain functionality in that case (similar to what we are doing in https://github.com/TestRoots/watchdog/blob/4dfcab88ca285f1fc1cb69021d5befd1de87a833/core/src/nl/tudelft/watchdog/core/logic/interval/intervaltypes/TypingInterval.java#L53), but I guess that remains future work ...