Groups keyboard shortcuts have been updated
Dismiss
See shortcuts
Envoy ext_proc filter
15 views
Skip to first unread message
Adil Fulara
Nov 21, 2024, 9:49:11 AM11/21/24
to envoy-users
I am trying to learn envoy ext_proc filter.
I wrote a simple grpc service based on
and
and envoy documentation
However, i get a grpc error 14
The logs from envoy are
```
[2024-11-20 23:29:53.191][3988132][debug][conn_handler] [source/common/listener_manager/active_tcp_listener.cc:160] [Tags: "ConnectionId":"0"] new connection from 127.0.0.1:41712
[2024-11-20 23:29:53.191][3988132][debug][http] [source/common/http/conn_manager_impl.cc:385] [Tags: "ConnectionId":"0"] new stream
[2024-11-20 23:29:53.191][3988132][debug][http] [source/common/http/conn_manager_impl.cc:1135] [Tags: "ConnectionId":"0","StreamId":"13768082304152152110"] request headers complete (end_stream=true):
':authority', 'localhost:10000'
':path', '/get'
':method', 'GET'
'user-agent', 'HTTPie/2.6.0'
'accept-encoding', 'gzip, deflate'
'accept', '*/*'
'connection', 'keep-alive'
'x-request-id', 'afulara'
[2024-11-20 23:29:53.191][3988132][debug][http] [source/common/http/conn_manager_impl.cc:1118] [Tags: "ConnectionId":"0","StreamId":"13768082304152152110"] request end stream
[2024-11-20 23:29:53.191][3988132][debug][connection] [./source/common/network/connection_impl.h:98] [Tags: "ConnectionId":"0"] current connecting state: false
[2024-11-20 23:29:53.191][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:338] Opening gRPC stream to external processor
[2024-11-20 23:29:53.192][3988132][debug][router] [source/common/router/router.cc:525] [Tags: "ConnectionId":"0","StreamId":"4416552663977735885"] cluster 'ext-proc' match for URL '/envoy.service.ext_proc.v3.ExternalProcessor/Process'
[2024-11-20 23:29:53.192][3988132][debug][router] [source/common/router/router.cc:750] [Tags: "ConnectionId":"0","StreamId":"4416552663977735885"] router decoding headers:
':method', 'POST'
':path', '/envoy.service.ext_proc.v3.ExternalProcessor/Process'
':authority', 'ext-proc'
':scheme', 'http'
'te', 'trailers'
'content-type', 'application/grpc'
'x-envoy-internal', 'true'
'x-forwarded-for', '192.168.1.50'
[2024-11-20 23:29:53.192][3988132][debug][pool] [source/common/http/conn_pool_base.cc:78] queueing stream due to no available connections (ready=0 busy=0 connecting=0)
[2024-11-20 23:29:53.192][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:291] trying to create new connection
[2024-11-20 23:29:53.192][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:145] creating a new connection (connecting=0)
[2024-11-20 23:29:53.192][3988132][debug][connection] [./source/common/network/connection_impl.h:98] [Tags: "ConnectionId":"1"] current connecting state: true
[2024-11-20 23:29:53.192][3988132][debug][client] [source/common/http/codec_client.cc:57] [Tags: "ConnectionId":"1"] connecting
[2024-11-20 23:29:53.192][3988132][debug][connection] [source/common/network/connection_impl.cc:1017] [Tags: "ConnectionId":"1"] connecting to 127.0.0.1:9999
[2024-11-20 23:29:53.192][3988132][debug][connection] [source/common/network/connection_impl.cc:1036] [Tags: "ConnectionId":"1"] connection in progress
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/processor_state.cc:29] Traffic direction INBOUND: 200 ms timer enabled
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:433] Sending headers message
[2024-11-20 23:29:53.192][3988132][debug][connection] [source/common/network/connection_impl.cc:746] [Tags: "ConnectionId":"1"] connected
[2024-11-20 23:29:53.192][3988132][debug][client] [source/common/http/codec_client.cc:88] [Tags: "ConnectionId":"1"] connected
[2024-11-20 23:29:53.192][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:328] [Tags: "ConnectionId":"1"] attaching to next stream
[2024-11-20 23:29:53.192][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:182] [Tags: "ConnectionId":"1"] creating stream
[2024-11-20 23:29:53.192][3988132][debug][router] [source/common/router/upstream_request.cc:595] [Tags: "ConnectionId":"0","StreamId":"4416552663977735885"] pool ready
[2024-11-20 23:29:53.192][3988132][debug][client] [source/common/http/codec_client.cc:171] [Tags: "ConnectionId":"1"] Error dispatching received data: http/1.1 protocol error: HPE_INVALID_CONSTANT
[2024-11-20 23:29:53.192][3988132][debug][connection] [source/common/network/connection_impl.cc:150] [Tags: "ConnectionId":"1"] closing data_to_write=0 type=1
[2024-11-20 23:29:53.192][3988132][debug][connection] [source/common/network/connection_impl.cc:276] [Tags: "ConnectionId":"1"] closing socket: 1
[2024-11-20 23:29:53.192][3988132][debug][client] [source/common/http/codec_client.cc:107] [Tags: "ConnectionId":"1"] disconnect. resetting 1 pending requests
[2024-11-20 23:29:53.192][3988132][debug][client] [source/common/http/codec_client.cc:159] [Tags: "ConnectionId":"1"] request reset
[2024-11-20 23:29:53.192][3988132][debug][router] [source/common/router/router.cc:1377] [Tags: "ConnectionId":"0","StreamId":"4416552663977735885"] upstream reset: reset reason: protocol error, transport failure reason:
[2024-11-20 23:29:53.192][3988132][debug][http] [source/common/http/async_client_impl.cc:147] async http request response headers (end_stream=true):
':status', '200'
'content-type', 'application/grpc'
'grpc-status', '14'
'grpc-message', 'upstream connect error or disconnect/reset before headers. reset reason: protocol error'
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/client_impl.cc:90] gRPC stream closed remotely with status 14: upstream connect error or disconnect/reset before headers. reset reason: protocol error
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:1157] Received gRPC error on stream: 14
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/processor_state.cc:55] Traffic direction INBOUND: timer disabled
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:374] Calling close on stream
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:1270] Sending local reply with status code 500
[2024-11-20 23:29:53.192][3988132][debug][http] [source/common/http/filter_manager.cc:1075] [Tags: "ConnectionId":"0","StreamId":"13768082304152152110"] Sending local reply with details ext_proc_error_gRPC_error_14
[2024-11-20 23:29:53.192][3988132][debug][http] [source/common/http/conn_manager_impl.cc:1825] [Tags: "ConnectionId":"0","StreamId":"13768082304152152110"] encoding headers via codec (end_stream=true):
':status', '500'
'date', 'Thu, 21 Nov 2024 07:29:52 GMT'
'server', 'envoy'
[2024-11-20 23:29:53.192][3988132][debug][http] [source/common/http/conn_manager_impl.cc:1937] [Tags: "ConnectionId":"0","StreamId":"13768082304152152110"] Codec completed encoding stream.
[2024-11-20 23:29:53.193][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:392] onDestroy
[2024-11-20 23:29:53.193][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/processor_state.cc:55] Traffic direction INBOUND: timer disabled
[2024-11-20 23:29:53.193][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:381] Stream already closed
[2024-11-21T07:29:53.191Z] "GET /get HTTP/1.1" 500 - 0 0 1 - "-" "HTTPie/2.6.0" "afulara" "localhost:10000" "-"
[2024-11-20 23:29:53.193][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:495] [Tags: "ConnectionId":"1"] client disconnected, failure reason:
[2024-11-20 23:29:53.193][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:463] invoking 1 idle callback(s) - is_draining_for_deletion_=false
[2024-11-20 23:29:53.193][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:215] [Tags: "ConnectionId":"1"] destroying stream: 0 remaining
[2024-11-20 23:29:53.208][3988132][debug][connection] [source/common/network/connection_impl.cc:714] [Tags: "ConnectionId":"0"] remote close
[2024-11-20 23:29:53.208][3988132][debug][connection] [source/common/network/connection_impl.cc:276] [Tags: "ConnectionId":"0"] closing socket: 0
[2024-11-20 23:29:53.208][3988132][debug][conn_handler] [source/common/listener_manager/active_stream_listener_base.cc:136] [Tags: "ConnectionId":"0"] adding to cleanup list
[2024-11-20 23:29:53.191][3988132][debug][http] [source/common/http/conn_manager_impl.cc:385] [Tags: "ConnectionId":"0"] new stream
[2024-11-20 23:29:53.191][3988132][debug][http] [source/common/http/conn_manager_impl.cc:1135] [Tags: "ConnectionId":"0","StreamId":"13768082304152152110"] request headers complete (end_stream=true):
':authority', 'localhost:10000'
':path', '/get'
':method', 'GET'
'user-agent', 'HTTPie/2.6.0'
'accept-encoding', 'gzip, deflate'
'accept', '*/*'
'connection', 'keep-alive'
'x-request-id', 'afulara'
[2024-11-20 23:29:53.191][3988132][debug][http] [source/common/http/conn_manager_impl.cc:1118] [Tags: "ConnectionId":"0","StreamId":"13768082304152152110"] request end stream
[2024-11-20 23:29:53.191][3988132][debug][connection] [./source/common/network/connection_impl.h:98] [Tags: "ConnectionId":"0"] current connecting state: false
[2024-11-20 23:29:53.191][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:338] Opening gRPC stream to external processor
[2024-11-20 23:29:53.192][3988132][debug][router] [source/common/router/router.cc:525] [Tags: "ConnectionId":"0","StreamId":"4416552663977735885"] cluster 'ext-proc' match for URL '/envoy.service.ext_proc.v3.ExternalProcessor/Process'
[2024-11-20 23:29:53.192][3988132][debug][router] [source/common/router/router.cc:750] [Tags: "ConnectionId":"0","StreamId":"4416552663977735885"] router decoding headers:
':method', 'POST'
':path', '/envoy.service.ext_proc.v3.ExternalProcessor/Process'
':authority', 'ext-proc'
':scheme', 'http'
'te', 'trailers'
'content-type', 'application/grpc'
'x-envoy-internal', 'true'
'x-forwarded-for', '192.168.1.50'
[2024-11-20 23:29:53.192][3988132][debug][pool] [source/common/http/conn_pool_base.cc:78] queueing stream due to no available connections (ready=0 busy=0 connecting=0)
[2024-11-20 23:29:53.192][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:291] trying to create new connection
[2024-11-20 23:29:53.192][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:145] creating a new connection (connecting=0)
[2024-11-20 23:29:53.192][3988132][debug][connection] [./source/common/network/connection_impl.h:98] [Tags: "ConnectionId":"1"] current connecting state: true
[2024-11-20 23:29:53.192][3988132][debug][client] [source/common/http/codec_client.cc:57] [Tags: "ConnectionId":"1"] connecting
[2024-11-20 23:29:53.192][3988132][debug][connection] [source/common/network/connection_impl.cc:1017] [Tags: "ConnectionId":"1"] connecting to 127.0.0.1:9999
[2024-11-20 23:29:53.192][3988132][debug][connection] [source/common/network/connection_impl.cc:1036] [Tags: "ConnectionId":"1"] connection in progress
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/processor_state.cc:29] Traffic direction INBOUND: 200 ms timer enabled
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:433] Sending headers message
[2024-11-20 23:29:53.192][3988132][debug][connection] [source/common/network/connection_impl.cc:746] [Tags: "ConnectionId":"1"] connected
[2024-11-20 23:29:53.192][3988132][debug][client] [source/common/http/codec_client.cc:88] [Tags: "ConnectionId":"1"] connected
[2024-11-20 23:29:53.192][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:328] [Tags: "ConnectionId":"1"] attaching to next stream
[2024-11-20 23:29:53.192][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:182] [Tags: "ConnectionId":"1"] creating stream
[2024-11-20 23:29:53.192][3988132][debug][router] [source/common/router/upstream_request.cc:595] [Tags: "ConnectionId":"0","StreamId":"4416552663977735885"] pool ready
[2024-11-20 23:29:53.192][3988132][debug][client] [source/common/http/codec_client.cc:171] [Tags: "ConnectionId":"1"] Error dispatching received data: http/1.1 protocol error: HPE_INVALID_CONSTANT
[2024-11-20 23:29:53.192][3988132][debug][connection] [source/common/network/connection_impl.cc:150] [Tags: "ConnectionId":"1"] closing data_to_write=0 type=1
[2024-11-20 23:29:53.192][3988132][debug][connection] [source/common/network/connection_impl.cc:276] [Tags: "ConnectionId":"1"] closing socket: 1
[2024-11-20 23:29:53.192][3988132][debug][client] [source/common/http/codec_client.cc:107] [Tags: "ConnectionId":"1"] disconnect. resetting 1 pending requests
[2024-11-20 23:29:53.192][3988132][debug][client] [source/common/http/codec_client.cc:159] [Tags: "ConnectionId":"1"] request reset
[2024-11-20 23:29:53.192][3988132][debug][router] [source/common/router/router.cc:1377] [Tags: "ConnectionId":"0","StreamId":"4416552663977735885"] upstream reset: reset reason: protocol error, transport failure reason:
[2024-11-20 23:29:53.192][3988132][debug][http] [source/common/http/async_client_impl.cc:147] async http request response headers (end_stream=true):
':status', '200'
'content-type', 'application/grpc'
'grpc-status', '14'
'grpc-message', 'upstream connect error or disconnect/reset before headers. reset reason: protocol error'
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/client_impl.cc:90] gRPC stream closed remotely with status 14: upstream connect error or disconnect/reset before headers. reset reason: protocol error
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:1157] Received gRPC error on stream: 14
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/processor_state.cc:55] Traffic direction INBOUND: timer disabled
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:374] Calling close on stream
[2024-11-20 23:29:53.192][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:1270] Sending local reply with status code 500
[2024-11-20 23:29:53.192][3988132][debug][http] [source/common/http/filter_manager.cc:1075] [Tags: "ConnectionId":"0","StreamId":"13768082304152152110"] Sending local reply with details ext_proc_error_gRPC_error_14
[2024-11-20 23:29:53.192][3988132][debug][http] [source/common/http/conn_manager_impl.cc:1825] [Tags: "ConnectionId":"0","StreamId":"13768082304152152110"] encoding headers via codec (end_stream=true):
':status', '500'
'date', 'Thu, 21 Nov 2024 07:29:52 GMT'
'server', 'envoy'
[2024-11-20 23:29:53.192][3988132][debug][http] [source/common/http/conn_manager_impl.cc:1937] [Tags: "ConnectionId":"0","StreamId":"13768082304152152110"] Codec completed encoding stream.
[2024-11-20 23:29:53.193][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:392] onDestroy
[2024-11-20 23:29:53.193][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/processor_state.cc:55] Traffic direction INBOUND: timer disabled
[2024-11-20 23:29:53.193][3988132][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:381] Stream already closed
[2024-11-21T07:29:53.191Z] "GET /get HTTP/1.1" 500 - 0 0 1 - "-" "HTTPie/2.6.0" "afulara" "localhost:10000" "-"
[2024-11-20 23:29:53.193][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:495] [Tags: "ConnectionId":"1"] client disconnected, failure reason:
[2024-11-20 23:29:53.193][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:463] invoking 1 idle callback(s) - is_draining_for_deletion_=false
[2024-11-20 23:29:53.193][3988132][debug][pool] [source/common/conn_pool/conn_pool_base.cc:215] [Tags: "ConnectionId":"1"] destroying stream: 0 remaining
[2024-11-20 23:29:53.208][3988132][debug][connection] [source/common/network/connection_impl.cc:714] [Tags: "ConnectionId":"0"] remote close
[2024-11-20 23:29:53.208][3988132][debug][connection] [source/common/network/connection_impl.cc:276] [Tags: "ConnectionId":"0"] closing socket: 0
[2024-11-20 23:29:53.208][3988132][debug][conn_handler] [source/common/listener_manager/active_stream_listener_base.cc:136] [Tags: "ConnectionId":"0"] adding to cleanup list
```
Could anyone help me understand where i am going wrong?
Appreciate all the help.
Attachement
- grpc ext_processor in golang
- go.mode file
- envoy.yaml file
Adil Fulara
Dec 16, 2024, 11:52:12 PM12/16/24
to envoy-users
For anyone looking at this question, the solution was to enable `http2` for the cluster.
So adding empty `http2_protocol_options` fixed it
#sillymistakes
Reply all
Reply to author
Forward
0 new messages