Next hop strategy with bad 'to' URL causes TS crash

[ywkaras]

Here is the trace output:

[Apr 23 17:20:39.860] [ET_NET 3] DEBUG: <HttpTransact.cc:3683 (handle_response_from_parent)> (http_trans) [0] [handle_response_from_parent] 1 per parent attempts exhausted
[Apr 23 17:20:39.861] [ET_NET 3] DEBUG: <NextHopConsistentHash.cc:248 (findNextHop)> (next_hop) [0] not firstcall, line_number: 0, result: PARENT_SPECIFIED
[Apr 23 17:20:39.861] [ET_NET 3] DEBUG: <NextHopConsistentHash.cc:190 (getHashKey)> (next_hop) [0] the parent selection over-ride url is not set, using default path: objwrong.comhttp://wrong.com/obj.
[Apr 23 17:20:39.861] [ET_NET 3] DEBUG: <NextHopConsistentHash.cc:290 (findNextHop)> (next_hop) [0] Initial parent lookups: 2723
traffic_server: received signal 11 (Segmentation fault)
traffic_server - STACK TRACE: 
traffic_server(_Z19crash_logger_invokeiP9siginfo_tPv+0x8e)[0x4fde2e]
/lib64/libpthread.so.0(+0xf680)[0x7fad331bf680]
traffic_server(_ZN21NextHopConsistentHash11findNextHopEP13tsapi_httptxnPvl+0x889)[0x634c79]
traffic_server[0x5d2c38]
traffic_server(_ZN12HttpTransact27handle_response_from_parentEPNS_5StateE+0x273)[0x5dec83]
traffic_server(_ZN12HttpTransact14HandleResponseEPNS_5StateE+0x655)[0x5e00a5]
traffic_server(_ZN6HttpSM32call_transact_and_set_next_stateEPFvPN12HttpTransact5StateEE+0x27)[0x580e67]
traffic_server(_ZN6HttpSM32state_send_server_request_headerEiPv+0x17f)[0x594bdf]
traffic_server(_ZN6HttpSM12main_handlerEiPv+0x108)[0x596f78]
traffic_server[0x7dfa7e]
traffic_server(_Z15write_to_net_ioP10NetHandlerP18UnixNetVConnectionP7EThread+0x6d8)[0x7e57e8]
traffic_server(_ZN10NetHandler18process_ready_listEv+0x1f6)[0x7d13b6]
traffic_server(_ZN10NetHandler15waitForActivityEl+0x245)[0x7d1715]
traffic_server(_ZN7EThread15execute_regularEv+0x66a)[0x8287ea]
traffic_server(_ZN7EThread7executeEv+0x1a2)[0x828a52]
traffic_server[0x826e2a]
/lib64/libpthread.so.0(+0x7dd5)[0x7fad331b7dd5]
/lib64/libc.so.6(clone+0x6d)[0x7fad324beb3d]

The crash looks to be in NextHopConsistentHash::findNextHop(tsapi_httptxn*, void*, long).

Here is the Au test that caused this crash: https://github.com/ywkaras/trafficserver/blob/StrategiesAutestCrash/tests/gold_tests/next_hop/strategies_ch/strategies_ch.test.py

[ywkaras]

Here is a backtrace from the core file:

(gdb) bt full
#0  NextHopConsistentHash::findNextHop(tsapi_httptxn*, void*, long) () at NextHopConsistentHash.cc:324
        r = <optimized out>
        sm = 0x7fad20e883f0
        result = 0x7fad20e88e10
        request_info = {<RequestData> = {_vptr.RequestData = 0x87b150 <vtable for HttpRequestData+16>}, hdr = 0x7fad20e88b98, hostname_str = 0x7fad20d67c24 "wrong.com", api_info = 0x7fad20e88d58, xact_start = 1619198439, src_ip = {sa = {sa_family = 2, sa_data = "\234&\177\000\000\001\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 9884, sin_addr = {s_addr = 16777343}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 9884, sin6_flowinfo = 16777343, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, dest_ip = {sa = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, incoming_port = 61033, tag = 0x0, internal_txn = false, cache_info_lookup_url = 0x7fad20e88520, cache_info_parent_selection_url = 0x7fad20e88580}
        sm_id = <optimized out>
        retry_time = <optimized out>
        _now = 0
        firstcall = <optimized out>
        nextHopRetry = false
        wrapped = true
        wrap_around = std::vector<bool> of length 1, capacity 64 = {1}
        cur_ring = <optimized out>
        hash_key = 0
        lookups = <optimized out>
        hash = {<ATSHash64> = {<ATSHashBase> = {_vptr.ATSHashBase = 0x7fad34b4a8e8 <vtable for ATSHash64Sip24+16>}, <No data fields>}, block_buffer = "/obj\000\000\000", block_buffer_len = 4 '\004', k0 = 0, k1 = 0, v0 = 6273115432221753012, v1 = 1893682315080405021, v2 = 17072421927894701096, v3 = 17951659473895730748, hfinal = 6378598250446050493, total_len = 4, finalized = true}
        hostRec = <optimized out>
        pRec = <optimized out>
Python Exception <class 'gdb.error'> There is no member or method named _M_bbegin.: 
        pStatus = @0xb1ff20: {hosts_statuses = std::unordered_map with 1 elements, host_status_rwlock = {__data = {__lock = 0, __nr_readers = 0, __readers_wakeup = 0, __writer_wakeup = 0, __nr_readers_queued = 0, __nr_writers_queued = 0, __writer = 0, __shared = 0, __pad1 = 0, __pad2 = 0, __flags = 0}, __size = '\000' <repeats 55 times>, __align = 0}}
        host_stat = <optimized out>
        hst = <optimized out>
        __FUNCTION__ = "findNextHop"
#1  0x00000000005d2c38 in find_server_and_update_current_info(HttpTransact::State*) () at HttpTransact.cc:614
        host_len = <optimized out>
        host = <optimized out>
        __FUNCTION__ = "find_server_and_update_current_info"
#2  0x00000000005dec83 in HttpTransact::handle_response_from_parent(HttpTransact::State*) () at HttpTransact.cc:3693
        addrbuf = "172.17.0.2\000\064\255\177\000\000\t\000\000\000\000\000\000\000P\336O\000\000\000\000\000\210͂\000\000\000\000\000ɝ?2\255\177"
        next_lookup = HttpTransact::UNDEFINED_LOOKUP
        __FUNCTION__ = "handle_response_from_parent"
#3  0x00000000005e00a5 in HttpTransact::HandleResponse(HttpTransact::State*) () at HttpTransact.cc:3490
        __FUNCTION__ = "HandleResponse"
#4  0x0000000000580e67 in HttpSM::call_transact_and_set_next_state(void (*)(HttpTransact::State*)) () at HttpSM.cc:7359
        __FUNCTION__ = "call_transact_and_set_next_state"
#5  0x0000000000594bdf in HttpSM::state_send_server_request_header(int, void*) () at HttpSM.cc:2184
        __FUNCTION__ = "state_send_server_request_header"
        method = <optimized out>
#6  0x0000000000596f78 in HttpSM::main_handler(int, void*) () at HttpSM.cc:2699
        jump_point = <optimized out>
        __FUNCTION__ = "main_handler"
        vc_entry = <optimized out>
#7  0x00000000007dfa7e in write_signal_and_update(int, UnixNetVConnection*) () at UnixNetVConnection.cc:117
        __FUNCTION__ = "write_signal_and_update"
        loc = {file = 0x0, func = 0x0, line = 0}
        log_message = {<Throttler> = {_vptr.Throttler = 0x0, _last_allowed_time = {static _S_min_alignment = 8, static _S_alignment = 8, _M_i = {<std::chrono::time_point<std::chrono::_V2::system_clock, std::chrono::duration<long, std::ratio<1, 1000000000> > >> = {__d = {__r = 0}}, <No data fields>}, static is_always_lock_free = <error reading variable: No global symbol "std::atomic<Throttler::TimePoint>::is_always_lock_free".>}, _interval = {static _S_min_alignment = 8, static _S_alignment = 8, _M_i = {__r = 0}, static is_always_lock_free = <optimized out>}, _suppressed_count = 0}, _throttling_value_is_explicitly_set = false, _is_throttled = false, static _default_log_throttling_interval = {static _S_min_alignment = 8, static _S_alignment = 8, _M_i = {__r = 60000}, static is_always_lock_free = <optimized out>}, static _default_debug_throttling_interval = {static _S_min_alignment = 8, static _S_alignment = 8, _M_i = {__r = 0}, static is_always_lock_free = <optimized out>}}
        loc = {file = 0x0, func = 0x0, line = 0}
        log_message = {<Throttler> = {_vptr.Throttler = 0x0, _last_allowed_time = {static _S_min_alignment = 8, static _S_alignment = 8, _M_i = {<std::chrono::time_point<std::chrono::_V2::system_clock, std::chrono::duration<long, std::ratio<1, 1000000000> > >> = {__d = {__r = 0}}, <No data fields>}, static is_always_lock_free = <error reading variable: No global symbol "std::atomic<Throttler::TimePoint>::is_always_lock_free".>}, _interval = {static _S_min_alignment = 8, static _S_alignment = 8, _M_i = {__r = 0}, static is_always_lock_free = <optimized out>}, _suppressed_count = 0}, _throttling_value_is_explicitly_set = false, _is_throttled = false, static _default_log_throttling_interval = {static _S_min_alignment = 8, static _S_alignment = 8, _M_i = {__r = 60000}, static is_always_lock_free = <optimized out>}, static _default_debug_throttling_interval = {static _S_min_alignment = 8, static _S_alignment = 8, _M_i = {__r = 0}, static is_always_lock_free = <optimized out>}}
        loc = {file = 0x0, func = 0x0, line = 0}
        log_message = {<Throttler> = {_vptr.Throttler = 0x0, _last_allowed_time = {static _S_min_alignment = 8, static _S_alignment = 8, _M_i = {<std::chrono::time_point<std::chrono::_V2::system_clock, std::chrono::duration<long, std::ratio<1, 1000000000> > >> = {__d = {__r = 0}}, <No data fields>}, static is_always_lock_free = <error reading variable: No global symbol "std::atomic<Throttler::TimePoint>::is_always_lock_free".>}, _interval = {static _S_min_alignment = 8, static _S_alignment = 8, _M_i = {__r = 0}, static is_always_lock_free = <optimized out>}, _suppressed_count = 0}, _throttling_value_is_explicitly_set = false, _is_throttled = false, static _default_log_throttling_interval = {static _S_min_alignment = 8, static _S_alignment = 8, _M_i = {__r = 60000}, static is_always_lock_free = <optimized out>}, static _default_debug_throttling_interval = {static _S_min_alignment = 8, static _S_alignment = 8, _M_i = {__r = 0}, static is_always_lock_free = <optimized out>}}
#8  0x00000000007e57e8 in write_signal_done (vc=0x7facd401e880, nh=0x7fad30c5c100, event=3) at UnixNetVConnection.cc:162
No locals.
#9  write_signal_error (lerrno=<optimized out>, vc=0x7facd401e880, nh=0x7fad30c5c100) at UnixNetVConnection.cc:181
No locals.
#10 write_to_net_io(NetHandler*, UnixNetVConnection*, EThread*) () at UnixNetVConnection.cc:491
        s = 0x7facd401eac8
        mutex = 0x1743d50
        lock = {m = {m_ptr = 0x183e3a0}, lock_acquired = true}
        ntodo = <optimized out>
        buf = @0x7facd401eaf0: {mbuf = 0x7fad1c030cb0, entry = 0x7fad1c030cc8}
        towrite = <optimized out>
        signalled = 1
        needs = -2147483644
        total_written = 0
        r = <optimized out>
#11 0x00000000007d13b6 in NetHandler::process_ready_list (this=this@entry=0x7fad30c5c100) at UnixNet.cc:432
        ne = <optimized out>
#12 0x00000000007d1715 in NetHandler::waitForActivity(long) () at UnixNet.cc:549
        epd = <optimized out>
        lock = {m = {m_ptr = 0x1743b70}, locked_p = true}
        p = <optimized out>
        pd = 0x7fad23dbe010
        ne = <optimized out>
        __FUNCTION__ = "waitForActivity"
#13 0x00000000008287ea in EThread::execute_regular (this=this@entry=0x7fad30c58010) at I_PriorityEventQueue.h:115
        done_one = <optimized out>
        sleep_time = <optimized out>
        e = <optimized out>
        NegativeQueue = {<DLL<Event, Event::Link_link>> = {head = 0x0}, tail = 0x0}
        next_time = <optimized out>
        delta = <optimized out>
        loop_start_time = 1619198439859105735
        loop_finish_time = <optimized out>
        prev_metric = 0x7fad30d5e850
        nq_count = 0
        ev_count = 0
        METRIC_INIT = {_loop_time = {_start = 0, _min = 9223372036854775807, _max = 0}, _events = {_min = 2147483647, _max = 0, _total = 0}, _count = 0, _wait = 0}
#14 0x0000000000828a52 in execute (this=0x7fad30c58010) at UnixEThread.cc:364
No locals.
#15 EThread::execute (this=0x7fad30c58010) at UnixEThread.cc:342
No locals.
#16 0x0000000000826e2a in spawn_thread_internal (a=0x1773020) at Thread.cc:92
        p = 0x1773020
#17 0x00007fad331b7dd5 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#18 0x00007fad324beb3d in clone () from /lib64/libc.so.6
No symbol table info available.
(gdb)