mit-cml / appinventor-sources

MIT App Inventor Public Open Source
http://appinventor.mit.edu/appinventor-sources/
Apache License 2.0
1.47k stars 2.05k forks source link

ConcurrentModificationException in Companion app #821

Open ewpatton opened 8 years ago

ewpatton commented 8 years ago

From @halatmit :

The bad news is there's still a bug that causes the app to crash with "The Application has stopped".

I don't know what it is. It's also hard to create reliably because of the timers and stuff. Here's what appear in the Android system log:

E/AndroidRuntime( 4308): java.util.ConcurrentModificationException E/AndroidRuntime( 4308): at java.util.HashMap$HashIterator.nextEntry(HashMap.java:787) E/AndroidRuntime( 4308): at java.util.HashMap$KeyIterator.next(HashMap.java:814) E/AndroidRuntime( 4308): at com.google.appinventor.components.runtime.EventDispatcher.delegateDispatchEvent(EventDispatcher.java:219) E/AndroidRuntime( 4308): at com.google.appinventor.components.runtime.EventDispatcher.dispatchEvent(EventDispatcher.java:198) E/AndroidRuntime( 4308): at com.google.appinventor.components.runtime.Button.Click(Button.java:51) E/AndroidRuntime( 4308): at com.google.appinventor.components.runtime.Button.click(Button.java:43) E/AndroidRuntime( 4308): at com.google.appinventor.components.runtime.ButtonBase.onClick(ButtonBase.java:656) E/AndroidRuntime( 4308): at android.view.View.performClick(View.java:4780) E/AndroidRuntime( 4308): at android.view.View$PerformClick.run(View.java:19866) E/AndroidRuntime( 4308): at android.os.Handler.handleCallback(Handler.java:739) E/AndroidRuntime( 4308): at android.os.Handler.dispatchMessage(Handler.java:95) E/AndroidRuntime( 4308): at android.os.Looper.loop(Looper.java:135) E/AndroidRuntime( 4308): at android.app.ActivityThread.main(ActivityThread.java:5254) E/AndroidRuntime( 4308): at java.lang.reflect.Method.invoke(Native Method) E/AndroidRuntime( 4308): at java.lang.reflect.Method.invoke(Method.java:372) E/AndroidRuntime( 4308): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:903) E/AndroidRuntime( 4308): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:698) W/ActivityManager( 1803): Force finishing activity 1 edu.mit.appinventor.aicompanion3/.Screen1

I'm guessing this has something to do with the way the app switches screens, but that's just a guess.

Bottom line is that this is a really complex app with lots of blocks and multiple screens and timers, which makes debugging hard. Together with something that is stimulating the ConcurrentModificationException, which I assume is due to an App Inventor bug.

ewpatton commented 8 years ago

ConcurrentModificationExceptions occur when a collection is modified by any means other than Iterator.remove() while it is in the process of being iterated over. Generally it is observed in multithreading environments but can also happen when a collection is modified by the same thread, for example in a recursive call that modifies the iterating collection. The latter is what happens to generate the ConcurrentModificationException in the EventDispatcher for this bug to occur.

The bug appears in the companion due to the lack of separation between screens. EventDispatcher maintains a Map between HandlesEventDispatching implementations and the associated EventRegistry. The bug is triggered in rare instances during the transition between screens when the companion hasn't finished cleaning up the events in the registry related to the previous screen when the same type of event is triggered on the new screen. In the MoodRing app, this is observed when the click on one button transitions to a screen and, after the Companion draws the screen but before the Companion cleans up the old event handlers, the user clicks on a second button. The behavior is exaserbated by other triggering events, such as timers, which occupy the UI thread after the initial layout of the screen has been presented.

With additional debugging information in the Companion app, the following (truncated) stack traces were observed:

I/EventDispatcher(23127): java.lang.RuntimeException: delegateDispatchEvent
I/EventDispatcher(23127):   at com.google.appinventor.components.runtime.EventDispatcher.delegateDispatchEvent(EventDispatcher.java:248)
I/EventDispatcher(23127):   at com.google.appinventor.components.runtime.EventDispatcher.dispatchEvent(EventDispatcher.java:226)
I/EventDispatcher(23127):   at com.google.appinventor.components.runtime.Button.Click(Button.java:51)
I/EventDispatcher(23127):   at com.google.appinventor.components.runtime.Button.click(Button.java:43)
I/EventDispatcher(23127):   at com.google.appinventor.components.runtime.ButtonBase.onClick(ButtonBase.java:656)
I/EventDispatcher(23127): makeFullEventName componentId=Button_emoji, eventName=Click
I/EventDispatcher(23127): java.lang.RuntimeException: unregisterEventForDelegation
I/EventDispatcher(23127):   at com.google.appinventor.components.runtime.EventDispatcher.unregisterEventForDelegation(EventDispatcher.java:156)
I/EventDispatcher(23127):   at edu.mit.appinventor.aicompanion3.Screen1.dispatchEvent(Screen1.yail:10134)
I/EventDispatcher(23127):   at com.google.appinventor.components.runtime.EventDispatcher.delegateDispatchEvent(EventDispatcher.java:255)
I/EventDispatcher(23127):   at com.google.appinventor.components.runtime.EventDispatcher.dispatchEvent(EventDispatcher.java:226)
I/EventDispatcher(23127):   at com.google.appinventor.components.runtime.Button.Click(Button.java:51)
I/EventDispatcher(23127):   at com.google.appinventor.components.runtime.Button.click(Button.java:43)
I/EventDispatcher(23127):   at com.google.appinventor.components.runtime.ButtonBase.onClick(ButtonBase.java:656)
I/EventDispatcher(23127): Deleting event closure for Button3_yr.Click
D/AndroidRuntime(23127): Shutting down VM
E/AndroidRuntime(23127): FATAL EXCEPTION: main
E/AndroidRuntime(23127): Process: edu.mit.appinventor.aicompanion3, PID: 23127
E/AndroidRuntime(23127): java.util.ConcurrentModificationException
E/AndroidRuntime(23127):    at java.util.HashMap$HashIterator.nextEntry(HashMap.java:787)
E/AndroidRuntime(23127):    at java.util.HashMap$KeyIterator.next(HashMap.java:814)
E/AndroidRuntime(23127):    at com.google.appinventor.components.runtime.EventDispatcher.delegateDispatchEvent(EventDispatcher.java:254)
E/AndroidRuntime(23127):    at com.google.appinventor.components.runtime.EventDispatcher.dispatchEvent(EventDispatcher.java:226)
E/AndroidRuntime(23127):    at com.google.appinventor.components.runtime.Button.Click(Button.java:51)
E/AndroidRuntime(23127):    at com.google.appinventor.components.runtime.Button.click(Button.java:43)
E/AndroidRuntime(23127):    at com.google.appinventor.components.runtime.ButtonBase.onClick(ButtonBase.java:656)

The unregisterEventForDelegation call comes from iterating over all of the registered event handlers in Java and the Companion (in YAIL) checking whether the component is registered with the current screen (runtime.scm:415). If this check is false, the event is unregistered (runtime.scm:438). Because the events are the same type (i.e., Click), this causes the set of registered event handlers to be modified separately from the iteration, which results in the ConcurrentModificationException.