Effective NULL dereference via TSActionCancel

[shinrich]

We had the following callstack from a crash against one of our plugins.

(gdb) bt
#0  0x00000000004ee7c0 in handle_event_count (event=1, this=<error reading variable: Cannot access memory at address 0x8>) at ../../../../../_vcs/trafficserver9/src/traffic_server/InkAPI.cc:6846
#1  TSActionCancel (actionp=0x1) at ../../../../../_vcs/trafficserver9/src/traffic_server/InkAPI.cc:6846
#2  0x00002b1023a4485e in RedirectFilterPlugin::local_callback(tsapi_cont*, TSEvent, void*) () at _vcs/redirect_filter-9/redirect_filter/redirect_filter.cc:325
#3  0x00000000004e3ec3 in INKContInternal::handle_event (this=0x2b10e91fd260, event=500, edata=0x2b10655ac800) at ../../../../../_vcs/trafficserver9/src/traffic_server/InkAPI.cc:1096
#4  0x0000000000645e11 in reply_to_cont(Continuation*, HostDBInfo*, bool) () at ../../../../../../_vcs/trafficserver9/iocore/hostdb/HostDB.cc:499
#5  0x0000000000648b11 in HostDBProcessor::getby(Continuation*, void (Continuation::*)(HostDBInfo*), HostDBHash&, HostDBProcessor::Options const&) ()
    at ../../../../../../_vcs/trafficserver9/iocore/hostdb/HostDB.cc:677
#6  0x0000000000648d6c in HostDBProcessor::getbyname_re(Continuation*, char const*, int, HostDBProcessor::Options const&) () at ../../../../../../_vcs/trafficserver9/iocore/hostdb/HostDB.cc:731
#7  0x00000000004f57ea in TSHostLookup () at ../../../../../_vcs/trafficserver9/src/traffic_server/InkAPI.cc:7281
#8  0x00002b1023a449dc in RedirectFilterPlugin::local_callback(tsapi_cont*, TSEvent, void*) () at _vcs/redirect_filter-9/redirect_filter/redirect_filter.cc:290
#9  0x00000000004e3ec3 in INKContInternal::handle_event (this=0x2b10e91fd260, event=60007, edata=0x2b107fcf1800) at ../../../../../_vcs/trafficserver9/src/traffic_server/InkAPI.cc:1096
#10 0x00000000004f672b in handleEvent (data=0x2b107fcf1800, event=60007, this=0x2b10e91fd260)
    at /sd/workspace/src/git.vzbuilders.com/Edge/build/_build/build_release_posix-x86_64_gcc_8/trafficserver9/build/../../../../_vcs/trafficserver9/iocore/eventsystem/I_Continuation.h:167
#11 handleEvent (data=0x2b107fcf1800, event=60007, this=0x2b10e91fd260)
    at /sd/workspace/src/git.vzbuilders.com/Edge/build/_build/build_release_posix-x86_64_gcc_8/trafficserver9/build/../../../../_vcs/trafficserver9/iocore/eventsystem/I_Continuation.h:163
#12 APIHook::invoke(int, void*) const () at ../../../../../_vcs/trafficserver9/src/traffic_server/InkAPI.cc:1333
#13 0x00000000005538ce in HttpSM::state_api_callout(int, void*) () at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:1476
#14 0x00000000005571d7 in HttpSM::state_api_callback (this=this@entry=0x2b107fcf1800, event=event@entry=60000, data=data@entry=0x0) at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:1347
#15 0x00000000004f86ea in TSHttpTxnReenable () at ../../../../../_vcs/trafficserver9/src/traffic_server/InkAPI.cc:6123
#16 0x00002b1018badd86 in cont_rewrite_headers (contp=<optimized out>, event=<optimized out>, edata=0x2b107fcf1800) at ../../../../../_vcs/trafficserver9/plugins/header_rewrite/header_rewrite.cc:308
#17 0x00000000004e3ec3 in INKContInternal::handle_event (this=0x2b0fed501180, event=60007, edata=0x2b107fcf1800) at ../../../../../_vcs/trafficserver9/src/traffic_server/InkAPI.cc:1096
#18 0x00000000004f672b in handleEvent (data=0x2b107fcf1800, event=60007, this=0x2b0fed501180)
    at /sd/workspace/src/git.vzbuilders.com/Edge/build/_build/build_release_posix-x86_64_gcc_8/trafficserver9/build/../../../../_vcs/trafficserver9/iocore/eventsystem/I_Continuation.h:167
#19 handleEvent (data=0x2b107fcf1800, event=60007, this=0x2b0fed501180)
    at /sd/workspace/src/git.vzbuilders.com/Edge/build/_build/build_release_posix-x86_64_gcc_8/trafficserver9/build/../../../../_vcs/trafficserver9/iocore/eventsystem/I_Continuation.h:163
#20 APIHook::invoke(int, void*) const () at ../../../../../_vcs/trafficserver9/src/traffic_server/InkAPI.cc:1333
#21 0x00000000005538ce in HttpSM::state_api_callout(int, void*) () at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:1476
#22 0x0000000000553f05 in HttpSM::do_api_callout_internal (this=this@entry=0x2b107fcf1800) at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:5245
#23 0x000000000055e0b3 in HttpSM::set_next_state (this=0x2b107fcf1800) at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:7529
#24 0x0000000000546ed2 in HttpSM::call_transact_and_set_next_state (this=this@entry=0x2b107fcf1800, f=f@entry=0x0) at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:7303
#25 0x00000000005579aa in HttpSM::handle_api_return (this=0x2b107fcf1800) at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:1611
#26 0x0000000000553971 in HttpSM::state_api_callout(int, void*) () at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:1543
#27 0x00000000005571d7 in HttpSM::state_api_callback (this=this@entry=0x2b107fcf1800, event=event@entry=60000, data=data@entry=0x0) at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:1347
#28 0x00000000004f86ea in TSHttpTxnReenable () at ../../../../../_vcs/trafficserver9/src/traffic_server/InkAPI.cc:6123
#29 0x00002b1018badd86 in cont_rewrite_headers (contp=<optimized out>, event=<optimized out>, edata=0x2b107fcf1800) at ../../../../../_vcs/trafficserver9/plugins/header_rewrite/header_rewrite.cc:308
#30 0x00000000004e3ec3 in INKContInternal::handle_event (this=0x2b0fed501180, event=60006, edata=0x2b107fcf1800) at ../../../../../_vcs/trafficserver9/src/traffic_server/InkAPI.cc:1096
#31 0x00000000004f672b in handleEvent (data=0x2b107fcf1800, event=60006, this=0x2b0fed501180)
    at /sd/workspace/src/git.vzbuilders.com/Edge/build/_build/build_release_posix-x86_64_gcc_8/trafficserver9/build/../../../../_vcs/trafficserver9/iocore/eventsystem/I_Continuation.h:167
#32 handleEvent (data=0x2b107fcf1800, event=60006, this=0x2b0fed501180)
    at /sd/workspace/src/git.vzbuilders.com/Edge/build/_build/build_release_posix-x86_64_gcc_8/trafficserver9/build/../../../../_vcs/trafficserver9/iocore/eventsystem/I_Continuation.h:163
#33 APIHook::invoke(int, void*) const () at ../../../../../_vcs/trafficserver9/src/traffic_server/InkAPI.cc:1333
#34 0x00000000005538ce in HttpSM::state_api_callout(int, void*) () at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:1476
#35 0x00000000005542c8 in HttpSM::state_read_server_response_header (this=0x2b107fcf1800, event=100, data=0x2b104a7668d8) at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:2009
#36 0x00000000005560e3 in main_handler (data=0x2b104a7668d8, event=100, this=0x2b107fcf1800) at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:2626
#37 HttpSM::main_handler (this=0x2b107fcf1800, event=100, data=0x2b104a7668d8) at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:2596
#38 0x000000000072b893 in handleEvent (data=0x2b104a7668d8, event=100, this=0x2b107fcf1800)
    at /sd/workspace/src/git.vzbuilders.com/Edge/build/_build/build_release_posix-x86_64_gcc_8/trafficserver9/build/../../../../_vcs/trafficserver9/iocore/eventsystem/I_Continuation.h:167
#39 handleEvent (data=0x2b104a7668d8, event=100, this=0x2b107fcf1800)
    at /sd/workspace/src/git.vzbuilders.com/Edge/build/_build/build_release_posix-x86_64_gcc_8/trafficserver9/build/../../../../_vcs/trafficserver9/iocore/eventsystem/I_Continuation.h:163
#40 read_signal_and_update (vc=vc@entry=0x2b104a766700, event=event@entry=100) at ../../../../../../_vcs/trafficserver9/iocore/net/UnixNetVConnection.cc:83
#41 UnixNetVConnection::readSignalAndUpdate (this=this@entry=0x2b104a766700, event=event@entry=100) at ../../../../../../_vcs/trafficserver9/iocore/net/UnixNetVConnection.cc:1014
#42 0x000000000070348a in SSLNetVConnection::net_read_io(NetHandler*, EThread*) () at ../../../../../../_vcs/trafficserver9/iocore/net/SSLNetVConnection.cc:672
#43 0x000000000071fa0e in NetHandler::process_ready_list (this=this@entry=0x2b0fed8e10c0) at ../../../../../../_vcs/trafficserver9/iocore/net/UnixNet.cc:413
#44 0x000000000071fe80 in NetHandler::waitForActivity(long) () at ../../../../../../_vcs/trafficserver9/iocore/net/UnixNet.cc:548
#45 0x000000000076b651 in EThread::execute_regular (this=this@entry=0x2b0fed8dd040) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/I_PriorityEventQueue.h:115
#46 0x000000000076b8a6 in execute (this=0x2b0fed8dd040) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/UnixEThread.cc:332
---Type <return> to continue, or q <return> to quit---
#47 EThread::execute (this=0x2b0fed8dd040) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/UnixEThread.cc:310
#48 0x0000000000769b29 in spawn_thread_internal (a=0x2b0fe9ce1100) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/Thread.cc:92
#49 0x00002b0fe809eea5 in start_thread () from /lib64/libpthread.so.0
#50 0x00002b0fe8dd48dd in clone () from /lib64/libc.so.6
(gdb) frame 2
#2  0x00002b1023a4485e in RedirectFilterPlugin::local_callback(tsapi_cont*, TSEvent, void*) () at _vcs/redirect_filter-9/redirect_filter/redirect_filter.cc:325
325	_vcs/redirect_filter-9/redirect_filter/redirect_filter.cc: No such file or directory.
(gdb) print cdata
$13 = (RedirectFilterPlugin::ContinuationData *) 0x2b0ff89b7a00
(gdb) print cdata[0]
$14 = {clientRequestHost = "ecp.yusercontent.com", txnp = 0x2b107fcf1800, lookup_actionp = 0x0, timeout_actionp = 0x1}
(gdb) 

The immediate cause for the crash is that timeout_actionp is 1. This really means it is null, because the TSAPI calls that return actions or in 0x1 to mark that the action is associated with an InkContInternal continuation. So easy enough to fix the TSActionCancel() logic to check for a null after removing the bottom bit.

It is a bit confusing how our plugin could have gotten into this state, but it seems reasonable to augment TSActionCancel to protect itself in this scenario.

[shinrich]

Just ran into another crash today due to an action pointer set to 1

(gdb) 
#0  HttpSM::kill_this() () at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:6932
#1  0x0000000000555fd0 in main_handler (data=0x2b93a4ae32d8, event=104, this=0x2b9447a97000) at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:2639
#2  HttpSM::main_handler (this=0x2b9447a97000, event=104, data=0x2b93a4ae32d8) at ../../../../../../_vcs/trafficserver9/proxy/http/HttpSM.cc:2596
#3  0x000000000072b6c3 in handleEvent (data=0x2b93a4ae32d8, event=104, this=0x2b9447a97000)
    at /sd/workspace/src/git.vzbuilders.com/Edge/build/_build/build_release_posix-x86_64_gcc_8/trafficserver9/build/../../../../_vcs/trafficserver9/iocore/eventsystem/I_Continuation.h:167
#4  handleEvent (data=0x2b93a4ae32d8, event=104, this=0x2b9447a97000)
    at /sd/workspace/src/git.vzbuilders.com/Edge/build/_build/build_release_posix-x86_64_gcc_8/trafficserver9/build/../../../../_vcs/trafficserver9/iocore/eventsystem/I_Continuation.h:163
#5  read_signal_and_update (vc=0x2b93a4ae3100, event=104) at ../../../../../../_vcs/trafficserver9/iocore/net/UnixNetVConnection.cc:83
#6  read_signal_done (vc=0x2b93a4ae3100, nh=0x2b92ce25f280, event=event@entry=104) at ../../../../../../_vcs/trafficserver9/iocore/net/UnixNetVConnection.cc:146
#7  UnixNetVConnection::readSignalDone (this=this@entry=0x2b93a4ae3100, event=event@entry=104, nh=nh@entry=0x2b92ce25f280)
    at ../../../../../../_vcs/trafficserver9/iocore/net/UnixNetVConnection.cc:1008
#8  0x00000000007035e5 in SSLNetVConnection::net_read_io(NetHandler*, EThread*) () at ../../../../../../_vcs/trafficserver9/iocore/net/SSLNetVConnection.cc:714
#9  0x000000000071fafe in NetHandler::process_ready_list (this=this@entry=0x2b92ce25f280) at ../../../../../../_vcs/trafficserver9/iocore/net/UnixNet.cc:413
#10 0x000000000071ff70 in NetHandler::waitForActivity(long) () at ../../../../../../_vcs/trafficserver9/iocore/net/UnixNet.cc:548
#11 0x000000000076b641 in EThread::execute_regular (this=this@entry=0x2b92ce25b200) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/I_PriorityEventQueue.h:115
#12 0x000000000076b896 in execute (this=0x2b92ce25b200) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/UnixEThread.cc:332
#13 EThread::execute (this=0x2b92ce25b200) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/UnixEThread.cc:310
#14 0x0000000000769b19 in spawn_thread_internal (a=0x2b92c8abea00) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/Thread.cc:92
#15 0x00002b92c6fb2dd5 in start_thread () from /lib64/libpthread.so.0
#16 0x00002b92c7ce802d in clone () from /lib64/libc.so.6
(gdb) print pending_action
$3 = (Action *) 0x1

This particular crash I think is due to PR #4921. Judging from the number of threads in the core the system was shutting down.

In that case I think we should either redefine ACTION_RESULT_NONE to 0 or have UnixNetProcessor::connect_re_internal return nullptr.