Anything I should know about thread safety and fprintf?
Anything I should know about thread safety and fprintf?
- Subject: Anything I should know about thread safety and fprintf?
- From: "Jonathan del Strother" <email@hidden>
- Date: Wed, 23 Jan 2008 19:48:06 +0000
I keep running into an apparent deadlock within fprintf. I can
semi-reliably reproduce it within my application, but have been
totally unable to reduce the problem to a smaller test case.
In a nutshell, I have two threads calling this -
fprintf(stderr, "%s:%d - %s\n", [fileBaseName
cStringUsingEncoding:NSASCIIStringEncoding], lineNumber,
[formattedMessage cStringUsingEncoding:NSASCIIStringEncoding]);
resulting in the following stack trace. The first thread just sits in
write$NOCANCEL$UNIX2003() for ever.
thread A :
#0 0x94709a36 in write$NOCANCEL$UNIX2003 ()
#1 0x9470998e in _swrite ()
#2 0x947098bb in __sflush ()
#3 0x946d4ac8 in __vfprintf ()
#4 0x94709603 in vfprintf_l ()
#5 0x94709597 in fprintf ()
thread B :
#0 0x946d392e in semaphore_wait_signal_trap ()
#1 0x946db405 in pthread_mutex_lock ()
#2 0x94713383 in flockfile ()
#3 0x947095e6 in vfprintf_l ()
#4 0x94709597 in fprintf ()
(full stack trace below)
The arguments to fprintf typically boil down to something like :
fprintf(stderr, "%s:%d - %s\n","BBDownloader.m", 56, "Downloading
/assets.xml from http://demo.host.com";);
Poking around with gdb seems to confirm this. My arguments to fprintf
seem fine, all the strings are null terminated and sensible lengths,
etc etc.
That on it's own doesn't seem enough to reproduce the problem, however
- eg a test app with two threads constantly logging to stderr will
happily run all night without problems. Scanning through the darwin
source, fprintf appears to be thread safe.
Any ideas what might cause that write() method to just block for ever?
Any suggestions on this would be massively appreciated - I've been
seeing this problem for around the past 5 months now and have wasted
days trying to track down the problem
Jonathan del Strother
Appendix A - Full stack trace
Thread 18 (process 7956 thread 0xa603):
#0 0x946daace in __semwait_signal ()
#1 0x946da94f in nanosleep$UNIX2003 ()
#2 0x000b439b in bbSleep (secs=0.033304762335319538) at
/Users/jon/Developer/BBView/src/MillicentView.m:105
#3 0x000b42bd in -[MillicentView drawLoop] (self=0x157df6b0,
_cmd=0xcb5e8) at /Users/jon/Developer/BBView/src/MillicentView.m:427
#4 0x9358004d in -[NSThread main] ()
#5 0x9357fbf4 in __NSThread__main__ ()
#6 0x94704075 in _pthread_start ()
#7 0x94703f32 in thread_start ()
Thread 17 (process 7956 thread 0xa403):
#0 0x946d3946 in semaphore_timedwait_signal_trap ()
#1 0x947051cf in _pthread_cond_wait ()
#2 0x94706a53 in pthread_cond_timedwait_relative_np ()
#3 0x96b79ba4 in CVDisplayLink::waitUntil ()
#4 0x96b7a566 in CVDisplayLink::runIOThread ()
#5 0x94704075 in _pthread_start ()
#6 0x94703f32 in thread_start ()
Thread 16 (process 7956 thread 0x9b07):
#0 0x946daace in __semwait_signal ()
#1 0x94705306 in _pthread_cond_wait ()
#2 0x94704ced in pthread_cond_wait$UNIX2003 ()
#3 0x94175f32 in glvmDoWork ()
#4 0x94704075 in _pthread_start ()
#5 0x94703f32 in thread_start ()
Thread 15 (process 7956 thread 0x9503):
#0 0x946d38e6 in mach_msg_trap ()
#1 0x946db0dc in mach_msg ()
#2 0x90014a5d in glcDebugListener ()
#3 0x94704075 in _pthread_start ()
#4 0x94703f32 in thread_start ()
Thread 14 (process 7956 thread 0x8d03):
#0 0x946d392e in semaphore_wait_signal_trap ()
#1 0x946db405 in pthread_mutex_lock ()
#2 0x94713383 in flockfile ()
#3 0x947095e6 in vfprintf_l ()
#4 0x94709597 in fprintf ()
#5 0x0007ef40 in BBDetailedLogWithVA (level=BB_LOG_INFO,
lineNumber=249, fileName=0x2580c
"/Users/jon/Developer/MillicentPro/src/AssetManager.m",
methodName=0x259c4 "-[AssetManager downloader:succeededWithData:]";,
message=0x2ca18, args=0xb066b184 "\020?|\025ST??\004\a") at
/Users/jon/Developer/BBUtilities/Src/BBLogger.m:41
#6 0x0007efb5 in BBDetailedLog (level=BB_LOG_INFO, lineNumber=249,
fileName=0x2580c
"/Users/jon/Developer/MillicentPro/src/AssetManager.m",
methodName=0x259c4 "-[AssetManager downloader:succeededWithData:]";,
message=0x2ca18) at /Users/jon/Developer/BBUtilities/Src/BBLogger.m:51
#7 0x0000d2b0 in -[AssetManager downloader:succeededWithData:]
(self=0x136c80, _cmd=0x85b56, aDownloader=0x157c4060,
downloadedData=0x17037060) at
/Users/jon/Developer/MillicentPro/src/AssetManager.m:249
#8 0x000705a8 in -[BBDownloader connectionDidFinishLoading:]
(self=0x157c4060, _cmd=0x95f235c4, connection=0x17037090) at
/Users/jon/Developer/BBUtilities/Src/BBDownloader.m:178
#9 0x935e5357 in -[NSURLConnection(NSURLConnectionReallyInternal)
sendDidFinishLoading] ()
#10 0x935e52e4 in _NSURLConnectionDidFinishLoading ()
#11 0x9546f897 in sendDidFinishLoadingCallback ()
#12 0x9546c9ca in _CFURLConnectionSendCallbacks ()
#13 0x9546c1db in muxerSourcePerform ()
#14 0x969fe64e in CFRunLoopRunSpecific ()
#15 0x969fed38 in CFRunLoopRunInMode ()
#16 0x935b45b5 in -[NSRunLoop(NSRunLoop) runMode:beforeDate:] ()
#17 0x00082967 in -[ThreadWorker startThread:] (self=0x157c42d0,
_cmd=0x8b58c, callingPortArray=0x157c43d0) at
/Users/jon/Developer/BBUtilities/Src/ThreadWorker.m:212
#18 0x9358004d in -[NSThread main] ()
#19 0x9357fbf4 in __NSThread__main__ ()
#20 0x94704075 in _pthread_start ()
#21 0x94703f32 in thread_start ()
Thread 13 (process 7956 thread 0x4243):
#0 0x946d38e6 in mach_msg_trap ()
#1 0x946db0dc in mach_msg ()
#2 0x969fe0fe in CFRunLoopRunSpecific ()
#3 0x969fed38 in CFRunLoopRunInMode ()
#4 0x954b4d45 in _KeychainThread ()
#5 0x94704075 in _pthread_start ()
#6 0x94703f32 in thread_start ()
Thread 12 (process 7956 thread 0x8303):
#0 0x00000000 in ?? ()
Cannot access memory at address 0x4
Thread 11 (process 7956 thread 0x8203):
#0 0x00000000 in ?? ()
Cannot access memory at address 0x4
Thread 10 (process 7956 thread 0x8103):
#0 0x00000000 in ?? ()
Cannot access memory at address 0x4
Thread 9 (process 7956 thread 0x8003):
#0 0x9473c95a in __workq_ops ()
#1 0x9473e052 in workqueue_exit ()
#2 0x9473c98a in start_wqthread ()
Thread 8 (process 7956 thread 0x7c07):
#0 0x946d3946 in semaphore_timedwait_signal_trap ()
#1 0x947051cf in _pthread_cond_wait ()
#2 0x94706a53 in pthread_cond_timedwait_relative_np ()
#3 0x935c5f9c in -[NSCondition waitUntilDate:] ()
#4 0x935c5db0 in -[NSConditionLock lockWhenCondition:beforeDate:] ()
#5 0x935c5d15 in -[NSConditionLock lockWhenCondition:] ()
#6 0x961bdc19 in -[NSUIHeartBeat _heartBeatThread:] ()
#7 0x9358004d in -[NSThread main] ()
#8 0x9357fbf4 in __NSThread__main__ ()
#9 0x94704075 in _pthread_start ()
#10 0x94703f32 in thread_start ()
Thread 7 (process 7956 thread 0x6e03):
#0 0x946d38e6 in mach_msg_trap ()
#1 0x946db0dc in mach_msg ()
#2 0x969fe0fe in CFRunLoopRunSpecific ()
#3 0x969fed38 in CFRunLoopRunInMode ()
#4 0x954677ba in CFURLCacheWorkerThread ()
#5 0x94704075 in _pthread_start ()
#6 0x94703f32 in thread_start ()
Thread 6 (process 7956 thread 0x6d03):
#0 0x946daace in __semwait_signal ()
#1 0x94705306 in _pthread_cond_wait ()
#2 0x94704ced in pthread_cond_wait$UNIX2003 ()
#3 0x92693460 in pthreadSemaphoreWait ()
#4 0x926a5d92 in CMMConvTask ()
#5 0x94704075 in _pthread_start ()
#6 0x94703f32 in thread_start ()
Thread 5 (process 7956 thread 0x6c03):
#0 0x946daace in __semwait_signal ()
#1 0x94705306 in _pthread_cond_wait ()
#2 0x94704ced in pthread_cond_wait$UNIX2003 ()
#3 0x92693460 in pthreadSemaphoreWait ()
#4 0x926a5d92 in CMMConvTask ()
#5 0x94704075 in _pthread_start ()
#6 0x94703f32 in thread_start ()
Thread 4 (process 7956 thread 0x6b07):
#0 0x946daace in __semwait_signal ()
#1 0x94705306 in _pthread_cond_wait ()
#2 0x94704ced in pthread_cond_wait$UNIX2003 ()
#3 0x92693460 in pthreadSemaphoreWait ()
#4 0x926a5d92 in CMMConvTask ()
#5 0x94704075 in _pthread_start ()
#6 0x94703f32 in thread_start ()
Thread 3 (process 7956 thread 0x6707):
#0 0x94722f5a in select$DARWIN_EXTSN ()
#1 0x96a0954f in __CFSocketManager ()
#2 0x94704075 in _pthread_start ()
#3 0x94703f32 in thread_start ()
Thread 2 (process 7956 thread 0x5c03):
#0 0x946d38e6 in mach_msg_trap ()
#1 0x946db0dc in mach_msg ()
#2 0x969fe0fe in CFRunLoopRunSpecific ()
#3 0x969fed38 in CFRunLoopRunInMode ()
#4 0x935e3560 in +[NSURLConnection(NSURLConnectionReallyInternal)
_resourceLoadLoop:] ()
#5 0x9358004d in -[NSThread main] ()
#6 0x9357fbf4 in __NSThread__main__ ()
#7 0x94704075 in _pthread_start ()
#8 0x94703f32 in thread_start ()
Thread 1 (process 7956 thread 0x10b):
#0 0x94709a36 in write$NOCANCEL$UNIX2003 ()
#1 0x9470998e in _swrite ()
#2 0x947098bb in __sflush ()
#3 0x946d4ac8 in __vfprintf ()
#4 0x94709603 in vfprintf_l ()
#5 0x94709597 in fprintf ()
#6 0x0007ef40 in BBDetailedLogWithVA (level=BB_LOG_INFO,
lineNumber=56, fileName=0x856b0
"/Users/jon/Developer/BBUtilities/Src/BBDownloader.m",
methodName=0x85610 "-[BBDownloader initWithURL:callBackObject:]",
message=0x8c300, args=0xbfffd8b4 "?d\003\027????????") at
/Users/jon/Developer/BBUtilities/Src/BBLogger.m:41
#7 0x0007efb5 in BBDetailedLog (level=BB_LOG_INFO, lineNumber=56,
fileName=0x856b0
"/Users/jon/Developer/BBUtilities/Src/BBDownloader.m",
methodName=0x85610 "-[BBDownloader initWithURL:callBackObject:]",
message=0x8c300) at /Users/jon/Developer/BBUtilities/Src/BBLogger.m:51
#8 0x0006fdf5 in -[BBDownloader initWithURL:callBackObject:]
(self=0x170364b0, _cmd=0x85be4, downloadURL=0x17036490,
obj=0x17036200) at
/Users/jon/Developer/BBUtilities/Src/BBDownloader.m:56
#9 0x0006fc3f in +[BBDownloader downloaderWithURL:callBackObject:]
(self=0x8ec00, _cmd=0x85db8, downloadURL=0x17036490, obj=0x17036200)
at /Users/jon/Developer/BBUtilities/Src/BBDownloader.m:32
#10 0x0006fbe3 in +[BBDownloader downloaderWithPath:callBackObject:]
(self=0x8ec00, _cmd=0x24748, downloadPath=0x2d078, obj=0x17036200) at
/Users/jon/Developer/BBUtilities/Src/BBDownloader.m:23
#11 0x000164bf in -[Scheduler startScheduler:] (self=0x17036200,
_cmd=0x266c1, isLinked=1 '\001') at
/Users/jon/Developer/MillicentPro/src/Scheduler.m:91
#12 0x0000fd49 in -[AppController startMainWindow] (self=0x136b20,
_cmd=0x267d3) at
/Users/jon/Developer/MillicentPro/src/AppController.m:222
#13 0x0000fa80 in -[AppController linkSucceeded] (self=0x136b20,
_cmd=0x267c5) at
/Users/jon/Developer/MillicentPro/src/AppController.m:193
#14 0x93580bfc in __NSThreadPerformPerform ()
#15 0x969fe64e in CFRunLoopRunSpecific ()
#16 0x969fed38 in CFRunLoopRunInMode ()
#17 0x928948a4 in RunCurrentEventLoopInMode ()
#18 0x928946bd in ReceiveNextEventCommon ()
#19 0x92894531 in BlockUntilNextEventMatchingListInMode ()
#20 0x96157d5b in _DPSNextEvent ()
#21 0x961576a0 in -[NSApplication
nextEventMatchingMask:untilDate:inMode:dequeue:] ()
#22 0x961506d1 in -[NSApplication run] ()
#23 0x9611d9ba in NSApplicationMain ()
#24 0x0000246c in child_main (argc=1, argv=0xbfffe9b0) at
/Users/jon/Developer/MillicentPro/src/main.m:23
#25 0x000024ce in main (argc=1, argv=0xbfffe9b0) at
/Users/jon/Developer/MillicentPro/src/main.m:70
_______________________________________________
Do not post admin requests to the list. They will be ignored.
Darwin-dev mailing list (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden