[Boost-users] boost asio: boost::asio::deadline_timer blocking ?

Subject: [Boost-users] boost asio: boost::asio::deadline_timer blocking ?
From: Avi Bahra (avibahra_at_[hidden])
Date: 2012-11-14 09:18:11

Answers:

1. I doubt this is really an issue is with deadline_timer accuracy.

2. Are you double-scheduling the same timer?  Or are you just doing some
extra work, every time a single expiry event crosses a minute boundary?
I wouldn't double-schedule the same timer, if that's what you're doing.

>> No. I record the next minute boundary, when the timer fires, I check the current
>> time against the minute boundary. So no double scheduling.

3. The timer may be susceptible to time changes on your system.  It
needn't be, but don't assume that means it's not.  It might be worth
looking at the implementation, to make sure.

>> The problem occurs independent of the time change.

4. Slow disk could be an issue, but only if your io_service thread(s)
are blocking on disk activity (either direct disk access or page
faults).  The file descriptors you're talking about have nothing to do
with disk files, in this case.

>> The current server is single threaded, so my this was my first suspect.
>> I log every client request to a log file. I had suspected that a slow
>> file system, would block  when logging the client request, and affect the timer.
>> I added extra instrumentation to time the logging. However this was not the cause

5. Depends on your accuracy needs and the load on the rest of the
system.  On a system under moderate loads, I'd expect no problems using
ASIO to perform processing on a one-second granularity.  Just be sure to
compute the next expiry based the current time, rather than sleeping for
1 second.  If you want to make this resilient to time change, you can
use a monotonic timebase.

Matt

================================================================

The client is designed to cancel long running connection to the
server.. ( > 20seconds)
This timeout is based on boost asio example:
  http://www.boost.org/doc/libs/1_47_0/doc/html/boost_asio/example/timeouts/async_tcp_client.cpp

What I have noticed is that the 1 second timer in the server
does not fire, *when* client request  have been cancelled.
It appears that some of chain of async handlers
that are being called in the server, during this process, cause the
timer to hang ?

For example if the client cancels after 20 seconds, then something in the server
must been blocking, for that period ?
When the client cancels, the server::handle_write(..), closes
both end of the socket. So I see the following message logged:

       shutdown: Transport endpoint is not connected

Here is the async' functions in the server:

void server::start_accept()
{
   connection_ptr new_conn( new connection( io_service_ ) );
   acceptor_.async_accept( new_conn->socket(),
                           boost::bind( &server::handle_accept, this,
                                 boost::asio::placeholders::error,
                                 new_conn ) );
}

void server::handle_accept( const boost::system::error_code& e,
connection_ptr conn )
{
   if (!acceptor_.is_open()) {
      if (serverEnv_.debug()) cout << "   server::handle_accept:
acceptor is closed, returning\n";
      return;
   }

   if ( !e ) {
      conn->async_read( inbound_request_,
                     boost::bind( &server::handle_read, this,
                                boost::asio::placeholders::error,conn ) );
   }
   else {
      if (e != boost::asio::error::operation_aborted) {
         // An error occurred. Log it
         LogToCout toCoutAsWell;
         LOG(Log::ERR, "   server::handle_accept error occurred  " <<
e.message());
      }
   }
   start_accept();
}

void server::handle_read(  const boost::system::error_code&
e,connection_ptr conn )
{
   if ( !e ) {
      try {
         // Service the in bound request, handling the request will
populate the outbound_response_
         // Note:: Handle request will first authenticate
         outbound_response_.set_cmd( inbound_request_.handleRequest( this ) );
      }
      catch (exception& e) {
         outbound_response_.set_cmd( PreAllocatedReply::error_cmd( e.what()  ));
      }

      // *Reply* back to the client:
      conn->async_write( outbound_response_,
                          boost::bind(&server::handle_write,
                                    this,
                                    boost::asio::placeholders::error,
                                    conn ) );
   }
   else {
      LOG(Log::ERR, "server::handle_read error occurred : " <<  e.message());
   }
}

void server::handle_write( const boost::system::error_code& e,
connection_ptr conn )
{
   boost::system::error_code ec;
   conn->socket().shutdown(boost::asio::ip::tcp::socket::shutdown_both,ec);
   if (ec) {
      ecf::LogToCout logToCout;
      LOG(Log::ERR,"server::handle_write: socket shutdown both failed:
" << ec.message());
      return;
   }
}

I had noticed that I was not checking error code in the server::handle_write(..)
but I'm not sure if this would account, for why the timer does not
fire temporarily.

Ta,
   Avi