EXC_BAD_INSTRUCTION in ApolloWebSocket 0.20.0

[andrewking1235]

I'm seeing an EXC_BAD_INSTRUCTION crash in ApolloWebSocket 0.20.0. I tried reverting to 0.19.0 and the issue does not occur there. I therefore wonder if this is related to the data race fix that was included in the .20 release.

When: we open a WebSocket and get the websocketDidConnect call-back
Expect: the code will continue as normal, and we can use the WebSocket.
Actual: The app crashes on line 282:

Reproduction Steps:
As far as I can tell all we're doing is opening a socket, and seeing it crash in response. But I'm new on this project so unfortunately I can't add much detail beyond that.

Stack Trace:

Thread 2 Queue : com.apollographql.WebSocketTransport (serial)
#0	0x000000010ba45233 in protocol descriptor for Cancellable ()
#1	0x000000010b994214 in WebSocketTransport.websocketDidConnect(socket:) at /Users/andrew/Library/Developer/Xcode/DerivedData/Shopify-drldslbbvdivfbfkshqscdrcptzd/SourcePackages/checkouts/apollo-ios/Sources/ApolloWebSocket/WebSocketTransport.swift:282
#2	0x000000010b995129 in protocol witness for WebSocketDelegate.websocketDidConnect(socket:) in conformance WebSocketTransport ()
#3	0x000000010b822b0a in closure #1 in WebSocket.processHTTP(_:bufferLen:) at /Users/andrew/Library/Developer/Xcode/DerivedData/Shopify-drldslbbvdivfbfkshqscdrcptzd/SourcePackages/checkouts/Starscream/Sources/Starscream/WebSocket.swift:839
#4	0x000000010b80945d in thunk for @escaping @callee_guaranteed () -> () ()
#5	0x000000010d9b4dd4 in _dispatch_call_block_and_release ()
#6	0x000000010d9b5d48 in _dispatch_client_callout ()
#7	0x000000010d9bc5ef in _dispatch_lane_serial_drain ()
#8	0x000000010d9bd17f in _dispatch_lane_invoke ()
#9	0x000000010d9c8a4e in _dispatch_workloop_worker_thread ()
#10	0x00007fff51c016fc in _pthread_wqthread ()
#11	0x00007fff51c00827 in start_wqthread ()
Enqueued from com.vluxe.starscream.websocket (Thread 6) Queue : com.vluxe.starscream.websocket (serial)
#0	0x000000010d9b9c5d in dispatch_async ()
#1	0x000000010d5b2b5a in OS_dispatch_queue.async(group:qos:flags:execute:) ()
#2	0x000000010b822733 in WebSocket.processHTTP(_:bufferLen:) at /Users/andrew/Library/Developer/Xcode/DerivedData/Shopify-drldslbbvdivfbfkshqscdrcptzd/SourcePackages/checkouts/Starscream/Sources/Starscream/WebSocket.swift:836
#3	0x000000010b821f52 in WebSocket.processTCPHandshake(_:bufferLen:) at /Users/andrew/Library/Developer/Xcode/DerivedData/Shopify-drldslbbvdivfbfkshqscdrcptzd/SourcePackages/checkouts/Starscream/Sources/Starscream/WebSocket.swift:795
#4	0x000000010b821b74 in closure #1 in WebSocket.dequeueInput() at /Users/andrew/Library/Developer/Xcode/DerivedData/Shopify-drldslbbvdivfbfkshqscdrcptzd/SourcePackages/checkouts/Starscream/Sources/Starscream/WebSocket.swift:782
#5	0x000000010b821e7f in thunk for @callee_guaranteed () -> (@error @owned Error) ()
#6	0x000000010b839474 in partial apply for thunk for @callee_guaranteed () -> (@error @owned Error) ()
#7	0x000000010d96bd8e in autoreleasepool<A>(invoking:) ()
#8	0x000000010b821756 in WebSocket.dequeueInput() at /Users/andrew/Library/Developer/Xcode/DerivedData/Shopify-drldslbbvdivfbfkshqscdrcptzd/SourcePackages/checkouts/Starscream/Sources/Starscream/WebSocket.swift:770
#9	0x000000010b8215fe in WebSocket.processInputStream() at /Users/andrew/Library/Developer/Xcode/DerivedData/Shopify-drldslbbvdivfbfkshqscdrcptzd/SourcePackages/checkouts/Starscream/Sources/Starscream/WebSocket.swift:761
#10	0x000000010b821139 in WebSocket.newBytesInStream() at /Users/andrew/Library/Developer/Xcode/DerivedData/Shopify-drldslbbvdivfbfkshqscdrcptzd/SourcePackages/checkouts/Starscream/Sources/Starscream/WebSocket.swift:715
#11	0x000000010b8342be in protocol witness for WSStreamDelegate.newBytesInStream() in conformance WebSocket ()
#12	0x000000010b81353c in FoundationStream.stream(_:handle:) at /Users/andrew/Library/Developer/Xcode/DerivedData/Shopify-drldslbbvdivfbfkshqscdrcptzd/SourcePackages/checkouts/Starscream/Sources/Starscream/WebSocket.swift:300
#13	0x000000010b813a1c in @objc FoundationStream.stream(_:handle:) ()
#14	0x00007fff23bc9897 in _signalEventSync ()
#15	0x00007fff23bc98f2 in ___signalEventQueue_block_invoke ()
#16	0x000000010d9b4dd4 in _dispatch_call_block_and_release ()
#17	0x000000010d9b5d48 in _dispatch_client_callout ()
#18	0x000000010d9bc5ef in _dispatch_lane_serial_drain ()
#19	0x000000010d9bd17f in _dispatch_lane_invoke ()
#20	0x000000010d9c8a4e in _dispatch_workloop_worker_thread ()
#21	0x00007fff51c016fc in _pthread_wqthread ()
#22	0x00007fff51c00827 in start_wqthread ()
Enqueued from com.apple.root.default-qos.overcommit (Thread 11) Queue : com.apple.root.default-qos.overcommit (serial)
#0	0x000000010d9b9c5d in dispatch_async ()
#1	0x00007fff23bc6919 in _cfstream_solo_signalEventSync ()
#2	0x00007fff23bc67e3 in _CFStreamSignalEvent ()
#3	0x00007fff22e68336 in ___lldb_unnamed_symbol4044$$CFNetwork ()
#4	0x00007fff22e6f715 in ___lldb_unnamed_symbol4094$$CFNetwork ()
#5	0x00007fff23bb95bd in __CFSocketPerformV0 ()
#6	0x00007fff23bb2221 in __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ ()
#7	0x00007fff23bb214c in __CFRunLoopDoSource0 ()
#8	0x00007fff23bb1924 in __CFRunLoopDoSources0 ()
#9	0x00007fff23bac62f in __CFRunLoopRun ()
#10	0x00007fff23babe16 in CFRunLoopRunSpecific ()
#11	0x00007fff23bc9ac5 in _legacyStreamRunLoop_workThread ()
#12	0x00007fff51c04e65 in _pthread_start ()
#13	0x00007fff51c0083b in thread_start ()

[andrewking1235]

Also I've just noticed that enabling the Address Sanitizer has the effect of fixing this issue, thought that's obviously not a viable solution.

[andrewking1235]

Also noticed that one of those threads is called "overcommit" which sounded suspicious, and found this thread which may (or may not) be useful: https://stackoverflow.com/questions/27948618/consistent-dispatch-queue-com-apple-root-default-qos-overcommit-crash

[designatednerd]

Weird! That's definitely in the locking code that was changed in #880 - @aivcec any thoughts on what might be happening here?

[andrewking1235]

Ok another data point - I can make the crash disappear by building for Release.

This probably changes the timing since there is a different compiler optimization level, so its likely just hiding the bug - seems like it could be a race condition of some sort.

[aivcec]

Can you tell me what version of the Starscream dependency you use?

[andrewking1235]

This is happening with Starscream 3.1.1, but only when hooked up via SwiftPM. We had the same versions of all our dependencies when using Carthage and didn't see the problem there.

[designatednerd]

Huh, that's very weird - unless maybe Carthage is seeing a build setting that SPM isn't, I can't think of a good reason there'd be any difference whatsoever.

[andrewking1235]

I think the difference is SwiftPM using Debug vs Carthage using Release (which fits with my observation that the bug goes away in release builds).

My thinking is that Carthage must always build for release, whereas when you use SwiftPM Xcode builds the package according to the build settings of the project we're embedded into.

Does that seem like its plausible?

If thats the case then it might be that the bug would be reproducible in any Debug build, and not in any Release build because of (maybe?) compiler optimization differences?

[designatednerd]

Ooh, that's a good point, I forgot about Carthage always building for release. Yes, that definitely seems plausible.

If you set the compiler optimization to the same settings for your debug and release and the issue goes away, that's almost certainly the issue.

[andrewking1235]

Ok so I've been testing on Xcode 11.3 and it seems that this issue may have resolved itself there - possibly the same issue seen in this ticket: mxcl/PromiseKit#1099

I'll run some more testing and confirm here before closing the ticket

[designatednerd]

Yikes. Would love to hear back!

[andrewking1235]

Ok well after more testing we're not able to reproduce this crash on Xcode 11.3. So I think we can go ahead and close this as resolved. Thanks Apple!

[designatednerd]

I GIS'd "Thanks Apple" and had to share this result: