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

Re: [reSIProcate] Resiprocate/DUM assert hit when rearrenged/lost packets received

From: Szokovacs Robert <robert.szokovacs@xxxxxxxxxxx>
Date: Fri, 21 Jul 2017 14:47:06 +0200

Hi,

Attached are the two runs' logs.

br

Szo

On 2017-07-13 16:13, Scott Godin wrote:

Hi Szo,

Thanks for the reminder on this issue.

The log output (at DEBUG level) from BasicCall would make things much easier for someone to troubleshoot, without needing to setup the test.

Scott

On Thu, Jul 13, 2017 at 9:33 AM, Szokovacs Robert <robert.szokovacs@xxxxxxxxxxx> wrote:

Hello all,

We still have this problem and I still can't solve it unfortunately :(
I have created a barebones testcase that reproduces the scenarios.
The attached sipp scenario XMLs should be run like:

./sipp -i 127.0.0.1 -p 12010 -sf refer100.xml
or
./sipp -i 127.0.0.1 -p 12010 -sf refer.xml

and run the BasicCall from resip/dum/test patched with the attached
diff. This test app has only one leg, the client leg in my original
post, and I simulated the BYE from the "A" leg with end() in the
onNewSubscriptionFromRefer(). The BasicCall app will crash and produce
the stacktrace I described below.

Please take a look!

TIA

br

Szo

On 2016-11-11 11:41, Szokovacs Robert wrote:
> Hi all,
>
> We have found a situation where a malicious third party possibly can
> crash the resiprocate based application by carefully rearranging SIP
> packets.
>
> We have the following setup: the resiprocate-based B2BUA receives the
> incoming call, calls the application server on an other leg, which,
> after some processing, REFERs the call towards it's final destination.
>
> Relevant packet flow:
>
> 1, A leg -> INVITE -> B2BUA
>
> 2, A leg <- 100 <- B2BUA
>
> 3, A leg <- 200OK <- B2BUA
>
> 4, B2BUA -> INVITE -> AppServer
>
> 5, B2BUA <- 100 <- AppServer
>
> 6, B2BUA <- 200OK <- AppServer
>
> 7, B2BUA -> ACK -> AppServer
>
> 8, B2BUA <- REFER <- AppServer
>
> 9, B2BUA -> 202 -> AppServer
>
> Etc, etc.
>
>
> In our situation packet #6 got lost and for reasons not important here
> the AppServer doesn't wait for ACK (#7) before sending the #8 REFER, #9
> is 491 instead of 202. All this is fine and correct behaviour; the
> problem manifests when the A leg sends BYE, causing our B2BUA to end the
> B leg too (bye calling AppDialogSet::end(), which in turn calls
> DialogSet::end() ), before #6 was retransmitted and received. Upon
> receiving the BYE, our app crashed:
>
> #16 in resip::Dialog::cancel (this=<optimized out>) at Dialog.cxx:341
>
> line 338: void
> Dialog::cancel()
> {
> resip_assert(mType == Invitation);
> ClientInviteSession* uac =
> dynamic_cast<ClientInviteSession*>(mInviteSession);
> resip_assert (uac);
> uac->cancel();
> line 345: }
>
> #17 in resip::DialogSet::end (this=0x874a27) at DialogSet.cxx:987
>
> line 983: for (DialogMap::iterator it = mDialogs.begin(); it !=
> mDialogs.end(); it++)
> {
> try
> {
> it->second->cancel();
> }
> catch (UsageUseException& e)
> {
> InfoLog(<< "Caught: " << e);
> }
> line 993: }
>
>
> Further investigation uncovered an other situation, when both #5 and #6
> is missing and not retransmitted, we hit a different assert, when the
> timeout generates the internal 408 response:
>
> #3 in __GI___assert_fail (assertion=0x875e85 "mDialogs.empty()",
> file=0x85b510 "DialogSet.cxx", line=352, function=0x8768c0 "void
> resip::DialogSet::dispatch(const resip::SipMessage&)") at assert.c:103
> #4 in resip::DialogSet::dispatch (this=0x7efec001f8d0, msg=...) at
> DialogSet.cxx:352
>
> line 350: if (mState == WaitingToEnd)
> {
> resip_assert(mDialogs.empty());
> if (msg.isResponse())
> line 354: {
>
> #5 in resip::DialogUsageManager::processResponse (this=<optimized out>,
> response=...) at DialogUsageManager.cxx:2173
> #6 in resip::DialogUsageManager::incomingProcess (this=0x7efefa6690c0,
> msg=...) at DialogUsageManager.cxx:1680
> #7 in resip::DialogUsageManager::internalProcess (this=0x7efefa6690c0,
> msg=...) at DialogUsageManager.cxx:1486
> #8 in resip::DialogUsageManager::process (this=0x7efefa6690c0,
> mutex=<optimized out>) at DialogUsageManager.cxx:1710
>
>
> What common in these scenarios is that the DialogSet has unexpected
> Dialogs hanging around (in the wrong state in the first case, existing
> at all in the second). We think the root of the problem is that after
> DUM sends the 491 response to the wayward REFER, it should get rid of
> the corresponding Dialog, but for some reason, doesn't. We don't see
> where would it fit naturally to do it, so we have no patch proposal yet,
> please comment, advise!
>
> Thanks in advance!
>
> br
>
> Szo
>

_______________________________________________
resiprocate-devel mailing list
resiprocate-devel@resiprocate.org
https://list.resiprocate.org/mailman/listinfo/resiprocate-devel

This email has been scanned for email related threats and delivered safely by Mimecast.
For more information please visit http://www.mimecast.com

Skipping registration (no arguments).
INFO | 20170721-144618.470 | BasicCall | RESIP:DNS | 139883071379264 | 
dns/AresDns.cxx:388 | DNS initialization: found  1 name servers
INFO | 20170721-144618.470 | BasicCall | RESIP:DNS | 139883071379264 | 
dns/AresDns.cxx:399 |  name server: 127.0.1.1
DEBUG | 20170721-144618.470 | BasicCall | RESIP | 139883071379264 | 
Compression.cxx:44 | COMPRESSION SUPPORT NOT COMPILED IN
DEBUG | 20170721-144618.470 | BasicCall | RESIP | 139883071379264 | 
Compression.cxx:47 | Compression configuration object created; algorithm = 0
DEBUG | 20170721-144618.471 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
TransportSelector.cxx:99 | No compression library available
INFO | 20170721-144618.471 | BasicCall | RESIP:DNS | 139883071379264 | 
DnsUtil.cxx:170 | local hostname does not contain a domain part gollam
DEBUG | 20170721-144618.471 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
InternalTransport.cxx:121 | Creating fd=10 V4/UDP
DEBUG | 20170721-144618.471 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
InternalTransport.cxx:133 | Binding to 0.0.0.0
INFO | 20170721-144618.471 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
UdpTransport.cxx:54 | Creating UDP transport host= port=12005 ipv4=1
DEBUG | 20170721-144618.471 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
UdpTransport.cxx:68 | No compression library available: Transport: [ V4 
0.0.0.0:12005 UDP flowKey=10 ]
DEBUG | 20170721-144618.471 | BasicCall | RESIP:DNS | 139883071379264 | 
DnsUtil.cxx:540 | Considering: lo -> 127.0.0.1 flags=0x49
DEBUG | 20170721-144618.471 | BasicCall | RESIP:DNS | 139883071379264 | 
DnsUtil.cxx:550 |   ignore because: interface is loopback
DEBUG | 20170721-144618.471 | BasicCall | RESIP:DNS | 139883071379264 | 
DnsUtil.cxx:540 | Considering: enp4s0 -> 10.12.12.18 flags=0x1043
DEBUG | 20170721-144618.471 | BasicCall | RESIP:DNS | 139883071379264 | 
DnsUtil.cxx:573 |   using this
DEBUG | 20170721-144618.471 | BasicCall | RESIP | 139883071379264 | 
SipStack.cxx:678 | Adding domain alias: 127.0.0.1:12005
DEBUG | 20170721-144618.471 | BasicCall | RESIP | 139883071379264 | 
SipStack.cxx:678 | Adding domain alias: 10.12.12.18:12005
DEBUG | 20170721-144618.471 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
TransportSelector.cxx:221 | Adding transport: [ V4 0.0.0.0:12005 UDP 
transportKey=1 ]
INFO | 20170721-144618.471 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
TransportSelector.cxx:293 | TransportSelector::addTransport:  added transport 
for tuple=[ V4 0.0.0.0:12005 UDP transportKey=1 ], key=1
DEBUG | 20170721-144618.471 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
ConnectionBase.cxx:71 | ConnectionBase::ConnectionBase, who: [ V4 0.0.0.0:0 
UNKNOWN_TRANSPORT ] 0x557dbf3762b0
DEBUG | 20170721-144618.471 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
ConnectionBase.cxx:84 | No compression library available: 0x557dbf3762b0
INFO | 20170721-144618.471 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
Connection.cxx:45 | Connection::Connection: new connection created to who: [ V4 
0.0.0.0:0 UNKNOWN_TRANSPORT ], is server = 0
DEBUG | 20170721-144618.472 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
ConnectionManager.cxx:34 | ConnectionManager::ConnectionManager() called 
DEBUG | 20170721-144618.472 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
InternalTransport.cxx:121 | Creating fd=13 V4/TCP
DEBUG | 20170721-144618.472 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
InternalTransport.cxx:133 | Binding to 0.0.0.0
INFO | 20170721-144618.472 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
TcpTransport.cxx:39 | Creating TCP transport host= port=12005 ipv4=1
DEBUG | 20170721-144618.472 | BasicCall | RESIP:DNS | 139883071379264 | 
DnsUtil.cxx:540 | Considering: lo -> 127.0.0.1 flags=0x49
DEBUG | 20170721-144618.472 | BasicCall | RESIP:DNS | 139883071379264 | 
DnsUtil.cxx:550 |   ignore because: interface is loopback
DEBUG | 20170721-144618.472 | BasicCall | RESIP:DNS | 139883071379264 | 
DnsUtil.cxx:540 | Considering: enp4s0 -> 10.12.12.18 flags=0x1043
DEBUG | 20170721-144618.472 | BasicCall | RESIP:DNS | 139883071379264 | 
DnsUtil.cxx:573 |   using this
DEBUG | 20170721-144618.472 | BasicCall | RESIP | 139883071379264 | 
SipStack.cxx:678 | Adding domain alias: 127.0.0.1:12005
DEBUG | 20170721-144618.472 | BasicCall | RESIP | 139883071379264 | 
SipStack.cxx:678 | Adding domain alias: 10.12.12.18:12005
DEBUG | 20170721-144618.472 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
TransportSelector.cxx:221 | Adding transport: [ V4 0.0.0.0:12005 TCP 
transportKey=2 ]
INFO | 20170721-144618.472 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
TransportSelector.cxx:293 | TransportSelector::addTransport:  added transport 
for tuple=[ V4 0.0.0.0:12005 TCP transportKey=2 ], key=2
UAC: Sending Invite Request to UAS.
UAC(INVITE): testAppDialogSet: created.
DEBUG | 20170721-144618.522 | BasicCall | RESIP:DUM | 139883071379264 | 
BaseCreator.cxx:148 | BaseCreator::makeInitialRequest: 

0x557dbf37a0a0
DEBUG | 20170721-144618.522 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogSet.cxx:52 |  ************* Created DialogSet(UAC)  -- 
YlsYt7odzBbEeISEPnzNxA..-ce9e4702*************
DEBUG | 20170721-144618.522 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogUsageManager.cxx:990 | SEND: 

INVITE sip:UAS@10.12.2.101:5060 SIP/2.0
Via: SIP/2.0/ ;branch=z9hG4bK-524287-1---c534ff3d1b98c169;rport
Max-Forwards: 70
Contact: <sip:UAC>
To: <sip:UAS@10.12.2.101:5060>
From: <sip:UAC@10.12.2.101:5060>;tag=ce9e4702
Call-ID: YlsYt7odzBbEeISEPnzNxA..
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, UPDATE, INFO, MESSAGE, REFER
Content-Type: application/sdp
Content-Length: 266

v=0
o=1900 369696545 369696545 IN IP4 192.168.2.15
s=X-Lite
c=IN IP4 192.168.2.15
t=0 0
m=audio 8000 RTP/AVP 8 3 98 97 101
a=rtpmap:8 pcma/8000
a=rtpmap:3 gsm/8000
a=rtpmap:98 iLBC
a=rtpmap:97 speex/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

DEBUG | 20170721-144618.523 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogId.cxx:50 | DialogId::DialogId: YlsYt7odzBbEeISEPnzNxA..-ce9e4702-
DEBUG | 20170721-144618.523 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogUsageManager.cxx:1151 | Send: SipReq:  INVITE UAS@10.12.2.101:5060 
tid=c534ff3d1b98c169 cseq=1 INVITE contact=UAC / 1 from(tu)
DEBUG | 20170721-144618.523 | BasicCall | RESIP | 139883071379264 | 
SipStack.cxx:839 | SEND: SipReq:  INVITE UAS@10.12.2.101:5060 
tid=c534ff3d1b98c169 cseq=1 INVITE contact=UAC / 1 from(tu)
DEBUG | 20170721-144618.523 | BasicCall | RESIP:TRANSACTION | 139883071379264 | 
TimerQueue.cxx:50 | Adding timer: Timer B tid=c534ff3d1b98c169 ms=32000
DEBUG | 20170721-144618.523 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
TransportSelector.cxx:556 | Looking up dns entries for sip:UAS@10.12.2.101:5060
DEBUG | 20170721-144618.523 | BasicCall | RESIP:DNS | 139883071379264 | 
DnsResult.cxx:261 | DnsResult::lookup sip:UAS@10.12.2.101:5060
DEBUG | 20170721-144618.523 | BasicCall | RESIP:DNS | 139883071379264 | 
DnsResult.cxx:501 | Numeric result so return immediately: [ V4 10.12.2.101:5060 
UDP targetDomain=10.12.2.101 ]
DEBUG | 20170721-144618.523 | BasicCall | RESIP:TRANSACTION | 139883071379264 | 
TimerQueue.cxx:50 | Adding timer: Timer A tid=c534ff3d1b98c169 ms=500
DEBUG | 20170721-144618.523 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
TransportSelector.cxx:935 | Found transport: [ V4 0.0.0.0:12005 UDP flowKey=10 
transportKey=1 ]
DEBUG | 20170721-144618.523 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
InternalTransport.cxx:121 | Creating fd=14 V4/UDP
DEBUG | 20170721-144618.523 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
TransportSelector.cxx:871 | Looked up source for destination: [ V4 
10.12.2.101:5060 UDP targetDomain=10.12.2.101 ] -> [ V4 10.12.12.18:0 UDP 
targetDomain=10.12.2.101 ] sent-by= sent-port=0
DEBUG | 20170721-144618.523 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
TransportSelector.cxx:1288 | Transmitting to [ V4 10.12.2.101:5060 UDP 
targetDomain=10.12.2.101 transportKey=1 ] tlsDomain= via [ V4 10.12.12.18:12005 
UDP targetDomain=10.12.2.101 ]

INVITE sip:UAS@10.12.2.101:5060 SIP/2.0
Via: SIP/2.0/UDP 
10.12.12.18:12005;branch=z9hG4bK-524287-1---c534ff3d1b98c169;rport
Max-Forwards: 70
Contact: <sip:UAC@10.12.12.18:12005>
To: <sip:UAS@10.12.2.101:5060>
From: <sip:UAC@10.12.2.101:5060>;tag=ce9e4702
Call-ID: YlsYt7odzBbEeISEPnzNxA..
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, UPDATE, INFO, MESSAGE, REFER
Content-Type: application/sdp
Content-Length: 266

v=0
o=1900 369696545 369696545 IN IP4 192.168.2.15
s=X-Lite
c=IN IP4 192.168.2.15
t=0 0
m=audio 8000 RTP/AVP 8 3 98 97 101
a=rtpmap:8 pcma/8000
a=rtpmap:3 gsm/8000
a=rtpmap:98 iLBC
a=rtpmap:97 speex/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
sigcomp id=
DEBUG | 20170721-144618.528 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
Transport.cxx:392 | incoming from: [ V4 10.12.2.101:5060 UDP flowKey=10 
transportKey=1 ]
DEBUG | 20170721-144618.528 | BasicCall | RESIP:TRANSACTION | 139883071379264 | 
TuSelector.cxx:70 | Send to TU: DialogUsageManager size=0 

SIP/2.0 100 Trying
Via: SIP/2.0/UDP 
10.12.12.18:12005;branch=z9hG4bK-524287-1---c534ff3d1b98c169;rport
Contact: sip:sipp@10.12.2.101:5060
To: <sip:UAS@10.12.2.101:5060>
From: <sip:UAC@10.12.2.101:5060>;tag=ce9e4702
Call-ID: YlsYt7odzBbEeISEPnzNxA..
CSeq: 1 INVITE
Content-Length: 0


DEBUG | 20170721-144618.528 | BasicCall | RESIP:DNS | 139883071379264 | 
DnsResult.cxx:253 | Whitelisting 10.12.2.101(1): 10.12.2.101
DEBUG | 20170721-144618.528 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogUsageManager.cxx:1606 | Got: SipResp: 100 tid=c534ff3d1b98c169 cseq=1 
INVITE contact=sipp@10.12.2.101:5060 / 1 from(wire)
DEBUG | 20170721-144618.528 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogUsageManager.cxx:2156 | DialogUsageManager::processResponse: 

SipResp: 100 tid=c534ff3d1b98c169 cseq=1 INVITE contact=sipp@10.12.2.101:5060 / 
1 from(wire)
DEBUG | 20170721-144618.528 | BasicCall | RESIP:TRANSPORT | 139883071379264 | 
Transport.cxx:392 | incoming from: [ V4 10.12.2.101:5060 UDP flowKey=10 
transportKey=1 ]
DEBUG | 20170721-144618.528 | BasicCall | RESIP:TRANSACTION | 139883071379264 | 
TuSelector.cxx:189 | TuSelector::selectTransactionUser: Checking which TU 
message belongs to:

REFER sip:UAC@10.12.12.18:12005 SIP/2.0
Via: SIP/2.0/UDP 10.12.2.101:5060;branch=z9hG4bK-28114-1-2
Max-Forwards: 70
Contact: sip:sipp@10.12.2.101:5060
To: <sip:UAC@10.12.2.101:5060>;tag=ce9e4702
From: <sip:UAS@10.12.2.101:5060>
Call-ID: YlsYt7odzBbEeISEPnzNxA..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789@internal
B2bua-Note: Call-Control;level=123
Content-Length: 0


DEBUG | 20170721-144618.528 | BasicCall | RESIP:TRANSACTION | 139883071379264 | 
TransactionUser.cxx:83 | TransactionUser::isForMe: TU=DialogUsageManager, 
Checking rule... : SipReq:  REFER UAC@10.12.12.18:12005 tid=-28114-1-2 cseq=12 
REFER contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144618.528 | BasicCall | RESIP:TRANSACTION | 139883071379264 | 
TransactionUser.cxx:86 | TransactionUser::isForMe: TU=DialogUsageManager, 
Match! : SipReq:  REFER UAC@10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER 
contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144618.528 | BasicCall | RESIP | 139883071379264 | 
Helper.cxx:374 | Helper::makeResponse(SipReq:  REFER UAC@10.12.12.18:12005 
tid=-28114-1-2 cseq=12 REFER contact=sipp@10.12.2.101:5060 / 12 from(wire) 
code=100 reason=
DEBUG | 20170721-144618.528 | BasicCall | RESIP:TRANSACTION | 139883071379264 | 
TimerQueue.cxx:50 | Adding timer: Timer Trying tid=-28114-1-2 ms=3500
DEBUG | 20170721-144618.528 | BasicCall | RESIP:TRANSACTION | 139883071379264 | 
TuSelector.cxx:70 | Send to TU: DialogUsageManager size=0 

REFER sip:UAC@10.12.12.18:12005 SIP/2.0
Via: SIP/2.0/UDP 10.12.2.101:5060;branch=z9hG4bK-28114-1-2
Max-Forwards: 70
Contact: sip:sipp@10.12.2.101:5060
To: <sip:UAC@10.12.2.101:5060>;tag=ce9e4702
From: <sip:UAS@10.12.2.101:5060>
Call-ID: YlsYt7odzBbEeISEPnzNxA..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789@internal
B2bua-Note: Call-Control;level=123
Content-Length: 0


DEBUG | 20170721-144618.578 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogUsageManager.cxx:1606 | Got: SipReq:  REFER UAC@10.12.12.18:12005 
tid=-28114-1-2 cseq=12 REFER contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogUsageManager.cxx:1964 | DialogUsageManager::processRequest: SipReq:  
REFER UAC@10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER 
contact=sipp@10.12.2.101:5060 / 12 from(wire)
INFO | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogUsageManager.cxx:2024 | Handling in-dialog request: SipReq:  REFER 
UAC@10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER 
contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogId.cxx:50 | DialogId::DialogId: YlsYt7odzBbEeISEPnzNxA..-ce9e4702-
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogSet.cxx:564 | in dialog refer request
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogSet.cxx:854 | mState == 2 Creating a new Dialog from msg: 

REFER sip:UAC@10.12.12.18:12005 SIP/2.0
Via: SIP/2.0/UDP 10.12.2.101:5060;branch=z9hG4bK-28114-1-2
Max-Forwards: 70
Contact: sip:sipp@10.12.2.101:5060
To: <sip:UAC@10.12.2.101:5060>;tag=ce9e4702
From: <sip:UAS@10.12.2.101:5060>
Call-ID: YlsYt7odzBbEeISEPnzNxA..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789@internal
B2bua-Note: Call-Control;level=123
Content-Length: 0


DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
Dialog.cxx:88 | UAS dialog ID creation, DS: YlsYt7odzBbEeISEPnzNxA..-ce9e4702
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogId.cxx:63 | DialogId::DialogId: YlsYt7odzBbEeISEPnzNxA..-ce9e4702-
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
Dialog.cxx:177 | ************** Created Dialog as UAS **************
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
Dialog.cxx:178 | mRemoteNameAddr: <sip:UAS@10.12.2.101:5060>
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
Dialog.cxx:179 | mLocalNameAddr: <sip:UAC@10.12.2.101:5060>;tag=ce9e4702
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
Dialog.cxx:180 | mLocalContact: <sip:UAC>
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
Dialog.cxx:181 | mRemoteTarget: sip:sipp@10.12.2.101:5060
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
Dialog.cxx:274 | Dialog::Dialog YlsYt7odzBbEeISEPnzNxA..-ce9e4702-
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogSet.cxx:901 | ### Calling CreateAppDialog ###: 

REFER sip:UAC@10.12.12.18:12005 SIP/2.0
Via: SIP/2.0/UDP 10.12.2.101:5060;branch=z9hG4bK-28114-1-2
Max-Forwards: 70
Contact: sip:sipp@10.12.2.101:5060
To: <sip:UAC@10.12.2.101:5060>;tag=ce9e4702
From: <sip:UAS@10.12.2.101:5060>
Call-ID: YlsYt7odzBbEeISEPnzNxA..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789@internal
B2bua-Note: Call-Control;level=123
Content-Length: 0


UAC(INVITE): testAppDialog: created.
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
Dialog.cxx:407 | Dialog::dispatch: SipReq:  REFER UAC@10.12.12.18:12005 
tid=-28114-1-2 cseq=12 REFER contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
ServerSubscription.cxx:216 | ServerSubscription::dispatch: SipReq:  REFER 
UAC@10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER 
contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144618.579 | BasicCall | RESIP | 139883071379264 | 
Helper.cxx:374 | Helper::makeResponse(SipReq:  REFER UAC@10.12.12.18:12005 
tid=-28114-1-2 cseq=12 REFER contact=sipp@10.12.2.101:5060 / 12 from(wire) 
code=200 reason=
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
Dialog.cxx:1052 | Dialog::makeResponse: 

SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.12.2.101:5060;branch=z9hG4bK-28114-1-2
Contact: <sip:UAC>
To: <sip:UAC@10.12.2.101:5060>;tag=ce9e4702
From: <sip:UAS@10.12.2.101:5060>
Call-ID: YlsYt7odzBbEeISEPnzNxA..
CSeq: 12 REFER
Content-Length: 0


DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
ServerSubscription.cxx:302 | onNewSubscriptionFromRefer called
UAC: onNewSubscriptionFromRefer - SipReq:  REFER UAC@10.12.12.18:12005 
tid=-28114-1-2 cseq=12 REFER contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogUsageManager.cxx:990 | SEND: 

CANCEL sip:UAS@10.12.2.101:5060 SIP/2.0
Via: SIP/2.0/ ;branch=z9hG4bK-524287-1---c534ff3d1b98c169;rport
Max-Forwards: 70
To: <sip:UAS@10.12.2.101:5060>
From: <sip:UAC@10.12.2.101:5060>;tag=ce9e4702
Call-ID: YlsYt7odzBbEeISEPnzNxA..
CSeq: 1 CANCEL
Content-Length: 0


DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogId.cxx:50 | DialogId::DialogId: YlsYt7odzBbEeISEPnzNxA..-ce9e4702-
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | 
DialogUsageManager.cxx:1151 | Send: SipReq:  CANCEL UAS@10.12.2.101:5060 
tid=c534ff3d1b98c169 cseq=1 CANCEL / 1 from(tu)
DEBUG | 20170721-144618.579 | BasicCall | RESIP | 139883071379264 | 
SipStack.cxx:839 | SEND: SipReq:  CANCEL UAS@10.12.2.101:5060 
tid=c534ff3d1b98c169 cseq=1 CANCEL / 1 from(tu)
BasicCall: Dialog.cxx:341: void resip::Dialog::cancel(): Assertion `mType == 
Invitation' failed.

Skipping registration (no arguments).
INFO | 20170721-144433.106 | BasicCall | RESIP:DNS | 139984863958848 | 
dns/AresDns.cxx:388 | DNS initialization: found  1 name servers
INFO | 20170721-144433.106 | BasicCall | RESIP:DNS | 139984863958848 | 
dns/AresDns.cxx:399 |  name server: 127.0.1.1
DEBUG | 20170721-144433.106 | BasicCall | RESIP | 139984863958848 | 
Compression.cxx:44 | COMPRESSION SUPPORT NOT COMPILED IN
DEBUG | 20170721-144433.106 | BasicCall | RESIP | 139984863958848 | 
Compression.cxx:47 | Compression configuration object created; algorithm = 0
DEBUG | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
TransportSelector.cxx:99 | No compression library available
INFO | 20170721-144433.107 | BasicCall | RESIP:DNS | 139984863958848 | 
DnsUtil.cxx:170 | local hostname does not contain a domain part gollam
DEBUG | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
InternalTransport.cxx:121 | Creating fd=10 V4/UDP
DEBUG | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
InternalTransport.cxx:133 | Binding to 0.0.0.0
INFO | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
UdpTransport.cxx:54 | Creating UDP transport host= port=12005 ipv4=1
DEBUG | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
UdpTransport.cxx:68 | No compression library available: Transport: [ V4 
0.0.0.0:12005 UDP flowKey=10 ]
DEBUG | 20170721-144433.107 | BasicCall | RESIP:DNS | 139984863958848 | 
DnsUtil.cxx:540 | Considering: lo -> 127.0.0.1 flags=0x49
DEBUG | 20170721-144433.107 | BasicCall | RESIP:DNS | 139984863958848 | 
DnsUtil.cxx:550 |   ignore because: interface is loopback
DEBUG | 20170721-144433.107 | BasicCall | RESIP:DNS | 139984863958848 | 
DnsUtil.cxx:540 | Considering: enp4s0 -> 10.12.12.18 flags=0x1043
DEBUG | 20170721-144433.107 | BasicCall | RESIP:DNS | 139984863958848 | 
DnsUtil.cxx:573 |   using this
DEBUG | 20170721-144433.107 | BasicCall | RESIP | 139984863958848 | 
SipStack.cxx:678 | Adding domain alias: 127.0.0.1:12005
DEBUG | 20170721-144433.107 | BasicCall | RESIP | 139984863958848 | 
SipStack.cxx:678 | Adding domain alias: 10.12.12.18:12005
DEBUG | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
TransportSelector.cxx:221 | Adding transport: [ V4 0.0.0.0:12005 UDP 
transportKey=1 ]
INFO | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
TransportSelector.cxx:293 | TransportSelector::addTransport:  added transport 
for tuple=[ V4 0.0.0.0:12005 UDP transportKey=1 ], key=1
DEBUG | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
ConnectionBase.cxx:71 | ConnectionBase::ConnectionBase, who: [ V4 0.0.0.0:0 
UNKNOWN_TRANSPORT ] 0x55ce1d8482b0
DEBUG | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
ConnectionBase.cxx:84 | No compression library available: 0x55ce1d8482b0
INFO | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
Connection.cxx:45 | Connection::Connection: new connection created to who: [ V4 
0.0.0.0:0 UNKNOWN_TRANSPORT ], is server = 0
DEBUG | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
ConnectionManager.cxx:34 | ConnectionManager::ConnectionManager() called 
DEBUG | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
InternalTransport.cxx:121 | Creating fd=13 V4/TCP
DEBUG | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
InternalTransport.cxx:133 | Binding to 0.0.0.0
INFO | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
TcpTransport.cxx:39 | Creating TCP transport host= port=12005 ipv4=1
DEBUG | 20170721-144433.107 | BasicCall | RESIP:DNS | 139984863958848 | 
DnsUtil.cxx:540 | Considering: lo -> 127.0.0.1 flags=0x49
DEBUG | 20170721-144433.107 | BasicCall | RESIP:DNS | 139984863958848 | 
DnsUtil.cxx:550 |   ignore because: interface is loopback
DEBUG | 20170721-144433.107 | BasicCall | RESIP:DNS | 139984863958848 | 
DnsUtil.cxx:540 | Considering: enp4s0 -> 10.12.12.18 flags=0x1043
DEBUG | 20170721-144433.107 | BasicCall | RESIP:DNS | 139984863958848 | 
DnsUtil.cxx:573 |   using this
DEBUG | 20170721-144433.107 | BasicCall | RESIP | 139984863958848 | 
SipStack.cxx:678 | Adding domain alias: 127.0.0.1:12005
DEBUG | 20170721-144433.107 | BasicCall | RESIP | 139984863958848 | 
SipStack.cxx:678 | Adding domain alias: 10.12.12.18:12005
DEBUG | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
TransportSelector.cxx:221 | Adding transport: [ V4 0.0.0.0:12005 TCP 
transportKey=2 ]
INFO | 20170721-144433.107 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
TransportSelector.cxx:293 | TransportSelector::addTransport:  added transport 
for tuple=[ V4 0.0.0.0:12005 TCP transportKey=2 ], key=2
UAC: Sending Invite Request to UAS.
UAC(INVITE): testAppDialogSet: created.
DEBUG | 20170721-144433.158 | BasicCall | RESIP:DUM | 139984863958848 | 
BaseCreator.cxx:148 | BaseCreator::makeInitialRequest: 

0x55ce1d84c0a0
DEBUG | 20170721-144433.158 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogSet.cxx:52 |  ************* Created DialogSet(UAC)  -- 
885lKF_ZxrpwP5gTWZlPdg..-4fd8ad7c*************
DEBUG | 20170721-144433.158 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogUsageManager.cxx:990 | SEND: 

INVITE sip:UAS@10.12.2.101:5060 SIP/2.0
Via: SIP/2.0/ ;branch=z9hG4bK-524287-1---5382820c264cf253;rport
Max-Forwards: 70
Contact: <sip:UAC>
To: <sip:UAS@10.12.2.101:5060>
From: <sip:UAC@10.12.2.101:5060>;tag=4fd8ad7c
Call-ID: 885lKF_ZxrpwP5gTWZlPdg..
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, UPDATE, INFO, MESSAGE, REFER
Content-Type: application/sdp
Content-Length: 266

v=0
o=1900 369696545 369696545 IN IP4 192.168.2.15
s=X-Lite
c=IN IP4 192.168.2.15
t=0 0
m=audio 8000 RTP/AVP 8 3 98 97 101
a=rtpmap:8 pcma/8000
a=rtpmap:3 gsm/8000
a=rtpmap:98 iLBC
a=rtpmap:97 speex/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

DEBUG | 20170721-144433.158 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogId.cxx:50 | DialogId::DialogId: 885lKF_ZxrpwP5gTWZlPdg..-4fd8ad7c-
DEBUG | 20170721-144433.158 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogUsageManager.cxx:1151 | Send: SipReq:  INVITE UAS@10.12.2.101:5060 
tid=5382820c264cf253 cseq=1 INVITE contact=UAC / 1 from(tu)
DEBUG | 20170721-144433.158 | BasicCall | RESIP | 139984863958848 | 
SipStack.cxx:839 | SEND: SipReq:  INVITE UAS@10.12.2.101:5060 
tid=5382820c264cf253 cseq=1 INVITE contact=UAC / 1 from(tu)
DEBUG | 20170721-144433.158 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TimerQueue.cxx:50 | Adding timer: Timer B tid=5382820c264cf253 ms=32000
DEBUG | 20170721-144433.158 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
TransportSelector.cxx:556 | Looking up dns entries for sip:UAS@10.12.2.101:5060
DEBUG | 20170721-144433.158 | BasicCall | RESIP:DNS | 139984863958848 | 
DnsResult.cxx:261 | DnsResult::lookup sip:UAS@10.12.2.101:5060
DEBUG | 20170721-144433.158 | BasicCall | RESIP:DNS | 139984863958848 | 
DnsResult.cxx:501 | Numeric result so return immediately: [ V4 10.12.2.101:5060 
UDP targetDomain=10.12.2.101 ]
DEBUG | 20170721-144433.158 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TimerQueue.cxx:50 | Adding timer: Timer A tid=5382820c264cf253 ms=500
DEBUG | 20170721-144433.158 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
TransportSelector.cxx:935 | Found transport: [ V4 0.0.0.0:12005 UDP flowKey=10 
transportKey=1 ]
DEBUG | 20170721-144433.158 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
InternalTransport.cxx:121 | Creating fd=14 V4/UDP
DEBUG | 20170721-144433.158 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
TransportSelector.cxx:871 | Looked up source for destination: [ V4 
10.12.2.101:5060 UDP targetDomain=10.12.2.101 ] -> [ V4 10.12.12.18:0 UDP 
targetDomain=10.12.2.101 ] sent-by= sent-port=0
DEBUG | 20170721-144433.159 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
TransportSelector.cxx:1288 | Transmitting to [ V4 10.12.2.101:5060 UDP 
targetDomain=10.12.2.101 transportKey=1 ] tlsDomain= via [ V4 10.12.12.18:12005 
UDP targetDomain=10.12.2.101 ]

INVITE sip:UAS@10.12.2.101:5060 SIP/2.0
Via: SIP/2.0/UDP 
10.12.12.18:12005;branch=z9hG4bK-524287-1---5382820c264cf253;rport
Max-Forwards: 70
Contact: <sip:UAC@10.12.12.18:12005>
To: <sip:UAS@10.12.2.101:5060>
From: <sip:UAC@10.12.2.101:5060>;tag=4fd8ad7c
Call-ID: 885lKF_ZxrpwP5gTWZlPdg..
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, UPDATE, INFO, MESSAGE, REFER
Content-Type: application/sdp
Content-Length: 266

v=0
o=1900 369696545 369696545 IN IP4 192.168.2.15
s=X-Lite
c=IN IP4 192.168.2.15
t=0 0
m=audio 8000 RTP/AVP 8 3 98 97 101
a=rtpmap:8 pcma/8000
a=rtpmap:3 gsm/8000
a=rtpmap:98 iLBC
a=rtpmap:97 speex/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
sigcomp id=
DEBUG | 20170721-144433.163 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
Transport.cxx:392 | incoming from: [ V4 10.12.2.101:5060 UDP flowKey=10 
transportKey=1 ]
DEBUG | 20170721-144433.163 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TuSelector.cxx:189 | TuSelector::selectTransactionUser: Checking which TU 
message belongs to:

REFER sip:UAC@10.12.12.18:12005 SIP/2.0
Via: SIP/2.0/UDP 10.12.2.101:5060;branch=z9hG4bK-27472-1-1
Max-Forwards: 70
Contact: sip:sipp@10.12.2.101:5060
To: <sip:UAC@10.12.2.101:5060>;tag=4fd8ad7c
From: <sip:UAS@10.12.2.101:5060>
Call-ID: 885lKF_ZxrpwP5gTWZlPdg..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789@internal
B2bua-Note: Call-Control;level=123
Content-Length: 0


DEBUG | 20170721-144433.163 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TransactionUser.cxx:83 | TransactionUser::isForMe: TU=DialogUsageManager, 
Checking rule... : SipReq:  REFER UAC@10.12.12.18:12005 tid=-27472-1-1 cseq=12 
REFER contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144433.163 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TransactionUser.cxx:86 | TransactionUser::isForMe: TU=DialogUsageManager, 
Match! : SipReq:  REFER UAC@10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER 
contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144433.163 | BasicCall | RESIP | 139984863958848 | 
Helper.cxx:374 | Helper::makeResponse(SipReq:  REFER UAC@10.12.12.18:12005 
tid=-27472-1-1 cseq=12 REFER contact=sipp@10.12.2.101:5060 / 12 from(wire) 
code=100 reason=
DEBUG | 20170721-144433.163 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TimerQueue.cxx:50 | Adding timer: Timer Trying tid=-27472-1-1 ms=3500
DEBUG | 20170721-144433.163 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TuSelector.cxx:70 | Send to TU: DialogUsageManager size=0 

REFER sip:UAC@10.12.12.18:12005 SIP/2.0
Via: SIP/2.0/UDP 10.12.2.101:5060;branch=z9hG4bK-27472-1-1
Max-Forwards: 70
Contact: sip:sipp@10.12.2.101:5060
To: <sip:UAC@10.12.2.101:5060>;tag=4fd8ad7c
From: <sip:UAS@10.12.2.101:5060>
Call-ID: 885lKF_ZxrpwP5gTWZlPdg..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789@internal
B2bua-Note: Call-Control;level=123
Content-Length: 0


DEBUG | 20170721-144433.213 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogUsageManager.cxx:1606 | Got: SipReq:  REFER UAC@10.12.12.18:12005 
tid=-27472-1-1 cseq=12 REFER contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144433.213 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogUsageManager.cxx:1964 | DialogUsageManager::processRequest: SipReq:  
REFER UAC@10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER 
contact=sipp@10.12.2.101:5060 / 12 from(wire)
INFO | 20170721-144433.213 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogUsageManager.cxx:2024 | Handling in-dialog request: SipReq:  REFER 
UAC@10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER 
contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144433.213 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogId.cxx:50 | DialogId::DialogId: 885lKF_ZxrpwP5gTWZlPdg..-4fd8ad7c-
DEBUG | 20170721-144433.213 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogSet.cxx:564 | in dialog refer request
DEBUG | 20170721-144433.213 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogSet.cxx:854 | mState == 0 Creating a new Dialog from msg: 

REFER sip:UAC@10.12.12.18:12005 SIP/2.0
Via: SIP/2.0/UDP 10.12.2.101:5060;branch=z9hG4bK-27472-1-1
Max-Forwards: 70
Contact: sip:sipp@10.12.2.101:5060
To: <sip:UAC@10.12.2.101:5060>;tag=4fd8ad7c
From: <sip:UAS@10.12.2.101:5060>
Call-ID: 885lKF_ZxrpwP5gTWZlPdg..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789@internal
B2bua-Note: Call-Control;level=123
Content-Length: 0


DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | 
Dialog.cxx:88 | UAS dialog ID creation, DS: 885lKF_ZxrpwP5gTWZlPdg..-4fd8ad7c
DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogId.cxx:63 | DialogId::DialogId: 885lKF_ZxrpwP5gTWZlPdg..-4fd8ad7c-
DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | 
Dialog.cxx:177 | ************** Created Dialog as UAS **************
DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | 
Dialog.cxx:178 | mRemoteNameAddr: <sip:UAS@10.12.2.101:5060>
DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | 
Dialog.cxx:179 | mLocalNameAddr: <sip:UAC@10.12.2.101:5060>;tag=4fd8ad7c
DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | 
Dialog.cxx:180 | mLocalContact: <sip:UAC>
DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | 
Dialog.cxx:181 | mRemoteTarget: sip:sipp@10.12.2.101:5060
DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | 
Dialog.cxx:274 | Dialog::Dialog 885lKF_ZxrpwP5gTWZlPdg..-4fd8ad7c-
DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogSet.cxx:901 | ### Calling CreateAppDialog ###: 

REFER sip:UAC@10.12.12.18:12005 SIP/2.0
Via: SIP/2.0/UDP 10.12.2.101:5060;branch=z9hG4bK-27472-1-1
Max-Forwards: 70
Contact: sip:sipp@10.12.2.101:5060
To: <sip:UAC@10.12.2.101:5060>;tag=4fd8ad7c
From: <sip:UAS@10.12.2.101:5060>
Call-ID: 885lKF_ZxrpwP5gTWZlPdg..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789@internal
B2bua-Note: Call-Control;level=123
Content-Length: 0


UAC(INVITE): testAppDialog: created.
DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | 
Dialog.cxx:407 | Dialog::dispatch: SipReq:  REFER UAC@10.12.12.18:12005 
tid=-27472-1-1 cseq=12 REFER contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | 
ServerSubscription.cxx:216 | ServerSubscription::dispatch: SipReq:  REFER 
UAC@10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER 
contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144433.214 | BasicCall | RESIP | 139984863958848 | 
Helper.cxx:374 | Helper::makeResponse(SipReq:  REFER UAC@10.12.12.18:12005 
tid=-27472-1-1 cseq=12 REFER contact=sipp@10.12.2.101:5060 / 12 from(wire) 
code=200 reason=
DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | 
Dialog.cxx:1052 | Dialog::makeResponse: 

SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.12.2.101:5060;branch=z9hG4bK-27472-1-1
Contact: <sip:UAC>
To: <sip:UAC@10.12.2.101:5060>;tag=4fd8ad7c
From: <sip:UAS@10.12.2.101:5060>
Call-ID: 885lKF_ZxrpwP5gTWZlPdg..
CSeq: 12 REFER
Content-Length: 0


DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | 
ServerSubscription.cxx:302 | onNewSubscriptionFromRefer called
UAC: onNewSubscriptionFromRefer - SipReq:  REFER UAC@10.12.12.18:12005 
tid=-27472-1-1 cseq=12 REFER contact=sipp@10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144433.659 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TimerQueue.cxx:50 | Adding timer: Timer A tid=5382820c264cf253 ms=1000
DEBUG | 20170721-144433.659 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TransactionState.cxx:1385 | Retransmitting INVITE 
DEBUG | 20170721-144433.663 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
Transport.cxx:392 | incoming from: [ V4 10.12.2.101:5060 UDP flowKey=10 
transportKey=1 ]
DEBUG | 20170721-144434.659 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TimerQueue.cxx:50 | Adding timer: Timer A tid=5382820c264cf253 ms=2000
DEBUG | 20170721-144434.660 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TransactionState.cxx:1385 | Retransmitting INVITE 
DEBUG | 20170721-144434.663 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
Transport.cxx:392 | incoming from: [ V4 10.12.2.101:5060 UDP flowKey=10 
transportKey=1 ]
DEBUG | 20170721-144436.660 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TimerQueue.cxx:50 | Adding timer: Timer A tid=5382820c264cf253 ms=4000
DEBUG | 20170721-144436.660 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TransactionState.cxx:1385 | Retransmitting INVITE 
DEBUG | 20170721-144436.663 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
TransportSelector.cxx:1072 | Found transport: [ V4 0.0.0.0:12005 UDP flowKey=10 
transportKey=1 ]
DEBUG | 20170721-144436.663 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
TransportSelector.cxx:871 | Looked up source for destination: [ V4 
10.12.2.101:5060 UDP flowKey=10 transportKey=1 ] -> [ V4 10.12.12.18:0 UDP 
flowKey=10 transportKey=1 ] sent-by=10.12.2.101 sent-port=5060
DEBUG | 20170721-144436.663 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
TransportSelector.cxx:1288 | Transmitting to [ V4 10.12.2.101:5060 UDP 
flowKey=10 transportKey=1 ] tlsDomain= via [ V4 10.12.12.18:12005 UDP 
flowKey=10 transportKey=1 ]

SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.12.2.101:5060;branch=z9hG4bK-27472-1-1
To: <sip:UAC@10.12.2.101:5060>;tag=4fd8ad7c
From: <sip:UAS@10.12.2.101:5060>
Call-ID: 885lKF_ZxrpwP5gTWZlPdg..
CSeq: 12 REFER
Content-Length: 0

sigcomp id=
DEBUG | 20170721-144436.663 | BasicCall | RESIP:TRANSPORT | 139984863958848 | 
Transport.cxx:392 | incoming from: [ V4 10.12.2.101:5060 UDP flowKey=10 
transportKey=1 ]
DEBUG | 20170721-144440.660 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TimerQueue.cxx:50 | Adding timer: Timer A tid=5382820c264cf253 ms=8000
DEBUG | 20170721-144440.660 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TransactionState.cxx:1385 | Retransmitting INVITE 
DEBUG | 20170721-144448.661 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TimerQueue.cxx:50 | Adding timer: Timer A tid=5382820c264cf253 ms=16000
DEBUG | 20170721-144448.661 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TransactionState.cxx:1385 | Retransmitting INVITE 
DEBUG | 20170721-144504.660 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TimerQueue.cxx:50 | Adding timer: Timer A tid=5382820c264cf253 ms=32000
DEBUG | 20170721-144504.660 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TransactionState.cxx:1385 | Retransmitting INVITE 
DEBUG | 20170721-144505.158 | BasicCall | RESIP | 139984863958848 | 
Helper.cxx:374 | Helper::makeResponse(SipReq:  INVITE UAS@10.12.2.101:5060 
tid=5382820c264cf253 cseq=1 INVITE contact=UAC@10.12.12.18:12005 / 1 from(tu) 
code=408 reason=
DEBUG | 20170721-144505.158 | BasicCall | RESIP:TRANSACTION | 139984863958848 | 
TuSelector.cxx:70 | Send to TU: DialogUsageManager size=0 

SIP/2.0 408 Request Timeout
Via: SIP/2.0/UDP 
10.12.12.18:12005;branch=z9hG4bK-524287-1---5382820c264cf253;rport
To: <sip:UAS@10.12.2.101:5060>;tag=220a2e3b
From: <sip:UAC@10.12.2.101:5060>;tag=4fd8ad7c
Call-ID: 885lKF_ZxrpwP5gTWZlPdg..
CSeq: 1 INVITE
Content-Length: 0


DEBUG | 20170721-144505.158 | BasicCall | RESIP:DNS | 139984863958848 | 
DnsResult.cxx:187 | Remove vip 10.12.2.101(1)
DEBUG | 20170721-144505.158 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogUsageManager.cxx:1606 | Got: SipResp: 408 tid=5382820c264cf253 cseq=1 
INVITE / 1 from(wire)
DEBUG | 20170721-144505.158 | BasicCall | RESIP:DUM | 139984863958848 | 
DialogUsageManager.cxx:2156 | DialogUsageManager::processResponse: 

SipResp: 408 tid=5382820c264cf253 cseq=1 INVITE / 1 from(wire)
BasicCall: DialogSet.cxx:352: void resip::DialogSet::dispatch(const 
resip::SipMessage&): Assertion `mDialogs.empty()' failed.

References:
- [reSIProcate] Resiprocate/DUM assert hit when rearrenged/lost packets received
  - From: Szokovacs Robert
- Re: [reSIProcate] Resiprocate/DUM assert hit when rearrenged/lost packets received
  - From: Szokovacs Robert
- Re: [reSIProcate] Resiprocate/DUM assert hit when rearrenged/lost packets received
  - From: Scott Godin

Prev by Date: Re: [reSIProcate] Resiprocate/DUM assert hit when rearrenged/lost packets received
Next by Date: Re: [reSIProcate] [reSIProcate-users] Help - Facing problem to send sip message towards proxy
Previous by thread: Re: [reSIProcate] Resiprocate/DUM assert hit when rearrenged/lost packets received
Next by thread: [reSIProcate] repro updating request URI
Index(es):
- Date
- Thread