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

[reSIProcate] UA "486 Busy Here" & ACK in case of SIP-Proxy

From: "Clemens Fischer (VI/SEA)" <clemens.fischer@xxxxxxxxxxxx>
Date: Mon, 7 Mar 2005 09:40:50 +0100

Hi reSIProcate gurus,

I've implemented a small (demo)UA and found a problem I couldn't come around. My problem is that if (via proxy) my UA e.g. calls itself, my UA will respond with 486 (busy here) and the ACK is sent towards the proxy (which will correctly skip the ACK). According to my knowledge the ACK sould be addressed directly to my UA ..

UA (x.x.111.35) Proxy UA (x.x.111.35)

| INVITE | |

| --------------> | Invite |

| | -------------> |

| | 486 |

| 486 | <------------- |

| <-------------- | |

["is"]

| ACK | |

| --------------> | |

| | 486(retrans) |

| 486(retrans) | <------------- |

| <-------------- | |

etc.

["should???"]

| ACK | |

| -------------------------------> |

I've alread scanned all threads but couldn't find any related issue(s) ...

Thnx for your help

// Clemens

DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\sipstack.cxx:199 | SEND: SipRequest: INVITE 200@xxxxxxxxxxxxxx:5060 tid=752251566 cseq=INVITE / 1 from(tu)
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:154 | No matching transaction for SipRequest: INVITE 200@xxxxxxxxxxxxxx:5060 tid=752251566 cseq=INVITE / 1 from(tu)
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:37 | Creating new TransactionState: tid=752251566 [ ClientInvite/Calling reliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:488 | TransactionState::processClientInvite: SipRequest: INVITE 200@xxxxxxxxxxxxxx:5060 tid=752251566 cseq=INVITE / 1 from(tu) tid=752251566 [ ClientInvite/Calling reliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\timerqueue.cxx:59 | Adding timer: Timer B tid=752251566 ms=32000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:1376 | sendToWire with no dns result: tid=752251566 [ ClientInvite/Calling reliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:274 | Looking up dns entries for sip:200@xxxxxxxxxxxxxx:5060
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\dnsresult.cxx:117 | DnsResult::lookup sip:200@xxxxxxxxxxxxxx:5060
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\dnsresult.cxx:166 | Numeric result so return immediately: [ V4 159.107.113.93:5060 , UDP ,transport=00000000 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:1219 | tid=752251566 [ ClientInvite/Calling reliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]] got DNS result:
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\dnsresult.cxx:110 | Returning next dns entry: [ V4 159.107.113.93:5060 , UDP ,transport=00000000 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:1262 | Unreliable transport: tid=752251566 [ ClientInvite/Calling unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\timerqueue.cxx:59 | Adding timer: Timer A tid=752251566 ms=500
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:356 | Looked up source for [ V4 159.107.113.93:5060 , UDP ,transport=00000000 ,connectionId=0 ] -> [ V4 159.107.111.35:0 , UDP ,transport=00000000 ,connectionId=0 ] sent-by= sent-port=0
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:539 | findTransport([ V4 159.107.111.35:0 , UDP ,transport=00000000 ,connectionId=0 ])
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:581 | findTransport (any port, any interface) => Transport: [ V4 0.0.0.0:5077 , UDP ,transport=00000000 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:483 | Transmitting to [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ] via [ V4 159.107.111.35:0 , UDP ,transport=00000000 ,connectionId=0 ]
INVITE sip:200@xxxxxxxxxxxxxx:5060 SIP/2.0
To: 200<sip:200@xxxxxxxxxxxxxx:5060>
From: 200<sip:200@xxxxxxxxxxxxxx:5060>;tag=23482900
Via: SIP/2.0/UDP 159.107.111.35:5077;branch=z9hG4bK-c87542-752251566-1--c87542-;rport
Call-ID: 8467be186c3de14a
CSeq: 1 INVITE
Contact: 200<sip:200@xxxxxxxxxxxxxx:5077>
Max-Forwards: 70
Content-Length: 0
EriSpecificData: 7@xxxxxxxxxxxxxx

DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:312 | Adding message to tx buffer to: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for Timer: Timer K 5000 -> tid=1043608801 [ ClientNonInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:362 | TransactionState::processClientNonInvite: Timer: Timer K 5000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\dnsresult.cxx:70 | DnsResult::destroy()
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\dnsresult.cxx:62 | DnsResult::~DnsResult()
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:67 | Deleting TransactionState 1043608801 : 01362978
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for Timer: Timer K 5000 -> tid=5310738 [ ClientNonInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:362 | TransactionState::processClientNonInvite: Timer: Timer K 5000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\dnsresult.cxx:70 | DnsResult::destroy()
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\dnsresult.cxx:62 | DnsResult::~DnsResult()
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:67 | Deleting TransactionState 5310738 : 01373BB8
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\udptransport.cxx:146 | Received from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:383 | incoming from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
INVITE sip:200@xxxxxxxxxxxxxx:5077 SIP/2.0
To: 200 <sip:200@xxxxxxxxxxxxxx:5060>
From: 200 <sip:200@xxxxxxxxxxxxxx:5060>;tag=23482900
Via: SIP/2.0/UDP 159.107.113.93:5060;branch=z9hG4bK110a78e6;received=159.107.113.93
Via: SIP/2.0/UDP 159.107.111.35:5077;branch=z9hG4bK-c87542-752251566-1--c87542-;rport
Call-ID: 8467be186c3de14a
CSeq: 1 INVITE
Contact: 200 <sip:200@xxxxxxxxxxxxxx:5077>
Max-Forwards: 69
Content-Length: 0
EriSpecificData: 7@xxxxxxxxxxxxxx

DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:154 | No matching transaction for SipRequest: INVITE 200@xxxxxxxxxxxxxx:5077 tid=110a78e6 cseq=INVITE / 1 from(wire)
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:37 | Creating new TransactionState: tid=110a78e6 [ ServerInvite/Trying reliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\helper.cxx:203 | Helper::makeResponse(SipRequest: INVITE 200@xxxxxxxxxxxxxx:5077 tid=110a78e6 cseq=INVITE / 1 from(wire) code=100 reason=
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\timerqueue.cxx:59 | Adding timer: Timer Trying tid=110a78e6 ms=80
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for Timer: Timer K 5000 -> tid=63189156 [ ClientNonInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:362 | TransactionState::processClientNonInvite: Timer: Timer K 5000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\dnsresult.cxx:70 | DnsResult::destroy()
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\dnsresult.cxx:62 | DnsResult::~DnsResult()
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:67 | Deleting TransactionState 63189156 : 013784B8
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\sipstack.cxx:254 | RECV: SipRequest: INVITE 200@xxxxxxxxxxxxxx:5077 tid=110a78e6 cseq=INVITE / 1 from(wire)
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\helper.cxx:203 | Helper::makeResponse(SipRequest: INVITE 200@xxxxxxxxxxxxxx:5077 tid=110a78e6 cseq=INVITE / 1 from(wire) code=486 reason=
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\sipstack.cxx:199 | SEND: SipResponse: 486 tid=110a78e6 cseq=INVITE / 1 from(tu)
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for SipResponse: 486 tid=110a78e6 cseq=INVITE / 1 from(tu) -> tid=110a78e6 [ ServerInvite/Proceeding unreliable target=[ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:806 | TransactionState::processServerInvite: SipResponse: 486 tid=110a78e6 cseq=INVITE / 1 from(tu)
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:949 | Received failed response in Trying or Proceeding. Start Timer H, move to completed.tid=110a78e6 [ ServerInvite/Proceeding unreliable target=[ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\timerqueue.cxx:59 | Adding timer: Timer H tid=110a78e6 ms=32000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\timerqueue.cxx:59 | Adding timer: Timer G tid=110a78e6 ms=500
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:1362 | sending to : [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:356 | Looked up source for [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ] -> [ V4 159.107.111.35:5060 , UDP ,transport=0090A190 ,connectionId=0 ] sent-by=159.107.113.93 sent-port=5060
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:470 | !sipit! Populated Contact: <sip:159.107.111.35:5077>
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:483 | Transmitting to [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ] via [ V4 159.107.111.35:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
SIP/2.0 486 Busy Here
To: 200 <sip:200@xxxxxxxxxxxxxx:5060>
From: 200 <sip:200@xxxxxxxxxxxxxx:5060>;tag=23482900
Via: SIP/2.0/UDP 159.107.113.93:5060;branch=z9hG4bK110a78e6;received=159.107.113.93
Via: SIP/2.0/UDP 159.107.111.35:5077;branch=z9hG4bK-c87542-752251566-1--c87542-;rport
Call-ID: 8467be186c3de14a
CSeq: 1 INVITE
Contact: <sip:159.107.111.35:5077>
Content-Length: 0

DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:312 | Adding message to tx buffer to: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for Timer: Timer K 5000 -> tid=933576914 [ ClientNonInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:362 | TransactionState::processClientNonInvite: Timer: Timer K 5000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\dnsresult.cxx:70 | DnsResult::destroy()
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\dnsresult.cxx:62 | DnsResult::~DnsResult()
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:67 | Deleting TransactionState 933576914 : 013781D8
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for Timer: Timer K 5000 -> tid=315426701 [ ClientNonInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:362 | TransactionState::processClientNonInvite: Timer: Timer K 5000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\dnsresult.cxx:70 | DnsResult::destroy()
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\dnsresult.cxx:62 | DnsResult::~DnsResult()
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:67 | Deleting TransactionState 315426701 : 01368E48
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\udptransport.cxx:146 | Received from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:383 | incoming from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
SIP/2.0 486 Busy Here
To: 200 <sip:200@xxxxxxxxxxxxxx:5060>
From: 200 <sip:200@xxxxxxxxxxxxxx:5060>;tag=23482900
Via: SIP/2.0/UDP 159.107.111.35:5077;branch=z9hG4bK-c87542-752251566-1--c87542-;rport
Call-ID: 8467be186c3de14a
CSeq: 1 INVITE
Contact: <sip:159.107.111.35:5077>
Content-Length: 0

DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\sipstack.cxx:254 | RECV: SipResponse: 486 tid=752251566 cseq=INVITE / 1 from(wire)
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\helper.cxx:203 | Helper::makeResponse(SipRequest: INVITE 200@xxxxxxxxxxxxxx:5060 tid=752251566 cseq=INVITE / 1 from(tu) code=486 reason=
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\sipstack.cxx:199 | SEND: SipResponse: 486 tid=752251566 cseq=INVITE / 1 from(wire)
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:154 | No matching transaction for SipResponse: 486 tid=752251566 cseq=INVITE / 1 from(tu)
INFO | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:290 | discarding stray response: SipResponse: 486 tid=752251566 cseq=INVITE / 1 from(tu)
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for Timer: Timer Trying 80 -> tid=110a78e6 [ ServerInvite/Completed unreliable target=[ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:806 | TransactionState::processServerInvite: Timer: Timer Trying 80
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for Timer: Timer A 500 -> tid=752251566 [ ClientInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:488 | TransactionState::processClientInvite: Timer: Timer A 500 tid=752251566 [ ClientInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:630 | timer fired: TimerMessage TransactionId[752251566] Type[Timer A] duration[500]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for Timer: Timer G 500 -> tid=110a78e6 [ ServerInvite/Completed unreliable target=[ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:806 | TransactionState::processServerInvite: Timer: Timer G 500
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:995 | TimerG fired. retransmit, and re-add TimerG
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:1362 | sending to : [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:506 | !ah! retransmit to [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:312 | Adding message to tx buffer to: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\timerqueue.cxx:59 | Adding timer: Timer G tid=110a78e6 ms=1000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\udptransport.cxx:146 | Received from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:383 | incoming from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
SIP/2.0 486 Busy Here
To: 200 <sip:200@xxxxxxxxxxxxxx:5060>
From: 200 <sip:200@xxxxxxxxxxxxxx:5060>;tag=23482900
Via: SIP/2.0/UDP 159.107.111.35:5077;branch=z9hG4bK-c87542-752251566-1--c87542-;rport
Call-ID: 8467be186c3de14a
CSeq: 1 INVITE
Contact: <sip:159.107.111.35:5077>
Content-Length: 0

DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for SipResponse: 486 tid=752251566 cseq=INVITE / 1 from(wire) -> tid=752251566 [ ClientInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:488 | TransactionState::processClientInvite: SipResponse: 486 tid=752251566 cseq=INVITE / 1 from(wire) tid=752251566 [ ClientInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:506 | !ah! retransmit to [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:312 | Adding message to tx buffer to: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for Timer: Timer G 1000 -> tid=110a78e6 [ ServerInvite/Completed unreliable target=[ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:806 | TransactionState::processServerInvite: Timer: Timer G 1000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:995 | TimerG fired. retransmit, and re-add TimerG
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:1362 | sending to : [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:506 | !ah! retransmit to [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:312 | Adding message to tx buffer to: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\timerqueue.cxx:59 | Adding timer: Timer G tid=110a78e6 ms=2000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\udptransport.cxx:146 | Received from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:383 | incoming from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
SIP/2.0 486 Busy Here
To: 200 <sip:200@xxxxxxxxxxxxxx:5060>
From: 200 <sip:200@xxxxxxxxxxxxxx:5060>;tag=23482900
Via: SIP/2.0/UDP 159.107.111.35:5077;branch=z9hG4bK-c87542-752251566-1--c87542-;rport
Call-ID: 8467be186c3de14a
CSeq: 1 INVITE
Contact: <sip:159.107.111.35:5077>
Content-Length: 0

DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for SipResponse: 486 tid=752251566 cseq=INVITE / 1 from(wire) -> tid=752251566 [ ClientInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:488 | TransactionState::processClientInvite: SipResponse: 486 tid=752251566 cseq=INVITE / 1 from(wire) tid=752251566 [ ClientInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:506 | !ah! retransmit to [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:312 | Adding message to tx buffer to: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for Timer: Timer G 2000 -> tid=110a78e6 [ ServerInvite/Completed unreliable target=[ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:806 | TransactionState::processServerInvite: Timer: Timer G 2000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:995 | TimerG fired. retransmit, and re-add TimerG
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:1362 | sending to : [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:506 | !ah! retransmit to [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:312 | Adding message to tx buffer to: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\timerqueue.cxx:59 | Adding timer: Timer G tid=110a78e6 ms=4000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\udptransport.cxx:146 | Received from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:383 | incoming from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
SIP/2.0 486 Busy Here
To: 200 <sip:200@xxxxxxxxxxxxxx:5060>
From: 200 <sip:200@xxxxxxxxxxxxxx:5060>;tag=23482900
Via: SIP/2.0/UDP 159.107.111.35:5077;branch=z9hG4bK-c87542-752251566-1--c87542-;rport
Call-ID: 8467be186c3de14a
CSeq: 1 INVITE
Contact: <sip:159.107.111.35:5077>
Content-Length: 0

DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for SipResponse: 486 tid=752251566 cseq=INVITE / 1 from(wire) -> tid=752251566 [ ClientInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:488 | TransactionState::processClientInvite: SipResponse: 486 tid=752251566 cseq=INVITE / 1 from(wire) tid=752251566 [ ClientInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:506 | !ah! retransmit to [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:312 | Adding message to tx buffer to: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for Timer: Timer G 4000 -> tid=110a78e6 [ ServerInvite/Completed unreliable target=[ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:806 | TransactionState::processServerInvite: Timer: Timer G 4000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:995 | TimerG fired. retransmit, and re-add TimerG
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:1362 | sending to : [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:506 | !ah! retransmit to [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:312 | Adding message to tx buffer to: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\timerqueue.cxx:59 | Adding timer: Timer G tid=110a78e6 ms=8000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\udptransport.cxx:146 | Received from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:383 | incoming from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
SIP/2.0 486 Busy Here
To: 200 <sip:200@xxxxxxxxxxxxxx:5060>
From: 200 <sip:200@xxxxxxxxxxxxxx:5060>;tag=23482900
Via: SIP/2.0/UDP 159.107.111.35:5077;branch=z9hG4bK-c87542-752251566-1--c87542-;rport
Call-ID: 8467be186c3de14a
CSeq: 1 INVITE
Contact: <sip:159.107.111.35:5077>
Content-Length: 0

DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for SipResponse: 486 tid=752251566 cseq=INVITE / 1 from(wire) -> tid=752251566 [ ClientInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:488 | TransactionState::processClientInvite: SipResponse: 486 tid=752251566 cseq=INVITE / 1 from(wire) tid=752251566 [ ClientInvite/Completed unreliable target=[ V4 0.0.0.0:0 , UNKNOWN_TRANSPORT ,transport=00000000 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:506 | !ah! retransmit to [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:312 | Adding message to tx buffer to: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:119 | Found matching transaction for Timer: Timer G 8000 -> tid=110a78e6 [ ServerInvite/Completed unreliable target=[ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:806 | TransactionState::processServerInvite: Timer: Timer G 8000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:995 | TimerG fired. retransmit, and re-add TimerG
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transactionstate.cxx:1362 | sending to : [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transportselector.cxx:506 | !ah! retransmit to [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:312 | Adding message to tx buffer to: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\timerqueue.cxx:59 | Adding timer: Timer G tid=110a78e6 ms=16000
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\udptransport.cxx:146 | Received from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
DEBUG | c:\data\sip\resiprocate\source\resiprocate-0.4.0\resiprocate\transport.cxx:383 | incoming from: [ V4 159.107.113.93:5060 , UDP ,transport=0090A190 ,connectionId=0 ]
SIP/2.0 486 Busy Here
To: 200 <sip:200@xxxxxxxxxxxxxx:5060>
From: 200 <sip:200@xxxxxxxxxxxxxx:5060>;tag=23482900
Via: SIP/2.0/UDP 159.107.111.35:5077;branch=z9hG4bK-c87542-752251566-1--c87542-;rport
Call-ID: 8467be186c3de14a
CSeq: 1 INVITE
Contact: <sip:159.107.111.35:5077>
Content-Length: 0

Follow-Ups:
- Re: [reSIProcate] UA "486 Busy Here" & ACK in case of SIP-Proxy
  - From: Fischl jason

Prev by Date: RE: [reSIProcate] problem compiling sbv resiprocate project!!
Next by Date: Re: [reSIProcate] UA "486 Busy Here" & ACK in case of SIP-Proxy
Previous by thread: RE: [reSIProcate] problem compiling sbv resiprocate project!!
Next by thread: Re: [reSIProcate] UA "486 Busy Here" & ACK in case of SIP-Proxy
Index(es):
- Date
- Thread