Community
Participate
Working Groups
Build Identifier: Eclipse 3.6.1 When the debug session starts, the debugger sends two source look up requests. This happens on an external source look up container which finds source on a remote host. Reproducible: Always Steps to Reproduce: The method StackFrameSourceDisplayAdapter.displaySource() saves the stackframe during the source look up to avoid the duplicated request. if (!force && frame.equals(fPrevFrame)) And the attribute fPrevFrame is going to be set when the source look up job runs. ISourceLookupResult result = DebugUITools.lookupSource(fTarget, fLocator); synchronized (StackFrameSourceDisplayAdapter.this) { fPrevResult = (SourceLookupResult)result; fPrevFrame = fTarget; } As you can see, fPrevFrame is set after the source look up is done. But the source look might be a time consuming one and debugger may get another request before the source look up comes back. In this case, debugger will send duplicated source look up request to the source look up container. We found this problem in bug 327495
I suppose the source lookup infrastructure could be improved to queue up clients interested in the source lookup result for the same frame (if a lookup happens to be in progress when another request comes in). However, I'm not sure how critical/common the scenario is.
JSDT debug is also hit with this with our changes to source lookup / duplicate script source selection. In the JSDT case this results in the dialog to select which script to open the source for being shown twice at the same time - one dialog stacked on top of the other. Debugging the problem I found that the source lookup job is being spawned because it is responding to two debug context changed events - which in the JSDT case only happens the very first time the debugger suspends.
Created attachment 189621 [details] Fix attempt using scheduling rule. This fix adds a scheduling rule to the lookup jobs so they run serially. Mike, give it a try.
Created attachment 189622 [details] Updated fir for an NPE.
I committed the fix.
Mike, please verify.
The patch does prevent my multiple dialog problem, as long as I don't cancel the dialog - if I do I am immediately presented with another 'select source' dialog. I think the scheduling rule is a good idea, but is only masking the real problem of why there is more than one source lookup job being spawned on the first suspend. See the attached tracings, where I found there are two deltas being responded to. I am going to re-open until we confirm it is not a problem with the platform.
Created attachment 189707 [details] viewer tracing
I backed out the scheduling rule change as it caused conflicts for source containers that modified resources during a source lookup (bug 339542).
Is this problem already fixed? Thanks.
(In reply to comment #10) > Is this problem already fixed? Thanks. Nope, we don't have a solution for this problem at this point. The one solution we attempted backfired.
Creative ideas welcome.
*** Bug 386589 has been marked as a duplicate of this bug. ***
steps and example projects from bug 385486 comment #3 cause the two source lookup dialog problem.
(In reply to comment #14) > steps and example projects from bug 385486 comment #3 cause the two source > lookup dialog problem. I added in some test tracing: [force: false] [frame: org.eclipse.jdt.internal.debug.core.model.JDIStackFrame@425aeb8d] [prev frame: null] java.lang.Exception: Stack trace at java.lang.Thread.dumpStack(Thread.java:1342) at org.eclipse.debug.internal.ui.elements.adapters.StackFrameSourceDisplayAdapter.displaySource(StackFrameSourceDisplayAdapter.java:190) at org.eclipse.debug.internal.ui.sourcelookup.SourceLookupService.displaySource(SourceLookupService.java:94) at org.eclipse.debug.internal.ui.sourcelookup.SourceLookupService.displaySource(SourceLookupService.java:76) at org.eclipse.debug.internal.ui.sourcelookup.SourceLookupService.debugContextChanged(SourceLookupService.java:51) at org.eclipse.debug.internal.ui.contexts.DebugWindowContextService$1.run(DebugWindowContextService.java:212) at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:42) at org.eclipse.debug.internal.ui.contexts.DebugWindowContextService.notify(DebugWindowContextService.java:210) at org.eclipse.debug.internal.ui.contexts.DebugWindowContextService.notify(DebugWindowContextService.java:185) at org.eclipse.debug.internal.ui.contexts.DebugWindowContextService.debugContextChanged(DebugWindowContextService.java:408) at org.eclipse.debug.ui.contexts.AbstractDebugContextProvider$1.run(AbstractDebugContextProvider.java:79) at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:42) at org.eclipse.debug.ui.contexts.AbstractDebugContextProvider.fire(AbstractDebugContextProvider.java:77) at org.eclipse.debug.internal.ui.views.launch.LaunchView$ContextProviderProxy.debugContextChanged(LaunchView.java:506) at org.eclipse.debug.ui.contexts.AbstractDebugContextProvider$1.run(AbstractDebugContextProvider.java:79) at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:42) at org.eclipse.debug.ui.contexts.AbstractDebugContextProvider.fire(AbstractDebugContextProvider.java:77) at org.eclipse.debug.internal.ui.views.launch.LaunchView$TreeViewerContextProvider.activate(LaunchView.java:371) at org.eclipse.debug.internal.ui.views.launch.LaunchView$1.selectionChanged(LaunchView.java:468) at org.eclipse.jface.viewers.Viewer$2.run(Viewer.java:164) at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:42) at org.eclipse.ui.internal.JFaceUtil$1.run(JFaceUtil.java:49) at org.eclipse.jface.util.SafeRunnable.run(SafeRunnable.java:175) at org.eclipse.jface.viewers.Viewer.fireSelectionChanged(Viewer.java:162) at org.eclipse.jface.viewers.StructuredViewer.updateSelection(StructuredViewer.java:2188) at org.eclipse.jface.viewers.StructuredViewer.setSelection(StructuredViewer.java:1725) at org.eclipse.jface.viewers.TreeViewer.setSelection(TreeViewer.java:1139) at org.eclipse.debug.internal.ui.viewers.model.InternalTreeModelViewer.trySelection(InternalTreeModelViewer.java:1047) at org.eclipse.debug.internal.ui.viewers.model.TreeModelContentProvider.handleSelect(TreeModelContentProvider.java:1521) at org.eclipse.debug.internal.ui.viewers.model.TreeModelContentProvider.updateNodes(TreeModelContentProvider.java:1173) at org.eclipse.debug.internal.ui.viewers.model.TreeModelContentProvider.updateNodes(TreeModelContentProvider.java:1178) at org.eclipse.debug.internal.ui.viewers.model.TreeModelContentProvider.updateNodes(TreeModelContentProvider.java:1178) at org.eclipse.debug.internal.ui.viewers.model.TreeModelContentProvider.updateNodes(TreeModelContentProvider.java:1178) at org.eclipse.debug.internal.ui.viewers.model.TreeModelContentProvider.updateNodes(TreeModelContentProvider.java:1178) at org.eclipse.debug.internal.ui.viewers.model.TreeModelContentProvider.updateModel(TreeModelContentProvider.java:437) at org.eclipse.debug.internal.ui.viewers.model.TreeModelContentProvider.doModelChanged(TreeModelContentProvider.java:407) at org.eclipse.debug.internal.ui.viewers.model.TreeModelContentProvider.access$0(TreeModelContentProvider.java:401) at org.eclipse.debug.internal.ui.viewers.model.TreeModelContentProvider$2.run(TreeModelContentProvider.java:389) at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35) at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:135) at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:4144) at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3761) at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine$9.run(PartRenderingEngine.java:1023) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332) at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine.run(PartRenderingEngine.java:917) at org.eclipse.e4.ui.internal.workbench.E4Workbench.createAndRunUI(E4Workbench.java:86) at org.eclipse.ui.internal.Workbench$5.run(Workbench.java:587) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332) at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:542) at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149) at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:124) at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:196) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:353) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:180) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:601) at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:629) at org.eclipse.equinox.launcher.Main.basicRun(Main.java:584) at org.eclipse.equinox.launcher.Main.run(Main.java:1438) at org.eclipse.equinox.launcher.Main.main(Main.java:1414) on the first launch we get two of these tracings, so it looks like the second request is coming in immediately after the first before we can set the previous frame, so we don't know to cancel the first job because the test 'frame.equals(fPrevFrame)' is false. In this case even the updated change to compare frame data does not help.
So it looks like the first job is responding to a request to cancel but ignores it because it is prompting the user - here is some job tracing: starting slj: Debug Source Lookup(1011) --> prompting cancelling slj: Debug Source Lookup(1011) starting slj: Debug Source Lookup(1055) --> prompting
Created attachment 223372 [details] Fix attempt using a custom locking mechanism to serialize source lookups. This patch replaces the scheduling rule with a home-grown locking to serialize the lookup jobs. However, I tried to test it with Bug 385486 comment #3 and still got two dialogs. The reason is that in that example one of the source lookups is performed by the label provider for the thread, which calls DebugUITools.lookupSource(). I don't see a way to prevent without opening a new API in the source display which the label provider would then need to reference.
(In reply to comment #17) > Created attachment 223372 [details] > Fix attempt using a custom locking mechanism to serialize source lookups. > > This patch replaces the scheduling rule with a home-grown locking to > serialize the lookup jobs. > Thanks Pawel. > However, I tried to test it with Bug 385486 comment #3 and still got two > dialogs. The reason is that in that example one of the source lookups is > performed by the label provider for the thread, which calls > DebugUITools.lookupSource(). I don't see a way to prevent without opening a > new API in the source display which the label provider would then need to > reference. Yeah, I figured as much. In that example the source lookup job ends up prompting so however many jobs you queue up is the number of dialogs you see. What about if we beef up the queuing a bit by adding in some checks that looks for successive lookup jobs for the exact same context (page + frame + attributes) and just ignore them?
(In reply to comment #18) > (In reply to comment #17) > Yeah, I figured as much. In that example the source lookup job ends up > prompting so however many jobs you queue up is the number of dialogs you > see. > > What about if we beef up the queuing a bit by adding in some checks that > looks for successive lookup jobs for the exact same context (page + frame + > attributes) and just ignore them? It's not that both source lookups that get queued put up the dialog, but rather one of the lookups doesn't go through the queue in source display adapter. So in case of JDT, would need to change the label provider to go through the queue in order to perform the lookup that it needs. However, there's a complication there, because the source display adapter currently cancels the previous display request if a new one comes, we would not want that for the label provider. Still, I think the problem may be unique to JDT, I wonder if other debuggers that need a fix for this bug would benefit from the proposed patch.
(In reply to comment #19) > (In reply to comment #18) > Still, I think the problem may be unique to JDT, I wonder if other debuggers > that need a fix for this bug would benefit from the proposed patch. In JDT, the problem comes from trying to resolve a project context using a source locator. For example in JavaWatchExpression#getProject(IStackFrame) we ask the source locator to find the source element, which causes a prompt. If you use the steps mentioned in comment #14 and make sure the Expressions view is closed source lookup works as intended. Now with the patch from bug 368212 the problem is even worse: 1. use the setup from comment #14 1a. add a conditional breakpoint on the throw statement (in the method() method) 2. open the expressions view 3. debug After step 3 you will now have all the dialogs you can handle, I counted 6 of them on the first suspend!
(In reply to comment #20) I'm also seeing the multiple dialogs popup with the expressions view open. However when I suspend in various scenarios, I only see only job that is started by the source display adapter. Other source lookup jobs are started by the label provider and expressions evaluator. I think jdt needs a specialized source display adapter, which will serialize the source display requests with other source lookup requests. The needs of source lookup are a little different since source display requests can be cancelled after a new one is queued, while the source lookup requests from label providers and elsewhere need all be completed. One very simple option to address this would be to override resolveSourceElement() in JavaSourceLookupDirector and make it synchronized, though a guard would need to be added in case resolveSourceElements() was called in the UI thread (else we'll get deadlocks eventually).
(In reply to comment #21) > ... though a guard would need to be added in case resolveSourceElements() was > called in the UI thread (else we'll get deadlocks eventually). Hmm... this part will be tricky since source lookup director is not in a UI plugin :-( I guess a custom source lookup director with additional APIs would be needed.
Created attachment 224184 [details] Fix synchronizing source lookups This patch implements serializing source lookups using a sync. section. I think this is a safe implementation since it avoids the locking when in UI thread. Since both source display adapter and expressions label provider use the DebugUITools.lookupSource() utility, this change effectively fixes the JDT use case. Other debuggers that implement their own source lookup logic will not be affected by this fix. Since no new APIs are created I think we could target this fix at Juno SR2 as well.
Feeling optimistic, I committed the fix. Mike please give it a try and review the change. http://git.eclipse.org/c/platform/eclipse.platform.debug.git/commit/?id=6969f6131bc0b5b970509047133b72ec67d8b3c0
Created attachment 224231 [details] Thread dump -1 for this fix, it deadlocks 100% of the time. I attached the thread dump of the deadlock. use the steps from comment #14 to reproduce.
I reverted the fix so we can look at it more.
Created attachment 224237 [details] Updated synchronized fix. Sorry about that, I felt too optimistic I guess. I didn't encounter the deadlock in my testing and didn't notice that the source lookup director was doing internal synchronization using its instance. This version of the fix adds use of lock objects that are private to the source lookup facility. This should avoid interference with locking in the director. I'll let you try it out before committing this time ;-)
(In reply to comment #27) > This version of the fix adds use of lock objects that are private to the > source lookup facility. This should avoid interference with locking in the > director. I'll let you try it out before committing this time ;-) -1 for this patch, it does not apply.
Created attachment 224339 [details] Updated patch in oneline format. Previous patch was in email format.
I'm going to defer this one as it makes some sync'ing changes to source loopkup that I don't want to push into M5 with only a few days left. Moving to M6.
On second thought, I am going to defer this one until 4.4. M7 is next week and then we are into the RC's, which would not be a good time to release synchronization / job changes to source lookup.
Just confirming - is this still on track for being fixed for 4.4?
(In reply to Steve Francisco from comment #32) > Just confirming - is this still on track for being fixed for 4.4? We are still considering it, time permitting with all of the Java 8 work left to do.
(In reply to Michael Rennie from comment #33) > (In reply to Steve Francisco from comment #32) > > Just confirming - is this still on track for being fixed for 4.4? > > We are still considering it, time permitting with all of the Java 8 work > left to do. Having the improved jobs is a good first step, but for all of the other places that ask for source(potentially) when a suspend occurs, perhaps it would be better to just extract the jobs out of the stackframe adapter and use them in the DebugUITools class in the #lookupSource and #displaySource methods. Or even better (perhaps) push the job use into the SourceLookupFacility class, which the DebugUITools API delegates to. That way any code that uses either of the methods to ask for or display source automatically is synchronized by the job rather than just the stackframe adapter.
(In reply to Michael Rennie from comment #34) > Having the improved jobs is a good first step, but for all of the other > places that ask for source(potentially) when a suspend occurs, perhaps it > would be better to just extract the jobs out of the stackframe adapter and > use them in the DebugUITools class in the #lookupSource and #displaySource > methods. > > Or even better (perhaps) push the job use into the SourceLookupFacility > class, which the DebugUITools API delegates to. That way any code that uses > either of the methods to ask for or display source automatically is > synchronized by the job rather than just the stackframe adapter. Another idea, perhaps less code changes, would be to add some sort of LRU caching to SourceLookupFacility, then every caller of either the DebugUITools or SourceLookupFacility methods would be able to short circuit a lookup the same way the stackframe adapter does.
Created attachment 240283 [details] patch Heres a patch that adds some caching to the SourceLookupFacility class. Stepping through it, it does prevent the associated source locator from being asked twice in a row for the same source for the exact same stackframe. While debugging it (to see if it even worked) I found these steps to reproduce the issue better: 1. create a simple hello world Java program (in a target workspace) 2. makes sure there is nothing in the debug view - no existing launches and no old terminated launches 3. debug your hello world app with a breakpoint in SourceLookupService line 87 and one in Viewer line 159. 4. notice that when the launch suspends we get three selection changed events; first an empty one, second for the stackframe (which spawns a lookup job) and third for the same stackframe again (which spawns another job)
(In reply to Michael Rennie from comment #36) > 4. notice that when the launch suspends we get three selection changed > events; first an empty one, second for the stackframe (which spawns a lookup > job) and third for the same stackframe again (which spawns another job) The first selection changed event is responding to this delta: Model Delta Start Element: org.eclipse.jdt.internal.debug.core.model.JDIDebugTarget@4b2c0772 Flags: CONTENT | SELECT | STATE | Index: -1 Child Count: -1 Model Delta End The second to this delta: Model Delta Start Element: org.eclipse.jdt.internal.debug.core.model.JDIStackFrame@732ef28 Flags: SELECT | STATE | Index: 0 Child Count: 0 Model Delta End The third to this delta: Model Delta Start Element: org.eclipse.jdt.internal.debug.core.model.JDIStackFrame@732ef28 Flags: SELECT | Index: 0 Child Count: 0 Model Delta End IMO we should either not be firing the third delta or not have the SELECT flag on the second one. While tracing these deltas I also found that when you terminate the launch *and* when you clear all the launches from the debug view we get a request to lookup source in the SourceLookupService. We definitely need to clean that up.
I can't make the time now to go in depth on source lookup, but from what I remember: The select events correspond to suspend event from both the target and thread. Additionally, if there content delta for the target or thread, another source lookup is performed on the current stack frame. So there may be more lookups than these two. The number of lookups can be reduced, but because of the asynchronous nature of events and unpredictable time for lookups, I don't think race conditions can ever be completely eliminated. Caching may help with the problem somewhat but for caching to be effective, it'll need to serialize lookup requests, as I tried in a couple different ways in this bug. IMO, the surest way to address this bug is what I mentioned in comment #21: create a specialized source lookup API for JDT where the frame label adapter can get the element's project without bringing up the dialog.
Created attachment 241598 [details] Combined patch for Caching and new Job location This patch takes the Caching patch as base and adds the Job creation to SourceLookupFacility . Job creation was happening in StackFrameSourceDisplayAdapter before but after this it will be a centralized place to cache and lookup job creation. For Java Problem information, lookup will continue to happen without job but through cache. I will do further testing with JSDT Debugger.
(In reply to Sarika Sinha from comment #39) > Created attachment 241598 [details] > Combined patch for Caching and new Job location > > This patch takes the Caching patch as base and adds the Job creation to > SourceLookupFacility . Job creation was happening in > StackFrameSourceDisplayAdapter before but after this it will be a > centralized place to cache and lookup job creation. > For Java Problem information, lookup will continue to happen without job but > through cache. > > I will do further testing with JSDT Debugger. No issues running with this patch installed into my host today, but I wasn't testing any extreme scenarios, just the usual java debugging.
Created attachment 243356 [details] removed API addition This patch removes the API addition from the last patch and also removes the old now defunct SourceDisplayAdapter class
http://git.eclipse.org/c/platform/eclipse.platform.debug.git/commit/?id=0643c40412ead265c6679ad608f2e8fceb7f15e9 +1 pushed to master
Verified using: Eclipse SDK Version: Luna (4.4) Build id: I20140515-1230
The committed patch is now causing a new bug in lookupSource. Since the map of cached lookup results uses only artifacts as keys, lookups will return the same results for any items with identical artifacts, even if the items have different source locators. This is reported in better detail in bug 436411.
