Crash when handler is being added

[saudeoncovr]

Expected behavior

When attempting handler.handlerAdded(context: self) I do not expect a crash to occur.

Actual behavior

Crashing at line 1482 in ChannelPipeline.swift. Following is the crash: Thread 3: EXC_BAD_INSTRUCTION (code=EXC_I386_INVOP, subcode=0x0)

Steps to reproduce

This is currently occurring with the nio implementation of grpc-swift. The implementation can be found here.

If possible, minimal yet complete reproducer code (or URL to code)

[anything to help us reproducing the issue]

SwiftNIO version/commit hash

2.9.0

Swift & OS version (output of swift --version && uname -a)

Apple Swift version 5.1.2 (swiftlang-1100.0.278 clang-1100.0.33.9) Target: x86_64-apple-darwin19.0.0

[Lukasa]

Thanks for this issue!

I think it’s highly unlikely that this is a NIO issue; the code in question there is very simple. The crash you’re seeing is a precondition failure; do you have a full crash report?

[weissi]

CC @glbrntt / @MrMage as grpc-swift is also in the picture

[weissi]

code in question is

$ git show 2.9.0:Sources/NIO/ChannelPipeline.swift | cat -n | grep -C 3 1482
  1479      fileprivate func invokeHandlerAdded() throws {
  1480          self.eventLoop.assertInEventLoop()
  1481  
  1482          handler.handlerAdded(context: self)
  1483      }
  1484  
  1485      fileprivate func invokeHandlerRemoved() throws {

I don't think the crash itself can actually be in 1482, it's more likely the crash happens in handlerAdded of the handler that was just added. As Cory says, we need a full crash report (best), or at least a full stack trace (screenshot from Xcode or bt in lldb)

[saudeoncovr]

Providing full stack trace here.

Note that we caught this by running our unit tests. I guess that's a +1 for unit testing networking request/response!

* thread #3, queue = 'nio.transportservices.eventloop.taskqueue', stop reason = EXC_BAD_INSTRUCTION (code=EXC_I386_INVOP, subcode=0x0)
    frame #0: 0x0000000111ab7a20 AppleGRPCPackageTests`partial apply for implicit closure #3 in ClientResponseChannelHandler.channelRead(context:data:) at <compiler-generated>:0
    frame #1: 0x0000000111ab8da1 AppleGRPCPackageTests`protocol witness for ChannelHandler.handlerAdded(context:) in conformance ClientResponseChannelHandler<A> at <compiler-generated>:0
    frame #2: 0x0000000111b8b43c AppleGRPCPackageTests`ChannelHandlerContext.invokeHandlerAdded(self=0x00007f962d595120) at ChannelPipeline.swift:1482:17
    frame #3: 0x0000000111b8a0fe AppleGRPCPackageTests`ChannelPipeline.add0(name=nil, handler=0x00007f964001f6b0, relativeContext=0x00007f962d593ab0, operation=0x0000000111b9e010 AppleGRPCPackageTests`partial apply forwarder for NIO.ChannelPipeline.(add0 in _EEC863903996E9F191EBAFEB0FB0DFDD)(context: NIO.ChannelHandlerContext, before: NIO.ChannelHandlerContext) -> () at <compiler-generated>, promise=NIO.EventLoopPromise<Swift.Void> @ 0x0000700008bc2088, self=0x00007f962d593a00) at ChannelPipeline.swift:284:25
    frame #4: 0x0000000111b897aa AppleGRPCPackageTests`_add #1 (self=0x00007f962d593a00, promise=NIO.EventLoopPromise<Swift.Void> @ 0x0000700008bc2380, position=last, name=nil, handler=0x00007f964001f6b0) in ChannelPipeline.addHandler(_:name:position:) at ChannelPipeline.swift:184:22
    frame #5: 0x0000000111b89026 AppleGRPCPackageTests`ChannelPipeline.addHandler(handler=0x00007f964001f6b0, name=nil, position=last, self=0x00007f962d593a00) at ChannelPipeline.swift:205:13
    frame #6: 0x0000000111b95891 AppleGRPCPackageTests`closure #1 in ChannelPipeline.addHandlers($0=0x00007f964001f6b0, self=0x00007f962d593a00, individualPosition=last) at ChannelPipeline.swift:905:46
    frame #7: 0x0000000111b958f0 AppleGRPCPackageTests`thunk for @callee_guaranteed (@guaranteed ChannelHandler) -> (@owned EventLoopFuture<()>, @error @owned Error) at <compiler-generated>:0
    frame #8: 0x0000000111b9c534 AppleGRPCPackageTests`partial apply for thunk for @callee_guaranteed (@guaranteed ChannelHandler) -> (@owned EventLoopFuture<()>, @error @owned Error) at <compiler-generated>:0
    frame #9: 0x0000000113379d4f libswiftCore.dylib`(extension in Swift):Swift.Collection.map<A>((A.Element) throws -> A1) throws -> Swift.Array<A1> + 751
    frame #10: 0x0000000111b956f8 AppleGRPCPackageTests`ChannelPipeline.addHandlers(handlers=5 values, position=last, self=0x00007f962d593a00) at ChannelPipeline.swift:905:40
    frame #11: 0x0000000111b95984 AppleGRPCPackageTests`ChannelPipeline.addHandlers(handlers=5 values, position=last, self=0x00007f962d593a00) at ChannelPipeline.swift:918:16
    frame #12: 0x0000000111a93f8c AppleGRPCPackageTests`closure #1 in closure #2 in BaseClientCall.createStreamChannel(subchannel=0x00007f962d594730, streamID=(networkStreamID = 1), self=0x00007f9642b00910) at BaseClientCall.swift:128:29
    frame #13: 0x0000000111e1e9b6 AppleGRPCPackageTests`closure #1 in HTTP2StreamChannel.configure(autoRead=true, self=0x00007f962d594730, initializer=0x0000000111a95920 AppleGRPCPackageTests`partial apply forwarder for closure #1 (NIO.Channel, NIOHTTP2.HTTP2StreamID) -> NIO.EventLoopFuture<()> in closure #2 (NIOHTTP2.HTTP2StreamMultiplexer) -> () in GRPC.BaseClientCall.(createStreamChannel in _4104CC2C1DDA91562B5DDDFACCA1B098)() -> () at <compiler-generated>) at HTTP2StreamChannel.swift:150:31
    frame #14: 0x0000000111e1eb5f AppleGRPCPackageTests`thunk for @escaping @callee_guaranteed (@unowned Bool) -> (@owned EventLoopFuture<()>) at <compiler-generated>:0
    frame #15: 0x0000000111be4e86 AppleGRPCPackageTests`closure #1 in EventLoopFuture.flatMap<Value>(self=0x00007f962d593c00, callback=0x0000000111e1eba0 AppleGRPCPackageTests`partial apply forwarder for reabstraction thunk helper from @escaping @callee_guaranteed (@unowned Swift.Bool) -> (@owned NIO.EventLoopFuture<()>) to @escaping @callee_guaranteed (@in_guaranteed Swift.Bool) -> (@owned NIO.EventLoopFuture<()>) at <compiler-generated>, next=NIO.EventLoopPromise<()> @ 0x0000700008bc30c8) at EventLoopFuture.swift:489:31
    frame #16: 0x0000000111be5748 AppleGRPCPackageTests`EventLoopFuture._addCallback(callback=0x0000000111beb000 AppleGRPCPackageTests`partial apply forwarder for closure #1 () -> NIO.CallbackList in NIO.EventLoopFuture.flatMap<A>(file: Swift.StaticString, line: Swift.UInt, _: (A) -> NIO.EventLoopFuture<A1>) -> NIO.EventLoopFuture<A1> at <compiler-generated>, self=0x00007f962d593c00) at EventLoopFuture.swift:682:16
    frame #17: 0x0000000111be58a2 AppleGRPCPackageTests`EventLoopFuture._whenComplete(callback=0x0000000111beb000 AppleGRPCPackageTests`partial apply forwarder for closure #1 () -> NIO.CallbackList in NIO.EventLoopFuture.flatMap<A>(file: Swift.StaticString, line: Swift.UInt, _: (A) -> NIO.EventLoopFuture<A1>) -> NIO.EventLoopFuture<A1> at <compiler-generated>, self=0x00007f962d593c00) at EventLoopFuture.swift:689:18
    frame #18: 0x0000000111be4add AppleGRPCPackageTests`EventLoopFuture.flatMap<Value>(file="/Users/sebastien/Library/Developer/Xcode/DerivedData/apple-grpc-package-evihpmhvkwwlckceywyenqguuxma/SourcePackages/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2StreamChannel.swift", line=148, callback=0x0000000111e1eba0 AppleGRPCPackageTests`partial apply forwarder for reabstraction thunk helper from @escaping @callee_guaranteed (@unowned Swift.Bool) -> (@owned NIO.EventLoopFuture<()>) to @escaping @callee_guaranteed (@in_guaranteed Swift.Bool) -> (@owned NIO.EventLoopFuture<()>) at <compiler-generated>, self=0x00007f962d593c00) at EventLoopFuture.swift:486:14
    frame #19: 0x0000000111e1e605 AppleGRPCPackageTests`HTTP2StreamChannel.configure(initializer=0x0000000111a95920 AppleGRPCPackageTests`partial apply forwarder for closure #1 (NIO.Channel, NIOHTTP2.HTTP2StreamID) -> NIO.EventLoopFuture<()> in closure #2 (NIOHTTP2.HTTP2StreamMultiplexer) -> () in GRPC.BaseClientCall.(createStreamChannel in _4104CC2C1DDA91562B5DDDFACCA1B098)() -> () at <compiler-generated>, promise=some, self=0x00007f962d594730) at HTTP2StreamChannel.swift:148:65
  * frame #20: 0x0000000111e2b1f8 AppleGRPCPackageTests`closure #1 in HTTP2StreamMultiplexer.createStreamChannel(self=0x00007f9640352670, streamStateInitializer=0x0000000111a95920 AppleGRPCPackageTests`partial apply forwarder for closure #1 (NIO.Channel, NIOHTTP2.HTTP2StreamID) -> NIO.EventLoopFuture<()> in closure #2 (NIOHTTP2.HTTP2StreamMultiplexer) -> () in GRPC.BaseClientCall.(createStreamChannel in _4104CC2C1DDA91562B5DDDFACCA1B098)() -> () at <compiler-generated>, promise=some) at HTTP2StreamMultiplexer.swift:308:21
    frame #21: 0x0000000111cb2a0d AppleGRPCPackageTests`thunk for @escaping @callee_guaranteed () -> () at <compiler-generated>:0
    frame #22: 0x00007fff519eb265 libdispatch.dylib`_dispatch_block_async_invoke2 + 83
    frame #23: 0x00007fff519de7b9 libdispatch.dylib`_dispatch_client_callout + 8
    frame #24: 0x00007fff519e4526 libdispatch.dylib`_dispatch_lane_serial_drain + 707
    frame #25: 0x00007fff519e4f93 libdispatch.dylib`_dispatch_lane_invoke + 443
    frame #26: 0x00007fff519e4394 libdispatch.dylib`_dispatch_lane_serial_drain + 305
    frame #27: 0x00007fff519e4f93 libdispatch.dylib`_dispatch_lane_invoke + 443
    frame #28: 0x00007fff519eeff9 libdispatch.dylib`_dispatch_workloop_worker_thread + 626
    frame #29: 0x00007fff51c0171b libsystem_pthread.dylib`_pthread_wqthread + 290
    frame #30: 0x00007fff51c0157b libsystem_pthread.dylib`start_wqthread + 15

I do not have a complete crash log as this unit test is being run from within a swift package. I will attempt to get a version of this into our main application so that I can provide a full crash log.

[weissi]

@saudeoncovr the crash report should be in ~/Library/Logs/DiagnosticReports/xctest_DATE-TIME.crash.

[saudeoncovr]

@weissi I took a look and it doesn't look like there are any crash reports for xctest at that path. I am going to attempt to get this crash occurring within our main application on the simulator so that the crash report is provided correctly.

[weissi]

@saudeoncovr oh sorry, just seeing that run this in lldb. You should get a crash report if you enter cont into the debugger window.

If that doesn't work, then you can reproduce the issue again and enter

command script import lldb.macosx.crashlog
save_crashlog /tmp/crash.log

into lldb (where you should see the (lldb) prompt.

[saudeoncovr]

@weissi easy, I have attached the crash log.

[weissi]

@saudeoncovr wow, this is a weird issue. This might actually be https://bugs.swift.org/projects/SR/issues/SR-11564 . Can you confirm you're running Xcode 11.2?

If you happen to have an Xcode 11.1 around, does it happen there too?

Just to get another angle on this: Can you try to run (from the command line)

xcodebuild -scheme MySchemeName test

? Then you should really get a file named

/Users/YOUR_USERNAME/Library/Logs/DiagnosticReports/xctest_DATE-TIME-X_COMPUTER-NAME-XXX.crash

which should be a slightly better crash log than the one generated with save_crashlog above?

I'm assuming your project does not run on macOS? If it does, can you confirm (with Xcode 11.1 or 11.2) that it doesn't crash on macOS?

[weissi]

@saudeoncovr last question: can you share the code or the binary?

[saudeoncovr]

@weissi Interesting. I can confirm that I am running Xcode 11.2 (11B52). I don't have Xcode 11.1 readily available.

I can confirm that this runs as expected when running the tests against macOS. There is no crash.

When running via the command line I receive a crash report per test case.

[saudeoncovr]

@weissi note that I used the following command to run the tests via the command line.

xcodebuild -scheme [package-name] -destination 'platform=iOS Simulator,name=iPhone 11,OS=13.2' test

[saudeoncovr]

@weissi I had to remove the crash logs. It seems the resolution to this was to do what has been described in SR-11564.

This involved setting DEAD_CODE_STRIPPING to NO in the build settings of the application. It will still break the unit tests per package but that can be dealt with separately.

Going to close this out as it seems to be a larger swift team issue.

[weissi]

Thanks @saudeoncovr for your info! Yes, this seems to be that Swift issue then 😭

[bimawa]

Guys when I did SPM where I should to setup DEAD_CODE_STRIPPING=NO. It set to NO by defult isn't? xcode13.4