Crash in NIOAsyncWriter.InternalClass.deinit

taylorswift · 2023-11-30T01:11:05.160Z

i’ve started seeing a puzzling runtime crash whenever i catch a NIOAsyncWriterError.alreadyFinished:

error: (HTTP/2) NIOAsyncWriterError.alreadyFinished

💣 Program crashed: Illegal instruction at 0x000055f1d8846c57

Thread 4 crashed:

0 0x000055f1d8846c57 NIOAsyncWriter.InternalClass.deinit + 55 in UnidocServer
1 0x00007f71c5c9c29b bool swift::RefCounts<swift::RefCountBitsT<(swift::RefCountInlinedness)1> >::doDecrementSlow<(swift::PerformDeinit)1>(swift::RefCountBitsT<(swift::RefCountInlinedness)1>, unsigned int) + 122 in libswiftCore.so
2 0x00007f71c5cbe7f0 void tuple_destroy<false, false>(swift::OpaqueValue*, swift::TargetMetadata<swift::InProcess> const*) + 47 in libswiftCore.so
3 0x00007f71c5c9c29b bool swift::RefCounts<swift::RefCountBitsT<(swift::RefCountInlinedness)1> >::doDecrementSlow<(swift::PerformDeinit)1>(swift::RefCountBitsT<(swift::RefCountInlinedness)1>, unsigned int) + 122 in libswiftCore.so
4 0x000055f1d866d713 objectdestroy.15Tm + 18 in UnidocServer
5 0x00007f71c5c9c29b bool swift::RefCounts<swift::RefCountBitsT<(swift::RefCountInlinedness)1> >::doDecrementSlow<(swift::PerformDeinit)1>(swift::RefCountBitsT<(swift::RefCountInlinedness)1>, unsigned int) + 122 in libswiftCore.so
6 0x00007f71c5c9c29b bool swift::RefCounts<swift::RefCountBitsT<(swift::RefCountInlinedness)1> >::doDecrementSlow<(swift::PerformDeinit)1>(swift::RefCountBitsT<(swift::RefCountInlinedness)1>, unsigned int) + 122 in libswiftCore.so
7 0x00007f71c610944d swift::runJobInEstablishedExecutorContext(swift::Job*) + 348 in libswift_Concurrency.so
8 0x00007f71c6109c7c swift_job_run + 91 in libswift_Concurrency.so

has anyone run into something similar?

taylorswift · 2023-11-30T02:05:20.968Z

okay, so something seems seriously wrong with NIOAsyncWriter’s internal state machine, because when i “sabotage” the response by ordering a manual call to finish,

writer.finish()
try await writer.send(message)

i see it is hitting the precondition failure in NIO:

debug: bound to :::8443
error: (HTTP/2) NIOAsyncWriterError.alreadyFinished
NIOCore/NIOAsyncWriter.swift:176: Fatal error: Deinited NIOAsyncWriter without calling finish()
Current stack trace:
0    libswiftCore.so                    0x00007fd8147f41c0 _swift_stdlib_reportFatalErrorInFile + 109
...

💣 Program crashed: Illegal instruction at 0x00007fd8144b8bf2

Thread 6 crashed:

.build/checkouts/swift-nio/Sources/NIOCore/AsyncSequences/NIOAsyncWriter.swift:176:17

   174│         deinit {
   175│             if !self._finishOnDeinit && !self._storage.isWriterFinished {
   176│                 preconditionFailure("Deinited NIOAsyncWriter without calling finish()")                                               
      │                 ▲
   177│             } else {
   178│                 // We need to call finish here to resume any suspended continuation.

this also happens if i exit NIOAsyncChannel.executeThenClose by returning instead of throwing:

writer.finish()
try? await writer.send(message)

in fact, any call to writer.finish() inside NIOAsyncChannel.executeThenClose crashes the application, even if i don’t send any message at all.

writer.finish()

if i do nothing at all and just return from the body of the closure, i also get the same crash.

try await stream.executeThenClose
{
    (
        remote:NIOAsyncChannelInboundStream<HTTP2Frame.FramePayload>,
        writer:NIOAsyncChannelOutboundWriter<HTTP2Frame.FramePayload>
    )   in
}

in fact, the only way i can avoid crashing is by successfully writing the entire sequence of HTTP2Frame.FramePayload before returning.

FranzBusch · 2023-11-30T11:10:48.963Z

I have just tried to reproduce this and written a small test and so far wasn't able to hit the precognition. Below is the test case that I wrote. Could you check for any difference in how you set this up?

    func test() async throws {
        guard #available(macOS 10.15, iOS 13.0, watchOS 6.0, tvOS 13.0, *) else { return }
        let serverChannel = try await ServerBootstrap(group: MultiThreadedEventLoopGroup.singleton).bind(
            host: "127.0.0.1",
            port: 0
        ) { channel in
            channel.eventLoop.makeCompletedFuture {
                try channel.pipeline.syncOperations.configureAsyncHTTP2Pipeline(mode: .server) { channel in
                    channel.eventLoop.makeCompletedFuture {
                        try NIOAsyncChannel<HTTP2Frame.FramePayload, HTTP2Frame.FramePayload>(wrappingChannelSynchronously: channel)
                    }
                }
            }
        }

        let clientMultiplexer = try await ClientBootstrap(group: MultiThreadedEventLoopGroup.singleton).connect(
            host: "127.0.0.1",
            port: serverChannel.channel.localAddress!.port!
        ) { channel in
            channel.eventLoop.makeCompletedFuture {
                try channel.pipeline.syncOperations.configureAsyncHTTP2Pipeline(mode: .client) { channel in
                    channel.eventLoop.makeCompletedFuture {
                        try NIOAsyncChannel<HTTP2Frame.FramePayload, HTTP2Frame.FramePayload>(wrappingChannelSynchronously: channel)
                    }
                }
            }
        }

        try await withThrowingTaskGroup(of: Void.self) { group in
            group.addTask {
                let stream = try await clientMultiplexer.openStream { channel in
                    channel.eventLoop.makeCompletedFuture {
                        try NIOAsyncChannel<HTTP2Frame.FramePayload, HTTP2Frame.FramePayload>(wrappingChannelSynchronously: channel)
                    }
                }

                try await stream.executeThenClose { inbound, outbound in
                    let headers = HTTP2Frame.FramePayload.headers(.init(headers: .basicRequestHeaders))
                    outbound.finish()
                    try await outbound.write(headers)
                }
            }

            try await serverChannel.executeThenClose { inbound in
                for try await multiplexer in inbound {
                    for try await stream in multiplexer.inbound {
                        try await stream.executeThenClose { inbound, outbound in
                            for try await payload in inbound {
                                print(payload)
                            }
                            outbound.finish()
                            try await outbound.write(.headers(.init(headers: .basicResponseHeaders)))
                        }
                    }
                }
            }

            try await group.next()
        }
    }

Are you by any chance re-wrapping the NIOAsyncChannelOutboundWriter into your own custom type and might deinit it by accident?

taylorswift · 2023-11-30T20:12:44.231Z

here is a small reproducer program:

import NIOCore
import NIOPosix
import NIOHTTP1
import NIOHPACK
import NIOHTTP2
import NIOSSL

final
class OutboundShimHandler
{
    init()
    {
    }
}
extension OutboundShimHandler:ChannelOutboundHandler
{
    typealias OutboundIn = HTTPPart<HTTPResponseHead, ByteBuffer>
    typealias OutboundOut = HTTPPart<HTTPResponseHead, IOData>

    func write(context:ChannelHandlerContext, data:NIOAny, promise:EventLoopPromise<Void>?)
    {
        let part:OutboundOut = switch self.unwrapOutboundIn(data)
        {
        case .head(let head):   .head(head)
        case .body(let body):   .body(.byteBuffer(body))
        case .end(let tail):    .end(tail)
        }

        context.write(self.wrapOutboundOut(part), promise: promise)
    }
}

func main() async throws
{
    let directory:String = "Local/Server/Certificates"
    let threads:MultiThreadedEventLoopGroup = .init(numberOfThreads: 2)
    let certificates:[NIOSSLCertificate] =
        try NIOSSLCertificate.fromPEMFile("\(directory)/fullchain.pem")

    let privateKey:NIOSSLPrivateKey =
        try .init(file: "\(directory)/privkey.pem", format: .pem)

    var configuration:TLSConfiguration = .makeServerConfiguration(
        certificateChain: certificates.map(NIOSSLCertificateSource.certificate(_:)),
        privateKey: .privateKey(privateKey))

        configuration.applicationProtocols = ["h2"]

    let niossl:NIOSSLContext = try .init(configuration: configuration)

    let bootstrap:ServerBootstrap = .init(group: threads)
        .serverChannelOption(ChannelOptions.backlog, value: 256)
        .serverChannelOption(ChannelOptions.socketOption(.so_reuseaddr), value: 1)
        .childChannelOption(ChannelOptions.socketOption(.so_reuseaddr), value: 1)
        .childChannelOption(ChannelOptions.maxMessagesPerRead, value: 1)

    let listener:
        NIOAsyncChannel<
            EventLoopFuture<NIONegotiatedHTTPVersion<
                NIOAsyncChannel<
                    HTTPPart<HTTPRequestHead, ByteBuffer>,
                    HTTPPart<HTTPResponseHead, ByteBuffer>>,
                (
                    NIOAsyncChannel<HTTP2Frame, HTTP2Frame>,
                    NIOHTTP2Handler.AsyncStreamMultiplexer<NIOAsyncChannel<
                        HTTP2Frame.FramePayload,
                        HTTP2Frame.FramePayload>>
                )>>,
            Never> = try await bootstrap.bind(
        host: "::",
        port: 8443)
    {
        (channel:any Channel) in

        channel.pipeline.addHandler(NIOSSLServerHandler.init(context: niossl))
            .flatMap
        {
            channel.configureAsyncHTTPServerPipeline
            {
                (connection:any Channel) in

                connection.eventLoop.makeCompletedFuture
                {
                    try connection.pipeline.syncOperations.addHandler(
                        OutboundShimHandler.init())

                    return try NIOAsyncChannel<
                        HTTPPart<HTTPRequestHead, ByteBuffer>,
                        HTTPPart<HTTPResponseHead, ByteBuffer>>.init(
                        wrappingChannelSynchronously: connection,
                        configuration: .init())
                }
            }
                http2ConnectionInitializer:
            {
                (connection:any Channel) in

                connection.eventLoop.makeCompletedFuture
                {
                    try NIOAsyncChannel<HTTP2Frame, HTTP2Frame>.init(
                        wrappingChannelSynchronously: connection,
                        configuration: .init())
                }
            }
                http2StreamInitializer:
            {
                (stream:any Channel) in

                stream.eventLoop.makeCompletedFuture
                {
                    try NIOAsyncChannel<
                        HTTP2Frame.FramePayload,
                        HTTP2Frame.FramePayload>.init(
                        wrappingChannelSynchronously: stream,
                        configuration: .init())
                }
            }
        }
    }

    try await listener.executeThenClose
    {
        for try await connection:EventLoopFuture<NIONegotiatedHTTPVersion<
            NIOAsyncChannel<
                HTTPPart<HTTPRequestHead, ByteBuffer>,
                HTTPPart<HTTPResponseHead, ByteBuffer>>,
            (
                NIOAsyncChannel<HTTP2Frame, HTTP2Frame>,
                NIOHTTP2Handler.AsyncStreamMultiplexer<NIOAsyncChannel<
                    HTTP2Frame.FramePayload,
                    HTTP2Frame.FramePayload>>
            )>> in $0
        {
            switch try await connection.get()
            {
            case .http1_1(let connection):
                try await connection.channel.close()

            case .http2((let connection, let streams)):
                do
                {
                    for try await stream:NIOAsyncChannel<
                        HTTP2Frame.FramePayload,
                        HTTP2Frame.FramePayload> in streams.inbound
                    {
                        try await stream.executeThenClose
                        {
                            (_, _) in
                        }
                    }
                }
                catch let error
                {
                    print(error)
                }

                try await connection.channel.close()
            }
        }
    }
}

try await main()

the easiest way to run it is probably pasting it into an SPM snippet.

you’ll need TLS certificates to get this running, you can generate your own in the directory referenced from the snippet (Local/Server/Certificates), or you can use these dummy localhost certificates:

fullchain.pem

privkey.pem

to cause the crash, run the snippet and navigate to https://localhost:8443.

$ swift run NIOCrash
Building for debugging...
[6/6] Linking NIOCrash
Build complete! (2.90s)
StreamClosed(streamID: HTTP2StreamID(15), errorCode: HTTP2ErrorCode<0x8 Cancel>, location: "NIOHTTP2/HTTP2StreamChannel.swift:865")
NIOCore/NIOAsyncWriter.swift:176: Fatal error: Deinited NIOAsyncWriter without calling finish()
Current stack trace:
0    libswiftCore.so                    0x00007f9b4291e1c0 _swift_stdlib_reportFatalErrorInFile + 109
1    libswiftCore.so                    0x00007f9b425e3d05 <unavailable> + 1461509
2    libswiftCore.so                    0x00007f9b425e3b27 <unavailable> + 1461031
3    libswiftCore.so                    0x00007f9b425e2a90 _assertionFailure(_:_:file:line:flags:) + 342
4    NIOCrash                           0x000055a105b25b28 <unavailable> + 10144552
5    NIOCrash                           0x000055a105b2613d <unavailable> + 10146109
6    libswiftCore.so                    0x00007f9b428878e0 <unavailable> + 4229344
7    libswiftCore.so                    0x00007f9b4288829b <unavailable> + 4231835
8    NIOCrash                           0x000055a105b122a5 <unavailable> + 10064549
9    libswiftCore.so                    0x00007f9b428aa7f0 <unavailable> + 4372464
10   NIOCrash                           0x000055a105e87d4a <unavailable> + 13692234
11   NIOCrash                           0x000055a105c3a76a <unavailable> + 11278186
12   NIOCrash                           0x000055a105c34164 <unavailable> + 11252068
13   NIOCrash                           0x000055a105c347f5 <unavailable> + 11253749
14   libswiftCore.so                    0x00007f9b428878e0 <unavailable> + 4229344
15   libswiftCore.so                    0x00007f9b4288829b <unavailable> + 4231835
16   NIOCrash                           0x000055a105c8d8e0 <unavailable> + 11618528
17   libswift_Concurrency.so            0x00007f9b42cb244d <unavailable> + 300109
18   libswift_Concurrency.so            0x00007f9b42cb2c20 swift_job_run + 92
19   libdispatch.so                     0x00007f9b41f2df89 <unavailable> + 176009
20   libdispatch.so                     0x00007f9b41f2dd9f <unavailable> + 175519
21   libdispatch.so                     0x00007f9b41f38dc6 <unavailable> + 220614
22   libpthread.so.0                    0x00007f9b4111644b <unavailable> + 29771
23   libc.so.6                          0x00007f9b404b24f0 clone + 63

💣 Program crashed: Illegal instruction at 0x00007f9b425e2bf2

Thread 1 crashed:

 0 0x00007f9b425e2bf2 _assertionFailure(_:_:file:line:flags:) + 354 in libswiftCore.so
 1 NIOAsyncWriter.InternalClass.deinit + 247 in NIOCrash at /swift/swift-unidoc/.build/checkouts/swift-nio/Sources/NIOCore/AsyncSequences/NIOAsyncWriter.swift:176:17

   174│         deinit {
   175│             if !self._finishOnDeinit && !self._storage.isWriterFinished {
   176│                 preconditionFailure("Deinited NIOAsyncWriter without calling finish()")                                               
      │                 ▲
   177│             } else {
   178│                 // We need to call finish here to resume any suspended continuation.

 2 0x00007f9b428878e0 _swift_release_dealloc + 15 in libswiftCore.so
 3 0x00007f9b4288829b bool swift::RefCounts<swift::RefCountBitsT<(swift::RefCountInlinedness)1> >::doDecrementSlow<(swift::PerformDeinit)1>(swift::RefCountBitsT<(swift::RefCountInlinedness)1>, unsigned int) + 122 in libswiftCore.so
 4 0x00007f9b428aa7f0 void tuple_destroy<false, false>(swift::OpaqueValue*, swift::TargetMetadata<swift::InProcess> const*) + 47 in libswiftCore.so
 5 EventLoopFuture.deinit + 163 in NIOCrash at /swift/swift-unidoc/.build/checkouts/swift-nio/Sources/NIOCore/EventLoopFuture.swift:431:5

   429│             }
   430│         }
   431│     }                                                                                                                                 
      │    ▲
   432│ }
   433│

 6 0x00007f9b428878e0 _swift_release_dealloc + 15 in libswiftCore.so
 7 0x00007f9b4288829b bool swift::RefCounts<swift::RefCountBitsT<(swift::RefCountInlinedness)1> >::doDecrementSlow<(swift::PerformDeinit)1>(swift::RefCountBitsT<(swift::RefCountInlinedness)1>, unsigned int) + 122 in libswiftCore.so
 8 closure #2 in main() + 159 in NIOCrash at /swift/swift-unidoc/Snippets/NIOCrash.swift:159:9

   157│                 try await connection.channel.close()
   158│             }
   159│         }                                                                                                                             
      │        ▲
   160│     }
   161│ }

 9 closure #1 in NIOAsyncChannel.executeThenClose<A>(_:) in NIOCrash at /swift/swift-unidoc/.build/checkouts/swift-nio/Sources/NIOCore/AsyncChannel/AsyncChannel.swift:303

   301│     ) async throws -> Result where Outbound == Never {
   302│         try await self.executeThenClose { inbound, _ in
   303│             try await body(inbound)                                                                                                   
      │             ▲
   304│         }
   305│     }

10 NIOAsyncChannel.executeThenClose<A>(_:) in NIOCrash at /swift/swift-unidoc/.build/checkouts/swift-nio/Sources/NIOCore/AsyncChannel/AsyncChannel.swift:271

   269│         let result: Result
   270│         do {
   271│             result = try await body(self._inbound, self._outbound)                                                                    
      │             ▲
   272│         } catch let bodyError {
   273│             do {

11 NIOAsyncChannel.executeThenClose<A>(_:) in NIOCrash at /swift/swift-unidoc/.build/checkouts/swift-nio/Sources/NIOCore/AsyncChannel/AsyncChannel.swift:302

   300│         _ body: (_ inbound: NIOAsyncChannelInboundStream<Inbound>) async throws -> Result
   301│     ) async throws -> Result where Outbound == Never {
   302│         try await self.executeThenClose { inbound, _ in                                                                               
      │         ▲
   303│             try await body(inbound)
   304│         }

12 main() in NIOCrash at /swift/swift-unidoc/Snippets/NIOCrash.swift:121

   119│     }
   120│ 
   121│     try await listener.executeThenClose                                                                                               
      │     ▲
   122│     {
   123│         for try await connection:EventLoopFuture<NIONegotiatedHTTPVersion<

Illegal instruction (core dumped)

taylorswift · 2023-11-30T21:38:17.929Z

i currently have no reason to believe these two issues are connected (particularly because i don’t think NIO has adopted the new 5.9 ownership specifiers yet), but one possible symptom of a compiler bug i just isolated could be the swift runtime calling deinit prematurely.

FranzBusch · 2023-11-30T22:29:16.090Z

Just from taking a Quick Look you are just dropping the NIOAsyncChannel for the http1 connection and http2 connection on the ground. You only consume the channels of the http2 streams. This might be the reason for the deinit preconditions.
I will run your reproducer tomorrow.

taylorswift · 2023-11-30T22:41:23.097Z

i’m not sure what you mean by “dropping the connection on the ground”, as i am just closing the HTTP/1 connection instantly, which i feel like, should be able to close the connection without crashing?

FranzBusch · 2023-11-30T22:48:00.829Z

I didn’t say you drop the connection on the ground but rather the NIOAsyncChannel. In fact it looks like you wrap those channels into NIOAsyncChannels but never use them. That’s most likely the problem here.
You don’t have to necessarily do anything with those channels, you can just not wrap them and return the bare Channel from the initializer closures.

taylorswift · 2023-11-30T23:06:58.857Z

FranzBusch:

In fact it looks like you wrap those channels into NIOAsyncChannels but never use them. That’s most likely the problem here.

thanks, as it turns out, in the original code base i also am never using the HTTP/2 connection-level NIOAsyncChannel, i am only ever using the NIOHTTP2Handler.AsyncStreamMultiplexer from the second tuple element.

(although, i don’t think creating an unused NIOAsyncChannel should end in a crash. the individual stream channels could also end up never being used, due to task cancellation.)

FranzBusch:

You don’t have to necessarily do anything with those channels, you can just not wrap them and return the bare Channel from the initializer closures.

i was cargo-culting the examples from when the new APIs were released, and when i did as you suggested the crash stopped occurring regardless of any writer.finish() calls on the streams. thanks!

am i correct in understanding that failing to perform any operations on a NIOAsyncChannel before deiniting it results in a crash? should i always be performing a ceremonial read/write on the NIOAsyncChannelInboundStream/NIOAsyncChannelOutboundWriter before exiting a scope that takes one as a parameter? how does this interact with task cancellation?

taylorswift · 2024-03-05T23:01:35.062Z

i suddenly ran into a bunch of occurrences of this crash in another one of our server applications today, and almost started a new thread before discourse reminded me i had already seen this before.

i understand this is “user error” and i probably made a mistake sometime earlier this week. but have a hard time understanding why ostensibly “safe” usages of this API can result in such a violent outcome. every crash has a non-trivial probability of setting off a node-wide cascade failure due to high resource requirements of swift backtracing and i am fortunate to have noticed this problem before it took the whole machine offline.

*** Signal 4: Backtracing from 0x55a89ce4e371...
 done ***
*** Program crashed: Illegal instruction at 0x000055a89ce4e371 ***
Thread 0 "app":
0  0x00007f955445508a sigsuspend + 74 in libc.so.6
Thread 1:
0  0x00007f955449c38a __futex_abstimed_wait_common + 202 in libc.so.6
Thread 2:
0  0x00007f955454e87e epoll_wait + 94 in libc.so.6
Thread 3 "NIO-ELT-0-#0" crashed:
 0                         0x000055a89ce4e371 NIOAsyncWriter.InternalClass.deinit + 65 in app
 1 [ra] [system]           0x000055a89ce4de09 NIOAsyncWriter.InternalClass.__deallocating_deinit + 8 in app at .build/checkouts/swift-nio/Sources/NIOCore/AsyncSequences/NIOAsyncWriter.swift
 2 [ra]                    0x00007f9554e082c0 _swift_release_dealloc + 15 in libswiftCore.so
 3 [ra]                    0x00007f9554e08c7b bool swift::RefCounts<swift::RefCountBitsT<(swift::RefCountInlinedness)1> >::doDecrementSlow<(swift::PerformDeinit)1>(swift::RefCountBitsT<(swift::RefCountInlinedness)1>, unsigned int) + 122 in libswiftCore.so
 4 [ra]                    0x00007f9554e0910b (anonymous namespace)::destroyGenericBox(swift::HeapObject*) + 26 in libswiftCore.so
 5 [ra]                    0x00007f9554e082c0 _swift_release_dealloc + 15 in libswiftCore.so
 6 [ra]                    0x00007f9554e08c7b bool swift::RefCounts<swift::RefCountBitsT<(swift::RefCountInlinedness)1> >::doDecrementSlow<(swift::PerformDeinit)1>(swift::RefCountBitsT<(swift::RefCountInlinedness)1>, unsigned int) + 122 in libswiftCore.so
 7 [ra] [system]           0x000055a89ceab6a0 EventLoopFuture.deinit + 79 in app at <compiler-generated>
 8 [ra] [system]           0x000055a89ceab6e9 EventLoopFuture.__deallocating_deinit + 8 in app at .build/checkouts/swift-nio/Sources/NIOCore/EventLoopFuture.swift
 9 [ra]                    0x00007f9554e082c0 _swift_release_dealloc + 15 in libswiftCore.so
10 [ra]                    0x00007f9554e08c7b bool swift::RefCounts<swift::RefCountBitsT<(swift::RefCountInlinedness)1> >::doDecrementSlow<(swift::PerformDeinit)1>(swift::RefCountBitsT<(swift::RefCountInlinedness)1>, unsigned int) + 122 in libswiftCore.so
11 [ra] [system]           0x000055a89cfa3338 HTTP2CommonInboundStreamMultiplexer.receivedFrame(_:context:multiplexer:) + 2679 in app at <compiler-generated>
12 [ra] [inlined]          0x000055a89cf91165 InlineStreamMultiplexer.receivedFrame(_:) in app at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2ChannelHandler+InlineStreamMultiplexer.swift:46:39
13 [ra]                    0x000055a89cf91165 NIOHTTP2Handler.InboundStreamMultiplexer.receivedFrame(_:) + 164 in app at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2ChannelHandler+InboundStreamMultiplexer.swift:52:41
14 [ra]                    0x000055a89cf98d8b NIOHTTP2Handler.processFrame(_:flowControlledLength:context:) + 4586 in app at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2ChannelHandler.swift:584:44
15 [ra] [inlined]          0x000055a89cf95419 NIOHTTP2Handler.frameDecodeLoop(context:) in app at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2ChannelHandler.swift:479:41
16 [ra]                    0x000055a89cf95419 NIOHTTP2Handler.channelRead(context:data:) + 264 in app at .build/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2ChannelHandler.swift:439:14
17 [ra]                    0x000055a89ce8dff6 ChannelHandlerContext.invokeChannelRead(_:) + 37 in app at .build/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1696:28
18 [ra]                    0x000055a89ce8b303 ChannelHandlerContext.fireChannelRead(_:) + 34 in app at .build/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1509:20
19 [ra] [inlined]          0x000055a89d08315b NIOSSLHandler.doFlushReadData(context:receiveBuffer:readOnEmptyBuffer:) in app at .build/checkouts/swift-nio-ssl/Sources/NIOSSL/NIOSSLHandler.swift:654:21
20 [ra]                    0x000055a89d08315b NIOSSLHandler.doDecodeData(context:) + 1306 in app at .build/checkouts/swift-nio-ssl/Sources/NIOSSL/NIOSSLHandler.swift:589:22
21 [ra]                    0x000055a89d080e21 NIOSSLHandler.channelRead(context:data:) + 240 in app at .build/checkouts/swift-nio-ssl/Sources/NIOSSL/NIOSSLHandler.swift:187:13
22 [ra]                    0x000055a89ce8dff6 ChannelHandlerContext.invokeChannelRead(_:) + 37 in app at .build/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1696:28
23 [ra] [inlined]          0x000055a89ce8ee2c ChannelPipeline.fireChannelRead0(_:) in app at .build/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:897:29
24 [ra]                    0x000055a89ce8ee2c ChannelPipeline.SynchronousOperations.fireChannelRead(_:) + 43 in app at .build/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1160:28
25 [ra]                    0x000055a89d003859 BaseStreamSocketChannel.readFromSocket() + 840 in app at .build/checkouts/swift-nio/Sources/NIOPosix/BaseStreamSocketChannel.swift:133:50
26 [ra]                    0x000055a89d05bcb0 specialized BaseSocketChannel.readable0() + 31 in app
27 [ra] [inlined]          0x000055a89d062e6a specialized BaseSocketChannel.readable() in app at .build/checkouts/swift-nio/Sources/NIOPosix/BaseSocketChannel.swift:1099:14
28 [ra] [inlined] [system] 0x000055a89d062e6a specialized protocol witness for SelectableChannel.readable() in conformance BaseSocketChannel<A> in app at <compiler-generated>:1096:23
29 [ra]                    0x000055a89d062e6a specialized SelectableEventLoop.handleEvent<A>(_:channel:) + 153 in app at .build/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:403:25
30 [ra] [inlined] [system] 0x000055a89d05e3f0 specialized SelectableEventLoop.handleEvent<A>(_:channel:) in app at <compiler-generated>
31 [ra]                    0x000055a89d05e3f0 closure #2 in closure #2 in SelectableEventLoop.run() + 159 in app at .build/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:478:30
32 [ra] [thunk]            0x000055a89d06634c partial apply for closure #2 in closure #2 in SelectableEventLoop.run() + 11 in app at <compiler-generated>
33 [ra]                    0x000055a89d05fae3 specialized Selector.whenReady0(strategy:onLoopBegin:_:) + 1090 in app at .build/checkouts/swift-nio/Sources/NIOPosix/SelectorEpoll.swift:252:25
34 [ra] [inlined]          0x000055a89d05c3ba specialized Selector.whenReady(strategy:onLoopBegin:_:) in app at .build/checkouts/swift-nio/Sources/NIOPosix/SelectorGeneric.swift:288:18
35 [ra]                    0x000055a89d05c3ba SelectableEventLoop.run() + 521 in app at .build/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:470:36
36 [ra] [inlined]          0x000055a89d0353c3 static MultiThreadedEventLoopGroup.runTheLoop(thread:parentGroup:canEventLoopBeShutdownIndividually:selectorFactory:initializer:_:) in app at .build/checkouts/swift-nio/Sources/NIOPosix/MultiThreadedEventLoopGroup.swift:93:22
37 [ra]                    0x000055a89d0353c3 closure #1 in static MultiThreadedEventLoopGroup.setupThreadAndEventLoop(name:parentGroup:selectorFactory:initializer:) + 322 in app at .build/checkouts/swift-nio/Sources/NIOPosix/MultiThreadedEventLoopGroup.swift:111:41
38 [ra] [thunk]            0x000055a89d0389da partial apply for closure #1 in static MultiThreadedEventLoopGroup.setupThreadAndEventLoop(name:parentGroup:selectorFactory:initializer:) + 41 in app at <compiler-generated>
39 [ra] [thunk]            0x000055a89d03aeff thunk for @escaping @callee_guaranteed (@guaranteed NIOThread) -> () + 14 in app at <compiler-generated>
40 [ra]                    0x000055a89d0783cd closure #1 in static ThreadOpsPosix.run(handle:args:detachThread:) + 380 in app at .build/checkouts/swift-nio/Sources/NIOPosix/ThreadPosix.swift:116:13
Thread 4 "NIO-ELT-0-#1":
0                0x00007f955454e87e epoll_wait + 94 in libc.so.6
1 [ra] [system]  0x000055a89d05f911 specialized Selector.whenReady0(strategy:onLoopBegin:_:) + 624 in app at <compiler-generated>
2 [ra] [inlined] 0x000055a89d05c3ba specialized Selector.whenReady(strategy:onLoopBegin:_:) in app at .build/checkouts/swift-nio/Sources/NIOPosix/SelectorGeneric.swift:288:18
3 [ra]           0x000055a89d05c3ba SelectableEventLoop.run() + 521 in app at .build/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:470:36
4 [ra] [inlined] 0x000055a89d0353c3 static MultiThreadedEventLoopGroup.runTheLoop(thread:parentGroup:canEventLoopBeShutdownIndividually:selectorFactory:initializer:_:) in app at .build/checkouts/swift-nio/Sources/NIOPosix/MultiThreadedEventLoopGroup.swift:93:22
5 [ra]           0x000055a89d0353c3 closure #1 in static MultiThreadedEventLoopGroup.setupThreadAndEventLoop(name:parentGroup:selectorFactory:initializer:) + 322 in app at .build/checkouts/swift-nio/Sources/NIOPosix/MultiThreadedEventLoopGroup.swift:111:41
6 [ra] [thunk]   0x000055a89d0389da partial apply for closure #1 in static MultiThreadedEventLoopGroup.setupThreadAndEventLoop(name:parentGroup:selectorFactory:initializer:) + 41 in app at <compiler-generated>
7 [ra] [thunk]   0x000055a89d03aeff thunk for @escaping @callee_guaranteed (@guaranteed NIOThread) -> () + 14 in app at <compiler-generated>
8 [ra]           0x000055a89d0783cd closure #1 in static ThreadOpsPosix.run(handle:args:detachThread:) + 380 in app at .build/checkouts/swift-nio/Sources/NIOPosix/ThreadPosix.swift:116:13
Thread 5 "NIO-ELT-0-#1":
0  0x00007f955449c38a __futex_abstimed_wait_common + 202 in libc.so.6
Registers:
rax 0x0000000000000000  0
rdx 0x00007f954f4a6420  70 3f ef 50 95 7f 00 00 03 00 00 00 01 00 00 00  p?ïP············
rcx 0xfffffffe00000000  18446744065119617024
rbx 0x0000000000000001  1
rsi 0x00007f9550dca550  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ················
rdi 0x0000000000000000  0
rbp 0x00007f95523fa570  80 a5 3f 52 95 7f 00 00 09 de e4 9c a8 55 00 00  ·¥?R·····Þä·¨U··
rsp 0x00007f95523fa550  70 3f ef 50 95 7f 00 00 38 42 ef 50 95 7f 00 00  p?ïP····8BïP····
 r8 0x0000000000000010  16
 r9 0x000000000ff2aa1f  267561503
r10 0x00007f9550fbbad8  08 96 f8 9d a8 55 00 00 80 b9 fb 50 95 7f 00 00  ··ø·¨U···¹ûP····
r11 0x0000000000000000  0
r12 0x00007f9553c49280  c0 91 fe 9d a8 55 00 00 03 00 00 00 04 00 00 00  À·þ·¨U··········
r13 0x00007f9553c620c0  38 ba fb 50 95 7f 00 00 03 00 00 00 02 00 00 00  8ºûP············
r14 0x000055a89ce4dbf0  55 48 89 e5 41 57 41 56 41 55 41 54 53 48 81 ec  UH·åAWAVAUATSH·ì
r15 0x00007f9553c4cca0  70 ab fb 50 95 7f 00 00 03 00 00 00 01 00 00 00  p«ûP············
rip 0x000055a89ce4e371  0f 0b 66 66 66 66 2e 0f 1f 84 00 00 00 00 00 55  ··ffff.········U
rflags 0x0000000000010246  ZF PF
cs 0x0033  fs 0x0000  gs 0x0000
Images (12 omitted):
0x000055a89c7f8000–0x000055a89d9689a9 <no build ID>                            app       /home/ec2-user/bin/app
0x00007f9554400000–0x00007f955459c05c 30448f508336fb6b11d92bcff7f65c300f3e68e1 libc.so.6       /usr/lib64/libc.so.6
0x00007f9554a00000–0x00007f9554f47048 <no build ID>                            libswiftCore.so /usr/lib/swift/linux/libswiftCore.so
Backtrace took 18.13s

taylorswift · 2024-03-06T00:19:47.124Z

after some investigation, i believe this is happening because we began buffering incoming HTTP/2 streams in an AsyncThrowingStream. this has a really nasty interaction with task cancellation, because based on @FranzBusch ’s answer earlier, if these incoming streams do not get served, they crash the application.

it’s not clear to me how to refactor the application so that we never accept incoming streams that eventually get aborted, as NIOHTTP2AsyncSequence has no backpressure, and as a security policy, the server cannot guarantee that every incoming stream in the buffer will be processed.

as far as i understand it, the most sensible solution is to just allow discarding buffered NIOAsyncChannels without serving them.

lukasa · 2024-03-06T10:32:39.031Z

Yeah, this is an area we have some active desire to resolve.

The issue isn't so much the lack of backpressure as it is the fact that dropping an async sequence that contains NIOAsyncChannels is almost always going to lead to a crash, unless that async sequence is specifically designed to handle NIOAsyncChannels. That's because the sequence buffer is at risk of holding the NIOAsyncChannel when it is deinited, which will trigger deinit of the channel and this crash.

In the very short term, a solution that you can adopt is to wrap the NIOAsyncChannel into a class that, on-deinit, invokes the shutdown methods. This essentially restores the deinit-based cleanup for NIOAsyncChannel while it's inside the async sequence. You can then unwrap it on the other side.

In the longer term, we need to reconstruct how we pass NIOAsyncChannel objects around. The current thinking is that we'll need to replace the existing Bootstraps, and the existing HTTP/2 multiplexing API, to provide one that doesn't have this risk of being incorrectly held.

taylorswift · 2024-03-06T20:33:45.329Z

lukasa:

In the very short term, a solution that you can adopt is to wrap the NIOAsyncChannel into a class that, on-deinit, invokes the shutdown methods. This essentially restores the deinit-based cleanup for NIOAsyncChannel while it's inside the async sequence. You can then unwrap it on the other side.

right, um this might be a silly question, but what are those shutdown methods? do you mean making a perfunctory call to executeThenClose?

adam-fowler · 2024-03-06T20:49:10.603Z

Calling executeThenClose with an empty closure was what I ended up doing.

lukasa · 2024-03-07T10:11:08.596Z

executeThenClose is the safest way, yes. You could also individually close the various parts of the NIOAsyncChannel, by calling finish on the outbound writer and close on the channel itself. That's going to be less resilient to future API changes though.