segfault in ActiveStreamFilterBase::commonContinue() #7595
Description
1.11 was released a few days ago and my Envoy configuration doesn't work ever since I upgraded from 1.10.
My configuration is based on a Lua filter that makes a few HTTP calls and updates upstream request and client response. Since the last upgrade, Envoy crashes at the very end of every request.
Here is the stacktrace I get :
[2019-07-15 15:16:11.594][108][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:582] script log: - END call my.app.module - API ack
[2019-07-15 15:16:11.594][108][debug][lua] [source/extensions/filters/common/lua/lua.cc:37] coroutine finished
[2019-07-15 15:16:11.594][108][trace][lua] [bazel-out/k8-opt/bin/source/extensions/filters/common/lua/_virtual_includes/lua_lib/extensions/filters/common/lua/lua.h:183] marking dead N5Envoy10Extensions11HttpFilters3Lua19StreamHandleWrapperE at 0x40fa8bf8
[2019-07-15 15:16:11.594][108][trace][lua] [bazel-out/k8-opt/bin/source/extensions/filters/common/lua/_virtual_includes/lua_lib/extensions/filters/common/lua/lua.h:183] marking dead N5Envoy10Extensions11HttpFilters3Lua16HeaderMapWrapperE at 0x40fa9368
[2019-07-15 15:16:11.594][108][trace][http] [source/common/http/conn_manager_impl.cc:1740] [C0][S14027106735730752972] continuing filter chain: filter=0x2b47090
[2019-07-15 15:16:11.594][108][debug][http] [source/common/http/conn_manager_impl.cc:1415] [C0][S14027106735730752972] encoding headers via codec (end_stream=true):
':status', '200'
'x-app-message', '{"operationId":"eac2bb0c-0088-45fa-89fa-576f083b5e3e","status":"success","timestamp":"2019-07-15T15:16:11.592+0000"}'
'date', 'Mon, 15 Jul 2019 15:16:11 GMT'
'server', 'envoy'
[2019-07-15 15:16:11.594][108][trace][connection] [source/common/network/connection_impl.cc:392] [C0] writing 224 bytes, end_stream false
[2019-07-15 15:16:11.594][108][trace][main] [source/common/event/dispatcher_impl.cc:158] item added to deferred deletion list (size=2)
[2019-07-15 15:16:11.594][108][trace][connection] [source/common/network/connection_impl.cc:288] [C0] readDisable: enabled=false disable=false
[2019-07-15 15:16:11.594][108][trace][http] [source/common/http/conn_manager_impl.cc:1553] [C0][S14027106735730752972] encoding data via codec (size=0 end_stream=true)
[2019-07-15 15:16:11.594][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:81] Caught Segmentation fault, suspect faulting address 0x20
[2019-07-15 15:16:11.594][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:69] Backtrace (use tools/stack_decode.py to get line numbers):
[2019-07-15 15:16:11.594][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #0: [0x7fe36c7074b0]
[2019-07-15 15:16:11.596][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #1: Envoy::Http::ConnectionManagerImpl::ActiveStreamFilterBase::commonContinue() [0xe33d10] source/common/http/conn_manager_impl.cc:1782
[2019-07-15 15:16:11.597][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #2: Envoy::Extensions::HttpFilters::Lua::StreamHandleWrapper::onSuccses() [0x880afd] source/extensions/filters/http/lua/lua_filter.cc:?
[2019-07-15 15:16:11.598][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #3: Envoy::Http::AsyncRequestImpl::onData() [0xdd1be3] /usr/lib/gcc/x86_64-linux-gnu/7.4.0/../../../../include/c++/7.4.0/bits/unique_ptr.h:267
(inlined by) source/common/http/async_client_impl.cc:193
(inlined by) source/common/http/async_client_impl.cc:210
[2019-07-15 15:16:11.600][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #4: Envoy::Http::AsyncStreamImpl::encodeData() [0xdd1484] source/common/http/async_client_impl.cc:102
[2019-07-15 15:16:11.601][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #5: Envoy::Http::StreamDecoderWrapper::decodeData() [0xd60e1c] bazel-out/k8-opt/bin/source/common/http/_virtual_includes/codec_wrappers_lib/common/http/codec_wrappers.h:38
[2019-07-15 15:16:11.601][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #6: Envoy::Http::StreamDecoderWrapper::decodeData() [0xd60e1c] bazel-out/k8-opt/bin/source/common/http/_virtual_includes/codec_wrappers_lib/common/http/codec_wrappers.h:38
[2019-07-15 15:16:11.602][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #7: Envoy::Http::Http1::ClientConnectionImpl::onMessageComplete() [0xe4168e] bazel-out/k8-opt/bin/source/common/buffer/_virtual_includes/buffer_lib/common/buffer/buffer_impl.h:480
(inlined by) source/common/http/http1/codec_impl.cc:768
[2019-07-15 15:16:11.603][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #8: Envoy::Http::Http1::ConnectionImpl::onMessageCompleteBase() [0xe3f109] source/common/http/http1/codec_impl.cc:476
[2019-07-15 15:16:11.605][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #9: Envoy::Http::Http1::ConnectionImpl::$_7::__invoke() [0xe42a4d] source/common/http/http1/codec_impl.cc:309
[2019-07-15 15:16:11.606][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #10: http_parser_execute [0xfd78b0] ??:?
[2019-07-15 15:16:11.607][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #11: Envoy::Http::Http1::ConnectionImpl::dispatchSlice() [0xe3e9a5] source/common/http/http1/codec_impl.cc:397
[2019-07-15 15:16:11.608][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #12: Envoy::Http::Http1::ConnectionImpl::dispatch() [0xe3e78f] source/common/http/http1/codec_impl.cc:381
[2019-07-15 15:16:11.610][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #13: Envoy::Http::CodecClient::onData() [0xdc1286] source/common/http/codec_client.cc:135
[2019-07-15 15:16:11.611][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #14: Envoy::Http::CodecClient::CodecReadFilter::onData() [0xdc1d1d] bazel-out/k8-opt/bin/source/common/http/_virtual_includes/codec_client_lib/common/http/codec_client.h:173
[2019-07-15 15:16:11.612][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #15: Envoy::Network::FilterManagerImpl::onContinueReading() [0xc1cf41] source/common/network/filter_manager_impl.cc:66
[2019-07-15 15:16:11.613][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #16: Envoy::Network::ConnectionImpl::onReadReady() [0xc198fc] source/common/network/connection_impl.cc:517
[2019-07-15 15:16:11.615][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #17: Envoy::Network::ConnectionImpl::onFileEvent() [0xc193c1] source/common/network/connection_impl.cc:489
[2019-07-15 15:16:11.616][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #18: Envoy::Event::FileEventImpl::assignEvents()::$_0::__invoke() [0xc14065] source/common/event/file_event_impl.cc:49
[2019-07-15 15:16:11.617][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #19: event_process_active_single_queue [0xfc783d] event.c:?
[2019-07-15 15:16:11.618][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #20: event_base_loop [0xfc5df0] ??:?
[2019-07-15 15:16:11.620][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #21: Envoy::Server::WorkerImpl::threadRoutine() [0xc0c55c] bazel-out/k8-opt/bin/source/common/common/_virtual_includes/minimal_logger_lib/common/common/logger.h:280
(inlined by) source/server/worker_impl.cc:105
[2019-07-15 15:16:11.621][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:73] #22: Envoy::Thread::ThreadImplPosix::ThreadImplPosix()::$_0::__invoke() [0x1195205] source/common/common/posix/thread_impl.cc:32
[2019-07-15 15:16:11.621][108][critical][backtrace] [bazel-out/k8-opt/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #23: [0x7fe36c6fccf8]
And here is my configuration :
static_resources:
listeners:
- per_connection_buffer_limit_bytes: 0
address:
socket_address:
address: 0.0.0.0
port_value: 80
filter_chains:
- filters:
- name: envoy.http_connection_manager
typed_config:
"@type": type.googleapis.com/envoy.config.filter.network.http_connection_manager.v2.HttpConnectionManager
stream_idle_timeout: 0s
codec_type: auto
stat_prefix: myapp-api
route_config:
name: ups_route
virtual_hosts:
- name: upload
domains:
- "*"
routes:
- match:
regex: "^.*$"
headers:
- name: ":method"
exact_match: "PUT"
route:
cluster: ups
timeout: 0s
http_filters:
- name: envoy.lua
typed_config:
"@type": type.googleapis.com/envoy.config.filter.http.lua.v2.Lua
inline_code: |
-- Load json library
package.path = package.path .. ";/etc/envoy-dependencies/json.lua"
local json = require('json')
-- Add util local function
function contains(table, val)
for i=1,#table do
if table[i] == val then
return true
end
end
return false
end
function splitstr(inputstr, sep)
if inputstr == nil then
return nil
end
if sep == nil then
sep = "%s"
end
local t={}
for str in string.gmatch(inputstr, "([^"..sep.."]+)") do
table.insert(t, str)
end
return t
end
function envoy_on_request(request_handle)
-- Make an HTTP call to init API
request_handle:logDebug("- START call my.app.module - API init")
local headers, body = request_handle:httpCall(
"module",
{
[":method"] = "POST",
[":path"] = "/api/v1/module/init",
[":authority"] = "module",
["Content-Type"] = "application/json",
["app-content-length"] = request_handle:headers():get("content-length"),
["Authorization"] = request_handle:headers():get("Authorization")
},
json.encode(
{
["appContentLength"] = request_handle:headers():get("content-length"),
["recipientList"] = splitstr(request_handle:headers():get("Recipient"), ","),
["retention"] = request_handle:headers():get("Expiration"),
["strategy"] = request_handle:headers():get("Strategy")
}),
5000)
local streamInfo = request_handle:streamInfo()
local dynamicMetadata = streamInfo:dynamicMetadata()
dynamicMetadata:set("client","Authorization",request_handle:headers():get("Authorization"))
if request_handle:headers():get("Recipient") ~= nil then
dynamicMetadata:set("client","Recipient",request_handle:headers():get("Recipient"))
end
if request_handle:headers():get("Expiration") ~= nil then
dynamicMetadata:set("client","Expiration",request_handle:headers():get("Expiration"))
end
if request_handle:headers():get("Strategy") ~= nil then
dynamicMetadata:set("client","Strategy",request_handle:headers():get("Strategy"))
end
-- get useful parameters from response
local computedPath = json.decode(body)["proxyData"]["path"]
local computedHeaders = json.decode(body)["proxyData"]["headers"]
local requestHeaders = request_handle:headers()
local toBeRemoved = {}
local toBeKept = { "x-real-ip", "x-forwarded-for", "x-forwarded-host", "x-forwarded-port", "x-forwarded-proto", "x-original-uri", "x-scheme", "x-request-id" }
for key, value in pairs(requestHeaders) do
if not contains(toBeKept,key) then
table.insert(toBeRemoved, key)
end
end
for nameHeader = 1, #toBeRemoved do
request_handle:headers():remove(toBeRemoved[nameHeader])
end
request_handle:headers():add(":method","PUT")
request_handle:headers():add(":path", computedPath)
local app_operationid = string.match(computedPath, "/.*/(.*)")
dynamicMetadata:set("app","x-app-operationid",app_operationid)
for computedHeader = 1, #computedHeaders do
request_handle:headers():add(computedHeaders[computedHeader]["name"],computedHeaders[computedHeader]["value"])
end
request_handle:logDebug("- END call my.app.module - API init")
end
function envoy_on_response(response_handle)
if response_handle:headers():get(":status") == "200" then
local streamInfo = response_handle:streamInfo()
local dynamicMetadata = streamInfo:dynamicMetadata()
local Authorization = dynamicMetadata:get("client")["Authorization"]
local operationId = dynamicMetadata:get("app")["x-app-operationid"]
local Recipient = dynamicMetadata:get("client")["Recipient"]
local Expiration = dynamicMetadata:get("client")["Expiration"]
local Strategy = dynamicMetadata:get("client")["Strategy"]
-- Make an HTTP call to ack API
response_handle:logDebug("- START call my.app.module - API ack")
local headers, body = response_handle:httpCall(
"module",
{
[":method"] = "POST",
[":path"] = "/api/v1/module/ack",
[":authority"] = "module",
["Content-Type"] = "application/json",
["Authorization"] = Authorization
},
json.encode(
{
["operationId"] = operationId,
["recipientList"] = splitstr(Recipient, ","),
["retention"] = Expiration,
["strategy"] = Strategy
}),
5000)
response_handle:logDebug(body)
local nameHeaders = {}
local responseHeaders = response_handle:headers()
for key, value in pairs(responseHeaders) do
table.insert(nameHeaders, key)
end
for nameHeader = 1, #nameHeaders do
if string.sub(nameHeaders[nameHeader],1,1) ~= ":" then
response_handle:headers():remove(nameHeaders[nameHeader])
end
end
response_handle:headers():replace(":status",headers[":status"])
response_handle:headers():add("x-app-message",body)
response_handle:logDebug("- END call my.app.module - API ack")
else
response_handle:logDebug("Errors in previous HTTP calls, bypassing on_response filter")
response_handle:logDebug(response_handle:headers():get(":status"))
end
end
- name: envoy.router
typed_config: {}
clusters:
- name: module
connect_timeout: 10.0s
type: strict_dns
http_protocol_options:
allow_absolute_url: true
tls_context: {}
hosts:
socket_address:
address: myapp-module-demo.myapp-demo-nprod
port_value: 8080
- name: ups
connect_timeout: 10.0s
type: strict_dns
tls_context: {}
hosts:
socket_address:
address: cloud.company.com
port_value: 443
admin:
access_log_path: "/dev/null"
address:
socket_address:
address: 0.0.0.0
port_value: 8001
As you can see, the Lua filter seems to run fine until the end; the first line of the logs snippet is the last thing logged in the Lua script.
I'm not 100% sure but I guess the segfault occurs in this version of conn_manager_impl
We temporarily fixed this problem by rollbacking to 1.10 but we'd like to understand this error in order to make sure we're not doing anything wrong (still new to Envoy).