Crash in OutboundConnTrack - per_server.connection.max

[c-taylor]

I will try to repro this in a controlled environment, but sharing the stack trace early...

ATS 9.0.1
Crash/trace shortly after per_server.connection.max triggered WARNING messages.

This appeared after 1-2h of load:

/some/path/bin/traffic_server(crash_logger_invoke(int, siginfo_t*, void*)+0x99)[0x559787130dc9]
/lib64/libpthread.so.0(+0xf630)[0x7f4e0247b630]
/some/path/bin/traffic_server(OutboundConnTrack::TxnState::Warn_Blocked(OutboundConnTrack::TxnConfig const*, long, int, sockaddr const*, char const*)+0x41)[0x55978718cd11]
/some/path/bin/traffic_server(HttpSM::do_http_server_open(bool)+0x1455)[0x55978719a745]
/some/path/bin/traffic_server(HttpSM::set_next_state()+0x32e)[0x5597871b089e]
/some/path/bin/traffic_server(HttpSM::send_origin_throttled_response()+0x10e)[0x5597871a2d2e]
/some/path/bin/traffic_server(HttpSM::do_http_server_open(bool)+0x12d8)[0x55978719a5c8]
/some/path/bin/traffic_server(HttpSM::set_next_state()+0x32e)[0x5597871b089e]
/some/path/bin/traffic_server(HttpSM::call_transact_and_set_next_state(void (*)(HttpTransact::State*))+0x10c)[0x559787196bfc]
/some/path/bin/traffic_server(HttpSM::state_cache_open_write(int, void*)+0x3f5)[0x5597871a68a5]
/some/path/bin/traffic_server(HttpSM::main_handler(int, void*)+0x1b1)[0x5597871937b1]
/some/path/bin/traffic_server(HttpCacheSM::state_cache_open_write(int, void*)+0x48a)[0x5597871ee44a]
/some/path/bin/traffic_server(CacheVC::callcont(int)+0x7b)[0x5597872d4b9b]
/some/path/bin/traffic_server(Cache::open_write(Continuation*, ats::CryptoHash const*, HTTPInfo*, long, ats::CryptoHash const*, CacheFragType, char const*, int)+0x40e)[0x5597872de97e]
/some/path/bin/traffic_server(CacheProcessor::open_write(Continuation*, int, HttpCacheKey const*, HTTPHdr*, HTTPInfo*, long, CacheFragType)+0x3a)[0x5597872ba35a]
/some/path/bin/traffic_server(HttpCacheSM::open_write(HttpCacheKey const*, URL*, HTTPHdr*, HTTPInfo*, long, bool, bool)+0x116)[0x5597871ee786]
/some/path/bin/traffic_server(HttpSM::do_cache_prepare_action(HttpCacheSM*, HTTPInfo*, bool, bool)+0x218)[0x5597871ad6d8]
/some/path/bin/traffic_server(HttpSM::set_next_state()+0x5bb)[0x5597871b0b2b]
/some/path/bin/traffic_server(HttpSM::call_transact_and_set_next_state(void (*)(HttpTransact::State*))+0x10c)[0x559787196bfc]
/some/path/bin/traffic_server(HttpSM::do_hostdb_lookup()+0x6a3)[0x5597871abf43]
/some/path/bin/traffic_server(HttpSM::set_next_state()+0x1191)[0x5597871b1701]
/some/path/bin/traffic_server(HttpSM::call_transact_and_set_next_state(void (*)(HttpTransact::State*))+0x10c)[0x559787196bfc]
/some/path/bin/traffic_server(HttpSM::state_api_callout(int, void*)+0x287)[0x55978719c707]
/some/path/bin/traffic_server(HttpSM::state_api_callback(int, void*)+0x1f7)[0x55978719c427]
/some/path/bin/traffic_server(TSHttpTxnReenable+0x1d3)[0x55978714ad93]
/var/run/trafficserver/5e386dbb-1989-4f9c-9417-c92047a73a0d/some/path/lib/trafficserver/plugins/cache_promote.so(+0x55bc)[0x7f4d83bf05bc]
/some/path/bin/traffic_server(INKContInternal::handle_event(int, void*)+0xde)[0x55978713c9ae]
/some/path/bin/traffic_server(APIHook::invoke(int, void*) const+0xe0)[0x55978713d960]
/some/path/bin/traffic_server(HttpSM::state_api_callout(int, void*)+0xc5d)[0x55978719d0dd]
/some/path/bin/traffic_server(HttpSM::state_api_callback(int, void*)+0x1f7)[0x55978719c427]
/some/path/bin/traffic_server(TSHttpTxnReenable+0x1d3)[0x55978714ad93]
/some/path/lib/trafficserver/plugins/xdebug.so(+0x63b8)[0x7f4ded1f33b8]
/some/path/bin/traffic_server(INKContInternal::handle_event(int, void*)+0xde)[0x55978713c9ae]
/some/path/bin/traffic_server(APIHook::invoke(int, void*) const+0xe0)[0x55978713d960]
/some/path/bin/traffic_server(HttpSM::state_api_callout(int, void*)+0xc5d)[0x55978719d0dd]
/some/path/bin/traffic_server(HttpSM::state_cache_open_read(int, void*)+0x46b)[0x5597871a6e8b]
/some/path/bin/traffic_server(HttpSM::main_handler(int, void*)+0x1b1)[0x5597871937b1]
/some/path/bin/traffic_server(HttpCacheSM::state_cache_open_read(int, void*)+0x322)[0x5597871edc92]
/some/path/bin/traffic_server(Cache::open_read(Continuation*, ats::CryptoHash const*, HTTPHdr*, OverridableHttpConfigParams const*, CacheFragType, char const*, int)+0xca)[0x5597872d091a]
/some/path/bin/traffic_server(CacheProcessor::open_read(Continuation*, HttpCacheKey const*, HTTPHdr*, OverridableHttpConfigParams const*, long, CacheFragType)+0x27)[0x5597872ba317]
/some/path/bin/traffic_server(HttpCacheSM::open_read(HttpCacheKey const*, URL*, HTTPHdr*, OverridableHttpConfigParams const*, long)+0xbd)[0x5597871ee88d]
/some/path/bin/traffic_server(HttpSM::do_cache_lookup_and_read()+0x210)[0x5597871ad300]
/some/path/bin/traffic_server(HttpSM::set_next_state()+0x243)[0x5597871b07b3]
/some/path/bin/traffic_server(HttpSM::call_transact_and_set_next_state(void (*)(HttpTransact::State*))+0x10c)[0x559787196bfc]
/some/path/bin/traffic_server(HttpSM::state_api_callout(int, void*)+0x287)[0x55978719c707]
/some/path/bin/traffic_server(HttpSM::set_next_state()+0xe84)[0x5597871b13f4]
/some/path/bin/traffic_server(HttpSM::call_transact_and_set_next_state(void (*)(HttpTransact::State*))+0x10c)[0x559787196bfc]
/some/path/bin/traffic_server(HttpSM::set_next_state()+0x11d2)[0x5597871b1742]
/some/path/bin/traffic_server(HttpSM::call_transact_and_set_next_state(void (*)(HttpTransact::State*))+0x10c)[0x559787196bfc]
/some/path/bin/traffic_server(HttpSM::state_api_callout(int, void*)+0x287)[0x55978719c707]
/some/path/bin/traffic_server(HttpSM::set_next_state()+0xe84)[0x5597871b13f4]
/some/path/bin/traffic_server(HttpSM::call_transact_and_set_next_state(void (*)(HttpTransact::State*))+0x10c)[0x559787196bfc]
/some/path/bin/traffic_server(HttpSM::state_api_callout(int, void*)+0x287)[0x55978719c707]
/some/path/bin/traffic_server(HttpSM::state_api_callback(int, void*)+0x1f7)[0x55978719c427]
/some/path/bin/traffic_server(TSHttpTxnReenable+0x1d3)[0x55978714ad93]
/some/path/lib/trafficserver/plugins/xdebug.so(+0x6dad)[0x7f4ded1f3dad]
/some/path/bin/traffic_server(INKContInternal::handle_event(int, void*)+0xde)[0x55978713c9ae]
/some/path/bin/traffic_server(APIHook::invoke(int, void*) const+0xe0)[0x55978713d960]
/some/path/bin/traffic_server(HttpSM::state_api_callout(int, void*)+0xc5d)[0x55978719d0dd]
/some/path/bin/traffic_server(HttpSM::state_api_callback(int, void*)+0x1f7)[0x55978719c427]
/some/path/bin/traffic_server(TSHttpTxnReenable+0x1d3)[0x55978714ad93]
/some/path/lib/trafficserver/plugins/healthchecks.so(+0x220c)[0x7f4dee55a20c]
/some/path/bin/traffic_server(INKContInternal::handle_event(int, void*)+0xde)[0x55978713c9ae]
/some/path/bin/traffic_server(APIHook::invoke(int, void*) const+0xe0)[0x55978713d960]
/some/path/bin/traffic_server(HttpSM::state_api_callout(int, void*)+0xc5d)[0x55978719d0dd]
/some/path/bin/traffic_server(HttpSM::state_api_callback(int, void*)+0x1f7)[0x55978719c427]
/some/path/bin/traffic_server(TSHttpTxnReenable+0x1d3)[0x55978714ad93]
/some/path/lib/trafficserver/plugins/header_rewrite.so(+0x1ed2b)[0x7f4deebe3d2b]
/some/path/bin/traffic_server(INKContInternal::handle_event(int, void*)+0xde)[0x55978713c9ae]
/some/path/bin/traffic_server(APIHook::invoke(int, void*) const+0xe0)[0x55978713d960]
/some/path/bin/traffic_server(HttpSM::state_api_callout(int, void*)+0xc5d)[0x55978719d0dd]
/some/path/bin/traffic_server(HttpSM::state_api_callback(int, void*)+0x1f7)[0x55978719c427]
/some/path/bin/traffic_server(TSHttpTxnReenable+0x1d3)[0x55978714ad93]
/some/path/lib/trafficserver/plugins/stats_over_http.so(+0x1b8b)[0x7f4deedfbb8b]
/some/path/bin/traffic_server(INKContInternal::handle_event(int, void*)+0xde)[0x55978713c9ae]
/some/path/bin/traffic_server(APIHook::invoke(int, void*) const+0xe0)[0x55978713d960]
/some/path/bin/traffic_server(HttpSM::state_api_callout(int, void*)+0xc5d)[0x55978719d0dd]
/some/path/bin/traffic_server(HttpSM::set_next_state()+0xe84)[0x5597871b13f4]
/some/path/bin/traffic_server(HttpSM::state_read_client_request_header(int, void*)+0xe28)[0x559787195728]
/some/path/bin/traffic_server(HttpSM::main_handler(int, void*)+0x1b1)[0x5597871937b1]
/some/path/bin/traffic_server(HttpSM::state_api_callout(int, void*)+0x287)[0x55978719c707]
/some/path/bin/traffic_server(HttpSM::state_add_to_list(int, void*)+0x49)[0x559787193889]
/some/path/bin/traffic_server(HttpSM::attach_client_session(ProxyTransaction*, IOBufferReader*)+0x8c2)[0x559787194882]
/some/path/bin/traffic_server(ProxyTransaction::new_transaction(bool)+0x1db)[0x55978731917b]
/some/path/bin/traffic_server(Http1ClientSession::state_keep_alive(int, void*)+0x151)[0x559787180411]
/some/path/bin/traffic_server(PluginVC::process_read_side(bool)+0x419)[0x559787313de9]
/some/path/bin/traffic_server(PluginVC::process_write_side(bool)+0x570)[0x559787314670]
/some/path/bin/traffic_server(PluginVC::main_handler(int, void*)+0x4ca)[0x559787312e0a]
/some/path/bin/traffic_server(EThread::process_event(Event*, int)+0x154)[0x55978737ff64]
/some/path/bin/traffic_server(EThread::process_queue(Queue<Event, Event::Link_link>*, int*, int*)+0xef)[0x55978738023f]
/some/path/bin/traffic_server(EThread::execute_regular()+0x1ab)[0x55978738062b]
/some/path/bin/traffic_server(EThread::execute()+0x10a)[0x559787380aca]
/some/path/bin/traffic_server(+0x3406cb)[0x55978737f6cb]
/lib64/libpthread.so.0(+0x7ea5)[0x7f4e02473ea5]
/lib64/libc.so.6(clone+0x6d)[0x7f4e018858dd]
traffic_manager ERROR: [LocalManager::sendMgmtMsgToProcesses] Error writing message
traffic_manager ERROR: last system error 104: Connection reset by peer
Alarm Message: The TS-TM connection is broken for some reason. Either restart TS and TM or correct this error for TM to display TS statistics correctly
traffic_manager NOTE: [LocalManager::pollMgmtProcessServer] Server Process terminated due to Sig 11: Segmentation fault
traffic_manager NOTE: [Alarms::signalAlarm] Server Process was reset

[SolidWallOfCode]

A "bt full" would be useful, although I would really only need the bottom 4-5 frames (particularly the arguments to Warn_Blocked).

OTOH, consider the bottom of the stack

/some/path/bin/traffic_server(OutboundConnTrack::TxnState::Warn_Blocked(OutboundConnTrack::TxnConfig const*, long, int, sockaddr const*, char const*)+0x41)[0x55978718cd11]
/some/path/bin/traffic_server(HttpSM::do_http_server_open(bool)+0x1455)[0x55978719a745]
/some/path/bin/traffic_server(HttpSM::set_next_state()+0x32e)[0x5597871b089e]
/some/path/bin/traffic_server(HttpSM::send_origin_throttled_response()+0x10e)[0x5597871a2d2e]
/some/path/bin/traffic_server(HttpSM::do_http_server_open(bool)+0x12d8)[0x55978719a5c8]

Why is HttpSM::do_http_server_open on the stack twice? We should look at that.

[vmamidi]

A "bt full" would be useful, although I would really only need the bottom 4-5 frames (particularly the arguments to Warn_Blocked).

OTOH, consider the bottom of the stack

/some/path/bin/traffic_server(OutboundConnTrack::TxnState::Warn_Blocked(OutboundConnTrack::TxnConfig const*, long, int, sockaddr const*, char const*)+0x41)[0x55978718cd11]
/some/path/bin/traffic_server(HttpSM::do_http_server_open(bool)+0x1455)[0x55978719a745]
/some/path/bin/traffic_server(HttpSM::set_next_state()+0x32e)[0x5597871b089e]
/some/path/bin/traffic_server(HttpSM::send_origin_throttled_response()+0x10e)[0x5597871a2d2e]
/some/path/bin/traffic_server(HttpSM::do_http_server_open(bool)+0x12d8)[0x55978719a5c8]

Why is HttpSM::do_http_server_open on the stack twice? We should look at that.

I think this can happen if the request is going to a parent. When number of "origin server" grouped connections to a parent reaches maximum, next parent configured for that origin server.

void
HttpSM::send_origin_throttled_response()
{
// if the request is to a parent proxy, do not reset
// t_state.current.attempts so that another parent or
// NextHop may be tried.
if (t_state.current.request_to != HttpTransact::PARENT_PROXY) {
t_state.current.attempts = t_state.txn_conf->connect_attempts_max_retries;
}
t_state.current.state = HttpTransact::OUTBOUND_CONGESTION;
call_transact_and_set_next_state(HttpTransact::HandleResponse);
}