Hi all,
I have a Mac OS X application running on 10.11 that sometimes hangs while performing a network upload. The upload is performed over HTTPs using NSURLConnection that has a bodyStream associated with it. The body stream is one end of a CFStream created with CFStreamCreateBoundPair. The other end of the stream is written to periodically as data becomes available. When I get an NSStreamHasSpaceAvailable delegate message, I append the data I have available in my stream.
This all works well 90% of the time, but around 1 in 20 uploads will deadlock with the backtrace below. It looks like CFStream is calling my delegate recursively—frames 10 and 4 are both in my delegate callback, for the same stream, with the same event code (hasBytesAvailable). This in itself is weird, but it causes a deadlock because boundPairWrite must be implemented with a mutex that is taken recursively.
In frame 10, I write all the data I have at the moment—152 bytes. This isn’t large, and doesn’t fill up the transfer size associated with the bound stream (which is 4K at the moment). Best I can tell, CFStream decides that since I didn’t consume all the space, it can send another hasBytesAvailable delegate message.
Am I reading things wrong? Here’s the backtrace.
(lldb) thread backtrace all * thread #1: tid = 0x82b0e1, 0x00007fff8ad8fee2 libsystem_kernel.dylib`__psynch_mutexwait + 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP frame #0: 0x00007fff8ad8fee2 libsystem_kernel.dylib`__psynch_mutexwait + 10 frame #1: 0x00007fff87f13a49 libsystem_pthread.dylib`_pthread_mutex_lock_wait + 89 frame #2: 0x00007fff849d1374 CoreFoundation`boundPairWrite + 52 frame #3: 0x00007fff848ed395 CoreFoundation`CFWriteStreamWrite + 437 * frame #4: 0x0000000103d5fe60 SymQual`-[SQSubmissionUpload stream:handleEvent:](self=0x00007fe3f9e12a20, _cmd="stream:handleEvent:", aStream=0x00007fe3f9d65f00, eventCode=4) + 2816 at SQSubmissionUpload.m:305 frame #5: 0x00007fff849529a4 CoreFoundation`_signalEventSync + 180 frame #6: 0x00007fff849528db CoreFoundation`_cfstream_solo_signalEventSync + 251 frame #7: 0x00007fff8495278c CoreFoundation`_CFStreamSignalEvent + 476 frame #8: 0x00007fff849d1572 CoreFoundation`boundPairWrite + 562 frame #9: 0x00007fff848ed395 CoreFoundation`CFWriteStreamWrite + 437 frame #10: 0x0000000103d5fe60 SymQual`-[SQSubmissionUpload stream:handleEvent:](self=0x00007fe3f9e12a20, _cmd="stream:handleEvent:", aStream=0x00007fe3f9d65f00, eventCode=4) + 2816 at SQSubmissionUpload.m:305 frame #11: 0x00007fff849529a4 CoreFoundation`_signalEventSync + 180 frame #12: 0x00007fff8499027e CoreFoundation`_cfstream_shared_signalEventSync + 478 frame #13: 0x00007fff849125c1 CoreFoundation`__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ + 17 frame #14: 0x00007fff8490441c CoreFoundation`__CFRunLoopDoSources0 + 556 frame #15: 0x00007fff8490393f CoreFoundation`__CFRunLoopRun + 927 frame #16: 0x00007fff84903338 CoreFoundation`CFRunLoopRunSpecific + 296 frame #17: 0x00007fff818d8e61 Foundation`-[NSRunLoop(NSRunLoop) runMode:beforeDate:] + 270 frame #18: 0x00007fff8194aafd Foundation`-[NSRunLoop(NSRunLoop) run] + 74 frame #19: 0x0000000103c3ddec symquald`-[SQDaemon run](self=0x00007fe3f9c03ae0, _cmd="run") + 2140 at SQDaemon.m:182 frame #20: 0x0000000103c38c02 symquald`main(argc=3, argv=0x00007fff5bfc9978) + 482 at main.m:71 frame #21: 0x0000000103c37be4 symquald`start + 52
thread #3: tid = 0x82b0f1, 0x00007fff8ad8fee2 libsystem_kernel.dylib`__psynch_mutexwait + 10, name = 'com.apple.NSURLConnectionLoader' frame #0: 0x00007fff8ad8fee2 libsystem_kernel.dylib`__psynch_mutexwait + 10 frame #1: 0x00007fff87f13a49 libsystem_pthread.dylib`_pthread_mutex_lock_wait + 89 frame #2: 0x00007fff849d0d57 CoreFoundation`boundPairRead + 151 frame #3: 0x00007fff849457a5 CoreFoundation`CFReadStreamRead + 389 frame #4: 0x00007fff817a9447 CFNetwork`spoolingRead(__CFReadStream*, unsigned char*, long, CFStreamError*, unsigned char*, void*) + 165 frame #5: 0x00007fff849457a5 CoreFoundation`CFReadStreamRead + 389 frame #6: 0x00007fff81681442 CFNetwork`HTTPNetConnection::transmitRequest(HTTPNetStreamInfo*, __CoreWriteStream*, CFStreamError*, unsigned char) + 1360 frame #7: 0x00007fff816ad5ed CFNetwork`HTTPNetConnection::transmitRequest(void*) + 107 frame #8: 0x00007fff816851ca CFNetwork`HTTPNetConnection::handleReadEventsDuringRequestBodyTransmission(void*, unsigned long) + 802 frame #9: 0x00007fff81684b8e CFNetwork`HTTPNetConnection::responseStreamCallback(void*, __CoreReadStream*, unsigned long) + 90 frame #10: 0x00007fff81684ac9 CFNetwork`NetConnection::connectionResponse(__CoreReadStream*, unsigned long) + 87 frame #11: 0x00007fff81684a06 CFNetwork`CoreReadStreamClient::coreStreamEventsAvailable(unsigned long) + 60 frame #12: 0x00007fff81680c7d CFNetwork`CoreStreamBase::_callClientNow(CoreStreamClient*) + 53 frame #13: 0x00007fff8167e5ff CFNetwork`CoreStreamBase::_streamSetEventAndScheduleDelivery(unsigned long, unsigned char) + 183 frame #14: 0x00007fff81682d41 CFNetwork`HTTPReadFilter::readHeaderBytes(StreamReader*, unsigned char, unsigned char*, long, CFStreamError*) + 85 frame #15: 0x00007fff81682bbe CFNetwork`HTTPReadFilter::canReadNoSignal(StreamReader*, CFStreamError*, unsigned char) + 128 frame #16: 0x00007fff81683640 CFNetwork`HTTPReadFilter::_streamImpl_CanRead() + 126 frame #17: 0x00007fff81683a3d CFNetwork`HTTPReadFilter::socketReadStreamCallback(unsigned long) + 179 frame #18: 0x00007fff8168397a CFNetwork`HTTPReadFilter::_httpRdFilterStreamCallBack(__CFReadStream*, unsigned long, void*) + 118 frame #19: 0x00007fff849529a4 CoreFoundation`_signalEventSync + 180 frame #20: 0x00007fff849528db CoreFoundation`_cfstream_solo_signalEventSync + 251 frame #21: 0x00007fff8495278c CoreFoundation`_CFStreamSignalEvent + 476 frame #22: 0x00007fff815cbea0 CFNetwork`SocketStream::dispatchSignalFromSocketCallbackUnlocked(SocketStreamSignalHolder*) + 58 frame #23: 0x00007fff815d11d6 CFNetwork`SocketStream::socketCallback(__CFSocket*, unsigned long, __CFData const*, void const*) + 246 frame #24: 0x00007fff815d10a6 CFNetwork`SocketStream::_SocketCallBack_stream(__CFSocket*, unsigned long, __CFData const*, void const*, void*) + 70 frame #25: 0x00007fff849521c4 CoreFoundation`__CFSocketPerformV0 + 996 frame #26: 0x00007fff849125c1 CoreFoundation`__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ + 17 frame #27: 0x00007fff8490441c CoreFoundation`__CFRunLoopDoSources0 + 556 frame #28: 0x00007fff8490393f CoreFoundation`__CFRunLoopRun + 927 frame #29: 0x00007fff84903338 CoreFoundation`CFRunLoopRunSpecific + 296 frame #30: 0x00007fff815966e9 CFNetwork`+[NSURLConnection(Loader) _resourceLoadLoop:] + 412 frame #31: 0x00007fff81a24c6f Foundation`__NSThread__start__ + 1351 frame #32: 0x00007fff87f10c13 libsystem_pthread.dylib`_pthread_body + 131 frame #33: 0x00007fff87f10b90 libsystem_pthread.dylib`_pthread_start + 168 frame #34: 0x00007fff87f0e375 libsystem_pthread.dylib`thread_start + 13 |