trafficserver
trafficserver copied to clipboard
apache
ATS 10 docs: unexpected tunnel_handler event
I noticed this on docs today:
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007ffff714c859 in __GI_abort () at abort.c:79
#2 0x0000555555effb85 in ink_abort (message_format=0x55555606b484 "%s:%d: failed assertion `%s`") at ink_error.cc:99
#3 0x0000555555efbbd3 in _ink_assert (expression=0x555555fb3418 "event == HTTP_TUNNEL_EVENT_DONE || event == VC_EVENT_INACTIVITY_TIMEOUT", file=0x555555fb12da "HttpSM.cc", line=3006) at ink_assert.cc:37
#4 0x0000555555b16eb9 in HttpSM::tunnel_handler (this=0x7fffe802d040, event=104, data=0x7fffe8037300) at HttpSM.cc:3006
#5 0x0000555555b152ce in HttpSM::main_handler (this=0x7fffe802d040, event=104, data=0x7fffe8037300) at HttpSM.cc:2666
#6 0x0000555555aa04ef in Continuation::handleEvent (this=0x7fffe802d040, event=104, data=0x7fffe8037300) at /home/maskit/trafficserver/iocore/eventsystem/I_Continuation.h:228
#7 0x0000555555c25843 in Http2Stream::main_event_handler (this=0x7fffe8037050, event=104, edata=0x7fffa0000cd0) at Http2Stream.cc:232
#8 0x0000555555aa04ef in Continuation::handleEvent (this=0x7fffe8037050, event=104, data=0x7fffa0000cd0) at /home/maskit/trafficserver/iocore/eventsystem/I_Continuation.h:228
#9 0x0000555555f90677 in EThread::process_event (this=0x7ffff41aa010, e=0x7fffa0000cd0, calling_code=104) at UnixEThread.cc:150
#10 0x0000555555f908c7 in EThread::process_queue (this=0x7ffff41aa010, NegativeQueue=0x7fffef9b0170, ev_count=0x7fffef9b0124, nq_count=0x7fffef9b0120) at UnixEThread.cc:185
#11 0x0000555555f90bd6 in EThread::execute_regular (this=0x7ffff41aa010) at UnixEThread.cc:241
#12 0x0000555555f90ff2 in EThread::execute (this=0x7ffff41aa010) at UnixEThread.cc:334
#13 0x0000555555f8f8d6 in spawn_thread_internal (a=0x5555564790e0) at Thread.cc:78
#14 0x00007ffff77a8609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#15 0x00007ffff7249133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
(gdb) f 4
#4 0x0000555555b16eb9 in HttpSM::tunnel_handler (this=0x7fffe802d040, event=104, data=0x7fffe8037300) at HttpSM.cc:3006
3006 ink_assert(event == HTTP_TUNNEL_EVENT_DONE || event == VC_EVENT_INACTIVITY_TIMEOUT);
(gdb) p event
$1 = 104
Per guidance from the community, I'm currently running ATS in docs without this assertion.
I saw this on CI with autest:
[Feb 21 19:56:27.486] traffic_server NOTE: records parsing completed.
[Feb 21 19:56:27.486] traffic_server NOTE: /tmp/sandbox/ramp/ts/config/records.yaml finished loading
[Feb 21 19:56:27.491] traffic_server NOTE: Traffic Server is running unprivileged, not switching to user 'nobody'
Fatal: ../src/proxy/http/HttpSM.cc:2968: failed assertion `event == HTTP_TUNNEL_EVENT_DONE || event == VC_EVENT_INACTIVITY_TIMEOUT`
NOTE: using the environment variable TS_RUNROOT
[Feb 21 19:56:27.751] traffic_crashlo NOTE: crashlog started, target=17638, debug=false syslog=true, uid=1200 euid=1200
[Feb 21 19:56:27.752] traffic_crashlo NOTE: logging to 0x677370
[Feb 21 19:56:27.754] traffic_crashlo ERROR: wrote crash log to /tmp/sandbox/ramp/ts/log/crash-2024-02-21-195627.log
traffic_server: received signal 6 (Aborted)
traffic_server - STACK TRACE:
/tmp/sandbox/ramp/ts/bin/traffic_server(_Z19crash_logger_invokeiP9siginfo_tPv+0xce)[0x87eb86]
/lib64/libc.so.6(+0x3e9a0)[0x7f92a8d8b9a0]
/lib64/libc.so.6(+0x90834)[0x7f92a8ddd834]
/lib64/libc.so.6(raise+0x1e)[0x7f92a8d8b8ee]
/lib64/libc.so.6(abort+0xdf)[0x7f92a8d738ff]
/tmp/sandbox/ramp/ts/bin/traffic_server(_Z11ink_warningPKcz+0x0)[0x8b4538]
/tmp/sandbox/ramp/ts/bin/traffic_server[0x8b0c4e]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN6HttpSM14tunnel_handlerEiPv+0x12a)[0x912c88]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN6HttpSM12main_handlerEiPv+0x254)[0x911412]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN12Continuation11handleEventEiPv+0xdd)[0x884831]
/tmp/sandbox/ramp/ts/bin/traffic_server[0xc01eb1]
/tmp/sandbox/ramp/ts/bin/traffic_server[0xc02302]
/tmp/sandbox/ramp/ts/bin/traffic_server(_Z15write_to_net_ioP10NetHandlerP18UnixNetVConnectionP7EThread+0x92b)[0xc036d4]
/tmp/sandbox/ramp/ts/bin/traffic_server(_Z12write_to_netP10NetHandlerP18UnixNetVConnectionP7EThread+0x3f)[0xc02da6]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN18UnixNetVConnection12net_write_ioEP10NetHandlerP7EThread+0x2b)[0xc04e0f]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN10NetHandler18process_ready_listEv+0x16d)[0xc307e5]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN10NetHandler15waitForActivityEl+0x150)[0xc30a96]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN7EThread15execute_regularEv+0x482)[0xc6c4da]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN7EThread7executeEv+0x107)[0xc6c67d]
/tmp/sandbox/ramp/ts/bin/traffic_server[0xc6aff0]
/lib64/libc.so.6(+0x8e897)[0x7f92a8ddb897]
/lib64/libc.so.6(clone+0x44)[0x7f92a8e62674]
I saw this issue again on another simple PR:
[Feb 23 18:16:13.053] traffic_server NOTE: records parsing completed.
[Feb 23 18:16:13.053] traffic_server NOTE: /tmp/sandbox/ramp/ts/config/records.yaml finished loading
[Feb 23 18:16:13.057] traffic_server NOTE: Traffic Server is running unprivileged, not switching to user 'nobody'
Fatal: ../src/proxy/http/HttpSM.cc:2968: failed assertion `event == HTTP_TUNNEL_EVENT_DONE || event == VC_EVENT_INACTIVITY_TIMEOUT`
NOTE: using the environment variable TS_RUNROOT
[Feb 23 18:16:13.302] traffic_crashlo NOTE: crashlog started, target=16479, debug=false syslog=true, uid=1200 euid=1200
[Feb 23 18:16:13.303] traffic_crashlo NOTE: logging to 0x153b370
[Feb 23 18:16:13.305] traffic_crashlo ERROR: wrote crash log to /tmp/sandbox/ramp/ts/log/crash-2024-02-23-181613.log
traffic_server: received signal 6 (Aborted)
traffic_server - STACK TRACE:
/tmp/sandbox/ramp/ts/bin/traffic_server(_Z19crash_logger_invokeiP9siginfo_tPv+0xce)[0x87eab6]
/lib64/libc.so.6(+0x3e9a0)[0x7f401e8569a0]
/lib64/libc.so.6(+0x90834)[0x7f401e8a8834]
/lib64/libc.so.6(raise+0x1e)[0x7f401e8568ee]
/lib64/libc.so.6(abort+0xdf)[0x7f401e83e8ff]
/tmp/sandbox/ramp/ts/bin/traffic_server(_Z11ink_warningPKcz+0x0)[0x8b443e]
/tmp/sandbox/ramp/ts/bin/traffic_server[0x8b0b54]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN6HttpSM14tunnel_handlerEiPv+0x12a)[0x91266e]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN6HttpSM12main_handlerEiPv+0x254)[0x910df8]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN12Continuation11handleEventEiPv+0xdd)[0x884761]
/tmp/sandbox/ramp/ts/bin/traffic_server[0xc01869]
/tmp/sandbox/ramp/ts/bin/traffic_server[0xc01cba]
/tmp/sandbox/ramp/ts/bin/traffic_server(_Z15write_to_net_ioP10NetHandlerP18UnixNetVConnectionP7EThread+0x92b)[0xc0308c]
/tmp/sandbox/ramp/ts/bin/traffic_server(_Z12write_to_netP10NetHandlerP18UnixNetVConnectionP7EThread+0x3f)[0xc0275e]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN18UnixNetVConnection12net_write_ioEP10NetHandlerP7EThread+0x2b)[0xc047c7]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN10NetHandler18process_ready_listEv+0x16d)[0xc3019d]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN10NetHandler15waitForActivityEl+0x150)[0xc3044e]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN7EThread15execute_regularEv+0x482)[0xc6be88]
/tmp/sandbox/ramp/ts/bin/traffic_server(_ZN7EThread7executeEv+0x107)[0xc6c02b]
/tmp/sandbox/ramp/ts/bin/traffic_server[0xc6a99e]
/lib64/libc.so.6(+0x8e897)[0x7f401e8a6897]
/lib64/libc.so.6(clone+0x44)[0x7f401e92d674]