Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.

Bug 276562

Summary: [repo] Repository not found error for valid repository
Product: [Eclipse Project] Equinox Reporter: John Arthorne <john.arthorne>
Component: p2Assignee: John Arthorne <john.arthorne>
Status: RESOLVED FIXED QA Contact:
Severity: normal    
Priority: P3 CC: aniefer, dj.houghton, eclipse, pascal, pwebster, susan
Version: 3.5Flags: susan: review+
pascal: review+
Target Milestone: 3.5 RC2   
Hardware: PC   
OS: Windows XP   
Whiteboard:
Attachments:
Description Flags
Fix and regression test v01 none

Description John Arthorne CLA 2009-05-15 16:10:31 EDT
I20090515-1143

1) Add two large or slow repositories to the list of available repositories
2) Open Install New Software dialog
3) Select one repository in Work With combo box
4) Quickly switch to another repository while the first is still loading.

Loading of the repo in 3) gets canceled, and this is presented to the end user as a "repository not found" error. Apart from the dialog there appear to be no other side-effects.

This is related to the change in bug 275398. We were previously not passing the progress monitor along, so this code never responded to cancelation before. Now we respond to cancelation, but it gets handled incorrectly.
Comment 1 John Arthorne CLA 2009-05-15 18:18:04 EDT
I don't think those steps are accurate. The best way to reproduce seems to be typing in the location of a very fast repository in the work with combo, and hitting enter. I haven't yet tracked down what is happening. There are a large number of background fetch jobs going on at once, even though I only have a single repository. One of them fails, but I haven't found any link to cancelation yet - it just says "not found" from the repository manager. I haven't been able to track it back any further yet. When stepping through in the debugger, it doesn't fail.
Comment 2 Susan McCourt CLA 2009-05-18 18:59:42 EDT
I only saw this once today, when I tried to load the I-build repo.  This was in the log:

!ENTRY org.eclipse.equinox.p2.metadata.repository 4 0 2009-05-18 15:50:52.341
!MESSAGE Unexpected error loading extension: org.eclipse.equinox.p2.metadata.repository.compositeRepository
!STACK 0
java.lang.NullPointerException
	at org.eclipse.equinox.internal.p2.repository.helpers.AbstractRepositoryManager.enterLoad(AbstractRepositoryManager.java:323)
	at org.eclipse.equinox.internal.p2.repository.helpers.AbstractRepositoryManager.loadRepository(AbstractRepositoryManager.java:599)
	at org.eclipse.equinox.internal.p2.metadata.repository.MetadataRepositoryManager.loadRepository(MetadataRepositoryManager.java:92)
	at org.eclipse.equinox.internal.p2.metadata.repository.MetadataRepositoryManager.loadRepository(MetadataRepositoryManager.java:88)
	at org.eclipse.equinox.internal.p2.metadata.repository.CompositeMetadataRepository.addChild(CompositeMetadataRepository.java:146)
	at org.eclipse.equinox.internal.p2.metadata.repository.CompositeMetadataRepository.<init>(CompositeMetadataRepository.java:101)
	at org.eclipse.equinox.internal.p2.metadata.repository.CompositeMetadataRepositoryFactory.validateAndLoad(CompositeMetadataRepositoryFactory.java:127)
	at org.eclipse.equinox.internal.p2.metadata.repository.CompositeMetadataRepositoryFactory.load(CompositeMetadataRepositoryFactory.java:87)
	at org.eclipse.equinox.internal.p2.metadata.repository.MetadataRepositoryManager.factoryLoad(MetadataRepositoryManager.java:54)
	at org.eclipse.equinox.internal.p2.repository.helpers.AbstractRepositoryManager.loadRepository(AbstractRepositoryManager.java:667)
	at org.eclipse.equinox.internal.p2.repository.helpers.AbstractRepositoryManager.loadRepository(AbstractRepositoryManager.java:615)
	at org.eclipse.equinox.internal.p2.metadata.repository.MetadataRepositoryManager.loadRepository(MetadataRepositoryManager.java:92)
	at org.eclipse.equinox.internal.p2.metadata.repository.MetadataRepositoryManager.loadRepository(MetadataRepositoryManager.java:88)
	at org.eclipse.equinox.internal.provisional.p2.ui.operations.ProvisioningUtil.loadMetadataRepository(ProvisioningUtil.java:88)
	at org.eclipse.equinox.internal.p2.ui.model.MetadataRepositoryElement.getMetadataRepository(MetadataRepositoryElement.java:111)
	at org.eclipse.equinox.internal.p2.ui.model.MetadataRepositoryElement.getRepository(MetadataRepositoryElement.java:105)
	at org.eclipse.equinox.internal.p2.ui.model.MetadataRepositoryElement.fetchChildren(MetadataRepositoryElement.java:73)
	at org.eclipse.equinox.internal.p2.ui.model.RemoteQueriedElement.fetchDeferredChildren(RemoteQueriedElement.java:33)
	at org.eclipse.ui.progress.DeferredTreeContentManager$1.run(DeferredTreeContentManager.java:234)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)
Comment 3 Susan McCourt CLA 2009-05-18 19:35:04 EDT
Looking at the code, I think that indeed the log is pointing us back to the original problem.  

In bug 275398, we introduced a monitor parmater to AbstractRepositoryManager.enterLoad(...) and we need to check for a null progress monitor.  :-(   (Something I should have realized in the review).

So the NPE is logged and the repo manager is left with a null result. 

This code (starting at line 628 in AbstractRepositoryManager) causes a NOT_FOUND to be thrown. 

if (result == null) {
	//if we just added the repository, remove it because it cannot be loaded
	if (added)
		removeRepository(location, false);
	//eagerly cleanup missing system repositories
	if (Boolean.valueOf(getRepositoryProperty(location, IRepository.PROP_SYSTEM)).booleanValue())
		removeRepository(location);
	else if (failure == null || failure.getStatus().getCode() != ProvisionException.REPOSITORY_FAILED_AUTHENTICATION)
>>>		rememberNotFound(location);
		if (failure != null)
			throw failure;
>>>		fail(location, ProvisionException.REPOSITORY_NOT_FOUND);
}

I think we just need to fix the repo manager to check for a null progress monitor.  

Comment 4 John Arthorne CLA 2009-05-18 22:13:40 EDT
I think you're right. Although, the NPE is only caught by the repository manager in the composite repository case, which could explain why I had so much trouble reproducing this at first. The only way I reliably found to reproduce this was when adding our integration build repository, which is a composite. The fact that it is timing related makes it even more subtle - the NPE only occurs if there is actually contention for the lock.
Comment 5 John Arthorne CLA 2009-05-18 22:14:37 EDT
Created attachment 136252 [details]
Fix and regression test v01
Comment 6 John Arthorne CLA 2009-05-18 22:16:33 EDT
The JUnit test reliably reproduces the NPE, which is fixed by the attached patch. I was also unable to reproduce the original symptom when running with the patch. Although, since the problem isn't consistently reproducible, it will take a bit more testing to be certain this is the only problem.
Comment 7 John Arthorne CLA 2009-05-18 22:17:19 EDT
DJ or Pascal, can you be second reviewer for this (whoever gets to it first).
Comment 8 Pascal Rapicault CLA 2009-05-19 13:42:03 EDT
Reviewed and released.
Comment 9 Pascal Rapicault CLA 2009-05-19 14:53:56 EDT
*** Bug 276980 has been marked as a duplicate of this bug. ***
Comment 10 John Arthorne CLA 2009-05-19 15:05:10 EDT
I don't think Susan has reviewed this yet...
Comment 11 Susan McCourt CLA 2009-05-19 15:22:39 EDT
no, I haven't yet.  I wasn't planning to review until done testing.
I will ensure that I review it before tagging for tonight's build, and if there is a problem with it, I'll pull it out.
Comment 12 Susan McCourt CLA 2009-05-19 17:07:45 EDT
reviewed.
Verified that the regression test captures the problem (it fails without the fix) and that the other caller of enterLoad (createRepository) is already creating a NullProgressMonitor.  I am running with this patch in my Eclipse and so far I have not seen the error.  

The code is already released and I think running tomorrow's build with this patch should give us more confidence that this was the only source of the original symptom.
Comment 13 John Arthorne CLA 2009-05-21 09:59:28 EDT
*** Bug 277324 has been marked as a duplicate of this bug. ***
Comment 14 Susan McCourt CLA 2009-06-01 01:31:53 EDT
*** Bug 278557 has been marked as a duplicate of this bug. ***