Istio 1.5 Proxy Sidecar Crash (WASM) (httpCall)

Hi,

We’re having a problem with the Envoy Proxy crashing when our custom WASM filter made a httpCall to an endpoint which the response is empty ex: http://httpbin.org/status/200

It seems there’s trying to access a null pointer to the body content… See backtrace below.

Has anyone seen something similar? Any advice on narrowing the problem down more?

Here’s the backtrace from the crash:

[Envoy (Epoch 0)] [2020-05-11 16:25:21.453][24][debug][http] [external/envoy/source/common/http/conn_manager_impl.cc:263] [C12] new stream
[Envoy (Epoch 0)] [2020-05-11 16:25:21.453][24][debug][http] [external/envoy/source/common/http/conn_manager_impl.cc:731] [C12][S1778501486270859586] request headers complete (end_stream=true):
':authority', '192.168.64.14:8000'
':path', '/status/200'
':method', 'GET'
'user-agent', 'curl/7.54.0'
'accept', '*/*'
'x-client-id', 'bar'

[Envoy (Epoch 0)] [2020-05-11 16:25:21.453][24][debug][http] [external/envoy/source/common/http/conn_manager_impl.cc:1276] [C12][S1778501486270859586] request end stream
[Envoy (Epoch 0)] [2020-05-11 16:25:21.453][24][debug][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1086] wasm log auth auth: ensureContext(context_id: 2, root_context_id: 1)
[Envoy (Epoch 0)] [2020-05-11 16:25:21.453][24][debug][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1086] wasm log auth auth: Current context_map: 1
[Envoy (Epoch 0)] [2020-05-11 16:25:21.453][24][debug][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1086] wasm log auth auth: ensureRootContext(root_context_id: 1)
[Envoy (Epoch 0)] [2020-05-11 16:25:21.453][24][debug][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1086] wasm log auth auth: Current context_map: 1
[Envoy (Epoch 0)] [2020-05-11 16:25:21.453][24][debug][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1086] wasm log auth auth: Returning root context for id: 1
[Envoy (Epoch 0)] [2020-05-11 16:25:21.453][24][debug][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1086] wasm log auth auth: Registering new context with context_id: 2 under root_context: 1
[Envoy (Epoch 0)] [2020-05-11 16:25:21.453][24][debug][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1086] wasm log auth auth: Updated context_map: 1, 2
[Envoy (Epoch 0)] [2020-05-11 16:25:21.454][24][debug][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1086] wasm log auth auth: context id: 1: httpCall(cluster: outbound|8000||httpbin.test.svc.cluster.local, headers:[object ArrayBuffer]:[object ArrayBuffer],[object ArrayBuffer]:[object ArrayBuffer],[object ArrayBuffer]:[object ArrayBuffer],[object ArrayBuffer]:[object ArrayBuffer],[object ArrayBuffer]:[object ArrayBuffer],[object ArrayBuffer]:[object ArrayBuffer],[object ArrayBuffer]:[object ArrayBuffer],[object ArrayBuffer]:[object ArrayBuffer], body:[object ArrayBuffer], trailers:)
[Envoy (Epoch 0)] [2020-05-11 16:25:21.454][24][debug][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1086] wasm log auth auth: Http call executed with result: 0
[Envoy (Epoch 0)] [2020-05-11 16:25:21.454][24][debug][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1086] wasm log auth auth: set token: 1 on 1
[Envoy (Epoch 0)] [2020-05-11 16:25:21.459][24][debug][http] [external/envoy/source/common/http/async_client_impl.cc:95] async http request response headers (end_stream=true):
':status', '200'
'server', 'gunicorn/19.6.0'
'date', 'Mon, 11 May 2020 16:25:21 GMT'
'connection', 'close'
'content-type', 'text/html; charset=utf-8'
'access-control-allow-origin', '*'
'access-control-allow-credentials', 'true'
'content-length', '0'
'x-envoy-upstream-service-time', '4'

[Envoy (Epoch 0)] [2020-05-11 16:25:21.459][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:83] Caught Segmentation fault, suspect faulting address 0x0
[Envoy (Epoch 0)] [2020-05-11 16:25:21.459][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:70] Backtrace (use tools/stack_decode.py to get line numbers):
[Envoy (Epoch 0)] [2020-05-11 16:25:21.459][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:71] Envoy version: 54fd05bc1e3e59a155651e5c84e4138d849e8d58/1.13.1-dev/Clean/RELEASE/BoringSSL
[Envoy (Epoch 0)] [2020-05-11 16:25:21.477][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #0: __restore_rt [0x7f40d1d8f890]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.488][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #1: Envoy::Http::AsyncRequestImpl::onComplete() [0x564a86c7d12c]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.497][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #2: Envoy::Http::AsyncStreamImpl::encodeHeaders() [0x564a86c7c935]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.506][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #3: Envoy::Router::Filter::onUpstreamHeaders() [0x564a86c88c58]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.515][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #4: Envoy::Router::Filter::UpstreamRequest::decodeHeaders() [0x564a86c8ad96]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.524][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #5: Envoy::Http::Http1::ConnPoolImpl::StreamWrapper::decodeHeaders() [0x564a86c0614b]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.532][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #6: Envoy::Http::StreamDecoderWrapper::decodeHeaders() [0x564a86c6c8ec]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.540][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #7: Envoy::Http::Http1::ClientConnectionImpl::onMessageComplete() [0x564a86cf7616]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.549][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #8: Envoy::Http::Http1::ConnectionImpl::onMessageCompleteBase() [0x564a86cf4a5e]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.558][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #9: Envoy::Http::Http1::ConnectionImpl::$_8::__invoke() [0x564a86cf8add]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.566][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #10: http_parser_execute [0x564a86dcb652]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.574][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #11: Envoy::Http::Http1::ConnectionImpl::dispatchSlice() [0x564a86cf359a]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.582][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #12: Envoy::Http::Http1::ConnectionImpl::dispatch() [0x564a86cf337f]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.590][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #13: Envoy::Http::CodecClient::onData() [0x564a86c6ba68]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.598][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #14: Envoy::Http::CodecClient::CodecReadFilter::onData() [0x564a86c6c7bd]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.606][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #15: Envoy::Network::FilterManagerImpl::onContinueReading() [0x564a86a9cb9b]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.615][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #16: Envoy::Network::ConnectionImpl::onReadReady() [0x564a86a9960a]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.623][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #17: Envoy::Network::ConnectionImpl::onFileEvent() [0x564a86a990dd]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.632][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #18: Envoy::Event::FileEventImpl::assignEvents()::$_0::__invoke() [0x564a86a93bb0]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.640][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #19: event_process_active_single_queue [0x564a86dc4fab]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.648][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #20: event_base_loop [0x564a86dc383e]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.656][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #21: Envoy::Server::WorkerImpl::threadRoutine() [0x564a86a89838]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.664][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #22: Envoy::Thread::ThreadImplPosix::ThreadImplPosix()::$_0::__invoke() [0x564a86f8ff53]
[Envoy (Epoch 0)] [2020-05-11 16:25:21.664][24][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #23: start_thread [0x7f40d1d846db]
AsyncClient 0x564a8ab00010, stream_id_: 12981097676272622052
&stream_info_:
  StreamInfoImpl 0x564a8ab001b0, protocol_: 1, response_code_: 200, response_code_details_: via_upstream, health_check_request_: 0, route_name_:
2020-05-11T16:25:21.789005Z	error	Epoch 0 exited with error: signal: segmentation fault (core dumped)
2020-05-11T16:25:21.789064Z	info	No more active epochs, terminating