Uploaded image for project: 'Traffic Server'
  1. Traffic Server
  2. TS-3784

Unpleasant debug assert in when starting up a SpdyClientSession



    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 6.0.0
    • Component/s: SPDY
    • Labels:


      Noticed this while trying to reproduce Chao Xu's issue on TS-3667.

      I have a callback set on the SNI hook. It selects a new certificate and reenables the vc before returning. The stack is below. The assert is because the current thread does not hold the read.vio mutex. In fact no thread holds the read vio mutex.

      For HttpClientSession and Http2ClientSession, they use the VC's mutex instead of creating new mutex. So that shared mutex is used when setting up the vio's, so when the do_io_reads occur the mutex is automatically already held.

      If I change SpdyClientSession to use the VC mutex instead of creating a new mutex, this assert does not get triggered. Not clear whether this is causing any real issues, but it seems cleaner to follow the mutex assignment strategy of the other protocols.

      Here is the stack

      #0  0x000000351e4328a5 in raise () from /lib64/libc.so.6
      #1  0x000000351e434085 in abort () from /lib64/libc.so.6
      #2  0x00007ffff7dda215 in ink_die_die_die () at ink_error.cc:43
      #3  0x00007ffff7dda2cc in ink_fatal_va(const char *, typedef __va_list_tag __va_list_tag *) (
          fmt=0x7ffff7deb298 "%s:%d: failed assert `%s`", ap=0x7fffef4a8530) at ink_error.cc:65
      #4  0x00007ffff7dda391 in ink_fatal (message_format=0x7ffff7deb298 "%s:%d: failed assert `%s`")
          at ink_error.cc:73
      #5  0x00007ffff7dd7f12 in _ink_assert (
          expression=0x826e48 "vio->mutex->thread_holding == this_ethread() && thread", 
          file=0x826a9e "UnixNetVConnection.cc", line=895) at ink_assert.cc:37
      #6  0x000000000077b4d7 in UnixNetVConnection::set_enabled (this=0x7fffb801c540, vio=0x7fffb801c660)
          at UnixNetVConnection.cc:895
      #7  0x000000000077ab94 in UnixNetVConnection::reenable (this=0x7fffb801c540, vio=0x7fffb801c660)
          at UnixNetVConnection.cc:788
      #8  0x0000000000509755 in VIO::reenable (this=0x7fffb801c660) at ../iocore/eventsystem/P_VIO.h:112
      #9  0x000000000077a1da in UnixNetVConnection::do_io_read (this=0x7fffb801c540, c=0x7fffd402e3c0, 
          nbytes=9223372036854775807, buf=0x16f9b30) at UnixNetVConnection.cc:628
      #10 0x00000000006393c1 in SpdyClientSession::start (this=0x7fffd402e3c0) at SpdyClientSession.cc:210
      #11 0x000000000054a1fa in ProxyClientSession::handle_api_return (this=0x7fffd402e3c0, event=60000)
          at ProxyClientSession.cc:167
      #12 0x000000000054a142 in ProxyClientSession::do_api_callout (this=0x7fffd402e3c0, 
          id=TS_HTTP_SSN_START_HOOK) at ProxyClientSession.cc:147
      #13 0x0000000000639303 in SpdyClientSession::new_connection (this=0x7fffd402e3c0, 
          new_vc=0x7fffb801c540, iobuf=0x0, reader=0x0, backdoor=false) at SpdyClientSession.cc:195
      #14 0x000000000063878e in SpdySessionAccept::mainEvent (this=0x16bc7a0, event=202, 
          edata=0x7fffb801c540) at SpdySessionAccept.cc:48
      #15 0x000000000050970e in Continuation::handleEvent (this=0x16bc7a0, event=202, data=0x7fffb801c540)
          at ../iocore/eventsystem/I_Continuation.h:146
      #16 0x0000000000763404 in send_plugin_event (plugin=0x16bc7a0, event=202, edata=0x7fffb801c540)
          at SSLNextProtocolAccept.cc:32
      #17 0x0000000000763b89 in SSLNextProtocolTrampoline::ioCompletionEvent (this=0x7fffd40008e0, 
          event=102, edata=0x7fffb801c660) at SSLNextProtocolAccept.cc:99
      #18 0x000000000050970e in Continuation::handleEvent (this=0x7fffd40008e0, event=102, 
          data=0x7fffb801c660) at ../iocore/eventsystem/I_Continuation.h:146
      #19 0x000000000077871e in read_signal_and_update (event=102, vc=0x7fffb801c540)
      ---Type <return> to continue, or q <return> to quit---
          at UnixNetVConnection.cc:145
      #20 0x0000000000778abe in read_signal_done (event=102, nh=0x7fffef9b2be0, vc=0x7fffb801c540)
          at UnixNetVConnection.cc:206
      #21 0x000000000077baac in UnixNetVConnection::readSignalDone (this=0x7fffb801c540, event=102, 
          nh=0x7fffef9b2be0) at UnixNetVConnection.cc:1006
      #22 0x000000000075e559 in SSLNetVConnection::net_read_io (this=0x7fffb801c540, nh=0x7fffef9b2be0, 
          lthread=0x7fffef9af010) at SSLNetVConnection.cc:543
      #23 0x0000000000770b52 in NetHandler::mainNetEvent (this=0x7fffef9b2be0, event=5, e=0x1153690)
          at UnixNet.cc:516
      #24 0x000000000050970e in Continuation::handleEvent (this=0x7fffef9b2be0, event=5, data=0x1153690)
          at ../iocore/eventsystem/I_Continuation.h:146
      #25 0x000000000079aefa in EThread::process_event (this=0x7fffef9af010, e=0x1153690, calling_code=5)
          at UnixEThread.cc:128
      #26 0x000000000079b51b in EThread::execute (this=0x7fffef9af010) at UnixEThread.cc:252
      #27 0x000000000079a414 in spawn_thread_internal (a=0x1532c60) at Thread.cc:86
      #28 0x000000351e807851 in start_thread () from /lib64/libpthread.so.0
      #29 0x000000351e4e890d in clone () from /lib64/libc.so.6


          Issue Links



              • Assignee:
                shinrich Susan Hinrichs
                shinrich Susan Hinrichs
              • Votes:
                0 Vote for this issue
                1 Start watching this issue


                • Created: