NSCache / libcache BIG BAD deadlock

Originator:me
Number:rdar://10916098 Date Originated:22-Feb-2012 06:18 PM
Status:Open Resolved:
Product:Mac OS X Product Version:10.7.3 (11D50)
Classification:Crash/Hang/Data Loss Reproducible:I Didn't Try
 
I hit what appears to be a deadlock situation, creating an NSCache while a background queue is destroying one. I paused the app after it spun for about 5 seconds. After examining the state in the debugger for a while, the app received SIGABRT. I suspect someone else on the system sent that (since it would apparently have failed to react to the memory pressure warning?). That crash report is attached.

Thread 1 is creating an NSCache instance with +[NSCache new] (frame 4). LIFancyCoverCache is not an NSCache subclass, btw.

It appears that Thread 1 and Thread 13 are messaging two different cache instances: <NSCache: 0x10f17c1d0> on Thread 1, <NSCache: 0x10c4f3590> on Thread 13. (At least, that's what were in $rbx on each thread.)

Here are the backtraces for the two threads in question. The backtrace of all threads is a separate attachment.


Thread 1, Queue : com.apple.main-thread
#0	0x00007fff88e2abf2 in __psynch_mutexwait ()
#1	0x00007fff8dca51a1 in pthread_mutex_lock ()
#2	0x00007fff90548905 in cache_create ()
#3	0x00007fff947f1a9c in -[NSCache init] ()
#4	0x00007fff947cb3b2 in +[NSObject new] ()
#5	0x000000010026cc4a in -[LIFancyCoverCache init] at /Users/jonathon/Documents/Streams/Delicious Monster/UberLibrary/Library/LIFancyCoverCache.m:39
#6	0x00007fff947cb3b2 in +[NSObject new] ()
#7	0x000000010026cf92 in +[LIFancyCoverCache fancyCoverCacheForSize:] ()
#8	0x000000010025ecce in -[LICoverImageView drawRect:] ()
#9	0x00007fff8ce09abe in -[NSView _drawRect:clip:] ()
#10	0x00007fff8ce371eb in -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:] ()
#11	0x00007fff8ce37617 in -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:] ()
#12	0x00007fff8ce37617 in -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:] ()
#13	0x00007fff8ce37617 in -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:] ()
#14	0x00007fff8ce37617 in -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:] ()
#15	0x00007fff8ce37617 in -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:] ()
#16	0x00007fff8ce37617 in -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:] ()
#17	0x00007fff8ce07099 in -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:] ()
#18	0x00007fff8ce0834e in -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:] ()
#19	0x00007fff8ce0834e in -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:] ()
#20	0x00007fff8ce0834e in -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:] ()
#21	0x00007fff8ce0834e in -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:] ()
#22	0x00007fff8ce0834e in -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:] ()
#23	0x00007fff8ce0834e in -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:] ()
#24	0x00007fff8ce0834e in -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:] ()
#25	0x00007fff8ce0834e in -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:] ()
#26	0x00007fff8ce0834e in -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:] ()
#27	0x00007fff8ce06593 in -[NSThemeFrame _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:] ()
#28	0x00007fff8ce019af in -[NSView _displayRectIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:] ()
#29	0x00007fff8cdfa429 in -[NSView displayIfNeeded] ()
#30	0x00007fff8cdf9b69 in _handleWindowNeedsDisplayOrLayoutOrUpdateConstraints ()
#31	0x00007fff947e4bd7 in __CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__ ()
#32	0x00007fff947e4b36 in __CFRunLoopDoObservers ()
#33	0x00007fff947b9ce9 in __CFRunLoopRun ()
#34	0x00007fff947b9676 in CFRunLoopRunSpecific ()
#35	0x00007fff8fd2731f in RunCurrentEventLoopInMode ()
#36	0x00007fff8fd2e5c9 in ReceiveNextEventCommon ()
#37	0x00007fff8fd2e456 in BlockUntilNextEventMatchingListInMode ()
#38	0x00007fff8cdbdf5d in _DPSNextEvent ()
#39	0x00007fff8cdbd861 in -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] ()
#40	0x00007fff8cdba19d in -[NSApplication run] ()
#41	0x00007fff8d038b88 in NSApplicationMain ()
#42	0x0000000100002c87 in main ()
Thread 2, Queue : com.apple.libdispatch-manager
Thread 7, Queue : (null)
Thread 11 CVDisplayLink, Queue : (null)
Thread 13, Queue : com.apple.root.default-priority
#0	0x00007fff88e2abf2 in __psynch_mutexwait ()
#1	0x00007fff8dca51a1 in pthread_mutex_lock ()
#2	0x00007fff9054792a in cache_destroy ()
#3	0x00007fff948c39db in -[NSCache dealloc] ()
#4	0x00007fff94789ca0 in CFRelease ()
#5	0x00007fff905468e4 in _value_entry_remove ()
#6	0x00007fff905469cd in _entry_unmap ()
#7	0x00007fff90546a71 in _entry_evict ()
#8	0x00007fff90546b04 in _evict_last ()
#9	0x00007fff90546cf2 in _cache_enforce_limits ()
#10	0x00007fff90546ea5 in cache_handle_memory_pressure ()
#11	0x00007fff8a7d92b6 in _dispatch_source_invoke ()
#12	0x00007fff8a7d5f77 in _dispatch_queue_invoke ()
#13	0x00007fff8a7d5760 in _dispatch_worker_thread2 ()
#14	0x00007fff8dca83da in _pthread_wqthread ()
#15	0x00007fff8dca9b85 in start_wqthread ()
Thread 17 QTKit: QTCALayerRendererPendingQWorkLoop, Queue : (null)
Thread 19 com.apple.NSURLConnectionLoader, Queue : (null)
Thread 21 com.apple.CFSocket.private, Queue : (null)
Thread 27, Queue : (null)
Thread 28, Queue : (null)

Comments

And again, while doing a parallel computation in the same app as before:

(gdb) thread apply all bt
[similar, but larger, stack traces followed; omitted in Open Radar]

06-Mar-2012 03:24 AM Jonathon Mah:

06-Mar-2012 03:24 AM Jonathon Mah:

In recent days I've seen this two additional times. The first happened at the same place. The second happened in a completely different project, which was accessing an NSCache. It had been open for a while and I suspect reactivating it caused it to grab some memory, but no real RAM was free at the time, giving a memory warning and paging.

(gdb) thread apply all bt

Thread 18 (process 88939):
#0  0x00007fff89c61192 in __workq_kernreturn ()
#1  0x00007fff9090d594 in _pthread_wqthread ()
#2  0x00007fff9090eb85 in start_wqthread ()

Thread 17 (process 88939):
#0  0x00007fff89c61192 in __workq_kernreturn ()
#1  0x00007fff9090d594 in _pthread_wqthread ()
#2  0x00007fff9090eb85 in start_wqthread ()

Thread 16 (process 88939):
#0  0x00007fff89c60bf2 in __psynch_mutexwait ()
#1  0x00007fff9090a1a1 in pthread_mutex_lock ()
#2  0x00007fff912d292a in cache_destroy ()
#3  0x00007fff8ff4a9db in -[NSCache dealloc] ()
#4  0x00007fff8fe10ca0 in CFRelease ()
#5  0x00007fff912d18e4 in _value_entry_remove ()
#6  0x00007fff912d19cd in _entry_unmap ()
#7  0x00007fff912d1a71 in _entry_evict ()
#8  0x00007fff912d1b04 in _evict_last ()
#9  0x00007fff912d1cf2 in _cache_enforce_limits ()
#10 0x00007fff912d1ea5 in cache_handle_memory_pressure ()
#11 0x00007fff934d22b6 in _dispatch_source_invoke ()
#12 0x00007fff934cef77 in _dispatch_queue_invoke ()
#13 0x00007fff934ce760 in _dispatch_worker_thread2 ()
#14 0x00007fff9090d3da in _pthread_wqthread ()
#15 0x00007fff9090eb85 in start_wqthread ()

Thread 6 (process 88939):
#0  0x00007fff89c60bca in __psynch_cvwait ()
#1  0x00007fff9090f274 in _pthread_cond_wait ()
#2  0x00007fff90011b3c in CVDisplayLink::runIOThread ()
#3  0x00007fff9001185d in startIOThread ()
#4  0x00007fff9090b8bf in _pthread_start ()
#5  0x00007fff9090eb75 in thread_start ()

Thread 2 (process 88939):
#0  0x00007fff89c617e6 in kevent ()
#1  0x00007fff934cf5be in _dispatch_mgr_invoke ()
#2  0x00007fff934ce14e in _dispatch_mgr_thread ()

Thread 1 (process 88939):
#0  0x00007fff89c60bf2 in __psynch_mutexwait ()
#1  0x00007fff9090a1a1 in pthread_mutex_lock ()
#2  0x00007fff912d3584 in cache_get_and_retain ()
#3  0x00007fff8fe78cdc in -[NSCache objectForKey:] ()
#4  0x00000001000195c9 in +[DMBarcodeDigitTemplates digitTemplatesForBlurKernel:contrastSettingIndex:] (self=0x10005d1f8, _cmd=0x100046280, blurKernel=0x10844bca0, contrastSettingIndex=3) at
#5  0x00000001000194d5 in +[DMBarcodeDigitTemplates digitTemplatesForResult:] (self=0x10005d1f8, _cmd=0x1000462d2, resultWithBlurAndContrast=0x108c17af0) at
#6  0x00000001000271cb in -[HMResultViewController knownBarcodeBuffer] (self=0x10019f9a0, _cmd=0x10004747d) at
#7  0x00007fff90eb2384 in _NSGetUsingKeyValueGetter ()
#8  0x00007fff90eb2339 in -[NSObject(NSKeyValueCoding) valueForKey:] ()
#9  0x00007fff90ed1dc6 in -[NSObject(NSKeyValueCoding) valueForKeyPath:] ()
#10 0x00007fff8e861b8c in -[NSAutounbinder valueForKeyPath:] ()
#11 0x00007fff8e692ae2 in -[NSBinder _valueForKeyPath:ofObject:mode:raisesForNotApplicableKeys:] ()
#12 0x00007fff8e6927cc in -[NSBinder valueForBinding:resolveMarkersToPlaceholders:] ()
#13 0x00007fff8e69243a in -[NSObjectParameterBinder _updateObject:observedController:observedKeyPath:context:] ()
#14 0x00007fff90ed57b2 in NSKeyValueNotifyObserver ()
#15 0x00007fff90ef68eb in NSKeyValueDidChange ()
#16 0x00007fff90ea304b in -[NSObject(NSKeyValueObserverNotification) didChangeValueForKey:] ()
#17 0x00007fff90ec9cca in _NSSetUsingKeyValueSetter ()
#18 0x00007fff90ec97fd in -[NSObject(NSKeyValueCoding) setValue:forKey:] ()
#19 0x00007fff8e6924da in -[NSObjectParameterBinder _updateObject:observedController:observedKeyPath:context:] ()
#20 0x00007fff90ed57b2 in NSKeyValueNotifyObserver ()
#21 0x00007fff90ecf7d7 in -[NSObject(NSKeyValueObservingPrivate) _notifyObserversForKeyPath:change:] ()
#22 0x00007fff8e67fe17 in -[NSController _notifyObserversForKeyPath:change:] ()
#23 0x00007fff8e8eceb5 in -[NSArrayController didChangeValuesForArrangedKeys:objectKeys:indexKeys:] ()
#24 0x00007fff8e8ecaf8 in -[NSArrayController _selectObjectsAtIndexesNoCopy:avoidsEmptySelection:sendObserverNotifications:forceUpdate:] ()
#25 0x00007fff8e92f74f in -[NSArrayController _selectObjectsAtIndexes:avoidsEmptySelection:sendObserverNotifications:forceUpdate:] ()
#26 0x00007fff8e92f6f7 in -[NSArrayController setSelectionIndexes:] ()
#27 0x00007fff8e92f6d0 in -[NSArrayController setSelectionIndex:] ()
#28 0x0000000100004e13 in -[HMAppDelegate selectTestImageWithURL:atScanlineRow:] (self=0x100169910, _cmd=0x10004507e, url=0x1054cb560, scanlineRow=239) at
#29 0x0000000100038840 in -[HMTestRunsWindowController testResultsView:didSelectTestImageWithURL:atRow:] (self=0x10a22de20, _cmd=0x10004821c, testResultsView=0x10a295900, url=0x1054cb560, scanlineRow=239) at
#30 0x000000010003da80 in -[HMTestResultsView mouseUp:] (self=0x10a295900, _cmd=0x7fff8efbb14c, event=0x10a233f90) at
#31 0x00007fff8e7397a6 in -[NSWindow sendEvent:] ()
#32 0x00007fff8e6d216d in -[NSApplication sendEvent:] ()
#33 0x00007fff8e6681f2 in -[NSApplication run] ()
#34 0x00007fff8e8e6b88 in NSApplicationMain ()
#35 0x0000000100001d72 in main (argc=5, argv=0x7fff5fbff608) at
(gdb)

Please note: Reports posted here will not necessarily be seen by Apple. All problems should be submitted at bugreport.apple.com before they are posted here. Please only post information for Radars that you have filed yourself, and please do not include Apple confidential information in your posts. Thank you!