Segfault in write_to_net_io with 7.1.x

[biilmann]

Seeing frequent segfaults when trying 7.1.x on some production traffic.

What happens is that the MUTEX_TRY_LOCK_FOR segfaults since s->vio.mutex is NULL

https://github.com/apache/trafficserver/blob/master/iocore/net/UnixNetVConnection.cc#L439

Digging into a core dump shows that this happens when s->enabled == 0 and s->error == 1. Inspecting s->vio shows that it's an empty vio instance with a null pointer mutex.

[bryancall]

What does the vc look like?

[biilmann]

Some info on the vc:

p vc
$1 = (UnixNetVConnection *) 0x2b9a7802ff10
p vc.closed
$2 = 0
p vc.action_
$3 = {_vptr.Action = 0x788a90 <vtable for Action+16>, continuation = 0x23dcdf0, mutex = {m_ptr = 0x0}, cancelled = 0}
p vc.inactivity_timeout_in
$4 = 86400000000000
p vc.active_timeout_in
$5 = 900000000000

Let me know if there's anything specific on the vc that would help...

[zwoop]

you didn't see this crasher in 7.0.0 right ?

[biilmann]

Not this one no. We've seen a crash that looks related in the crash logs from 7.0.x but it is much rarer and I don't currently have a core-dump of that.

[zwoop]

Are you getting a core file / backtrace ?

[bryancall]

(gdb) bt full
#0  0x00000000005150b0 in Mutex_trylock (m=0x0, t=0x2b44f3a6d010)
    at /home/bcall/dev/yahoo/build/_build/ats_build/../../trafficserver/iocore/eventsystem/I_Lock.h:289
No locals.
#1  0x000000000051526f in MutexTryLock::MutexTryLock (this=0x2b44f9c35be0, am=..., t=0x2b44f3a6d010)
    at /home/bcall/dev/yahoo/build/_build/ats_build/../../trafficserver/iocore/eventsystem/I_Lock.h:555
No locals.
#2  0x0000000000787888 in write_to_net_io (nh=0x2b44f3a70e60, vc=0x2aac5002bf10, thread=0x2b44f3a6d010)
    at ../../../../trafficserver/iocore/net/UnixNetVConnection.cc:439
        s = 0x2aac5002c098
        mutex = 0x2b44f40035d0
        lock = {m = {m_ptr = 0x0}, lock_acquired = 16}
        ntodo = 47575248100432
        buf = @0x2b9de60
        towrite = 47575145566224
        signalled = 10
        needs = 2147483647
        total_written = 3807
        r = 44090535680
#3  0x000000000078781e in write_to_net (nh=0x2b44f3a70e60, vc=0x2aac5002bf10, thread=0x2b44f3a6d010)
    at ../../../../trafficserver/iocore/net/UnixNetVConnection.cc:430
        mutex = 0x2b44f40035d0
#4  0x000000000077f443 in NetHandler::mainNetEvent (this=0x2b44f3a70e60, event=5, e=0x2cb5860)
    at ../../../../trafficserver/iocore/net/UnixNet.cc:526
        epd = 0x2aac5c02dd70
        poll_timeout = 0
        pd = 0x2b45a0000010
        vc = 0x2aac5002bf10
        __func__ = "mainNetEvent"
#5  0x0000000000515354 in Continuation::handleEvent (this=0x2b44f3a70e60, event=5, data=0x2cb5860)
    at /home/bcall/dev/yahoo/build/_build/ats_build/../../trafficserver/iocore/eventsystem/I_Continuation.h:153
No locals.
#6  0x00000000007a8bc3 in EThread::process_event (this=0x2b44f3a6d010, e=0x2cb5860, calling_code=5)
    at ../../../../trafficserver/iocore/eventsystem/UnixEThread.cc:143
        c_temp = 0x2b44f3a70e60
        lock = {m = {m_ptr = 0x2b44f4001f50}, lock_acquired = true}
#7  0x00000000007a90c4 in EThread::execute (this=0x2b44f3a6d010)
    at ../../../../trafficserver/iocore/eventsystem/UnixEThread.cc:270
        done_one = false
        e = 0x2cb5860
        NegativeQueue = {<DLL<Event, Event::Link_link>> = {head = 0x0}, tail = 0x0}
        next_time = 1486425567363334599
#8  0x00000000007a8279 in spawn_thread_internal (a=0x2ba5fd0)
    at ../../../../trafficserver/iocore/eventsystem/Thread.cc:84
        p = 0x2ba5fd0
#9  0x00002b44f0c14aa1 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#10 0x00002b44f0960aad in clone () from /lib64/libc.so.6

[shinrich]

I've finally got my environment running and I see the same stack very quickly as well. In the cases I've seen it looks like there was a write error, but for some reason the write vio has been cleared out (or was never set?)

(gdb) frame 2
#2  0x0000000000788350 in write_to_net_io (nh=0x2af588003e60, vc=0x2aad1401b800, thread=0x2af588000010) at UnixNetVConnection.cc:440
440	UnixNetVConnection.cc: No such file or directory.
	in UnixNetVConnection.cc
(gdb) print *s
$1 = {enabled = 0, error = 1, vio = {_cont = 0x0, nbytes = 0, ndone = 0, op = 0, buffer = {mbuf = 0x0, entry = 0x0}, vc_server = 0x0, mutex = {m_ptr = 0x0}}, 
  ready_link = {<SLink<UnixNetVConnection>> = {next = 0x0}, prev = 0x0}, enable_link = {next = 0x0}, in_enabled_list = 0, triggered = 1}

The write.error stuff was added by Thomas in TS-4796, but if this just showed up between 7.0 and 7.1, it is unlikely that this was the culprit. I think it has been a while (since 9/3/2016).

Seems more likely that someone has cleared the vio, or we are bouncing an error.

In the short term I'm adding a NULL check at the begining of write_to_net_io, but that just seems to be masking the failure case rather than identifying the root cause.

+  if (!s->vio.mutex) {
+    ink_release_assert(s->vio._cont == NULL && vc->write.error);
+    return;
+  }

[PSUdaemon]

I think I am seeing this in 6.2.x as well:

traffic_server: Segmentation fault (Address not mapped to object [0x18])
traffic_server - STACK TRACE: 
/var/jenkins/workspace/ubuntu_14_04-6.2.x/compiler/clang/label/ubuntu_14_04/type/release/143/install/bin/traffic_server(_Z19crash_logger_invokeiP9siginfo_tPv+0x8e)[0x4a234e]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10330)[0x7fb6fa205330]
/var/jenkins/workspace/ubuntu_14_04-6.2.x/compiler/clang/label/ubuntu_14_04/type/release/143/install/bin/traffic_server(_Z15write_to_net_ioP10NetHandlerP18UnixNetVConnectionP7EThread+0xa1e)[0x6bb3ae]
/var/jenkins/workspace/ubuntu_14_04-6.2.x/compiler/clang/label/ubuntu_14_04/type/release/143/install/bin/traffic_server(_ZN10NetHandler12mainNetEventEiP5Event+0x686)[0x6b4606]
/var/jenkins/workspace/ubuntu_14_04-6.2.x/compiler/clang/label/ubuntu_14_04/type/release/143/install/bin/traffic_server(_ZN7EThread13process_eventEP5Eventi+0x123)[0x6d7af3]
/var/jenkins/workspace/ubuntu_14_04-6.2.x/compiler/clang/label/ubuntu_14_04/type/release/143/install/bin/traffic_server(_ZN7EThread7executeEv+0x560)[0x6d8210]
/var/jenkins/workspace/ubuntu_14_04-6.2.x/compiler/clang/label/ubuntu_14_04/type/release/143/install/bin/traffic_server(main+0x1de0)[0x4c8bd0]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5)[0x7fb6f93ccf45]
/var/jenkins/workspace/ubuntu_14_04-6.2.x/compiler/clang/label/ubuntu_14_04/type/release/143/install/bin/traffic_server[0x49218d]
/home/jenkins/bin/regression.sh: line 24: 21351 Segmentation fault      (core dumped) "${WORKSPACE}/${BUILD_NUMBER}/install/bin/traffic_server" -k -K -R 1

[shinrich]

@PSUdaemon would be cool to see symbols with the stack to verify that is the same thing. My hacky fix made it go away only to be immediately replaced by a new crash. (New issue to be posted).

[shinrich]

BTW I'm currently testing without HTTP/2.

[PSUdaemon]

I'm not sure there is a core to look at in the case I pasted. It was on a build host.