ext_proc fuzzer test exposed a race issue which leads to ENVOY_BUG by yanjunxiang-google · Pull Request #27639 · envoyproxy/envoy

yanjunxiang-google · 2023-05-25T19:02:27Z

ext_proc fuzzer test exposed a race issue which leads to ENVOY_BUG() get triggered when opening a gRPC stream.

The issue is that

when onData() is called, it first open a gRPC stream to send the body to the ext_proc server.
when ext_proc server sends back a spurious response, which leads to the gRPC stream is closed, and processing_complete_ is set to true.
onData() later on will try to send the just added trailer. Before that it will try to call openStream() again with processing_complete_ already set to true. This triggers ENVOY_BUG().

The solution is that:
openStream() actually already has the check for processing_complete_ then return error. Just needs to move that check to front.

Commit Message:
Additional Description:
Risk Level:
Testing:
Docs Changes:
Release Notes:
Platform Specific Features:
[Optional Runtime guard:]
[Optional Fixes #Issue]
[Optional Fixes commit #PR or SHA]
[Optional Deprecated:]
[Optional API Considerations:]

… ext_proc filter when opens a gRPC stream. Signed-off-by: Yanjun Xiang <yanjunxiang@google.com>

yanjunxiang-google · 2023-05-25T19:03:14Z

This is the fuzzer crash traceback:

./bazel-bin/test/extensions/filters/http/ext_proc/unit_test_fuzz/ext_proc_unit_test_fuzz test/extensions/filters/http/ext_proc/unit_test_fuzz/ext_proc_corpus/crash-232906f11069ff930e29c13c1a3ae5a2c3202c57 -l trace
[==========] Running 1 test from 1 test suite.
[----------] Global test environment set-up.
[----------] 1 test from CorpusExamples/FuzzerCorpusTest
[ RUN ] CorpusExamples/FuzzerCorpusTest.RunOneCorpusFile/0
[2023-05-25 18:54:41.621][154380][info][misc] [test/fuzz/main.cc:47] Corpus file: test/extensions/filters/http/ext_proc/unit_test_fuzz/ext_proc_corpus/crash-232906f11069ff930e29c13c1a3ae5a2c3202c57
[2023-05-25 18:54:41.629][154380][warning][misc] [source/common/protobuf/message_validator_impl.cc:35] message 'envoy.extensions.filters.http.ext_proc.v3.ExternalProcessor' is contained in proto file 'envoy/extensions/filters/http/ext_proc/v3/ext_proc.proto' marked as work-in-progress. API features marked as work-in-progress are not considered stable, are not covered by the threat model, are not supported by the security team, and are subject to breaking changes. Do not use this feature without understanding each of the previous points.
[2023-05-25 18:54:41.629][154380][warning][misc] [source/common/protobuf/message_validator_impl.cc:35] message 'envoy.extensions.filters.http.ext_proc.v3.ProcessingMode' is contained in proto file 'envoy/extensions/filters/http/ext_proc/v3/processing_mode.proto' marked as work-in-progress. API features marked as work-in-progress are not considered stable, are not covered by the threat model, are not supported by the security team, and are subject to breaking changes. Do not use this feature without understanding each of the previous points.
[2023-05-25 18:54:41.630][154380][warning][misc] [source/common/protobuf/message_validator_impl.cc:35] message 'envoy.service.ext_proc.v3.ProcessingResponse' is contained in proto file 'envoy/service/ext_proc/v3/external_processor.proto' marked as work-in-progress. API features marked as work-in-progress are not considered stable, are not covered by the threat model, are not supported by the security team, and are subject to breaking changes. Do not use this feature without understanding each of the previous points.
[2023-05-25 18:54:41.630][154380][warning][misc] [source/common/protobuf/message_validator_impl.cc:35] message 'envoy.service.ext_proc.v3.HeadersResponse' is contained in proto file 'envoy/service/ext_proc/v3/external_processor.proto' marked as work-in-progress. API features marked as work-in-progress are not considered stable, are not covered by the threat model, are not supported by the security team, and are subject to breaking changes. Do not use this feature without understanding each of the previous points.
[2023-05-25 18:54:41.630][154380][warning][misc] [source/common/protobuf/message_validator_impl.cc:35] message 'envoy.service.ext_proc.v3.CommonResponse' is contained in proto file 'envoy/service/ext_proc/v3/external_processor.proto' marked as work-in-progress. API features marked as work-in-progress are not considered stable, are not covered by the threat model, are not supported by the security team, and are subject to breaking changes. Do not use this feature without understanding each of the previous points.
[2023-05-25 18:54:41.630][154380][warning][misc] [source/common/protobuf/message_validator_impl.cc:35] message 'envoy.service.ext_proc.v3.HeaderMutation' is contained in proto file 'envoy/service/ext_proc/v3/external_processor.proto' marked as work-in-progress. API features marked as work-in-progress are not considered stable, are not covered by the threat model, are not supported by the security team, and are subject to breaking changes. Do not use this feature without understanding each of the previous points.
[2023-05-25 18:54:41.630][154380][warning][misc] [source/common/protobuf/message_validator_impl.cc:35] message 'envoy.extensions.filters.http.ext_proc.v3.ProcessingMode' is contained in proto file 'envoy/extensions/filters/http/ext_proc/v3/processing_mode.proto' marked as work-in-progress. API features marked as work-in-progress are not considered stable, are not covered by the threat model, are not supported by the security team, and are subject to breaking changes. Do not use this feature without understanding each of the previous points.
[2023-05-25 18:54:41.630][154380][info][misc] [test/test_common/test_random_generator.cc:20] TestRandomGenerator running with seed 228576712
[2023-05-25 18:54:41.702][154380][debug][misc] [./test/extensions/filters/http/common/fuzz/http_filter_fuzzer.h:144] Decoding headers (end_stream=false):
':path', '/foo'
':method', 'GET'
':authority', 'foo.com'
'(', ''
'test_uri', ''

[2023-05-25 18:54:41.702][154380][trace][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:189] decodeHeaders: end_stream = false
[2023-05-25 18:54:41.702][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:123] Opening gRPC stream to external processor

GMOCK WARNING:
Uninteresting mock function call - taking default action specified at:
test/extensions/filters/http/ext_proc/unit_test_fuzz/ext_proc_unit_test_fuzz.cc:90:
Function call: start(@0x616000060fa8 8-byte object <50-5D 77-07 00-00 00-00>, @0x616000061038 64-byte object <50-A2 9A-07 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 01-00 00-00 01-00 00-00 90-64 0F-00 20-60 00-00 00-00 00-00 00-00 00-00 00-B0 01-00 B0-60 00-00 00-00 00-00 02-00 00-00>, @0x9eb0050 8-byte object <20-B8 76-07 00-00 00-00>)
Returns: 0x61100007ca00
NOTE: You can safely ignore the above warning unless this call should not happen. Do not suppress it by blindly adding an EXPECT_CALL() if you don't mean to enforce the call. See https://github.com/google/googletest/blob/master/googlemock/docs/cook_book.md#knowing-when-to-expect for details.
[2023-05-25 18:54:41.704][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/processor_state.cc:30] Traffic direction INBOUND: 200 ms timer enabled
[2023-05-25 18:54:41.704][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:181] Sending headers message
[2023-05-25 18:54:41.705][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:606] Processing mode overridden by server for this request
[2023-05-25 18:54:41.705][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:611] Received request headers response
[2023-05-25 18:54:41.705][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/processor_state.cc:84] applying headers response. body mode = BUFFERED
[2023-05-25 18:54:41.705][154380][trace][ext_proc] [source/extensions/filters/http/ext_proc/mutation_utils.cc:60] Removing header f
[2023-05-25 18:54:41.705][154380][trace][ext_proc] [source/extensions/filters/http/ext_proc/mutation_utils.cc:60] Removing header f
[2023-05-25 18:54:41.705][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/processor_state.cc:52] Traffic direction INBOUND: timer disabled
[2023-05-25 18:54:41.705][154380][trace][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:201] decodeHeaders returning 1
[2023-05-25 18:54:41.705][154380][debug][misc] [./test/extensions/filters/http/common/fuzz/http_filter_fuzzer.h:103] Finished with FilterHeadersStatus: 1
[2023-05-25 18:54:41.705][154380][debug][misc] [./test/extensions/filters/http/common/fuzz/http_filter_fuzzer.h:185] Decoding data (end_stream=true): 𸸸𸸸𸸸𸸸𸸸𸸸𸸸𸸸𸸸𸸸𸸸𸸸踸
[2023-05-25 18:54:41.705][154380][trace][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:419] decodeData(51): end_stream = true
[2023-05-25 18:54:41.705][154380][trace][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:225] Creating new, empty trailers
[2023-05-25 18:54:41.705][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:274] Sending request body message
[2023-05-25 18:54:41.705][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:524] Sending a body chunk of 3 bytes
[2023-05-25 18:54:41.705][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/processor_state.cc:30] Traffic direction INBOUND: 200 ms timer enabled
[2023-05-25 18:54:41.705][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:606] Processing mode overridden by server for this request
[2023-05-25 18:54:41.705][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:611] Received request headers response
[2023-05-25 18:54:41.705][154380][warning][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:660] Spurious response message 1 received on gRPC stream
[2023-05-25 18:54:41.705][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/ext_proc.cc:140] Calling close on stream

GMOCK WARNING:
Uninteresting mock function call - taking default action specified at:
test/extensions/filters/http/ext_proc/unit_test_fuzz/ext_proc_unit_test_fuzz.cc:106:
Function call: close()
Returns: false
NOTE: You can safely ignore the above warning unless this call should not happen. Do not suppress it by blindly adding an EXPECT_CALL() if you don't mean to enforce the call. See https://github.com/google/googletest/blob/master/googlemock/docs/cook_book.md#knowing-when-to-expect for details.
[2023-05-25 18:54:41.705][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/processor_state.cc:52] Traffic direction INBOUND: timer disabled
[2023-05-25 18:54:41.705][154380][debug][ext_proc] [source/extensions/filters/http/ext_proc/processor_state.cc:413] Continuing processing
[2023-05-25 18:54:41.705][154380][error][envoy_bug] [source/extensions/filters/http/ext_proc/ext_proc.cc:121] envoy bug failure: !processing_complete_. Details: openStream should not have been called
[2023-05-25 18:54:41.705][154380][error][envoy_bug] [./source/common/common/assert.h:38] stacktrace for envoy bug
[2023-05-25 18:54:41.738][154380][error][envoy_bug] [./source/common/common/assert.h:43] #0 Envoy::Extensions::HttpFilters::ExternalProcessing::Filter::openStream() [0x28f7999]
[2023-05-25 18:54:41.770][154380][error][envoy_bug] [./source/common/common/assert.h:43] #1 Envoy::Extensions::HttpFilters::ExternalProcessing::Filter::onData() [0x28fe17b]
[2023-05-25 18:54:41.802][154380][error][envoy_bug] [./source/common/common/assert.h:43] #2 Envoy::Extensions::HttpFilters::ExternalProcessing::Filter::decodeData() [0x29014e5]
[2023-05-25 18:54:41.834][154380][error][envoy_bug] [./source/common/common/assert.h:43] #3 Envoy::Extensions::HttpFilters::HttpFilterFuzzer::sendData<>() [0x288e6d9]
[2023-05-25 18:54:41.866][154380][error][envoy_bug] [./source/common/common/assert.h:43] #4 Envoy::Extensions::HttpFilters::HttpFilterFuzzer::runData<>() [0x276139e]
[2023-05-25 18:54:41.898][154380][error][envoy_bug] [./source/common/common/assert.h:43] #5 LLVMFuzzerTestOneInput [0x274dcb6]
[2023-05-25 18:54:41.930][154380][error][envoy_bug] [./source/common/common/assert.h:43] #6 Envoy::(anonymous namespace)::FuzzerCorpusTest_RunOneCorpusFile_Test::TestBody() [0x4ff4a7b]
[2023-05-25 18:54:41.962][154380][error][envoy_bug] [./source/common/common/assert.h:43] #7 testing::internal::HandleExceptionsInMethodIfSupported<>() [0x76bd508]
[2023-05-25 18:54:41.995][154380][error][envoy_bug] [./source/common/common/assert.h:43] #8 testing::Test::Run() [0x76934fc]
[2023-05-25 18:54:42.028][154380][error][envoy_bug] [./source/common/common/assert.h:43] #9 testing::TestInfo::Run() [0x7694b31]
[2023-05-25 18:54:42.062][154380][error][envoy_bug] [./source/common/common/assert.h:43] #10 testing::TestSuite::Run() [0x769614b]
[2023-05-25 18:54:42.094][154380][error][envoy_bug] [./source/common/common/assert.h:43] #11 testing::internal::UnitTestImpl::RunAllTests() [0x76af34c]
[2023-05-25 18:54:42.127][154380][error][envoy_bug] [./source/common/common/assert.h:43] #12 testing::internal::HandleExceptionsInMethodIfSupported<>() [0x76c0d58]
[2023-05-25 18:54:42.160][154380][error][envoy_bug] [./source/common/common/assert.h:43] #13 testing::UnitTest::Run() [0x76ae8fe]
[2023-05-25 18:54:42.192][154380][error][envoy_bug] [./source/common/common/assert.h:43] #14 main [0x4ff2db6]
[2023-05-25 18:54:42.193][154380][error][envoy_bug] [./source/common/common/assert.h:45] #15 UNKNOWN [0x7fa3e50cd18a]
Aborted

yanjunxiang-google · 2023-05-25T19:03:50Z

This is the test case:

cat test/extensions/filters/http/ext_proc/unit_test_fuzz/ext_proc_corpus/crash-232906f11069ff930e29c13c1a3ae5a2c3202c57
config {
grpc_service {
google_grpc {
target_uri: "test_uri"
channel_credentials {
ssl_credentials {
private_key {
inline_string: "/"
}
}
}
stat_prefix: "test_uri"
credentials_factory_name: "test_uri"
config {
}
}
initial_metadata {
key: "test_uri"
}
}
failure_mode_allow: true
processing_mode {
response_header_mode: SKIP
}
request_attributes: "("
response_attributes: "test_uri"
response_attributes: "9\000\000\000\000\000\000\000"
stat_prefix: "\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000."
}
request {
headers {
headers {
key: "("
}
headers {
key: "test_uri"
}
}
http_body {
data: "\360\270\270\270\360\270\270\270\360\270\270\270\360\270\270\270\360\270\270\270\360\270\270\270\360\270\270\270\360\270\270\270\360\270\270\270\360\270\270\270\360\270\270\270\360\270\270\270\350\270\270"
}
}
response {
request_headers {
response {
header_mutation {
remove_headers: "f"
remove_headers: "f"
}
}
}
dynamic_metadata {
fields {
key: ""
value {
}
}
fields {
key: ""
value {
}
}
}
mode_override {
request_header_mode: SKIP
request_body_mode: BUFFERED
response_body_mode: BUFFERED
request_trailer_mode: SEND
}
}

yanjunxiang-google · 2023-05-25T19:06:12Z

The fuzzer can easily trigger this race since it sends back and handles the spurious response right within onData() when the body request is sent to the ext_proc server. This is after the first openStream() but before the 2nd openStream() / sendTrailers() in onData() function.

yanjunxiang-google · 2023-05-25T19:06:30Z

@yanavlasov @tyxia

yanjunxiang-google · 2023-05-25T19:06:51Z

@stevenzzzz @mpwarres

yanjunxiang-google · 2023-05-26T14:23:06Z

The test is failed with the issue addressed by: #27619. So wait for that PR to be merged first.

KBaichoo · 2023-05-29T12:13:21Z

/wait

…stream_fuzzer_crash Signed-off-by: Yanjun Xiang <yanjunxiang@google.com>

Signed-off-by: Yanjun Xiang <yanjunxiang@google.com>

KBaichoo · 2023-05-31T12:30:07Z

/assign @tyxia

As codeowner

Signed-off-by: Yanjun Xiang <yanjunxiang@google.com>

tyxia

LGTM! Thanks.

A small nit for future: If possible, It will be great if we include fuzzer crash traceback as attachment. I just feel it is too long to fit in the comment section,

tyxia · 2023-06-01T14:27:10Z

/assign @stevenzzzz @mpwarres

I think we also want the review from team that is using this filter. Also, cced @yanavlasov and @htuch, please feel free to chime in and comment/review. Thanks!

KBaichoo

/wait

Generally looks good, thanks

Signed-off-by: Yanjun Xiang <yanjunxiang@google.com>

KBaichoo

Thanks!

* ext_proc should not open an additional stream if we've completed processing. Signed-off-by: Yanjun Xiang <yanjunxiang@google.com> Signed-off-by: Ryan Eskin <ryan.eskin89@protonmail.com>

ext_proc fuzzer test exposed a race issue which leads to ENVOY_BUG in…

f1f246e

… ext_proc filter when opens a gRPC stream. Signed-off-by: Yanjun Xiang <yanjunxiang@google.com>

yanjunxiang-google requested a review from snowp as a code owner May 25, 2023 19:02

tyxia reviewed May 26, 2023

View reviewed changes

Comment thread source/extensions/filters/http/ext_proc/ext_proc.cc Outdated

Comment thread source/extensions/filters/http/ext_proc/ext_proc.cc

repokitteh-read-only Bot added the waiting label May 29, 2023

phlax assigned KBaichoo May 30, 2023

yanjunxiang-google added 2 commits May 30, 2023 17:50

Merge branch 'main' of https://github.com/envoyproxy/envoy into open_…

8e9d5e5

…stream_fuzzer_crash Signed-off-by: Yanjun Xiang <yanjunxiang@google.com>

Merge branch 'main' of https://github.com/envoyproxy/envoy into open_…

0ebd8c7

…stream_fuzzer_crash Signed-off-by: Yanjun Xiang <yanjunxiang@google.com>

repokitteh-read-only Bot removed the waiting label May 30, 2023

adding stream_ check

3bfe644

Signed-off-by: Yanjun Xiang <yanjunxiang@google.com>

repokitteh-read-only Bot assigned tyxia May 31, 2023

addressing comments

7e3f10b

Signed-off-by: Yanjun Xiang <yanjunxiang@google.com>

tyxia previously approved these changes Jun 1, 2023

View reviewed changes

repokitteh-read-only Bot assigned mpwarres and stevenzzzz Jun 1, 2023

KBaichoo reviewed Jun 1, 2023

View reviewed changes

Comment thread source/extensions/filters/http/ext_proc/ext_proc.cc Outdated

repokitteh-read-only Bot added the waiting label Jun 1, 2023

ENVOY_LOG

595f038

Signed-off-by: Yanjun Xiang <yanjunxiang@google.com>

yanjunxiang-google dismissed tyxia’s stale review via 595f038 June 2, 2023 17:30

repokitteh-read-only Bot removed the waiting label Jun 2, 2023

addressing comments

4bea75d

Signed-off-by: Yanjun Xiang <yanjunxiang@google.com>

KBaichoo approved these changes Jun 2, 2023

View reviewed changes

KBaichoo merged commit d0fd025 into envoyproxy:main Jun 2, 2023

yanjunxiang-google deleted the open_stream_fuzzer_crash branch June 2, 2023 19:11

Conversation

yanjunxiang-google commented May 25, 2023

Uh oh!

yanjunxiang-google commented May 25, 2023

Uh oh!

yanjunxiang-google commented May 25, 2023

Uh oh!

yanjunxiang-google commented May 25, 2023

Uh oh!

yanjunxiang-google commented May 25, 2023

Uh oh!

yanjunxiang-google commented May 25, 2023

Uh oh!

yanjunxiang-google commented May 26, 2023

Uh oh!

Uh oh!

Uh oh!

KBaichoo commented May 29, 2023

Uh oh!

KBaichoo commented May 31, 2023

Uh oh!

tyxia left a comment

Choose a reason for hiding this comment

Uh oh!

tyxia commented Jun 1, 2023

Uh oh!

KBaichoo left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

KBaichoo left a comment

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants