Today I spent some time debugging MacGDBp 1.4. The issue I was having was that socket data was being processed out of order, and I couldn’t figure out why. Until I stuck it in the debugger. It turns out that when you call -[NSAttributedString initWithHTML:documentAttributes:]
, it spins the run loop internally (making a nested run loop). If, for example, you have a socket scheduled on the main run loop in common modes, the socket will signaled if you create the NSAttributedString on the main thread. Here’s a stack trace:
#0 0x0000495e in -[DebuggerConnection handlePacket:] at DebuggerConnection.m:597
#1 0x000044e8 in -[DebuggerConnection readStreamHasData] at DebuggerConnection.m:508
#2 0x00003243 in ReadStreamCallback at DebuggerConnection.m:76
#3 0x9021cdd3 in _signalEventSync
#4 0x9021d7be in _cfstream_solo_signalEventSync
#5 0x9021ca88 in _CFStreamSignalEvent
#6 0x9021d707 in CFReadStreamSignalEvent
#7 0x906e7cd9 in SocketStream::dispatchSignalFromSocketCallbackUnlocked
#8 0x90694819 in SocketStream::socketCallback
#9 0x90694721 in SocketStream::_SocketCallBack_stream
#10 0x901d91ae in __CFSocketDoCallback
#11 0x901d8c97 in __CFSocketPerformV0
#12 0x90192ff1 in __CFRunLoopDoSources0
#13 0x90190c1f in __CFRunLoopRun
#14 0x901900f4 in CFRunLoopRunSpecific
#15 0x9018ff21 in CFRunLoopRunInMode
#16 0x989ee6e8 in -[NSHTMLReader _loadUsingWebKit]
#17 0x989e2ddb in -[NSHTMLReader attributedString]
#18 0x98842585 in _NSReadAttributedStringFromURLOrData
#19 0x9883f910 in -[NSAttributedString(NSAttributedStringKitAdditions) initWithData:options:documentAttributes:error:]
#20 0x98887a35 in -[NSAttributedString(NSAttributedStringKitAdditions) initWithHTML:options:documentAttributes:]
#21 0x988879a9 in -[NSAttributedString(NSAttributedStringKitAdditions) initWithHTML:documentAttributes:]
#22 0x0000acf7 in -[BSSourceView setFile:] at BSSourceView.m:93
#23 0x0000af91 in -[BSSourceView setString:asFile:] at BSSourceView.m:120
#24 0x00007bae in -[DebuggerController updateSourceViewer] at DebuggerController.m:264
#25 0x000081e4 in -[DebuggerController sourceUpdated:] at DebuggerController.m:353
#26 0x00005a6b in -[DebuggerConnection setSource:] at DebuggerConnection.m:839
#27 0x00004ecf in -[DebuggerConnection handleResponse:] at DebuggerConnection.m:694
#28 0x000049cc in -[DebuggerConnection handlePacket:] at DebuggerConnection.m:600
#29 0x000044e8 in -[DebuggerConnection readStreamHasData] at DebuggerConnection.m:508
#30 0x00003243 in ReadStreamCallback at DebuggerConnection.m:76
#31 0x9021cdd3 in _signalEventSync
#32 0x9021cd58 in _cfstream_shared_signalEventSync
#33 0x9019315b in __CFRunLoopDoSources0
#34 0x90190c1f in __CFRunLoopRun
#35 0x901900f4 in CFRunLoopRunSpecific
#36 0x9018ff21 in CFRunLoopRunInMode
#37 0x944ed0fc in RunCurrentEventLoopInMode
#38 0x944eceb1 in ReceiveNextEventCommon
#39 0x944ecd36 in BlockUntilNextEventMatchingListInMode
#40 0x98605135 in _DPSNextEvent
#41 0x98604976 in -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]
#42 0x985c6bef in -[NSApplication run]
#43 0x985bec85 in NSApplicationMain
#44 0x00002c44 in main at main.m:21
At frame 30, the socket callback gets signaled because data is ready. This happens on the outermost loop invocation, which is supposed to happen (yay!). At frame 22, the data for this most recent network packet is still being processed. At frame 21, there’s the call to initWithHTML for NSAttributedString. And at frame 15, trouble starts when the run loop gets spun again, while still processing sources from the first/outermost run loop invocation. At frame 2, while still processing the packet from frame 30, the socket source gets signaled again and new data is read and processed, while still processing the first piece of data. Sigh.
I haven’t yet decided how I’m going to get around this problem. The issue is that more data gets read from the socket before the current packet finishes handling, making a hot mess (it screws up internal state). The easiest conceptual solution is to push the socket stuff into its own thread on its own run loop, but that will require a fairly significant refactoring. Another option would be to schedule the socket in its own run loop mode, but then I’d be responsible for spinning the loop myself and would have to manage that carefully.
Update: I bit the bullet and refactored. In the long run, this is probably a good thing because it forced a separation of components that deal with CFNetwork itself and the response to the data received from it. It also split a 1032 line file into two files, one about 600 lines and one about 500 lines.