Python/Core: Regression in `grpcio`, error parsing of content-type metadata #35323

fg91 · 2023-12-15T14:44:19Z

What version of gRPC and what language are you using?

For these grpcio (python) versions (client side), the problem described below appears or doesn't appear:

1.53.0 works
1.53.1 works
1.53.2 works
1.54.0 works
1.54.2 works
1.54.3 works
1.55.3 doesn't work (prior 1.55 versions have been yanked)
1.56.0 works
1.56.2 doesn't work
1.57.0 doesn't work
1.58.0 doesn't work
1.59.0 doesn't work
1.60.0 doesn't work

What operating system (Linux, Windows,...) and version?

Mac or Linux (client)
Linux (server)

What runtime / compiler are you using (e.g. python version or version of gcc)

Python 3.10.7 (also tested with 3.9)

What did you do?

Our python client library makes calls to a gRPC backend deployed behind a GCP load balancer (GCE Ingress on GKE) with GCP Identity Aware Proxy (IAP) enabled. The client authenticates lazily in the sense that it first tries an unauthenticated request/request with cached credentials and if this doesn't work, refreshes credentials and tries again:

class AuthUnaryInterceptor(grpc.UnaryUnaryClientInterceptor):
    ...
    def intercept_unary_unary(...):
        """
        Intercepts unary calls and adds auth metadata if available. On Unauthenticated, resets the token
        and refreshes and then retries with the new token.
        """
        updated_call_details = self._call_details_with_auth_metadata(client_call_details)
        fut: grpc.Future = continuation(updated_call_details, request)
        e = fut.exception()
        if e:
            if e.code() == grpc.StatusCode.UNAUTHENTICATED or e.code() == grpc.StatusCode.UNKNOWN:
                self._authenticator.refresh_credentials()
                updated_call_details = self._call_details_with_auth_metadata(client_call_details)
                return continuation(updated_call_details, request)
        return fut

For newer versions of grpcio, the rpc fails even though the lazy authentication works and the server responds with "the right payload".

Minimal working example

We condensed the relevant logic from the client library into this example greeter client:

Click me

import os
import typing
import grpc
import ssl
from collections import namedtuple

import greeting_pb2
import greeting_pb2_grpc

def bootstrap_creds_from_server(endpoint: str) -> grpc.ChannelCredentials:
    """
    Retrieves the SSL cert from the remote and uses that.
    """
    # Get port from endpoint or use 443
    endpoint_parts = endpoint.rsplit(":", 1)
    if len(endpoint_parts) == 2 and endpoint_parts[1].isdigit():
        server_address = (endpoint_parts[0], endpoint_parts[1])
    else:
        server_address = (endpoint, "443")
    cert = ssl.get_server_certificate(server_address)  # noqa
    return grpc.ssl_channel_credentials(str.encode(cert))


class Authenticator(object):
    def __init__(
        self,
        header_key: str,
    ):
        self._token = None
        self._header_key = header_key if header_key else "authorization"

    def fetch_grpc_call_auth_metadata(self) -> typing.Optional[typing.Tuple[str, str]]:
        if self._token:
            return self._header_key, f"Bearer {self._token}"
        return None

    def refresh_credentials(self):
        token = os.environ.get("TOKEN")
        if not token:
            raise Exception("No token found")
        self._token = token


class _ClientCallDetails(
    namedtuple("_ClientCallDetails", ("method", "timeout", "metadata", "credentials")),
    grpc.ClientCallDetails,
):
    """Wrapper class for initializing a new ClientCallDetails instance."""

    pass


class AuthUnaryInterceptor(grpc.UnaryUnaryClientInterceptor):
    """
    This Interceptor can be used to automatically add Auth Metadata for every call - lazily in case authentication
    is needed.
    """

    def __init__(self, authenticator: Authenticator):
        self._authenticator = authenticator

    def _call_details_with_auth_metadata(
        self, client_call_details: grpc.ClientCallDetails
    ) -> grpc.ClientCallDetails:
        """
        Returns new ClientCallDetails with metadata added.
        """
        metadata = client_call_details.metadata
        auth_metadata = self._authenticator.fetch_grpc_call_auth_metadata()
        if auth_metadata:
            metadata = []
            if client_call_details.metadata:
                metadata.extend(list(client_call_details.metadata))
            metadata.append(auth_metadata)

        return _ClientCallDetails(
            client_call_details.method,
            client_call_details.timeout,
            metadata,
            client_call_details.credentials,
        )

    def intercept_unary_unary(
        self,
        continuation: typing.Callable,
        client_call_details: grpc.ClientCallDetails,
        request: typing.Any,
    ):
        """
        Intercepts unary calls and adds auth metadata if available. On Unauthenticated, resets the token and refreshes
        and then retries with the new token
        """
        # self._authenticator.refresh_credentials()

        updated_call_details = self._call_details_with_auth_metadata(
            client_call_details
        )
        fut: grpc.Future = continuation(updated_call_details, request)
        e = fut.exception()
        if e:
            if (
                e.code() == grpc.StatusCode.UNAUTHENTICATED
                or e.code() == grpc.StatusCode.UNKNOWN
            ):
                self._authenticator.refresh_credentials()
                updated_call_details = self._call_details_with_auth_metadata(
                    client_call_details
                )
                return continuation(updated_call_details, request)
        return fut


 def upgrade_channel_to_proxy_authenticated(in_channel: grpc.Channel) -> grpc.Channel:
    return grpc.intercept_channel(
        in_channel,
        AuthUnaryInterceptor(Authenticator(header_key="proxy-authorization")),
    )


def get_channel(endpoint):
    credentials = bootstrap_creds_from_server(endpoint)

    return upgrade_channel_to_proxy_authenticated(
        grpc.secure_channel(target=endpoint, credentials=credentials)
    )


if __name__ == "__main__":
    endpoint = "<fill in>.com:443"

    stub = greeting_pb2_grpc.GreeterStub(get_channel(endpoint))

    response = stub.greet(greeting_pb2.ClientInput(name="Client", greeting="Hi"))
    print("Greeter client received following from server: " + response.message)

What did you expect to see?

~ TOKEN=eyJh... python client.py
Greeter client received following from server: Hi Client!

What did you see instead?

With a working version, e.g. grpcio==1.53.0:

E1215 14:41:40.919736000 4303291776 hpack_parser.cc:853]               Error parsing metadata: error=invalid value key=content-type value=text/html; charset=UTF-8
Greeter client received following from server: Hi Client!

With a non-working version, e.g. grpcio==1.60.0:

E1215 14:42:40.210358000 4348839296 hpack_parser.cc:999]               Error parsing 'content-type' metadata: invalid value
Traceback (most recent call last):
  File "client.py", line 134, in <module>
    response = stub.greet(greeting_pb2.ClientInput(name="Client", greeting="Hi"))
  File "python3.10/site-packages/grpc/_interceptor.py", line 277, in __call__
    response, ignored_call = self._with_call(
  File "python3.10/site-packages/grpc/_interceptor.py", line 332, in _with_call
    return call.result(), call
  File "python3.10/site-packages/grpc/_channel.py", line 437, in result
    raise self
  File "python3.10/site-packages/grpc/_interceptor.py", line 315, in continuation
    response, call = self._thunk(new_method).with_call(
  File "python3.10/site-packages/grpc/_channel.py", line 1177, in with_call
    return _end_unary_response_blocking(state, call, True, None)
  File "python3.10/site-packages/grpc/_channel.py", line 1003, in _end_unary_response_blocking
    raise _InactiveRpcError(state)  # pytype: disable=not-instantiable
grpc._channel._InactiveRpcError: <_InactiveRpcError of RPC that terminated with:
        status = StatusCode.UNKNOWN
        details = "Stream removed"
        debug_error_string = "UNKNOWN:Error received from peer  {created_time:"2023-12-15T14:42:40.385259+01:00", grpc_status:2, grpc_message:"Stream removed"}"
>

What we have discovered so far

1. Wrong content type of response

When unauthenticated, GCP IAP returns content-type text/html. This happens even if one includes ("accept", "application/grpc") headers (which we omitted in the minimal example as it doesn't help).

See screenshots from developer console showing this

Authenticated request:

Unauthenticated request:

2. Lazy authentication actually always successful!

With GRPC_VERBOSITY=debug GRPC_TRACE=all we have figured out that the lazy authentication actually always works and even if the rpc ultimately fails, e.g. with grpcio==1.60.0, the server actually returns the correct payload (including "Hi Client").

Requests/responses for `grpcio==1.53.0`

First request, without token

Request:

 --metadata--
HTTP:0:HDR:CLI:user-agent: grpc-python/1.53.0 grpc-c/30.1.0 (linux; chttp2)
HTTP:0:HDR:CLI::authority: MY_DOMAIN:443
HTTP:0:HDR:CLI::path: /Greeter/greet
HTTP:0:HDR:CLI:WaitForReady: false
HTTP:0:HDR:CLI:grpc-accept-encoding: identity, deflate, gzip
HTTP:0:HDR:CLI:te: trailers
HTTP:0:HDR:CLI:content-type: application/grpc
HTTP:0:HDR:CLI::scheme: https
HTTP:0:HDR:CLI::method: POST
--metadata--

Response:

INCOMING[0x56457019b930;0x564570189020]: Parse 176b last frame fragment with header
HTTP:1:HDR:CLI: :status: 401
HTTP:1:HDR:CLI: content-length: 36
Error parsing metadata: error=invalid value key=content-type value=text/html; charset=UTF-8
HTTP:1:HDR:CLI: content-type: <discarded-invalid-value>
HTTP:1:HDR:CLI: x-goog-iap-generated-response: true
HTTP:1:HDR:CLI: grpc-message: Invalid IAP credentials: empty token
HTTP:1:HDR:CLI: grpc-status: 16
HTTP:1:HDR:CLI: date: Fri, 15 Dec 2023 10:21:17 GMT
HTTP:1:HDR:CLI: alt-svc: h3=":443"; ma=2592000,h3-29=":443"; ma=2592000
INCOMING[0x56457019b930]: DATA:END_STREAM len:36 id:0x00000001

Second request, with token

Request:

--metadata--
HTTP:0:HDR:CLI:user-agent: grpc-python/1.53.0 grpc-c/30.1.0 (linux; chttp2)
HTTP:0:HDR:CLI::authority: MY_DOMAIN:443
HTTP:0:HDR:CLI::path: /Greeter/greet
HTTP:0:HDR:CLI:WaitForReady: false
HTTP:0:HDR:CLI:te: trailers
HTTP:0:HDR:CLI:content-type: application/grpc
HTTP:0:HDR:CLI::scheme: https
HTTP:0:HDR:CLI::method: POST
HTTP:0:HDR:CLI:grpc-accept-encoding: identity, deflate, gzip
HTTP:0:HDR:CLI:proxy-authorization: Bearer 
--metadata--

Response:

READ DATA: DATA_BLOCK (redacted)
READ 0x5645701a48c0: 00 00 ... f3 '...Hi Client!...'
INCOMING[0x56457019b930]: HEADERS:END_HEADERS len:83 id:0x00000003
parsing initial_metadata
INCOMING[0x56457019b930;0x5645701bc860]: Parse 83b last frame fragment with header
HTTP:3:HDR:CLI: :status: 200
HTTP:3:HDR:CLI: content-type: application/grpc
HTTP:3:HDR:CLI: grpc-accept-encoding: identity, deflate, gzip
HTTP:3:HDR:CLI: date: Fri, 15 Dec 2023 10:21:17 GMT
HTTP:3:HDR:CLI: via: 1.1 google
HTTP:3:HDR:CLI: alt-svc: h3=":443"; ma=2592000,h3-29=":443"; ma=2592000
INCOMING[0x56457019b930]: DATA len:16 id:0x00000003

Requests/responses for `grpcio==1.60.0` which ultimately fails but still shows `"Hi Client"` in the response!

First request, without token

Request:

--metadata--
HTTP:0:HDR:CLI:user-agent: grpc-python/1.60.0 grpc-c/37.0.0 (linux; chttp2)
HTTP:0:HDR:CLI::authority: MY_DOMAIN:443
HTTP:0:HDR:CLI::path: /Greeter/greet
HTTP:0:HDR:CLI:GrpcRegisteredMethod: (nil)
HTTP:0:HDR:CLI:WaitForReady: false
HTTP:0:HDR:CLI:grpc-accept-encoding: identity, deflate, gzip
HTTP:0:HDR:CLI:te: trailers
HTTP:0:HDR:CLI:content-type: application/grpc
HTTP:0:HDR:CLI::scheme: https
HTTP:0:HDR:CLI::method: POST
--metadata--

Response:

HTTP:1:HDR:CLI: :status: 401
HTTP:1:HDR:CLI: content-length: 36
Error parsing 'content-type' metadata: invalid value
HTTP:1:HDR:CLI: content-type: <discarded-invalid-value> (parse error: INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0'])
HTTP:1:HDR:CLI: x-goog-iap-generated-response: true (parse error: INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0'])
HTTP:1:HDR:CLI: grpc-message: Invalid IAP credentials: empty token (parse error: INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0'])
HTTP:1:HDR:CLI: grpc-status: 16 (parse error: INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0'])
HTTP:1:HDR:CLI: date: Fri, 15 Dec 2023 10:24:42 GMT (parse error: INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0'])
HTTP:1:HDR:CLI: alt-svc: h3=":443"; ma=2592000,h3-29=":443"; ma=2592000 (parse error: INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0'])
INCOMING[0x55a82f6496e0;0x55a82f656fd0]: Parse failed with INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0']
MARK_STREAM_CLOSED: t=0x55a82f6496e0 s=0x55a82f656fd0(id=1) read+write [INTERNAL:Error parsing 'content-type' metadata {stream_id:0}]

Second request, with token

Request:

--metadata--
HTTP:0:HDR:CLI:user-agent: grpc-python/1.60.0 grpc-c/37.0.0 (linux; chttp2)
HTTP:0:HDR:CLI::authority: MY_DOMAIN:443
HTTP:0:HDR:CLI::path: /Greeter/greet
HTTP:0:HDR:CLI:GrpcRegisteredMethod: (nil)
HTTP:0:HDR:CLI:WaitForReady: false
HTTP:0:HDR:CLI:grpc-accept-encoding: identity, deflate, gzip
HTTP:0:HDR:CLI:te: trailers
HTTP:0:HDR:CLI:content-type: application/grpc
HTTP:0:HDR:CLI::scheme: https
HTTP:0:HDR:CLI::method: POST
HTTP:0:HDR:CLI:proxy-authorization: Bearer MY_BEARER_TOKEN
--metadata--

Response:

Notice the content-type: application/grpc, status: 200 and Hi Client!

READ DATA: 17 03 ... 9c '..q.' (redacted)
READ 0x55a82f64d020: 00 .... f2 '...Hi Client!..' (redacted)
INCOMING[0x55a82f6496e0]: HEADERS:END_HEADERS len:83 id:0x00000003
parsing initial_metadata
INCOMING[0x55a82f6496e0;0x55a82f661820]: Parse 83b last frame fragment with header
HTTP:3:HDR:CLI: :status: 200
HTTP:3:HDR:CLI: content-type: application/grpc
HTTP:3:HDR:CLI: grpc-accept-encoding: identity, deflate, gzip
HTTP:3:HDR:CLI: date: Fri, 15 Dec 2023 10:24:43 GMT
HTTP:3:HDR:CLI: via: 1.1 google
HTTP:3:HDR:CLI: alt-svc: h3=":443"; ma=2592000,h3-29=":443"; ma=2592000 (parse error: INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0'])
E1215 18:24:43.269780968  228678 parsing.cc:923]                       INCOMING[0x55a82f6496e0;0x55a82f661820]: Parse failed with INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0']
D1215 18:24:43.269791061  228678 chttp2_transport.cc:2428]             MARK_STREAM_CLOSED: t=0x55a82f6496e0 s=0x55a82f661820(id=3) read+write [INTERNAL:Error parsing 'content-type' metadata {stream_id:0}]

D1215 18:24:43.269876407  228678 hpack_parser.cc:705]                  HTTP:3:???:CLI: grpc-status: 0 (parse error: INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0'])
D1215 18:24:43.269882099  228678 hpack_parser.cc:705]                  HTTP:3:???:CLI: grpc-message:  (parse error: INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0'])

And we see it a couple of times after that:

D1215 18:24:43.269876407  228678 hpack_parser.cc:705]                  HTTP:3:???:CLI: grpc-status: 0 (parse error: INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0'])
D1215 18:24:43.269882099  228678 hpack_parser.cc:705]                  HTTP:3:???:CLI: grpc-message:  (parse error: INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0'])
E1215 18:24:43.269891987  228678 parsing.cc:923]                       INCOMING[0x55a82f6496e0;(nil)]: Parse failed with INTERNAL: Error parsing 'content-type' metadata [type.googleapis.com/grpc.status.int.stream_id='0']
I1215 18:24:43.269897544  228678 parsing.cc:338]                       INCOMING[0x55a82f6496e0]: PING len:8 id:0x00000000
D1215 18:24:43.269902634  228678 parsing.cc:911]                       INCOMING[0x55a82f6496e0;(nil)]: Parse 8b last frame fragment with ping
I1215 18:24:43.269907051  228678 frame_ping.cc:117]                    CLIENT[0x55a82f6496e0]: received ping 2f2
I1215 18:24:43.269912128  228678 tcp_posix.cc:679]                     TCP:0x55a82f522060 notify_on_read

We wonder why the rpc ultimately fails for grpc==1.60.0 even though the refreshing of the credentials works and the server responds with "Hi Client".

3. It works with e.g. `grpcio==1.60.0` if one never makes an unauthenticated request

If one never makes an unauthenticated request but refreshes credentials before the first call (by uncommenting the first # self._authenticator.refresh_credentials() in intercept_unary_unary), the rpc works for all versions.

Anything else we should know about your project / environment?

We would appreciate guidance in what to test/look for
We could share full log files (with redacted tokens, addresses, ...)
We could share the server code and K8s manifests for the deployment, ingress, IAP configuration
In a private channel we could share credentials with minimal permissions for our greeter example endpoint which we deployed in an isolated sandbox project.

Thank you!

The text was updated successfully, but these errors were encountered:

XuanWang-Amos · 2024-01-09T21:38:50Z

Hi, thanks providing such a detailed description. It will save us a significant amount of time if all issues have description like this!

I think this is the same issue with #33935 which you already commented.

Since it's impacting multiple users, I'll reopen that issue and follow up with core team for a fix.

XuanWang-Amos · 2024-01-09T21:42:14Z

Closing this one as duplicate, we can use the old issue to track the progress.

fg91 · 2024-01-10T08:53:52Z

Thank you for taking a look and reopening the original issue @XuanWang-Amos !

fg91 added kind/bug lang/Python priority/P2 labels Dec 15, 2023

fg91 assigned gnossen and XuanWang-Amos Dec 15, 2023

XuanWang-Amos closed this as completed Jan 9, 2024

fg91 mentioned this issue Jan 10, 2024

Python/Core: Error parsing http status code - 401 converted to UNKNOWN: Stream removed #33935

Closed

fg91 mentioned this issue Feb 2, 2024

Fix: Limit grpcio version in flytekit-identity-aware-proxy due to regression flyteorg/flytekit#2156

Merged

fg91 mentioned this issue Feb 23, 2024

Dep: Pin grpcio in flytekit-identity-aware-proxy to version that allo… flyteorg/flytekit#2212

Merged

fg91 mentioned this issue Apr 10, 2024

Title: grpc-status UNKNOWN instead of UNAUTHENTICATED when server responds with 401 but content-type is not application/grpc #36328

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Python/Core: Regression in `grpcio`, error parsing of content-type metadata #35323

Python/Core: Regression in `grpcio`, error parsing of content-type metadata #35323

fg91 commented Dec 15, 2023 •

edited

Loading

First request, without token

Second request, with token

First request, without token

Second request, with token

XuanWang-Amos commented Jan 9, 2024

XuanWang-Amos commented Jan 9, 2024

fg91 commented Jan 10, 2024

Python/Core: Regression in grpcio, error parsing of content-type metadata #35323

Python/Core: Regression in grpcio, error parsing of content-type metadata #35323

Comments

fg91 commented Dec 15, 2023 • edited Loading

What version of gRPC and what language are you using?

What operating system (Linux, Windows,...) and version?

What runtime / compiler are you using (e.g. python version or version of gcc)

What did you do?

Minimal working example

What did you expect to see?

What did you see instead?

What we have discovered so far

1. Wrong content type of response

2. Lazy authentication actually always successful!

First request, without token

Second request, with token

First request, without token

Second request, with token

3. It works with e.g. grpcio==1.60.0 if one never makes an unauthenticated request

Anything else we should know about your project / environment?

XuanWang-Amos commented Jan 9, 2024

XuanWang-Amos commented Jan 9, 2024

fg91 commented Jan 10, 2024

Python/Core: Regression in `grpcio`, error parsing of content-type metadata #35323

Python/Core: Regression in `grpcio`, error parsing of content-type metadata #35323

fg91 commented Dec 15, 2023 •

edited

Loading

3. It works with e.g. `grpcio==1.60.0` if one never makes an unauthenticated request