Comment 1 John Arthorne 2010-03-08 14:31:52 EST

Created attachment 161339 [details]
Log file

Comment 2 Olivier Thomann 2010-03-08 14:35:38 EST

Jay, please investigate.

Comment 3 John Arthorne 2010-03-09 09:46:21 EST

Created attachment 161463 [details]
Log running on I20100309-0100

This error happened again today after upgrading to the latest build. There are several more errors in the log this time so I'm attaching the new log for reference.

Comment 4 Olivier Thomann 2010-03-09 11:09:55 EST

Szymon,

Did something changed lately related to the rules scheduling?

Comment 5 Jay Arthanareeswaran 2010-03-09 11:29:14 EST

(In reply to comment #3)
> Created an attachment (id=161463) [details]
> Log running on I20100309-0100
> 
> This error happened again today after upgrading to the latest build. There are
> several more errors in the log this time so I'm attaching the new log for
> reference.

Thanks for the log, John. This is helpful. While looking at the exception and
the JDT/Core code, it looked like the most likely scenario is that there was
some problem resolving the JRE library. The following log message (from the
second log) seems to substantiate that somewhat:

!SUBENTRY 2 org.eclipse.jdt.compiler.tool 2 0 2010-03-09 09:34:25.718
!MESSAGE Missing Constraint: Bundle-RequiredExecutionEnvironment: JavaSE-1.6

Can you tell me if you get a valid JRE library in your workspace?

(In reply to comment #4)
> Szymon,
> 
> Did something changed lately related to the rules scheduling?

Olivier, the schedule rules in question here are introduced by bug 289560. However, this happens only in the scenario that I just mentioned. I will investigate further.

Comment 6 Olivier Thomann 2010-03-09 11:31:07 EST

John is using a EE 1.5 so all bundles that require 1.6 won't resolve. This is expected and should not cause grief.

Comment 7 Szymon Brandys 2010-03-09 11:50:03 EST

(In reply to comment #4)
> Szymon,
> 
> Did something changed lately related to the rules scheduling?

I don't think it is a problem with scheduling itself. The first rule just doesn't contain the second one. You should investigate the code that creates these MultiRules and it seems that Jay is investigating this code already.

Comment 8 John Arthorne 2010-03-09 12:04:20 EST

Interestingly, although I have many projects in my workspace, the error occurred in the same two projects both times. Jay asked me to look at the build paths on these projects, and it turns out they both have build path errors;

org.eclipse.ebots.client: build path has JavaSE-1.6 container on the build path, but I have not Java 1.6 JRE installed on my system so the container is unbound.

org.eclipse.releng.basebuilder: its build path has an entry "j2ee.jar" that is missing

Comment 9 Ian Trimble 2010-03-10 18:44:17 EST

What's interesting here is if you search for ".org.eclipse.jdt.core.external.folders" you'll see a lot of bugs appearing, and, in my opinion, they all have the same root cause - some process is creating this ".org.eclipse.jdt.core.external.folders" folder in the "{workspace}/.metadata/.plugins/org.eclipse.core.resources/.projects" folder and this is NOT a good place for it be created.

I too, am hitting issues where the rule doesn't match the outer scope due to this folder being created. Who's creating this folder here, and why? This is just plain WRONG.

Comment 10 John Arthorne 2010-03-11 08:54:46 EST

.org.eclipse.jdt.core.external.folders is actually a project in your workspace. It is hidden from view for the end user because it is for internal use by JDT to track entries on your build path that are outside your workspace. From an end user perspective you shouldn't know or care about the existence of this project. 

Jay can correct me, but I don't think that project is the source of the problem in this case - it just happens to be involved in the classpath initialization process, and in this case there is a nested classpath initialization happening that shouldn't.

Comment 11 Ian Trimble 2010-03-11 11:05:47 EST

Ok, but why am I only recently seeing breakage all around this, such as errors stating that the project metadata (.project) can't be located for the project, and the WorkspaceJobManager complaining because the outer scope doesn't contain the project but the inner one does (i.e. "this workspace has changed!")?

These seem unrelated, which lead me to assume that the creation of this "project" folder was a recent change. I've never seen the project before in my filesystem, but am seeing it now, and colleagues who say they have seen related issues say they can't locate the project in any workspace.

So, are you telling me that this is unchanged and related functionality in seemingly-varied other areas has changed? If so, then I stand corrected, and will log more appropriate issues elsewhere. Right now, I have 97 JUnit test errors and failures because of the workspace job rule scope issue, where I didn't before.

Comment 12 Jay Arthanareeswaran 2010-03-13 05:02:30 EST

(In reply to comment #10)
> 
> Jay can correct me, but I don't think that project is the source of the problem
> in this case - it just happens to be involved in the classpath initialization
> process, and in this case there is a nested classpath initialization happening
> that shouldn't.

Yes, we didn't add anything to the creation of the external project folder project itself in this milestone. To my knowledge, only change that has happened around this is the new schedule rule for the container set operation.

(In reply to comment #11)
> Ok, but why am I only recently seeing breakage all around this, such as errors
> stating that the project metadata (.project) can't be located for the project,
> and the WorkspaceJobManager complaining because the outer scope doesn't contain
> the project but the inner one does (i.e. "this workspace has changed!")?

Can you please add the details about the rules scope problem here? It will be interesting to see if it's the same scenario as John's or a different one.

> So, are you telling me that this is unchanged and related functionality in
> seemingly-varied other areas has changed? If so, then I stand corrected, and
> will log more appropriate issues elsewhere. Right now, I have 97 JUnit test
> errors and failures because of the workspace job rule scope issue, where I
> didn't before.

As mentioned earlier, add the details of the rule scope problem here.

Comment 13 Jay Arthanareeswaran 2010-03-13 05:10:24 EST

There seems to be a couple of places where one SetContainerOperation can be invoked within another but under exceptional conditions. While one way of fixing this bug would be to get rid of such possibilities, I feel that the long term solution would be to allow operations to find out about the outer rules if any in that thread so that they can add the new rules to the existing multi rule. John can probably comment on or add to this part.

Comment 14 John Arthorne 2010-03-15 16:34:44 EDT

(In reply to comment #13)
> I feel that the long
> term solution would be to allow operations to find out about the outer rules if
> any in that thread so that they can add the new rules to the existing multi
> rule.

By design, a thread that owns a scheduling rule is not allowed to obtain another rule because of the deadlock risk. For example if thread 1 was doing classpath intialization in the order A -> B and thread 2 had the order B -> A then you would deadlock.

Comment 15 Ian Trimble 2010-03-16 14:07:55 EDT

Here's an example of what I am seeing a lot - it seems one WorkspaceJob "sees" the hidden folder, while another doesn't, resulting in the IllegalArgumentException.

java.lang.IllegalArgumentException: Attempted to beginRule: MultiRule[P/testCreateFromELExpression_FileReferencesWebProject_,P/.org.eclipse.jdt.core.external.folders], does not match outer scope rule: P/testCreateFromELExpression_FileReferencesWebProject_
at org.eclipse.core.runtime.Assert.isLegal(Assert.java:63)
at org.eclipse.core.internal.jobs.ThreadJob.illegalPush(ThreadJob.java:136)
at org.eclipse.core.internal.jobs.ThreadJob.push(ThreadJob.java:326)
at org.eclipse.core.internal.jobs.ImplicitJobs.begin(ImplicitJobs.java:63)
at org.eclipse.core.internal.jobs.JobManager.beginRule(JobManager.java:285)
at org.eclipse.core.internal.resources.WorkManager.checkIn(WorkManager.java:117)
at org.eclipse.core.internal.resources.Workspace.prepareOperation(Workspace.java:1918)
at org.eclipse.core.internal.resources.Workspace.run(Workspace.java:1974)
at org.eclipse.jdt.internal.core.JavaModelOperation.runOperation(JavaModelOperation.java:793)
at org.eclipse.jdt.core.JavaCore.setClasspathContainer(JavaCore.java:4833)
at org.eclipse.jdt.internal.launching.JREContainerInitializer.initialize(JREContainerInitializer.java:69)
at org.eclipse.jdt.internal.core.JavaModelManager.initializeContainer(JavaModelManager.java:2695)
at org.eclipse.jdt.internal.core.JavaModelManager.getClasspathContainer(JavaModelManager.java:1842)
at org.eclipse.jdt.core.JavaCore.getClasspathContainer(JavaCore.java:2699)
at org.eclipse.jdt.internal.core.JavaProject.resolveClasspath(JavaProject.java:2664)
at org.eclipse.jdt.internal.core.JavaProject.resolveClasspath(JavaProject.java:2802)
at org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath(JavaProject.java:1946)
at org.eclipse.jst.jsp.core.taglib.ProjectDescription.ensureUpTodate(ProjectDescription.java:994)
at org.eclipse.jst.jsp.core.taglib.ProjectDescription.getAvailableTaglibRecords(ProjectDescription.java:1085)
at org.eclipse.jst.jsp.core.taglib.TaglibIndex.internalGetAvailableTaglibRecords(TaglibIndex.java:847)
at org.eclipse.jst.jsp.core.taglib.TaglibIndex.getAvailableTaglibRecords(TaglibIndex.java:506)
at org.eclipse.jst.jsf.core.metadata.internal.TaglibMetaDataLocator.locateMetaDataModelProviders(TaglibMetaDataLocator.java:69)
at org.eclipse.jst.jsf.common.metadata.internal.DomainLoadingStrategy.locateMetaDataSourceInstances(DomainLoadingStrategy.java:143)
at org.eclipse.jst.jsf.common.metadata.internal.DomainLoadingStrategy.load(DomainLoadingStrategy.java:54)
at org.eclipse.jst.jsf.common.metadata.internal.MetaDataModel.load(MetaDataModel.java:80)
at org.eclipse.jst.jsf.common.metadata.internal.MetaDataModelManager.loadMetadata(MetaDataModelManager.java:220)
at org.eclipse.jst.jsf.common.metadata.internal.MetaDataModelManager.getModel(MetaDataModelManager.java:150)
at org.eclipse.jst.jsf.common.metadata.query.TaglibDomainMetaDataQueryHelper.getMDModel(TaglibDomainMetaDataQueryHelper.java:197)
at org.eclipse.jst.jsf.common.metadata.query.TaglibDomainMetaDataQueryHelper.getModel(TaglibDomainMetaDataQueryHelper.java:73)
at org.eclipse.jst.jsf.common.metadata.query.TaglibDomainMetaDataQueryHelper.getEntities(TaglibDomainMetaDataQueryHelper.java:111)
at org.eclipse.jst.jsf.common.metadata.query.TaglibDomainMetaDataQueryHelper.getEntity(TaglibDomainMetaDataQueryHelper.java:89)
at org.eclipse.jst.jsf.common.metadata.query.TaglibDomainMetaDataQueryHelper.getTrait(TaglibDomainMetaDataQueryHelper.java:210)

...snip...

Comment 16 Jay Arthanareeswaran 2010-03-18 01:24:13 EDT

An observation: Looking at the stack trace, there are two invocations of the
JavaModelManager#initializeAllContainers in the same stack. This could be
because JavaModelManager#batchContainerInitializations returns true even if the
state is BATCH_INITIALIZATION_IN_PROGRESS. This makes multiple calls to
initializeAllContainers (not necessarily in the same thread) possible. I am not
quite sure if that is the intended behavior.

I am investigating further.

Comment 17 Jay Arthanareeswaran 2010-03-18 01:34:15 EDT

(In reply to comment #15)
> Here's an example of what I am seeing a lot - it seems one WorkspaceJob "sees"
> the hidden folder, while another doesn't, resulting in the
> IllegalArgumentException.
> 
> java.lang.IllegalArgumentException: Attempted to beginRule:
> MultiRule[P/testCreateFromELExpression_FileReferencesWebProject_,P/.org.eclipse.jdt.core.external.folders],
> does not match outer scope rule:
> P/testCreateFromELExpression_FileReferencesWebProject_
> at org.eclipse.core.runtime.Assert.isLegal(Assert.java:63)
> at org.eclipse.core.internal.jobs.ThreadJob.illegalPush(ThreadJob.java:136)
> at org.eclipse.core.internal.jobs.ThreadJob.push(ThreadJob.java:326)
> at org.eclipse.core.internal.jobs.ImplicitJobs.begin(ImplicitJobs.java:63)
> at org.eclipse.core.internal.jobs.JobManager.beginRule(JobManager.java:285)
> at
> org.eclipse.core.internal.resources.WorkManager.checkIn(WorkManager.java:117)
> at

Ian,

Can you please attach the complete log file, which has this stack trace?

Comment 18 Jay Arthanareeswaran 2010-03-18 05:47:39 EDT

(In reply to comment #17)
> Ian,
> 
> Can you please attach the complete log file, which has this stack trace?

It would help to have the log file with the following debug options turned on:

org.eclipse.jdt.core/debug=true
org.eclipse.jdt.core/debug/javamodel=true
org.eclipse.jdt.core/debug/javamodel/cache=true
org.eclipse.jdt.core/debug/cpresolution=true
org.eclipse.jdt.core/debug/cpresolution/advanced=true
org.eclipse.jdt.core/debug/cpresolution/failure=true

The first one is enabled by default. Just make sure it is 'true' and also the -debug command line option is passed on to eclipse.

Comment 19 Jay Arthanareeswaran 2010-03-18 07:17:49 EDT

*** Bug 305869 has been marked as a duplicate of this bug. ***

Comment 20 Ian Trimble 2010-03-18 15:13:16 EDT

Created attachment 162454 [details]
Log File from ian.trimble

As requested.

Comment 21 Ian Trimble 2010-03-18 15:14:14 EDT

Created attachment 162455 [details]
Console Output from ian.trimble

As requested.

Comment 22 Jay Arthanareeswaran 2010-03-19 10:14:49 EDT

(In reply to comment #21)
> Created an attachment (id=162455) [details]
> Console Output from ian.trimble
> 
> As requested.

Thanks, Ian. 

Finally I am able to reproduce the problem consistently. The issue manifests (but not limited to) when we have two or more projects using JavaSE-1.6 Execution Environment but we don't have a compatible JRE (i.e. 1.6 or above). I will soon post a patch and perhaps a plug-in patch too, so that Ian/John can verify the fix.

Comment 23 Jay Arthanareeswaran 2010-03-19 11:23:00 EDT

Created attachment 162531 [details]
Proposed Fix

Proposed fix. Tests will be added once plug-in patch with fix is verified.

The fix is to not allow multiple invocations of initializeAllContainers simultaneously.  When the batch initialization is already in progress (i.e. state BATCH_INITIALIZATION_IN_PROGRESS), JavaModelManager#batchContainerInitializations returns false.

Comment 24 Jay Arthanareeswaran 2010-03-19 12:07:06 EDT

Created attachment 162536 [details]
Plug-in Patch

Ian/John,

Could you please test if this plug-in patch addresses the bug.

By the way, I don't see bug 305869 getting fixed with this one. I will take another look at it and if required re-open the bug.

Comment 25 Ian Trimble 2010-03-22 14:21:57 EDT

(In reply to comment #24)
> Created an attachment (id=162536) [details]
> Plug-in Patch
> Ian/John,
> Could you please test if this plug-in patch addresses the bug.
> By the way, I don't see bug 305869 getting fixed with this one. I will take
> another look at it and if required re-open the bug.

Could you please advise how to test a "plug-in patch"? I tried the obvious (place the file in plugins, place the file in dropins, -clean each time, even remove older plugin JAR), but nothing I do will show the newer plug-in as being active, and the fix behaviour is not present.

Comment 26 Jay Arthanareeswaran 2010-03-23 01:07:11 EDT

*** Bug 306784 has been marked as a duplicate of this bug. ***

Comment 27 Jay Arthanareeswaran 2010-03-23 13:11:59 EDT

(In reply to comment #25)
> Could you please advise how to test a "plug-in patch"? I tried the obvious
> (place the file in plugins, place the file in dropins, -clean each time, even
> remove older plugin JAR), but nothing I do will show the newer plug-in as being
> active, and the fix behaviour is not present.

That should do it. Can you please tell me what version of the JDT plug-in you have. I can provide one with the same version.

Comment 28 Ian Trimble 2010-03-23 14:06:54 EDT

(In reply to comment #27)
> That should do it. Can you please tell me what version of the JDT plug-in you
> have. I can provide one with the same version.

I didn't realize the version was the issue, my mistake. I hacked the version to 3.6.0.v_A32a and verified the plug-in was active, but there was no overall change in behaviour. I see now that what I am experiencing is a change in scheduling rules - what is being compared is a single project and a workspace root (I'm not sure what used to be compared; perhaps some process used to run without any rule at all). So I'm not even sure I am testing for the same issue that you are fixing any longer. That is, your fix may be fine, I'm just not sure how to test it (your fix does nothing to affect my scheduling rule conflicts).

Comment 29 Jay Arthanareeswaran 2010-03-23 14:40:24 EDT

(In reply to comment #28)
> (In reply to comment #27)
> > That should do it. Can you please tell me what version of the JDT plug-in you
> > have. I can provide one with the same version.
> 
> I didn't realize the version was the issue, my mistake. I hacked the version to
> 3.6.0.v_A32a and verified the plug-in was active, but there was no overall
> change in behaviour. I see now that what I am experiencing is a change in
> scheduling rules - what is being compared is a single project and a workspace
> root (I'm not sure what used to be compared; perhaps some process used to run
> without any rule at all). So I'm not even sure I am testing for the same issue
> that you are fixing any longer. That is, your fix may be fine, I'm just not
> sure how to test it (your fix does nothing to affect my scheduling rule
> conflicts).

Can you please post your new error message and the exception from the log? The patch should address the issue reported in comment #15. The fix was not to change any schedule rules but simply avoid the nested calls to the SetContainerOperation.

Comment 30 Carlin Rogers 2010-03-23 14:49:07 EDT

Hi Ian, Jay,

I agree, I think we're now looking at a different issue. This appears to be a conflict caused by a change to the SetContainerOperation class. It now overrides getSchedulingRule() returning the MultiRule that includes the external folder. Previously, the parent class, ChangeClasspathOperation, just returned null so there where no scheduling rule conflicts. Jay pointed out bug 289560.

So now, if a thread has a scheduling rule such as a project, and there is a JDT call that invokes the SetContainerOperation (as in the case of calling the JSFAppConfigManager), it will try to get/resolve a class path for the project and the Java Model will run a workspace runnable with the operation and the MultiRule from the operation. This causes the rule conflict. Maybe the operation could check to see if the current job already has a rule and if there is a conflict while creating the MultiRule.

I have a simple test that will cause the IllegalArgumentException without going through the initializeAllContainers() discussed here. 

java.lang.IllegalArgumentException: Attempted to beginRule: MultiRule[P/testBug_SerializationTestProject_,P/.org.eclipse.jdt.core.external.folders], does not match outer scope rule: P/testBug_SerializationTestProject_
	at org.eclipse.core.runtime.Assert.isLegal(Assert.java:63)
	at org.eclipse.core.internal.jobs.ThreadJob.illegalPush(ThreadJob.java:136)
	at org.eclipse.core.internal.jobs.ThreadJob.push(ThreadJob.java:326)
	at org.eclipse.core.internal.jobs.ImplicitJobs.begin(ImplicitJobs.java:63)
	at org.eclipse.core.internal.jobs.JobManager.beginRule(JobManager.java:285)
	at org.eclipse.core.internal.resources.WorkManager.checkIn(WorkManager.java:117)
	at org.eclipse.core.internal.resources.Workspace.prepareOperation(Workspace.java:1914)
	at org.eclipse.core.internal.resources.Workspace.run(Workspace.java:1970)
	at org.eclipse.jdt.internal.core.JavaModelOperation.runOperation(JavaModelOperation.java:793)
	at org.eclipse.jdt.core.JavaCore.setClasspathContainer(JavaCore.java:4833)
	at org.eclipse.jdt.internal.launching.JREContainerInitializer.initialize(JREContainerInitializer.java:69)
	at org.eclipse.jdt.internal.core.JavaModelManager.initializeContainer(JavaModelManager.java:2695)
	at org.eclipse.jdt.internal.core.JavaModelManager.getClasspathContainer(JavaModelManager.java:1842)
	at org.eclipse.jdt.core.JavaCore.getClasspathContainer(JavaCore.java:2699)
	at org.eclipse.jdt.internal.core.JavaProject.resolveClasspath(JavaProject.java:2639)
	at org.eclipse.jdt.internal.core.JavaProject.resolveClasspath(JavaProject.java:2777)
	at org.eclipse.jdt.internal.core.JavaProject.getResolvedClasspath(JavaProject.java:1946)
	at org.eclipse.jst.jsf.core.jsfappconfig.JSFAppConfigUtils.getConfigFileJARsFromClasspath(JSFAppConfigUtils.java:326)
	at org.eclipse.jst.jsf.core.jsfappconfig.RuntimeClasspathJSFAppConfigLocater.locateProviders(RuntimeClasspathJSFAppConfigLocater.java:64)
	at org.eclipse.jst.jsf.core.jsfappconfig.RuntimeClasspathJSFAppConfigLocater.startLocating(RuntimeClasspathJSFAppConfigLocater.java:45)
	at org.eclipse.jst.jsf.core.jsfappconfig.JSFAppConfigManager.startConfigLocaters(JSFAppConfigManager.java:284)
	at org.eclipse.jst.jsf.core.jsfappconfig.JSFAppConfigManager.initialize(JSFAppConfigManager.java:247)

Comment 31 Jay Arthanareeswaran 2010-03-23 15:50:40 EDT

(In reply to comment #30)
> Maybe the
> operation could check to see if the current job already has a rule and if there
> is a conflict while creating the MultiRule.
> 

Yes, that would eliminate this and other similar bugs (bug 305869 and bug 306784). However, we won't be able to address scenarios such as bug 289560. Besides, operations such as SetContainerOperation and SetClasspathOperation (which also has a rule) would want to have their own rules.

Comment 32 Min Idzelis 2010-03-23 17:27:56 EDT

Not sure if it helps in this case, but I want to call your attention to new API in Eclipse 3.6M6. 

JobManager.currentRule() (which tells you what active rule, if any is present) 

and

JobManager.currentJob().yieldRule() (which will temporarily pause the running job to let another conflicting job to run)

Comment 33 Jay Arthanareeswaran 2010-03-30 12:57:33 EDT

I tried something similar to the following code and doesn't seem to help. I am wondering if yielding makes a difference to nested jobs at all or if the following code is missing something.

Job baseJob = Job.getJobManager().currentJob();
ISchedulingRule baseRule = baseJob.getRule(); // == Job.getJobManager().currentRule() ? 
boolean conflicting = false;
...
if (!conflicting && baseRule != null && baseRule.isConflicting(rules[length]))
	conflicting = true;

ISchedulingRule newRule = new MultiRule(rules);
if (conflicting) 
	baseJob.yieldRule(this.progressMonitor);

The ThreadJob that is throwing IAE doesn't seem to check for the status of the base job (whether it's WAITING or not) at all. And hence yielding the base job may not make a difference and I continue to see the error. Investigating further.

Comment 34 Jay Arthanareeswaran 2010-04-08 05:41:44 EDT

Created attachment 164188 [details]
Reversal of fix to bug 289560

The bug 289560 (whose fix caused this one) perhaps has been fixed by 260968. Hence rolling back those changes, which should take care of this one.

Comment 35 Jay Arthanareeswaran 2010-04-08 06:12:57 EDT

Released the changes in HEAD for 3.6M7.

Comment 36 Jay Arthanareeswaran 2010-04-22 09:55:15 EDT

*** Bug 310070 has been marked as a duplicate of this bug. ***

Comment 37 Satyam Kandula 2010-04-26 11:14:38 EDT

Verified for 3.6M7 using build I20100424-2000

Comment 38 Olivier Thomann 2010-04-26 11:17:00 EDT

Verified.

Comment 39 Carlin Rogers 2010-04-30 17:03:33 EDT

Appreciate the fix Jay - we've verified that this works for us as well.