Hi, istio community,
We were running the wasm filter with V8 runtime but encountered a high memory usage problem. So we tried to move our wasm filter into istio/proxy and use the NullVM to run it. This change succeeded in bringing our customized filter into istio/proxy binary. But by doing so, we have a new crash happens. We’re not sure its root cause.
Sidecar crash logs
[2021-06-09 08:44:22.298][20][trace][http] [external/envoy/source/common/http/filter_manager.cc:463] [C3][S2233450314024706697] decode headers called: filter=0x55b43bc803c0 status=0
[2021-06-09 08:44:22.298][20][debug][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1145] wasm log: [policy/context.cc:170]::ResumeRequest() continue request with id 6 route frontend-ddd7c64f-gv6sf:default -> productcatalogservice-5f5bdd7bd4-t26qm:default
[2021-06-09 08:44:22.298][20][trace][http] [external/envoy/source/common/http/filter_manager.cc:54] [C3][S2233450314024706697] continuing filter chain: filter=0x55b43bfb3da0
[2021-06-09 08:44:22.298][20][critical][assert] [external/envoy/source/common/http/filter_manager.cc:56] assert failure: !canIterate(). Details: Attempting to continue iteration while the IterationState is already Continue
[2021-06-09 08:44:22.298][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:104] Caught Aborted, suspect faulting address 0x5390000000c
[2021-06-09 08:44:22.298][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:91] Backtrace (use tools/stack_decode.py to get line numbers):
[2021-06-09 08:44:22.298][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:92] Envoy version: 0/1.16.1//DEBUG/BoringSSL
[2021-06-09 08:44:22.298][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #0: __restore_rt [0x7fde28f84730]
[2021-06-09 08:44:22.306][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #1: proxy_wasm::WasmBase::doAfterVmCallActions() [0x55b4375b7ddb]
[2021-06-09 08:44:22.315][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #2: proxy_wasm::ContextBase::onRequestHeaders() [0x55b4375bbb4e]
[2021-06-09 08:44:22.323][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #3: Envoy::Extensions::Common::Wasm::Context::decodeHeaders() [0x55b4374efe24]
[2021-06-09 08:44:22.331][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #4: Envoy::Http::FilterManager::decodeHeaders() [0x55b438ac4317]
[2021-06-09 08:44:22.340][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #5: Envoy::Http::ConnectionManagerImpl::ActiveStream::decodeHeaders() [0x55b438ab2ed4]
[2021-06-09 08:44:22.349][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #6: Envoy::Http::Legacy::Http2::ConnectionImpl::onFrameReceived() [0x55b438b0cd84]
[2021-06-09 08:44:22.357][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #7: session_call_on_frame_received [0x55b438d02142]
[2021-06-09 08:44:22.365][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #8: session_after_header_block_received [0x55b438d07f17]
[2021-06-09 08:44:22.374][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #9: nghttp2_session_mem_recv [0x55b438d05a6b]
[2021-06-09 08:44:22.382][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #10: Envoy::Http::Legacy::Http2::ConnectionImpl::innerDispatch() [0x55b438b0b5cb]
[2021-06-09 08:44:22.390][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #11: Envoy::Http::Legacy::Http2::ServerConnectionImpl::innerDispatch() [0x55b438b15155]
[2021-06-09 08:44:22.398][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #12: std::__1::__function::__func<>::operator()() [0x55b438b1a896]
[2021-06-09 08:44:22.407][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #13: Envoy::Http::Utility::exceptionToStatus() [0x55b438ca3fb7]
[2021-06-09 08:44:22.415][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #14: Envoy::Http::Legacy::Http2::ServerConnectionImpl::dispatch() [0x55b438b14e9a]
[2021-06-09 08:44:22.425][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #15: Envoy::Http::ConnectionManagerImpl::onData() [0x55b438aac00c]
[2021-06-09 08:44:22.436][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #16: Envoy::Network::FilterManagerImpl::onContinueReading() [0x55b4387229a6]
[2021-06-09 08:44:22.449][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #17: Envoy::Network::ConnectionImpl::onReadReady() [0x55b43871bc5d]
[2021-06-09 08:44:22.460][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #18: Envoy::Network::ConnectionImpl::onFileEvent() [0x55b438718d90]
[2021-06-09 08:44:22.470][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #19: Envoy::Event::FileEventImpl::assignEvents()::$_1::__invoke() [0x55b438709292]
[2021-06-09 08:44:22.480][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #20: event_persist_closure [0x55b438ce53de]
[2021-06-09 08:44:22.492][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #21: event_process_active_single_queue [0x55b438ce4a08]
[2021-06-09 08:44:22.503][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #22: event_process_active [0x55b438cdf1ca]
[2021-06-09 08:44:22.515][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #23: event_base_loop [0x55b438cde07c]
[2021-06-09 08:44:22.526][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #24: Envoy::Server::WorkerImpl::threadRoutine() [0x55b4386f040e]
[2021-06-09 08:44:22.538][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #25: Envoy::Thread::ThreadImplPosix::ThreadImplPosix()::{lambda()#1}::__invoke() [0x55b438f51623]
[2021-06-09 08:44:22.538][20][critical][backtrace] [bazel-out/k8-fastbuild/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #26: start_thread [0x7fde28f79fa3]
ActiveStream 0x55b43bc33400, stream_id_: 2233450314024706697&filter_manager_:
FilterManager 0x55b43bc33478, state_.has_continue_headers_: 0, state_.decoding_headers_only_: 0, state_.encoding_headers_only_: 0
filter_manager_callbacks_.requestHeaders():
':method', 'POST'
':scheme', 'http'
':path', '/hipstershop.ProductCatalogService/GetProduct'
':authority', 'productcatalogservice:3550'
'content-type', 'application/grpc'
'user-agent', 'grpc-go/1.22.0'
'te', 'trailers'
'grpc-trace-bin', 'AAAszPlryKu4LV/yTu4I8Y52AXAPHI/OOgZ7AgE'
'x-forwarded-proto', 'http'
'x-request-id', 'f3eb17fd-4dc7-4d8e-bf73-1bbc5067f835'
'x-glasnostic-service-name', 'frontend-ddd7c64f-gv6sf'
'x-glasnostic-pod-namespace', 'default'
filter_manager_callbacks_.requestTrailers(): empty
filter_manager_callbacks_.responseHeaders(): empty
filter_manager_callbacks_.responseTrailers(): empty
&stream_info_:
StreamInfoImpl 0x55b43bc33550, protocol_: 2, response_code_: null, response_code_details_: null, health_check_request_: 0, route_name_:
/usr/local/bin/bootstrap.sh: line 86: 12 Aborted (core dumped) /usr/local/bin/envoy -c $HOME/bootstrap.yaml -l $LOG_LEVEL --concurrency 2
When we moved our wasm filter into istio/proxy, we changed the wasm SDK version from a96408d (wasm) → 7afb39d (sidecar =~ istio/envoy@1.8.1) for compiling it. Not sure it’s related. But we’re also trying to downgrade the SDK version.
Does anyone have some idea about it?