Issue with null ua_buffer_reader due to PR #2123

[shinrich]

@d2r and I have seen the following stack in production. We believe it is due to PR #2123

[ 0  ] traffic_server     Ptr<IOBufferBlock>::get() const                     ( Ptr.h:150                 ) 
[ 1  ] traffic_server     MIOBuffer::write(IOBufferReader*, long, long)       ( IOBuffer.cc:138           ) 
[ 2  ] traffic_server     HttpTunnel::copy_partial_post_data()                ( HttpTunnel.cc:1701        ) 
[ 3  ] traffic_server     HttpTunnel::producer_run(HttpTunnelProducer*)       ( HttpTunnel.cc:1005        ) 
[ 4  ] traffic_server     HttpTunnel::tunnel_run(HttpTunnelProducer*)         ( HttpTunnel.cc:800         ) 
[ 5  ] traffic_server     HttpSM::do_setup_post_tunnel(HttpVC_t)              ( HttpSM.cc:5825            ) 
[ 6  ] traffic_server     HttpSM::tunnel_handler_for_partial_post(int, void*) ( HttpSM.cc:3675            ) 
[ 7  ] traffic_server     HttpSM::main_handler(int, void*)                    ( HttpSM.cc:2720            ) 
[ 8  ] traffic_server     Continuation::handleEvent(int, void*)               ( I_Continuation.h:153      ) 
[ 9  ] traffic_server     HttpTunnel::main_handler(int, void*)                ( HttpTunnel.cc:1665        ) 
[ 10 ] traffic_server     Continuation::handleEvent(int, void*)               ( I_Continuation.h:153      ) 
[ 11 ] traffic_server     write_signal_and_update                             ( UnixNetVConnection.cc:175 ) 
[ 12 ] traffic_server     write_signal_done                                   ( UnixNetVConnection.cc:217 ) 
[ 13 ] traffic_server     write_to_net_io                                     ( UnixNetVConnection.cc:564 ) 
[ 14 ] traffic_server     write_to_net                                        ( UnixNetVConnection.cc:416 ) 
[ 15 ] traffic_server     NetHandler::mainNetEvent(int, Event*)               ( UnixNet.cc:516            ) 
[ 16 ] traffic_server     Continuation::handleEvent(int, void*)               ( I_Continuation.h:153      ) 
[ 17 ] traffic_server     EThread::process_event(Event*, int)                 ( UnixEThread.cc:122        ) 
[ 18 ] traffic_server     EThread::execute()                                  ( UnixEThread.cc:266        ) 
[ 19 ] traffic_server     spawn_thread_internal                               ( Thread.cc:85              ) 
[ 20 ] libpthread-2.12.so start_thread                                        ( :undefined                )

HttpSM::tunnel_handler_for_partial_post calls tunnel.deallocate_buffers(), which now clears ua_buffer_reader out of postbuf. But we don't clear/free postbuf on this path, so when HttpTunnel::producer_run calls allocate_redirect_postdata_buffers, it does not reallocate postbuf and reset the ua_buffer_reader field. So very quickly it tries to dereference against the null reader object and dies.

In our stack the WRITE_COMPLETE event is being processed.

I'm not clear how best to fix this. Should HttpSM::tunnel_handler_for_partial_post also be calling deallocate_redirect_postdata_buffers? Should we merge the two deallocate buffer calls if they should always be called together?

[scw00]

It seems reason to me ! I saw the crash and I need to dig a bit more !

[scw00]

As far as I can talk ! There are two ways to fix these crashes .

For #2123, the root cause is that we copy data from reader, the p->buffer_start->read_avail() > HttpConfig::m_master.post_copy_size is true at the first time, but got false at next time.

  if (p->alive && sm->t_state.method == HTTP_WKSIDX_POST && sm->enable_redirection && (p->vc_type == HT_HTTP_CLIENT)) {
    Debug("http_redirect", "[HttpTunnel::producer_run] client post: %" PRId64 " max size: %" PRId64 "",
          p->buffer_start->read_avail(), HttpConfig::m_master.post_copy_size);

    // (note that since we are not dechunking POST, this is the chunked size if chunked)
    if (p->buffer_start->read_avail() > HttpConfig::m_master.post_copy_size) {
      Debug("http_redirect", "[HttpTunnel::producer_handler] post exceeds buffer limit, buffer_avail=%" PRId64 " limit=%" PRId64 "",
            p->buffer_start->read_avail(), HttpConfig::m_master.post_copy_size);
     // set false next time
      sm->enable_redirection = false;
    } else {
      // allocate post buffers with a new reader. The reader will be freed when p->read_buffer is freed
      allocate_redirect_postdata_buffers(p->read_buffer->clone_reader(p->buffer_start));
      copy_partial_post_data();
    }
  }

Then postbuf->ua_buffer_reader will never be released !

Approach：

• We can change condition from p->buffer_start->read_avail() > HttpConfig::m_master.post_copy_size to post_bytes > HttpConfig::m_master.post_copy_size . But this fix disable the chunk post cache
• do deallocate_redirect_postdata_buffers like producer_handler.

// producer_handler
  if (sm->t_state.method == HTTP_WKSIDX_POST && sm->enable_redirection &&
      (event == VC_EVENT_READ_READY || event == VC_EVENT_READ_COMPLETE) && (p->vc_type == HT_HTTP_CLIENT)) {
    Debug("http_redirect", "[HttpTunnel::producer_handler] [%s %s]", p->name, HttpDebugNames::get_event_name(event));

    if ((postbuf->postdata_copy_buffer_start->read_avail() + postbuf->ua_buffer_reader->read_avail()) >
        HttpConfig::m_master.post_copy_size) {
      Debug("http_redirect", "[HttpTunnel::producer_handler] post exceeds buffer limit, buffer_avail=%" PRId64
                             " reader_avail=%" PRId64 " limit=%" PRId64 "",
            postbuf->postdata_copy_buffer_start->read_avail(), postbuf->ua_buffer_reader->read_avail(),
            HttpConfig::m_master.post_copy_size);
      deallocate_redirect_postdata_buffers();
      sm->enable_redirection = false;
    } else {
      copy_partial_post_data();
    }
  } 

[scw00]

fixed by #2766 .

[scw00]

ping @d2r @shinrich
Can we closed it ?