[TIMOB-2715] Collection <__NSArrayM: 0x367560> was mutated while being enumerated

GitHub Issue	n/a
Type	Bug
Priority	Medium
Status	Closed
Resolution	Needs more info
Resolution Date	2012-05-03T15:55:26.000+0000
Affected Version/s	n/a
Fix Version/s	n/a
Components	iOS
Labels	crash, ios, iphone, look1, multi-threading
Reporter	lukaso
Assignee	Marshall Culpepper
Created	2011-04-15T03:27:38.000+0000
Updated	2017-03-16T20:44:15.000+0000

Description

I'm not sure exactly what is going on, but there appear to be some multithreading issues in Titanium.

I've looked at the code, and based on where Titanium actually calls postNotification, it appears only to occur on window close. I have a callback on 'pause' but nothing on window close which means it's even more likely to be a Titanium problem.

Here is the contents of the crash log:

Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : [ERROR] The application has crashed with an unhandled exception. Stack trace:
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 0 CoreFoundation 0x33ac0975 exceptionPreprocess + 96
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 1 libobjc.A.dylib 0x3347b49d objc_exception_throw + 24
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 2 CoreFoundation 0x33ac030b NSFastEnumerationMutationHandler + 214
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 3 libobjc.A.dylib 0x3348148d objc_enumerationMutation + 24
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 4 My Hood 0x000677e9 0x0 + 423913
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 5 My Hood 0x00067477 0x0 + 423031
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 6 Foundation 0x3362d623 nsnote_callback + 142
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 7 CoreFoundation 0x33a47123 __CFXNotificationPost_old + 402
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 8 CoreFoundation 0x33a46dc3 CFXNotificationPostNotification + 118
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 9 Foundation 0x33623f8b -[NSNotificationCenter postNotification:] + 138
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 10 My Hood 0x0001b157 0x0 + 110935
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 11 Foundation 0x33639dfd NSFireDelayedPerform + 368
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 12 CoreFoundation 0x33a770a3 CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION + 14
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 13 CoreFoundation 0x33a76b5b CFRunLoopDoTimer + 850
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 14 CoreFoundation 0x33a481b5 CFRunLoopRun + 1088
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 15 CoreFoundation 0x33a47c87 CFRunLoopRunSpecific + 230
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 16 CoreFoundation 0x33a47b8f CFRunLoopRunInMode + 58
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 17 GraphicsServices 0x33b0e4ab GSEventRunModal + 114
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 18 GraphicsServices 0x33b0e557 GSEventRun + 62
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 19 UIKit 0x32099329 -[UIApplication _run] + 412
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 20 UIKit 0x32096e93 UIApplicationMain + 670
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 21 My Hood 0x000041e3 0x0 + 16867
Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : 22 My Hood 0x00003d2c 0x0 + 15660
Thu Dec 30 22:14:35 unknown My Hood[161] : Terminating app due to uncaught exception 'NSGenericException', reason: ' Collection <NSArrayM: 0x367560> was mutated while being enumerated.(

    "<ListenerEntry: 0x367540>",
    "<ListenerEntry: 0x67edd80>",
    "<ListenerEntry: 0x67f7b20>"
)'
*** Call stack at first throw:
(
    0   CoreFoundation                      0x33ac0987 __exceptionPreprocess + 114
    1   libobjc.A.dylib                     0x3347b49d objc_exception_throw + 24
    2   CoreFoundation                      0x33ac030b __NSFastEnumerationMutationHandler + 214
    3   libobjc.A.dylib                     0x3348148d objc_enumerationMutation + 24
    4   My Hood                             0x000677e9 0x0 + 423913
    5   My Hood                             0x00067477 0x0 + 423031
    6   Foundation                          0x3362d623 _nsnote_callback + 142
    7   CoreFoundation                      0x33a47123 __CFXNotificationPost_old + 402
    8   CoreFoundation                      0x33a46dc3 _CFXNotificationPostNotification + 118
    9   Foundation                          0x33623f8b -[NSNotificationCenter postNotification:] + 138
    10  My Hood                             0x0001b157 0x0 + 110935
    11  Foundation                          0x33639dfd __NSFireDelayedPerform + 368
    12  CoreFoundation                      0x33a770a3 __CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION__ + 14
    13  CoreFoundation                      0x33a76b5b __CFRunLoopDoTimer + 850
    14  CoreFoundation                      0x33a481b5 __CFRunLoopRun + 1088
    15  CoreFoundation                      0x33a47c87 CFRunLoopRunSpecific + 230
    16  CoreFoundation                      0x33a47b8f CFRunLoopRunInMode + 58
    17  GraphicsServices                    0x33b0e4ab GSEventRunModal + 114
    18  GraphicsServices                    0x33b0e557 GSEventRun + 62
    19  UIKit                               0x32099329 -[UIApplication _run] + 412
    20  UIKit                               0x32096e93 UIApplicationMain + 670
    21  My Hood                             0x000041e3 0x0 + 16867
    22  My Hood                             0x00003d2c 0x0 + 15660
)

Thu Dec 30 22:14:35 unknown UIKitApplication:myhood[0x239e][161] : terminate called after throwing an instance of 'NSException'
Thu Dec 30 22:14:36 unknown ReportCrash[172] : Formulating crash report for process My Hood[161]
Thu Dec 30 22:14:36 unknown com.apple.launchd[1] : (UIKitApplication:myhood[0x239e]) Job appears to have crashed: Abort trap
Thu Dec 30 22:14:36 unknown SpringBoard[29] : Application 'My Hood' exited abnormally with signal 6: Abort trap
Thu Dec 30 22:14:36 unknown ReportCrash[172] : Saved crashreport to /var/mobile/Library/Logs/CrashReporter/My Hood_2010-12-30-221435_Lukass-iPhone.plist using uid: 0 gid: 0, synthetic_euid: 501 egid: 0

Attachments

File	Date	Size
thread_analysis.patch	2011-04-15T03:27:39.000+0000	13311

Comments

lukaso 2011-04-15

The location of the exception is in AppModule.m:92:

-(void)removeEventListener:(NSArray*)args {

   NSString *type = [args objectAtIndex:0];
   id listener = [args objectAtIndex:1];
   
   ListenerEntry *entry = nil;
   
   NSMutableArray *l = [appListeners objectForKey:type];
   
   BOOL needsScanning;
   do
   {
       needsScanning = NO;

-->>>>>>> for (entry in l) //The fast iteration is blindly fast when l is nil or count.

       {
           if ([listener isEqual:[entry listener]]) //NSNumber does the right thing with this too.
           {
               [l removeObject:entry]; //It's safe to modify the array as long as you break right after.
               needsScanning = [l count]>0;
               break;
           }
       }
   } while (needsScanning);
   
   if ([appListeners count]==0)
   {
       RELEASE_TO_NIL(appListeners);
   }
   
   [[self _host] removeListener:listener context:pageContext];

}

After being called from line 271:

-(void)willShutdownContext:(NSNotification*)note {

   // we have to check and see if this context has any listeners
   // that are registered at the global scope and that haven't been
   // removed and if so, we need to remove them since their context
   // is toast.
   if (appListeners!=nil)
   {
       NSMutableArray *found = [NSMutableArray array];
       id context = [note object];
       for (NSString *type in appListeners)
       {
           for (ListenerEntry *entry in [appListeners objectForKey:type])
           {
               if ([entry context] == context)
               {
                   id listener = [entry listener];
                   if ([listener isKindOfClass:[KrollCallback class]])
                   {
                       [found addObject:[NSArray
                                         arrayWithObjects:((KrollCallback*)listener).type,listener,nil]];
                   }
                   else 
                   {
                       [found addObject:[NSArray
                                      arrayWithObjects:[entry type],listener,nil]];
                   }
               }
           }
       }
       if ([found count]>0)
       {
           for (NSArray *a in found)
           {

---->>>>>> [self removeEventListener:a];

           }
       }
   }

}

lukaso 2011-04-15

I suspect the comment:

//It's safe to modify the array as long as you break right after.

A few lines below the crash is incorrect, as the break only breaks out of that block in the for and then as soon as it goes to the next item, the crash occurs. Was the code expecting to break out of the overall loop completely?
lukaso 2011-04-15

Done some further checking, and it doesn't appear to be the line I thought (I changed the code, rebuilt the SDK and still crashes). I think there's some kind of memory corruption going on in the app due to the number of windows being opened. It opens up lots of windows and closes them again. Eventually the app crashes.

lukaso 2011-04-15

OK, I've spent a few more hours debugging this problem.

I'm attaching a patch which DOES NOT fix the problem. However it makes it happen a lot less frequently. Some things I observed.

First, my app has many windows and sends some global messages, one of which is 'show_indicator'. This is listened for most of the windows I open, and then subsequently close.

The crashes always occur as above with type set to 'show_indicator'.

So in my patch I've added a semaphore around the appListeners NSMutableDictionary throughout AppModule.m. This doesn't help at all, as now the app hangs on the lock statement in removeEventListener. There are no other threads obviously holding the lock, so not sure where it is being taken (my XCode debugging fu is not strong enough, clearly).

So finally I added some warn logging statements to the whole thing before each action. Suddenly the problem occurs much less frequently. But there is still a semaphore problem as this stack trace (using my new version of the 1.5.1 module which I've dubbed 1.5.22) shows.

      #0    0x33b5d2c4 in semaphore_wait_signal_trap
      #1   0x33b8ab40 in semaphore_wait_signal
      #2   0x33b5f0d6 in pthread_mutex_lock
      #3   0x001422fc in TI::TiLock::lock at TiLock.cpp:88
      #4   0x00142354 in TI::TiLock::TiLock at TiLock.cpp:72
      #5   0x0014e454 in TI::TiValue::strictEqual at TiCore:174
      #6   0x0014e454 in TiValueIsStrictEqual
      #7   0x0002a712 in -[KrollCallback isEqual:] at KrollCallback.m:94
      #8   0x0009de40 in -[AppModule removeEventListener:] at AppModule.m:107
      #9   0x0009f5c6 in -[AppModule willShutdownContext:] at AppModule.m:305
      #10  0x3362d622 in _nsnote_callback
      #11  0x33a47122 in __CFXNotificationPost_old
      #12  0x33a46dc2 in _CFXNotificationPostNotification
      #13  0x33623f8a in -[NSNotificationCenter postNotification:]
      #14  0x000276f4 in -[KrollBridge shutdown:] at KrollBridge.mm:429
      #15  0x33639dfc in __NSFireDelayedPerform
      #16  0x33a770a2 in __CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION__
      #17  0x33a76b5a in __CFRunLoopDoTimer
      #18  0x33a481b4 in __CFRunLoopRun
      #19  0x33a47c86 in CFRunLoopRunSpecific
      #20  0x33a47b8e in CFRunLoopRunInMode
      #21  0x33b0e4aa in GSEventRunModal
      #22  0x33b0e556 in GSEventRun
      #23  0x32099328 in -[UIApplication _run]
      #24  0x32096e92 in UIApplicationMain

I'm a bit at a loss as to what is going wrong, but hopefully this give you a lot more to go on.

lukaso 2011-04-15

And now the patch which it wouldn't let me upload (could be a Chrome bug).
Stephen Tramer 2012-05-03

Ticket does not include a sample case and we cannot evaluate/include source code without a signed CLA on behalf of the submitter.
Lee Morris 2017-03-16

Closing ticket as the information that was requested was never provided.

JSON Source