[reSIProcate] Resiprocate/DUM assert hit when rearrenged/lost packets received
Szokovacs Robert
robert.szokovacs at gamma.co.uk
Fri Jul 21 07:47:06 CDT 2017
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 at gamma.co.uk <mailto:robert.szokovacs at gamma.co.uk>>
> 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 at resiprocate.org
> <mailto:resiprocate-devel at resiprocate.org>
> https://list.resiprocate.org/mailman/listinfo/resiprocate-devel
> <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
> ------------------------------------------------------------------------
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://list.resiprocate.org/pipermail/resiprocate-devel/attachments/20170721/40bc2abc/attachment.htm>
-------------- next part --------------
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 at 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 at 10.12.2.101:5060>
From: <sip:UAC at 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 at 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 at 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 at 10.12.2.101:5060
DEBUG | 20170721-144618.523 | BasicCall | RESIP:DNS | 139883071379264 | DnsResult.cxx:261 | DnsResult::lookup sip:UAS at 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 at 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 at 10.12.12.18:12005>
To: <sip:UAS at 10.12.2.101:5060>
From: <sip:UAC at 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 at 10.12.2.101:5060
To: <sip:UAS at 10.12.2.101:5060>
From: <sip:UAC at 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 at 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 at 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 at 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 at 10.12.2.101:5060
To: <sip:UAC at 10.12.2.101:5060>;tag=ce9e4702
From: <sip:UAS at 10.12.2.101:5060>
Call-ID: YlsYt7odzBbEeISEPnzNxA..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789 at 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 at 10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER contact=sipp at 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 at 10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER contact=sipp at 10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144618.528 | BasicCall | RESIP | 139883071379264 | Helper.cxx:374 | Helper::makeResponse(SipReq: REFER UAC at 10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER contact=sipp at 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 at 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 at 10.12.2.101:5060
To: <sip:UAC at 10.12.2.101:5060>;tag=ce9e4702
From: <sip:UAS at 10.12.2.101:5060>
Call-ID: YlsYt7odzBbEeISEPnzNxA..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789 at 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 at 10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER contact=sipp at 10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | DialogUsageManager.cxx:1964 | DialogUsageManager::processRequest: SipReq: REFER UAC at 10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER contact=sipp at 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 at 10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER contact=sipp at 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 at 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 at 10.12.2.101:5060
To: <sip:UAC at 10.12.2.101:5060>;tag=ce9e4702
From: <sip:UAS at 10.12.2.101:5060>
Call-ID: YlsYt7odzBbEeISEPnzNxA..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789 at 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 at 10.12.2.101:5060>
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | Dialog.cxx:179 | mLocalNameAddr: <sip:UAC at 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 at 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 at 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 at 10.12.2.101:5060
To: <sip:UAC at 10.12.2.101:5060>;tag=ce9e4702
From: <sip:UAS at 10.12.2.101:5060>
Call-ID: YlsYt7odzBbEeISEPnzNxA..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789 at 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 at 10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER contact=sipp at 10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | ServerSubscription.cxx:216 | ServerSubscription::dispatch: SipReq: REFER UAC at 10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER contact=sipp at 10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144618.579 | BasicCall | RESIP | 139883071379264 | Helper.cxx:374 | Helper::makeResponse(SipReq: REFER UAC at 10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER contact=sipp at 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 at 10.12.2.101:5060>;tag=ce9e4702
From: <sip:UAS at 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 at 10.12.12.18:12005 tid=-28114-1-2 cseq=12 REFER contact=sipp at 10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144618.579 | BasicCall | RESIP:DUM | 139883071379264 | DialogUsageManager.cxx:990 | SEND:
CANCEL sip:UAS at 10.12.2.101:5060 SIP/2.0
Via: SIP/2.0/ ;branch=z9hG4bK-524287-1---c534ff3d1b98c169;rport
Max-Forwards: 70
To: <sip:UAS at 10.12.2.101:5060>
From: <sip:UAC at 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 at 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 at 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.
-------------- next part --------------
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 at 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 at 10.12.2.101:5060>
From: <sip:UAC at 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 at 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 at 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 at 10.12.2.101:5060
DEBUG | 20170721-144433.158 | BasicCall | RESIP:DNS | 139984863958848 | DnsResult.cxx:261 | DnsResult::lookup sip:UAS at 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 at 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 at 10.12.12.18:12005>
To: <sip:UAS at 10.12.2.101:5060>
From: <sip:UAC at 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 at 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 at 10.12.2.101:5060
To: <sip:UAC at 10.12.2.101:5060>;tag=4fd8ad7c
From: <sip:UAS at 10.12.2.101:5060>
Call-ID: 885lKF_ZxrpwP5gTWZlPdg..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789 at 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 at 10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER contact=sipp at 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 at 10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER contact=sipp at 10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144433.163 | BasicCall | RESIP | 139984863958848 | Helper.cxx:374 | Helper::makeResponse(SipReq: REFER UAC at 10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER contact=sipp at 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 at 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 at 10.12.2.101:5060
To: <sip:UAC at 10.12.2.101:5060>;tag=4fd8ad7c
From: <sip:UAS at 10.12.2.101:5060>
Call-ID: 885lKF_ZxrpwP5gTWZlPdg..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789 at 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 at 10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER contact=sipp at 10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144433.213 | BasicCall | RESIP:DUM | 139984863958848 | DialogUsageManager.cxx:1964 | DialogUsageManager::processRequest: SipReq: REFER UAC at 10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER contact=sipp at 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 at 10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER contact=sipp at 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 at 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 at 10.12.2.101:5060
To: <sip:UAC at 10.12.2.101:5060>;tag=4fd8ad7c
From: <sip:UAS at 10.12.2.101:5060>
Call-ID: 885lKF_ZxrpwP5gTWZlPdg..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789 at 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 at 10.12.2.101:5060>
DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | Dialog.cxx:179 | mLocalNameAddr: <sip:UAC at 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 at 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 at 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 at 10.12.2.101:5060
To: <sip:UAC at 10.12.2.101:5060>;tag=4fd8ad7c
From: <sip:UAS at 10.12.2.101:5060>
Call-ID: 885lKF_ZxrpwP5gTWZlPdg..
CSeq: 12 REFER
Expires: 3600
User-Agent: SEMS Call Control
Refer-To: sip:0123456789 at 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 at 10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER contact=sipp at 10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144433.214 | BasicCall | RESIP:DUM | 139984863958848 | ServerSubscription.cxx:216 | ServerSubscription::dispatch: SipReq: REFER UAC at 10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER contact=sipp at 10.12.2.101:5060 / 12 from(wire)
DEBUG | 20170721-144433.214 | BasicCall | RESIP | 139984863958848 | Helper.cxx:374 | Helper::makeResponse(SipReq: REFER UAC at 10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER contact=sipp at 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 at 10.12.2.101:5060>;tag=4fd8ad7c
From: <sip:UAS at 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 at 10.12.12.18:12005 tid=-27472-1-1 cseq=12 REFER contact=sipp at 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 at 10.12.2.101:5060>;tag=4fd8ad7c
From: <sip:UAS at 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 at 10.12.2.101:5060 tid=5382820c264cf253 cseq=1 INVITE contact=UAC at 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 at 10.12.2.101:5060>;tag=220a2e3b
From: <sip:UAC at 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.
More information about the resiprocate-devel
mailing list