[pjsip] [Fwd: Re: Exceptions when using ICE functionalities]

Pedro Gonçalves pedro.pandre at gmail.com
Fri Aug 8 10:07:59 EDT 2008


BTW, sometimes check->tdata is NULL.
There must be a reason why it is NULL.
Can you explain this?

Many thanks
Pedro Gonçalves

-------- Original Message --------
Subject: 	Re: [pjsip] Exceptions when using ICE functionalities
Date: 	Fri, 08 Aug 2008 14:56:24 +0100
From: 	Pedro Gonçalves <pedro.pandre at gmail.com>
To: 	pjsip list <pjsip at lists.pjsip.org>
References: 	<48988BCE.30908 at gmail.com> 
<1879720d0808060210l5004bc90r8cd1ce4fff29eb20 at mail.gmail.com> 
<48998005.10004 at gmail.com> 
<1879720d0808060435i618dd5c0p938a810607eb6387 at mail.gmail.com> 
<4899E830.20706 at gmail.com> 
<1879720d0808070258m4c87f939raadab2f299c5eb39 at mail.gmail.com>



Hi!

I updated to the latest version, but the problems remain the same.
Now I am experiencing the failing assert in on_stun_request_complete().
Can you explain better why this assert is needed and tell some reasons 
why it could fail?

Anything you tell me will help me to have a better undertanding of this 
part of PJSIP.

Best regards
Pedro Gonçalves


Benny Prijono wrote:
> Pedro,
>
> this looks similar to http://trac.pjsip.org/repos/ticket/567
> Can you try the latest SVN version?
>
> Thanks
>  Benny
>
> On Wed, Aug 6, 2008 at 7:06 PM, Pedro Gonçalves 
> <pedro.pandre at gmail.com <mailto:pedro.pandre at gmail.com>> wrote:
>
>     Hi again
>
>     Now I am experiencing very frequently the exception #2, which
>     happens when, in sess_init_update, one of ice_st's components is NULL.
>     This even happens in the beggining, in caller before the initial
>     offer (when ICE procedures are starting). As you can see in the
>     capture, only a STUN binding request and its answer were captured.
>     As can be seen in the log, I printed ice_st's components, and they
>     don't seem to be changed in the call stack (you can see the
>     complete call stack below).
>     We can see that ice_st's comp[0] is not NULL, but ice_st's comp[1]
>     is NULL since on_request_complete
>
>     18:52:56.245    stun_sock.c pandre-dbg comp=15C7BC0C i=0 on
>     sess_on_request_complete
>     18:52:56.266    stun_sock.c pandre-dbg comp=00000000 i=1 on
>     sess_on_request_complete
>     18:52:56.307   ice_strans.c pandre-dbg comp=15C7BC0C i=0 on
>     stun_on_status(1)
>     18:52:56.337   ice_strans.c pandre-dbg comp=00000000 i=1 on
>     stun_on_status(1)
>     18:52:56.418   ice_strans.c pandre-dbg comp=15C7BC0C i=0 on
>     stun_on_status
>     18:52:56.457   ice_strans.c pandre-dbg comp=00000000 i=1 on
>     stun_on_status
>     18:52:56.488   ice_strans.c pandre-dbg comp=15C7BC0C i=0 on
>     sess_init_update
>     18:52:56.514   ice_strans.c pandre-dbg comp=00000000 i=1 on
>     sess_init_update
>
>     >From previous runs I know that some components can be NULL, but
>     then they get some value.
>     In this case, they keep the NULL value until sess_init_update is
>     called.
>     Is there something missing?
>     I don't know why this happens, nor do I know how to solve this
>     issue, despite my efforts.
>
>     Best Regards
>     Pedro Gonçalves
>
>
>     Complete call stack:
>     >    PCCommunicator.exe!sess_init_update(pj_ice_strans *
>     ice_st=0x15b52c5c)  Line 547 + 0x18 bytes    C
>        PCCommunicator.exe!stun_on_status(pj_stun_sock *
>     stun_sock=0x15c7fe0c, pj_stun_sock_op op=PJ_STUN_SOCK_BINDING_OP,
>     int status=0)  Line 1276 + 0x9 bytes    C
>        PCCommunicator.exe!sess_on_request_complete(pj_stun_session *
>     sess=0x15c8783c, int status=0, void * token=0x00000001,
>     pj_stun_tx_data * tdata=0x15ca1c5c, const pj_stun_msg *
>     response=0x15c9fc5c, const void * src_addr=0x15c81e9c, unsigned
>     int src_addr_len=16)  Line 706 + 0x14 bytes    C
>        PCCommunicator.exe!stun_tsx_on_complete(pj_stun_client_tsx *
>     tsx=0x15ca3f44, int status=0, const pj_stun_msg *
>     response=0x15c9fc5c, const void * src_addr=0x15c81e9c, unsigned
>     int src_addr_len=16)  Line 424 + 0x29 bytes    C
>      
>      PCCommunicator.exe!pj_stun_client_tsx_on_rx_msg(pj_stun_client_tsx
>     * tsx=0x15ca3f44, const pj_stun_msg * msg=0x15c9fc5c, const void *
>     src_addr=0x15c81e9c, unsigned int src_addr_len=16)  Line 395 +
>     0x1e bytes    C
>        PCCommunicator.exe!on_incoming_response(pj_stun_session *
>     sess=0x15c8783c, unsigned int options=5, const unsigned char *
>     pkt=0x15c8380c, unsigned int pkt_len=88, pj_stun_msg *
>     msg=0x15c9fc5c, const void * src_addr=0x15c81e9c, unsigned int
>     src_addr_len=16)  Line 1189 + 0x18 bytes    C
>        PCCommunicator.exe!pj_stun_session_on_rx_pkt(pj_stun_session *
>     sess=0x15c8783c, const void * packet=0x15c8380c, unsigned int
>     pkt_size=88, unsigned int options=1, void * token=0x00000000,
>     unsigned int * parsed_len=0x00000000, const void *
>     src_addr=0x15c81e9c, unsigned int src_addr_len=16)  Line 1416 +
>     0x21 bytes    C
>        PCCommunicator.exe!on_data_recvfrom(pj_activesock_t *
>     asock=0x15c7ffb8, void * data=0x15c8380c, unsigned int size=88,
>     const void * src_addr=0x15c81e9c, int addr_len=16, int status=0)
>      Line 817 + 0x25 bytes    C
>        PCCommunicator.exe!ioqueue_on_read_complete(pj_ioqueue_key_t *
>     key=0x08b458d4, pj_ioqueue_op_key_t * op_key=0x15c81e0c, long
>     bytes_read=88)  Line 341 + 0x38 bytes    C
>        PCCommunicator.exe!ioqueue_dispatch_read_event(pj_ioqueue_t *
>     ioqueue=0x0da80928, pj_ioqueue_key_t * h=0x08b458d4)  Line 549 +
>     0x16 bytes    C
>        PCCommunicator.exe!pj_ioqueue_poll(pj_ioqueue_t *
>     ioqueue=0x0da80928, const pj_time_val * timeout=0x0dd3fcac)  Line
>     763 + 0x17 bytes    C
>        PCCommunicator.exe!pjsip_endpt_handle_events2(pjsip_endpoint *
>     endpt=0x0b9c705c, const pj_time_val * max_timeout=0x0dd3fe7c,
>     unsigned int * p_count=0x00000000)  Line 694 + 0x10 bytes    C
>        PCCommunicator.exe!pjsip_endpt_handle_events(pjsip_endpoint *
>     endpt=0x0b9c705c, const pj_time_val * max_timeout=0x0dd3fe7c)
>      Line 721 + 0xf bytes    C
>
>        PCCommunicator.exe!EventHandler(void * __formal=0x00000000)
>      Line 630 + 0x16 bytes    C++
>        PCCommunicator.exe!thread_main(void * param=0x08af5e7c)  Line
>     413 + 0x11 bytes    C
>
>
>
>
>
>
>
>
>
>     Benny Prijono wrote:
>
>         On Wed, Aug 6, 2008 at 11:42 AM, Pedro Gonçalves
>         <pedro.pandre at gmail.com <mailto:pedro.pandre at gmail.com>
>         <mailto:pedro.pandre at gmail.com
>         <mailto:pedro.pandre at gmail.com>>> wrote:
>
>            Benny Prijono wrote:
>
>                On Tue, Aug 5, 2008 at 6:20 PM, Pedro Gonçalves
>                <pedro.pandre at gmail.com <mailto:pedro.pandre at gmail.com>
>         <mailto:pedro.pandre at gmail.com <mailto:pedro.pandre at gmail.com>>
>                <mailto:pedro.pandre at gmail.com
>         <mailto:pedro.pandre at gmail.com>
>                <mailto:pedro.pandre at gmail.com
>         <mailto:pedro.pandre at gmail.com>>>> wrote:
>
>                   Hi!
>
>                   With the help from PJSIP list useres, I think I am
>         close to
>                having my
>                   program to use PJSIP's ICE functionalities 100%
>         correctly.
>
>
>                Not that I'm discouraging you, but I think you've still got
>                some issues to fix there (as discussed on the other
>         thread). :)
>                 Regarding the crashes below, do you know in what stage did
>                these happen? E.g. during ICE creation, in the middle of
>                conversation, or during ICE destroy sequence? We had
>         this bug
>                that looks similar: http://trac.pjsip.org/repos/ticket/567
>
>
>            About the other issues (the ones you told in the other
>         thread, I
>            moved the stream destruction to on_media_update(), but these
>            problems persist (these problems happen in the answerer).
>
>
>         Is the problem still with stream not being closed? So what do
>         you exactly do in on_media_update()? And is on_media_update()
>         called? And do you close the stream when the call is
>         disconnected? A snippet will help.
>
>         And lets discuss this on separate/the other thread please.
>
>          
>            About 1), the failing assert, it happens after initial offer /
>            answer, but before the subsequent offer, during ICE negotiation
>            (more specifically, during ICE connectivity checks).
>
>            I've included both the application log and the capture I made
>            during the exception.
>
>            I can reproduce this behaviour at any time, so if there is
>            something I can do to help us debug this issue, just ask.
>
>            I've added some debug information in some PJSIP files, in
>         order to
>            help me understand the problem. As you can see in the end
>         of the
>            log, the assert problem seems to come from somewhere before
>            pj_stun_session_on_rx_pkt, is it not?
>            11:19:15.375 stun_session.c pandre-dbg tdata=339762268
>            check->tdata=338037852 on pj_stun_session_on_rx_pkt ckid=0
>            11:19:15.687 stun_session.c pandre-dbg tdata=339762268
>            check->tdata=338037852 on on_incoming_response ckid=0
>            11:19:16.292 stun_session.c pandre-dbg tdata=339762268
>            check->tdata=338037852 on stun_tsx_on_complete(1)
>            11:19:16.335 stun_session.c pandre-dbg tdata=339762268
>            check->tdata=338037852 on stun_tsx_on_complete(2)
>
>
>         Unfortunately I didn't see the messages (above) in the log,
>         probably because the file has not completely been written when
>         the assertion occurs. When the "pj_assert(tdata ==
>         check->tdata)" assertion occurs, does "check->tdata" contain a
>         value, or is it NULL?
>
>         Cheers
>          Benny
>
>
>         ------------------------------------------------------------------------
>
>
>
>         _______________________________________________
>         Visit our blog: http://blog.pjsip.org
>
>         pjsip mailing list
>         pjsip at lists.pjsip.org <mailto:pjsip at lists.pjsip.org>
>         http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org
>          
>
>
>
>      18:52:05.989 os_core_win32. pjlib 0.9.0-release for win32 initialized
>      18:52:05.995      pasound.c PA message: before
>     paHostApiInitializers[0].
>
>      18:52:06.312      pasound.c PA message: after
>     paHostApiInitializers[0].
>
>      18:52:06.317      pasound.c PA message: before
>     paHostApiInitializers[1].
>
>      18:52:06.414      pasound.c PA message: after
>     paHostApiInitializers[1].
>
>      18:52:06.420      pasound.c PA message: before
>     paHostApiInitializers[2].
>
>      18:52:06.425      pasound.c PA message: after
>     paHostApiInitializers[2].
>
>      18:52:06.430      pasound.c PortAudio sound library initialized,
>     status=0
>      18:52:06.436      pasound.c PortAudio host api count=3
>      18:52:06.441      pasound.c Sound device count=8
>      18:52:06.449          pjlib select() I/O Queue created (0C1C4A0C)
>      18:52:06.458    g723decoder Init
>      18:52:06.465    g723decoder Init 1
>      18:52:06.470    g723decoder Init done
>      18:52:06.476   conference.c Creating conference bridge with 5 ports
>      18:52:06.483   conference.c Sound device successfully created for
>     port 0
>      18:52:06.575 sip_endpoint.c Creating endpoint instance...
>      18:52:06.587          pjlib select() I/O Queue created (0DA80928)
>      18:52:06.595 sip_endpoint.c Module "mod-msg-print" registered
>      18:52:06.619 sip_transport. Transport manager created.
>      18:52:06.655    udp08B7BDF8 SIP UDP transport started, published
>     address is 172.18.0.51:64184 <http://172.18.0.51:64184>
>      18:52:06.662 sip_endpoint.c Module "mod-tsx-layer" registered
>      18:52:06.670 sip_endpoint.c Module "mod-stateful-util" registered
>      18:52:06.677 sip_endpoint.c Module "mod-ua" registered
>      18:52:06.685 sip_endpoint.c Module "mod-100rel" registered
>      18:52:06.694 sip_endpoint.c Module "mod_expire_session" registered
>      18:52:06.700 sip_endpoint.c Module "mod-evsub" registered
>      18:52:06.706 sip_endpoint.c Module "mod-presence" registered
>      18:52:06.715        evsub.c Event pkg "presence" registered by
>     mod-presence
>      18:52:06.721 sip_endpoint.c Module "mod_options" registered
>      18:52:06.730 sip_endpoint.c Module "mod_logging" registered
>      18:52:06.737 sip_endpoint.c Module "mod_message" registered
>      18:52:06.744 sip_endpoint.c Module "mod_call" registered
>      18:52:06.751 sip_endpoint.c Module "mod_opaque" registered
>      18:52:06.758 sip_endpoint.c Module "mod-invite" registered
>      18:52:06.761    SIPEngine.c Starting Event Handler...
>      18:52:06.772    SIPCall.cpp pandre resolve_stun_server
>     stun_srv=172.18.0.169:3478 <http://172.18.0.169:3478>
>      18:52:06.787    SIPCall.cpp pandre resolve_stun_server stun_srv
>     in SIPEngine=172.18.0.169:3478 <http://172.18.0.169:3478>
>      18:52:06.837       endpoint Request msg REGISTER/cseq=18508
>     (tdta0DAD5FF8) created.
>      18:52:06.845    tsx0DAEF85C Transaction created for Request msg
>     REGISTER/cseq=18509 (tdta0DAD5FF8)
>      18:52:06.853    tsx0DAEF85C Sending Request msg
>     REGISTER/cseq=18509 (tdta0DAD5FF8) in state Null
>      18:52:06.866  sip_resolve.c Target '172.18.0.170:5060
>     <http://172.18.0.170:5060>' type=UDP resolved to
>     '172.18.0.170:5060 <http://172.18.0.170:5060>' type=UDP (UDP
>     transport)
>      18:52:06.901            LOG TX 600 bytes Request msg
>     REGISTER/cseq=18509 (tdta0DAD5FF8) to UDP 172.18.0.170:5060
>     <http://172.18.0.170:5060>:
>     REGISTER sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com> SIP/2.0Via:
>     SIP/2.0/UDP
>     172.18.0.51:64184;rport;branch=z9hG4bKPj5a52444ef72b4316a8f5c09a68d3e18bRoute:
>     <sip:172.18.0.170:5060;transport=UDP;lr>Max-Forwards: 70From:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>;tag=3cce5f2e578642298a0beb9a06054e99To:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>Call-ID:
>     157d9d3aad6d4107ad1a522be677dc1eCSeq: 18509 REGISTERUser-Agent:
>     WITPCCommunicator/2.0 (English;)Contact:
>     <sip:172.18.0.51:64184;transport=UDP>;methods="INVITE,NOTIFY,MESSAGE,ACK,BYE,CANCEL";cfwd="False"Expires:
>     30Content-Length:  0
>     --end msg--
>      18:52:06.910    tsx0DAEF85C State changed from Null to Calling,
>     event=TX_MSG
>      18:52:07.026 sip_endpoint.c Processing incoming message: Response
>     msg 100/REGISTER/cseq=18509 (rdata08AD205C)
>      18:52:07.038            LOG RX 328 bytes Response msg
>     100/REGISTER/cseq=18509 (rdata08AD205C) from UDP 172.18.0.170:5060
>     <http://172.18.0.170:5060>:
>     SIP/2.0 100 TryingVia: SIP/2.0/UDP
>     172.18.0.51:64184;rport;branch=z9hG4bKPj5a52444ef72b4316a8f5c09a68d3e18bFrom:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>;tag=3cce5f2e578642298a0beb9a06054e99To:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>Call-ID:
>     157d9d3aad6d4107ad1a522be677dc1eCSeq: 18509 REGISTERContent-Length: 0
>     --end msg--
>      18:52:07.051    tsx0DAEF85C Incoming Response msg
>     100/REGISTER/cseq=18509 (rdata08AD205C) in state Calling
>      18:52:07.063    tsx0DAEF85C State changed from Calling to
>     Proceeding, event=RX_MSG
>      18:52:07.076 sip_endpoint.c Processing incoming message: Response
>     msg 401/REGISTER/cseq=18509 (rdata08AD205C)
>      18:52:07.087            LOG RX 493 bytes Response msg
>     401/REGISTER/cseq=18509 (rdata08AD205C) from UDP 172.18.0.170:5060
>     <http://172.18.0.170:5060>:
>     SIP/2.0 401 UnauthorizedVia: SIP/2.0/UDP
>     172.18.0.51:64184;rport;branch=z9hG4bKPj5a52444ef72b4316a8f5c09a68d3e18bFrom:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>;tag=3cce5f2e578642298a0beb9a06054e99To:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>Call-ID:
>     157d9d3aad6d4107ad1a522be677dc1eCSeq: 18509
>     REGISTERWWW-Authenticate: Digest
>     realm="mcg",nonce="MTIxODA0NTEyNjk1MzpXSVQtTUNH",opaque="D03207FDBFBA3D6B2029A4545420C1E05116612932C8B3A7",stale=false,algorithm=MD5Content-Length:
>     0
>     --end msg--
>      18:52:07.096    tsx0DAEF85C Incoming Response msg
>     401/REGISTER/cseq=18509 (rdata08AD205C) in state Proceeding
>      18:52:07.108    tsx0DAEF85C State changed from Proceeding to
>     Completed, event=RX_MSG
>      18:52:07.119    tsx0DFB585C Transaction created for Request msg
>     REGISTER/cseq=18510 (tdta0DAD5FF8)
>      18:52:07.129    tsx0DFB585C Sending Request msg
>     REGISTER/cseq=18510 (tdta0DAD5FF8) in state Null
>      18:52:07.145  sip_resolve.c Target '172.18.0.170:5060
>     <http://172.18.0.170:5060>' type=UDP resolved to
>     '172.18.0.170:5060 <http://172.18.0.170:5060>' type=UDP (UDP
>     transport)
>      18:52:07.184            LOG TX 885 bytes Request msg
>     REGISTER/cseq=18510 (tdta0DAD5FF8) to UDP 172.18.0.170:5060
>     <http://172.18.0.170:5060>:
>     REGISTER sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com> SIP/2.0Via:
>     SIP/2.0/UDP
>     172.18.0.51:64184;rport;branch=z9hG4bKPj6fde5226e9fe4ceaa2f2e2bc56b6236fRoute:
>     <sip:172.18.0.170:5060;transport=UDP;lr>Max-Forwards: 70From:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>;tag=3cce5f2e578642298a0beb9a06054e99To:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>Call-ID:
>     157d9d3aad6d4107ad1a522be677dc1eCSeq: 18510 REGISTERUser-Agent:
>     WITPCCommunicator/2.0 (English;)Contact:
>     <sip:172.18.0.51:64184;transport=UDP>;methods="INVITE,NOTIFY,MESSAGE,ACK,BYE,CANCEL";cfwd="False"Expires:
>     30Authorization: Digest
>     username="+351914871189 at wcs.wit-software.com
>     <mailto:351914871189 at wcs.wit-software.com>", realm="mcg",
>     nonce="MTIxODA0NTEyNjk1MzpXSVQtTUNH",
>     uri="sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>",
>     response="e41c4f72c394c78665889c0e29488e33", algorithm=MD5,
>     opaque="D03207FDBFBA3D6B2029A4545420C1E05116612932C8B3A7"Content-Length:
>      0
>     --end msg--
>      18:52:07.194    tsx0DFB585C State changed from Null to Calling,
>     event=TX_MSG
>      18:52:07.215 sip_endpoint.c Processing incoming message: Response
>     msg 100/REGISTER/cseq=18510 (rdata08AD205C)
>      18:52:07.232            LOG RX 328 bytes Response msg
>     100/REGISTER/cseq=18510 (rdata08AD205C) from UDP 172.18.0.170:5060
>     <http://172.18.0.170:5060>:
>     SIP/2.0 100 TryingVia: SIP/2.0/UDP
>     172.18.0.51:64184;rport;branch=z9hG4bKPj6fde5226e9fe4ceaa2f2e2bc56b6236fFrom:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>;tag=3cce5f2e578642298a0beb9a06054e99To:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>Call-ID:
>     157d9d3aad6d4107ad1a522be677dc1eCSeq: 18510 REGISTERContent-Length: 0
>     --end msg--
>      18:52:07.243    tsx0DFB585C Incoming Response msg
>     100/REGISTER/cseq=18510 (rdata08AD205C) in state Calling
>      18:52:07.261    tsx0DFB585C State changed from Calling to
>     Proceeding, event=RX_MSG
>      18:52:07.278 sip_endpoint.c Processing incoming message: Response
>     msg 200/REGISTER/cseq=18510 (rdata08AD205C)
>      18:52:07.294            LOG RX 488 bytes Response msg
>     200/REGISTER/cseq=18510 (rdata08AD205C) from UDP 172.18.0.170:5060
>     <http://172.18.0.170:5060>:
>     SIP/2.0 200 OKVia: SIP/2.0/UDP
>     172.18.0.51:64184;rport;branch=z9hG4bKPj6fde5226e9fe4ceaa2f2e2bc56b6236fFrom:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>;tag=3cce5f2e578642298a0beb9a06054e99To:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>Call-ID:
>     157d9d3aad6d4107ad1a522be677dc1eCSeq: 18510 REGISTERX-Invite-SMS:
>     trueX-Recommend-EMail: trueContact:
>     <sip:172.18.0.51:64184;transport=UDP>;methods="INVITE,NOTIFY,MESSAGE,ACK,BYE,CANCEL";cfwd="False";expires=90Content-Length:
>     0
>     --end msg--
>      18:52:07.306    tsx0DFB585C Incoming Response msg
>     200/REGISTER/cseq=18510 (rdata08AD205C) in state Proceeding
>      18:52:07.322    tsx0DFB585C State changed from Proceeding to
>     Completed, event=RX_MSG
>      18:52:30.056    dlg0F05085C UAC dialog created
>      18:52:30.069    dlg0F05085C Module mod-evsub added as dialog
>     usage, data=0EF96FAC
>      18:52:30.099  evsub0F050E54 UAC subscription created, using
>     dialog dlg0F05085C
>      18:52:30.115    dlg0F05085C Session count inc to 3 by mod-evsub
>      18:52:30.132       endpoint Request msg SUBSCRIBE/cseq=18468
>     (tdta0ED66FF8) created.
>      18:52:30.144    dlg0F05085C Sending Request msg
>     SUBSCRIBE/cseq=18468 (tdta0ED66FF8)
>      18:52:30.155    tsx0F26D85C Transaction created for Request msg
>     SUBSCRIBE/cseq=18467 (tdta0ED66FF8)
>      18:52:30.168    tsx0F26D85C Sending Request msg
>     SUBSCRIBE/cseq=18467 (tdta0ED66FF8) in state Null
>      18:52:30.179  sip_resolve.c Target '172.18.0.170:5060
>     <http://172.18.0.170:5060>' type=UDP resolved to
>     '172.18.0.170:5060 <http://172.18.0.170:5060>' type=UDP (UDP
>     transport)
>      18:52:30.193            LOG TX 574 bytes Request msg
>     SUBSCRIBE/cseq=18467 (tdta0ED66FF8) to UDP 172.18.0.170:5060
>     <http://172.18.0.170:5060>:
>     SUBSCRIBE sip:172.18.0.170:5060;transport=UDP;lr SIP/2.0Via:
>     SIP/2.0/UDP
>     172.18.0.51:64184;rport;branch=z9hG4bKPj2a88b60293e04037b45d300b58f62805Max-Forwards:
>     70From: <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>;tag=d103bb6cc0da447e9c7c9c33639de6ffTo:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>Contact:
>     <sip:172.18.0.51:64184 <http://172.18.0.51:64184>>Call-ID:
>     604970b238994208a7d87f72670279d8CSeq: 18467 SUBSCRIBEEvent:
>     presenceExpires: 600Accept: application/pidf+xml,
>     application/xpidf+xmlAllow-Events: presenceUser-Agent:
>     WITPCCommunicator/2.0 (English;)Content-Length:  0
>     --end msg--
>      18:52:30.205    tsx0F26D85C State changed from Null to Calling,
>     event=TX_MSG
>      18:52:30.224    dlg0F05085C Transaction tsx0F26D85C state changed
>     to Calling
>      18:52:30.236  evsub0F050E54 Subscription state changed NULL --> SENT
>      18:52:30.247 sip_endpoint.c Processing incoming message: Response
>     msg 200/SUBSCRIBE/cseq=18467 (rdata08AD205C)
>      18:52:30.264            LOG RX 325 bytes Response msg
>     200/SUBSCRIBE/cseq=18467 (rdata08AD205C) from UDP
>     172.18.0.170:5060 <http://172.18.0.170:5060>:
>     SIP/2.0 200 OKVia: SIP/2.0/UDP
>     172.18.0.51:64184;rport;branch=z9hG4bKPj2a88b60293e04037b45d300b58f62805From:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>;tag=d103bb6cc0da447e9c7c9c33639de6ffTo:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>Call-ID:
>     604970b238994208a7d87f72670279d8CSeq: 18467 SUBSCRIBEContent-Length: 0
>     --end msg--
>      18:52:30.290    tsx0F26D85C Incoming Response msg
>     200/SUBSCRIBE/cseq=18467 (rdata08AD205C) in state Calling
>      18:52:30.300    tsx0F26D85C State changed from Calling to
>     Completed, event=RX_MSG
>      18:52:30.310    dlg0F05085C Received Response msg
>     200/SUBSCRIBE/cseq=18467 (rdata08AD205C)
>      18:52:30.325    dlg0F05085C Route-set updated
>      18:52:30.338    dlg0F05085C Route-set frozen
>      18:52:30.350    dlg0F05085C Transaction tsx0F26D85C state changed
>     to Completed
>      18:52:30.361  evsub0F050E54 Will refresh in 595 seconds
>      18:52:30.371  evsub0F050E54 Timer UAC_REFRESH scheduled in 595
>     seconds
>      18:52:30.385  evsub0F050E54 Subscription state changed SENT -->
>     ACCEPTED
>      18:52:30.398 sip_endpoint.c Processing incoming message: Request
>     msg NOTIFY/cseq=1 (rdata08AD205C)
>      18:52:30.408            LOG RX 659 bytes Request msg
>     NOTIFY/cseq=1 (rdata08AD205C) from UDP 172.18.0.170:5060
>     <http://172.18.0.170:5060>:
>     NOTIFY sip:172.18.0.51:64184;transport=udp SIP/2.0Call-ID:
>     604970b238994208a7d87f72670279d8CSeq: 1 NOTIFYFrom:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>To:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>;tag=d103bb6cc0da447e9c7c9c33639de6ffVia:
>     SIP/2.0/UDP
>     172.18.0.170:5060;branch=z9hG4bK2dc5f14fb0047ac49899ed225763d3feMax-Forwards:
>     70Event:  presenceSubscription-State:
>     active;expires=600Content-Type:
>     application/pidf+xmlContent-Length: 199<?xml version="1.0"
>     encoding="UTF-8" standalone="no"?><presence
>     xmlns:mcg="http://mcg.wit-software.com/presence"
>     entity="pres:+351914871189 at wcs.wit-software.com
>     <mailto:pres%3A%2B351914871189 at wcs.wit-software.com>"
>     xmlns="urn:ietf:params:xml:ns:pidf"/>
>     --end msg--
>      18:52:30.423    dlg0F05085C Received Request msg NOTIFY/cseq=1
>     (rdata08AD205C)
>      18:52:30.438    tsx0ECF885C Transaction created for Request msg
>     NOTIFY/cseq=1 (rdata08AD205C)
>      18:52:30.449    tsx0ECF885C Incoming Request msg NOTIFY/cseq=1
>     (rdata08AD205C) in state Null
>      18:52:30.461    tsx0ECF885C State changed from Null to Trying,
>     event=RX_MSG
>      18:52:30.474    dlg0F05085C Transaction tsx0ECF885C state changed
>     to Trying
>      18:52:30.490  evsub0F050E54 Will refresh in 595 seconds
>      18:52:30.510  evsub0F050E54 Updating UAC_REFRESH timer
>      18:52:30.535  evsub0F050E54 Timer UAC_REFRESH scheduled in 595
>     seconds
>      18:52:30.567       endpoint Response msg 200/NOTIFY/cseq=1
>     (tdta0FA52FF8) created
>      18:52:30.578    dlg0F05085C Sending Response msg
>     200/NOTIFY/cseq=1 (tdta0FA52FF8)
>      18:52:30.590    tsx0ECF885C Sending Response msg
>     200/NOTIFY/cseq=1 (tdta0FA52FF8) in state Trying
>      18:52:30.602  sip_resolve.c Target '172.18.0.170:5060
>     <http://172.18.0.170:5060>' type=UDP resolved to
>     '172.18.0.170:5060 <http://172.18.0.170:5060>' type=UDP (UDP
>     transport)
>      18:52:30.615            LOG TX 462 bytes Response msg
>     200/NOTIFY/cseq=1 (tdta0FA52FF8) to UDP 172.18.0.170:5060
>     <http://172.18.0.170:5060>:
>     SIP/2.0 200 OKVia: SIP/2.0/UDP
>     172.18.0.170:5060;received=172.18.0.170
>     <http://172.18.0.170>;branch=z9hG4bK2dc5f14fb0047ac49899ed225763d3feCall-ID:
>     604970b238994208a7d87f72670279d8From:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>To:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>;tag=d103bb6cc0da447e9c7c9c33639de6ffCSeq:
>     1 NOTIFYContact: <sip:172.18.0.51:64184
>     <http://172.18.0.51:64184>>Allow: PRACK, SUBSCRIBE, NOTIFY,
>     PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATESupported:
>     100relContent-Length:  0
>     --end msg--
>      18:52:30.626    tsx0ECF885C State changed from Trying to
>     Completed, event=TX_MSG
>      18:52:30.640    dlg0F05085C Transaction tsx0ECF885C state changed
>     to Completed
>      18:52:30.654  evsub0F050E54 Subscription state changed ACCEPTED
>     --> ACTIVE
>      18:52:30.665    tsx0DAEF85C Timeout timer event
>      18:52:30.684    tsx0DAEF85C State changed from Completed to
>     Terminated, event=TIMER
>      18:52:30.695    tsx0DFB585C Timeout timer event
>      18:52:30.711    tsx0DFB585C State changed from Completed to
>     Terminated, event=TIMER
>      18:52:30.733    tsx0DAEF85C Timeout timer event
>      18:52:30.746    tsx0DAEF85C State changed from Terminated to
>     Destroyed, event=TIMER
>      18:52:30.757    tsx0DAEF85C Transaction destroyed!
>      18:52:30.773    tsx0DFB585C Timeout timer event
>      18:52:30.791    tsx0DFB585C State changed from Terminated to
>     Destroyed, event=TIMER
>      18:52:30.809   tdta0DAD5FF8 Destroying txdata Request msg
>     REGISTER/cseq=18510 (tdta0DAD5FF8)
>      18:52:30.823    tsx0DFB585C Transaction destroyed!
>      18:52:35.300    tsx0F26D85C Timeout timer event
>      18:52:35.314    tsx0F26D85C State changed from Completed to
>     Terminated, event=TIMER
>      18:52:35.331    dlg0F05085C Transaction tsx0F26D85C state changed
>     to Terminated
>      18:52:35.370       endpoint Request msg PUBLISH/cseq=32834
>     (tdta0EF2CFF8) created.
>      18:52:35.387    tsx0ED0A85C Transaction created for Request msg
>     PUBLISH/cseq=32835 (tdta0EF2CFF8)
>      18:52:35.400    tsx0ED0A85C Sending Request msg
>     PUBLISH/cseq=32835 (tdta0EF2CFF8) in state Null
>      18:52:35.413  sip_resolve.c Target '172.18.0.170:5060
>     <http://172.18.0.170:5060>' type=UDP resolved to
>     '172.18.0.170:5060 <http://172.18.0.170:5060>' type=UDP (UDP
>     transport)
>      18:52:35.430            LOG TX 672 bytes Request msg
>     PUBLISH/cseq=32835 (tdta0EF2CFF8) to UDP 172.18.0.170:5060
>     <http://172.18.0.170:5060>:
>     PUBLISH sip:172.18.0.170:5060;transport=UDP;lr SIP/2.0Via:
>     SIP/2.0/UDP
>     172.18.0.51:64184;rport;branch=z9hG4bKPj435ca0600a114dcfa95f2e0042fcc663Max-Forwards:
>     70From: <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>;tag=2dc057d91f2d43df9100295244573051To:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>Call-ID:
>     13cc3b3719394e9d9fc59a546ac81ebcCSeq: 32835 PUBLISHEvent:
>     presenceContent-Type: application/pidf+xmlContent-Length:  
>     234<?xml version="1.0" encoding="UTF-8"?><presence
>     xmlns:mcg="http://mcg.wit-software.com/presence"
>     entity="pres:+351914871189 at wcs.wit-software.com
>     <mailto:pres%3A%2B351914871189 at wcs.wit-software.com>"><tuple
>     id="0"><mcg:presence><mcg:status>1</mcg:status></mcg:presence></tuple></presence>
>     --end msg--
>      18:52:35.452    tsx0ED0A85C State changed from Null to Calling,
>     event=TX_MSG
>      18:52:35.477    tsx0F26D85C Timeout timer event
>      18:52:35.492    tsx0F26D85C State changed from Terminated to
>     Destroyed, event=TIMER
>      18:52:35.505   tdta0ED66FF8 Destroying txdata Request msg
>     SUBSCRIBE/cseq=18467 (tdta0ED66FF8)
>      18:52:35.526    tsx0F26D85C Transaction destroyed!
>      18:52:35.550 sip_endpoint.c Processing incoming message: Response
>     msg 100/PUBLISH/cseq=32835 (rdata08AD205C)
>      18:52:35.576            LOG RX 327 bytes Response msg
>     100/PUBLISH/cseq=32835 (rdata08AD205C) from UDP 172.18.0.170:5060
>     <http://172.18.0.170:5060>:
>     SIP/2.0 100 TryingVia: SIP/2.0/UDP
>     172.18.0.51:64184;rport;branch=z9hG4bKPj435ca0600a114dcfa95f2e0042fcc663From:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>;tag=2dc057d91f2d43df9100295244573051To:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>Call-ID:
>     13cc3b3719394e9d9fc59a546ac81ebcCSeq: 32835 PUBLISHContent-Length: 0
>     --end msg--
>      18:52:35.589    tsx0ED0A85C Incoming Response msg
>     100/PUBLISH/cseq=32835 (rdata08AD205C) in state Calling
>      18:52:35.607    tsx0ED0A85C State changed from Calling to
>     Proceeding, event=RX_MSG
>      18:52:35.649 sip_endpoint.c Processing incoming message: Response
>     msg 200/PUBLISH/cseq=32835 (rdata08AD205C)
>      18:52:35.665            LOG RX 323 bytes Response msg
>     200/PUBLISH/cseq=32835 (rdata08AD205C) from UDP 172.18.0.170:5060
>     <http://172.18.0.170:5060>:
>     SIP/2.0 200 OKVia: SIP/2.0/UDP
>     172.18.0.51:64184;rport;branch=z9hG4bKPj435ca0600a114dcfa95f2e0042fcc663From:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>;tag=2dc057d91f2d43df9100295244573051To:
>     <sip:+351914871189 at wcs.wit-software.com
>     <mailto:sip%3A%2B351914871189 at wcs.wit-software.com>>Call-ID:
>     13cc3b3719394e9d9fc59a546ac81ebcCSeq: 32835 PUBLISHContent-Length: 0
>     --end msg--
>      18:52:35.678    tsx0ED0A85C Incoming Response msg
>     200/PUBLISH/cseq=32835 (rdata08AD205C) in state Proceeding
>      18:52:35.689    tsx0ED0A85C State changed from Proceeding to
>     Completed, event=RX_MSG
>      18:52:40.689    tsx0ED0A85C Timeout timer event
>      18:52:40.701    tsx0ED0A85C State changed from Completed to
>     Terminated, event=TIMER
>      18:52:40.723    tsx0ED0A85C Timeout timer event
>      18:52:40.734    tsx0ED0A85C State changed from Terminated to
>     Destroyed, event=TIMER
>      18:52:40.747   tdta0EF2CFF8 Destroying txdata Request msg
>     PUBLISH/cseq=32835 (tdta0EF2CFF8)
>      18:52:40.759    tsx0ED0A85C Transaction destroyed!
>      18:52:55.957    SIPCall.cpp [TEST] StartCall()
>      18:52:55.971    SIPCall.cpp [TEST] StartCall() - MCG Call
>      18:52:55.983    SIPCall.cpp [TEST] StartCall() -
>     pjsip_dlg_create_uac()
>      18:52:55.998    dlg15AE285C UAC dialog created
>      18:52:56.022    SIPCall.cpp [TEST] StartCall() -
>     CreateRTPTransports()
>      18:52:56.049    SIPCall.cpp [TEST] StartCall() -
>     pjmedia_endpt_create_sdp()
>      18:52:56.061    g723decoder test_Alloc?
>      18:52:56.073    g723decoder test_Alloc Ok
>      18:52:56.086    SIPCall.cpp pandre create_ice_offer stun_srv in
>     SIPEngine=172.18.0.169:3478 <http://172.18.0.169:3478> slen=0.000000
>      18:52:56.099 ICEVoiceTransp Creating ICE stream transport with 2
>     component(s)
>      18:52:56.112 stuntp15C7DEF8 TX 20 bytes STUN message to
>     172.18.0.169:3478 <http://172.18.0.169:3478>:
>     --- begin STUN message ---
>     STUN Binding request
>      Hdr: length=0, magic=2112a442, tsx_id=72ae3d6c6df15f90000141bb
>      Attributes:
>     --- end of STUN message ---
>
>      18:52:56.125 stuntsx15CA3F4 STUN client transaction created
>      18:52:56.137 stuntsx15CA3F4 STUN sending message (transmit count=1)
>      18:52:56.151     stun_msg.c Unrecognized attribute type 0x8020
>      18:52:56.172  sock_common.c pandre-dbg on pj_sockaddr_cp
>     dst=15C7BC58 src=0012DAAC
>      18:52:56.173 stuntp15C7DEF8 RX 88 bytes STUN message from
>     172.18.0.169:3478 <http://172.18.0.169:3478>:
>     --- begin STUN message ---
>     STUN Binding success response
>      Hdr: length=68, magic=2112a442, tsx_id=72ae3d6c6df15f90000141bb
>      Attributes:
>      MAPPED-ADDRESS: length=8, IPv4 addr=172.18.0.51:64888
>     <http://172.18.0.51:64888>
>      SOURCE-ADDRESS: length=8, IPv4 addr=172.18.0.169:3478
>     <http://172.18.0.169:3478>
>      CHANGED-ADDRESS: length=8, IPv4 addr=172.18.0.170:3479
>     <http://172.18.0.170:3479>
>      ???: length=8
>      SERVER: length=16, value="Vovida.org 0.96"
>     --- end of STUN message ---
>
>      18:52:56.186  sock_common.c pandre-dbg on pj_sockaddr_cp
>     dst=15C7BC74 src=15C7BC58
>      18:52:56.210 ICEVoiceTransp Comp 1: srflx candidate starts
>     Binding discovery
>      18:52:56.197 stuntp15C7DEF8 STUN mapped address found/changed:
>     172.18.0.51:64888 <http://172.18.0.51:64888>
>      18:52:56.211  sock_common.c pandre-dbg on pj_sockaddr_cp
>     dst=15C7FE78 src=15C9FCBC
>      18:52:56.245    stun_sock.c pandre-dbg comp=15C7BC0C i=0 on
>     sess_on_request_complete
>      18:52:56.255  sock_common.c pandre-dbg on pj_sockaddr_cp
>     dst=15C7BCA8 src=0012D96C
>      18:52:56.266    stun_sock.c pandre-dbg comp=00000000 i=1 on
>     sess_on_request_complete
>      18:52:56.292  sock_common.c pandre-dbg on pj_sockaddr_cp
>     dst=15C7BCC4 src=0012D96C
>      18:52:56.307   ice_strans.c pandre-dbg comp=15C7BC0C i=0 on
>     stun_on_status(1)
>      18:52:56.323 ICEVoiceTransp Comp 1: host candidate
>     172.18.0.51:64888 <http://172.18.0.51:64888> added
>      18:52:56.337   ice_strans.c pandre-dbg comp=00000000 i=1 on
>     stun_on_status(1)
>      18:52:56.351  sock_common.c pandre-dbg on pj_sockaddr_cp
>     dst=15C7BD14 src=0012D988
>      18:52:56.382  sock_common.c pandre-dbg on pj_sockaddr_cp
>     dst=15C7BD30 src=0012D988
>      18:52:56.395 ICEVoiceTransp Comp 1: Binding discovery complete,
>     srflx address is 172.18.0.51:64888 <http://172.18.0.51:64888>
>      18:52:56.400 ICEVoiceTransp Comp 1: host candidate
>     192.168.102.1:64888 <http://192.168.102.1:64888> added
>      18:52:56.418   ice_strans.c pandre-dbg comp=15C7BC0C i=0 on
>     stun_on_status
>      18:52:56.439  sock_common.c pandre-dbg on pj_sockaddr_cp
>     dst=15C7BD14 src=0012D9A4
>      18:52:56.457   ice_strans.c pandre-dbg comp=00000000 i=1 on
>     stun_on_status
>      18:52:56.471  sock_common.c pandre-dbg on pj_sockaddr_cp
>     dst=15C7BD30 src=0012D9A4
>      18:52:56.488   ice_strans.c pandre-dbg comp=15C7BC0C i=0 on
>     sess_init_update
>      18:52:56.495 ICEVoiceTransp Comp 1: host candidate
>     192.168.1.1:64888 <http://192.168.1.1:64888> added
>      18:52:56.512  sock_common.c pandre-dbg on pj_sockaddr_cp
>     dst=15C7BD80 src=0012D9C0
>      18:52:56.513  sock_common.c pandre-dbg on pj_sockaddr_cp
>     dst=15C7BD9C src=0012D9C0
>      18:52:56.514 ICEVoiceTransp Comp 1: host candidate
>     172.18.0.52:64888 <http://172.18.0.52:64888> added
>      18:52:56.514   ice_strans.c pandre-dbg comp=00000000 i=1 on
>     sess_init_update
>      18:52:56.564 stuntp15D2DEF8 TX 20 bytes STUN message to
>     172.18.0.169:3478 <http://172.18.0.169:3478>:
>     --- begin STUN message ---
>     STUN Binding request
>      Hdr: length=0, magic=2112a442, tsx_id=153c2ea60099390c0001305e
>      Attributes:
>     --- end of STUN message ---
>
>      18:52:56.578 stuntsx14087F4 STUN client transaction created
>      18:52:56.579 stuntsx14087F4 STUN sending message (transmit count=1)
>
>     _______________________________________________
>     Visit our blog: http://blog.pjsip.org
>
>     pjsip mailing list
>     pjsip at lists.pjsip.org <mailto:pjsip at lists.pjsip.org>
>     http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org
>
>
> ------------------------------------------------------------------------
>
> _______________________________________________
> Visit our blog: http://blog.pjsip.org
>
> pjsip mailing list
> pjsip at lists.pjsip.org
> http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org
>   






More information about the pjsip mailing list