reSIProcate

Mailing Lists

Source Code

Google Search:



< Previous by Date Date Index Next by Date >
< Previous in Thread Thread Index  

Re: [reSIProcate] Performance of a P2P-over-SIP program using resiprocate

Hi!

Sorry for the delay...

I compiled the stack with the uncommented line you gave me.
Here is the log that I got and I only show the summary of the retransmission as a sequence. 

I can see the retransmission in the log now.
I cannot see the ACK getting to the stack or any error or clue as to why the retransmission is happening. 

Could my code be causing this somehow?

Thank you.

Victor M.

==================================
Here is the summary from Wireshark
==================================
No.     Time        Source                Destination           Protocol Info
65 9.193841 192.168.61.132 192.168.61.130 SIP/XML Request: INVITE sip:spzero@xxxxxxxxxxxxxx:12005 89 10.073606 192.168.61.130 192.168.61.132 SIP/XML Status: 606 Not Acceptable 90 10.073795 192.168.61.132 192.168.61.130 SIP Request: ACK sip:spzero@xxxxxxxxxxxxxx:12005 120 11.064069 192.168.61.130 192.168.61.132 SIP/XML Status: 606 Not Acceptable 
==========================================
And here is the debug level log from resip
==========================================
DEBUG | 20070514-223643.844 | kenobi | nsp | RESIP:TRANSPORT | 5165 | 3079915904 | Transport.cxx:287 | incoming from: [ V4 192.168.61.132:5060 UDP target domain=unspecified received on: Transport: [ V4 0.0.0.0:12005 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] DEBUG | 20070514-223643.845 | kenobi | nsp | RESIP:TRANSACTION | 5165 | 3079915904 | TransactionUser.cxx:66 | Checking if SipReq: INVITE spzero@xxxxxxxxxxxxxx:12005 tid=-7258-26-0 cseq=INVITE contact=candid@xxxxxxxxxxxxxx:5060 / 26 from(wire) is for me DEBUG | 20070514-223643.845 | kenobi | nsp | RESIP:TRANSACTION | 5165 | 3079915904 | TransactionUser.cxx:71 | Checking rule... DEBUG | 20070514-223643.845 | kenobi | nsp | RESIP:TRANSACTION | 5165 | 3079915904 | MessageFilterRule.cxx:42 | Matching rule for: 

INVITE sip:spzero@xxxxxxxxxxxxxx:12005 SIP/2.0
Via: SIP/2.0/UDP 192.168.61.132:5060;branch=z9hG4bK-7258-26-0
Max-Forwards: 70
Contact: <sip:candid@xxxxxxxxxxxxxx:5060>
To: spzero <sip:spzero@xxxxxxxxxxxxxx:12005>
From: candid <sip:candid@xxxxxxxxxxxxxx:5060>;tag=26
Call-ID: 26-7258@xxxxxxxxxxxxxx
CSeq: 26 INVITE
Allow: INVITE, ACK, MESSAGE
Content-Type: text/xml
Content-Length: 180

<?xml version="1.0" encoding="ISO-8859-1" ?>
<request>
<name>Trac</name>
<extended type="size">0</extended>
<extended type="date">01.01.1900-01.01.2100</extended>
</request>
DEBUG | 20070514-223643.845 | kenobi | nsp | RESIP:TRANSACTION | 5165 | 3079915904 | TransactionUser.cxx:74 | Match! DEBUG | 20070514-223643.845 | kenobi | nsp | RESIP | 5165 | 3079915904 | Helper.cxx:372 | Helper::makeResponse(SipReq: INVITE spzero@xxxxxxxxxxxxxx:12005 tid=-7258-26-0 cseq=INVITE contact=candid@xxxxxxxxxxxxxx:5060 / 26 from(wire) code=100 reason= DEBUG | 20070514-223643.845 | kenobi | nsp | RESIP:TRANSACTION | 5165 | 3079915904 | TimerQueue.cxx:85 | Adding timer: Timer Trying tid=-7258-26-0 ms=80 DEBUG | 20070514-223643.845 | kenobi | nsp | RESIP:TRANSACTION | 5165 | 3079915904 | TransactionState.cxx:1852 | Send to TU: TU: DialogUsageManager size=0 

INVITE sip:spzero@xxxxxxxxxxxxxx:12005 SIP/2.0
Via: SIP/2.0/UDP 192.168.61.132:5060;branch=z9hG4bK-7258-26-0
Max-Forwards: 70
Contact: <sip:candid@xxxxxxxxxxxxxx:5060>
To: spzero <sip:spzero@xxxxxxxxxxxxxx:12005>
From: candid <sip:candid@xxxxxxxxxxxxxx:5060>;tag=26
Call-ID: 26-7258@xxxxxxxxxxxxxx
CSeq: 26 INVITE
Allow: INVITE, ACK, MESSAGE
Content-Type: text/xml
Content-Length: 180

<?xml version="1.0" encoding="ISO-8859-1" ?>
<request>
<name>Trac</name>
<extended type="size">0</extended>
<extended type="date">01.01.1900-01.01.2100</extended>
</request>
INFO | 20070514-223643.845 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogUsageManager.cxx:1227 | Got: SipReq: INVITE spzero@xxxxxxxxxxxxxx:12005 tid=-7258-26-0 cseq=INVITE contact=candid@xxxxxxxxxxxxxx:5060 / 26 from(wire) DEBUG | 20070514-223643.845 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogUsageManager.cxx:1494 | DialogUsageManager::processRequest: SipReq: INVITE spzero@xxxxxxxxxxxxxx:12005 tid=-7258-26-0 cseq=INVITE contact=candid@xxxxxxxxxxxxxx:5060 / 26 from(wire) DEBUG | 20070514-223643.845 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogSetId.cxx:31 | ********** Generated Local Tag *********** DEBUG | 20070514-223643.845 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogSetId.cxx:31 | ********** Generated Local Tag *********** DEBUG | 20070514-223643.845 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogSetId.cxx:31 | ********** Generated Local Tag *********** DEBUG | 20070514-223643.845 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogSet.cxx:84 | ************* Created DialogSet(UAS) -- 26-7258@xxxxxxxxxxxxxxxxxxxxxxx************* DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogSetId.cxx:31 | ********** Generated Local Tag *********** DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogId.cxx:50 | DialogId::DialogId: 26-7258@xxxxxxxxxxxxxxxxxxxxxxxxxx DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogSet.cxx:736 | mState == 3 Creating a new Dialog from msg: 

INVITE sip:spzero@xxxxxxxxxxxxxx:12005 SIP/2.0
Via: SIP/2.0/UDP 192.168.61.132:5060;branch=z9hG4bK-7258-26-0
Max-Forwards: 70
Contact: <sip:candid@xxxxxxxxxxxxxx:5060>
To: "spzero"<sip:spzero@xxxxxxxxxxxxxx:12005>
From: "candid"<sip:candid@xxxxxxxxxxxxxx:5060>;tag=26
Call-ID: 26-7258@xxxxxxxxxxxxxx
CSeq: 26 INVITE
Allow: INVITE, ACK, MESSAGE
Content-Type: text/xml
Content-Length: 180

<?xml version="1.0" encoding="ISO-8859-1" ?>
<request>
<name>Trac</name>
<extended type="size">0</extended>
<extended type="date">01.01.1900-01.01.2100</extended>
</request>
DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | Dialog.cxx:87 | UAS dialog ID creation, DS: 26-7258@xxxxxxxxxxxxxxxxxxxxxxx DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogId.cxx:63 | DialogId::DialogId: 26-7258@xxxxxxxxxxxxxxxxxxxxxxxxxx DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | Dialog.cxx:129 | ************** Created Dialog as UAS ************** DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | Dialog.cxx:130 | mRemoteNameAddr: "candid"<sip:candid@xxxxxxxxxxxxxx:5060>;tag=26 DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | Dialog.cxx:131 | mLocalNameAddr: "spzero"<sip:spzero@xxxxxxxxxxxxxx:12005>;tag=ec956632 DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | Dialog.cxx:132 | mLocalContact: <sip:spzero@xxxxxxxxxxxxxx:12005> DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | Dialog.cxx:133 | mRemoteTarget: <sip:candid@xxxxxxxxxxxxxx:5060> DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | Dialog.cxx:227 | Dialog::Dialog 26-7258@xxxxxxxxxxxxxxxxxxxxxxxxxx DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogSet.cxx:774 | ### Calling CreateAppDialog ###: 

INVITE sip:spzero@xxxxxxxxxxxxxx:12005 SIP/2.0
Via: SIP/2.0/UDP 192.168.61.132:5060;branch=z9hG4bK-7258-26-0
Max-Forwards: 70
Contact: <sip:candid@xxxxxxxxxxxxxx:5060>
To: "spzero"<sip:spzero@xxxxxxxxxxxxxx:12005>
From: "candid"<sip:candid@xxxxxxxxxxxxxx:5060>;tag=26
Call-ID: 26-7258@xxxxxxxxxxxxxx
CSeq: 26 INVITE
Allow: INVITE, ACK, MESSAGE
Content-Type: text/xml
Content-Length: 180

<?xml version="1.0" encoding="ISO-8859-1" ?>
<request>
<name>Trac</name>
<extended type="size">0</extended>
<extended type="date">01.01.1900-01.01.2100</extended>
</request>
DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | Dialog.cxx:313 | Dialog::dispatch: SipReq: INVITE spzero@xxxxxxxxxxxxxx:12005 tid=-7258-26-0 cseq=INVITE contact=candid@xxxxxxxxxxxxxx:5060 / 26 from(wire) DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | Dialog.cxx:345 | Dialog::dispatch -- Created new server invite sessionSipReq: INVITE spzero@xxxxxxxxxxxxxx:12005 tid=-7258-26-0 cseq=INVITE contact=candid@xxxxxxxxxxxxxx:5060 / 26 from(wire) DEBUG | 20070514-223643.847 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | InviteSession.cxx:73 | ^^^ InviteSession::InviteSession 0x8398c70 DEBUG | 20070514-223643.848 | kenobi | nsp | RESIP | 5165 | 3079915904 | SipMessage.cxx:963 | SipMessage::getContents: text/xml INFO | 20070514-223643.848 | kenobi | nsp | RESIP | 5165 | 3079915904 | SipMessage.cxx:972 | SipMessage::getContents: got content type (text/xml) that is not known, returning as opaque application/octet-stream INFO | 20070514-223643.848 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | InviteSession.cxx:2067 | Transition UAS_Start -> UAS_NoOffer INFO | 20070514-223643.852 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | ServerInviteSession.cxx:384 | UAS_NoOffer: reject(606) DEBUG | 20070514-223643.852 | kenobi | nsp | RESIP | 5165 | 3079915904 | Helper.cxx:372 | Helper::makeResponse(SipReq: INVITE spzero@xxxxxxxxxxxxxx:12005 tid=-7258-26-0 cseq=INVITE contact=candid@xxxxxxxxxxxxxx:5060 / 26 from(wire) code=606 reason= DEBUG | 20070514-223643.852 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | Dialog.cxx:982 | Dialog::makeResponse: 

SIP/2.0 606 Not Acceptable
Via: SIP/2.0/UDP 192.168.61.132:5060;branch=z9hG4bK-7258-26-0
To: "spzero"<sip:spzero@xxxxxxxxxxxxxx:12005>;tag=ec956632
From: "candid"<sip:candid@xxxxxxxxxxxxxx:5060>;tag=26
Call-ID: 26-7258@xxxxxxxxxxxxxx
CSeq: 26 INVITE
Content-Length: 0
DEBUG | 20070514-223643.852 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogUsageManager.cxx:800 | SEND: 

SIP/2.0 606 Not Acceptable
Via: SIP/2.0/UDP 192.168.61.132:5060;branch=z9hG4bK-7258-26-0
To: "spzero"<sip:spzero@xxxxxxxxxxxxxx:12005>;tag=ec956632
From: "candid"<sip:candid@xxxxxxxxxxxxxx:5060>;tag=26
Call-ID: 26-7258@xxxxxxxxxxxxxx
CSeq: 26 INVITE
Content-Type: text/xml
Content-Length: 50

<?xml version="1.0" ?><reply status="Not found" />
DEBUG | 20070514-223643.852 | kenobi | nsp | RESIP | 5165 | 3079915904 | SipStack.cxx:290 | SEND: SipResp: 606 tid=-7258-26-0 cseq=INVITE / 26 from(tu) INFO | 20070514-223643.852 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | InviteSession.cxx:2067 | Transition UAS_NoOffer -> InviteSession::Terminated DEBUG | 20070514-223643.852 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | InviteSession.cxx:79 | ^^^ InviteSession::~InviteSession 0x8398c70 DEBUG | 20070514-223643.852 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | Dialog.cxx:232 | Dialog::~Dialog() DEBUG | 20070514-223643.852 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogUsageManager.cxx:1986 | Got merged request removal request DEBUG | 20070514-223643.852 | kenobi | nsp | RESIP:TRANSACTION | 5165 | 3079915904 | TimerQueue.cxx:105 | Adding application timer: DEBUG | 20070514-223643.852 | kenobi | nsp | RESIP:DUM | 5165 | 3079915904 | DialogSet.cxx:122 | ********** DialogSet::~DialogSet: 26-7258@xxxxxxxxxxxxxxxxxxxxxxx************* DEBUG | 20070514-223643.910 | kenobi | nsp | RESIP:TRANSPORT | 5165 | 3079915904 | Transport.cxx:287 | incoming from: [ V4 192.168.61.132:5060 UDP target domain=unspecified received on: Transport: [ V4 0.0.0.0:12005 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] DEBUG | 20070514-223643.911 | kenobi | nsp | RESIP:TRANSACTION | 5165 | 3079915904 | TimerQueue.cxx:85 | Adding timer: Timer H tid=-7258-26-0 ms=64000 DEBUG | 20070514-223643.911 | kenobi | nsp | RESIP:TRANSACTION | 5165 | 3079915904 | TimerQueue.cxx:85 | Adding timer: Timer G tid=-7258-26-0 ms=1000 DEBUG | 20070514-223643.911 | kenobi | nsp | RESIP:TRANSPORT | 5165 | 3079915904 | TransportSelector.cxx:521 | Looked up source for destination: [ V4 192.168.61.132:5060 UDP target domain=unspecified received on: Transport: [ V4 0.0.0.0:12005 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] -> [ V4 192.168.61.130:0 UDP target domain=unspecified received on: Transport: [ V4 0.0.0.0:12005 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] sent-by=192.168.61.132 sent-port=5060 DEBUG | 20070514-223643.911 | kenobi | nsp | RESIP:TRANSPORT | 5165 | 3079915904 | TransportSelector.cxx:879 | Transmitting to [ V4 192.168.61.132:5060 UDP target domain=unspecified received on: Transport: [ V4 0.0.0.0:12005 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] tlsDomain= via [ V4 192.168.61.130:12005 UDP target domain=unspecified received on: Transport: [ V4 0.0.0.0:12005 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] 

SIP/2.0 606 Not Acceptable
Via: SIP/2.0/UDP 192.168.61.132:5060;branch=z9hG4bK-7258-26-0
To: "spzero"<sip:spzero@xxxxxxxxxxxxxx:12005>;tag=ec956632
From: "candid"<sip:candid@xxxxxxxxxxxxxx:5060>;tag=26
Call-ID: 26-7258@xxxxxxxxxxxxxx
CSeq: 26 INVITE
Content-Type: text/xml
Content-Length: 50

<?xml version="1.0" ?><reply status="Not found" />
==================================================
DEBUG | 20070514-223644.055 | kenobi | nsp | RESIP:TRANSPORT | 5165 | 3079915904 | UdpTransport.cxx:81 | Sent: SIP/2.0 606 Not Acceptable 
Via: SIP/2.0/UDP 192.168.61.132:5060;branch=z9hG4bK-7258-26-0
To: "spzero"<sip:spzero@xxxxxxxxxxxxxx:12005>;tag=ec956632
From: "candid"<sip:candid@xxxxxxxxxxxxxx:5060>;tag=26
Call-ID: 26-7258@xxxxxxxxxxxxxx
CSeq: 26 INVITE
Content-Type: text/xml
Content-Length: 50

<?xml version="1.0" ?><reply status="Not found" />
DEBUG | 20070514-223644.057 | kenobi | nsp | RESIP:TRANSPORT | 5165 | 3079915904 | Transport.cxx:287 | incoming from: [ V4 192.168.61.132:5060 UDP target domain=unspecified received on: Transport: [ V4 0.0.0.0:12005 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] DEBUG | 20070514-223644.057 | kenobi | nsp | RESIP:TRANSACTION | 5165 | 3079915904 | TimerQueue.cxx:85 | Adding timer: Timer H tid=-7258-27-0 ms=64000 DEBUG | 20070514-223644.057 | kenobi | nsp | RESIP:TRANSACTION | 5165 | 3079915904 | TimerQueue.cxx:85 | Adding timer: Timer G tid=-7258-27-0 ms=1000 DEBUG | 20070514-223644.057 | kenobi | nsp | RESIP:TRANSPORT | 5165 | 3079915904 | TransportSelector.cxx:521 | Looked up source for destination: [ V4 192.168.61.132:5060 UDP target domain=unspecified received on: Transport: [ V4 0.0.0.0:12005 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] -> [ V4 192.168.61.130:0 UDP target domain=unspecified received on: Transport: [ V4 0.0.0.0:12005 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] sent-by=192.168.61.132 sent-port=5060 DEBUG | 20070514-223644.057 | kenobi | nsp | RESIP:TRANSPORT | 5165 | 3079915904 | TransportSelector.cxx:879 | Transmitting to [ V4 192.168.61.132:5060 UDP target domain=unspecified received on: Transport: [ V4 0.0.0.0:12005 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] tlsDomain= via [ V4 192.168.61.130:12005 UDP target domain=unspecified received on: Transport: [ V4 0.0.0.0:12005 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] 

SIP/2.0 606 Not Acceptable
Via: SIP/2.0/UDP 192.168.61.132:5060;branch=z9hG4bK-7258-27-0
To: "spzero"<sip:spzero@xxxxxxxxxxxxxx:12005>;tag=e10c9500
From: "aceline"<sip:aceline@xxxxxxxxxxxxxx:5060>;tag=27
Call-ID: 27-7258@xxxxxxxxxxxxxx
CSeq: 27 INVITE
Content-Type: text/xml
Content-Length: 50

<?xml version="1.0" ?><reply status="Not found" />
DEBUG | 20070514-223644.057 | kenobi | nsp | RESIP:TRANSPORT | 5165 | 3079915904 | Transport.cxx:213 | Adding message to tx buffer to: [ V4 192.168.61.132:5060 UDP target domain=unspecified received on: Transport: [ V4 0.0.0.0:12005 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] DEBUG | 20070514-223644.057 | kenobi | nsp | RESIP:TRANSACTION | 5165 | 3079915904 | TimerQueue.cxx:85 | Adding timer: Timer I tid=-7258-19-0 ms=10000 DEBUG | 20070514-223644.109 | kenobi | nsp | RESIP:TRANSPORT | 5165 | 3079915904 | UdpTransport.cxx:81 | Sent: SIP/2.0 606 Not Acceptable 
Via: SIP/2.0/UDP 192.168.61.132:5060;branch=z9hG4bK-7258-27-0
To: "spzero"<sip:spzero@xxxxxxxxxxxxxx:12005>;tag=e10c9500
From: "aceline"<sip:aceline@xxxxxxxxxxxxxx:5060>;tag=27
Call-ID: 27-7258@xxxxxxxxxxxxxx
CSeq: 27 INVITE
Content-Type: text/xml
Content-Length: 50

<?xml version="1.0" ?><reply status="Not found" />
==================================================
DEBUG | 20070514-223645.047 | kenobi | nsp | RESIP:TRANSPORT | 5165 | 3079915904 | UdpTransport.cxx:81 | Sent: SIP/2.0 606 Not Acceptable 
Via: SIP/2.0/UDP 192.168.61.132:5060;branch=z9hG4bK-7258-26-0
To: "spzero"<sip:spzero@xxxxxxxxxxxxxx:12005>;tag=ec956632
From: "candid"<sip:candid@xxxxxxxxxxxxxx:5060>;tag=26
Call-ID: 26-7258@xxxxxxxxxxxxxx
CSeq: 26 INVITE
Content-Type: text/xml
Content-Length: 50

<?xml version="1.0" ?><reply status="Not found" />
==================================================