Istio transforming grpc requests in a way not supported by client?

[dmosesson]

Is this the right place to submit this?

• This is not a security vulnerability or a crashing bug
• This is not a question about how to use Istio

Bug Description

We are using a gRPC service that when the port name on the service is gRPC, the service gives an error saying: UNKNOWN:Error received from peer {grpc_message:"Missing :te header", grpc_status:2, created_time:"<current time>"}, but if we change the port name to tcp it works.

Version

client version: 1.21.0-rc.0
control plane version: 1.21.0-rc.0
data plane version: 1.20.1 (35 proxies), 1.21.0-rc.0 (72 proxies)

kubectl version
Client Version: v1.29.2
Server Version: v1.28.6+rke2r1

Additional Information

I cannot include the output of that command because the cluster is air-gapped. Key logs are:

Calling client error: UNKNOWN:Error received from peer {grpc_message:"Missing :te header", grpc_status:2, created_time:"<current time>"}
Calling istio-proxy log: [<Timestamp>] "POST /endpoint HTTP/2" 200 - via_upstream - "-" 5 0 112 111 "-" "grpc-python/1.60.0 grpc-c/37.0.0 (linux; chttp2)" "<uuid>" "<destination service> <destination pod ip>:3030" outbound|3030||<fqdn of destination service> <caller ip>:48238 <destination service ip> - default
Destination pod application log: everything normal
attempted with Istio-proxy both enabled and disabled on the destination, getting the same error. If istio-proxy is enabled, it shows a 200 as well, same as the calling istio proxy

[howardjohn]

If you can get full debug logs from the client it would be ideal. istioctl proxy-config log --level=debug POD can turn them on.

[dmosesson]

I can't transfer the logs, but I can retype particular lines, sorry.

What I see is:

• Router gets the request, and matches the call
• decodes the headers, and sees the path, scheme is http, grpc-encoding: gzip, content-type: application/grpc, whole big amount of base64 encoded data in the x-envoy-peer-metadata head (looking at it base64 decoded it all seems reasonsable, except the labels on unprintable
• bunch of creating, attaching, encoding
• encoding headers via codec step (end_stream=true) shows

    ':status', '200'
    'grpc-status', '2'
    'grpc-message', 'Missing :te header'
    ....
  

[frauniki]

I have the same problem.
Changing the service port to connect to from grpc to tcp solves the problem, but I don't know the root cause.
This problem started occurring after upgrading from istio v1.20.x to v1.21.x.

Related Logs

Using grpc

{"level":"debug","time":"2024-03-26T11:44:37.233897Z","scope":"envoy http","msg":"[Tags: \"ConnectionId\":\"36\"] new stream","caller":"external/envoy/source/common/http/conn_manager_impl.cc:393","thread":33}
{"level":"debug","time":"2024-03-26T11:44:37.234004Z","scope":"envoy http","msg":"[Tags: \"ConnectionId\":\"36\",\"StreamId\":\"14758402311674678876\"] request headers complete (end_stream=false):\n':authority', 'server:8000'\n':method', 'POST'\n':path', '/service.v1.Service/Foo'\n':scheme', 'http'\n'user-agent', 'grpc-go-connect/1.15.0 (go1.22.1)'\n'content-type', 'application/grpc'\n'accept-encoding', 'identity'\n'grpc-accept-encoding', 'gzip'\n'te', 'trailers'\n'content-length', '355'\n","caller":"external/envoy/source/common/http/conn_manager_impl.cc:1192","thread":33}
{"level":"debug","time":"2024-03-26T11:44:37.234049Z","scope":"envoy connection","msg":"[Tags: \"ConnectionId\":\"36\"] current connecting state: false","caller":"external/envoy/source/common/network/connection_impl.h:98","thread":33}
{"level":"debug","time":"2024-03-26T11:44:37.234108Z","scope":"envoy filter","msg":"override with 3 ALPNs","caller":"source/extensions/filters/http/alpn/alpn_filter.cc:92","thread":33}
{"level":"debug","time":"2024-03-26T11:44:37.234131Z","scope":"envoy router","msg":"[Tags: \"ConnectionId\":\"36\",\"StreamId\":\"14758402311674678876\"] cluster 'PassthroughCluster' match for URL '/service.v1.Service/Foo'","caller":"external/envoy/source/common/router/router.cc:514","thread":33}
{"level":"debug","time":"2024-03-26T11:44:37.234177Z","scope":"envoy router","msg":"[Tags: \"ConnectionId\":\"36\",\"StreamId\":\"14758402311674678876\"] router decoding headers:\n':authority', 'server:8000'\n':method', 'POST'\n':path', '/service.v1.Service/Foo'\n':scheme', 'http'\n'user-agent', 'grpc-go-connect/1.15.0 (go1.22.1)'\n'content-type', 'application/grpc'\n'accept-encoding', 'identity'\n'grpc-accept-encoding', 'gzip'\n'content-length', '355'\n'x-forwarded-proto', 'http'\n'x-request-id', '2e3bf4ae-1bc6-4076-90d3-9f5c8938a69f'\n'x-envoy-peer-metadata-id', 'sidecar~10.1.12.177~server-9d98fc87c-wbrqr.<NAMESPACE>~.<NAMESPACE>.svc.cluster.local'\n'x-envoy-peer-metadata', '<BASE64 ENCODED DATA>'\n'x-envoy-attempt-count', '1'\n","caller":"external/envoy/source/common/router/router.cc:731","thread":33}
{"level":"debug","time":"2024-03-26T11:44:37.234235Z","scope":"envoy router","msg":"[Tags: \"ConnectionId\":\"36\",\"StreamId\":\"14758402311674678876\"] pool ready","caller":"external/envoy/source/common/router/upstream_request.cc:578","thread":33}
{"level":"debug","time":"2024-03-26T11:44:37.234301Z","scope":"envoy http","msg":"[Tags: \"ConnectionId\":\"36\",\"StreamId\":\"14758402311674678876\"] request end stream","caller":"external/envoy/source/common/http/conn_manager_impl.cc:1175","thread":33}
{"level":"debug","time":"2024-03-26T11:44:37.337317Z","scope":"envoy router","msg":"[Tags: \"ConnectionId\":\"36\",\"StreamId\":\"14758402311674678876\"] upstream headers complete: end_stream=true","caller":"external/envoy/source/common/router/router.cc:1506","thread":33}
{"level":"debug","time":"2024-03-26T11:44:37.337398Z","scope":"envoy http","msg":"[Tags: \"ConnectionId\":\"36\",\"StreamId\":\"14758402311674678876\"] encoding headers via codec (end_stream=true):\n':status', '200'\n'content-type', 'application/grpc'\n'grpc-status', '2'\n'grpc-message', 'Missing :te header'\n'x-envoy-upstream-service-time', '102'\n'date', 'Tue, 26 Mar 2024 11:44:37 GMT'\n'server', 'envoy'\n","caller":"external/envoy/source/common/http/conn_manager_impl.cc:1869","thread":33}
{"level":"debug","time":"2024-03-26T11:44:37.337443Z","scope":"envoy http","msg":"[Tags: \"ConnectionId\":\"36\",\"StreamId\":\"14758402311674678876\"] Codec completed encoding stream.","caller":"external/envoy/source/common/http/conn_manager_impl.cc:1974","thread":33}
{"level":"debug","time":"2024-03-26T11:44:37.337455Z","scope":"envoy http2","msg":"[Tags: \"ConnectionId\":\"36\"] stream 7 closed: 0","caller":"external/envoy/source/common/http/http2/codec_impl.cc:1363","thread":33}
{"level":"debug","time":"2024-03-26T11:44:37.337463Z","scope":"envoy http2","msg":"[Tags: \"ConnectionId\":\"36\"] Recouping 0 bytes of flow control window for stream 7.","caller":"external/envoy/source/common/http/http2/codec_impl.cc:1427","thread":33}

Using 'tcp'

{"level":"debug","time":"2024-03-26T11:47:03.252243Z","scope":"envoy filter","msg":"original_dst: set destination to 172.20.149.95:8000","caller":"external/envoy/source/extensions/filters/listener/original_dst/original_dst.cc:69","thread":32}
{"level":"debug","time":"2024-03-26T11:47:03.252364Z","scope":"envoy filter","msg":"[Tags: \"ConnectionId\":\"21\"] new tcp proxy session","caller":"external/envoy/source/common/tcp_proxy/tcp_proxy.cc:243","thread":32}
{"level":"debug","time":"2024-03-26T11:47:03.252397Z","scope":"envoy filter","msg":"[Tags: \"ConnectionId\":\"21\"] Creating connection to cluster outbound|8000||server.<NAMESPACE>.svc.cluster.local","caller":"external/envoy/source/common/tcp_proxy/tcp_proxy.cc:436","thread":32}
{"level":"debug","time":"2024-03-26T11:47:03.252455Z","scope":"envoy pool","msg":"trying to create new connection","caller":"external/envoy/source/common/conn_pool/conn_pool_base.cc:291","thread":32}
{"level":"debug","time":"2024-03-26T11:47:03.252490Z","scope":"envoy pool","msg":"creating a new connection (connecting=0)","caller":"external/envoy/source/common/conn_pool/conn_pool_base.cc:145","thread":32}
{"level":"debug","time":"2024-03-26T11:47:03.252950Z","scope":"envoy connection","msg":"[Tags: \"ConnectionId\":\"22\"] connecting to 10.1.6.137:8000","caller":"external/envoy/source/common/network/connection_impl.cc:1009","thread":32}
{"level":"debug","time":"2024-03-26T11:47:03.253090Z","scope":"envoy connection","msg":"[Tags: \"ConnectionId\":\"22\"] connection in progress","caller":"external/envoy/source/common/network/connection_impl.cc:1028","thread":32}
{"level":"debug","time":"2024-03-26T11:47:03.253177Z","scope":"envoy conn_handler","msg":"[Tags: \"ConnectionId\":\"21\"] new connection from 10.1.13.214:39644","caller":"external/envoy/source/common/listener_manager/active_tcp_listener.cc:160","thread":32}
{"level":"debug","time":"2024-03-26T11:47:03.253339Z","scope":"envoy connection","msg":"[Tags: \"ConnectionId\":\"22\"] connected","caller":"external/envoy/source/common/network/connection_impl.cc:746","thread":32}
{"level":"debug","time":"2024-03-26T11:47:03.256881Z","scope":"envoy pool","msg":"[Tags: \"ConnectionId\":\"22\"] attaching to next stream","caller":"external/envoy/source/common/conn_pool/conn_pool_base.cc:328","thread":32}
{"level":"debug","time":"2024-03-26T11:47:03.256904Z","scope":"envoy pool","msg":"[Tags: \"ConnectionId\":\"22\"] creating stream","caller":"external/envoy/source/common/conn_pool/conn_pool_base.cc:182","thread":32}
{"level":"debug","time":"2024-03-26T11:47:03.256920Z","scope":"envoy router","msg":"Attached upstream connection [C22] to downstream connection [C21]","caller":"external/envoy/source/common/tcp_proxy/upstream.cc:255","thread":32}
{"level":"debug","time":"2024-03-26T11:47:03.256936Z","scope":"envoy filter","msg":"[Tags: \"ConnectionId\":\"21\"] TCP:onUpstreamEvent(), requestedServerName: ","caller":"external/envoy/source/common/tcp_proxy/tcp_proxy.cc:830","thread":32}

[frauniki]

This issue may be fixed in the envoy release v1.29.3.

Related

• Missing :te header when using envoy proxy with grpc-web filter triton-inference-server/server#6936
• http: keep trailers TE header instead of removing it envoyproxy/envoy#32255
• [bp/1.29] http: keep trailers TE header instead of removing it (#32255) envoyproxy/envoy#33018

[frauniki]

I was able to temporarily work around this problem by setting runtimeValues.

defaultConfig:
  runtimeValues:
    envoy.reloadable_features.sanitize_te: "false"

or

annotations:
  proxy.istio.io/config: |
    runtimeValues:
      envoy.reloadable_features.sanitize_te: "false"

[peter-resnick]

We ran into this issue too - solved it by downgrading to v1.20.0

[mwduarte]

I was able to temporarily work around this problem by setting runtimeValues.

defaultConfig:
  runtimeValues:
    envoy.reloadable_features.sanitize_te: "false"

or

annotations:
  proxy.istio.io/config: |
    runtimeValues:
      envoy.reloadable_features.sanitize_te: "false"

This workaround worked for me too, thanks for sharing @frauniki

[frauniki]

This issue has been fundamentally resolved with the release of istio/proxy v1.21.1.
istio/proxy@4674387

[dmosesson]

Agree that 1.21.1 solves the issue. Thanks!