Details

    • Bug
    • Status: Closed
    • Major
    • Resolution: Cannot Reproduce
    • 5.0.0
    • None
    • SPDY

    Description

      Intercept plugin crash when working with ats-5.0.

      #0  0x00000000004e0f80 in Ptr<IOBufferBlock>::operator IOBufferBlock* (
          this=0x38) at ../lib/ts/Ptr.h:326
      #1  0x00000000004f52dc in IOBufferReader::skip_empty_blocks (
          this=0x2b4bec073718) at ../iocore/eventsystem/P_IOBuffer.h:551
      #2  0x0000000000532c04 in IOBufferReader::block_read_avail (
          this=0x2b4bec073718) at ../iocore/eventsystem/P_IOBuffer.h:604
      #3  0x000000000052ffce in PluginVC::transfer_bytes (this=0x2b4b88586768,
          transfer_to=0x2b4b6806c440, transfer_from=0x2b4bec073718, act_on=943)
          at PluginVC.cc:438
      #4  0x0000000000530d7b in PluginVC::process_read_side (this=0x2b4b88586768,
          other_side_call=true) at PluginVC.cc:655
      #5  0x00000000005307fe in PluginVC::process_write_side (this=0x2b4b88586580,
          other_side_call=false) at PluginVC.cc:567
      #6  0x000000000052f5a0 in PluginVC::main_handler (this=0x2b4b88586580,
          event=1, data=0x2b4b1426a060) at PluginVC.cc:212
      #7  0x00000000004f4f18 in Continuation::handleEvent (this=0x2b4b88586580,
          event=1, data=0x2b4b1426a060) at ../iocore/eventsystem/I_Continuation.h:146
      #8  0x0000000000753d62 in EThread::process_event (this=0x2b4aed111010,
          e=0x2b4b1426a060, calling_code=1) at UnixEThread.cc:145
      #9  0x0000000000753f30 in EThread::execute (this=0x2b4aed111010)
          at UnixEThread.cc:196
      #10 0x00000000007532c0 in spawn_thread_internal (a=0x2bddf50) at Thread.cc:88
      #11 0x00002b4ad0c8c9d1 in start_thread () from /lib64/libpthread.so.0
      #12 0x0000003f09ae8b7d in clone () from /lib64/libc.so.6
      (gdb) up 3
      #3  0x000000000052ffce in PluginVC::transfer_bytes (this=0x2b4b88586768,
          transfer_to=0x2b4b6806c440, transfer_from=0x2b4bec073718, act_on=943)
          at PluginVC.cc:438
      438     PluginVC.cc: No such file or directory.
              in PluginVC.cc
      (gdb) p transfer_from
      $1 = (IOBufferReader *) 0x2b4bec073718
      (gdb) p *transfer_from
      $2 = {accessor = 0x0, mbuf = 0x0, block = {m_ptr = 0x0}, start_offset = 0,
        size_limit = 9223372036854775807}
      

      Attachments

        Activity

          sunwei Wei Sun added a comment -

          Looking into it, seems it happened on a spdy connection.

          (gdb) bt
          #0  0x00000000004f66d0 in Ptr<IOBufferBlock>::operator-> (this=0x38) at ../lib/ts/Ptr.h:330
          #1  0x00000000004f5c39 in IOBufferReader::skip_empty_blocks (this=0x2b612452d258) at ../iocore/eventsystem/P_IOBuffer.h:551
          #2  0x00000000005338ec in IOBufferReader::block_read_avail (this=0x2b612452d258) at ../iocore/eventsystem/P_IOBuffer.h:604
          #3  0x0000000000530cb6 in PluginVC::transfer_bytes (this=0x2b615cf782d8, transfer_to=0x2b614d77f580, transfer_from=0x2b612452d258, act_on=1688) at PluginVC.cc:438
          #4  0x0000000000531a63 in PluginVC::process_read_side (this=0x2b615cf782d8, other_side_call=true) at PluginVC.cc:655
          #5  0x00000000005314e6 in PluginVC::process_write_side (this=0x2b615cf780f0, other_side_call=false) at PluginVC.cc:567
          #6  0x0000000000530288 in PluginVC::main_handler (this=0x2b615cf780f0, event=1, data=0x2b61540fad30) at PluginVC.cc:212
          #7  0x00000000004f5854 in Continuation::handleEvent (this=0x2b615cf780f0, event=1, data=0x2b61540fad30) at ../iocore/eventsystem/I_Continuation.h:146
          #8  0x0000000000755d26 in EThread::process_event (this=0x2b607670c010, e=0x2b61540fad30, calling_code=1) at UnixEThread.cc:145
          #9  0x0000000000755ef4 in EThread::execute (this=0x2b607670c010) at UnixEThread.cc:196
          #10 0x0000000000755284 in spawn_thread_internal (a=0x309c8c0) at Thread.cc:88
          #11 0x00002b605b0f79d1 in start_thread () from /lib64/libpthread.so.0
          #12 0x00000034666e8b5d in clone () from /lib64/libc.so.6
          (gdb) f 5
          #5  0x00000000005314e6 in PluginVC::process_write_side (this=0x2b615cf780f0, other_side_call=false) at PluginVC.cc:567
          567	in PluginVC.cc
          (gdb) p *((write_state.vio._cont)->ua_entry->vc->client_vc->other_side->read_state.vio._cont->contp)
          $1 = (SpdyClientSession) {<Continuation> = {<force_VFPT_to_top> = {_vptr.force_VFPT_to_top = 0x797530}, handler = (int (Continuation::*)(Continuation *, int, 
              void *)) 0x61d34a <SpdyClientSession::state_session_readwrite(int, void*)>, mutex = {m_ptr = 0x2b608c0612a0}, link = {<SLink<Continuation>> = {next = 0x0}, prev = 0x0}}, <PluginIdentity> = {
              _vptr.PluginIdentity = 0x797560}, sm_id = 1989840, version = spdy::SESSION_VERSION_3_1, total_size = 340, start_time = 1415964248205125093, vc = 0x2b608c916350, req_buffer = 0x2b611ea6c530, 
            req_reader = 0x2b611ea6c548, resp_buffer = 0x2b6114328e00, resp_reader = 0x2b6114328e18, read_vio = 0x2b608c916460, write_vio = 0x2b608c9164c8, event = 100, session = 0x2b615faf4000, 
            req_map = std::map with 1 elements = {[13] = 0x2b60931192a0}}
          
          sunwei Wei Sun added a comment - Looking into it, seems it happened on a spdy connection. (gdb) bt #0 0x00000000004f66d0 in Ptr<IOBufferBlock>:: operator -> ( this =0x38) at ../lib/ts/Ptr.h:330 #1 0x00000000004f5c39 in IOBufferReader::skip_empty_blocks ( this =0x2b612452d258) at ../iocore/eventsystem/P_IOBuffer.h:551 #2 0x00000000005338ec in IOBufferReader::block_read_avail ( this =0x2b612452d258) at ../iocore/eventsystem/P_IOBuffer.h:604 #3 0x0000000000530cb6 in PluginVC::transfer_bytes ( this =0x2b615cf782d8, transfer_to=0x2b614d77f580, transfer_from=0x2b612452d258, act_on=1688) at PluginVC.cc:438 #4 0x0000000000531a63 in PluginVC::process_read_side ( this =0x2b615cf782d8, other_side_call= true ) at PluginVC.cc:655 #5 0x00000000005314e6 in PluginVC::process_write_side ( this =0x2b615cf780f0, other_side_call= false ) at PluginVC.cc:567 #6 0x0000000000530288 in PluginVC::main_handler ( this =0x2b615cf780f0, event=1, data=0x2b61540fad30) at PluginVC.cc:212 #7 0x00000000004f5854 in Continuation::handleEvent ( this =0x2b615cf780f0, event=1, data=0x2b61540fad30) at ../iocore/eventsystem/I_Continuation.h:146 #8 0x0000000000755d26 in EThread::process_event ( this =0x2b607670c010, e=0x2b61540fad30, calling_code=1) at UnixEThread.cc:145 #9 0x0000000000755ef4 in EThread::execute ( this =0x2b607670c010) at UnixEThread.cc:196 #10 0x0000000000755284 in spawn_thread_internal (a=0x309c8c0) at Thread .cc:88 #11 0x00002b605b0f79d1 in start_thread () from /lib64/libpthread.so.0 #12 0x00000034666e8b5d in clone () from /lib64/libc.so.6 (gdb) f 5 #5 0x00000000005314e6 in PluginVC::process_write_side ( this =0x2b615cf780f0, other_side_call= false ) at PluginVC.cc:567 567 in PluginVC.cc (gdb) p *((write_state.vio._cont)->ua_entry->vc->client_vc->other_side->read_state.vio._cont->contp) $1 = (SpdyClientSession) {<Continuation> = {<force_VFPT_to_top> = {_vptr.force_VFPT_to_top = 0x797530}, handler = ( int (Continuation::*)(Continuation *, int , void *)) 0x61d34a <SpdyClientSession::state_session_readwrite( int , void*)>, mutex = {m_ptr = 0x2b608c0612a0}, link = {<SLink<Continuation>> = {next = 0x0}, prev = 0x0}}, <PluginIdentity> = { _vptr.PluginIdentity = 0x797560}, sm_id = 1989840, version = spdy::SESSION_VERSION_3_1, total_size = 340, start_time = 1415964248205125093, vc = 0x2b608c916350, req_buffer = 0x2b611ea6c530, req_reader = 0x2b611ea6c548, resp_buffer = 0x2b6114328e00, resp_reader = 0x2b6114328e18, read_vio = 0x2b608c916460, write_vio = 0x2b608c9164c8, event = 100, session = 0x2b615faf4000, req_map = std::map with 1 elements = {[13] = 0x2b60931192a0}}
          sunwei Wei Sun added a comment - - edited

          Found another crash that seems to be related, both indicated that the IOBufferReader pointed to the NULL MIOBuffer, whereas the MIOBuffer object is still existed.

          (gdb) bt
          #0  0x00000000004f5478 in IOBufferReader::allocated (this=0x18) at ../iocore/eventsystem/I_IOBuffer.h:766
          #1  0x0000000000533986 in MIOBuffer::max_read_avail (this=0x0) at ../iocore/eventsystem/P_IOBuffer.h:1048
          #2  0x000000000053bd72 in MIOBuffer::high_water (this=0x0) at ../iocore/eventsystem/I_IOBuffer.h:994
          #3  0x00000000006cb386 in MIOBuffer::check_add_block (this=0x0) at ../../iocore/eventsystem/P_IOBuffer.h:965
          #4  0x00000000006cb434 in MIOBuffer::write_avail (this=0x0) at ../../iocore/eventsystem/P_IOBuffer.h:1009
          #5  0x0000000000735c8d in write_to_net_io (nh=0x2b3980c0fbc0, vc=0x2b399445d190, thread=0x2b3980c0c010) at UnixNetVConnection.cc:422
          #6  0x00000000007358ef in write_to_net (nh=0x2b3980c0fbc0, vc=0x2b399445d190, thread=0x2b3980c0c010) at UnixNetVConnection.cc:354
          #7  0x000000000072f09e in NetHandler::mainNetEvent (this=0x2b3980c0fbc0, event=5, e=0x18859b0) at UnixNet.cc:415
          #8  0x00000000004f5854 in Continuation::handleEvent (this=0x2b3980c0fbc0, event=5, data=0x18859b0) at ../iocore/eventsystem/I_Continuation.h:146
          #9  0x0000000000755d26 in EThread::process_event (this=0x2b3980c0c010, e=0x18859b0, calling_code=5) at UnixEThread.cc:145
          #10 0x0000000000756230 in EThread::execute (this=0x2b3980c0c010) at UnixEThread.cc:269
          #11 0x0000000000755284 in spawn_thread_internal (a=0x1bfd0a0) at Thread.cc:88
          #12 0x00002b3960d4f9d1 in start_thread () from /lib64/libpthread.so.0
          #13 0x0000003a86ce8b5d in clone () from /lib64/libc.so.6
          (gdb) f 5
          #5  0x0000000000735c8d in write_to_net_io (nh=0x2b3980c0fbc0, vc=0x2b399445d190, thread=0x2b3980c0c010) at UnixNetVConnection.cc:422
          422	  if (towrite != ntodo && buf.writer()->write_avail()) {
          (gdb) p vc->write.vio
          $11 = {_cont = 0x2b39ecb366b0, nbytes = 9223372036854775807, ndone = 0, op = 2, buffer = {mbuf = 0x0, entry = 0x2b3a302acfd8}, vc_server = 0x2b399445d190, mutex = {m_ptr = 0x2b3a6c002100}}
          (gdb)  p *vc->write.vio._cont
          $12 = (SpdyClientSession) {<Continuation> = {<force_VFPT_to_top> = {_vptr.force_VFPT_to_top = 0x797530}, handler = (int (Continuation::*)(Continuation *, int, 
              void *)) 0x61d34a <SpdyClientSession::state_session_readwrite(int, void*)>, mutex = {m_ptr = 0x2b3a6c002100}, link = {<SLink<Continuation>> = {next = 0x0}, prev = 0x0}}, <PluginIdentity> = {
              _vptr.PluginIdentity = 0x797560}, sm_id = 4845541, version = spdy::SESSION_VERSION_3_1, total_size = 0, start_time = 1416313589240113216, vc = 0x2b399445d190, req_buffer = 0x2b3a49435e60, 
            req_reader = 0x2b3a49435e78, resp_buffer = 0x2b3a302acfc0, resp_reader = 0x2b3a302acfd8, read_vio = 0x2b399445d2a0, write_vio = 0x2b399445d308, event = 100, session = 0x2b3a05596230, 
            req_map = std::map with 0 elements}
          (gdb)  p vc->write.vio._cont->resp_buffer
          $13 = (tsapi_iobuffer *) 0x2b3a302acfc0
          (gdb)  p *(IOBufferReader *)vc->write.vio._cont->resp_reader
          $14 = {accessor = 0x0, mbuf = 0x0, block = {m_ptr = 0x0}, start_offset = 0, size_limit = 9223372036854775807}
          (gdb) 
          

          The above trace shows SpdyClientSession was not destroyed since this->mutex is not NULL, so resp_reader was not free'ed, seems that there is an timing issue on manipulating MIOBufferReader.

          sunwei Wei Sun added a comment - - edited Found another crash that seems to be related, both indicated that the IOBufferReader pointed to the NULL MIOBuffer , whereas the MIOBuffer object is still existed. (gdb) bt #0 0x00000000004f5478 in IOBufferReader::allocated ( this =0x18) at ../iocore/eventsystem/I_IOBuffer.h:766 #1 0x0000000000533986 in MIOBuffer::max_read_avail ( this =0x0) at ../iocore/eventsystem/P_IOBuffer.h:1048 #2 0x000000000053bd72 in MIOBuffer::high_water ( this =0x0) at ../iocore/eventsystem/I_IOBuffer.h:994 #3 0x00000000006cb386 in MIOBuffer::check_add_block ( this =0x0) at ../../iocore/eventsystem/P_IOBuffer.h:965 #4 0x00000000006cb434 in MIOBuffer::write_avail ( this =0x0) at ../../iocore/eventsystem/P_IOBuffer.h:1009 #5 0x0000000000735c8d in write_to_net_io (nh=0x2b3980c0fbc0, vc=0x2b399445d190, thread=0x2b3980c0c010) at UnixNetVConnection.cc:422 #6 0x00000000007358ef in write_to_net (nh=0x2b3980c0fbc0, vc=0x2b399445d190, thread=0x2b3980c0c010) at UnixNetVConnection.cc:354 #7 0x000000000072f09e in NetHandler::mainNetEvent ( this =0x2b3980c0fbc0, event=5, e=0x18859b0) at UnixNet.cc:415 #8 0x00000000004f5854 in Continuation::handleEvent ( this =0x2b3980c0fbc0, event=5, data=0x18859b0) at ../iocore/eventsystem/I_Continuation.h:146 #9 0x0000000000755d26 in EThread::process_event ( this =0x2b3980c0c010, e=0x18859b0, calling_code=5) at UnixEThread.cc:145 #10 0x0000000000756230 in EThread::execute ( this =0x2b3980c0c010) at UnixEThread.cc:269 #11 0x0000000000755284 in spawn_thread_internal (a=0x1bfd0a0) at Thread .cc:88 #12 0x00002b3960d4f9d1 in start_thread () from /lib64/libpthread.so.0 #13 0x0000003a86ce8b5d in clone () from /lib64/libc.so.6 (gdb) f 5 #5 0x0000000000735c8d in write_to_net_io (nh=0x2b3980c0fbc0, vc=0x2b399445d190, thread=0x2b3980c0c010) at UnixNetVConnection.cc:422 422 if (towrite != ntodo && buf.writer()->write_avail()) { (gdb) p vc->write.vio $11 = {_cont = 0x2b39ecb366b0, nbytes = 9223372036854775807, ndone = 0, op = 2, buffer = {mbuf = 0x0, entry = 0x2b3a302acfd8}, vc_server = 0x2b399445d190, mutex = {m_ptr = 0x2b3a6c002100}} (gdb) p *vc->write.vio._cont $12 = (SpdyClientSession) {<Continuation> = {<force_VFPT_to_top> = {_vptr.force_VFPT_to_top = 0x797530}, handler = ( int (Continuation::*)(Continuation *, int , void *)) 0x61d34a <SpdyClientSession::state_session_readwrite( int , void*)>, mutex = {m_ptr = 0x2b3a6c002100}, link = {<SLink<Continuation>> = {next = 0x0}, prev = 0x0}}, <PluginIdentity> = { _vptr.PluginIdentity = 0x797560}, sm_id = 4845541, version = spdy::SESSION_VERSION_3_1, total_size = 0, start_time = 1416313589240113216, vc = 0x2b399445d190, req_buffer = 0x2b3a49435e60, req_reader = 0x2b3a49435e78, resp_buffer = 0x2b3a302acfc0, resp_reader = 0x2b3a302acfd8, read_vio = 0x2b399445d2a0, write_vio = 0x2b399445d308, event = 100, session = 0x2b3a05596230, req_map = std::map with 0 elements} (gdb) p vc->write.vio._cont->resp_buffer $13 = (tsapi_iobuffer *) 0x2b3a302acfc0 (gdb) p *(IOBufferReader *)vc->write.vio._cont->resp_reader $14 = {accessor = 0x0, mbuf = 0x0, block = {m_ptr = 0x0}, start_offset = 0, size_limit = 9223372036854775807} (gdb) The above trace shows SpdyClientSession was not destroyed since this->mutex is not NULL, so resp_reader was not free'ed, seems that there is an timing issue on manipulating MIOBufferReader.

          People

            Unassigned Unassigned
            sunwei Wei Sun
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: