Assert for unexpected event in UnixNetVConnection::mainEvent

[shinrich]

We are seeing this in our production testing. Looks like it is due to commit 3e039a2 which re-enabled the active timeout logic for UnixNetVConnection. The original code used event immediate and event interval to distinguish between active and inactive timeouts. The commit changed that to process ACTIVE_TIMEOUT and INACTIVE_TIMEOUT's explicitly. However, it appears there is a path somewhere that is doing a schedule immediate that is being processed by this handler. Perhaps it should should put the extra immediate events into the inactivity timeout bucket which is how the original code would have handled it.

(gdb) bt
#0  0x00002b9ec320a207 in raise () from /lib64/libc.so.6
#1  0x00002b9ec320b8f8 in abort () from /lib64/libc.so.6
#2  0x00002b9ec096a53b in ink_abort (message_format=message_format@entry=0x2b9ec09d50c7 "%s:%d: failed assertion `%s`") at ../../../../../../_vcs/trafficserver9/src/tscore/ink_error.cc:99
#3  0x00002b9ec0967cf5 in _ink_assert (expression=expression@entry=0x79ba18 "!\"BUG: unexpected event in UnixNetVConnection::mainEvent\"", 
    file=file@entry=0x79b6e0 "../../../../../../_vcs/trafficserver9/iocore/net/UnixNetVConnection.cc", line=line@entry=1133) at ../../../../../../_vcs/trafficserver9/src/tscore/ink_assert.cc:37
#4  0x00000000006fb947 in UnixNetVConnection::mainEvent(int, Event*) () at ../../../../../../_vcs/trafficserver9/iocore/net/UnixNetVConnection.cc:1133
#5  0x000000000073930f in handleEvent (data=0x2ba17e277aa0, event=1, this=0x2b9eff616620) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/I_Continuation.h:167
#6  handleEvent (data=0x2ba17e277aa0, event=1, this=0x2b9eff616620) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/I_Continuation.h:163
#7  EThread::process_event(Event*, int) () at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/UnixEThread.cc:136
#8  0x00000000007399de in EThread::process_queue (this=this@entry=0x2b9ec799e300, NegativeQueue=NegativeQueue@entry=0x2b9ecba02600, ev_count=ev_count@entry=0x2b9ecba025fc, 
    nq_count=nq_count@entry=0x2b9ecba025f8) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/UnixEThread.cc:175
#9  0x0000000000739e8c in EThread::execute_regular (this=this@entry=0x2b9ec799e300) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/UnixEThread.cc:235
#10 0x000000000073a5d6 in execute (this=0x2b9ec799e300) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/UnixEThread.cc:338
#11 EThread::execute (this=0x2b9ec799e300) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/UnixEThread.cc:316
#12 0x0000000000738899 in spawn_thread_internal (a=0x2b9ec41c5940) at ../../../../../../_vcs/trafficserver9/iocore/eventsystem/Thread.cc:92
#13 0x00002b9ec259cdd5 in start_thread () from /lib64/libpthread.so.0
#14 0x00002b9ec32d1ead in clone () from /lib64/libc.so.6

[zwoop]

This would have to go to 8.1.x, although, if we revert #4028, not sure where we stand with this.

[shinrich]

Fix merged onto master. Still waiting the fix to go to 9.0.x

[shinrich]

Looks like it is in 9.0.x