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

Bug 323431

Summary: [ActivityMgmt] ConcurrentModificationException when activities added dynamically
Product: [Eclipse Project] Platform Reporter: Paul Webster <pwebster>
Component: UIAssignee: Oleg Besedin <ob1.eclipse>
Status: VERIFIED FIXED QA Contact: Oleg Besedin <ob1.eclipse>
Severity: normal    
Priority: P3 CC: bokowski, daniel_megert, edwinc, het, hokamoto, john.arthorne, kazm, liuj1, loskutov, markus.kell.r, Matthew_Hatem, ob1.eclipse, pwebster, raji, remy.suen, wbeckwith
Version: 3.4   
Target Milestone: 3.7 M7   
Hardware: PC   
OS: Windows XP   
Whiteboard:
Bug Depends on: 244757    
Bug Blocks: 393327    
Attachments:
Description Flags
Log file
none
Patch none

Description Paul Webster CLA 2010-08-23 14:59:22 EDT
+++ This bug was initially created as a clone of Bug #244757 +++

Build ID: I20080617-2000

Steps To Reproduce:
We are dynamically adding Activity extensions.
then we got the following ConcurrentModificationException.
This should be called on UI thread.

2008/08/20 15:35:11.581 SEVERE Error notifying registry change listener. ::class.method=unknown ::thread=Worker-18 ::loggername=org.eclipse.equinox.registry

        java.util.ConcurrentModificationException
        at java.util.WeakHashMap$HashIterator.next(Unknown Source)
        at org.eclipse.ui.internal.activities.MutableActivityManager.updateIdentifiers(MutableActivityManager.java:881)
        at org.eclipse.ui.internal.activities.MutableActivityManager.updateIdentifiers(MutableActivityManager.java:874)
        at org.eclipse.ui.internal.activities.MutableActivityManager.readRegistry(MutableActivityManager.java:469)
        at org.eclipse.ui.internal.activities.MutableActivityManager.access$0(MutableActivityManager.java:263)
        at org.eclipse.ui.internal.activities.MutableActivityManager$1.activityRegistryChanged(MutableActivityManager.java:104)
        at org.eclipse.ui.internal.activities.AbstractActivityRegistry.fireActivityRegistryChanged(AbstractActivityRegistry.java:61)
        at org.eclipse.ui.internal.activities.ExtensionActivityRegistry.load(ExtensionActivityRegistry.java:267)
        at org.eclipse.ui.internal.activities.ExtensionActivityRegistry.access$0(ExtensionActivityRegistry.java:115)
        at org.eclipse.ui.internal.activities.ExtensionActivityRegistry$1.registryChanged(ExtensionActivityRegistry.java:70)
        at org.eclipse.core.internal.registry.ExtensionRegistry$2.run(ExtensionRegistry.java:884)
        at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:37)
        at org.eclipse.core.internal.registry.ExtensionRegistry.processChangeEvent(Unknown Source)
        at org.eclipse.core.runtime.spi.RegistryStrategy.processChangeEvent(Unknown Source)
        at org.eclipse.core.internal.registry.osgi.ExtensionEventDispatcherJob.run(ExtensionEventDispatcherJob.java:50)
        at org.eclipse.core.internal.jobs.Worker.run(Unknown Source)


More information:
Comment 1 Dani Megert CLA 2010-08-24 07:05:58 EDT
Normally, one should put a fix into HEAD, wait a while and see whether tests and performance tests are green and then backport to the maintenance build ;-)
Comment 2 Paul Webster CLA 2010-08-26 09:05:58 EDT
We'll also have another look at the use of this off UI thread in 3.7
PW
Comment 3 Paul Webster CLA 2010-08-30 08:42:56 EDT
I've released the same code as bug 244757 into HEAD.  We will continue to investigate off-the-UI-thread use of activities.

PW
Comment 4 John Arthorne CLA 2010-09-13 14:47:19 EDT
I am seeing a lot of messages like the following in my log. Is this related or should I enter a separate bug report?

In this case it is not a change to activities, but simply a background thread that is accessing the activity API:

java.lang.Exception: Invalid Thread Access to Activity Manager
at org.eclipse.ui.internal.activities.MutableActivityManager.checkThread(MutableActivityManager.java:1001)
at org.eclipse.ui.internal.activities.MutableActivityManager.getIdentifier(MutableActivityManager.java:193)
at org.eclipse.ui.internal.activities.ProxyActivityManager.getIdentifier(ProxyActivityManager.java:76)
at org.eclipse.ui.activities.WorkbenchActivityHelper.getIdentifier(WorkbenchActivityHelper.java:57)
at org.eclipse.ui.activities.WorkbenchActivityHelper.allowUseOf(WorkbenchActivityHelper.java:104)
at org.eclipse.ui.activities.WorkbenchActivityHelper.restrictUseOf(WorkbenchActivityHelper.java:122)
at org.eclipse.ui.activities.WorkbenchActivityHelper.restrictArray(WorkbenchActivityHelper.java:624)
at org.eclipse.ui.internal.registry.EditorRegistry$RelatedRegistry.getRelatedObjects(EditorRegistry.java:96)
at org.eclipse.ui.internal.registry.EditorRegistry.findRelatedObjects(EditorRegistry.java:1543)
at org.eclipse.ui.internal.registry.EditorRegistry.getEditorForContentType(EditorRegistry.java:1394)
at org.eclipse.ui.internal.registry.EditorRegistry.getImageDescriptor(EditorRegistry.java:1417)
at org.eclipse.ui.internal.ide.ContentTypeDecorator.decorate(ContentTypeDecorator.java:53)
Comment 5 John Arthorne CLA 2010-09-13 14:48:12 EDT
(In reply to comment #4)

This is on I20100907-0800 and also I20100912-2000.
Comment 6 Dani Megert CLA 2010-09-14 02:03:27 EDT
>I am seeing a lot of messages like the following in my log. Is this related or
>should I enter a separate bug report?
Are you maybe running with enabled debug options and
org.eclipse.ui.workbench/debug=true
?
Comment 7 John Arthorne CLA 2010-09-15 12:01:40 EDT
(In reply to comment #6)
> Are you maybe running with enabled debug options and
> org.eclipse.ui.workbench/debug=true
> ?

Yes. I'm not complaining about seeing the logs. But I assume they are being logged for a reason, such as tracking down a problem, so I wanted to know where to report them to. I will just attach the log here.
Comment 8 John Arthorne CLA 2010-09-15 12:04:26 EDT
Created attachment 178958 [details]
Log file
Comment 9 Oleg Besedin CLA 2010-09-29 10:35:39 EDT
Any chance we can increment JRE for org.eclipse.ui.workbench to Java 1.5? As ICU now is 1.5+ that should be a mere formality.

There are 13 collections maintained by the MutableActivityManager; none of them synchronized. If we were able to switch them to ConcurrentHashMap from Java 1.5, it would be a start.

Otherwise, the MutableActivityManager needs to be significantly changed to achieve some degree of thread safety, and it is a 1000+ lines class with 13 collections that went through 47 revisions. Meaning, we are guaranteed to have bugs coming from this fix.
Comment 10 Dani Megert CLA 2010-09-29 10:46:01 EDT
(In reply to comment #9)
> Any chance we can increment JRE for org.eclipse.ui.workbench to Java 1.5? As
> ICU now is 1.5+ that should be a mere formality.
For ICU there are two easy ways for RCP developers that still have to run on J2ME Foundation 1.1: they can either use the ICU replacement plug-in or they can package their RCP with the previous ICU version from Orbit. This is not the case for 'org.eclipse.ui.workbench' once we switch. If you want to proceed with this you have to discuss it with Boris and if he agrees, you have to ask for PMC approval.
Comment 11 John Arthorne CLA 2010-09-29 10:57:50 EDT
(In reply to comment #9)
> There are 13 collections maintained by the MutableActivityManager; none of them
> synchronized. If we were able to switch them to ConcurrentHashMap from Java
> 1.5, it would be a start.

Does ConcurrentHashMap buy you much over Collections.synchronizedMap()? I realize ConcurrentHashMap allows for thread safe concurrent access but I would expect that to only matter in extreme cases - large numbers of concurrent callers in multiple threads.
Comment 12 Oleg Besedin CLA 2010-09-29 11:17:33 EDT
(In reply to comment #11)
> (In reply to comment #9)
> > There are 13 collections maintained by the MutableActivityManager; none of them
> > synchronized. If we were able to switch them to ConcurrentHashMap from Java
> > 1.5, it would be a start.
> Does ConcurrentHashMap buy you much over Collections.synchronizedMap()? I
> realize ConcurrentHashMap allows for thread safe concurrent access but I would
> expect that to only matter in extreme cases - large numbers of concurrent
> callers in multiple threads.

As far as I understand:
- the Collections.synchronizedMap() has much greater performance overhead then ConcurrentHashMap, on the order of 10 times overhead with just 2 threads. (It is hard to predict the real effect of this on what the consumer sees in UI. Might be significant, might be none);
- the Collections.synchronizedMap() still needs extra code changes, say, around #keySet() results, which this class uses in several places;
- the ConcurrentHashMap does not create actual locks for most #get() operations thus reducing chances of deadlocking (at least that's what I read?).

Overall, ConcurrentHashMap should be much more forgiving both on deadlocks and performance.
Comment 13 Boris Bokowski CLA 2010-09-30 10:23:07 EDT
(In reply to comment #10)
> > Any chance we can increment JRE for org.eclipse.ui.workbench to Java 1.5? As
> > ICU now is 1.5+ that should be a mere formality.
> For ICU there are two easy ways for RCP developers that still have to run on
> J2ME Foundation 1.1: they can either use the ICU replacement plug-in or they
> can package their RCP with the previous ICU version from Orbit.

While true in theory, I am not aware of anybody who is using RCP on Foundation 1.1. I think it should be safe to require 1.5, but we would have to announce this on eclipse-dev.

(In reply to comment #12)
> - the Collections.synchronizedMap() has much greater performance overhead then
> ConcurrentHashMap, on the order of 10 times overhead with just 2 threads. (It
> is hard to predict the real effect of this on what the consumer sees in UI.
> Might be significant, might be none);

It would be good to quantify this - it is much easier to argue for 1.5 if we have some hard numbers ;-)
Comment 14 Dani Megert CLA 2010-09-30 10:30:35 EDT
> While true in theory, I am not aware of anybody who is using RCP on Foundation
> 1.1. I think it should be safe to require 1.5, but we would have to announce
> this on eclipse-dev.
What about the embedded space? Not sure they use us but you never know. There must be reasons why we were keeping those low EEs. Just remember how long it took us to move to 1.5 for JDT. The poll should be done on eclipse-dev and cross-project-issues-dev.
Comment 15 Paul Webster CLA 2010-11-08 09:59:55 EST
*** Bug 329650 has been marked as a duplicate of this bug. ***
Comment 16 Markus Keller CLA 2011-03-07 05:28:58 EST
We can't ship 3.7 with these exceptions in the log. Please make sure the underlying issue gets fixed (or the exceptions are not logged if they are not important).
Comment 17 Paul Webster CLA 2011-03-07 07:27:49 EST
(In reply to comment #16)
> We can't ship 3.7 with these exceptions in the log.

They are only logged in debug mode.
PW
Comment 18 Oleg Besedin CLA 2011-03-17 13:57:21 EDT
(In reply to comment #10)
> (In reply to comment #9)
> > Any chance we can increment JRE for org.eclipse.ui.workbench to Java 1.5? As
> > ICU now is 1.5+ that should be a mere formality.
> For ICU there are two easy ways for RCP developers that still have to run on
> J2ME Foundation 1.1: they can either use the ICU replacement plug-in or they
> can package their RCP with the previous ICU version from Orbit. 

The com.ibm.icu.base supplied with Eclipse 3.7M6:

Bundle-RequiredExecutionEnvironment: J2SE-1.5
Comment 19 Paul Webster CLA 2011-03-17 14:23:48 EDT
(In reply to comment #18)
> 
> The com.ibm.icu.base supplied with Eclipse 3.7M6:
> 
> Bundle-RequiredExecutionEnvironment: J2SE-1.5

Yes, we took the contribution replacement bundle at 1.5 as well.  RCP apps can still run on 1.4, but they are limited to taking the ICU bundle or ICU replacement from 3.6.x

PW
Comment 20 Oleg Besedin CLA 2011-03-18 15:29:33 EDT
Created attachment 191544 [details]
Patch

The patch adds "synchronized" statements to getter and setter methods.

If we are limited to Java 1.4 / Foundation 1.1 this seems to be the safest approach. 

(I tired first to create lower-level locking based on the member collections, but method MutableActivityManager#setEnabledActivityIds() touches most of the collections. Because getters are public and theoretically can be called while setEnabledActivityIds() is executed that seemed to create good potential for deadlocks.)

Any constructive criticism is welcome. I'll use this patch in my workspace for a few days and if nothing comes up I''will commit it in the middle of the next week.
Comment 21 Oleg Besedin CLA 2011-03-23 14:31:20 EDT
Patch applied to CVS Head and will appear in builds > 20110323.

Tentatively marking this bug as fixed; we'll need to watch for deadlocks and effects on performance tests.
Comment 22 Dani Megert CLA 2011-04-01 06:00:29 EDT
Oleg, the unhookRegistryListeners() is the last non-synchronized method. Is this on purpose? Currently, this method is used when the manager is cloned and since clone() is synchronized we should probably also synchronize unhookRegistryListeners(). Even better: we could move that into clone() since this is the behavior one would expect from clone.
Comment 23 Oleg Besedin CLA 2011-04-01 09:47:52 EDT
(In reply to comment #22)
> Oleg, the unhookRegistryListeners() is the last non-synchronized method. Is
> this on purpose?

Yes. The method touches different field from the rest (AbstractActivityRegistry.activityRegistryListeners, not any field on MutableActivityManager). I'd much prefer to minimize the number of synchronized blocks - unless there is an actual problem.
Comment 24 Dani Megert CLA 2011-04-01 09:54:51 EDT
(In reply to comment #23)
> (In reply to comment #22)
> > Oleg, the unhookRegistryListeners() is the last non-synchronized method. Is
> > this on purpose?
> 
> Yes. The method touches different field from the rest
> (AbstractActivityRegistry.activityRegistryListeners, not any field on
> MutableActivityManager). I'd much prefer to minimize the number of synchronized
> blocks - unless there is an actual problem.

You synchronized all public methods including clone, hence I think you should also synchronize that one for completeness.
Comment 25 Oleg Besedin CLA 2011-04-26 11:49:34 EDT
Verified that updated code is present in the I20110425-1800.
Comment 26 Krzysztof Kazmierczyk CLA 2012-11-01 09:18:49 EDT
I have created also backport request to stream 3.6. It is bug 393327
Comment 27 Harry Terkelsen CLA 2014-06-16 21:19:16 EDT
I see this bug in a plug-in of mine that registers an activity during early startup:

!ENTRY org.eclipse.ui.workbench 4 2 2013-12-03 10:35:47.391
!MESSAGE Problems occurred when invoking code from plug-in: "org.eclipse.ui.workbench".
!STACK 0
java.util.ConcurrentModificationException
        at java.util.HashMap$HashIterator.nextEntry(HashMap.java:806)
        at java.util.HashMap$KeyIterator.next(HashMap.java:841)
        at org.eclipse.ui.internal.activities.MutableActivityManager.updateIdentifiers(MutableActivityManager.java:879)
        at org.eclipse.ui.internal.activities.MutableActivityManager.updateListeners(MutableActivityManager.java:589)
        at org.eclipse.ui.internal.activities.MutableActivityManager.updateExpressionEnabledActivities(MutableActivityManager.java:629)
        at org.eclipse.ui.internal.activities.MutableActivityManager.addExpressionEnabledActivity(MutableActivityManager.java:609)
        at org.eclipse.ui.internal.activities.MutableActivityManager.access$3(MutableActivityManager.java:605)
        at org.eclipse.ui.internal.activities.MutableActivityManager$2.propertyChange(MutableActivityManager.java:684)
        at org.eclipse.ui.internal.services.EvaluationReference.evaluate(EvaluationReference.java:143)
        at org.eclipse.ui.internal.services.EvaluationReference.changed(EvaluationReference.java:125)
        at org.eclipse.e4.core.internal.contexts.TrackableComputationExt.update(TrackableComputationExt.java:110)
        at org.eclipse.e4.core.internal.contexts.EclipseContext.processScheduled(EclipseContext.java:334)
        at org.eclipse.e4.core.internal.contexts.EclipseContext.set(EclipseContext.java:348)
        at org.eclipse.ui.internal.services.EvaluationService$1.changed(EvaluationService.java:73)
        at org.eclipse.e4.core.internal.contexts.TrackableComputationExt.update(TrackableComputationExt.java:110)
        at org.eclipse.e4.core.internal.contexts.EclipseContext.processScheduled(EclipseContext.java:334)
        at org.eclipse.e4.core.internal.contexts.EclipseContext.set(EclipseContext.java:348)
        at org.eclipse.e4.core.commands.ExpressionContext.addVariable(ExpressionContext.java:108)
        at org.eclipse.ui.internal.services.EvaluationService.changeVariable(EvaluationService.java:140)
        at org.eclipse.ui.internal.services.EvaluationService$3.sourceChanged(EvaluationService.java:108)
        at org.eclipse.ui.AbstractSourceProvider.fireSourceChanged(AbstractSourceProvider.java:69)
        at com.google.eclipse.saveonfocuslost.sourceprovider.PluginState.setActive(PluginState.java:38)
        at com.google.eclipse.saveonfocuslost.Activator.earlyStartup(Activator.java:110)
        at org.eclipse.ui.internal.EarlyStartupRunnable.runEarlyStartup(EarlyStartupRunnable.java:87)
        at org.eclipse.ui.internal.EarlyStartupRunnable.run(EarlyStartupRunnable.java:73)
        at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:42)
        at org.eclipse.ui.internal.Workbench$55.run(Workbench.java:2551)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:53)

This bug should be reopened and the idea of using ConcurrentHashMap should be reconsidered since org.eclipse.ui.workbench in newer versions requires JavaSE-1.6