Re: [reSIProcate-users] Unexpected TCP connection termination disturbing call setup

["Julio Cesar Esteves Cabezas" <jcabezas@xxxxxxxxxxxxx>]

Hello,

  Attached the zipped log.
  Below a snippet of the debug statements I inserted.
  
//inside TcpConnection.cxx
   if (bytesWritten == INVALID_SOCKET)
   {
      int e = getErrno();
      InfoLog (<< "Failed write on " << getSocket() << " " << strerror(e));

      DebugLog(<< "getErrno()value inside TcpConnection::write() = " << e);
//jcec: for debugging

      Transport::error(e);
      //setFailureReason(TransportFailure::ConnectionException, e+1000);
      return -1;
   }  

//inside Connection.cxx
   if (nBytes < 0)
   {
      int xerrno = errno;
//jcec: for debugging

      if (errno != EAGAIN && errno != EWOULDBLOCK) // Treat EGAIN and
EWOULDBLOCK as the same:
http://stackoverflow.com/questions/7003234/which-systems-define-eagain-and-e
wouldblock-as-different-values
      {
        DebugLog(<< "errno value after write failure = " << xerrno);
//jcec: for debugging
        DebugLog(<< "EAGAIN = " << EAGAIN);
//jcec: for debugging
        DebugLog(<< "EWOULDBLOCK = " << EWOULDBLOCK);
//jcec: for debugging

         //fail(data.transactionId);
         InfoLog(<< "Write failed on socket: " << this->getSocket() << ",
closing connection");
         return -1;
      }
      else
      {
         return 0;
      }
   }

And a snippet of the log file showing the result of my traces:
12/10/2013 15:23:31 [Debug] RESIP:DUM | 1420 | DialogId.cxx:50 |
DialogId::DialogId: y10j0IawQ1mFPqz5RHxhwg..-f32a2239-962af37a
12/10/2013 15:23:31 [Info] RESIP:TRANSPORT | 4108 | TcpConnection.cxx:97 |
Failed write on 3408 Unknown error
12/10/2013 15:23:31 [Debug] RESIP:DUM | 1420 | DialogUsageManager.cxx:1144 |
Send: SipReq:  NOTIFY 5903@10.0.1.30:5060 tid=197f360b636f2d27 cseq=9 NOTIFY
contact=5901 / 9 from(tu)
12/10/2013 15:23:31 [Debug] RESIP:TRANSPORT | 4108 | TcpConnection.cxx:99 |
getErrno()value inside TcpConnection::write() = 10035
12/10/2013 15:23:31 [Debug] RESIP | 1420 | SipStack.cxx:571 | SEND: SipReq:
NOTIFY 5903@10.0.1.30:5060 tid=197f360b636f2d27 cseq=9 NOTIFY contact=5901 /
9 from(tu)
12/10/2013 15:23:31 [Debug] RESIP:TRANSPORT | 4108 | Transport.cxx:156 |
Would Block 
12/10/2013 15:23:31 [Debug] RESIP:TRANSPORT | 4108 | Connection.cxx:169 |
errno value after write failure = 0
12/10/2013 15:23:31 [Debug] RESIP:TRANSPORT | 4108 | Connection.cxx:170 |
EAGAIN = 11
12/10/2013 15:23:31 [Debug] RESIP:TRANSPORT | 4108 | Connection.cxx:171 |
EWOULDBLOCK = 10035
12/10/2013 15:23:31 [Debug] RESIP:DUM | 1420 | Dialog.cxx:1051 |
Dialog::makeRequest: 
  
We see that:
  getErrno()value inside TcpConnection::write() = 10035          
but:
  errno value after write failure = 0 inside Connection.cxx
  
It seems that some successful system call made between the two points could
have reset errno and caused the "if" to be taken.

Interestingly EWOULDBLOCK is not defined in the errno.h file in my VS2012
platform, that could explain why strerror() doesn't know it ?  
  
Regards,
Julio.

Attachment: _SipEngine.zip
Description: Binary data