StreamClosed in sendMessage instead of Failure in Initial Metadata

[fabianmuecke]

Describe the bug

We make a ClientStreamingCall, to upload a file in chunks to our backends. There are conditions, where the backend will immediately report a failure in the initial metadata and close the stream. If we do not send anything, the backend won't deliver initial metadata, so we have to start sending the chunks.

However there is unexpected behavior in the sequence of events. Instead of the initial metadata stream reporting the failure, the first thing to happen is the sendMessage reporting a stream closed - although obviously the error response of the server happens before the stream is closed.

To reproduce

Steps to reproduce the bug you've found:

1. Make a ClientStreamingCall
2. Subscribe to initialMetadata
3. Start sending messages and make sure they're still being sent, when
4. The server responds with a failure in initialMetadata and
5. Closes the stream

Expected behaviour

I expect the server error in initialMetadata to be propagated before the StreamClosed error in sendMessage.

Additional information

I dug deeper and followed the trace back to processStateChange(_ stateChange: NIOHTTP2ConnectionStateChange?) NIOHTTP2Handler. This is called from processFrame(_ frame: HTTP2Frame, flowControlledLength: Int, context: ChannelHandlerContext) in the same class before processPendingUserEvents(context: ChannelHandlerContext) is called. The latter will propagate the server failure, while processStateChange will propagate the StreamClosed in failDroppedPromises.

I couldn't figure out a way to get the errors in the right order and consider this a bug, as the server error happens before the stream is closed, but is propagated after the StreamClosed error. I can't say, if this is a grpc-swift or a swift-nio-http2 bug, as it is just too deep inside, for me to be sure.

We're using:

    {
        "package": "grpc-swift",
        "repositoryURL": "https://github.com/grpc/grpc-swift",
        "state": {
          "branch": null,
          "revision": "593fe0fe931f7e838969243cd137be48e8055b1d",
          "version": "1.7.3"
        }
      },
    ...
     {
        "package": "swift-nio-http2",
        "repositoryURL": "https://github.com/apple/swift-nio-http2.git",
        "state": {
          "branch": null,
          "revision": "50c25c132b140e62b45e90b5a76f13ded02c8a46",
          "version": "1.20.1"
        }
      },

[Lukasa]

Interesting.

The "dropped promises" that are being failed here are the promises attached to the writes. These writes have not yet been sent. It is standard NIO practice to fail the writes before we notify about the channel being closed. However, we probably should send the read on first in HTTP/2. So I'm inclined to call this a swift-nio-http2 bug.

[Lukasa]

With that said, I don't know why grpc-swift is using the error on the write in preference to the one on the channel. @glbrntt any ideas?

[Lukasa]

Sorry, my analysis here is wrong. We can only have an ordering problem here if it is possible to receive a single frame that both closes a stream and carries data. But we can't: only RST_STREAM can close a stream unilaterally, and it can't carry data. DATA can only partway close a stream, and if it does close the stream then we could never have sent more data anyway, so we'd never fail any write promises.

[glbrntt]

hey @fabianmuecke,

I just want to double check I understand the situation here.

• You have a gRPC Swift client which creates a client streaming call
• You attach a callback to the initialMetadata future on that call
• You send a message on the request stream to the server
• Sometimes the server will reject the call. When it does this it will: modify the initial metadata to be returned and then close the stream with an error of some kind.

The issue as I understand it is that the callback on the initialMetadata is fired after the future for sending a message is completed.

---

It seems like the initial metadata sent by the server is going missing somewhere.

If the server is responding with just headers, then it could be that the client is just delivering the headers to trailingMetadata and failing the promise for initialMetadata when the stream is closed soon after. This, I think, ties in with what @Lukasa mentioned above:

It is standard NIO practice to fail the writes before we notify about the channel being closed. However, we probably should send the read on first in HTTP/2.

Could you check whether in this situation we receive the trailingMetadata on the call?

Also, are you using a gRPC Swift server here?

[fabianmuecke]

Yes, we do receive trailingMetadata in the end.
No, the server isn't using gRPC Swift. It's a C# Server, afaik.

This is what we receive, in the order we receive it:

requests error: StreamClosed(streamID: HTTP2StreamID(1), errorCode: HTTP2ErrorCode<0x0 No Error>, location: "[...]/SourcePackages/checkouts/swift-nio-http2/Sources/NIOHTTP2/HTTP2ChannelHandler.swift:530")
initial metadata: rpc(error: Networking.GRPCExecutor.RPCError(status: resource exhausted (8): 800_[...], trailingMetadata: nil, initialMetadata: nil))
trailing metadata: [([], ":status", "200"), ([], "server", "envoy"), ([], "date", "Tue, 07 Jun 2022 06:52:07 GMT"), ([], "content-type", "application/grpc"), ([non-indexable], "content-length", "0"), ([], "x-error-detail-code", "800_[...]"), ([], "grpc-status", "8"), ([], "grpc-message", "800_[...]")]

[glbrntt]

Great, thanks for that.

In this scenario when there's only one set of metadata, I think gRPC should be a bit more helpful by succeeding both the promise for the initial and for the trailing metadata.

With regards to the ordering, I think this still holds true:

These writes have not yet been sent. It is standard NIO practice to fail the writes before we notify about the channel being closed. However, we probably should send the read on first in HTTP/2. So I'm inclined to call this a swift-nio-http2 bug.

Do you agree @Lukasa?

[Lukasa]

Yes, I think that we should still fix that. In practice I don't think there is a real bug there, but it wouldn't hurt to clean this up anyway.