Issue #363 resolved

Deadlock in properties view showing incoming changeset

Andrey Loskutov
created an issue

AS IS: I've opened sync view and wanted to see the long commit message for one incoming changeset. So I've selected "properties" menu to see the full log. Unfortunately this caused immediate error logging to the error log view, which automaticaly got to the front with an error: {{{

!java

java.lang.IllegalArgumentException: No phase for unknown node 55134e328e4a from 1-phase boundary e1dbd9646d6a6105e6df446030568bdc9bbe53f6 public at com.aragost.javahg.Phase.fromText(Phase.java:30) at com.aragost.javahg.Repository.phases(Repository.java:276) at com.aragost.javahg.Changeset.phase(Changeset.java:307) at com.vectrace.MercurialEclipse.model.JHgChangeSet.getPhase(JHgChangeSet.java:346) 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 com.vectrace.MercurialEclipse.properties.GenericPropertySource.getPropertyValue(GenericPropertySource.java:81) at org.eclipse.ui.views.properties.PropertySheetEntry.refreshValues(PropertySheetEntry.java:611) at org.eclipse.ui.views.properties.PropertySheetEntry.refreshChildEntries(PropertySheetEntry.java:568) at org.eclipse.ui.views.properties.PropertySheetEntry.setValues(PropertySheetEntry.java:760) at org.eclipse.ui.views.properties.PropertySheetViewer.setInput(PropertySheetViewer.java:973) at org.eclipse.ui.views.properties.PropertySheetPage.selectionChanged(PropertySheetPage.java:510) at org.eclipse.ui.views.properties.PropertySheet.partActivated(PropertySheet.java:338) at org.eclipse.ui.part.PageBookView.showBootstrapPart(PageBookView.java:920) at org.eclipse.ui.part.PageBookView.createPartControl(PageBookView.java:491) at org.eclipse.ui.views.properties.PropertySheet.createPartControl(PropertySheet.java:157) at org.eclipse.ui.internal.ViewReference.createPartHelper(ViewReference.java:386) at org.eclipse.ui.internal.ViewReference.createPart(ViewReference.java:240) at org.eclipse.ui.internal.WorkbenchPartReference.getPart(WorkbenchPartReference.java:595) at org.eclipse.ui.internal.ViewReference.getView(ViewReference.java:209) at org.eclipse.ui.internal.WorkbenchPage.busyShowView(WorkbenchPage.java:1137) at org.eclipse.ui.internal.WorkbenchPage$20.run(WorkbenchPage.java:3925) at org.eclipse.swt.custom.BusyIndicator.showWhile(BusyIndicator.java:70) at org.eclipse.ui.internal.WorkbenchPage.showView(WorkbenchPage.java:3922) at org.eclipse.ui.internal.WorkbenchPage.showView(WorkbenchPage.java:3898) at com.vectrace.MercurialEclipse.properties.OpenPropertiesAction.run(OpenPropertiesAction.java:49) at com.vectrace.MercurialEclipse.synchronize.cs.HgChangeSetActionProvider$1.run(HgChangeSetActionProvider.java:85) at org.eclipse.jface.action.Action.runWithEvent(Action.java:498) at org.eclipse.jface.action.ActionContributionItem.handleWidgetSelection(ActionContributionItem.java:584) at org.eclipse.jface.action.ActionContributionItem.access$2(ActionContributionItem.java:501) at org.eclipse.jface.action.ActionContributionItem$5.handleEvent(ActionContributionItem.java:411) at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:84) }}}

So I've selected the changeset again to see the properties view again -> again the error view popped up. Finally I've closed the error view and ... got immediate lockup of the UI. So I had to kill Eclipse after that. The stack dump of a deadlocked UI is attached.

Comments (11)

  1. John Peberdy

    A couple weeks ago I pushed a change to catch and log a warning for this phase error but I don't know why its occurring in the first place.

    If you invoke 'hg phase 55134e328e4a ' or 'hg phase .' on the command line do you get the same error?

    I think it's something related to hgsubversion - maybe it breaks if phase is invoked on it?

  2. John Peberdy

    The deadlock is slightly different issue I think - if it is reproducible can you open the mercurial console and report the last command printed before the deadlock - that may be a JavaHg command with a bug.

  3. Andrey Loskutov reporter

    command:

    log --debug --style /tmp/1348521751811-0/styles/tags.style --rev e1dbd9646d6a6105e6df446030568bdc9bbe53f6 --repository /tmp/javahg-8925666411090356534.bundle 
    

    bundle of the incoming state is attached error stack:

    ava.lang.IllegalArgumentException: No phase for unknown node 55134e328e4a from 1-phase boundary
    e1dbd9646d6a6105e6df446030568bdc9bbe53f6 public
    	at com.aragost.javahg.Phase.fromText(Phase.java:30)
    	at com.aragost.javahg.Repository.phases(Repository.java:276)
    	at com.aragost.javahg.Changeset.phase(Changeset.java:307)
    	at com.vectrace.MercurialEclipse.model.JHgChangeSet.getPhase(JHgChangeSet.java:346)
    	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 com.vectrace.MercurialEclipse.properties.GenericPropertySource.getPropertyValue(GenericPropertySource.java:81)
    

    But everything just freezes while "touching" sync view if the error log view is closed. Looking on the dump file, the command which doesn't work has something to do with tags...

    "main" prio=10 tid=0x00007ff1b8009000 nid=0x1128 waiting on condition [0x00007ff1bfa68000]
       java.lang.Thread.State: TIMED_WAITING (parking)
            at sun.misc.Unsafe.park(Native Method)
            - parking to wait for  <0x0000000783cdcd00> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
            at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
            at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
            at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
            at com.aragost.javahg.internals.ServerPool.waitForServer(ServerPool.java:196)
            at com.aragost.javahg.internals.ServerPool.take(ServerPool.java:167)
            at com.aragost.javahg.internals.AbstractCommand.launchStream(AbstractCommand.java:162)
            at com.aragost.javahg.internals.GenericLogCommand.stream(GenericLogCommand.java:43)
            at com.aragost.javahg.Changeset.tags(Changeset.java:317)
            at com.vectrace.MercurialEclipse.model.JHgChangeSet.fetchTags(JHgChangeSet.java:244)
            at com.vectrace.MercurialEclipse.model.JHgChangeSet.getTagsStr(JHgChangeSet.java:222)
            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 com.vectrace.MercurialEclipse.properties.GenericPropertySource.getPropertyValue(GenericPropertySource.java:81)
            at org.eclipse.ui.views.properties.PropertySheetEntry.refreshValues(PropertySheetEntry.java:611)
            at org.eclipse.ui.views.properties.PropertySheetEntry.refreshChildEntries(PropertySheetEntry.java:568)
    

    Question is: why it freezes in Eclipse, while executing the command above on the command line it just returns "tip^".

  4. Andrey Loskutov reporter
    andrei@Pinguin:~/workspace/hgsubversion$ hg phase .
    936: draft
    
    andrei@Pinguin:~/workspace/hgsubversion$ hg phase 55134e328e4a
    abort: unknown revision '55134e328e4a'!
    
    andrei@Pinguin:~/workspace/hgsubversion$hg log --rev e1dbd9646d6a6105e6df446030568bdc9bbe53f6 --repository /tmp/javahg-8925666411090356534.bundle
    changeset:   937:e1dbd9646d6a
    tag:         tip
    parent:      935:5bacb9c63e3e
    user:        Patrick Mezard <patrick@mezard.eu>
    date:        Sun Sep 16 19:31:49 2012 +0200
    summary:     svnwrap: use custom StringIO class in get_file()
    
    andrei@Pinguin:~/workspace/hgsubversion$ hg sum
    parent: 936:ce18f955be64 tip
     Merge with 312f36a425f01328c9f36b831019c30b6f4957fc
    branch: default
    commit: (clean)
    update: (current)
    
  5. John Peberdy

    It's deadlocking because it's waiting for a command server to become available. Javahg has a server pool for each repository of size 3. I think there's a concurrency bug in javahg.. all 3 servers are crashing or getting stopped after the main thread leaves the synchronized block in ServerPool.take() so waitForServer() never gets a server (it expects commands to exit normally so it only listens on 'freeServers').

    I'd say it's a bug anyway but if you can repro in a debugger then we can confirm it's the cause - is ServerPool's 'servers' field empty or not. If it is empty then I think we've found the cause.

  6. Log in to comment