Strange behavior when making a call (format fix)

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi Mathieu,

The problematic address is coming from the origin o= line in the SDP:

Failed to resolve 'pcgw-0005.imsgroup0-000.xxx.xxx.org'

To compare with XLite, you could do a wireshark trace of XLite call and 
capture the outgoing invite and compare that to the invite from pjsip. 
It might offer some clues.

Regards,

Bill

On 2/26/2015 11:29 AM, Mathieu Trinc wrote:
> Hi Bill,
>   
> Thank you for your help.
>   
> I cannot resolve this hostname on my machine but I am not sure this is an issue.
> With a different SIP stack (XLite is based on reSIProcate if I am correct) no PRACK is sent and the 183 is immediately followed by 180 Ringing.
>
> I rebuild PJSIP with PJ_LOG_MAX_LEVEL set to 6 and I got a much more verbose log. I removed the Mutex / Semaphore / Pool  stuff to keep it somewhat short.
> The scenario is: Register - Make a call - When established wait a few seconds and hang up - Unregister.
>
> 16:17:56.356 sip_endpoint.c  .Module "mod-pjsua-log" registered
> 16:17:56.356 sip_endpoint.c  .Module "mod-tsx-layer" registered
> 16:17:56.356 sip_endpoint.c  .Module "mod-stateful-util" registered
> 16:17:56.356 sip_endpoint.c  .Module "mod-ua" registered
> 16:17:56.356 sip_endpoint.c  .Module "mod-100rel" registered
> 16:17:56.356 sip_endpoint.c  .Module "mod-pjsua" registered
> 16:17:56.356 sip_endpoint.c  .Module "mod-invite" registered
> 16:17:56.376     wmme_dev.c  ..WMME found 4 devices:
> 16:17:56.376     wmme_dev.c  .. dev_id 0: Wave mapper  (in=2, out=2)
> 16:17:56.376     wmme_dev.c  .. dev_id 1: CABLE Output (VB-Audio Virtual   (in=2, out=0)
> 16:17:56.376     wmme_dev.c  .. dev_id 2: Haut-parleurs (Realtek High Def  (in=0, out=2)
> 16:17:56.376     wmme_dev.c  .. dev_id 3: CABLE Input (VB-Audio Virtual C  (in=0, out=2)
> 16:17:56.376     wmme_dev.c  ..WMME initialized
> 16:17:56.377          pjlib  ..select() I/O Queue created (00391F34)
> 16:17:56.377   conference.c  ..Creating conference bridge with 254 ports
> 16:17:56.378   Master/sound  ..Using delay buffer with WSOLA.
> 16:17:56.379 sip_endpoint.c  .Module "mod-evsub" registered
> 16:17:56.379 sip_endpoint.c  .Module "mod-presence" registered
> 16:17:56.379        evsub.c  .Event pkg "presence" registered by mod-presence
> 16:17:56.379 sip_endpoint.c  .Module "mod-mwi" registered
> 16:17:56.379        evsub.c  .Event pkg "message-summary" registered by mod-mwi
> 16:17:56.379 sip_endpoint.c  .Module "mod-refer" registered
> 16:17:56.379        evsub.c  .Event pkg "refer" registered by mod-refer
> 16:17:56.379 sip_endpoint.c  .Module "mod-pjsua-pres" registered
> 16:17:56.379 sip_endpoint.c  .Module "mod-pjsua-im" registered
> 16:17:56.379 sip_endpoint.c  .Module "mod-pjsua-options" registered
> 16:17:56.379   pjsua_core.c  .1 SIP worker threads created
> 16:17:56.379   pjsua_core.c  .pjsua version 2.3 for win32-6.1/i386/msvc-18.0 initialized
> 16:17:56.379   pjsua_core.c  .PJSUA state changed: CREATED --> INIT
> 16:17:56.379 sip_endpoint.c  Module "mod-default-handler" registered
> 16:17:56.381   pjsua_core.c  SIP UDP socket reachable at 192.168.1.25:5060
> 16:17:56.381    udp00397478  SIP UDP transport started, published address is 192.168.1.25:5060
> 16:17:56.381    pjsua_acc.c  Adding account: id=<sip:192.168.1.25:5060>
> 16:17:56.382    pjsua_acc.c  .Account <sip:192.168.1.25:5060> added with id 0
> 16:17:56.382    pjsua_acc.c  Modifying accunt 0
> 16:17:56.382    pjsua_acc.c  Acc 0: setting online status to 1..
> 16:17:56.383    tcplis:5060  SIP TCP listener ready for incoming connections at 192.168.1.25:5060
> 16:17:56.383    pjsua_acc.c  Adding account: id=<sip:192.168.1.25:5060;transport=TCP>
> 16:17:56.383    pjsua_acc.c  .Account <sip:192.168.1.25:5060;transport=TCP> added with id 1
> 16:17:56.383    pjsua_acc.c  Modifying accunt 1
> 16:17:56.383    pjsua_acc.c  Acc 1: setting online status to 1..
> 16:17:56.383    pjsua_acc.c  Adding account: id=sip:USERID at DOMAIN
> 16:17:56.383    pjsua_acc.c  .Account sip:USERID at DOMAIN added with id 2
> 16:17:56.383    pjsua_acc.c  .Acc 2: setting registration..
> 16:17:56.383       endpoint  ..Request msg REGISTER/cseq=28616 (tdta003AE538) created.
> 16:17:56.384    tsx003AF5A4  ..tsx_key=c$REGISTER$z9hG4bKPj1caae52047514465bbbb37b048652f7f
> 16:17:56.384    tsx003AF5A4  ...Transaction created for Request msg REGISTER/cseq=28617 (tdta003AE538)
> 16:17:56.384    tsx003AF5A4  ..Sending Request msg REGISTER/cseq=28617 (tdta003AE538) in state Null
> 16:17:56.384  sip_resolve.c  ...DNS resolver not available, target 'OUTBOUNDPROXY_NAME:5060' type=Unspecified will be resolved with getaddrinfo()
> 16:17:56.384  sip_resolve.c  ...Target 'OUTBOUNDPROXY_NAME:5060' type=Unspecified resolved to 'OUTBOUNDPROXY_IP:5060' type=UDP (UDP transport)
> 16:17:56.384   pjsua_core.c  ...TX 661 bytes Request msg REGISTER/cseq=28617 (tdta003AE538) to UDP OUTBOUNDPROXY_IP:5060:
> REGISTER sip:DOMAIN SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.25:5060;rport;branch=z9hG4bKPj1caae52047514465bbbb37b048652f7f
> Route: <sip:OUTBOUNDPROXY_NAME:5060;lr>
> Max-Forwards: 70
> From: <sip:USERID@DOMAIN>;tag=eb783c90ea264adeba0df424b03d9ed8
> To: <sip:USERID at DOMAIN>
> Call-ID: 9a4de08282c5425f87ad8241a66aad68
> CSeq: 28617 REGISTER
> User-Agent: PJSUA v2.3 win32-6.1/i386/msvc-18.0
> Contact: <sip:USERID at 192.168.1.25:5060;ob>
> Expires: 300
> Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
> Content-Length:  0
>
>
> --end msg--
> 16:17:56.384    tsx003AF5A4  ...State changed from Null to Calling, event=TX_MSG
> 16:17:56.384    pjsua_acc.c  ..Acc 2: Registration sent
> 16:17:56.384    pjsua_acc.c  Acc 2: setting online status to 1..
> 16:17:56.384   pjsua_core.c  PJSUA state changed: INIT --> STARTING
> 16:17:56.384 sip_endpoint.c  .pjsip_endpt_schedule_timer(entry=01423638, delay=300.0)
> 16:17:56.384 sip_endpoint.c  .Module "mod-unsolicited-mwi" registered
> 16:17:56.384   pjsua_core.c  .PJSUA state changed: STARTING --> RUNNING
> 16:17:56.384         main.c  Ready: Success
> 16:17:56.759 sip_endpoint.c  Processing incoming message: Response msg 401/REGISTER/cseq=28617 (rdata003A6214)
> 16:17:56.759   pjsua_core.c  .RX 715 bytes Response msg 401/REGISTER/cseq=28617 (rdata003A6214) from UDP OUTBOUNDPROXY_IP:5060:
> SIP/2.0 401 Unauthorized
> Call-ID: 9a4de08282c5425f87ad8241a66aad68
> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPj1caae52047514465bbbb37b048652f7f;rport=5060
> To: <sip:USERID at DOMAIN>;tag=54596245-54ef38b957bcfb4
> From: <sip:USERID@DOMAIN>;tag=eb783c90ea264adeba0df424b03d9ed8
> CSeq: 28617 REGISTER
> Date: Thu, 26 Feb 2015 15:16:09 GMT
> Server: Alcatel-Lucent-HPSS/3.0.3
> WWW-Authenticate: Digest realm="REALM",
> nonce="xxx",
> opaque="ALU:xxx",
> algorithm=MD5,
> qop="auth"
> Content-Length: 0
>
>
> --end msg--
> 16:17:56.759    tsx003AF5A4  .Incoming Response msg 401/REGISTER/cseq=28617 (rdata003A6214) in state Calling
> 16:17:56.759    tsx003AF5A4  ..State changed from Calling to Completed, event=RX_MSG
> 16:17:56.760    tsx003B1CF4  ...tsx_key=c$REGISTER$z9hG4bKPje41f2d4140fd47d1835769e90ac88ffa
> 16:17:56.760    tsx003B1CF4  ....Transaction created for Request msg REGISTER/cseq=28618 (tdta003AE538)
> 16:17:56.760    tsx003B1CF4  ...Sending Request msg REGISTER/cseq=28618 (tdta003AE538) in state Null
> 16:17:56.760       endpoint  ....Request msg REGISTER/cseq=28618 (tdta003AE538): skipping target resolution because address is already set
> 16:17:56.760   pjsua_core.c  ....TX 1056 bytes Request msg REGISTER/cseq=28618 (tdta003AE538) to UDP OUTBOUNDPROXY_IP:5060:
> REGISTER sip:DOMAIN SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.25:5060;rport;branch=z9hG4bKPje41f2d4140fd47d1835769e90ac88ffa
> Route: <sip:OUTBOUNDPROXY_NAME:5060;lr>
> Max-Forwards: 70
> From: <sip:USERID@DOMAIN>;tag=eb783c90ea264adeba0df424b03d9ed8
> To: <sip:USERID at DOMAIN>
> Call-ID: 9a4de08282c5425f87ad8241a66aad68
> CSeq: 28618 REGISTER
> User-Agent: PJSUA v2.3 win32-6.1/i386/msvc-18.0
> Contact: <sip:USERID at 192.168.1.25:5060;ob>
> Expires: 300
> Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
> Authorization: Digest username="AUTHNAME", realm="REALM", nonce="xxx", uri="sip:DOMAIN", response="xxx", algorithm=MD5, cnonce="xxx", opaque="ALU:xxx", qop=auth, nc=00000001
> Content-Length:  0
>
>
> --end msg--
> 16:17:56.760    tsx003B1CF4  ....State changed from Null to Calling, event=TX_MSG
> 16:17:56.873 sip_endpoint.c  Processing incoming message: Response msg 200/REGISTER/cseq=28618 (rdata003A6214)
> 16:17:56.873   pjsua_core.c  .RX 792 bytes Response msg 200/REGISTER/cseq=28618 (rdata003A6214) from UDP OUTBOUNDPROXY_IP:5060:
> SIP/2.0 200 OK
> Call-ID: 9a4de08282c5425f87ad8241a66aad68
> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPje41f2d4140fd47d1835769e90ac88ffa;rport=5060
> To: <sip:USERID at DOMAIN>;tag=54596245-54ef38b9c28301d
> From: <sip:USERID@DOMAIN>;tag=eb783c90ea264adeba0df424b03d9ed8
> CSeq: 28618 REGISTER
> Allow-Events: reg
> Contact: <sip:USERID at 192.168.1.25:5060;ob;transport=udp>;expires=300
> Date: Thu, 26 Feb 2015 15:16:09 GMT
> Path: <sip:pcgw-0005.imsgroup0-000.xxx.xxx.org:5060;lr;ottag=ue_term;bidx=6201093;access-type=ADSL>
> P-Associated-URI: <sip:USERID at DOMAIN>
> P-Associated-URI: <tel:USERID>
> Server: Alcatel-Lucent-HPSS/3.0.3
> Content-Length: 0
>
>
> --end msg--
> 16:17:56.873    tsx003B1CF4  .Incoming Response msg 200/REGISTER/cseq=28618 (rdata003A6214) in state Calling
> 16:17:56.873    tsx003B1CF4  ..State changed from Calling to Completed, event=RX_MSG
> 16:17:56.873 sip_endpoint.c  ...pjsip_endpt_schedule_timer(entry=003AC76C, delay=295.0)
> 16:17:56.874    pjsua_acc.c  ....SIP outbound status for acc 2 is not active
> 16:17:56.874    pjsua_acc.c  ....sip:USERID at DOMAIN: registration success, status=200 (OK), will re-register in 300 seconds
> 16:17:56.874 sip_endpoint.c  ....pjsip_endpt_schedule_timer(entry=013DA2B4, delay=15.0)
> 16:17:56.874    pjsua_acc.c  ....Keep-alive timer started for acc 2, destination:OUTBOUNDPROXY_IP:5060, interval:15s
> 16:18:01.761    tsx003AF5A4  Timeout timer event
> 16:18:01.761    tsx003AF5A4  .State changed from Completed to Terminated, event=TIMER
> 16:18:01.761    tsx003AF5A4  Timeout timer event
> 16:18:01.761    tsx003AF5A4  .State changed from Terminated to Destroyed, event=TIMER
> 16:18:01.761    tsx003AF5A4  Transaction destroyed!
> 16:18:01.875    tsx003B1CF4  Timeout timer event
> 16:18:01.875    tsx003B1CF4  .State changed from Completed to Terminated, event=TIMER
> 16:18:01.875    tsx003B1CF4  Timeout timer event
> 16:18:01.875    tsx003B1CF4  .State changed from Terminated to Destroyed, event=TIMER
> 16:18:01.875   tdta003AE538  ..Destroying txdata Request msg REGISTER/cseq=28618 (tdta003AE538)
> 16:18:01.875    tsx003B1CF4  Transaction destroyed!
> 16:18:07.342   pjsua_call.c  Making call with acc #2 to sip:01xxxxxxxx at DOMAIN
> 16:18:07.342    pjsua_aud.c  .Set sound device: capture=-1, playback=-2
> 16:18:07.342    pjsua_app.c  ..Turning sound device ON
> 16:18:07.342    pjsua_aud.c  ..Opening sound device PCM at 16000/1/20ms
> 16:18:07.376     wmme_dev.c  ... WaveAPI Sound player "Wave mapper" initialized (format=PCM, clock_rate=16000, channel_count=1, samples_per_frame=320 (20ms))
> 16:18:07.387     wmme_dev.c  ... WaveAPI Sound recorder "Wave mapper" initialized (format=PCM, clock_rate=16000, channel_count=1, samples_per_frame=320 (20ms))
> 16:18:07.388     ec003C2680  ...Creating AEC
> 16:18:07.388     ec003C2680  ...AEC created, clock_rate=16000, channel=1, samples per frame=320, tail length=200 ms, latency=0 ms
> 16:18:07.388     wmme_dev.c  ...WMME playback stream started
> 16:18:07.388     wmme_dev.c  ...WMME capture stream started
> 16:18:07.389    dlg003F40FC  .UAC dialog created
> 16:18:07.389    dlg003F40FC  ..Session count inc to 2 by mod-pjsua
> 16:18:07.389  pjsua_media.c  .Call 0: initializing media..
> 16:18:07.392  pjsua_media.c  ..RTP socket reachable at 192.168.1.25:4000
> 16:18:07.392  pjsua_media.c  ..RTCP socket reachable at 192.168.1.25:4001
> 16:18:07.392  pjsua_media.c  ..Media index 0 selected for audio call 0
> 16:18:07.392    dlg003F40FC  ..Session count dec to 2 by mod-pjsua
> 16:18:07.393    dlg003F40FC  .Module mod-invite added as dialog usage, data=003A93BC
> 16:18:07.393    dlg003F40FC  ..Session count inc to 4 by mod-invite
> 16:18:07.393    dlg003F40FC  .Module mod-100rel added as dialog usage, data=003A99DC
> 16:18:07.393    dlg003F40FC  .100rel module attached
> 16:18:07.393    inv003F40FC  .UAC invite session created for dialog dlg003F40FC
> 16:18:07.393       endpoint  .Request msg INVITE/cseq=27953 (tdta003F9070) created.
> 16:18:07.393    inv003F40FC  ..Sending Request msg INVITE/cseq=27953 (tdta003F9070)
> 16:18:07.393    dlg003F40FC  ...Sending Request msg INVITE/cseq=27953 (tdta003F9070)
> 16:18:07.393    tsx003FB084  ...tsx_key=c$z9hG4bKPj4cff374a64f44dd59ed8163da9fcbd36
> 16:18:07.393    tsx003FB084  ....Transaction created for Request msg INVITE/cseq=27952 (tdta003F9070)
> 16:18:07.393    tsx003FB084  ...Sending Request msg INVITE/cseq=27952 (tdta003F9070) in state Null
> 16:18:07.393  sip_resolve.c  ....DNS resolver not available, target 'OUTBOUNDPROXY_NAME:5060' type=Unspecified will be resolved with getaddrinfo()
> 16:18:07.394  sip_resolve.c  ....Target 'OUTBOUNDPROXY_NAME:5060' type=Unspecified resolved to 'OUTBOUNDPROXY_IP:5060' type=UDP (UDP transport)
> 16:18:07.394   pjsua_core.c  ....TX 1238 bytes Request msg INVITE/cseq=27952 (tdta003F9070) to UDP OUTBOUNDPROXY_IP:5060:
> INVITE sip:01xxxxxxxx at DOMAIN SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.25:5060;rport;branch=z9hG4bKPj4cff374a64f44dd59ed8163da9fcbd36
> Max-Forwards: 70
> From: sip:USERID@DOMAIN;tag=1162169bb9034eac9d245678948fabfc
> To: sip:01xxxxxxxx at DOMAIN
> Contact: <sip:USERID at 192.168.1.25:5060;ob>
> Call-ID: b072b55fa1f14d3bb25591d61f3c73bc
> CSeq: 27952 INVITE
> Route: <sip:OUTBOUNDPROXY_NAME:5060;lr>
> Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
> Supported: replaces, 100rel, timer, norefersub
> Session-Expires: 1800
> Min-SE: 90
> User-Agent: PJSUA v2.3 win32-6.1/i386/msvc-18.0
> Content-Type: application/sdp
> Content-Length:   473
>
> v=0
> o=- 3633956287 3633956287 IN IP4 192.168.1.25
> s=pjmedia
> b=AS:84
> t=0 0
> a=X-nat:0
> m=audio 4000 RTP/AVP 98 97 99 104 3 0 8 9 96
> c=IN IP4 192.168.1.25
> b=TIAS:64000
> a=rtcp:4001 IN IP4 192.168.1.25
> a=sendrecv
> a=rtpmap:98 speex/16000
> a=rtpmap:97 speex/8000
> a=rtpmap:99 speex/32000
> a=rtpmap:104 iLBC/8000
> a=fmtp:104 mode=30
> a=rtpmap:3 GSM/8000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:8 PCMA/8000
> a=rtpmap:9 G722/8000
> a=rtpmap:96 telephone-event/8000
> a=fmtp:96 0-16
>
> --end msg--
> 16:18:07.394    tsx003FB084  ....State changed from Null to Calling, event=TX_MSG
> 16:18:07.394    dlg003F40FC  .....Transaction tsx003FB084 state changed to Calling
> 16:18:07.394    pjsua_app.c  .......Call 0 state changed to CALLING
> 16:18:07.419          speex  warning: discarded first playback frame
> 16:18:07.448          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
> 16:18:07.448 sip_endpoint.c  Processing incoming message: Response msg 100/INVITE/cseq=27952 (rdata003A6214)
> 16:18:07.448   pjsua_core.c  .RX 469 bytes Response msg 100/INVITE/cseq=27952 (rdata003A6214) from UDP OUTBOUNDPROXY_IP:5060:
> SIP/2.0 100 Trying
> Call-ID: b072b55fa1f14d3bb25591d61f3c73bc
> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPj4cff374a64f44dd59ed8163da9fcbd36;rport=5060
> To: <sip:01xxxxxxxx at DOMAIN;user=phone>
> From: <sip:USERID@DOMAIN;user=phone>;tag=1162169bb9034eac9d245678948fabfc
> CSeq: 27952 INVITE
> Date: Thu, 26 Feb 2015 15:16:19 GMT
> Server: Alcatel-Lucent-HPSS/3.0.3
> Content-Length: 0
>
>
> --end msg--
> 16:18:07.448    tsx003FB084  .Incoming Response msg 100/INVITE/cseq=27952 (rdata003A6214) in state Calling
> 16:18:07.449    tsx003FB084  ..State changed from Calling to Proceeding, event=RX_MSG
> 16:18:07.449    dlg003F40FC  ...UA layer acquiring dialog lock for response
> 16:18:07.449    dlg003F40FC  ...Received Response msg 100/INVITE/cseq=27952 (rdata003A6214)
> 16:18:07.449    dlg003F40FC  ...Transaction tsx003FB084 state changed to Proceeding
> 16:18:10.337 sip_endpoint.c  Processing incoming message: Response msg 183/INVITE/cseq=27952 (rdata003A6214)
> 16:18:10.338   pjsua_core.c  .RX 1097 bytes Response msg 183/INVITE/cseq=27952 (rdata003A6214) from UDP OUTBOUNDPROXY_IP:5060:
> SIP/2.0 183 Session Progress
> Call-ID: b072b55fa1f14d3bb25591d61f3c73bc
> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPj4cff374a64f44dd59ed8163da9fcbd36;rport=5060
> To: <sip:01xxxxxxxx at DOMAIN;user=phone>;tag=54596251-54ef38c32e9e55a9-gm-po-lucentPCSF-035501
> From: <sip:USERID@DOMAIN;user=phone>;tag=1162169bb9034eac9d245678948fabfc
> CSeq: 27952 INVITE
> Require: 100rel
> Allow: INVITE,BYE,REGISTER,ACK,OPTIONS,CANCEL,SUBSCRIBE,NOTIFY,PRACK,INFO,REFER,UPDATE
> Contact: <sip:lucentNGFS-007410 at pcgw-0005.imsgroup0-000.xxx.xxx.org:5060;encoded-parm=QbkRBthOEgsTXgkTBA0HHiUrKz1CQEFFR0VFNgQMGAlsMTcgK2ghOyAnOCs.ITogYX9jZmR4NjsxblJGQAQEGF5VSh5dSBNMDQERXFJYX1o_>
> Content-Type: application/sdp
> RSeq: 1
> Server: Alcatel-Lucent-HPSS/3.0.3
> Content-Length: 247
>
> v=0
> o=LucentPCSF 600759623 600759623 IN IP4 imsgroup0-000.xxx.xxx.org
> s=-
> c=IN IP4 X.X.X.X
> t=0 0
> m=audio 37794 RTP/AVP 8 101
> a=rtpmap:101 telephone-event/8000
> a=sendrecv
> a=ptime:20
> a=maxptime:30
> a=silenceSupp:off - - - -
>
> --end msg--
> 16:18:10.338    tsx003FB084  .Incoming Response msg 183/INVITE/cseq=27952 (rdata003A6214) in state Proceeding
> 16:18:10.338    tsx003FB084  ..State changed from Proceeding to Proceeding, event=RX_MSG
> 16:18:10.338    dlg003F40FC  ...UA layer acquiring dialog lock for response
> 16:18:10.338    dlg003F40FC  ...Received Response msg 183/INVITE/cseq=27952 (rdata003A6214)
> 16:18:10.338    dlg003F40FC  ....Route-set updated
> 16:18:10.338    dlg003F40FC  ...Transaction tsx003FB084 state changed to Proceeding
> 16:18:10.338    pjsua_app.c  .....Call 0 state changed to EARLY (183 Session Progress)
> 16:18:10.338    inv003F40FC  ....Got SDP answer in Response msg 183/INVITE/cseq=27952 (rdata003A6214)
> 16:18:10.338    inv003F40FC  ....SDP negotiation done, status=0
> 16:18:10.338   pjsua_call.c  .....Call 0: remote NAT type is 0 (Unknown)
> 16:18:10.338  pjsua_media.c  .....Call 0: updating media..
> 16:18:10.338    pjsua_aud.c  ......Audio channel update..
> 16:18:10.338    mtx004067B4  .......Mutex created
> 16:18:10.339   strm00405D94  .......VAD temporarily disabled
> 16:18:10.339          rtp.c  .......pjmedia_rtp_session_init: ses=00407C40, default_pt=8, ssrc=0x33ed08d6
> 16:18:10.339          rtp.c  .......pjmedia_rtp_session_init: ses=004082C8, default_pt=8, ssrc=0x33ed08d6
> 16:18:10.339       stream.c  .......Stream strm00405D94 created
> 16:18:10.339   strm00405D94  .......Encoder stream started
> 16:18:10.339   strm00405D94  .......Decoder stream started
> 16:18:10.339     resample.c  .......resample created: high qualiy, large filter, in/out rate=8000/16000
> 16:18:10.339     resample.c  .......resample created: high qualiy, large filter, in/out rate=16000/8000
> 16:18:10.339  pjsua_media.c  ......Audio updated, stream #0: PCMA (sendrecv)
> 16:18:10.339 sip_endpoint.c  .....pjsip_endpt_schedule_timer(entry=013DE684, delay=0.0)
> 16:18:10.339    pjsua_app.c  .....Call 0 media 0 [type=audio], status is Active
> 16:18:10.339    pjsua_aud.c  .....Conf connect: 3 --> 0
> 16:18:10.339   conference.c  ......Port 3 (sip:01xxxxxxxx at DOMAIN) transmitting to port 0 (Wave mapper)
> 16:18:10.339    pjsua_aud.c  .....Conf connect: 0 --> 3
> 16:18:10.339   conference.c  ......Port 0 (Wave mapper) transmitting to port 3 (sip:01xxxxxxxx at DOMAIN)
> 16:18:10.339       endpoint  ....Request msg PRACK/cseq=27954 (tdta00409890) created.
> 16:18:10.339    dlg003F40FC  .....Sending Request msg PRACK/cseq=27954 (tdta00409890)
> 16:18:10.339   glck003AA7F8  .....Mutex created
> 16:18:10.339    tsx0040A8FC  .....Mutex created
> 16:18:10.339    tsx0040A8FC  .....tsx_key=c$PRACK$z9hG4bKPj4a9207e3ef1a444fa25f77a436b0662a
> 16:18:10.339    tsx0040A8FC  ......Transaction created for Request msg PRACK/cseq=27953 (tdta00409890)
> 16:18:10.339    tsx0040A8FC  .....Sending Request msg PRACK/cseq=27953 (tdta00409890) in state Null
> 16:18:10.339  sip_resolve.c  ......DNS resolver not available, target 'pcgw-0005.imsgroup0-000.xxx.xxx.org:5060' type=Unspecified will be resolved with getaddrinfo()
> 16:18:10.340  sip_resolve.c  ......Failed to resolve 'pcgw-0005.imsgroup0-000.xxx.xxx.org'. Err=70018 (gethostbyname() has returned error (PJ_ERESOLVE))
> 16:18:10.340    tsx0040A8FC  ......Failed to send Request msg PRACK/cseq=27953 (tdta00409890)! err=70018 (gethostbyname() has returned error (PJ_ERESOLVE))
> 16:18:10.340    tsx0040A8FC  ......State changed from Null to Terminated, event=TRANSPORT_ERROR
> 16:18:10.340    dlg003F40FC  .......Transaction tsx0040A8FC state changed to Terminated
> 16:18:10.341    tsx0040A8FC  Timeout timer event
> 16:18:10.341    tsx0040A8FC  .State changed from Terminated to Destroyed, event=TIMER
> 16:18:10.341   tdta00409890  ..Destroying txdata Request msg PRACK/cseq=27953 (tdta00409890)
> 16:18:10.341    tsx0040A8FC  Transaction destroyed!
> 16:18:10.358   strm00405D94  Jitter buffer is bufferring (prefetch=0), plc invoked
> 16:18:10.359   strm00405D94  Start talksprut..
> 16:18:10.907 sip_endpoint.c  Processing incoming message: Response msg 183/INVITE/cseq=27952 (rdata003A6214)
> 16:18:10.907   pjsua_core.c  .RX 1097 bytes Response msg 183/INVITE/cseq=27952 (rdata003A6214) from UDP OUTBOUNDPROXY_IP:5060:
> SIP/2.0 183 Session Progress
> Call-ID: b072b55fa1f14d3bb25591d61f3c73bc
> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPj4cff374a64f44dd59ed8163da9fcbd36;rport=5060
> To: <sip:01xxxxxxxx at DOMAIN;user=phone>;tag=54596251-54ef38c32e9e55a9-gm-po-lucentPCSF-035501
> From: <sip:USERID@DOMAIN;user=phone>;tag=1162169bb9034eac9d245678948fabfc
> CSeq: 27952 INVITE
> Require: 100rel
> Allow: INVITE,BYE,REGISTER,ACK,OPTIONS,CANCEL,SUBSCRIBE,NOTIFY,PRACK,INFO,REFER,UPDATE
> Contact: <sip:lucentNGFS-007410 at pcgw-0005.imsgroup0-000.xxx.xxx.org:5060;encoded-parm=QbkRBthOEgsTXgkTBA0HHiUrKz1CQEFFR0VFNgQMGAlsMTcgK2ghOyAnOCs.ITogYX9jZmR4NjsxblJGQAQEGF5VSh5dSBNMDQERXFJYX1o_>
> Content-Type: application/sdp
> RSeq: 1
> Server: Alcatel-Lucent-HPSS/3.0.3
> Content-Length: 247
>
> v=0
> o=LucentPCSF 600759623 600759623 IN IP4 imsgroup0-000.xxx.xxx.org
> s=-
> c=IN IP4 X.X.X.X
> t=0 0
> m=audio 37794 RTP/AVP 8 101
> a=rtpmap:101 telephone-event/8000
> a=sendrecv
> a=ptime:20
> a=maxptime:30
> a=silenceSupp:off - - - -
>
> --end msg--
> 16:18:10.907    tsx003FB084  .Incoming Response msg 183/INVITE/cseq=27952 (rdata003A6214) in state Proceeding
> 16:18:10.907    tsx003FB084  ..State changed from Proceeding to Proceeding, event=RX_MSG
> 16:18:10.907    dlg003F40FC  ...UA layer acquiring dialog lock for response
> 16:18:10.907    dlg003F40FC  ...Received Response msg 183/INVITE/cseq=27952 (rdata003A6214)
> 16:18:10.907    dlg003F40FC  ...Transaction tsx003FB084 state changed to Proceeding
> 16:18:10.907    pjsua_app.c  .....Call 0 state changed to EARLY (183 Session Progress)
> 16:18:10.907    inv003F40FC  ....SDP negotiation done, message body is ignored
> 16:18:10.978   strm00405D94  VAD re-enabled
> 16:18:10.978   strm00405D94  Starting silence
> 16:18:11.085   strm00405D94  RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=0
> 16:18:11.098   strm00405D94  Jitter buffer starts returning normal frames (after 37 empty/lost)
> 16:18:11.875    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 2 to OUTBOUNDPROXY_IP:5060
> 16:18:11.875   tdta00409890  Destroying txdata raw
> 16:18:11.875 sip_endpoint.c  pjsip_endpt_schedule_timer(entry=013DA2B4, delay=15.0)
> 16:18:12.007 sip_endpoint.c  Processing incoming message: Response msg 183/INVITE/cseq=27952 (rdata003A6214)
> 16:18:12.007   pjsua_core.c  .RX 1097 bytes Response msg 183/INVITE/cseq=27952 (rdata003A6214) from UDP OUTBOUNDPROXY_IP:5060:
> SIP/2.0 183 Session Progress
> Call-ID: b072b55fa1f14d3bb25591d61f3c73bc
> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPj4cff374a64f44dd59ed8163da9fcbd36;rport=5060
> To: <sip:01xxxxxxxx at DOMAIN;user=phone>;tag=54596251-54ef38c32e9e55a9-gm-po-lucentPCSF-035501
> From: <sip:USERID@DOMAIN;user=phone>;tag=1162169bb9034eac9d245678948fabfc
> CSeq: 27952 INVITE
> Require: 100rel
> Allow: INVITE,BYE,REGISTER,ACK,OPTIONS,CANCEL,SUBSCRIBE,NOTIFY,PRACK,INFO,REFER,UPDATE
> Contact: <sip:lucentNGFS-007410 at pcgw-0005.imsgroup0-000.xxx.xxx.org:5060;encoded-parm=QbkRBthOEgsTXgkTBA0HHiUrKz1CQEFFR0VFNgQMGAlsMTcgK2ghOyAnOCs.ITogYX9jZmR4NjsxblJGQAQEGF5VSh5dSBNMDQERXFJYX1o_>
> Content-Type: application/sdp
> RSeq: 1
> Server: Alcatel-Lucent-HPSS/3.0.3
> Content-Length: 247
>
> v=0
> o=LucentPCSF 600759623 600759623 IN IP4 imsgroup0-000.xxx.xxx.org
> s=-
> c=IN IP4 X.X.X.X
> t=0 0
> m=audio 37794 RTP/AVP 8 101
> a=rtpmap:101 telephone-event/8000
> a=sendrecv
> a=ptime:20
> a=maxptime:30
> a=silenceSupp:off - - - -
>
> --end msg--
> 16:18:12.007    tsx003FB084  .Incoming Response msg 183/INVITE/cseq=27952 (rdata003A6214) in state Proceeding
> 16:18:12.007    tsx003FB084  ..State changed from Proceeding to Proceeding, event=RX_MSG
> 16:18:12.007    dlg003F40FC  ...UA layer acquiring dialog lock for response
> 16:18:12.007    dlg003F40FC  ...Received Response msg 183/INVITE/cseq=27952 (rdata003A6214)
> 16:18:12.007    dlg003F40FC  ...Transaction tsx003FB084 state changed to Proceeding
> 16:18:12.007    pjsua_app.c  .....Call 0 state changed to EARLY (183 Session Progress)
> 16:18:12.007    inv003F40FC  ....SDP negotiation done, message body is ignored
> 16:18:12.418   strm00405D94  Start talksprut..
> 16:18:12.438   strm00405D94  Starting silence
> 16:18:14.106 sip_endpoint.c  Processing incoming message: Response msg 183/INVITE/cseq=27952 (rdata003A6214)
> 16:18:14.106   pjsua_core.c  .RX 1097 bytes Response msg 183/INVITE/cseq=27952 (rdata003A6214) from UDP OUTBOUNDPROXY_IP:5060:
> SIP/2.0 183 Session Progress
> Call-ID: b072b55fa1f14d3bb25591d61f3c73bc
> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPj4cff374a64f44dd59ed8163da9fcbd36;rport=5060
> To: <sip:01xxxxxxxx at DOMAIN;user=phone>;tag=54596251-54ef38c32e9e55a9-gm-po-lucentPCSF-035501
> From: <sip:USERID@DOMAIN;user=phone>;tag=1162169bb9034eac9d245678948fabfc
> CSeq: 27952 INVITE
> Require: 100rel
> Allow: INVITE,BYE,REGISTER,ACK,OPTIONS,CANCEL,SUBSCRIBE,NOTIFY,PRACK,INFO,REFER,UPDATE
> Contact: <sip:lucentNGFS-007410 at pcgw-0005.imsgroup0-000.xxx.xxx.org:5060;encoded-parm=QbkRBthOEgsTXgkTBA0HHiUrKz1CQEFFR0VFNgQMGAlsMTcgK2ghOyAnOCs.ITogYX9jZmR4NjsxblJGQAQEGF5VSh5dSBNMDQERXFJYX1o_>
> Content-Type: application/sdp
> RSeq: 1
> Server: Alcatel-Lucent-HPSS/3.0.3
> Content-Length: 247
>
> v=0
> o=LucentPCSF 600759623 600759623 IN IP4 imsgroup0-000.xxx.xxx.org
> s=-
> c=IN IP4 X.X.X.X
> t=0 0
> m=audio 37794 RTP/AVP 8 101
> a=rtpmap:101 telephone-event/8000
> a=sendrecv
> a=ptime:20
> a=maxptime:30
> a=silenceSupp:off - - - -
>
> --end msg--
> 16:18:14.106    tsx003FB084  .Incoming Response msg 183/INVITE/cseq=27952 (rdata003A6214) in state Proceeding
> 16:18:14.106    tsx003FB084  ..State changed from Proceeding to Proceeding, event=RX_MSG
> 16:18:14.106    dlg003F40FC  ...UA layer acquiring dialog lock for response
> 16:18:14.106    dlg003F40FC  ...Received Response msg 183/INVITE/cseq=27952 (rdata003A6214)
> 16:18:14.107    dlg003F40FC  ...Transaction tsx003FB084 state changed to Proceeding
> 16:18:14.107    pjsua_app.c  .....Call 0 state changed to EARLY (183 Session Progress)
> 16:18:14.107    inv003F40FC  ....SDP negotiation done, message body is ignored
> 16:18:14.958   silencedet.c  Re-adjust threshold (in silence)to 0
> 16:18:17.419   strm00405D94  Start talksprut..
> 16:18:17.439   strm00405D94  Starting silence
> 16:18:18.208 sip_endpoint.c  Processing incoming message: Response msg 183/INVITE/cseq=27952 (rdata003A6214)
> 16:18:18.208   pjsua_core.c  .RX 1097 bytes Response msg 183/INVITE/cseq=27952 (rdata003A6214) from UDP OUTBOUNDPROXY_IP:5060:
> SIP/2.0 183 Session Progress
> Call-ID: b072b55fa1f14d3bb25591d61f3c73bc
> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPj4cff374a64f44dd59ed8163da9fcbd36;rport=5060
> To: <sip:01xxxxxxxx at DOMAIN;user=phone>;tag=54596251-54ef38c32e9e55a9-gm-po-lucentPCSF-035501
> From: <sip:USERID@DOMAIN;user=phone>;tag=1162169bb9034eac9d245678948fabfc
> CSeq: 27952 INVITE
> Require: 100rel
> Allow: INVITE,BYE,REGISTER,ACK,OPTIONS,CANCEL,SUBSCRIBE,NOTIFY,PRACK,INFO,REFER,UPDATE
> Contact: <sip:lucentNGFS-007410 at pcgw-0005.imsgroup0-000.xxx.xxx.org:5060;encoded-parm=QbkRBthOEgsTXgkTBA0HHiUrKz1CQEFFR0VFNgQMGAlsMTcgK2ghOyAnOCs.ITogYX9jZmR4NjsxblJGQAQEGF5VSh5dSBNMDQERXFJYX1o_>
> Content-Type: application/sdp
> RSeq: 1
> Server: Alcatel-Lucent-HPSS/3.0.3
> Content-Length: 247
>
> v=0
> o=LucentPCSF 600759623 600759623 IN IP4 imsgroup0-000.xxx.xxx.org
> s=-
> c=IN IP4 X.X.X.X
> t=0 0
> m=audio 37794 RTP/AVP 8 101
> a=rtpmap:101 telephone-event/8000
> a=sendrecv
> a=ptime:20
> a=maxptime:30
> a=silenceSupp:off - - - -
>
> --end msg--
> 16:18:18.208    tsx003FB084  .Incoming Response msg 183/INVITE/cseq=27952 (rdata003A6214) in state Proceeding
> 16:18:18.208    tsx003FB084  ..State changed from Proceeding to Proceeding, event=RX_MSG
> 16:18:18.208    dlg003F40FC  ...UA layer acquiring dialog lock for response
> 16:18:18.208    dlg003F40FC  ...Received Response msg 183/INVITE/cseq=27952 (rdata003A6214)
> 16:18:18.208    dlg003F40FC  ...Transaction tsx003FB084 state changed to Proceeding
> 16:18:18.208    pjsua_app.c  .....Call 0 state changed to EARLY (183 Session Progress)
> 16:18:18.208    inv003F40FC  ....SDP negotiation done, message body is ignored
> 16:18:18.969   silencedet.c  Re-adjust threshold (in silence)to 0
> 16:18:22.428   strm00405D94  Start talksprut..
> 16:18:22.448   strm00405D94  Starting silence
> 16:18:22.968   silencedet.c  Re-adjust threshold (in silence)to 0
> 16:18:24.646   pjsua_call.c !Call 0 hanging up: code=0..
> 16:18:24.647       endpoint  ..Request msg CANCEL/cseq=27952 (tdta00409890) created.
> 16:18:24.647    inv003F40FC  ..Sending Request msg CANCEL/cseq=27952 (tdta00409890)
> 16:18:24.647    dlg003F40FC  ...Sending Request msg CANCEL/cseq=27952 (tdta00409890)
> 16:18:24.647    tsx0040A8FC  ...tsx_key=c$CANCEL$z9hG4bKPj4cff374a64f44dd59ed8163da9fcbd36
> 16:18:24.647    tsx0040A8FC  ....Transaction created for Request msg CANCEL/cseq=27952 (tdta00409890)
> 16:18:24.647    tsx0040A8FC  ...Sending Request msg CANCEL/cseq=27952 (tdta00409890) in state Null
> 16:18:24.647       endpoint  ....Request msg CANCEL/cseq=27952 (tdta00409890): skipping target resolution because address is already set
> 16:18:24.647   pjsua_core.c  ....TX 500 bytes Request msg CANCEL/cseq=27952 (tdta00409890) to UDP OUTBOUNDPROXY_IP:5060:
> CANCEL sip:01xxxxxxxx at DOMAIN SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.25:5060;rport;branch=z9hG4bKPj4cff374a64f44dd59ed8163da9fcbd36
> Max-Forwards: 70
> From: sip:USERID@DOMAIN;tag=1162169bb9034eac9d245678948fabfc
> To: sip:01xxxxxxxx at DOMAIN
> Call-ID: b072b55fa1f14d3bb25591d61f3c73bc
> CSeq: 27952 CANCEL
> Route: <sip:OUTBOUNDPROXY_NAME:5060;lr>
> User-Agent: PJSUA v2.3 win32-6.1/i386/msvc-18.0
> Content-Length:  0
>
>
> --end msg--
> 16:18:24.647    tsx0040A8FC  ....State changed from Null to Calling, event=TX_MSG
> 16:18:24.647    dlg003F40FC  .....Transaction tsx0040A8FC state changed to Calling
> 16:18:24.692 sip_endpoint.c  Processing incoming message: Response msg 200/CANCEL/cseq=27952 (rdata003A6214)
> 16:18:24.692   pjsua_core.c  .RX 493 bytes Response msg 200/CANCEL/cseq=27952 (rdata003A6214) from UDP OUTBOUNDPROXY_IP:5060:
> SIP/2.0 200 OK
> Call-ID: b072b55fa1f14d3bb25591d61f3c73bc
> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPj4cff374a64f44dd59ed8163da9fcbd36;rport=5060
> To: sip:01xxxxxxxx at DOMAIN;tag=54596251-54ef38c32e9e55a9-gm-po-lucentPCSF-035501
> From: sip:USERID@DOMAIN;tag=1162169bb9034eac9d245678948fabfc
> CSeq: 27952 CANCEL
> Date: Thu, 26 Feb 2015 15:16:37 GMT
> Server: Alcatel-Lucent-HPSS/3.0.3
> Content-Length: 0
>
>
> --end msg--
> 16:18:24.692    tsx0040A8FC  .Incoming Response msg 200/CANCEL/cseq=27952 (rdata003A6214) in state Calling
> 16:18:24.692    tsx0040A8FC  ..State changed from Calling to Completed, event=RX_MSG
> 16:18:24.692    dlg003F40FC  ...UA layer acquiring dialog lock for response
> 16:18:24.692    dlg003F40FC  ...Received Response msg 200/CANCEL/cseq=27952 (rdata003A6214)
> 16:18:24.692    dlg003F40FC  ...Transaction tsx0040A8FC state changed to Completed
> 16:18:24.692 sip_endpoint.c  Processing incoming message: Response msg 487/INVITE/cseq=27952 (rdata003A6214)
> 16:18:24.692   pjsua_core.c  .RX 535 bytes Response msg 487/INVITE/cseq=27952 (rdata003A6214) from UDP OUTBOUNDPROXY_IP:5060:
> SIP/2.0 487 Request Terminated
> Call-ID: b072b55fa1f14d3bb25591d61f3c73bc
> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPj4cff374a64f44dd59ed8163da9fcbd36;rport=5060
> To: <sip:01xxxxxxxx at DOMAIN;user=phone>;tag=54596251-54ef38c32e9e55a9-gm-po-lucentPCSF-035501
> From: <sip:USERID@DOMAIN;user=phone>;tag=1162169bb9034eac9d245678948fabfc
> CSeq: 27952 INVITE
> Date: Thu, 26 Feb 2015 15:16:37 GMT
> Server: Alcatel-Lucent-HPSS/3.0.3
> Content-Length: 0
>
>
> --end msg--
> 16:18:24.692    tsx003FB084  .Incoming Response msg 487/INVITE/cseq=27952 (rdata003A6214) in state Proceeding
> 16:18:24.692       endpoint  ..Request msg ACK/cseq=27952 (tdta0040E5C8) created.
> 16:18:24.693   pjsua_core.c  ..TX 499 bytes Request msg ACK/cseq=27952 (tdta0040E5C8) to UDP OUTBOUNDPROXY_IP:5060:
> ACK sip:01xxxxxxxx at DOMAIN SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.25:5060;rport;branch=z9hG4bKPj4cff374a64f44dd59ed8163da9fcbd36
> Max-Forwards: 70
> From: sip:USERID@DOMAIN;tag=1162169bb9034eac9d245678948fabfc
> To: sip:01xxxxxxxx at DOMAIN;tag=54596251-54ef38c32e9e55a9-gm-po-lucentPCSF-035501
> Call-ID: b072b55fa1f14d3bb25591d61f3c73bc
> CSeq: 27952 ACK
> Route: <sip:OUTBOUNDPROXY_NAME:5060;lr>
> Content-Length:  0
>
>
> --end msg--
> 16:18:24.693    tsx003FB084  ..State changed from Proceeding to Completed, event=RX_MSG
> 16:18:24.693    dlg003F40FC  ...UA layer acquiring dialog lock for response
> 16:18:24.693    dlg003F40FC  ...Received Response msg 487/INVITE/cseq=27952 (rdata003A6214)
> 16:18:24.693    dlg003F40FC  ...Transaction tsx003FB084 state changed to Completed
> 16:18:24.693    pjsua_app.c  .....Call 0 is DISCONNECTED [reason=487 (Request Terminated)]
> 16:18:24.693    pjsua_app.c  .....Call 0 disconnected, dumping media stats..
> 16:18:24.693 pjsua_app_comm  .....
> [DISCONNCTD] To: sip:01xxxxxxxx at DOMAIN;tag=54596251-54ef38c32e9e55a9-gm-po-lucentPCSF-035501
> Call time: 00h:00m:00s, 1st res in 2949 ms, conn in 0ms
> #0 audio PCMA @8kHz, sendrecv, peer=X.X.X.X:37794
> SRTP status: Not active Crypto-suite:
> RX pt=8, last update:00h:00m:04.245s ago
> total 682pkt 108.8KB (136.1KB +IP hdr) @avg=60.6Kbps/75.8Kbps
> pkt loss=0 (0.0%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%)
> (msec)    min     avg     max     last    dev
> loss period:   0.000   0.000   0.000   0.000   0.000
> jitter     :   0.000   0.224   1.250   0.250   0.133
> TX pt=8, ptime=20, last update:00h:00m:04.428s ago
> total 34pkt 5.4KB (6.8KB +IP hdr) @avg=3.0Kbps/3.7Kbps
> pkt loss=0 (0.0%), dup=0 (0.0%), reorder=0 (0.0%)
> (msec)    min     avg     max     last    dev
> loss period:   0.000   0.000   0.000   0.000   0.000
> jitter     : 107.250 260.125 413.000 413.000  56.755
> RTT msec      : 168.000 177.000 186.000 186.000   9.000
> 16:18:24.693  pjsua_media.c  .....Call 0: deinitializing media..
> 16:18:24.693 sip_endpoint.c  .......pjsip_endpt_schedule_timer(entry=014237B0, delay=1.0)
> 16:18:24.694    mtx004067B4  .......Mutex destroyed
> 16:18:24.694   strm00405D94  .......JB summary:
> size=1/eff=1 prefetch=0 level=2
> delay (min/max/avg/dev)=20/40/29/6 ms
> burst (min/max/avg/dev)=1/4/2/0 frames
> lost=0 discard=0 empty=37
> 16:18:24.694  pjsua_media.c  .......Media stream call00:0 is destroyed
> 16:18:24.694   srtp003F70A8  ......Mutex destroyed
> 16:18:24.694    dlg003F40FC  .....Session count dec to 1 by mod-invite
> 16:18:24.694   tdta003F9070  ..Destroying txdata Request msg INVITE/cseq=27952 (tdta003F9070)
> 16:18:25.694    pjsua_aud.c  Closing sound device after idle for 1 second(s)
> 16:18:25.694    pjsua_app.c  .Turning sound device OFF
> 16:18:25.694    pjsua_aud.c  .Closing Wave mapper sound playback device and Wave mapper sound capture device
> 16:18:25.696     wmme_dev.c  .Stopped WMME playback stream
> 16:18:25.697     wmme_dev.c  .Stopped WMME capture stream
> 16:18:25.697     wmme_dev.c  .Stopped WMME playback stream
> 16:18:25.697     wmme_dev.c  .Stopped WMME capture stream
> 16:18:25.697          pjsua  .Joining thread wmme
> 16:18:25.697     wmme_dev.c !WMME: thread stopping..
> 16:18:25.697           wmme  Thread quitting
> 16:18:25.697           wmme  Thread stack max usage=4837 by ..\src\pj\string.c:226
> 16:18:26.876    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 2 to OUTBOUNDPROXY_IP:5060
> 16:18:26.876   tdta003AE538  Destroying txdata raw
> 16:18:26.876 sip_endpoint.c  pjsip_endpt_schedule_timer(entry=013DA2B4, delay=15.0)
> 16:18:29.692    tsx0040A8FC  Timeout timer event
> 16:18:29.692    tsx0040A8FC  .State changed from Completed to Terminated, event=TIMER
> 16:18:29.692    dlg003F40FC  ..Transaction tsx0040A8FC state changed to Terminated
> 16:18:29.692    tsx0040A8FC  Timeout timer event
> 16:18:29.692    tsx0040A8FC  .State changed from Terminated to Destroyed, event=TIMER
> 16:18:29.692   tdta00409890  ..Destroying txdata Request msg CANCEL/cseq=27952 (tdta00409890)
> 16:18:29.692    tsx0040A8FC  Transaction destroyed!
> 16:18:31.257   pjsua_core.c  Shutting down, flags=0...
> 16:18:31.257   pjsua_core.c  PJSUA state changed: RUNNING --> CLOSING
> 16:18:31.257    thr00002704  Joining thread pjsua
> 16:18:31.262          pjsua !Thread quitting
> 16:18:31.262          pjsua  Thread stack max usage=8473 by ..\src\pj\string.c:226
> 16:18:31.262   pjsua_call.c !.Hangup all calls..
> 16:18:31.262  pjsua_media.c  .Call 0: deinitializing media..
> 16:18:31.262  pjsua_media.c  .Call 1: deinitializing media..
> 16:18:31.262  pjsua_media.c  .Call 2: deinitializing media..
> 16:18:31.262  pjsua_media.c  .Call 3: deinitializing media..
> 16:18:31.262   pjsua_pres.c  .Shutting down presence..
> 16:18:31.262 sip_endpoint.c  ..pjsip_endpt_cancel_timer(entry=01423638)
> 16:18:31.262    pjsua_acc.c  .Acc 2: setting unregistration..
> 16:18:31.262 sip_endpoint.c  ..pjsip_endpt_cancel_timer(entry=003AC76C)
> 16:18:31.262       endpoint  ..Request msg REGISTER/cseq=28618 (tdta003AE538) created.
> 16:18:31.262    tsx0037CF24  ..tsx_key=c$REGISTER$z9hG4bKPjc97ba121b18c4073b6de2550e6d4d33d
> 16:18:31.262    tsx0037CF24  ...Transaction created for Request msg REGISTER/cseq=28619 (tdta003AE538)
> 16:18:31.262    tsx0037CF24  ..Sending Request msg REGISTER/cseq=28619 (tdta003AE538) in state Null
> 16:18:31.262  sip_resolve.c  ...DNS resolver not available, target 'OUTBOUNDPROXY_NAME:5060' type=Unspecified will be resolved with getaddrinfo()
> 16:18:31.263  sip_resolve.c  ...Target 'OUTBOUNDPROXY_NAME:5060' type=Unspecified resolved to 'OUTBOUNDPROXY_IP:5060' type=UDP (UDP transport)
> 16:18:31.263   pjsua_core.c  ...TX 561 bytes Request msg REGISTER/cseq=28619 (tdta003AE538) to UDP OUTBOUNDPROXY_IP:5060:
> REGISTER sip:DOMAIN SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.25:5060;rport;branch=z9hG4bKPjc97ba121b18c4073b6de2550e6d4d33d
> Route: <sip:OUTBOUNDPROXY_NAME:5060;lr>
> Max-Forwards: 70
> From: <sip:USERID@DOMAIN>;tag=e259de5bf7f2420f820f1213d293856b
> To: <sip:USERID at DOMAIN>
> Call-ID: 9a4de08282c5425f87ad8241a66aad68
> CSeq: 28619 REGISTER
> User-Agent: PJSUA v2.3 win32-6.1/i386/msvc-18.0
> Contact: <sip:USERID at 192.168.1.25:5060;ob>
> Expires: 0
> Content-Length:  0
>
>
> --end msg--
> 16:18:31.263    tsx0037CF24  ...State changed from Null to Calling, event=TX_MSG
> 16:18:31.263    pjsua_acc.c  ..Acc 2: Unregistration sent
> 16:18:31.372 sip_endpoint.c  .Processing incoming message: Response msg 401/REGISTER/cseq=28619 (rdata003A6214)
> 16:18:31.372   pjsua_core.c  ..RX 716 bytes Response msg 401/REGISTER/cseq=28619 (rdata003A6214) from UDP OUTBOUNDPROXY_IP:5060:
> SIP/2.0 401 Unauthorized
> Call-ID: 9a4de08282c5425f87ad8241a66aad68
> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPjc97ba121b18c4073b6de2550e6d4d33d;rport=5060
> To: <sip:USERID at DOMAIN>;tag=54596245-54ef38db29f74c9b
> From: <sip:USERID@DOMAIN>;tag=e259de5bf7f2420f820f1213d293856b
> CSeq: 28619 REGISTER
> Date: Thu, 26 Feb 2015 15:16:43 GMT
> Server: Alcatel-Lucent-HPSS/3.0.3
> WWW-Authenticate: Digest realm="REALM",
> nonce="xxx",
> opaque="ALU:xxx",
> algorithm=MD5,
> qop="auth"
> Content-Length: 0
>
>
> --end msg--
> 16:18:31.372    tsx0037CF24  ..Incoming Response msg 401/REGISTER/cseq=28619 (rdata003A6214) in state Calling
> 16:18:31.372    tsx0037CF24  ...State changed from Calling to Completed, event=RX_MSG
> 16:18:31.372   glck003A9FD8  ....Mutex created
> 16:18:31.372    tsx0041157C  ....Mutex created
> 16:18:31.372    tsx0041157C  ....tsx_key=c$REGISTER$z9hG4bKPj529256ca5b38499d8ab92a12f22e9d83
> 16:18:31.372    tsx0041157C  .....Transaction created for Request msg REGISTER/cseq=28620 (tdta003AE538)
> 16:18:31.372    tsx0041157C  ....Sending Request msg REGISTER/cseq=28620 (tdta003AE538) in state Null
> 16:18:31.372       endpoint  .....Request msg REGISTER/cseq=28620 (tdta003AE538): skipping target resolution because address is already set
> 16:18:31.372   pjsua_core.c  .....TX 956 bytes Request msg REGISTER/cseq=28620 (tdta003AE538) to UDP OUTBOUNDPROXY_IP:5060:
> REGISTER sip:DOMAIN SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.25:5060;rport;branch=z9hG4bKPj529256ca5b38499d8ab92a12f22e9d83
> Route: <sip:OUTBOUNDPROXY_NAME:5060;lr>
> Max-Forwards: 70
> From: <sip:USERID@DOMAIN>;tag=e259de5bf7f2420f820f1213d293856b
> To: <sip:USERID at DOMAIN>
> Call-ID: 9a4de08282c5425f87ad8241a66aad68
> CSeq: 28620 REGISTER
> User-Agent: PJSUA v2.3 win32-6.1/i386/msvc-18.0
> Contact: <sip:USERID at 192.168.1.25:5060;ob>
> Expires: 0
> Authorization: Digest username="AUTHNAME", realm="REALM", nonce="xxx", uri="sip:DOMAIN", response="xxx", algorithm=MD5, cnonce="xxx", opaque="ALU:xxx", qop=auth, nc=00000001
> Content-Length:  0
>
>
> --end msg--
> 16:18:31.373    tsx0041157C  .....State changed from Null to Calling, event=TX_MSG
> 16:18:31.447 sip_endpoint.c  .Processing incoming message: Response msg 200/REGISTER/cseq=28620 (rdata003F9084)
> 16:18:31.447   pjsua_core.c  ..RX 772 bytes Response msg 200/REGISTER/cseq=28620 (rdata003F9084) from UDP OUTBOUNDPROXY_IP:5060:
> SIP/2.0 200 OK
> Call-ID: 9a4de08282c5425f87ad8241a66aad68
> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPj529256ca5b38499d8ab92a12f22e9d83;rport=5060
> To: <sip:USERID at DOMAIN>;tag=54596245-54ef38db2e66fecc
> From: <sip:USERID@DOMAIN>;tag=e259de5bf7f2420f820f1213d293856b
> CSeq: 28620 REGISTER
> Contact: <sip:USERID at 192.168.1.25:5060;ob;transport=udp>;expires=0
> Date: Thu, 26 Feb 2015 15:16:43 GMT
> Path: <sip:pcgw-0005.imsgroup0-000.xxx.xxx.org:5060;lr;ottag=ue_term;bidx=6201093;access-type=ADSL>
> P-Associated-URI: <sip:USERID at DOMAIN>
> P-Associated-URI: <tel:USERID>
> Server: Alcatel-Lucent-HPSS/3.0.3
> Content-Length: 0
>
>
> --end msg--
> 16:18:31.447    tsx0041157C  ..Incoming Response msg 200/REGISTER/cseq=28620 (rdata003F9084) in state Calling
> 16:18:31.448    tsx0041157C  ...State changed from Calling to Completed, event=RX_MSG
> 16:18:31.448 sip_endpoint.c  .....pjsip_endpt_cancel_timer(entry=013DA2B4)
> 16:18:31.448    pjsua_acc.c  .....sip:USERID at DOMAIN: unregistration success
> 16:18:31.448   regc003AC548  ....Mutex destroyed
> 16:18:32.298   pjsua_core.c  .Destroying...
> 16:18:32.298  pjsua_media.c  .Shutting down media..
> 16:18:32.298    thr00002704  ..Joining thread media
> 16:18:32.694          media !Thread quitting
> 16:18:32.694          media  Thread stack max usage=6153 by ..\src\pj\string.c:226
> 16:18:32.695 sip_endpoint.c  .Destroying endpoing instance..
> 16:18:32.695 sip_transactio  .Stopping transaction layer module
> 16:18:32.695    tsx003FB084  .Request to terminate transaction
> 16:18:32.695    tsx003FB084  ..State changed from Completed to Terminated, event=USER
> 16:18:32.695    dlg003F40FC  ...Transaction tsx003FB084 state changed to Terminated
> 16:18:32.695    dlg003F40FC  ....Dialog destroyed
> 16:18:32.695    dlg003F40FC  ....Mutex destroyed
> 16:18:32.695   tdta0040E5C8  .Destroying txdata Request msg ACK/cseq=27952 (tdta0040E5C8)
> 16:18:32.695    tsx003FB084  .Transaction destroyed!
> 16:18:32.695    tsx0037CF24  .Request to terminate transaction
> 16:18:32.695    tsx0037CF24  ..State changed from Completed to Terminated, event=USER
> 16:18:32.695    tsx0037CF24  .Transaction destroyed!
> 16:18:32.695    tsx0041157C  .Request to terminate transaction
> 16:18:32.695    tsx0041157C  ..State changed from Completed to Terminated, event=USER
> 16:18:32.696   tdta003AE538  .Destroying txdata Request msg REGISTER/cseq=28620 (tdta003AE538)
> 16:18:32.696    tsx0041157C  .Transaction destroyed!
> 16:18:32.696 sip_transactio  .Stopped transaction layer module
> 16:18:32.696 sip_endpoint.c  .Module "mod-default-handler" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-unsolicited-mwi" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-pjsua-options" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-pjsua-im" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-pjsua-pres" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-pjsua" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-stateful-util" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-refer" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-mwi" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-presence" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-evsub" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-invite" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-100rel" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-ua" unregistered
> 16:18:32.696 sip_transactio  .Transaction layer module destroyed
> 16:18:32.696 sip_endpoint.c  .Module "mod-tsx-layer" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-msg-print" unregistered
> 16:18:32.696 sip_endpoint.c  .Module "mod-pjsua-log" unregistered
> 16:18:32.696 sip_transport.  .Destroying transport manager
> 16:18:32.697    tcplis:5060  .SIP TCP listener destroyed
> 16:18:32.697 sip_endpoint.c  .Endpoint 0036F554 destroyed
> 16:18:32.698   pjsua_core.c  .PJSUA state changed: CLOSING --> NULL
> 16:18:32.698   pjsua_core.c  .PJSUA destroyed...
>
>
> Thanks !
>
>
> Mathieu
>
>
>
>
>
>
> Sent: Thursday, February 26, 2015 at 4:45 PM
> From: "Bill Gardner" <billg@xxxxxxxxxxxx>
> To: pjsip at lists.pjsip.org
> Subject: Re: Strange behavior when making a call (format fix)
> Hi Mathieu,
>
> I'm really not a SIP expert, but my reading of this is that the bad
> contact address causes the PRACK to not be sent and the other endpoint
> keeps sending the 183 and finally gives up and sends a BYE. But the
> contact address looks OK. Can you do an nslookup of
> pcgw-0005.xxx.wiz.net and see if that works on your machine?
>
> Regards,
>
> Bill
>
> On 2/26/2015 9:59 AM, Mathieu Trinc wrote:
>> Hi Bill,
>>
>> The error occurs when PJSIP tries to resolve a hostname present in the Contact field of the first '183 Statut progress' message received:
>>
>> Contact: <sip:lucentNGFS-000116 at pcgw-0005.xxx.wiz.net:5060;encoded-parm=QbkRBthOEgsTXgkTBA0HHiUrKz1CQEFCQkVDNgQMGAlsMTcgK2ghOyAnOCs.ITogYX9jZmR4NjsxblJGQAQEGF5VSh5dSBNMDQERXFJYX1o_>
>>
>> Could this error explain why I keep receiving these messages?
>>
>> I set the log verbosity level to 6 but there is not much information (Is there a way to get more detailed information?):
>>
>> 09:46:21.703 pjsua_core.c !.pjsua version 2.3 for win32-6.1/i386/msvc-18.0 initialized
>> 09:46:21.711 main.c Ready: Success
>> 09:46:22.002 pjsua_acc.c !....sip:from at foo.org: registration success, status=200 (OK), will re-register in 300 seconds
>> 09:46:40.171 pjsua_app.c !..Turning sound device ON
>> 09:46:40.222 pjsua_app.c .......Call 0 state changed to CALLING
>> 09:46:42.919 pjsua_app.c !.....Call 0 state changed to EARLY (183 Session Progress)
>> 09:46:42.976 tsx005CBDEC ......Failed to send Request msg PRACK/cseq=18743 (tdta005CAD80)! err=70018 (gethostbyname() has returned error (PJ_ERESOLVE))
>> 09:46:43.494 pjsua_app.c .....Call 0 state changed to EARLY (183 Session Progress)
>> 09:46:44.593 pjsua_app.c .....Call 0 state changed to EARLY (183 Session Progress)
>> 09:46:46.694 pjsua_app.c .....Call 0 state changed to EARLY (183 Session Progress)
>> 09:46:50.795 pjsua_app.c .....Call 0 state changed to EARLY (183 Session Progress)
>> 09:46:53.696 pjsua_app.c .....Call 0 is DISCONNECTED [reason=487 (Request Terminated)]
>> 09:46:53.696 pjsua_app_comm .....
>> [DISCONNCTD] To: sip:to at foo.org;tag=54596251-54ef31642d05c34a-gm-po-lucentPCSF-152762
>> Call time: 00h:00m:00s, 1st res in 2701 ms, conn in 0ms
>> #0 audio PCMA @8kHz, sendrecv, peer=85.31.200.0:48546
>> SRTP status: Not active Crypto-suite:
>> RX pt=8, last update:00h:00m:00.684s ago
>> total 508pkt 80.0KB (100.4KB +IP hdr) @avg=59.4Kbps/74.5Kbps
>> pkt loss=1 (0.2%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%)
>> (msec) min avg max last dev
>> loss period: 20.000 20.000 20.000 20.000 0.000
>> jitter : 0.000 0.291 1.500 0.125 0.210
>> TX pt=8, ptime=20, last update:00h:00m:00.818s ago
>> total 33pkt 5.2KB (6.6KB +IP hdr) @avg=3.9Kbps/4.8Kbps
>> pkt loss=0 (0.0%), dup=0 (0.0%), reorder=0 (0.0%)
>> (msec) min avg max last dev
>> loss period: 0.000 0.000 0.000 0.000 0.000
>> jitter : 123.500 275.938 428.375 428.375 56.755
>> RTT msec : 154.000 165.500 177.000 177.000 11.500
>> 09:46:54.696 pjsua_app.c .Turning sound device OFF
>> 09:46:57.188 pjsua_acc.c !.....sip:from at foo.org: unregistration success
>>
>>
>> Thanks !
>>
>>
>> Mathieu
>>
>>
>>
>> Sent: Thursday, February 26, 2015 at 2:45 PM
>> From: "Bill Gardner" <billg@xxxxxxxxxxxx>
>> To: pjsip at lists.pjsip.org
>> Subject: Re: Strange behavior when making a call (format fix)
>> Hi Mathieu,
>>
>> I think you should track down the source of the PJ_ERESOLVE error. Can
>> you send a complete log?
>>
>> Regards,
>>
>> Bill
>>
>> On 2/26/2015 6:29 AM, Mathieu Trinc wrote:
>>> (Sorry for the previous email which was in HTML format)
>>>
>>> Hello everyone,
>>>
>>> I'm trying to use pjsua to make a call. The registration process works fine but when I make a call I notice a strange behavior: the INVITE message is sent, I receive a "Status: 100 Trying" message
>>> and then I keep receiving "Status: 183 Session Progress" messages until the recipient answers. The communication is then established but I think some SIP messages are missing (for instance there is no 200 OK message)
>>> and this leads to an incorrect state (I do not know when the call is established, how long it lasts, etc.).
>>>
>>> (I tried to make the same call with a different softphone (XLite) and I get a different behavior:
>>> INVITE - 100 Trying - 183 Session Progress - 180 Ringing. And when the recipient answers I get 200 OK)
>>>
>>> Any help to understand what is going on and how to get the standard behavior would be greatly appreciated.
>>>
>>> Here is the log displayed in pjsua and the details of some SIP messages (slightly modified for privacy concerns):
>>>
>>> 02:31:35.649 pjsua_app.c !..Turning sound device ON
>>> 02:31:35.699 pjsua_app.c .......Call 0 state changed to CALLING
>>> 02:31:39.446 pjsua_app.c !.....Call 0 state changed to EARLY (183 Session Progress)
>>> 02:31:39.448 tsx0060CD0C ......Failed to send Request msg PRACK/cseq=17029 (tdta0060BCA0)! err=70018 (gethostbyname() has returned error (PJ_ERESOLVE))
>>> 02:31:39.981 pjsua_app.c .....Call 0 state changed to EARLY (183 Session Progress)
>>> 02:31:41.081 pjsua_app.c .....Call 0 state changed to EARLY (183 Session Progress)
>>> 02:31:43.181 pjsua_app.c .....Call 0 state changed to EARLY (183 Session Progress)
>>> 02:31:47.280 pjsua_app.c .....Call 0 state changed to EARLY (183 Session Progress)
>>>
>>> // The recipient answers and we can communicate
>>>
>>> // I decide to hang up (if it is the recipient that hangs up I get this after a few seconds: Call 0 is DISCONNECTED [reason=500 (Server Inernal Error)])
>>> h
>>>
>>> 02:31:54.231 pjsua_app.c .....Call 0 is DISCONNECTED [reason=487 (Request Terminated)]
>>> 02:31:54.232 pjsua_app_comm .....
>>> [DISCONNCTD] To: sip:to at foo.org;tag=54596251
>>> -54ee770c1f6962c8-gm-po-lucentPCSF-055498
>>> Call time: 00h:00m:00s, 1st res in 3750 ms, conn in 0ms
>>> #0 audio PCMA @8kHz, sendrecv, peer=85.31.200.0:47386
>>> SRTP status: Not active Crypto-suite:
>>> RX pt=8, last update:00h:00m:04.702s ago
>>> total 706pkt 112.6KB (140.8KB +IP hdr) @avg=60.9Kbps/76.2Kbps
>>> pkt loss=0 (0.0%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%)
>>> (msec) min avg max last dev
>>> loss period: 0.000 0.000 0.000 0.000 0.000
>>> jitter : 0.000 0.206 1.250 0.250 0.137
>>> TX pt=8, ptime=20, last update:00h:00m:04.838s ago
>>> total 34pkt 5.4KB (6.8KB +IP hdr) @avg=2.9Kbps/3.6Kbps
>>> pkt loss=0 (0.0%), dup=0 (0.0%), reorder=0 (0.0%)
>>> (msec) min avg max last dev
>>> loss period: 0.000 0.000 0.000 0.000 0.000
>>> jitter : 82.000 225.063 368.125 368.125 56.755
>>> RTT msec : 175.000 233.500 292.000 175.000 56.755
>>> 02:31:55.237 pjsua_app.c .Turning sound device OFF
>>>
>>> INVITE sip:to at foo.org SIP/2.0
>>> Via: SIP/2.0/UDP 192.168.1.25:5060;rport;branch=z9hG4bKPja40ebf7032174a939b836f6a4030dfd9
>>> Max-Forwards: 70
>>> From: sip:from@xxxxxxx;tag=bc2c850cf705496cabe58b4a071794fb
>>> To: sip:to at foo.org
>>> Contact: <sip:from at 192.168.1.25:5060;ob>
>>> Call-ID: 635050fa9ef7442990b7809c34a2328b
>>> CSeq: 17028 INVITE
>>> Route: <sip:p-cscf.wiz.net:5060;lr>
>>> Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
>>> Supported: replaces, 100rel, timer, norefersub
>>> Session-Expires: 1800
>>> Min-SE: 90
>>> User-Agent: PJSUA v2.3 win32-6.1/i386/msvc-18.0
>>> Content-Type: application/sdp
>>> Content-Length: 473
>>> v=0
>>> o=- 3633906695 3633906695 IN IP4 192.168.1.25
>>> s=pjmedia
>>> b=AS:84
>>> t=0 0
>>> a=X-nat:0
>>> m=audio 4000 RTP/AVP 98 97 99 104 3 0 8 9 96
>>> c=IN IP4 192.168.1.25
>>> b=TIAS:64000
>>> a=rtcp:4001 IN IP4 192.168.1.25
>>> a=sendrecv
>>> a=rtpmap:98 speex/16000
>>> a=rtpmap:97 speex/8000
>>> a=rtpmap:99 speex/32000
>>> a=rtpmap:104 iLBC/8000
>>> a=fmtp:104 mode=30
>>> a=rtpmap:3 GSM/8000
>>> a=rtpmap:0 PCMU/8000
>>> a=rtpmap:8 PCMA/8000
>>> a=rtpmap:9 G722/8000
>>> a=rtpmap:96 telephone-event/8000
>>> a=fmtp:96 0-16
>>>
>>> SIP/2.0 100 Trying
>>> Call-ID: 635050fa9ef7442990b7809c34a2328b
>>> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPja40ebf7032174a939b836f6a4030dfd9;rport=5060
>>> To: <sip:to at foo.org;user=phone>
>>> From: <sip:from@xxxxxxx;user=phone>;tag=bc2c850cf705496cabe58b4a071794fb
>>> CSeq: 17028 INVITE
>>> Date: Thu, 26 Feb 2015 01:29:48 GMT
>>> Server: Alcatel-Lucent-HPSS/3.0.3
>>> Content-Length: 0
>>>
>>> SIP/2.0 183 Session Progress
>>> Call-ID: 635050fa9ef7442990b7809c34a2328b
>>> Via: SIP/2.0/UDP 192.168.1.25:5060;received=192.168.1.25;branch=z9hG4bKPja40ebf7032174a939b836f6a4030dfd9;rport=5060
>>> To: <sip:to at foo.org;user=phone>;tag=54596251-54ee770c1f6962c8-gm-po-lucentPCSF-055498
>>> From: <sip:from@xxxxxxx;user=phone>;tag=bc2c850cf705496cabe58b4a071794fb
>>> CSeq: 17028 INVITE
>>> Require: 100rel
>>> Allow: INVITE,BYE,REGISTER,ACK,OPTIONS,CANCEL,SUBSCRIBE,NOTIFY,PRACK,INFO,REFER,UPDATE
>>> Contact: <sip:lucentNGFS-000116 at pcgw-0005.xxx.wiz.net:5060;encoded-parm=QbkRBthOEgsTXgkTBA0HHiUrKz1CQEFCQkVDNgQMGAlsMTcgK2ghOyAnOCs.ITogYX9jZmR4NjsxblJGQAQEGF5VSh5dSBNMDQERXFJYX1o_>
>>> Content-Type: application/sdp
>>> RSeq: 1
>>> Server: Alcatel-Lucent-HPSS/3.0.3
>>> Content-Length: 220
>>> v=0
>>> o=LucentPCSF 113972553 113972553 IN IP4 .wiz.net
>>> s=-
>>> c=IN IP4 85.31.200.0
>>> t=0 0
>>> m=audio 47386 RTP/AVP 8 101
>>> a=rtpmap:101 telephone-event/8000
>>> a=sendrecv
>>> a=ptime:20
>>> a=maxptime:30
>>>
>>> Thank you !
>>>
>>> Mathieu
>>>
>>> _______________________________________________
>>> 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[http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org][http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org[http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org]]
>> _______________________________________________
>> Visit our blog: http://blog.pjsip.org[http://blog.pjsip.org][http://blog.pjsip.org[http://blog.pjsip.org]]
>>
>> pjsip mailing list
>> pjsip at lists.pjsip.org
>> http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org[http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org][http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org[http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org]]
>>
>> _______________________________________________
>> Visit our blog: http://blog.pjsip.org[http://blog.pjsip.org]
>>
>> pjsip mailing list
>> pjsip at lists.pjsip.org
>> http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org[http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org]
>
> _______________________________________________
> Visit our blog: http://blog.pjsip.org[http://blog.pjsip.org]
>
> pjsip mailing list
> pjsip at lists.pjsip.org
> http://lists.pjsip.org/mailman/listinfo/pjsip_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




[Index of Archives]     [Asterisk Users]     [Asterisk App Development]     [Linux ARM Kernel]     [Linux ARM]     [Linux Omap]     [Fedora ARM]     [IETF Annouce]     [Security]     [Bugtraq]     [Linux]     [Linux OMAP]     [Linux MIPS]     [Linux API]
  Powered by Linux