Swift runtime failure: precondition failure in HTTP2CommonInboundStreamMultiplexer.swift

the Swiftinit server has inexplicably begun crashing every few hours starting on Tuesday, when i look at the backtrace logs, it seems something is crashing deep inside swift-nio-http2.

*** Signal 4: Backtracing from 0x5577e6dd0134...
 done ***
*** Swift runtime failure: precondition failure ***
Thread 0 "swiftinit":
0  0x00007fce5c05508a sigsuspend + 74 in libc.so.6
Thread 1:
0  0x00007fce5c09c38a __futex_abstimed_wait_common + 202 in libc.so.6
Thread 2:
0  0x00007fce5c14e87e epoll_wait + 94 in libc.so.6
Thread 3 "NIO-ELT-0-#0":
0                0x00007fce5c14e87e epoll_wait + 94 in libc.so.6
1 [ra] [system]  0x00005577e6e872f1 specialized Selector.whenReady0(strategy:onLoopBegin:_:) + 624 in swiftinit at <compiler-generated>
2 [ra] [inlined] 0x00005577e6e83d9a specialized Selector.whenReady(strategy:onLoopBegin:_:) in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/SelectorGeneric.swift:288:18
3 [ra]           0x00005577e6e83d9a SelectableEventLoop.run() + 521 in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:470:36
4 [ra] [inlined] 0x00005577e6e5cda3 static MultiThreadedEventLoopGroup.runTheLoop(thread:parentGroup:canEventLoopBeShutdownIndividually:selectorFactory:initializer:_:) in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/MultiThreadedEventLoopGroup.swift:93:22
5 [ra]           0x00005577e6e5cda3 closure #1 in static MultiThreadedEventLoopGroup.setupThreadAndEventLoop(name:parentGroup:selectorFactory:initializer:) + 322 in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/MultiThreadedEventLoopGroup.swift:111:41
6 [ra] [thunk]   0x00005577e6e603ba partial apply for closure #1 in static MultiThreadedEventLoopGroup.setupThreadAndEventLoop(name:parentGroup:selectorFactory:initializer:) + 41 in swiftinit at <compiler-generated>
7 [ra] [thunk]   0x00005577e6e628df thunk for @escaping @callee_guaranteed (@guaranteed NIOThread) -> () + 14 in swiftinit at <compiler-generated>
8 [ra]           0x00005577e6e9fdad closure #1 in static ThreadOpsPosix.run(handle:args:detachThread:) + 380 in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/ThreadPosix.swift:116:13
Thread 4 "NIO-ELT-0-#1" crashed:
 0 [inlined] [system]      0x00005577e6dd0134 Swift runtime failure: precondition failure in swiftinit at <compiler-generated>
 1                         0x00005577e6dd0134 NIOHTTP2AsyncSequence.Continuation.yield(any:) + 372 in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2CommonInboundStreamMultiplexer.swift:513:21
 2 [ra] [thunk]            0x00005577e6dd0be2 partial apply for closure #1 in HTTP2CommonInboundStreamMultiplexer.receivedFrame(_:context:multiplexer:) + 49 in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2CommonInboundStreamMultiplexer.swift:117:47
 3 [ra] [system]           0x00005577e6dd04ee specialized closure #1 in EventLoopFuture._whenSuccess(_:) + 93 in swiftinit at <compiler-generated>
 4 [ra]                    0x00005577e6cd509d CallbackList._run() + 2796 in swiftinit at .build/checkouts/swift-nio/Sources/NIOCore/EventLoopFuture.swift:89:27
 5 [ra] [system]           0x00005577e6e0d1bc specialized EventLoopPromise._resolve(value:) + 75 in swiftinit at <compiler-generated>
 6 [ra] [inlined]          0x00005577e6df8c3b specialized HTTP2StreamChannel.postInitializerActivate<A>(output:promise:) in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2StreamChannel.swift
 7 [ra] [inlined]          0x00005577e6df8c3b specialized EventLoopPromise.succeed(_:) in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2StreamChannel.swift:259:18
 8 [ra]                    0x00005577e6df8c3b specialized HTTP2StreamChannel.onInitializationResult<A>(_:promise:) + 234 in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2StreamChannel.swift:290:18
 9 [ra] [inlined]          0x00005577e6df9490 specialized EventLoopFuture.whenComplete(_:) in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2StreamChannel.swift:248:26
10 [ra]                    0x00005577e6df9490 closure #1 in HTTP2StreamChannel.configure(initializer:userPromise:) + 975 in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2StreamChannel.swift:247:35
11 [ra]                    0x00005577e6e05ad8 specialized HTTP2StreamChannel.getAutoReadFromParent(_:) + 711 in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2StreamChannel.swift:273:13
12 [ra] [inlined] [system] 0x00005577e6dccc6d specialized HTTP2StreamChannel.getAutoReadFromParent(_:) in swiftinit at <compiler-generated>
13 [ra] [inlined]          0x00005577e6dccc6d HTTP2StreamChannel.configure(initializer:userPromise:) in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2StreamChannel.swift:243:14
14 [ra] [inlined]          0x00005577e6dccc6d MultiplexerAbstractChannel.configureInboundStream(initializer:promise:) in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/MultiplexerAbstractChannel.swift:109:30
15 [ra]                    0x00005577e6dccc6d HTTP2CommonInboundStreamMultiplexer.receivedFrame(_:context:multiplexer:) + 2492 in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2CommonInboundStreamMultiplexer.swift:120:25
16 [ra] [inlined]          0x00005577e6dbbb45 InlineStreamMultiplexer.receivedFrame(_:) in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2ChannelHandler+InlineStreamMultiplexer.swift:43:38
17 [ra]                    0x00005577e6dbbb45 NIOHTTP2Handler.InboundStreamMultiplexer.receivedFrame(_:) + 164 in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2ChannelHandler+InboundStreamMultiplexer.swift:51:41
18 [ra]                    0x00005577e6dc295b NIOHTTP2Handler.processFrame(_:flowControlledLength:context:) + 4586 in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2ChannelHandler.swift:582:44
19 [ra] [inlined]          0x00005577e6dbefe9 NIOHTTP2Handler.frameDecodeLoop(context:) in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2ChannelHandler.swift:477:41
20 [ra]                    0x00005577e6dbefe9 NIOHTTP2Handler.channelRead(context:data:) + 264 in swiftinit at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2ChannelHandler.swift:437:14
21 [ra]                    0x00005577e6cb8ff6 ChannelHandlerContext.invokeChannelRead(_:) + 37 in swiftinit at .build/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1696:28
22 [ra]                    0x00005577e6cb6303 ChannelHandlerContext.fireChannelRead(_:) + 34 in swiftinit at .build/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1509:20
23 [ra]                    0x00005577e6eaafbc NIOSSLHandler.doFlushReadData(context:receiveBuffer:readOnEmptyBuffer:) + 171 in swiftinit at .build/checkouts/swift-nio-ssl/Sources/NIOSSL/NIOSSLHandler.swift:654:21
24 [ra]                    0x00005577e6ea89ee NIOSSLHandler.channelReadComplete(context:) + 93 in swiftinit at .build/checkouts/swift-nio-ssl/Sources/NIOSSL/NIOSSLHandler.swift:201:14
25 [ra]                    0x00005577e6cb9040 ChannelHandlerContext.invokeChannelReadComplete() + 31 in swiftinit at .build/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1706:28
26 [ra]                    0x00005577e6cb9e86 ChannelPipeline.SynchronousOperations.fireChannelRegistered() + 37 in swiftinit
27 [ra]                    0x00005577e6e838c1 specialized BaseSocketChannel.readable0() + 592 in swiftinit
28 [ra] [inlined]          0x00005577e6e8a84a specialized BaseSocketChannel.readable() in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/BaseSocketChannel.swift:1099:14
29 [ra] [inlined] [system] 0x00005577e6e8a84a specialized protocol witness for SelectableChannel.readable() in conformance BaseSocketChannel<A> in swiftinit at <compiler-generated>:1096:23
30 [ra]                    0x00005577e6e8a84a specialized SelectableEventLoop.handleEvent<A>(_:channel:) + 153 in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:403:25
31 [ra] [inlined] [system] 0x00005577e6e85dd0 specialized SelectableEventLoop.handleEvent<A>(_:channel:) in swiftinit at <compiler-generated>
32 [ra]                    0x00005577e6e85dd0 closure #2 in closure #2 in SelectableEventLoop.run() + 159 in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:478:30
33 [ra] [thunk]            0x00005577e6e8dd2c partial apply for closure #2 in closure #2 in SelectableEventLoop.run() + 11 in swiftinit at <compiler-generated>
34 [ra]                    0x00005577e6e874c3 specialized Selector.whenReady0(strategy:onLoopBegin:_:) + 1090 in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/SelectorEpoll.swift:252:25
35 [ra] [inlined]          0x00005577e6e83d9a specialized Selector.whenReady(strategy:onLoopBegin:_:) in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/SelectorGeneric.swift:288:18
36 [ra]                    0x00005577e6e83d9a SelectableEventLoop.run() + 521 in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:470:36
37 [ra] [inlined]          0x00005577e6e5cda3 static MultiThreadedEventLoopGroup.runTheLoop(thread:parentGroup:canEventLoopBeShutdownIndividually:selectorFactory:initializer:_:) in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/MultiThreadedEventLoopGroup.swift:93:22
38 [ra]                    0x00005577e6e5cda3 closure #1 in static MultiThreadedEventLoopGroup.setupThreadAndEventLoop(name:parentGroup:selectorFactory:initializer:) + 322 in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/MultiThreadedEventLoopGroup.swift:111:41
39 [ra] [thunk]            0x00005577e6e603ba partial apply for closure #1 in static MultiThreadedEventLoopGroup.setupThreadAndEventLoop(name:parentGroup:selectorFactory:initializer:) + 41 in swiftinit at <compiler-generated>
40 [ra] [thunk]            0x00005577e6e628df thunk for @escaping @callee_guaranteed (@guaranteed NIOThread) -> () + 14 in swiftinit at <compiler-generated>
41 [ra]                    0x00005577e6e9fdad closure #1 in static ThreadOpsPosix.run(handle:args:detachThread:) + 380 in swiftinit at .build/checkouts/swift-nio/Sources/NIOPosix/ThreadPosix.swift:116:13
Thread 5 "NIO-ELT-0-#0":
0  0x00007fce5c09c38a __futex_abstimed_wait_common + 202 in libc.so.6
Registers:
rax 0x0000000000000002  2
rdx 0x00007fce595f9190  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ยทยทยทยทยทยทยทยทยทยทยทยทยทยทยทยท
rcx 0x00007fce5cf27a50  02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ยทยทยทยทยทยทยทยทยทยทยทยทยทยทยทยท
rbx 0x0000000000000002  2
rsi 0x00007fce595f91d0  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ยทยทยทยทยทยทยทยทยทยทยทยทยทยทยทยท
rdi 0x00007fce5cf25530  de ea fd ff a1 ea fd ff ab ea fd ff b5 ea fd ff  รžรชรฝรฟยกรชรฝรฟยซรชรฝรฟยตรชรฝรฟ
rbp 0x00007fce595f92d0  00 93 5f 59 ce 7f 00 00 e2 0b dd e6 77 55 00 00  ยทยท_YรŽยทยทยทรขยทรรฆwUยทยท
rsp 0x00007fce595f9190  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ยทยทยทยทยทยทยทยทยทยทยทยทยทยทยทยท
 r8 0x0000000000000002  2
 r9 0x000000000ff9cb94  268028820
r10 0x00007fce58be8f98  48 bb dd e7 77 55 00 00 f8 1c a6 5c ce 7f 00 00  HยปรรงwUยทยทรธยทยฆ\รŽยทยทยท
r11 0x0000000000000000  0
r12 0x00007fce595f91d0  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ยทยทยทยทยทยทยทยทยทยทยทยทยทยทยทยท
r13 0x00007fce595f9210  80 e7 53 55 ce 7f 00 00 20 00 dd e6 77 55 00 00  ยทรงSUรŽยทยทยท ยทรรฆwUยทยท
r14 0x00007fce58be8ff8  80 35 f0 5c ce 7f 00 00 a0 36 f0 5c ce 7f 00 00  ยท5รฐ\รŽยทยทยท 6รฐ\รŽยทยทยท
r15 0x00007fce58be8fc0  01 02 00 00 00 00 00 00 f0 79 f2 5c ce 7f 00 00  ยทยทยทยทยทยทยทยทรฐyรฒ\รŽยทยทยท
rip 0x00005577e6dd0134  0f 0b 0f 0b 0f 1f 84 00 00 00 00 00 55 48 89 e5  ยทยทยทยทยทยทยทยทยทยทยทยทUHยทรฅ
rflags 0x0000000000010246  ZF PF
cs 0x0033  fs 0x0000  gs 0x0000
Images (13 omitted):
0x00005577e6608000โ€“0x00005577e77688b9 <no build ID>                            swiftinit /home/ec2-user/bin/swiftinit
0x00007fce5c000000โ€“0x00007fce5c19c05c 30448f508336fb6b11d92bcff7f65c300f3e68e1 libc.so.6 /usr/lib64/libc.so.6
Backtrace took 19.11s
421533 Illegal instruction     (core dumped)

the source location corresponds to the terminated case in NIOHTTP2AsyncSequence.Continuation.yield(_:).

/// `yield` takes a channel as outputted by the stream initializer and yields the wrapped `AsyncThrowingStream`.
///
/// It takes channels as as `Any` type to allow wrapping by the stream initializer.
func yield(any: Any) {
    let yieldResult = self.continuation.yield(any as! Output)
        switch yieldResult {
        case .enqueued:
            break // success, nothing to do
        case .dropped:
            preconditionFailure("Attempted to yield when AsyncThrowingStream is over capacity. This shouldn't be possible for an unbounded stream.")
        case .terminated:
            preconditionFailure("Attempted to yield to AsyncThrowingStream in terminated state.")
        default:
            preconditionFailure("Attempt to yield to AsyncThrowingStream failed for unhandled reason.")
        }
}

this became hard to ignore when it started triggering cascade failure due to high resource requirements of backtrace collection and resulted in long-lasting service outage.

why on earth are there even runtime traps in SwiftNIO in the first place? the blast radius of assertion failures in server applications is far, far greater than in client applications, and this was simply catastrophic for us.

i thought this precondition failure looked familiar and i rediscovered Attempted to yield to AsyncThrowingStream in terminated state

which means this crasher has existed in SwiftNIO for nearly 3 months now. we are treating this as an emergency at our org. @lukasa have you heard back from the SwiftNIO team?

Yes, that issue was fixed in 1.30.0: Remove precondition: yielding to terminated AsyncSequence by rnro ยท Pull Request #432 ยท apple/swift-nio-http2 ยท GitHub, which was shipped on January 22nd.

1 Like

thanks Cory, thatโ€™ll teach me to run swift package update more often. i should keep closer tabs on that repoโ€ฆ