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

Bug 314176

Summary: Deadlock can occur between JSPModelProcessor and tag registry via MD framework
Product: [WebTools] Java Server Faces Reporter: Cameron Bateman <cameron.bateman>
Component: CoreAssignee: Cameron Bateman <cameron.bateman>
Status: RESOLVED FIXED QA Contact:
Severity: normal    
Priority: P3 CC: carlin.rogers, gerry.kessler, raghunathan.srinivasan
Version: 3.2Flags: raghunathan.srinivasan: pmc_approved+
raghunathan.srinivasan: pmc_approved? (david_williams)
raghunathan.srinivasan: pmc_approved? (naci.dai)
deboer: pmc_approved+
raghunathan.srinivasan: pmc_approved? (neil.hauge)
raghunathan.srinivasan: pmc_approved? (kaloyan)
carlin.rogers: review+
gerry.kessler: review+
Target Milestone: 3.2 RC3   
Hardware: PC   
OS: Windows XP   
Whiteboard: PMC_approved
Attachments:
Description Flags
Proposed fix. none

Description Cameron Bateman CLA 2010-05-24 18:47:53 EDT 
The stack trace below was encountered during testing.  Basically what happens is that one thread (worker-3) tries to access some metadata for a tag in JSPModelProcessor while holding a workspace rule lock.  So it holds the rule and waits for GLOBAL_INSTANCE_LOCK in the MetadataModelManager.  At same time, another thread is attempting to lazily initialize the MD model.  It takes the GLOBAL_INSTANCE_LOCK and then after calling into the tag registry, it eventually tries to take a rule lock that conflicts with worker-3.  Thus deadlock.



org.eclipse.equinox.launcher.Main at localhost:2402 (Suspended)	
	Thread [Main Thread] (Suspended)	
	Daemon System Thread [(Signal Handler)] (Suspended)	
	Daemon System Thread [(GC Main Thread)] (Suspended)	
	Daemon System Thread [(Code Generation Thread 1)] (Suspended)	
	Daemon System Thread [(Code Optimization Thread 1)] (Suspended)	
	Daemon System Thread [(VM Periodic Task)] (Suspended)	
	Daemon System Thread [(Attach Listener)] (Suspended)	
	Daemon System Thread [Finalizer] (Suspended)	
	Daemon System Thread [Reference Handler] (Suspended)	
	Daemon System Thread [(Sensor Event Thread)] (Suspended)	
	Daemon System Thread [RMI TCP Accept-0] (Suspended)	
	Daemon Thread [State Data Manager] (Suspended)	
	Daemon Thread [Start Level Event Dispatcher] (Suspended)	
	Daemon Thread [Framework Event Dispatcher] (Suspended)	
	Daemon Thread [[Timer] - Main Queue Handler] (Suspended)	
	Daemon Thread [Bundle File Closer] (Suspended)	
	Thread [Worker-JM] (Suspended)	
	Thread [Worker-0] (Suspended)	
	Thread [Worker-1] (Suspended)	
	Daemon Thread [Java indexing] (Suspended)	
	Thread [Worker-3] (Suspended)	
		owns: JSPModelProcessor$CountingMutex  (id=247)	
		waiting for: Object  (id=115)	
		MetaDataModelManager.getModel(IMetaDataModelContext) line: 60	
		TaglibDomainMetaDataQueryHelper.getMDModel(ITaglibDomainMetaDataModelContext) line: 205	
		TaglibDomainMetaDataQueryHelper.getModel(ITaglibDomainMetaDataModelContext) line: 90	
		TaglibDomainMetaDataQueryHelper.getEntities(ITaglibDomainMetaDataModelContext, String, IEntityQueryVisitor) line: 123	
		TaglibDomainMetaDataQueryHelper.getEntity(ITaglibDomainMetaDataModelContext, String) line: 101	
		ViewMetadataLoader.getTagToViewMapping(TagIdentifier) line: 44	
		DefaultJSPTagResolver.resolve(TLDElementDeclaration) line: 82	
		<unknown receiving type>(JSPTagResolvingStrategy).resolve(Object) line: 1	
		DefaultJSPTagResolver(AbstractTagResolvingStrategy<TLDELEMENT,IDTYPE>).perform(TLDELEMENT) line: 42	
		<unknown receiving type>(AbstractTagResolvingStrategy<TLDELEMENT,IDTYPE>).perform(Object) line: 1	
		StrategyComposite$DefaultCompositionStrategy<INPUT,OUTPUT,RESULTOUTPUT,STRATEGY>.compose(CompositionArguments<INPUT,OUTPUT,STRATEGY>) line: 180	
		CompositeTagResolvingStrategy<TLDELEMENT>(StrategyComposite<INPUT,OUTPUT,RESULTOUTPUT,IDTYPE,STRATEGYTYPE>).perform(INPUT) line: 66	
		CompositeTagResolvingStrategy<TLDELEMENT>.resolve(TLDELEMENT) line: 64	
		TLDNamespace$DocumentTLDNamespaceData.createTagElement(String) line: 162	
		TLDNamespace$DocumentTLDNamespaceData.getViewElement(String) line: 206	
		TLDNamespace.getViewElement(String) line: 78	
		XMLViewDefnAdapter.findTagElement(String, Namespace) line: 227	
		JSPViewDefnAdapter(TaglibBasedViewDefnAdapter).findTagElement(Element, IDocument) line: 57	
		JSPViewDefnAdapter(XMLViewDefnAdapter).mapToTagElement(Node, IDocument) line: 97	
		ViewBasedTaglibResolverFactory$ViewBasedTaglibResolver._getTagElement(Node) line: 212	
		ViewBasedTaglibResolverFactory$ViewBasedTaglibResolver.hasTag(Node) line: 173	
		JSPModelProcessor.processAttributes(IDOMModel, Node, ITaglibContextResolver) line: 512	
		JSPModelProcessor.recurseChildNodes(IDOMModel, NodeList, ITaglibContextResolver) line: 504	
		JSPModelProcessor.recurseChildNodes(IDOMModel, NodeList, ITaglibContextResolver) line: 505	
		JSPModelProcessor.recurseChildNodes(IDOMModel, NodeList, ITaglibContextResolver) line: 505	
		JSPModelProcessor.recurseChildNodes(IDOMModel, NodeList, ITaglibContextResolver) line: 505	
		JSPModelProcessor.refreshInternal(IDOMModel) line: 490	
		JSPModelProcessor.access$3(JSPModelProcessor, IDOMModel) line: 472	
		JSPModelProcessor$RefreshRunnable.run(IProgressMonitor) line: 445	
		JSPModelProcessor$3.runInWorkspace(IProgressMonitor) line: 387	
		JSPModelProcessor$3(InternalWorkspaceJob).run(IProgressMonitor) line: 38	
		Worker.run() line: 54	
	Thread [Worker-2] (Suspended)	
	Thread [Worker-4] (Suspended)	
	Thread [Worker-5] (Suspended)	
		owns: ProjectTaglibDescriptor  (id=248)	
		owns: FaceletTagRegistry  (id=249)	
		owns: FaceletTagRegistry  (id=249)	
		owns: MetaDataModel  (id=250)	
		owns: Object  (id=115)	
		waiting for: Object  (id=244)	
		Object.wait(long) line: not available [native method]	
		ThreadJob.waitForRun(ThreadJob, IProgressMonitor, InternalJob, Thread) line: 269	
		ThreadJob.joinRun(ThreadJob, IProgressMonitor) line: 199	
		ImplicitJobs.begin(ISchedulingRule, IProgressMonitor, boolean) line: 92	
		JobManager.beginRule(ISchedulingRule, IProgressMonitor) line: 285	
		WorkManager.checkIn(ISchedulingRule, IProgressMonitor) line: 117	
		Workspace.prepareOperation(ISchedulingRule, IProgressMonitor) line: 1914	
		Workspace.run(IWorkspaceRunnable, ISchedulingRule, int, IProgressMonitor) line: 1970	
		Web25MergedModelProvider(AbstractMergedModelProvider<T>).loadModel() line: 229	
		Web25MergedModelProvider(AbstractMergedModelProvider<T>).getMergedModel() line: 213	
		Web25MergedModelProvider(AbstractMergedModelProvider<T>).getModelObject() line: 133	
		WebappConfiguration.getConfigFilesFromContextParam(IProject, IModelProvider) line: 184	
		WebappConfiguration.getFiles() line: 115	
		TaglibResourceManager.initResources() line: 62	
		ContextParamSpecifiedFaceletTaglibLocator.start(IProject) line: 82	
		<unknown receiving type>(ContextParamSpecifiedFaceletTaglibLocator).start(Object) line: 1	
		ProjectTaglibDescriptor$1.run() line: 79	
		SafeRunner.run(ISafeRunnable) line: 42	
		ProjectTaglibDescriptor.initialize() line: 68	
		ProjectTaglibDescriptor.getTagLibraries() line: 90	
		FaceletTagRegistry.initialize(boolean) line: 155	
		FaceletTagRegistry.getAllTagLibraries() line: 110	
		FaceletTagRegistry.getTagLibrary(String) line: 201	
		FaceletNamespaceMetaDataLocator.locateMetaDataModelProviders(String) line: 42	
		JSPTagLibDomainLoadingStrategy(DomainLoadingStrategy).locateMetaDataSourceInstances(List<IDomainSourceModelType>, MetaDataModel) line: 143	
		JSPTagLibDomainLoadingStrategy(DomainLoadingStrategy).load(MetaDataModel) line: 55	
		MetaDataModel.load() line: 93	
		MetaDataModelManager.loadMetadata(IMetaDataModelContext) line: 112	
		MetaDataModelManager.getModel(IMetaDataModelContext) line: 66	
		TaglibDomainMetaDataQueryHelper.getMDModel(ITaglibDomainMetaDataModelContext) line: 205	
		TaglibDomainMetaDataQueryHelper.getModel(ITaglibDomainMetaDataModelContext) line: 90	
		TaglibDomainMetaDataQueryHelper.getEntities(ITaglibDomainMetaDataModelContext, String, IEntityQueryVisitor) line: 123	
		TaglibDomainMetaDataQueryHelper.getEntity(ITaglibDomainMetaDataModelContext, String) line: 101	
		ContainmentValidatingStrategy.validateContainment(Region2ElementAdapter, JSFValidationContext) line: 119	
		ContainmentValidatingStrategy.validate(DOMAdapter) line: 87	
		XMLViewDefnValidator.validateTag(IStructuredDocumentRegion, JSFValidationContext, ContainmentValidatingStrategy) line: 88	
		XMLViewDefnValidator.validateRegions(IStructuredDocumentRegion[], JSFValidationContext, ContainmentValidatingStrategy) line: 177	
		XMLViewDefnValidator.validateView(IFile, IJSFViewValidator$IValidationReporter) line: 134	
		HTMLValidator.validateFile(IFile, IReporter) line: 158	
		HTMLValidator.validate(IResource, int, ValidationState, IProgressMonitor) line: 108	
		Validator$V2.validate(IResource, int, ValOperation, IProgressMonitor, ValidationEvent) line: 1132	
		ValManager.validate(Validator, ValOperation, IResource, int, IProgressMonitor, ValidationEvent) line: 704	
		ValManager$1.visit(Validator, IProject, ValType, ValOperation, IProgressMonitor) line: 665	
		ValManager.accept(IValidatorVisitor, IProject, IResource, ValType, ValOperation, IProgressMonitor) line: 810	
		ValManager.validate(IProject, IResource, int, ValType, int, ValOperation, IProgressMonitor) line: 669	
		ValBuilderJob$Visitor.visit(IResourceDelta) line: 320	
		ResourceDelta.accept(IResourceDeltaVisitor, int) line: 68	
		ResourceDelta.accept(IResourceDeltaVisitor, int) line: 79	
		ResourceDelta.accept(IResourceDeltaVisitor, int) line: 79	
		ResourceDelta.accept(IResourceDeltaVisitor) line: 48	
		ValBuilderJob.deltaBuild(ValBuilderJob$ValidationRequest, IProgressMonitor) line: 210	
		ValBuilderJob.run(ValBuilderJob$ValidationRequest, IProgressMonitor) line: 178	
		ValBuilderJob.runInWorkspace(IProgressMonitor) line: 125	
		ValBuilderJob(InternalWorkspaceJob).run(IProgressMonitor) line: 38	
		Worker.run() line: 54	
	Thread [Worker-6] (Suspended)	
	Thread [Worker-7] (Suspended)	
	Thread [Worker-8] (Suspended)	
	Daemon Thread [[ThreadPool Manager] - Idle Thread] (Suspended)	
	Daemon Thread [JavaScript indexing] (Suspended)	
	Thread [Worker-9] (Suspended)
Comment 1 Cameron Bateman CLA 2010-05-24 18:53:24 EDT 
Created attachment 169746 [details]
Proposed fix.

This attempts to resolve the problem in a similar way to the fix for ModelManagerImpl.  As I've stated on that issue, I don't think this is a long term solution, however it eliminates the chance of this particular deadlock involving rule locks and the MetadataManager lock.  The problem remains that that we can't predict the order of locks held when called, take a lock and then call out into code we don't control (i.e. the tag registry with all its possible locators).

This stop gap attempts to resolve the situation by spinning on a ReentrantLock with 5000 second timeouts.  Each time it fails to take the lock, it attempts to yield any rules it holds.  Ultimately, MD model acquisition will fail after 30seconds.
Comment 2 Cameron Bateman CLA 2010-05-24 18:55:37 EDT 
> with 5000 second timeouts.  Each time it fails to take the lock, it attempts to

Meant 5000 milliseconds :)
Comment 3 Gerry Kessler CLA 2010-05-25 11:26:15 EDT 
Good fix
Comment 4 Raghunathan Srinivasan CLA 2010-05-25 13:44:37 EDT 
* Explain why you believe this is a stop-ship defect. Or, if it is a "hotbug"
(requested by an adopter) please document it as such. 
This is a stop-ship bug. The fix avoids a deadlocak scenario discovered during testing.
* Is there a work-around? If so, why do you believe the work-around is
insufficient? 
No workaround.
* How has the fix been tested? Is there a test case attached to the bugzilla
record? Has a JUnit Test been added? 
Manual testing, reviewed by Carlin and Gerry.
* Give a brief technical overview. Who has reviewed this fix? 
See  comment 1.
* What is the risk associated with this fix?
low-medium
Comment 5 Cameron Bateman CLA 2010-05-26 18:50:13 EDT 
Patch applied to HEAD (3.2M3).