getting Underflow, buf_cnt=0, will generate 1 frame continuessly

[itssuresh79@xxxxxxxxx (suresh jaiswal)]

Hi ALL i'm new in PJSIP 
Sudenlly i'm getting strange problem with PJSUA to PJSUA call.. 
when i calling PJSUA to PJSUA (between three PJSUA clent using OPENIMS ) multiple times 
say 5-6 times after successfull tear down call we getting callee side PJSIU hang getting 
Underflow, buf_cnt=0, will generate 1 frame continuessly
?
i'm also attching log file alson this mail
can any tell me what is mean by VAD its seems to be problem is related to 
VAD not able to re-enalbe
?
?
?18:05:34.501 sip_endpoint.c Module "mod-pjsua-log" registered
18:05:34.517 sip_endpoint.c Module "mod-tsx-layer" registered
18:05:34.517 sip_endpoint.c Module "mod-stateful-util" registered
18:05:34.517 sip_endpoint.c Module "mod-ua" registered
18:05:34.517 sip_endpoint.c Module "mod-100rel" registered
18:05:34.517 sip_endpoint.c Module "mod-pjsua" registered
18:05:34.517 sip_endpoint.c Module "mod-invite" registered
18:05:34.548 pa_dev.c PA message: before paHostApiInitializers[0].
18:05:34.642 pa_dev.c PA message: Pa_GetDeviceInfo: Num input channels reported as 65535! Changed to 2.
18:05:34.642 pa_dev.c PA message: Pa_GetDeviceInfo: Num input channels reported as 65535! Changed to 2.
18:05:34.642 pa_dev.c PA message: Pa_GetDeviceInfo: Num output channels reported as 65535! Changed to 2.
18:05:34.642 pa_dev.c PA message: Pa_GetDeviceInfo: Num output channels reported as 65535! Changed to 2.
18:05:34.642 pa_dev.c PA message: after paHostApiInitializers[0].
18:05:34.642 pa_dev.c PA message: before paHostApiInitializers[1].
18:05:34.923 pa_dev.c PA message: after paHostApiInitializers[1].
18:05:34.923 pa_dev.c PA message: before paHostApiInitializers[2].
18:05:34.923 pa_dev.c PA message: after paHostApiInitializers[2].
18:05:34.923 pa_dev.c PortAudio sound library initialized, status=0
18:05:34.923 pa_dev.c PortAudio host api count=3
18:05:34.923 pa_dev.c Sound device count=12
18:05:34.923 wmme_dev.c WMME initialized, found 5 devices:
18:05:34.923 wmme_dev.c dev_id 0: Wave mapper (in=2, out=2)
18:05:34.923 wmme_dev.c dev_id 1: USB Device (in=2, out=0)
18:05:34.923 wmme_dev.c dev_id 2: Realtek AC97 Audio (in=2, out=0)
18:05:34.923 wmme_dev.c dev_id 3: USB Device (in=0, out=2)
18:05:34.923 wmme_dev.c dev_id 4: Realtek AC97 Audio (in=0, out=2)
18:05:34.939 pjlib select() I/O Queue created (00DD60AC)
18:05:34.939 conference.c Creating conference bridge with 254 ports
18:05:34.954 conference.c Sound device successfully created for port 0
18:05:34.954 sip_endpoint.c Module "mod-evsub" registered
18:05:34.954 sip_endpoint.c Module "mod-presence" registered
18:05:34.954 evsub.c Event pkg "presence" registered by mod-presence
18:05:34.954 sip_endpoint.c Module "mod-refer" registered
18:05:34.954 evsub.c Event pkg "refer" registered by mod-refer
18:05:34.954 sip_endpoint.c Module "mod-pjsua-pres" registered
18:05:34.954 sip_endpoint.c Module "mod-pjsua-im" registered
18:05:34.954 sip_endpoint.c Module "mod-pjsua-options" registered
18:05:34.954 pjsua_core.c 1 SIP worker threads created
18:05:34.954 pjsua_core.c pjsua version 1.1 for win32 initialized
18:05:34.954 sip_endpoint.c Module "mod-default-handler" registered
18:05:34.986 pjsua_core.c SIP UDP socket reachable at 172.18.2.74:5060
18:05:34.986 udp00DE60A8 SIP UDP transport started, published address is 172.18.2.74:5060
18:05:34.986 pjsua_acc.c Account <sip:172.18.2.74:5060> added with id 0
18:05:34.986 pjsua_acc.c Account sip:alice at voip3gppsrv2 added with id 1
18:05:34.986 endpoint Request msg REGISTER/cseq=16537 (tdta00DEA8F8) created.
18:05:34.986 tsx00DEB98C Transaction created for Request msg REGISTER/cseq=16538 (tdta00DEA8F8)
18:05:34.986 tsx00DEB98C Sending Request msg REGISTER/cseq=16538 (tdta00DEA8F8) in state Null
18:05:35.001 sip_resolve.c Target '172.18.1.218:4060' type=Unspecified resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:05:35.001 pjsua_core.c TX 569 bytes Request msg REGISTER/cseq=16538 (tdta00DEA8F8) to UDP 172.18.1.218:4060:
REGISTER sip:voip3gppsrv2 SIP/2.0
Via: SIP/2.0/UDP 172.18.2.74:5060;rport;branch=z9hG4bKPjc429fb3bcf2246949527e32b9e57b536
Route: <sip:172.18.1.218:4060;lr>
Max-Forwards: 70
From: <sip:alice@voip3gppsrv2>;tag=94aba484e1b54cc69a4f3967e1a951b3
To: <sip:alice at voip3gppsrv2>
Call-ID: de5488e94dbe4614bebd1aebecaa08d4
CSeq: 16538 REGISTER
Authorization: Digest username="alice at voip3gppsrv2", realm="voip3gppsrv2", nonce="", uri="sip:voip3gppsrv2", response=""
User-Agent: PJSUA v1.1/win32
Contact: <sip:alice at 172.18.2.74:5060>
Expires: 300
Content-Length: 0
?
--end msg--
18:05:35.017 tsx00DEB98C State changed from Null to Calling, event=TX_MSG
18:05:35.017 pjsua_acc.c Registration sent
18:05:35.033 pjsua_media.c RTP socket reachable at 172.18.2.74:4000
18:05:35.033 pjsua_media.c RTCP socket reachable at 172.18.2.74:4001
18:05:35.033 pjsua_media.c RTP socket reachable at 172.18.2.74:4002
18:05:35.033 pjsua_media.c RTCP socket reachable at 172.18.2.74:4003
18:05:35.033 pjsua_media.c RTP socket reachable at 172.18.2.74:4004
18:05:35.048 pjsua_media.c RTCP socket reachable at 172.18.2.74:4005
18:05:35.048 pjsua_media.c RTP socket reachable at 172.18.2.74:4006
18:05:35.048 pjsua_media.c RTCP socket reachable at 172.18.2.74:4007
18:05:35.095 sip_endpoint.c Processing incoming message: Response msg 401/REGISTER/cseq=16538 (rdata00DE754C)
18:05:35.095 pjsua_core.c RX 929 bytes Response msg 401/REGISTER/cseq=16538 (rdata00DE754C) from UDP 172.18.1.218:4060:
SIP/2.0 401 Unauthorized - Challenging the UE
Via: SIP/2.0/UDP 172.18.2.74:5060;rport=5060;branch=z9hG4bKPjc429fb3bcf2246949527e32b9e57b536
From: <sip:alice@voip3gppsrv2>;tag=94aba484e1b54cc69a4f3967e1a951b3
To: <sip:alice at voip3gppsrv2>;tag=f75735bb452c646ce340d959ac7ef7f2-7309
Call-ID: de5488e94dbe4614bebd1aebecaa08d4
CSeq: 16538 REGISTER
Path: <sip:term at pcscf.voip3gppsrv2:4060;lr>
Service-Route: <sip:orig at scscf.voip3gppsrv2:6060;lr>
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, MESSAGE, INFO
Server: Sip EXpress router (2.1.0-dev1 OpenIMSCore (i386/linux))
Content-Length: 0
Warning: 392 172.18.1.218:6060 "Noisy feedback tells: pid=5458 req_src_ip=172.18.1.218 req_src_port=5060 in_uri=sip:scscf.voip3gppsrv2:6060 out_uri=sip:scscf.voip3gppsrv2:6060 via_cnt==3"
WWW-Authenticate: Digest realm="voip3gppsrv2", nonce="W8Qrvi9uiMwtOAuJzLd/810z500IuAAALdQsY0WER6Q=", algorithm=AKAv1-MD5
?
--end msg--
18:05:35.126 tsx00DEB98C Incoming Response msg 401/REGISTER/cseq=16538 (rdata00DE754C) in state Calling
18:05:35.126 tsx00DEB98C State changed from Calling to Completed, event=RX_MSG
18:05:35.126 tsx00DF82BC Transaction created for Request msg REGISTER/cseq=16539 (tdta00DEA8F8)
18:05:35.126 tsx00DF82BC Sending Request msg REGISTER/cseq=16539 (tdta00DEA8F8) in state Null
18:05:35.126 sip_resolve.c Target '172.18.1.218:4060' type=Unspecified resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:05:35.126 pjsua_core.c TX 666 bytes Request msg REGISTER/cseq=16539 (tdta00DEA8F8) to UDP 172.18.1.218:4060:
REGISTER sip:voip3gppsrv2 SIP/2.0
Via: SIP/2.0/UDP 172.18.2.74:5060;rport;branch=z9hG4bKPj694ded0a6955423085df0f848f600e98
Route: <sip:172.18.1.218:4060;lr>
Max-Forwards: 70
From: <sip:alice@voip3gppsrv2>;tag=94aba484e1b54cc69a4f3967e1a951b3
To: <sip:alice at voip3gppsrv2>
Call-ID: de5488e94dbe4614bebd1aebecaa08d4
CSeq: 16539 REGISTER
User-Agent: PJSUA v1.1/win32
Contact: <sip:alice at 172.18.2.74:5060>
Expires: 300
Authorization: Digest username="alice at voip3gppsrv2", realm="voip3gppsrv2", nonce="W8Qrvi9uiMwtOAuJzLd/810z500IuAAALdQsY0WER6Q=", uri="sip:voip3gppsrv2", response="6fe922446c03b2792df1e8758edb9ece", algorithm=AKAv1-MD5
Content-Length: 0
?
--end msg--
18:05:35.158 tsx00DF82BC State changed from Null to Calling, event=TX_MSG
18:05:35.267 sip_endpoint.c Processing incoming message: Response msg 200/REGISTER/cseq=16539 (rdata00DE754C)
18:05:35.267 pjsua_core.c RX 959 bytes Response msg 200/REGISTER/cseq=16539 (rdata00DE754C) from UDP 172.18.1.218:4060:
SIP/2.0 200 OK - SAR succesful and registrar saved
Via: SIP/2.0/UDP 172.18.2.74:5060;rport=5060;branch=z9hG4bKPj694ded0a6955423085df0f848f600e98
From: <sip:alice@voip3gppsrv2>;tag=94aba484e1b54cc69a4f3967e1a951b3
To: <sip:alice at voip3gppsrv2>;tag=f75735bb452c646ce340d959ac7ef7f2-6158
Call-ID: de5488e94dbe4614bebd1aebecaa08d4
CSeq: 16539 REGISTER
P-Associated-URI: <sip:alice at voip3gppsrv2>
Contact: <sip:alice at 172.18.2.74:5060>;expires=300
Path: <sip:term at pcscf.voip3gppsrv2:4060;lr>
Service-Route: <sip:orig at scscf.voip3gppsrv2:6060;lr>
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, MESSAGE, INFO
P-Charging-Function-Addresses: ccf=pri_ccf_address
Server: Sip EXpress router (2.1.0-dev1 OpenIMSCore (i386/linux))
Content-Length: 0
Warning: 392 172.18.1.218:6060 "Noisy feedback tells: pid=5457 req_src_ip=172.18.1.218 req_src_port=5060 in_uri=sip:scscf.voip3gppsrv2:6060 out_uri=sip:scscf.voip3gppsrv2:6060 via_cnt==3"
?
--end msg--
18:05:35.283 tsx00DF82BC Incoming Response msg 200/REGISTER/cseq=16539 (rdata00DE754C) in state Calling
18:05:35.283 tsx00DF82BC State changed from Calling to Completed, event=RX_MSG
18:05:35.283 pjsua_acc.c Service-Route updated for acc 1 with 1 URI(s)
18:05:35.283 pjsua_acc.c sip:alice at voip3gppsrv2: registration success, status=200 (OK - SAR succesful and registrar saved), will re-register in 300 seconds
18:05:35.283 pjsua_acc.c Keep-alive timer started for acc 1, destination:172.18.1.218:4060, interval:15s
18:05:40.158 tsx00DEB98C Timeout timer event
18:05:40.158 tsx00DEB98C State changed from Completed to Terminated, event=TIMER
18:05:40.158 tsx00DEB98C Timeout timer event
18:05:40.158 tsx00DEB98C State changed from Terminated to Destroyed, event=TIMER
18:05:40.158 tsx00DEB98C Transaction destroyed!
18:05:40.283 tsx00DF82BC Timeout timer event
18:05:40.283 tsx00DF82BC State changed from Completed to Terminated, event=TIMER
18:05:40.283 tsx00DF82BC Timeout timer event
18:05:40.283 tsx00DF82BC State changed from Terminated to Destroyed, event=TIMER
18:05:40.283 tdta00DEA8F8 Destroying txdata Request msg REGISTER/cseq=16539 (tdta00DEA8F8)
18:05:40.283 tsx00DF82BC Transaction destroyed!
18:05:50.283 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:05:50.283 tdta00DEA8F8 Destroying txdata raw
18:06:05.284 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:06:05.284 tdta00DEA8F8 Destroying txdata raw
18:06:20.285 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:06:20.285 tdta00DEA8F8 Destroying txdata raw
18:06:35.286 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:06:35.286 tdta00DEA8F8 Destroying txdata raw
18:06:50.287 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:06:50.287 tdta00DEA8F8 Destroying txdata raw
18:07:05.288 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:07:05.288 tdta00DEA8F8 Destroying txdata raw
18:07:20.289 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:07:20.289 tdta00DEA8F8 Destroying txdata raw
18:07:35.290 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:07:35.290 tdta00DEA8F8 Destroying txdata raw
18:07:50.291 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:07:50.291 tdta00DEA8F8 Destroying txdata raw
18:08:04.011 endpoint Request msg REGISTER/cseq=16539 (tdta00DEA8F8) created.
18:08:04.011 tsx00DF82BC Transaction created for Request msg REGISTER/cseq=16540 (tdta00DEA8F8)
18:08:04.011 tsx00DF82BC Sending Request msg REGISTER/cseq=16540 (tdta00DEA8F8) in state Null
18:08:04.011 sip_resolve.c Target '172.18.1.218:4060' type=Unspecified resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:08:04.011 pjsua_core.c TX 567 bytes Request msg REGISTER/cseq=16540 (tdta00DEA8F8) to UDP 172.18.1.218:4060:
REGISTER sip:voip3gppsrv2 SIP/2.0
Via: SIP/2.0/UDP 172.18.2.74:5060;rport;branch=z9hG4bKPjcdb105a9aa11427097534838b6f9e146
Route: <sip:172.18.1.218:4060;lr>
Max-Forwards: 70
From: <sip:alice@voip3gppsrv2>;tag=17189584ace94648b77649b6524475f5
To: <sip:alice at voip3gppsrv2>
Call-ID: de5488e94dbe4614bebd1aebecaa08d4
CSeq: 16540 REGISTER
Authorization: Digest username="alice at voip3gppsrv2", realm="voip3gppsrv2", nonce="", uri="sip:voip3gppsrv2", response=""
User-Agent: PJSUA v1.1/win32
Contact: <sip:alice at 172.18.2.74:5060>
Expires: 0
Content-Length: 0
?
--end msg--
18:08:04.042 tsx00DF82BC State changed from Null to Calling, event=TX_MSG
18:08:04.042 pjsua_acc.c Unregistration sent
18:08:04.073 sip_endpoint.c Processing incoming message: Response msg 401/REGISTER/cseq=16540 (rdata00DE754C)
18:08:04.073 pjsua_core.c RX 929 bytes Response msg 401/REGISTER/cseq=16540 (rdata00DE754C) from UDP 172.18.1.218:4060:
SIP/2.0 401 Unauthorized - Challenging the UE
Via: SIP/2.0/UDP 172.18.2.74:5060;rport=5060;branch=z9hG4bKPjcdb105a9aa11427097534838b6f9e146
From: <sip:alice@voip3gppsrv2>;tag=17189584ace94648b77649b6524475f5
To: <sip:alice at voip3gppsrv2>;tag=f75735bb452c646ce340d959ac7ef7f2-8083
Call-ID: de5488e94dbe4614bebd1aebecaa08d4
CSeq: 16540 REGISTER
Path: <sip:term at pcscf.voip3gppsrv2:4060;lr>
Service-Route: <sip:orig at scscf.voip3gppsrv2:6060;lr>
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, MESSAGE, INFO
Server: Sip EXpress router (2.1.0-dev1 OpenIMSCore (i386/linux))
Content-Length: 0
Warning: 392 172.18.1.218:6060 "Noisy feedback tells: pid=5459 req_src_ip=172.18.1.218 req_src_port=5060 in_uri=sip:scscf.voip3gppsrv2:6060 out_uri=sip:scscf.voip3gppsrv2:6060 via_cnt==3"
WWW-Authenticate: Digest realm="voip3gppsrv2", nonce="ozvm+wuT1P9MzFE+9e08b3zexrGI7QAAKIZR2cW4Avg=", algorithm=AKAv1-MD5
?
--end msg--
18:08:04.105 tsx00DF82BC Incoming Response msg 401/REGISTER/cseq=16540 (rdata00DE754C) in state Calling
18:08:04.105 tsx00DF82BC State changed from Calling to Completed, event=RX_MSG
18:08:04.105 tsx00DED8FC Transaction created for Request msg REGISTER/cseq=16541 (tdta00DEA8F8)
18:08:04.105 tsx00DED8FC Sending Request msg REGISTER/cseq=16541 (tdta00DEA8F8) in state Null
18:08:04.105 sip_resolve.c Target '172.18.1.218:4060' type=Unspecified resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:08:04.105 pjsua_core.c TX 664 bytes Request msg REGISTER/cseq=16541 (tdta00DEA8F8) to UDP 172.18.1.218:4060:
REGISTER sip:voip3gppsrv2 SIP/2.0
Via: SIP/2.0/UDP 172.18.2.74:5060;rport;branch=z9hG4bKPjf8a49dd8e62344879d66639d70cd1e41
Route: <sip:172.18.1.218:4060;lr>
Max-Forwards: 70
From: <sip:alice@voip3gppsrv2>;tag=17189584ace94648b77649b6524475f5
To: <sip:alice at voip3gppsrv2>
Call-ID: de5488e94dbe4614bebd1aebecaa08d4
CSeq: 16541 REGISTER
User-Agent: PJSUA v1.1/win32
Contact: <sip:alice at 172.18.2.74:5060>
Expires: 0
Authorization: Digest username="alice at voip3gppsrv2", realm="voip3gppsrv2", nonce="ozvm+wuT1P9MzFE+9e08b3zexrGI7QAAKIZR2cW4Avg=", uri="sip:voip3gppsrv2", response="283d0a54f683e1d39d892e1ac61381d2", algorithm=AKAv1-MD5
Content-Length: 0
?
--end msg--
18:08:04.136 tsx00DED8FC State changed from Null to Calling, event=TX_MSG
18:08:04.183 sip_endpoint.c Processing incoming message: Response msg 200/REGISTER/cseq=16541 (rdata00DE754C)
18:08:04.183 pjsua_core.c RX 861 bytes Response msg 200/REGISTER/cseq=16541 (rdata00DE754C) from UDP 172.18.1.218:4060:
SIP/2.0 200 OK - SAR succesful and registrar saved
Via: SIP/2.0/UDP 172.18.2.74:5060;rport=5060;branch=z9hG4bKPjf8a49dd8e62344879d66639d70cd1e41
From: <sip:alice@voip3gppsrv2>;tag=17189584ace94648b77649b6524475f5
To: <sip:alice at voip3gppsrv2>;tag=f75735bb452c646ce340d959ac7ef7f2-c20b
Call-ID: de5488e94dbe4614bebd1aebecaa08d4
CSeq: 16541 REGISTER
Contact: <sip:alice at 172.18.2.74:5060>;expires=0
Path: <sip:term at pcscf.voip3gppsrv2:4060;lr>
Service-Route: <sip:orig at scscf.voip3gppsrv2:6060;lr>
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, MESSAGE, INFO
Server: Sip EXpress router (2.1.0-dev1 OpenIMSCore (i386/linux))
Content-Length: 0
Warning: 392 172.18.1.218:6060 "Noisy feedback tells: pid=5458 req_src_ip=172.18.1.218 req_src_port=5060 in_uri=sip:scscf.voip3gppsrv2:6060 out_uri=sip:scscf.voip3gppsrv2:6060 via_cnt==3"
?
--end msg--
18:08:04.214 tsx00DED8FC Incoming Response msg 200/REGISTER/cseq=16541 (rdata00DE754C) in state Calling
18:08:04.214 tsx00DED8FC State changed from Calling to Completed, event=RX_MSG
18:08:04.214 pjsua_acc.c sip:alice at voip3gppsrv2: unregistration success
18:08:06.261 endpoint Request msg REGISTER/cseq=21817 (tdta00DF8BB8) created.
18:08:06.261 tsx00DF9C4C Transaction created for Request msg REGISTER/cseq=21818 (tdta00DF8BB8)
18:08:06.261 tsx00DF9C4C Sending Request msg REGISTER/cseq=21818 (tdta00DF8BB8) in state Null
18:08:06.261 sip_resolve.c Target '172.18.1.218:4060' type=Unspecified resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:08:06.261 pjsua_core.c TX 615 bytes Request msg REGISTER/cseq=21818 (tdta00DF8BB8) to UDP 172.18.1.218:4060:
REGISTER sip:voip3gppsrv2 SIP/2.0
Via: SIP/2.0/UDP 172.18.2.74:5060;rport;branch=z9hG4bKPjaa93ed7bb9054801a656aa1ca192ef4e
Route: <sip:172.18.1.218:4060;lr>
Route: <sip:orig at scscf.voip3gppsrv2:6060;lr>
Max-Forwards: 70
From: <sip:alice@voip3gppsrv2>;tag=4300084482054a6692ea1f03821f4c36
To: <sip:alice at voip3gppsrv2>
Call-ID: d8f852bfe7cb4c758fafbaa8dbffed30
CSeq: 21818 REGISTER
Authorization: Digest username="alice at voip3gppsrv2", realm="voip3gppsrv2", nonce="", uri="sip:voip3gppsrv2", response=""
User-Agent: PJSUA v1.1/win32
Contact: <sip:alice at 172.18.2.74:5060>
Expires: 300
Content-Length: 0
?
--end msg--
18:08:06.292 tsx00DF9C4C State changed from Null to Calling, event=TX_MSG
18:08:06.292 pjsua_acc.c Registration sent
18:08:06.355 sip_endpoint.c Processing incoming message: Response msg 401/REGISTER/cseq=21818 (rdata00DE754C)
18:08:06.355 pjsua_core.c RX 929 bytes Response msg 401/REGISTER/cseq=21818 (rdata00DE754C) from UDP 172.18.1.218:4060:
SIP/2.0 401 Unauthorized - Challenging the UE
Via: SIP/2.0/UDP 172.18.2.74:5060;rport=5060;branch=z9hG4bKPjaa93ed7bb9054801a656aa1ca192ef4e
From: <sip:alice@voip3gppsrv2>;tag=4300084482054a6692ea1f03821f4c36
To: <sip:alice at voip3gppsrv2>;tag=f75735bb452c646ce340d959ac7ef7f2-7e85
Call-ID: d8f852bfe7cb4c758fafbaa8dbffed30
CSeq: 21818 REGISTER
Path: <sip:term at pcscf.voip3gppsrv2:4060;lr>
Service-Route: <sip:orig at scscf.voip3gppsrv2:6060;lr>
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, MESSAGE, INFO
Server: Sip EXpress router (2.1.0-dev1 OpenIMSCore (i386/linux))
Content-Length: 0
Warning: 392 172.18.1.218:6060 "Noisy feedback tells: pid=5456 req_src_ip=172.18.1.218 req_src_port=5060 in_uri=sip:scscf.voip3gppsrv2:6060 out_uri=sip:scscf.voip3gppsrv2:6060 via_cnt==3"
WWW-Authenticate: Digest realm="voip3gppsrv2", nonce="QMkAKwXNfHFTF7VRGe0TU8MqGconRQAAw4qvwNo+An8=", algorithm=AKAv1-MD5
?
--end msg--
18:08:06.370 tsx00DF9C4C Incoming Response msg 401/REGISTER/cseq=21818 (rdata00DE754C) in state Calling
18:08:06.370 tsx00DF9C4C State changed from Calling to Completed, event=RX_MSG
18:08:06.370 tsx00DFC3EC Transaction created for Request msg REGISTER/cseq=21819 (tdta00DF8BB8)
18:08:06.370 tsx00DFC3EC Sending Request msg REGISTER/cseq=21819 (tdta00DF8BB8) in state Null
18:08:06.370 sip_resolve.c Target '172.18.1.218:4060' type=Unspecified resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:08:06.370 pjsua_core.c TX 712 bytes Request msg REGISTER/cseq=21819 (tdta00DF8BB8) to UDP 172.18.1.218:4060:
REGISTER sip:voip3gppsrv2 SIP/2.0
Via: SIP/2.0/UDP 172.18.2.74:5060;rport;branch=z9hG4bKPj6a28b0354fdc46c28aaee2caf90888fa
Route: <sip:172.18.1.218:4060;lr>
Route: <sip:orig at scscf.voip3gppsrv2:6060;lr>
Max-Forwards: 70
From: <sip:alice@voip3gppsrv2>;tag=4300084482054a6692ea1f03821f4c36
To: <sip:alice at voip3gppsrv2>
Call-ID: d8f852bfe7cb4c758fafbaa8dbffed30
CSeq: 21819 REGISTER
User-Agent: PJSUA v1.1/win32
Contact: <sip:alice at 172.18.2.74:5060>
Expires: 300
Authorization: Digest username="alice at voip3gppsrv2", realm="voip3gppsrv2", nonce="QMkAKwXNfHFTF7VRGe0TU8MqGconRQAAw4qvwNo+An8=", uri="sip:voip3gppsrv2", response="06f555889f318639d98b428c80446e6e", algorithm=AKAv1-MD5
Content-Length: 0
?
--end msg--
18:08:06.402 tsx00DFC3EC State changed from Null to Calling, event=TX_MSG
18:08:06.495 sip_endpoint.c Processing incoming message: Response msg 200/REGISTER/cseq=21819 (rdata00DE754C)
18:08:06.495 pjsua_core.c RX 959 bytes Response msg 200/REGISTER/cseq=21819 (rdata00DE754C) from UDP 172.18.1.218:4060:
SIP/2.0 200 OK - SAR succesful and registrar saved
Via: SIP/2.0/UDP 172.18.2.74:5060;rport=5060;branch=z9hG4bKPj6a28b0354fdc46c28aaee2caf90888fa
From: <sip:alice@voip3gppsrv2>;tag=4300084482054a6692ea1f03821f4c36
To: <sip:alice at voip3gppsrv2>;tag=f75735bb452c646ce340d959ac7ef7f2-3712
Call-ID: d8f852bfe7cb4c758fafbaa8dbffed30
CSeq: 21819 REGISTER
P-Associated-URI: <sip:alice at voip3gppsrv2>
Contact: <sip:alice at 172.18.2.74:5060>;expires=300
Path: <sip:term at pcscf.voip3gppsrv2:4060;lr>
Service-Route: <sip:orig at scscf.voip3gppsrv2:6060;lr>
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, MESSAGE, INFO
P-Charging-Function-Addresses: ccf=pri_ccf_address
Server: Sip EXpress router (2.1.0-dev1 OpenIMSCore (i386/linux))
Content-Length: 0
Warning: 392 172.18.1.218:6060 "Noisy feedback tells: pid=5457 req_src_ip=172.18.1.218 req_src_port=5060 in_uri=sip:scscf.voip3gppsrv2:6060 out_uri=sip:scscf.voip3gppsrv2:6060 via_cnt==3"
?
--end msg--
18:08:06.511 tsx00DFC3EC Incoming Response msg 200/REGISTER/cseq=21819 (rdata00DE754C) in state Calling
18:08:06.511 tsx00DFC3EC State changed from Calling to Completed, event=RX_MSG
18:08:06.511 pjsua_acc.c Service-Route updated for acc 1 with 1 URI(s)
18:08:06.511 pjsua_acc.c sip:alice at voip3gppsrv2: registration success, status=200 (OK - SAR succesful and registrar saved), will re-register in 300 seconds
18:08:06.527 pjsua_acc.c Keep-alive timer started for acc 1, destination:172.18.1.218:4060, interval:15s
18:08:09.136 tsx00DF82BC Timeout timer event
18:08:09.136 tsx00DF82BC State changed from Completed to Terminated, event=TIMER
18:08:09.136 tsx00DF82BC Timeout timer event
18:08:09.136 tsx00DF82BC State changed from Terminated to Destroyed, event=TIMER
18:08:09.136 tsx00DF82BC Transaction destroyed!
18:08:09.214 tsx00DED8FC Timeout timer event
18:08:09.214 tsx00DED8FC State changed from Completed to Terminated, event=TIMER
18:08:09.214 tsx00DED8FC Timeout timer event
18:08:09.214 tsx00DED8FC State changed from Terminated to Destroyed, event=TIMER
18:08:09.214 tdta00DEA8F8 Destroying txdata Request msg REGISTER/cseq=16541 (tdta00DEA8F8)
18:08:09.214 tsx00DED8FC Transaction destroyed!
18:08:11.402 tsx00DF9C4C Timeout timer event
18:08:11.402 tsx00DF9C4C State changed from Completed to Terminated, event=TIMER
18:08:11.402 tsx00DF9C4C Timeout timer event
18:08:11.402 tsx00DF9C4C State changed from Terminated to Destroyed, event=TIMER
18:08:11.402 tsx00DF9C4C Transaction destroyed!
18:08:11.511 tsx00DFC3EC Timeout timer event
18:08:11.511 tsx00DFC3EC State changed from Completed to Terminated, event=TIMER
18:08:11.511 tsx00DFC3EC Timeout timer event
18:08:11.511 tsx00DFC3EC State changed from Terminated to Destroyed, event=TIMER
18:08:11.511 tdta00DF8BB8 Destroying txdata Request msg REGISTER/cseq=21819 (tdta00DF8BB8)
18:08:11.511 tsx00DFC3EC Transaction destroyed!
18:08:21.528 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:08:21.528 tdta00DEA8F8 Destroying txdata raw
18:08:25.122 sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=5857 (rdata00DE754C)
18:08:25.122 pjsua_core.c <logging error: msg too long>
18:08:25.153 pjsua_media.c Media index 0 selected for call 0
18:08:25.153 tsx00DF907C Transaction created for Request msg INVITE/cseq=5857 (rdata00DE754C)
18:08:25.153 tsx00DF907C Incoming Request msg INVITE/cseq=5857 (rdata00DE754C) in state Null
18:08:25.153 tsx00DF907C State changed from Null to Trying, event=RX_MSG
18:08:25.153 dlg00DED8CC Transaction tsx00DF907C state changed to Trying
18:08:25.153 dlg00DED8CC UAS dialog created
18:08:25.153 dlg00DED8CC Module mod-invite added as dialog usage, data=00DF985C
18:08:25.153 dlg00DED8CC Session count inc to 2 by mod-invite
18:08:25.153 inv00DED8CC UAS invite session created for dialog dlg00DED8CC
18:08:25.153 pjsua_call.c Call 0: remote NAT type is 0 (Unknown)
18:08:25.153 endpoint Response msg 100/INVITE/cseq=5857 (tdta00DFB3F8) created
18:08:25.153 dlg00DED8CC Initial answer Response msg 100/INVITE/cseq=5857 (tdta00DFB3F8)
18:08:25.153 inv00DED8CC Sending Response msg 100/INVITE/cseq=5857 (tdta00DFB3F8)
18:08:25.153 dlg00DED8CC Sending Response msg 100/INVITE/cseq=5857 (tdta00DFB3F8)
18:08:25.153 tsx00DF907C Sending Response msg 100/INVITE/cseq=5857 (tdta00DFB3F8) in state Trying
18:08:25.153 sip_resolve.c Target '172.18.1.218:4060' type=UDP resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:08:25.153 pjsua_core.c TX 1144 bytes Response msg 100/INVITE/cseq=5857 (tdta00DFB3F8) to UDP 172.18.1.218:4060:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.18.1.218:4060;received=172.18.1.218;branch=z9hG4bK1439.ce76d226.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;received=172.18.1.218;branch=z9hG4bK1439.f0db72b1.0
Via: SIP/2.0/UDP 172.18.1.218;branch=z9hG4bK1439.2f38d716.0
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=z9hG4bK1439.e0db72b1.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK1439.e2dffd85.0
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=z9hG4bK1439.d0db72b1.0
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=z9hG4bK1439.be76d226.0
Via: SIP/2.0/UDP 172.18.1.222:5060;rport=5060;branch=z9hG4bKPj7af9a09c2e5a4c9599bbc5f74218db38
Record-Route: <sip:mt at pcscf.voip3gppsrv2:4060;lr>
Record-Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:172.18.1.218:5065;lr;ftag=062ce89b154844dfa30567ae5214c92a>
Record-Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:mo at pcscf.voip3gppsrv2:4060;lr>
Call-ID: fbef225ea1e145d7b409ef1b34b5f316
From: <sip:bob@voip3gppsrv2>;tag=062ce89b154844dfa30567ae5214c92a
To: <sip:alice at voip3gppsrv2>
CSeq: 5857 INVITE
Content-Length: 0
?
--end msg--
18:08:25.184 tsx00DF907C State changed from Trying to Proceeding, event=TX_MSG
18:08:25.184 dlg00DED8CC Transaction tsx00DF907C state changed to Proceeding
18:08:25.184 pjsua_media.c Opening sound device PCM at 16000/1/20ms
18:08:25.278 pa_dev.c Opened device Microsoft Sound Mapper - Input(MME)/Microsoft Sound Mapper - Output(MME) for recording and playback, sample rate=16000, ch=1, bits=16, 320 samples per frame, input latency=100 ms, output latency=100 ms
18:08:25.309 ec00DF88B8 Creating AEC
18:08:25.340 ec00DF88B8 AEC created, clock_rate=16000, channel=1, samples per frame=320, tail length=200 ms, latency=100 ms
18:08:25.340 pa_dev.c Starting Microsoft Sound Mapper - Input stream..
18:08:25.356 pa_dev.c PA message: Pa_StartStream: waveInStart returned = 0x0.
18:08:25.356 pa_dev.c Done, status=0
18:08:25.356 conference.c Port 2 (ring) transmitting to port 0 (Microsoft Sound Mapper - Input)
18:08:25.356 inv00DED8CC SDP negotiation done, status=0
18:08:25.356 pjsua_call.c Call 0: remote NAT type is 0 (Unknown)
18:08:25.356 strm00E3086C VAD temporarily disabled
18:08:25.356 rtp.c pjmedia_rtp_session_init: ses=00E31A40, default_pt=103, ssrc=0x294823
18:08:25.356 rtp.c pjmedia_rtp_session_init: ses=00E31EB4, default_pt=103, ssrc=0x294823
18:08:25.356 stream.c Stream strm00E3086C created
18:08:25.356 strm00E3086C Encoder stream started
18:08:25.356 strm00E3086C Decoder stream started
18:08:25.356 pjsua_media.c Media updates, stream #0: speex (sendrecv)
18:08:25.356 conference.c Port 2 (ring) stop transmitting to port 0 (Microsoft Sound Mapper - Input)
18:08:25.372 conference.c Port 3 (sip:bob at voip3gppsrv2) transmitting to port 0 (Microsoft Sound Mapper - Input)
18:08:25.372 conference.c Port 0 (Microsoft Sound Mapper - Input) transmitting to port 3 (sip:bob at voip3gppsrv2)
18:08:25.372 pjsua_app.c Media for call 0 is active
18:08:25.372 inv00DED8CC Sending Response msg 200/INVITE/cseq=5857 (tdta00DFB3F8)
18:08:25.372 dlg00DED8CC Sending Response msg 200/INVITE/cseq=5857 (tdta00DFB3F8)
18:08:25.372 tsx00DF907C Sending Response msg 200/INVITE/cseq=5857 (tdta00DFB3F8) in state Proceeding
18:08:25.372 pa_dev.c Recorder thread started
18:08:25.372 ec00DF88B8 Prefetching..
18:08:25.372 pjsua_core.c TX 1637 bytes Response msg 200/INVITE/cseq=5857 (tdta00DFB3F8) to UDP 172.18.1.218:4060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.18.1.218:4060;received=172.18.1.218;branch=z9hG4bK1439.ce76d226.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;received=172.18.1.218;branch=z9hG4bK1439.f0db72b1.0
Via: SIP/2.0/UDP 172.18.1.218;branch=z9hG4bK1439.2f38d716.0
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=z9hG4bK1439.e0db72b1.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK1439.e2dffd85.0
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=z9hG4bK1439.d0db72b1.0
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=z9hG4bK1439.be76d226.0
Via: SIP/2.0/UDP 172.18.1.222:5060;rport=5060;branch=z9hG4bKPj7af9a09c2e5a4c9599bbc5f74218db38
Record-Route: <sip:mt at pcscf.voip3gppsrv2:4060;lr>
Record-Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:172.18.1.218:5065;lr;ftag=062ce89b154844dfa30567ae5214c92a>
Record-Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:mo at pcscf.voip3gppsrv2:4060;lr>
Call-ID: fbef225ea1e145d7b409ef1b34b5f316
From: <sip:bob@voip3gppsrv2>;tag=062ce89b154844dfa30567ae5214c92a
To: <sip:alice at voip3gppsrv2>;tag=eddd2b9b09f74cc0851e94a9043f996f
CSeq: 5857 INVITE
Contact: <sip:alice at 172.18.2.74:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length: 254
v=0
o=- 3449844505 3449844506 IN IP4 172.18.2.74
s=pjmedia
c=IN IP4 172.18.2.74
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 103 101
a=rtcp:4001 IN IP4 172.18.2.74
a=rtpmap:103 speex/16000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
--end msg--
18:08:25.403 pa_dev.c Player thread started
18:08:25.403 strm00E3086C Jitter buffer empty (prefetch=0)
18:08:25.403 strm00E3086C Start talksprut..
18:08:25.403 ec00DF88B8 Prefetching..
18:08:25.434 Master/sound Underflow, buf_cnt=0, will generate 1 frame
18:08:25.434 ec00DF88B8 Prefetching..
18:08:25.450 ec00DF88B8 Prefetching..
18:08:25.450 tsx00DF907C State changed from Proceeding to Completed, event=TX_MSG
18:08:25.450 dlg00DED8CC Transaction tsx00DF907C state changed to Completed
18:08:25.450 pjsua_app.c Call 0 state changed to CONNECTING
18:08:25.465 ec00DF88B8 Prefetching..
18:08:25.481 ec00DF88B8 Prefetching..
18:08:25.481 sip_endpoint.c Processing incoming message: Request msg ACK/cseq=5857 (rdata00DE754C)
18:08:25.481 pjsua_core.c RX 771 bytes Request msg ACK/cseq=5857 (rdata00DE754C) from UDP 172.18.1.218:5065:
ACK sip:alice at 172.18.2.74:5060 SIP/2.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK1439.e2dffd85.2
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=0
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=0
Via: SIP/2.0/UDP 172.18.1.222:5060;rport=5060;branch=z9hG4bKPja95db9fe3dfc44968b29928e00927c66
Max-Forwards: 14
From: sip:bob@voip3gppsrv2;tag=062ce89b154844dfa30567ae5214c92a
To: sip:alice at voip3gppsrv2;tag=eddd2b9b09f74cc0851e94a9043f996f
Call-ID: fbef225ea1e145d7b409ef1b34b5f316
CSeq: 5857 ACK
Route: <sip:172.18.1.218:5065;lr;ftag=062ce89b154844dfa30567ae5214c92a>
Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Route: <sip:mt at pcscf.voip3gppsrv2:4060;lr>
Content-Length: 0
P-Asserted-Identity: <sip:bob at voip3gppsrv2>
?
--end msg--
18:08:25.512 ec00DF88B8 Prefetching..
18:08:25.512 strm00E3086C RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=0
18:08:25.512 ec00DF88B8 Latency bufferring complete
18:08:25.512 strm00E3086C Jitter buffer empty (prefetch=0)
18:08:25.512 dlg00DED8CC Received Request msg ACK/cseq=5857 (rdata00DE754C)
18:08:25.512 tsx00DF907C Request to terminate transaction
18:08:25.512 tsx00DF907C State changed from Completed to Terminated, event=USER
18:08:25.512 dlg00DED8CC Transaction tsx00DF907C state changed to Terminated
18:08:25.528 pjsua_app.c Call 0 state changed to CONFIRMED
18:08:25.528 tsx00DF907C Timeout timer event
18:08:25.528 tsx00DF907C State changed from Terminated to Destroyed, event=TIMER
18:08:25.528 tdta00DFB3F8 Destroying txdata Response msg 200/INVITE/cseq=5857 (tdta00DFB3F8)
18:08:25.528 tsx00DF907C Transaction destroyed!
18:08:25.528 strm00E3086C jb updated(2), prefetch=1, size=1
18:08:25.528 strm00E3086C PUT prefetch_cnt=1/1
18:08:26.012 strm00E3086C VAD re-enabled
18:08:26.340 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:26.481 strm00E3086C Starting silence
18:08:26.622 strm00E3086C Start talksprut..
18:08:26.653 strm00E3086C Starting silence
18:08:26.731 strm00E3086C PUT prefetch_cnt=21/1
18:08:26.762 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:27.028 strm00E3086C Start talksprut..
18:08:27.028 strm00E3086C PUT prefetch_cnt=15/1
18:08:27.059 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:27.090 strm00E3086C PUT prefetch_cnt=3/1
18:08:27.122 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:27.340 strm00E3086C Starting silence
18:08:27.419 strm00E3086C Start talksprut..
18:08:27.450 strm00E3086C Starting silence
18:08:27.512 strm00E3086C PUT prefetch_cnt=21/1
18:08:27.544 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:27.825 strm00E3086C PUT prefetch_cnt=16/1
18:08:27.840 strm00E3086C Start talksprut..
18:08:27.872 strm00E3086C Starting silence
18:08:27.887 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:28.028 strm00E3086C PUT prefetch_cnt=9/1
18:08:28.262 strm00E3086C Start talksprut..
18:08:28.278 strm00E3086C Starting silence
18:08:28.340 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:28.684 strm00E3086C Start talksprut..
18:08:28.700 strm00E3086C Starting silence
18:08:28.731 strm00E3086C PUT prefetch_cnt=21/1
18:08:28.762 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:28.950 strm00E3086C Start talksprut..
18:08:28.981 strm00E3086C Starting silence
18:08:29.137 strm00E3086C PUT prefetch_cnt=20/1
18:08:29.153 strm00E3086C Start talksprut..
18:08:29.169 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:29.325 strm00E3086C PUT prefetch_cnt=10/1
18:08:29.372 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:29.747 strm00E3086C PUT prefetch_cnt=21/1
18:08:29.778 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:29.825 strm00E3086C PUT prefetch_cnt=4/1
18:08:29.887 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:30.216 strm00E3086C PUT prefetch_cnt=18/1
18:08:30.247 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:30.247 strm00E3086C PUT prefetch_cnt=2/1
18:08:30.278 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:30.309 strm00E3086C Starting silence
18:08:30.497 strm00E3086C PUT prefetch_cnt=12/1
18:08:30.528 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:30.559 strm00E3086C PUT prefetch_cnt=3/1
18:08:30.591 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:30.700 strm00E3086C Start talksprut..
18:08:30.731 strm00E3086C Starting silence
18:08:30.934 strm00E3086C PUT prefetch_cnt=19/1
18:08:31.044 strm00E3086C Start talksprut..
18:08:31.263 strm00E3086C Starting silence
18:08:31.403 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:31.450 strm00E3086C PUT prefetch_cnt=4/1
18:08:31.466 strm00E3086C Start talksprut..
18:08:31.513 strm00E3086C Starting silence
18:08:31.528 strm00E3086C Start talksprut..
18:08:31.700 strm00E3086C Starting silence
18:08:31.778 strm00E3086C Start talksprut..
18:08:31.809 strm00E3086C Starting silence
18:08:31.981 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:32.216 strm00E3086C Start talksprut..
18:08:32.216 strm00E3086C PUT prefetch_cnt=13/1
18:08:32.231 strm00E3086C Starting silence
18:08:32.466 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:32.622 strm00E3086C Start talksprut..
18:08:32.638 strm00E3086C Starting silence
18:08:32.747 strm00E3086C PUT prefetch_cnt=16/1
18:08:32.810 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:32.856 strm00E3086C PUT prefetch_cnt=4/1
18:08:32.888 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:32.919 strm00E3086C PUT prefetch_cnt=3/1
18:08:33.044 strm00E3086C Start talksprut..
18:08:33.060 strm00E3086C Starting silence
18:08:33.091 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:33.278 strm00E3086C PUT prefetch_cnt=11/1
18:08:33.325 strm00E3086C Start talksprut..
18:08:33.513 strm00E3086C Starting silence
18:08:33.544 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:33.810 strm00E3086C Start talksprut..
18:08:33.935 strm00E3086C PUT prefetch_cnt=21/1
18:08:33.966 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:34.013 strm00E3086C PUT prefetch_cnt=4/1
18:08:34.044 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:34.060 strm00E3086C PUT prefetch_cnt=2/1
18:08:34.091 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:34.231 strm00E3086C PUT prefetch_cnt=9/1
18:08:34.263 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:34.513 strm00E3086C PUT prefetch_cnt=14/1
18:08:34.544 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:34.638 strm00E3086C PUT prefetch_cnt=6/1
18:08:34.638 strm00E3086C Starting silence
18:08:34.685 strm00E3086C Start talksprut..
18:08:34.841 strm00E3086C Starting silence
18:08:34.888 strm00E3086C Start talksprut..
18:08:34.903 strm00E3086C Starting silence
18:08:34.997 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:35.013 strm00E3086C PUT prefetch_cnt=2/1
18:08:35.232 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:35.310 strm00E3086C Start talksprut..
18:08:35.607 strm00E3086C PUT prefetch_cnt=21/1
18:08:35.622 strm00E3086C Starting silence
18:08:35.638 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:36.028 strm00E3086C Start talksprut..
18:08:36.028 strm00E3086C PUT prefetch_cnt=21/1
18:08:36.044 strm00E3086C Starting silence
18:08:36.060 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:36.294 strm00E3086C Start talksprut..
18:08:36.372 strm00E3086C PUT prefetch_cnt=17/1
18:08:36.403 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:36.528 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:08:36.528 tdta00DFB3F8 Destroying txdata raw
18:08:36.794 strm00E3086C PUT prefetch_cnt=21/1
18:08:36.825 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:36.841 strm00E3086C Starting silence
18:08:36.919 strm00E3086C Start talksprut..
18:08:36.950 strm00E3086C Starting silence
18:08:36.966 strm00E3086C PUT prefetch_cnt=9/1
18:08:37.091 strm00E3086C Start talksprut..
18:08:37.310 strm00E3086C Jitter buffer empty (prefetch=1)
18:08:37.388 strm00E3086C Starting silence
18:08:37.404 strm00E3086C PUT prefetch_cnt=1/1
18:08:37.419 strm00E3086C jb updated(2), prefetch=7, size=7
18:08:37.419 strm00E3086C Start talksprut..
18:08:37.435 strm00E3086C PUT prefetch_cnt=2/7
18:08:37.450 strm00E3086C Starting silence
18:08:37.450 strm00E3086C PUT prefetch_cnt=3/7
18:08:37.482 strm00E3086C PUT prefetch_cnt=4/7
18:08:37.497 strm00E3086C PUT prefetch_cnt=5/7
18:08:37.513 strm00E3086C PUT prefetch_cnt=6/7
18:08:37.529 strm00E3086C PUT prefetch_cnt=7/7
18:08:37.560 strm00E3086C Start talksprut..
18:08:37.591 strm00E3086C Starting silence
18:08:37.669 strm00E3086C Start talksprut..
18:08:37.888 strm00E3086C Starting silence
18:08:37.966 strm00E3086C Start talksprut..
18:08:37.982 strm00E3086C Lost frame recovered
18:08:37.982 strm00E3086C Starting silence
18:08:37.997 strm00E3086C Lost frame recovered
18:08:38.029 strm00E3086C Lost frame recovered
18:08:38.029 strm00E3086C Start talksprut..
18:08:38.060 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:38.091 strm00E3086C Starting silence
18:08:38.107 strm00E3086C Start talksprut..
18:08:38.247 strm00E3086C PUT prefetch_cnt=17/7
18:08:38.263 strm00E3086C Starting silence
18:08:38.279 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:38.372 strm00E3086C PUT prefetch_cnt=6/7
18:08:38.404 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:38.450 strm00E3086C PUT prefetch_cnt=4/7
18:08:38.482 strm00E3086C PUT prefetch_cnt=5/7
18:08:38.497 strm00E3086C PUT prefetch_cnt=6/7
18:08:38.497 strm00E3086C Start talksprut..
18:08:38.513 strm00E3086C PUT prefetch_cnt=7/7
18:08:38.544 strm00E3086C Starting silence
18:08:38.638 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:38.841 strm00E3086C Start talksprut..
18:08:38.857 strm00E3086C Starting silence
18:08:39.029 strm00E3086C PUT prefetch_cnt=21/7
18:08:39.060 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:39.263 strm00E3086C Start talksprut..
18:08:39.279 strm00E3086C Starting silence
18:08:39.451 strm00E3086C PUT prefetch_cnt=21/7
18:08:39.482 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:39.685 strm00E3086C Start talksprut..
18:08:39.701 strm00E3086C Starting silence
18:08:39.872 strm00E3086C PUT prefetch_cnt=21/7
18:08:39.904 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:39.919 strm00E3086C PUT prefetch_cnt=2/7
18:08:39.951 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:39.951 strm00E3086C PUT prefetch_cnt=2/7
18:08:39.982 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:40.107 strm00E3086C Start talksprut..
18:08:40.122 strm00E3086C Starting silence
18:08:40.372 strm00E3086C PUT prefetch_cnt=21/7
18:08:40.404 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:40.529 strm00E3086C Start talksprut..
18:08:40.544 strm00E3086C Starting silence
18:08:40.669 strm00E3086C PUT prefetch_cnt=15/7
18:08:40.701 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:40.951 strm00E3086C Start talksprut..
18:08:40.966 strm00E3086C Starting silence
18:08:41.091 strm00E3086C PUT prefetch_cnt=21/7
18:08:41.123 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:41.357 strm00E3086C Start talksprut..
18:08:41.388 strm00E3086C Starting silence
18:08:41.513 strm00E3086C PUT prefetch_cnt=21/7
18:08:41.544 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:41.779 strm00E3086C Start talksprut..
18:08:41.810 strm00E3086C Starting silence
18:08:41.935 strm00E3086C PUT prefetch_cnt=21/7
18:08:41.966 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:42.201 strm00E3086C Start talksprut..
18:08:42.216 strm00E3086C Starting silence
18:08:42.357 strm00E3086C PUT prefetch_cnt=21/7
18:08:42.388 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:42.623 strm00E3086C Start talksprut..
18:08:42.638 strm00E3086C Starting silence
18:08:42.779 strm00E3086C PUT prefetch_cnt=21/7
18:08:42.810 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:43.045 strm00E3086C Start talksprut..
18:08:43.060 strm00E3086C Starting silence
18:08:43.201 strm00E3086C PUT prefetch_cnt=21/7
18:08:43.216 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:43.295 strm00E3086C PUT prefetch_cnt=5/7
18:08:43.326 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:43.357 strm00E3086C PUT prefetch_cnt=3/7
18:08:43.388 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:43.466 strm00E3086C Start talksprut..
18:08:43.482 strm00E3086C Starting silence
18:08:43.779 strm00E3086C PUT prefetch_cnt=21/7
18:08:43.810 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:43.857 strm00E3086C PUT prefetch_cnt=4/7
18:08:43.873 strm00E3086C PUT prefetch_cnt=5/7
18:08:43.888 strm00E3086C Start talksprut..
18:08:43.904 strm00E3086C PUT prefetch_cnt=6/7
18:08:43.904 strm00E3086C Starting silence
18:08:43.920 strm00E3086C PUT prefetch_cnt=7/7
18:08:43.966 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:44.295 strm00E3086C PUT prefetch_cnt=18/7
18:08:44.310 strm00E3086C Start talksprut..
18:08:44.326 strm00E3086C Starting silence
18:08:44.420 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:44.717 strm00E3086C Start talksprut..
18:08:44.748 strm00E3086C Starting silence
18:08:44.810 strm00E3086C PUT prefetch_cnt=21/7
18:08:44.842 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:45.013 strm00E3086C PUT prefetch_cnt=10/7
18:08:45.045 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:45.138 strm00E3086C Start talksprut..
18:08:45.170 strm00E3086C Starting silence
18:08:45.201 strm00E3086C PUT prefetch_cnt=9/7
18:08:45.420 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:45.560 strm00E3086C Start talksprut..
18:08:45.576 strm00E3086C Starting silence
18:08:45.810 strm00E3086C PUT prefetch_cnt=21/7
18:08:45.842 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:45.888 strm00E3086C Start talksprut..
18:08:46.060 strm00E3086C Starting silence
18:08:46.232 strm00E3086C PUT prefetch_cnt=21/7
18:08:46.263 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:46.467 strm00E3086C Start talksprut..
18:08:46.482 strm00E3086C Starting silence
18:08:46.498 strm00E3086C PUT prefetch_cnt=13/7
18:08:46.607 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:46.889 strm00E3086C Start talksprut..
18:08:46.904 strm00E3086C Starting silence
18:08:46.998 strm00E3086C PUT prefetch_cnt=21/7
18:08:47.029 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:47.139 strm00E3086C PUT prefetch_cnt=7/7
18:08:47.310 strm00E3086C Start talksprut..
18:08:47.326 strm00E3086C Starting silence
18:08:47.529 strm00E3086C Jitter buffer empty (prefetch=7)
18:08:47.607 strm00E3086C Start talksprut..
18:08:47.607 strm00E3086C PUT prefetch_cnt=6/7
18:08:47.623 strm00E3086C jb updated(1), prefetch=6, size=1
18:08:47.623 strm00E3086C Starting silence
18:08:47.639 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:47.717 strm00E3086C PUT prefetch_cnt=5/6
18:08:47.748 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:47.826 strm00E3086C Start talksprut..
18:08:47.842 strm00E3086C Starting silence
18:08:47.920 strm00E3086C Start talksprut..
18:08:48.107 strm00E3086C Starting silence
18:08:48.139 strm00E3086C PUT prefetch_cnt=21/6
18:08:48.170 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:48.498 strm00E3086C Start talksprut..
18:08:48.529 strm00E3086C Starting silence
18:08:48.561 strm00E3086C PUT prefetch_cnt=21/6
18:08:48.576 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:48.920 strm00E3086C Start talksprut..
18:08:48.936 strm00E3086C Starting silence
18:08:48.967 strm00E3086C PUT prefetch_cnt=21/6
18:08:48.998 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:49.342 strm00E3086C Start talksprut..
18:08:49.357 strm00E3086C Starting silence
18:08:49.389 strm00E3086C PUT prefetch_cnt=21/6
18:08:49.420 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:49.764 strm00E3086C Start talksprut..
18:08:49.779 strm00E3086C Starting silence
18:08:49.811 strm00E3086C PUT prefetch_cnt=21/6
18:08:49.842 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:49.920 strm00E3086C PUT prefetch_cnt=5/6
18:08:49.936 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:50.186 strm00E3086C Start talksprut..
18:08:50.201 strm00E3086C Starting silence
18:08:50.326 strm00E3086C PUT prefetch_cnt=21/6
18:08:50.358 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:50.420 strm00E3086C PUT prefetch_cnt=4/6
18:08:50.436 strm00E3086C PUT prefetch_cnt=5/6
18:08:50.451 strm00E3086C PUT prefetch_cnt=6/6
18:08:50.498 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:50.514 strm00E3086C PUT prefetch_cnt=2/6
18:08:50.529 strm00E3086C PUT prefetch_cnt=3/6
18:08:50.545 strm00E3086C Start talksprut..
18:08:50.561 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:50.561 strm00E3086C Starting silence
18:08:50.576 strm00E3086C Start talksprut..
18:08:50.623 strm00E3086C Starting silence
18:08:50.951 strm00E3086C PUT prefetch_cnt=21/6
18:08:50.983 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:51.014 strm00E3086C PUT prefetch_cnt=3/6
18:08:51.029 strm00E3086C Start talksprut..
18:08:51.045 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:51.045 strm00E3086C Starting silence
18:08:51.248 strm00E3086C PUT prefetch_cnt=12/6
18:08:51.279 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:51.436 strm00E3086C Start talksprut..
18:08:51.467 strm00E3086C Starting silence
18:08:51.529 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:08:51.529 tdta00DFB3F8 Destroying txdata raw
18:08:51.654 strm00E3086C PUT prefetch_cnt=20/6
18:08:51.686 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:51.717 strm00E3086C PUT prefetch_cnt=3/6
18:08:51.748 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:51.858 strm00E3086C Start talksprut..
18:08:51.889 strm00E3086C Starting silence
18:08:52.014 strm00E3086C PUT prefetch_cnt=15/6
18:08:52.045 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:52.280 strm00E3086C PUT prefetch_cnt=13/6
18:08:52.280 strm00E3086C Start talksprut..
18:08:52.295 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:52.311 strm00E3086C Starting silence
18:08:52.436 strm00E3086C PUT prefetch_cnt=8/6
18:08:52.561 strm00E3086C Start talksprut..
18:08:52.576 strm00E3086C Starting silence
18:08:52.623 strm00E3086C Start talksprut..
18:08:52.639 strm00E3086C Starting silence
18:08:52.795 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:53.045 strm00E3086C Start talksprut..
18:08:53.061 strm00E3086C Starting silence
18:08:53.201 strm00E3086C PUT prefetch_cnt=21/6
18:08:53.217 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:53.420 strm00E3086C Start talksprut..
18:08:53.608 strm00E3086C Starting silence
18:08:53.608 strm00E3086C PUT prefetch_cnt=21/6
18:08:53.639 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:53.748 strm00E3086C PUT prefetch_cnt=7/6
18:08:53.780 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:53.920 strm00E3086C PUT prefetch_cnt=8/6
18:08:53.967 strm00E3086C Start talksprut..
18:08:54.076 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:54.123 strm00E3086C Starting silence
18:08:54.467 strm00E3086C PUT prefetch_cnt=21/6
18:08:54.498 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:54.530 strm00E3086C Start talksprut..
18:08:54.545 strm00E3086C Starting silence
18:08:54.889 strm00E3086C PUT prefetch_cnt=21/6
18:08:54.920 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:54.936 strm00E3086C Start talksprut..
18:08:54.967 strm00E3086C Starting silence
18:08:54.998 strm00E3086C PUT prefetch_cnt=5/6
18:08:55.030 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:55.092 strm00E3086C PUT prefetch_cnt=5/6
18:08:55.123 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:55.358 strm00E3086C Start talksprut..
18:08:55.389 strm00E3086C Starting silence
18:08:55.514 strm00E3086C PUT prefetch_cnt=21/6
18:08:55.545 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:55.655 strm00E3086C PUT prefetch_cnt=7/6
18:08:55.686 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:55.780 strm00E3086C Start talksprut..
18:08:55.795 strm00E3086C Starting silence
18:08:55.998 strm00E3086C Start talksprut..
18:08:56.030 strm00E3086C Starting silence
18:08:56.077 strm00E3086C PUT prefetch_cnt=21/6
18:08:56.077 strm00E3086C Start talksprut..
18:08:56.108 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:56.108 strm00E3086C Starting silence
18:08:56.233 strm00E3086C PUT prefetch_cnt=8/6
18:08:56.264 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:56.295 strm00E3086C PUT prefetch_cnt=3/6
18:08:56.327 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:56.374 strm00E3086C PUT prefetch_cnt=4/6
18:08:56.405 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:56.420 strm00E3086C PUT prefetch_cnt=2/6
18:08:56.436 strm00E3086C PUT prefetch_cnt=3/6
18:08:56.452 strm00E3086C PUT prefetch_cnt=4/6
18:08:56.483 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:56.499 strm00E3086C Start talksprut..
18:08:56.530 strm00E3086C Starting silence
18:08:56.874 strm00E3086C PUT prefetch_cnt=21/6
18:08:56.905 strm00E3086C Jitter buffer empty (prefetch=6)
18:08:56.920 strm00E3086C Start talksprut..
18:08:56.936 strm00E3086C Starting silence
18:08:57.077 strm00E3086C PUT prefetch_cnt=10/6
18:08:57.124 strm00E3086C Start talksprut..
18:08:57.420 strm00E3086C Starting silence
18:08:57.530 strm00E3086C Start talksprut..
18:08:57.702 strm00E3086C Starting silence
18:08:57.795 strm00E3086C jb updated(1), prefetch=5, size=1
18:08:57.905 strm00E3086C Jitter buffer empty (prefetch=5)
18:08:57.936 strm00E3086C PUT prefetch_cnt=3/5
18:08:57.936 strm00E3086C Start talksprut..
18:08:57.952 strm00E3086C PUT prefetch_cnt=4/5
18:08:57.967 strm00E3086C Starting silence
18:08:57.983 strm00E3086C PUT prefetch_cnt=5/5
18:08:57.999 strm00E3086C Jitter buffer empty (prefetch=5)
18:08:58.014 strm00E3086C PUT prefetch_cnt=2/5
18:08:58.030 strm00E3086C PUT prefetch_cnt=3/5
18:08:58.061 strm00E3086C PUT prefetch_cnt=4/5
18:08:58.077 strm00E3086C PUT prefetch_cnt=5/5
18:08:58.249 strm00E3086C Jitter buffer empty (prefetch=5)
18:08:58.280 strm00E3086C PUT prefetch_cnt=3/5
18:08:58.296 strm00E3086C PUT prefetch_cnt=4/5
18:08:58.311 strm00E3086C PUT prefetch_cnt=5/5
18:08:58.358 strm00E3086C Start talksprut..
18:08:58.389 strm00E3086C Starting silence
18:08:58.467 strm00E3086C Jitter buffer empty (prefetch=5)
18:08:58.530 strm00E3086C PUT prefetch_cnt=5/5
18:08:58.624 strm00E3086C Jitter buffer empty (prefetch=5)
18:08:58.639 strm00E3086C PUT prefetch_cnt=2/5
18:08:58.655 strm00E3086C PUT prefetch_cnt=3/5
18:08:58.671 strm00E3086C PUT prefetch_cnt=4/5
18:08:58.702 strm00E3086C PUT prefetch_cnt=5/5
18:08:58.717 strm00E3086C Jitter buffer empty (prefetch=5)
18:08:58.780 strm00E3086C Start talksprut..
18:08:58.796 strm00E3086C Starting silence
18:08:58.921 strm00E3086C PUT prefetch_cnt=11/5
18:08:58.936 strm00E3086C Jitter buffer empty (prefetch=5)
18:08:59.124 strm00E3086C PUT prefetch_cnt=10/5
18:08:59.202 strm00E3086C Start talksprut..
18:08:59.217 strm00E3086C Starting silence
18:08:59.327 strm00E3086C Jitter buffer empty (prefetch=5)
18:08:59.624 strm00E3086C Start talksprut..
18:08:59.639 strm00E3086C Starting silence
18:08:59.717 strm00E3086C PUT prefetch_cnt=21/5
18:08:59.749 strm00E3086C Jitter buffer empty (prefetch=5)
18:09:00.046 strm00E3086C Start talksprut..
18:09:00.061 strm00E3086C Starting silence
18:09:00.139 strm00E3086C PUT prefetch_cnt=21/5
18:09:00.155 strm00E3086C Jitter buffer empty (prefetch=5)
18:09:00.468 strm00E3086C Start talksprut..
18:09:00.483 strm00E3086C Starting silence
18:09:00.561 strm00E3086C PUT prefetch_cnt=21/5
18:09:00.577 strm00E3086C Jitter buffer empty (prefetch=5)
18:09:00.889 strm00E3086C Start talksprut..
18:09:00.905 strm00E3086C Starting silence
18:09:00.983 strm00E3086C PUT prefetch_cnt=21/5
18:09:00.999 strm00E3086C Jitter buffer empty (prefetch=5)
18:09:01.124 strm00E3086C PUT prefetch_cnt=7/5
18:09:01.280 strm00E3086C Jitter buffer empty (prefetch=5)
18:09:01.296 strm00E3086C Start talksprut..
18:09:01.327 strm00E3086C Starting silence
18:09:01.671 strm00E3086C PUT prefetch_cnt=21/5
18:09:01.702 strm00E3086C Jitter buffer empty (prefetch=5)
18:09:01.718 strm00E3086C Start talksprut..
18:09:01.749 strm00E3086C Starting silence
18:09:02.014 sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=5867 (rdata00DE754C)
18:09:02.014 pjsua_core.c RX 1266 bytes Request msg INVITE/cseq=5867 (rdata00DE754C) from UDP 172.18.1.218:4060:
INVITE sip:alice at 172.18.2.74:5060 SIP/2.0
Record-Route: <sip:mt at pcscf.voip3gppsrv2:4060;lr>
Record-Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Max-Forwards: 8
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=z9hG4bK1a09.41feccf5.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;branch=z9hG4bK1a09.c6087fb5.0
Via: SIP/2.0/UDP 172.18.1.218;branch=z9hG4bK1a09.98bc3ec4.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK1a09.feb17ec1.0
To: sip:alice at voip3gppsrv2;tag=eddd2b9b09f74cc0851e94a9043f996f
From: sip:bob@voip3gppsrv2;tag=062ce89b154844dfa30567ae5214c92a
CSeq: 5867 INVITE
Call-ID: fbef225ea1e145d7b409ef1b34b5f316
Content-Length: 456
User-Agent: OpenSIPS (1.4.0-notls (i386/linux))
Contact: <sip:bob at 172.18.1.78:5060>
Content-Type: application/sdp
P-Called-Party-ID: <sip:alice at voip3gppsrv2>
v=0
o=- 3449844533 3449844533 IN IP4 172.18.1.78
s=pjmedia
c=IN IP4 172.18.1.78
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 103 102 104 117 3 0 8 9 101
a=rtcp:4001 IN IP4 172.18.1.78
a=rtpmap:103 speex/16000
a=rtpmap:102 speex/8000
a=rtpmap:104 speex/32000
a=rtpmap:117 iLBC/8000
a=fmtp:117 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
--end msg--
18:09:02.061 dlg00DED8CC Received Request msg INVITE/cseq=5867 (rdata00DE754C)
18:09:02.061 tsx00DF907C Transaction created for Request msg INVITE/cseq=5867 (rdata00DE754C)
18:09:02.061 tsx00DF907C Incoming Request msg INVITE/cseq=5867 (rdata00DE754C) in state Null
18:09:02.061 tsx00DF907C State changed from Null to Trying, event=RX_MSG
18:09:02.061 dlg00DED8CC Transaction tsx00DF907C state changed to Trying
18:09:02.061 inv00DED8CC Got SDP offer in Request msg INVITE/cseq=5867 (rdata00DE754C)
18:09:02.061 pjsua_call.c Call 0: received updated media offer
18:09:02.061 endpoint Response msg 200/INVITE/cseq=5867 (tdta00DEB8C8) created
18:09:02.061 inv00DED8CC SDP negotiation done, status=0
18:09:02.061 pjsua_call.c Call 0: remote NAT type is 0 (Unknown)
18:09:02.061 pjsua_media.c Media session for call 0 is destroyed
18:09:02.061 strm00E3086C VAD temporarily disabled
18:09:02.061 rtp.c pjmedia_rtp_session_init: ses=00E31A40, default_pt=103, ssrc=0x294823
18:09:02.061 rtp.c pjmedia_rtp_session_init: ses=00E31EB4, default_pt=103, ssrc=0x294823
18:09:02.061 stream.c Stream strm00E3086C created
18:09:02.061 strm00E3086C Encoder stream started
18:09:02.061 strm00E3086C Decoder stream started
18:09:02.061 pjsua_media.c Media updates, stream #0: speex (sendrecv)
18:09:02.061 conference.c Port 3 (sip:bob at voip3gppsrv2) transmitting to port 0 (Microsoft Sound Mapper - Input)
18:09:02.061 conference.c Port 0 (Microsoft Sound Mapper - Input) transmitting to port 3 (sip:bob at voip3gppsrv2)
18:09:02.061 pjsua_app.c Media for call 0 is active
18:09:02.077 inv00DED8CC Sending Response msg 200/INVITE/cseq=5867 (tdta00DEB8C8)
18:09:02.077 dlg00DED8CC Sending Response msg 200/INVITE/cseq=5867 (tdta00DEB8C8)
18:09:02.077 tsx00DF907C Sending Response msg 200/INVITE/cseq=5867 (tdta00DEB8C8) in state Trying
18:09:02.077 sip_resolve.c Target '172.18.1.218:4060' type=UDP resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:09:02.077 pjsua_core.c TX 1088 bytes Response msg 200/INVITE/cseq=5867 (tdta00DEB8C8) to UDP 172.18.1.218:4060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.18.1.218:4060;received=172.18.1.218;branch=z9hG4bK1a09.41feccf5.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;branch=z9hG4bK1a09.c6087fb5.0
Via: SIP/2.0/UDP 172.18.1.218;branch=z9hG4bK1a09.98bc3ec4.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK1a09.feb17ec1.0
Record-Route: <sip:mt at pcscf.voip3gppsrv2:4060;lr>
Record-Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Call-ID: fbef225ea1e145d7b409ef1b34b5f316
From: <sip:bob@voip3gppsrv2>;tag=062ce89b154844dfa30567ae5214c92a
To: <sip:alice at voip3gppsrv2>;tag=eddd2b9b09f74cc0851e94a9043f996f
CSeq: 5867 INVITE
Contact: <sip:alice at 172.18.2.74:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length: 254
v=0
o=- 3449844542 3449844507 IN IP4 172.18.2.74
s=pjmedia
c=IN IP4 172.18.2.74
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 103 101
a=rtcp:4001 IN IP4 172.18.2.74
a=rtpmap:103 speex/16000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
--end msg--
18:09:02.093 strm00E3086C Jitter buffer empty (prefetch=0)
18:09:02.108 strm00E3086C Start talksprut..
18:09:02.108 strm00E3086C RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=0
18:09:02.124 tsx00DF907C State changed from Trying to Completed, event=TX_MSG
18:09:02.124 dlg00DED8CC Transaction tsx00DF907C state changed to Completed
18:09:02.124 sip_endpoint.c Processing incoming message: Request msg ACK/cseq=5867 (rdata00DE754C)
18:09:02.124 pjsua_core.c RX 554 bytes Request msg ACK/cseq=5867 (rdata00DE754C) from UDP 172.18.1.218:4060:
ACK sip:alice at 172.18.2.74:5060 SIP/2.0
Max-Forwards: 8
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;branch=0
Via: SIP/2.0/UDP 172.18.1.218;branch=0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK1a09.feb17ec1.0
From: sip:bob@voip3gppsrv2;tag=062ce89b154844dfa30567ae5214c92a
Call-ID: fbef225ea1e145d7b409ef1b34b5f316
To: <sip:alice at voip3gppsrv2>;tag=eddd2b9b09f74cc0851e94a9043f996f
CSeq: 5867 ACK
User-Agent: OpenSIPS (1.4.0-notls (i386/linux))
Content-Length: 0
P-hint: I-CSCF rr-enforced
?
--end msg--
18:09:02.140 strm00E3086C Jitter buffer empty (prefetch=0)
18:09:02.155 udp00DE9D38 Remote RTCP address switched to 172.18.1.222:4001
18:09:02.155 udp00DE9D38 Remote RTCP address switched to 172.18.1.78:4001
18:09:02.155 dlg00DED8CC Received Request msg ACK/cseq=5867 (rdata00DE754C)
18:09:02.155 tsx00DF907C Request to terminate transaction
18:09:02.155 tsx00DF907C State changed from Completed to Terminated, event=USER
18:09:02.155 dlg00DED8CC Transaction tsx00DF907C state changed to Terminated
18:09:02.155 tsx00DF907C Timeout timer event
18:09:02.155 tsx00DF907C State changed from Terminated to Destroyed, event=TIMER
18:09:02.155 tdta00DEB8C8 Destroying txdata Response msg 200/INVITE/cseq=5867 (tdta00DEB8C8)
18:09:02.155 tsx00DF907C Transaction destroyed!
18:09:02.155 strm00E3086C RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=-1, restart=0
18:09:02.186 strm00E3086C jb updated(2), prefetch=1, size=0
18:09:02.702 strm00E3086C VAD re-enabled
18:09:02.874 strm00E3086C Starting silence
18:09:03.280 strm00E3086C Start talksprut..
18:09:03.296 strm00E3086C Starting silence
18:09:03.436 strm00E3086C Start talksprut..
18:09:03.686 strm00E3086C Starting silence
18:09:04.077 strm00E3086C Start talksprut..
18:09:04.108 strm00E3086C Starting silence
18:09:04.499 strm00E3086C Start talksprut..
18:09:04.515 strm00E3086C Starting silence
18:09:04.765 strm00E3086C Start talksprut..
18:09:05.202 strm00E3086C Starting silence
18:09:05.265 strm00E3086C Start talksprut..
18:09:05.280 strm00E3086C Starting silence
18:09:05.687 strm00E3086C Start talksprut..
18:09:05.702 strm00E3086C Starting silence
18:09:06.109 strm00E3086C Start talksprut..
18:09:06.124 strm00E3086C Starting silence
18:09:06.515 strm00E3086C Start talksprut..
18:09:06.530 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:09:06.530 tdta00DEB8C8 Destroying txdata raw
18:09:06.546 strm00E3086C Starting silence
18:09:06.702 sound_port.c EC suspended because of inactivity
18:09:06.780 strm00E3086C Start talksprut..
18:09:09.015 strm00E3086C Starting silence
18:09:09.421 strm00E3086C Start talksprut..
18:09:09.437 strm00E3086C Starting silence
18:09:09.843 strm00E3086C Start talksprut..
18:09:09.859 strm00E3086C Starting silence
18:09:10.265 strm00E3086C Start talksprut..
18:09:10.281 strm00E3086C Starting silence
18:09:10.656 strm00E3086C Start talksprut..
18:09:11.093 strm00E3086C Starting silence
18:09:11.499 strm00E3086C Start talksprut..
18:09:11.515 strm00E3086C Starting silence
18:09:11.921 strm00E3086C Start talksprut..
18:09:11.937 strm00E3086C Starting silence
18:09:12.343 strm00E3086C Start talksprut..
18:09:12.359 strm00E3086C Starting silence
18:09:12.437 strm00E3086C Start talksprut..
18:09:12.468 strm00E3086C Starting silence
18:09:12.562 strm00E3086C Start talksprut..
18:09:12.578 strm00E3086C Starting silence
18:09:12.984 strm00E3086C Start talksprut..
18:09:13.000 strm00E3086C Starting silence
18:09:13.406 strm00E3086C Start talksprut..
18:09:13.421 strm00E3086C Starting silence
18:09:13.828 strm00E3086C Start talksprut..
18:09:13.843 strm00E3086C Starting silence
18:09:14.234 strm00E3086C Start talksprut..
18:09:14.265 strm00E3086C Starting silence
18:09:14.656 strm00E3086C Start talksprut..
18:09:14.687 strm00E3086C Starting silence
18:09:14.687 endpoint Request msg BYE/cseq=9210 (tdta00DEB8C8) created.
18:09:14.687 inv00DED8CC Sending Request msg BYE/cseq=9210 (tdta00DEB8C8)
18:09:14.687 dlg00DED8CC Sending Request msg BYE/cseq=9210 (tdta00DEB8C8)
18:09:14.687 tsx00DF907C Transaction created for Request msg BYE/cseq=9209 (tdta00DEB8C8)
18:09:14.687 tsx00DF907C Sending Request msg BYE/cseq=9209 (tdta00DEB8C8) in state Null
18:09:14.687 sip_resolve.c DNS resolver not available, target 'pcscf.voip3gppsrv2:4060' type=Unspecified will be resolved with gethostbyname()
18:09:14.687 sip_resolve.c Target 'pcscf.voip3gppsrv2:4060' type=Unspecified resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:09:14.687 pjsua_core.c TX 814 bytes Request msg BYE/cseq=9209 (tdta00DEB8C8) to UDP 172.18.1.218:4060:
BYE sip:bob at 172.18.1.78:5060 SIP/2.0
Via: SIP/2.0/UDP 172.18.2.74:5060;rport;branch=z9hG4bKPj34a8526d58ab4f5885575012224fac43
Max-Forwards: 70
From: <sip:alice@voip3gppsrv2>;tag=eddd2b9b09f74cc0851e94a9043f996f
To: <sip:bob at voip3gppsrv2>;tag=062ce89b154844dfa30567ae5214c92a
Call-ID: fbef225ea1e145d7b409ef1b34b5f316
CSeq: 9209 BYE
Route: <sip:mt at pcscf.voip3gppsrv2:4060;lr>
Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Route: <sip:172.18.1.218:5065;lr;ftag=062ce89b154844dfa30567ae5214c92a>
Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Route: <sip:mo at pcscf.voip3gppsrv2:4060;lr>
Authorization: Digest username="alice at voip3gppsrv2", realm="voip3gppsrv2", nonce="", uri="sip:bob at 172.18.1.78:5060", response=""
User-Agent: PJSUA v1.1/win32
Content-Length: 0
?
--end msg--
18:09:14.703 tsx00DF907C State changed from Null to Calling, event=TX_MSG
18:09:14.703 dlg00DED8CC Transaction tsx00DF907C state changed to Calling
18:09:14.718 sip_endpoint.c Processing incoming message: Response msg 400/BYE/cseq=9209 (rdata00DE754C)
18:09:14.718 pjsua_core.c RX 623 bytes Response msg 400/BYE/cseq=9209 (rdata00DE754C) from UDP 172.18.1.218:4060:
SIP/2.0 400 Bad Request - Not following indicated dialog routes
Via: SIP/2.0/UDP 172.18.2.74:5060;rport=5060;branch=z9hG4bKPj34a8526d58ab4f5885575012224fac43
From: <sip:alice@voip3gppsrv2>;tag=eddd2b9b09f74cc0851e94a9043f996f
To: <sip:bob at voip3gppsrv2>;tag=062ce89b154844dfa30567ae5214c92a
Call-ID: fbef225ea1e145d7b409ef1b34b5f316
CSeq: 9209 BYE
Server: Sip EXpress router (2.1.0-dev1 OpenIMSCore (i386/linux))
Content-Length: 0
Warning: 392 172.18.1.218:4060 "Noisy feedback tells: pid=5328 req_src_ip=172.18.2.74 req_src_port=5060 in_uri=sip:bob at 172.18.1.78:5060 out_uri=sip:bob at 172.18.1.78:5060 via_cnt==1"
?
--end msg--
18:09:14.734 tsx00DF907C Incoming Response msg 400/BYE/cseq=9209 (rdata00DE754C) in state Calling
18:09:14.734 tsx00DF907C State changed from Calling to Completed, event=RX_MSG
18:09:14.734 dlg00DED8CC Received Response msg 400/BYE/cseq=9209 (rdata00DE754C)
18:09:14.734 dlg00DED8CC Transaction tsx00DF907C state changed to Completed
18:09:14.734 pjsua_app.c Call 0 is DISCONNECTED [reason=200 (Normal call clearing)]
18:09:14.734 pjsua_app.c Call 0 disconnected, dumping media stats..
18:09:14.734 pjsua_app.c 
[DISCONNCTD] To: <sip:bob at voip3gppsrv2>;tag=062ce89b154844dfa30567ae5214c92a
Call time: 00h:00m:49s, 1st res in 234 ms, conn in 406ms
SRTP status: Not active Crypto-suite: (null)
#0 speex @16KHz, sendrecv, peer=172.18.1.78:4000
RX pt=103, stat last update: 00h:00m:02.609s ago
total 171pkt 9.4KB (16.2KB +IP hdr) @avg=5.9Kbps/10.2Kbps
pkt loss=0 (0.0%), discrd=1 (0.6%), 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.503 11.437 0.062 1.416
TX pt=103, ptime=20ms, stat last update: 00h:00m:02.500s ago
total 228pkt 14.4KB (23.5KB +IP hdr) @avg 9.1Kbps/14.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 : 0.000 0.187 0.312 0.312 0.134
RTT msec : 0.991 1.014 1.037 0.991 0.023
18:09:14.765 pjsua_media.c Media session for call 0 is destroyed
18:09:14.765 dlg00DED8CC Session count dec to 1 by mod-invite
18:09:15.765 pjsua_media.c Closing sound device after idle for 1 seconds
18:09:15.765 pjsua_media.c Closing Microsoft Sound Mapper - Output sound playback device and Microsoft Sound Mapper - Input sound capture device
18:09:15.781 pa_dev.c Stopping stream..
18:09:15.781 pa_dev.c PA message: WinMME StopStream: waiting for background thread.
18:09:15.859 pa_dev.c PA message: WinMME StopStream: waiting for background thread.
18:09:15.875 pa_dev.c Done, status=0
18:09:15.875 pa_dev.c Closing Microsoft Sound Mapper - Input: 0 underflow, 0 overflow
18:09:19.766 tsx00DF907C Timeout timer event
18:09:19.766 tsx00DF907C State changed from Completed to Terminated, event=TIMER
18:09:19.766 dlg00DED8CC Transaction tsx00DF907C state changed to Terminated
18:09:19.766 dlg00DED8CC Dialog destroyed
18:09:19.766 tsx00DF907C Timeout timer event
18:09:19.766 tsx00DF907C State changed from Terminated to Destroyed, event=TIMER
18:09:19.766 tdta00DEB8C8 Destroying txdata Request msg BYE/cseq=9209 (tdta00DEB8C8)
18:09:19.766 tsx00DF907C Transaction destroyed!
18:09:21.531 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:09:21.531 tdta00DF8BB8 Destroying txdata raw
18:09:36.532 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:09:36.532 tdta00DF8BB8 Destroying txdata raw
18:09:51.533 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:09:51.533 tdta00DF8BB8 Destroying txdata raw
18:10:00.925 sip_endpoint.c Processing incoming message: Request msg BYE/cseq=5869 (rdata00DE754C)
18:10:00.925 pjsua_core.c RX 563 bytes Request msg BYE/cseq=5869 (rdata00DE754C) from UDP 172.18.1.218:4060:
BYE sip:alice at 172.18.2.74:5060 SIP/2.0
Max-Forwards: 9
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=z9hG4bKea09.262408f4.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;branch=z9hG4bKea09.46a96585.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bKea09.1ae24474.0
To: sip:alice at voip3gppsrv2;tag=eddd2b9b09f74cc0851e94a9043f996f
From: sip:bob@voip3gppsrv2;tag=062ce89b154844dfa30567ae5214c92a
CSeq: 5869 BYE
Call-ID: fbef225ea1e145d7b409ef1b34b5f316
Content-Length: 0
User-Agent: OpenSIPS (1.4.0-notls (i386/linux))
Contact: <sip:bob at 172.18.1.78:5060>
?
--end msg--
18:10:00.940 sip_ua_layer.c Unable to find dialogset for Request msg BYE/cseq=5869 (rdata00DE754C), answering with 481
18:10:00.940 endpoint Response msg 481/BYE/cseq=5869 (tdta00DF8BB8) created
18:10:00.940 sip_resolve.c Target '172.18.1.218:4060' type=UDP resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:10:00.940 pjsua_core.c TX 491 bytes Response msg 481/BYE/cseq=5869 (tdta00DF8BB8) to UDP 172.18.1.218:4060:
SIP/2.0 481 Call/Transaction Does Not Exist
Via: SIP/2.0/UDP 172.18.1.218:4060;received=172.18.1.218;branch=z9hG4bKea09.262408f4.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;branch=z9hG4bKea09.46a96585.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bKea09.1ae24474.0
Call-ID: fbef225ea1e145d7b409ef1b34b5f316
From: <sip:bob@voip3gppsrv2>;tag=062ce89b154844dfa30567ae5214c92a
To: <sip:alice at voip3gppsrv2>;tag=eddd2b9b09f74cc0851e94a9043f996f
CSeq: 5869 BYE
Content-Length: 0
?
--end msg--
18:10:00.971 tdta00DF8BB8 Destroying txdata Response msg 481/BYE/cseq=5869 (tdta00DF8BB8)
18:10:06.534 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:10:06.534 tdta00DF8BB8 Destroying txdata raw
18:10:17.519 sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=21779 (rdata00DE754C)
18:10:17.519 pjsua_core.c <logging error: msg too long>
18:10:17.519 pjsua_media.c Media index 0 selected for call 1
18:10:17.519 tsx00DEA95C Transaction created for Request msg INVITE/cseq=21779 (rdata00DE754C)
18:10:17.519 tsx00DEA95C Incoming Request msg INVITE/cseq=21779 (rdata00DE754C) in state Null
18:10:17.519 tsx00DEA95C State changed from Null to Trying, event=RX_MSG
18:10:17.519 dlg00DFC08C Transaction tsx00DEA95C state changed to Trying
18:10:17.519 dlg00DFC08C UAS dialog created
18:10:17.519 dlg00DFC08C Module mod-invite added as dialog usage, data=00DF9DCC
18:10:17.519 dlg00DFC08C Session count inc to 2 by mod-invite
18:10:17.519 inv00DFC08C UAS invite session created for dialog dlg00DFC08C
18:10:17.535 pjsua_call.c Call 1: remote NAT type is 0 (Unknown)
18:10:17.535 endpoint Response msg 100/INVITE/cseq=21779 (tdta00DEC448) created
18:10:17.535 dlg00DFC08C Initial answer Response msg 100/INVITE/cseq=21779 (tdta00DEC448)
18:10:17.535 inv00DFC08C Sending Response msg 100/INVITE/cseq=21779 (tdta00DEC448)
18:10:17.535 dlg00DFC08C Sending Response msg 100/INVITE/cseq=21779 (tdta00DEC448)
18:10:17.535 tsx00DEA95C Sending Response msg 100/INVITE/cseq=21779 (tdta00DEC448) in state Trying
18:10:17.535 sip_resolve.c Target '172.18.1.218:4060' type=UDP resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:10:17.535 pjsua_core.c TX 1142 bytes Response msg 100/INVITE/cseq=21779 (tdta00DEC448) to UDP 172.18.1.218:4060:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.18.1.218:4060;received=172.18.1.218;branch=z9hG4bKb42f.fb5c6986.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;received=172.18.1.218;branch=z9hG4bKb42f.c6065a34.0
Via: SIP/2.0/UDP 172.18.1.218;branch=z9hG4bKb42f.09075161.0
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=z9hG4bKb42f.b6065a34.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bKb42f.97e4e9.0
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=z9hG4bKb42f.a6065a34.0
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=z9hG4bKb42f.eb5c6986.0
Via: SIP/2.0/UDP 172.18.1.78:5060;rport=5060;branch=z9hG4bKPj860d814952d8408a9b8e0dbeff7bdb90
Record-Route: <sip:mt at pcscf.voip3gppsrv2:4060;lr>
Record-Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:172.18.1.218:5065;lr;ftag=d1668b6ac642456cbfbd4f2c1a301227>
Record-Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:mo at pcscf.voip3gppsrv2:4060;lr>
Call-ID: 0f23cac12e744ad1866cd555948b4b6e
From: <sip:bob@voip3gppsrv2>;tag=d1668b6ac642456cbfbd4f2c1a301227
To: <sip:alice at voip3gppsrv2>
CSeq: 21779 INVITE
Content-Length: 0
?
--end msg--
18:10:17.551 tsx00DEA95C State changed from Trying to Proceeding, event=TX_MSG
18:10:17.551 dlg00DFC08C Transaction tsx00DEA95C state changed to Proceeding
18:10:17.551 pjsua_media.c Opening sound device PCM at 16000/1/20ms
18:10:17.582 pa_dev.c Opened device Microsoft Sound Mapper - Input(MME)/Microsoft Sound Mapper - Output(MME) for recording and playback, sample rate=16000, ch=1, bits=16, 320 samples per frame, input latency=100 ms, output latency=100 ms
18:10:17.582 ec00DFCA88 Creating AEC
18:10:17.582 ec00DFCA88 AEC created, clock_rate=16000, channel=1, samples per frame=320, tail length=200 ms, latency=100 ms
18:10:17.582 pa_dev.c Starting Microsoft Sound Mapper - Input stream..
18:10:17.597 pa_dev.c PA message: Pa_StartStream: waveInStart returned = 0x0.
18:10:17.597 pa_dev.c Done, status=0
18:10:17.597 conference.c Port 2 (ring) transmitting to port 0 (Microsoft Sound Mapper - Input)
18:10:17.597 inv00DFC08C SDP negotiation done, status=0
18:10:17.597 pjsua_call.c Call 1: remote NAT type is 0 (Unknown)
18:10:17.597 strm00E2A164 VAD temporarily disabled
18:10:17.597 rtp.c pjmedia_rtp_session_init: ses=00E2B338, default_pt=103, ssrc=0x6d5c2c8f
18:10:17.597 rtp.c pjmedia_rtp_session_init: ses=00E2B7AC, default_pt=103, ssrc=0x6d5c2c8f
18:10:17.597 stream.c Stream strm00E2A164 created
18:10:17.597 strm00E2A164 Encoder stream started
18:10:17.597 strm00E2A164 Decoder stream started
18:10:17.597 pjsua_media.c Media updates, stream #0: speex (sendrecv)
18:10:17.597 conference.c Port 2 (ring) stop transmitting to port 0 (Microsoft Sound Mapper - Input)
18:10:17.597 conference.c Port 3 (sip:bob at voip3gppsrv2) transmitting to port 0 (Microsoft Sound Mapper - Input)
18:10:17.597 conference.c Port 0 (Microsoft Sound Mapper - Input) transmitting to port 3 (sip:bob at voip3gppsrv2)
18:10:17.597 pjsua_app.c Media for call 1 is active
18:10:17.597 inv00DFC08C Sending Response msg 200/INVITE/cseq=21779 (tdta00DEC448)
18:10:17.597 dlg00DFC08C Sending Response msg 200/INVITE/cseq=21779 (tdta00DEC448)
18:10:17.597 tsx00DEA95C Sending Response msg 200/INVITE/cseq=21779 (tdta00DEC448) in state Proceeding
18:10:17.597 pjsua_core.c TX 1635 bytes Response msg 200/INVITE/cseq=21779 (tdta00DEC448) to UDP 172.18.1.218:4060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.18.1.218:4060;received=172.18.1.218;branch=z9hG4bKb42f.fb5c6986.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;received=172.18.1.218;branch=z9hG4bKb42f.c6065a34.0
Via: SIP/2.0/UDP 172.18.1.218;branch=z9hG4bKb42f.09075161.0
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=z9hG4bKb42f.b6065a34.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bKb42f.97e4e9.0
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=z9hG4bKb42f.a6065a34.0
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=z9hG4bKb42f.eb5c6986.0
Via: SIP/2.0/UDP 172.18.1.78:5060;rport=5060;branch=z9hG4bKPj860d814952d8408a9b8e0dbeff7bdb90
Record-Route: <sip:mt at pcscf.voip3gppsrv2:4060;lr>
Record-Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:172.18.1.218:5065;lr;ftag=d1668b6ac642456cbfbd4f2c1a301227>
Record-Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:mo at pcscf.voip3gppsrv2:4060;lr>
Call-ID: 0f23cac12e744ad1866cd555948b4b6e
From: <sip:bob@voip3gppsrv2>;tag=d1668b6ac642456cbfbd4f2c1a301227
To: <sip:alice at voip3gppsrv2>;tag=bc27d41fb5ea4706839220367a190b5e
CSeq: 21779 INVITE
Contact: <sip:alice at 172.18.2.74:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length: 254
v=0
o=- 3449844617 3449844618 IN IP4 172.18.2.74
s=pjmedia
c=IN IP4 172.18.2.74
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 103 101
a=rtcp:4003 IN IP4 172.18.2.74
a=rtpmap:103 speex/16000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
--end msg--
18:10:17.629 pa_dev.c Player thread started
18:10:17.629 strm00E2A164 Jitter buffer empty (prefetch=0)
18:10:17.629 strm00E2A164 Start talksprut..
18:10:17.629 pa_dev.c Recorder thread started
18:10:17.629 ec00DFCA88 Prefetching..
18:10:17.660 ec00DFCA88 Prefetching..
18:10:17.660 ec00DFCA88 Prefetching..
18:10:17.676 tsx00DEA95C State changed from Proceeding to Completed, event=TX_MSG
18:10:17.676 dlg00DFC08C Transaction tsx00DEA95C state changed to Completed
18:10:17.676 pjsua_app.c Call 1 state changed to CONNECTING
18:10:17.676 ec00DFCA88 Prefetching..
18:10:17.676 Master/sound 333 samples reduced, buf_cnt=627
18:10:17.676 Master/sound Buffer size adjusted from 960 to 627 (eff_cnt=376)
18:10:17.691 ec00DFCA88 Prefetching..
18:10:17.707 strm00E2A164 RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=0
18:10:17.722 ec00DFCA88 Prefetching..
18:10:17.722 sip_endpoint.c Processing incoming message: Request msg ACK/cseq=21779 (rdata00DE754C)
18:10:17.722 pjsua_core.c RX 769 bytes Request msg ACK/cseq=21779 (rdata00DE754C) from UDP 172.18.1.218:5065:
ACK sip:alice at 172.18.2.74:5060 SIP/2.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bKb42f.97e4e9.2
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=0
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=0
Via: SIP/2.0/UDP 172.18.1.78:5060;rport=5060;branch=z9hG4bKPjd0298f60fd814d3b9b20f3fe1cecf20c
Max-Forwards: 14
From: sip:bob@voip3gppsrv2;tag=d1668b6ac642456cbfbd4f2c1a301227
To: sip:alice at voip3gppsrv2;tag=bc27d41fb5ea4706839220367a190b5e
Call-ID: 0f23cac12e744ad1866cd555948b4b6e
CSeq: 21779 ACK
Route: <sip:172.18.1.218:5065;lr;ftag=d1668b6ac642456cbfbd4f2c1a301227>
Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Route: <sip:mt at pcscf.voip3gppsrv2:4060;lr>
Content-Length: 0
P-Asserted-Identity: <sip:bob at voip3gppsrv2>
?
--end msg--
18:10:17.738 ec00DFCA88 Prefetching..
18:10:17.738 strm00E2A164 jb updated(2), prefetch=1, size=2
18:10:17.754 ec00DFCA88 Latency bufferring complete
18:10:17.754 dlg00DFC08C Received Request msg ACK/cseq=21779 (rdata00DE754C)
18:10:17.754 tsx00DEA95C Request to terminate transaction
18:10:17.754 tsx00DEA95C State changed from Completed to Terminated, event=USER
18:10:17.754 dlg00DFC08C Transaction tsx00DEA95C state changed to Terminated
18:10:17.754 pjsua_app.c Call 1 state changed to CONFIRMED
18:10:17.754 tsx00DEA95C Timeout timer event
18:10:17.754 tsx00DEA95C State changed from Terminated to Destroyed, event=TIMER
18:10:17.754 tdta00DEC448 Destroying txdata Response msg 200/INVITE/cseq=21779 (tdta00DEC448)
18:10:17.754 tsx00DEA95C Transaction destroyed!
18:10:17.754 strm00E2A164 PUT prefetch_cnt=1/1
18:10:18.238 strm00E2A164 VAD re-enabled
18:10:18.723 strm00E2A164 Starting silence
18:10:19.004 strm00E2A164 Start talksprut..
18:10:19.019 strm00E2A164 Starting silence
18:10:19.269 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:19.316 strm00E2A164 PUT prefetch_cnt=4/1
18:10:19.363 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:19.379 strm00E2A164 Start talksprut..
18:10:19.394 strm00E2A164 PUT prefetch_cnt=3/1
18:10:19.410 strm00E2A164 Starting silence
18:10:19.426 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:19.426 strm00E2A164 PUT prefetch_cnt=2/1
18:10:19.457 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:19.488 strm00E2A164 PUT prefetch_cnt=3/1
18:10:19.519 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:19.754 strm00E2A164 PUT prefetch_cnt=13/1
18:10:19.785 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:19.801 strm00E2A164 Start talksprut..
18:10:19.832 strm00E2A164 Starting silence
18:10:20.113 strm00E2A164 PUT prefetch_cnt=18/1
18:10:20.144 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:20.144 strm00E2A164 PUT prefetch_cnt=2/1
18:10:20.191 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:20.223 strm00E2A164 Start talksprut..
18:10:20.238 strm00E2A164 Starting silence
18:10:20.566 strm00E2A164 PUT prefetch_cnt=21/1
18:10:20.582 strm00E2A164 Start talksprut..
18:10:20.598 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:20.598 strm00E2A164 Starting silence
18:10:20.988 strm00E2A164 PUT prefetch_cnt=21/1
18:10:21.004 strm00E2A164 Start talksprut..
18:10:21.020 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:21.020 strm00E2A164 Starting silence
18:10:21.098 strm00E2A164 PUT prefetch_cnt=5/1
18:10:21.129 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:21.145 strm00E2A164 PUT prefetch_cnt=3/1
18:10:21.426 strm00E2A164 Start talksprut..
18:10:21.441 strm00E2A164 Starting silence
18:10:21.535 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:10:21.535 tdta00DEC448 Destroying txdata raw
18:10:21.801 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:21.848 strm00E2A164 Start talksprut..
18:10:21.863 strm00E2A164 Starting silence
18:10:21.926 strm00E2A164 PUT prefetch_cnt=8/1
18:10:21.957 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:21.973 strm00E2A164 PUT prefetch_cnt=2/1
18:10:22.020 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:22.145 strm00E2A164 PUT prefetch_cnt=8/1
18:10:22.192 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:22.270 strm00E2A164 Start talksprut..
18:10:22.285 strm00E2A164 Starting silence
18:10:22.426 strm00E2A164 PUT prefetch_cnt=14/1
18:10:22.457 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:22.504 strm00E2A164 PUT prefetch_cnt=4/1
18:10:22.551 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:22.676 strm00E2A164 PUT prefetch_cnt=8/1
18:10:22.692 strm00E2A164 Start talksprut..
18:10:22.707 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:22.707 strm00E2A164 Starting silence
18:10:22.848 strm00E2A164 PUT prefetch_cnt=9/1
18:10:22.879 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:23.004 strm00E2A164 PUT prefetch_cnt=8/1
18:10:23.051 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:23.098 strm00E2A164 Start talksprut..
18:10:23.129 strm00E2A164 Starting silence
18:10:23.176 strm00E2A164 PUT prefetch_cnt=8/1
18:10:23.207 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:23.223 strm00E2A164 Start talksprut..
18:10:23.238 strm00E2A164 Starting silence
18:10:23.254 strm00E2A164 PUT prefetch_cnt=4/1
18:10:23.301 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:23.317 strm00E2A164 PUT prefetch_cnt=2/1
18:10:23.348 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:23.426 strm00E2A164 PUT prefetch_cnt=6/1
18:10:23.457 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:23.473 strm00E2A164 PUT prefetch_cnt=2/1
18:10:23.504 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:23.504 strm00E2A164 PUT prefetch_cnt=2/1
18:10:23.520 strm00E2A164 Start talksprut..
18:10:23.551 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:23.551 strm00E2A164 Starting silence
18:10:23.551 strm00E2A164 PUT prefetch_cnt=2/1
18:10:23.582 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:23.645 strm00E2A164 Start talksprut..
18:10:23.660 strm00E2A164 Starting silence
18:10:23.738 strm00E2A164 PUT prefetch_cnt=9/1
18:10:23.770 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:23.848 strm00E2A164 PUT prefetch_cnt=6/1
18:10:23.879 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:23.988 strm00E2A164 PUT prefetch_cnt=7/1
18:10:24.051 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:24.067 strm00E2A164 Start talksprut..
18:10:24.082 strm00E2A164 Starting silence
18:10:24.145 strm00E2A164 PUT prefetch_cnt=7/1
18:10:24.160 strm00E2A164 Start talksprut..
18:10:24.176 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:24.192 strm00E2A164 Starting silence
18:10:24.207 strm00E2A164 PUT prefetch_cnt=3/1
18:10:24.239 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:24.317 strm00E2A164 PUT prefetch_cnt=5/1
18:10:24.317 strm00E2A164 Start talksprut..
18:10:24.348 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:24.348 strm00E2A164 Starting silence
18:10:24.489 strm00E2A164 PUT prefetch_cnt=9/1
18:10:24.551 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:24.739 strm00E2A164 Start talksprut..
18:10:24.770 strm00E2A164 Starting silence
18:10:24.926 strm00E2A164 PUT prefetch_cnt=21/1
18:10:24.957 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:25.160 strm00E2A164 Start talksprut..
18:10:25.176 strm00E2A164 Starting silence
18:10:25.348 strm00E2A164 PUT prefetch_cnt=21/1
18:10:25.379 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:25.582 strm00E2A164 Start talksprut..
18:10:25.598 strm00E2A164 Starting silence
18:10:25.692 strm00E2A164 PUT prefetch_cnt=17/1
18:10:25.739 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:25.754 strm00E2A164 PUT prefetch_cnt=2/1
18:10:25.770 strm00E2A164 Start talksprut..
18:10:25.785 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:25.785 strm00E2A164 Starting silence
18:10:25.817 strm00E2A164 Start talksprut..
18:10:25.848 strm00E2A164 Starting silence
18:10:25.864 strm00E2A164 PUT prefetch_cnt=6/1
18:10:25.910 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:26.036 strm00E2A164 PUT prefetch_cnt=8/1
18:10:26.129 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:26.239 strm00E2A164 Start talksprut..
18:10:26.270 strm00E2A164 Starting silence
18:10:26.504 strm00E2A164 PUT prefetch_cnt=21/1
18:10:26.551 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:26.661 strm00E2A164 Start talksprut..
18:10:26.676 strm00E2A164 Starting silence
18:10:26.926 strm00E2A164 PUT prefetch_cnt=21/1
18:10:26.957 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:26.989 strm00E2A164 PUT prefetch_cnt=3/1
18:10:27.020 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:27.082 strm00E2A164 Start talksprut..
18:10:27.098 strm00E2A164 Starting silence
18:10:27.411 strm00E2A164 PUT prefetch_cnt=21/1
18:10:27.442 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:27.504 strm00E2A164 Start talksprut..
18:10:27.520 strm00E2A164 Starting silence
18:10:27.598 strm00E2A164 PUT prefetch_cnt=9/1
18:10:27.926 strm00E2A164 Start talksprut..
18:10:27.942 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:27.942 strm00E2A164 Starting silence
18:10:28.333 strm00E2A164 PUT prefetch_cnt=21/1
18:10:28.348 strm00E2A164 Start talksprut..
18:10:28.364 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:28.364 strm00E2A164 Starting silence
18:10:28.754 strm00E2A164 PUT prefetch_cnt=21/1
18:10:28.770 strm00E2A164 Start talksprut..
18:10:28.786 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:28.786 strm00E2A164 Starting silence
18:10:28.926 strm00E2A164 PUT prefetch_cnt=9/1
18:10:28.958 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:28.973 strm00E2A164 PUT prefetch_cnt=2/1
18:10:29.004 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:29.114 strm00E2A164 PUT prefetch_cnt=7/1
18:10:29.145 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:29.176 strm00E2A164 Start talksprut..
18:10:29.208 strm00E2A164 Starting silence
18:10:29.395 strm00E2A164 PUT prefetch_cnt=14/1
18:10:29.442 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:29.598 strm00E2A164 Start talksprut..
18:10:29.629 strm00E2A164 Starting silence
18:10:29.833 strm00E2A164 PUT prefetch_cnt=21/1
18:10:29.864 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:30.020 strm00E2A164 Start talksprut..
18:10:30.036 strm00E2A164 Starting silence
18:10:30.255 strm00E2A164 PUT prefetch_cnt=21/1
18:10:30.286 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:30.442 strm00E2A164 Start talksprut..
18:10:30.458 strm00E2A164 Starting silence
18:10:30.676 strm00E2A164 PUT prefetch_cnt=21/1
18:10:30.708 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:30.864 strm00E2A164 Start talksprut..
18:10:30.880 strm00E2A164 Starting silence
18:10:31.098 strm00E2A164 PUT prefetch_cnt=21/1
18:10:31.270 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:31.286 strm00E2A164 Start talksprut..
18:10:31.301 strm00E2A164 Starting silence
18:10:31.645 strm00E2A164 PUT prefetch_cnt=21/1
18:10:31.676 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:31.708 strm00E2A164 Start talksprut..
18:10:31.723 strm00E2A164 Starting silence
18:10:32.067 strm00E2A164 PUT prefetch_cnt=21/1
18:10:32.130 strm00E2A164 Start talksprut..
18:10:32.145 strm00E2A164 Starting silence
18:10:32.223 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:32.458 strm00E2A164 PUT prefetch_cnt=13/1
18:10:32.489 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:32.536 strm00E2A164 PUT prefetch_cnt=4/1
18:10:32.536 strm00E2A164 Start talksprut..
18:10:32.567 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:32.567 strm00E2A164 Starting silence
18:10:32.958 strm00E2A164 PUT prefetch_cnt=21/1
18:10:32.958 strm00E2A164 Start talksprut..
18:10:32.989 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:32.989 strm00E2A164 Starting silence
18:10:33.255 strm00E2A164 PUT prefetch_cnt=15/1
18:10:33.286 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:33.333 strm00E2A164 PUT prefetch_cnt=4/1
18:10:33.364 strm00E2A164 Jitter buffer empty (prefetch=1)
18:10:33.380 strm00E2A164 Start talksprut..
18:10:33.395 strm00E2A164 Starting silence
18:10:33.723 sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=21789 (rdata00DE754C)
18:10:33.723 pjsua_core.c RX 1220 bytes Request msg INVITE/cseq=21789 (rdata00DE754C) from UDP 172.18.1.218:4060:
INVITE sip:alice at 172.18.2.74:5060 SIP/2.0
Record-Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Max-Forwards: 8
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=z9hG4bK952f.9f77fb01.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;branch=z9hG4bK952f.8b570035.0
Via: SIP/2.0/UDP 172.18.1.218;branch=z9hG4bK952f.7a9c97d1.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK952f.e5f69b87.0
To: sip:alice at voip3gppsrv2;tag=bc27d41fb5ea4706839220367a190b5e
From: sip:bob@voip3gppsrv2;tag=d1668b6ac642456cbfbd4f2c1a301227
CSeq: 21789 INVITE
Call-ID: 0f23cac12e744ad1866cd555948b4b6e
Content-Length: 459
User-Agent: OpenSIPS (1.4.0-notls (i386/linux))
Contact: <sip:bob at 172.18.1.222:5060>
Content-Type: application/sdp
P-Called-Party-ID: <sip:alice at voip3gppsrv2>
v=0
o=- 3449844628 3449844628 IN IP4 172.18.1.222
s=pjmedia
c=IN IP4 172.18.1.222
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 103 102 104 117 3 0 8 9 101
a=rtcp:4003 IN IP4 172.18.1.222
a=rtpmap:103 speex/16000
a=rtpmap:102 speex/8000
a=rtpmap:104 speex/32000
a=rtpmap:117 iLBC/8000
a=fmtp:117 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
--end msg--
18:10:33.770 strm00E2A164 PUT prefetch_cnt=21/1
18:10:33.770 dlg00DFC08C Received Request msg INVITE/cseq=21789 (rdata00DE754C)
18:10:33.770 tsx00DEA95C Transaction created for Request msg INVITE/cseq=21789 (rdata00DE754C)
18:10:33.770 tsx00DEA95C Incoming Request msg INVITE/cseq=21789 (rdata00DE754C) in state Null
18:10:33.770 tsx00DEA95C State changed from Null to Trying, event=RX_MSG
18:10:33.770 dlg00DFC08C Transaction tsx00DEA95C state changed to Trying
18:10:33.770 inv00DFC08C Got SDP offer in Request msg INVITE/cseq=21789 (rdata00DE754C)
18:10:33.770 pjsua_call.c Call 1: received updated media offer
18:10:33.770 endpoint Response msg 200/INVITE/cseq=21789 (tdta00E37898) created
18:10:33.770 inv00DFC08C SDP negotiation done, status=0
18:10:33.770 pjsua_call.c Call 1: remote NAT type is 0 (Unknown)
18:10:33.770 pjsua_media.c Media session for call 1 is destroyed
18:10:33.770 strm00E2A164 VAD temporarily disabled
18:10:33.770 rtp.c pjmedia_rtp_session_init: ses=00E2B338, default_pt=103, ssrc=0x6d5c2c8f
18:10:33.770 rtp.c pjmedia_rtp_session_init: ses=00E2B7AC, default_pt=103, ssrc=0x6d5c2c8f
18:10:33.770 stream.c Stream strm00E2A164 created
18:10:33.770 strm00E2A164 Encoder stream started
18:10:33.770 strm00E2A164 Decoder stream started
18:10:33.770 pjsua_media.c Media updates, stream #0: speex (sendrecv)
18:10:33.770 conference.c Port 3 (sip:bob at voip3gppsrv2) transmitting to port 0 (Microsoft Sound Mapper - Input)
18:10:33.770 conference.c Port 0 (Microsoft Sound Mapper - Input) transmitting to port 3 (sip:bob at voip3gppsrv2)
18:10:33.786 pjsua_app.c Media for call 1 is active
18:10:33.786 inv00DFC08C Sending Response msg 200/INVITE/cseq=21789 (tdta00E37898)
18:10:33.786 dlg00DFC08C Sending Response msg 200/INVITE/cseq=21789 (tdta00E37898)
18:10:33.786 tsx00DEA95C Sending Response msg 200/INVITE/cseq=21789 (tdta00E37898) in state Trying
18:10:33.786 sip_resolve.c Target '172.18.1.218:4060' type=UDP resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:10:33.786 pjsua_core.c TX 1038 bytes Response msg 200/INVITE/cseq=21789 (tdta00E37898) to UDP 172.18.1.218:4060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.18.1.218:4060;received=172.18.1.218;branch=z9hG4bK952f.9f77fb01.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;branch=z9hG4bK952f.8b570035.0
Via: SIP/2.0/UDP 172.18.1.218;branch=z9hG4bK952f.7a9c97d1.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK952f.e5f69b87.0
Record-Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Call-ID: 0f23cac12e744ad1866cd555948b4b6e
From: <sip:bob@voip3gppsrv2>;tag=d1668b6ac642456cbfbd4f2c1a301227
To: <sip:alice at voip3gppsrv2>;tag=bc27d41fb5ea4706839220367a190b5e
CSeq: 21789 INVITE
Contact: <sip:alice at 172.18.2.74:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length: 254
v=0
o=- 3449844633 3449844619 IN IP4 172.18.2.74
s=pjmedia
c=IN IP4 172.18.2.74
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 103 101
a=rtcp:4003 IN IP4 172.18.2.74
a=rtpmap:103 speex/16000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
--end msg--
18:10:33.817 strm00E2A164 Jitter buffer empty (prefetch=0)
18:10:33.817 strm00E2A164 Start talksprut..
18:10:33.817 Master/sound Underflow, buf_cnt=307, will generate 1 frame
18:10:33.833 tsx00DEA95C State changed from Trying to Completed, event=TX_MSG
18:10:33.833 dlg00DFC08C Transaction tsx00DEA95C state changed to Completed
18:10:33.833 sip_endpoint.c Processing incoming message: Request msg ACK/cseq=21789 (rdata00DE754C)
18:10:33.833 pjsua_core.c RX 499 bytes Request msg ACK/cseq=21789 (rdata00DE754C) from UDP 172.18.1.218:6060:
ACK sip:alice at 172.18.2.74:5060 SIP/2.0
Max-Forwards: 9
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=0
Via: SIP/2.0/UDP 172.18.1.218;branch=0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK952f.e5f69b87.0
From: sip:bob@voip3gppsrv2;tag=d1668b6ac642456cbfbd4f2c1a301227
Call-ID: 0f23cac12e744ad1866cd555948b4b6e
To: <sip:alice at voip3gppsrv2>;tag=bc27d41fb5ea4706839220367a190b5e
CSeq: 21789 ACK
User-Agent: OpenSIPS (1.4.0-notls (i386/linux))
Content-Length: 0
P-hint: I-CSCF rr-enforced
?
--end msg--
18:10:33.864 strm00E2A164 RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=0
18:10:33.864 dlg00DFC08C Received Request msg ACK/cseq=21789 (rdata00DE754C)
18:10:33.864 tsx00DEA95C Request to terminate transaction
18:10:33.864 tsx00DEA95C State changed from Completed to Terminated, event=USER
18:10:33.864 dlg00DFC08C Transaction tsx00DEA95C state changed to Terminated
18:10:33.864 tsx00DEA95C Timeout timer event
18:10:33.864 tsx00DEA95C State changed from Terminated to Destroyed, event=TIMER
18:10:33.864 tdta00E37898 Destroying txdata Response msg 200/INVITE/cseq=21789 (tdta00E37898)
18:10:33.864 tsx00DEA95C Transaction destroyed!
18:10:33.864 udp00DF06F8 Remote RTCP address switched to 172.18.1.78:4003
18:10:33.880 strm00E2A164 jb updated(2), prefetch=1, size=1
18:10:33.880 strm00E2A164 PUT prefetch_cnt=1/1
18:10:34.020 udp00DF06F8 Remote RTCP address switched to 172.18.1.222:4003
18:10:34.395 strm00E2A164 VAD re-enabled
18:10:34.536 strm00E2A164 Starting silence
18:10:34.567 strm00E2A164 jb updated(2), prefetch=2, size=2
18:10:34.599 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:34.599 strm00E2A164 PUT prefetch_cnt=2/2
18:10:34.661 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:34.786 strm00E2A164 PUT prefetch_cnt=8/2
18:10:34.942 strm00E2A164 Start talksprut..
18:10:34.958 strm00E2A164 Starting silence
18:10:35.364 strm00E2A164 Start talksprut..
18:10:35.520 strm00E2A164 Starting silence
18:10:35.599 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:35.739 strm00E2A164 PUT prefetch_cnt=9/2
18:10:35.755 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:35.770 strm00E2A164 PUT prefetch_cnt=1/2
18:10:35.786 strm00E2A164 PUT prefetch_cnt=2/2
18:10:35.927 strm00E2A164 Start talksprut..
18:10:35.942 strm00E2A164 Starting silence
18:10:36.099 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:36.161 strm00E2A164 PUT prefetch_cnt=5/2
18:10:36.317 strm00E2A164 Start talksprut..
18:10:36.349 strm00E2A164 Starting silence
18:10:36.489 strm00E2A164 Start talksprut..
18:10:36.505 strm00E2A164 Starting silence
18:10:36.536 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:10:36.536 tdta00E37898 Destroying txdata raw
18:10:36.536 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:36.802 strm00E2A164 PUT prefetch_cnt=15/2
18:10:36.864 strm00E2A164 Start talksprut..
18:10:36.880 strm00E2A164 Starting silence
18:10:36.989 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:37.161 strm00E2A164 Start talksprut..
18:10:37.161 strm00E2A164 PUT prefetch_cnt=11/2
18:10:37.177 strm00E2A164 Starting silence
18:10:37.567 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:37.583 strm00E2A164 Start talksprut..
18:10:37.599 strm00E2A164 Starting silence
18:10:37.739 strm00E2A164 PUT prefetch_cnt=11/2
18:10:38.005 strm00E2A164 Start talksprut..
18:10:38.021 strm00E2A164 Starting silence
18:10:38.068 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:38.099 strm00E2A164 PUT prefetch_cnt=4/2
18:10:38.146 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:38.161 strm00E2A164 PUT prefetch_cnt=2/2
18:10:38.177 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:38.177 strm00E2A164 Start talksprut..
18:10:38.177 strm00E2A164 PUT prefetch_cnt=1/2
18:10:38.208 strm00E2A164 Starting silence
18:10:38.208 strm00E2A164 PUT prefetch_cnt=2/2
18:10:38.239 strm00E2A164 Start talksprut..
18:10:38.255 strm00E2A164 Starting silence
18:10:38.489 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:38.599 strm00E2A164 PUT prefetch_cnt=8/2
18:10:38.614 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:38.661 strm00E2A164 Start talksprut..
18:10:38.677 strm00E2A164 Starting silence
18:10:39.021 strm00E2A164 PUT prefetch_cnt=21/2
18:10:39.036 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:39.083 strm00E2A164 Start talksprut..
18:10:39.099 strm00E2A164 Starting silence
18:10:39.177 strm00E2A164 PUT prefetch_cnt=8/2
18:10:39.505 strm00E2A164 Start talksprut..
18:10:39.521 strm00E2A164 Starting silence
18:10:39.583 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:39.927 strm00E2A164 Start talksprut..
18:10:39.943 strm00E2A164 Starting silence
18:10:39.958 strm00E2A164 PUT prefetch_cnt=21/2
18:10:39.990 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:40.208 strm00E2A164 PUT prefetch_cnt=12/2
18:10:40.349 strm00E2A164 Start talksprut..
18:10:40.365 strm00E2A164 Starting silence
18:10:40.755 strm00E2A164 Start talksprut..
18:10:40.786 strm00E2A164 Starting silence
18:10:40.880 strm00E2A164 Start talksprut..
18:10:40.896 strm00E2A164 Starting silence
18:10:40.958 strm00E2A164 Start talksprut..
18:10:40.990 strm00E2A164 Starting silence
18:10:41.130 strm00E2A164 Start talksprut..
18:10:41.146 strm00E2A164 Starting silence
18:10:41.161 strm00E2A164 Start talksprut..
18:10:41.177 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:41.177 strm00E2A164 Starting silence
18:10:41.208 strm00E2A164 Start talksprut..
18:10:41.208 strm00E2A164 PUT prefetch_cnt=3/2
18:10:41.302 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:41.380 strm00E2A164 PUT prefetch_cnt=6/2
18:10:41.396 strm00E2A164 Starting silence
18:10:41.427 strm00E2A164 Start talksprut..
18:10:41.568 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:41.740 strm00E2A164 PUT prefetch_cnt=11/2
18:10:41.755 strm00E2A164 Starting silence
18:10:41.927 strm00E2A164 Start talksprut..
18:10:41.958 strm00E2A164 Starting silence
18:10:42.208 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:42.208 strm00E2A164 Start talksprut..
18:10:42.318 strm00E2A164 PUT prefetch_cnt=8/2
18:10:42.365 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:42.380 strm00E2A164 PUT prefetch_cnt=3/2
18:10:42.427 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:42.427 strm00E2A164 Starting silence
18:10:42.490 strm00E2A164 Start talksprut..
18:10:42.583 strm00E2A164 PUT prefetch_cnt=10/2
18:10:42.615 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:42.615 strm00E2A164 Starting silence
18:10:42.771 strm00E2A164 Start talksprut..
18:10:43.005 strm00E2A164 PUT prefetch_cnt=21/2
18:10:43.037 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:43.099 strm00E2A164 PUT prefetch_cnt=5/2
18:10:43.146 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:43.162 strm00E2A164 Starting silence
18:10:43.208 strm00E2A164 Start talksprut..
18:10:43.240 strm00E2A164 Starting silence
18:10:43.255 strm00E2A164 PUT prefetch_cnt=8/2
18:10:43.302 strm00E2A164 Start talksprut..
18:10:43.396 strm00E2A164 Starting silence
18:10:43.458 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:43.505 strm00E2A164 PUT prefetch_cnt=4/2
18:10:43.537 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:43.599 strm00E2A164 PUT prefetch_cnt=5/2
18:10:43.646 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:43.709 strm00E2A164 Start talksprut..
18:10:43.724 strm00E2A164 Starting silence
18:10:43.787 strm00E2A164 PUT prefetch_cnt=9/2
18:10:43.849 strm00E2A164 Start talksprut..
18:10:43.865 strm00E2A164 Starting silence
18:10:43.896 strm00E2A164 Start talksprut..
18:10:43.927 strm00E2A164 Starting silence
18:10:43.974 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:44.224 strm00E2A164 Start talksprut..
18:10:44.240 strm00E2A164 Starting silence
18:10:44.318 strm00E2A164 PUT prefetch_cnt=19/2
18:10:44.646 strm00E2A164 Start talksprut..
18:10:44.662 strm00E2A164 Starting silence
18:10:44.740 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:45.068 strm00E2A164 Start talksprut..
18:10:45.084 strm00E2A164 Starting silence
18:10:45.115 strm00E2A164 PUT prefetch_cnt=21/2
18:10:45.162 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:45.396 strm00E2A164 PUT prefetch_cnt=14/2
18:10:45.443 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:45.443 strm00E2A164 PUT prefetch_cnt=2/2
18:10:45.490 strm00E2A164 Start talksprut..
18:10:45.505 strm00E2A164 Starting silence
18:10:45.787 strm00E2A164 Start talksprut..
18:10:45.802 strm00E2A164 Starting silence
18:10:45.865 strm00E2A164 Start talksprut..
18:10:45.881 strm00E2A164 Starting silence
18:10:46.021 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:46.287 strm00E2A164 Start talksprut..
18:10:46.302 strm00E2A164 Starting silence
18:10:46.318 strm00E2A164 PUT prefetch_cnt=17/2
18:10:46.459 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:46.709 strm00E2A164 Start talksprut..
18:10:46.724 strm00E2A164 Starting silence
18:10:46.849 strm00E2A164 PUT prefetch_cnt=21/2
18:10:46.881 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:47.115 strm00E2A164 Start talksprut..
18:10:47.146 strm00E2A164 Starting silence
18:10:47.209 strm00E2A164 PUT prefetch_cnt=18/2
18:10:47.224 sip_endpoint.c Processing incoming message: Request msg BYE/cseq=21791 (rdata00DE754C)
18:10:47.224 pjsua_core.c RX 565 bytes Request msg BYE/cseq=21791 (rdata00DE754C) from UDP 172.18.1.218:4060:
BYE sip:alice at 172.18.2.74:5060 SIP/2.0
Max-Forwards: 9
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=z9hG4bK152f.b7653005.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;branch=z9hG4bK152f.1d926fd5.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK152f.12a22fd5.0
To: sip:alice at voip3gppsrv2;tag=bc27d41fb5ea4706839220367a190b5e
From: sip:bob@voip3gppsrv2;tag=d1668b6ac642456cbfbd4f2c1a301227
CSeq: 21791 BYE
Call-ID: 0f23cac12e744ad1866cd555948b4b6e
Content-Length: 0
User-Agent: OpenSIPS (1.4.0-notls (i386/linux))
Contact: <sip:bob at 172.18.1.222:5060>
?
--end msg--
18:10:47.240 dlg00DFC08C Received Request msg BYE/cseq=21791 (rdata00DE754C)
18:10:47.240 tsx00DEA95C Transaction created for Request msg BYE/cseq=21791 (rdata00DE754C)
18:10:47.240 tsx00DEA95C Incoming Request msg BYE/cseq=21791 (rdata00DE754C) in state Null
18:10:47.240 tsx00DEA95C State changed from Null to Trying, event=RX_MSG
18:10:47.240 dlg00DFC08C Transaction tsx00DEA95C state changed to Trying
18:10:47.240 endpoint Response msg 200/BYE/cseq=21791 (tdta00E37898) created
18:10:47.240 dlg00DFC08C Sending Response msg 200/BYE/cseq=21791 (tdta00E37898)
18:10:47.240 tsx00DEA95C Sending Response msg 200/BYE/cseq=21791 (tdta00E37898) in state Trying
18:10:47.240 sip_resolve.c Target '172.18.1.218:4060' type=UDP resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:10:47.240 pjsua_core.c TX 463 bytes Response msg 200/BYE/cseq=21791 (tdta00E37898) to UDP 172.18.1.218:4060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.18.1.218:4060;received=172.18.1.218;branch=z9hG4bK152f.b7653005.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;branch=z9hG4bK152f.1d926fd5.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK152f.12a22fd5.0
Call-ID: 0f23cac12e744ad1866cd555948b4b6e
From: <sip:bob@voip3gppsrv2>;tag=d1668b6ac642456cbfbd4f2c1a301227
To: <sip:alice at voip3gppsrv2>;tag=bc27d41fb5ea4706839220367a190b5e
CSeq: 21791 BYE
Content-Length: 0
?
--end msg--
18:10:47.256 strm00E2A164 Jitter buffer empty (prefetch=2)
18:10:47.256 tsx00DEA95C State changed from Trying to Completed, event=TX_MSG
18:10:47.256 dlg00DFC08C Transaction tsx00DEA95C state changed to Completed
18:10:47.256 pjsua_app.c Call 1 is DISCONNECTED [reason=200 (Normal call clearing)]
18:10:47.256 pjsua_app.c Call 1 disconnected, dumping media stats..
18:10:47.256 pjsua_app.c 
[DISCONNCTD] To: <sip:bob at voip3gppsrv2>;tag=d1668b6ac642456cbfbd4f2c1a301227
Call time: 00h:00m:29s, 1st res in 78 ms, conn in 235ms
SRTP status: Not active Crypto-suite: (null)
#0 speex @16KHz, sendrecv, peer=172.18.1.222:4002
RX pt=103, stat last update: 00h:00m:03.798s ago
total 360pkt 22.3KB (36.7KB +IP hdr) @avg=13.2Kbps/21.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.612 4.000 0.062 0.916
TX pt=103, ptime=20ms, stat last update: 00h:00m:03.016s ago
total 152pkt 7.8KB (13.9KB +IP hdr) @avg 4.6Kbps/8.2Kbps
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 : 0.000 0.333 0.750 0.750 0.311
RTT msec : 1.327 1.403 1.480 1.327 0.076
Start talksprut.. 18:10:47.287 pjsua_media.c Media session for call 1 is destroyed
18:10:47.287 dlg00DFC08C Session count dec to 3 by mod-invite
18:10:48.287 pjsua_media.c Closing sound device after idle for 1 seconds
18:10:48.287 pjsua_media.c Closing Microsoft Sound Mapper - Output sound playback device and Microsoft Sound Mapper - Input sound capture device
18:10:48.365 pa_dev.c Stopping stream..
18:10:48.365 pa_dev.c PA message: WinMME StopStream: waiting for background thread.
18:10:48.459 pa_dev.c PA message: WinMME StopStream: waiting for background thread.
18:10:48.459 pa_dev.c Done, status=0
18:10:48.459 pa_dev.c Closing Microsoft Sound Mapper - Input: 0 underflow, 0 overflow
18:10:51.537 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:10:51.537 tdta00E19028 Destroying txdata raw
18:10:59.522 sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=6884 (rdata00DE754C)
18:10:59.522 pjsua_core.c <logging error: msg too long>
18:10:59.522 pjsua_media.c Media index 0 selected for call 2
18:10:59.522 tsx00DED7CC Transaction created for Request msg INVITE/cseq=6884 (rdata00DE754C)
18:10:59.522 tsx00DED7CC Incoming Request msg INVITE/cseq=6884 (rdata00DE754C) in state Null
18:10:59.522 tsx00DED7CC State changed from Null to Trying, event=RX_MSG
18:10:59.522 dlg00E2808C Transaction tsx00DED7CC state changed to Trying
18:10:59.522 dlg00E2808C UAS dialog created
18:10:59.522 dlg00E2808C Module mod-invite added as dialog usage, data=00DF9FFC
18:10:59.522 dlg00E2808C Session count inc to 2 by mod-invite
18:10:59.522 inv00E2808C UAS invite session created for dialog dlg00E2808C
18:10:59.522 pjsua_call.c Call 2: remote NAT type is 0 (Unknown)
18:10:59.522 endpoint Response msg 100/INVITE/cseq=6884 (tdta00E2D650) created
18:10:59.522 dlg00E2808C Initial answer Response msg 100/INVITE/cseq=6884 (tdta00E2D650)
18:10:59.522 inv00E2808C Sending Response msg 100/INVITE/cseq=6884 (tdta00E2D650)
18:10:59.522 dlg00E2808C Sending Response msg 100/INVITE/cseq=6884 (tdta00E2D650)
18:10:59.522 tsx00DED7CC Sending Response msg 100/INVITE/cseq=6884 (tdta00E2D650) in state Trying
18:10:59.522 sip_resolve.c Target '172.18.1.218:4060' type=UDP resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:10:59.522 pjsua_core.c TX 1137 bytes Response msg 100/INVITE/cseq=6884 (tdta00E2D650) to UDP 172.18.1.218:4060:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.18.1.218:4060;received=172.18.1.218;branch=z9hG4bK67a2.48fe566.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;received=172.18.1.218;branch=z9hG4bK67a2.0e84f71.0
Via: SIP/2.0/UDP 172.18.1.218;branch=z9hG4bK67a2.628ecfe.0
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=z9hG4bK67a2.fd84f71.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK67a2.e2eb58c.0
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=z9hG4bK67a2.ed84f71.0
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=z9hG4bK67a2.38fe566.0
Via: SIP/2.0/UDP 172.18.1.222:5060;rport=5060;branch=z9hG4bKPjde466559097f4883b24e1f88a13e463f
Record-Route: <sip:mt at pcscf.voip3gppsrv2:4060;lr>
Record-Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:172.18.1.218:5065;lr;ftag=15a28719e9eb4442a1d20d24ca897b37>
Record-Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:mo at pcscf.voip3gppsrv2:4060;lr>
Call-ID: af199956066e448d851bdb067a6ced46
From: <sip:bob@voip3gppsrv2>;tag=15a28719e9eb4442a1d20d24ca897b37
To: <sip:alice at voip3gppsrv2>
CSeq: 6884 INVITE
Content-Length: 0
?
--end msg--
18:10:59.553 tsx00DED7CC State changed from Trying to Proceeding, event=TX_MSG
18:10:59.553 dlg00E2808C Transaction tsx00DED7CC state changed to Proceeding
18:10:59.553 pjsua_media.c Opening sound device PCM at 16000/1/20ms
18:10:59.585 pa_dev.c Opened device Microsoft Sound Mapper - Input(MME)/Microsoft Sound Mapper - Output(MME) for recording and playback, sample rate=16000, ch=1, bits=16, 320 samples per frame, input latency=100 ms, output latency=100 ms
18:10:59.585 ec00DEDF98 Creating AEC
18:10:59.585 ec00DEDF98 AEC created, clock_rate=16000, channel=1, samples per frame=320, tail length=200 ms, latency=100 ms
18:10:59.585 pa_dev.c Starting Microsoft Sound Mapper - Input stream..
18:10:59.600 pa_dev.c PA message: Pa_StartStream: waveInStart returned = 0x0.
18:10:59.600 pa_dev.c Done, status=0
18:10:59.600 conference.c Port 2 (ring) transmitting to port 0 (Microsoft Sound Mapper - Input)
18:10:59.600 inv00E2808C SDP negotiation done, status=0
18:10:59.600 pjsua_call.c Call 2: remote NAT type is 0 (Unknown)
18:10:59.600 strm00E3D4FC VAD temporarily disabled
18:10:59.600 rtp.c pjmedia_rtp_session_init: ses=00E3E6D0, default_pt=103, ssrc=0x3a284172
18:10:59.600 rtp.c pjmedia_rtp_session_init: ses=00E3EB44, default_pt=103, ssrc=0x3a284172
18:10:59.600 stream.c Stream strm00E3D4FC created
18:10:59.600 strm00E3D4FC Encoder stream started
18:10:59.600 strm00E3D4FC Decoder stream started
18:10:59.600 pjsua_media.c Media updates, stream #0: speex (sendrecv)
18:10:59.600 conference.c Port 2 (ring) stop transmitting to port 0 (Microsoft Sound Mapper - Input)
18:10:59.600 conference.c Port 3 (sip:bob at voip3gppsrv2) transmitting to port 0 (Microsoft Sound Mapper - Input)
18:10:59.616 conference.c Port 0 (Microsoft Sound Mapper - Input) transmitting to port 3 (sip:bob at voip3gppsrv2)
18:10:59.616 pjsua_app.c Media for call 2 is active
18:10:59.616 inv00E2808C Sending Response msg 200/INVITE/cseq=6884 (tdta00E2D650)
18:10:59.616 dlg00E2808C Sending Response msg 200/INVITE/cseq=6884 (tdta00E2D650)
18:10:59.616 tsx00DED7CC Sending Response msg 200/INVITE/cseq=6884 (tdta00E2D650) in state Proceeding
18:10:59.616 pjsua_core.c TX 1630 bytes Response msg 200/INVITE/cseq=6884 (tdta00E2D650) to UDP 172.18.1.218:4060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.18.1.218:4060;received=172.18.1.218;branch=z9hG4bK67a2.48fe566.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;received=172.18.1.218;branch=z9hG4bK67a2.0e84f71.0
Via: SIP/2.0/UDP 172.18.1.218;branch=z9hG4bK67a2.628ecfe.0
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=z9hG4bK67a2.fd84f71.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK67a2.e2eb58c.0
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=z9hG4bK67a2.ed84f71.0
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=z9hG4bK67a2.38fe566.0
Via: SIP/2.0/UDP 172.18.1.222:5060;rport=5060;branch=z9hG4bKPjde466559097f4883b24e1f88a13e463f
Record-Route: <sip:mt at pcscf.voip3gppsrv2:4060;lr>
Record-Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:172.18.1.218:5065;lr;ftag=15a28719e9eb4442a1d20d24ca897b37>
Record-Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Record-Route: <sip:mo at pcscf.voip3gppsrv2:4060;lr>
Call-ID: af199956066e448d851bdb067a6ced46
From: <sip:bob@voip3gppsrv2>;tag=15a28719e9eb4442a1d20d24ca897b37
To: <sip:alice at voip3gppsrv2>;tag=d77e8361ab1d4cc5894928a47ca53aa6
CSeq: 6884 INVITE
Contact: <sip:alice at 172.18.2.74:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length: 254
v=0
o=- 3449844659 3449844660 IN IP4 172.18.2.74
s=pjmedia
c=IN IP4 172.18.2.74
t=0 0
a=X-nat:0
m=audio 4004 RTP/AVP 103 101
a=rtcp:4005 IN IP4 172.18.2.74
a=rtpmap:103 speex/16000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
--end msg--
18:10:59.631 pa_dev.c Player thread started
18:10:59.631 strm00E3D4FC Jitter buffer empty (prefetch=0)
18:10:59.631 strm00E3D4FC Start talksprut..
18:10:59.631 pa_dev.c Recorder thread started
18:10:59.631 ec00DEDF98 Prefetching..
18:10:59.678 ec00DEDF98 Prefetching..
18:10:59.678 ec00DEDF98 Prefetching..
18:10:59.678 tsx00DED7CC State changed from Proceeding to Completed, event=TX_MSG
18:10:59.678 dlg00E2808C Transaction tsx00DED7CC state changed to Completed
18:10:59.678 pjsua_app.c Call 2 state changed to CONNECTING
18:10:59.678 ec00DEDF98 Prefetching..
18:10:59.694 sip_endpoint.c Processing incoming message: Request msg ACK/cseq=6884 (rdata00DE754C)
18:10:59.694 pjsua_core.c RX 770 bytes Request msg ACK/cseq=6884 (rdata00DE754C) from UDP 172.18.1.218:5065:
ACK sip:alice at 172.18.2.74:5060 SIP/2.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK67a2.e2eb58c.2
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=0
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=0
Via: SIP/2.0/UDP 172.18.1.222:5060;rport=5060;branch=z9hG4bKPj489a067215e44ca0a0034154e8ef0fef
Max-Forwards: 14
From: sip:bob@voip3gppsrv2;tag=15a28719e9eb4442a1d20d24ca897b37
To: sip:alice at voip3gppsrv2;tag=d77e8361ab1d4cc5894928a47ca53aa6
Call-ID: af199956066e448d851bdb067a6ced46
CSeq: 6884 ACK
Route: <sip:172.18.1.218:5065;lr;ftag=15a28719e9eb4442a1d20d24ca897b37>
Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Route: <sip:mt at pcscf.voip3gppsrv2:4060;lr>
Content-Length: 0
P-Asserted-Identity: <sip:bob at voip3gppsrv2>
?
--end msg--
18:10:59.725 ec00DEDF98 Prefetching..
18:10:59.725 ec00DEDF98 Prefetching..
18:10:59.725 strm00E3D4FC RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=0
18:10:59.725 dlg00E2808C Received Request msg ACK/cseq=6884 (rdata00DE754C)
18:10:59.725 tsx00DED7CC Request to terminate transaction
18:10:59.725 tsx00DED7CC State changed from Completed to Terminated, event=USER
18:10:59.725 dlg00E2808C Transaction tsx00DED7CC state changed to Terminated
18:10:59.725 pjsua_app.c Call 2 state changed to CONFIRMED
18:10:59.725 tsx00DED7CC Timeout timer event
18:10:59.725 tsx00DED7CC State changed from Terminated to Destroyed, event=TIMER
18:10:59.725 tdta00E2D650 Destroying txdata Response msg 200/INVITE/cseq=6884 (tdta00E2D650)
18:10:59.725 tsx00DED7CC Transaction destroyed!
18:10:59.725 strm00E3D4FC jb updated(2), prefetch=1, size=2
18:10:59.725 ec00DEDF98 Latency bufferring complete
18:10:59.741 strm00E3D4FC PUT prefetch_cnt=1/1
18:11:00.241 strm00E3D4FC VAD re-enabled
18:11:00.725 strm00E3D4FC Starting silence
18:11:00.772 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:00.803 strm00E3D4FC PUT prefetch_cnt=4/1
18:11:00.928 strm00E3D4FC Start talksprut..
18:11:00.944 strm00E3D4FC Starting silence
18:11:00.991 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:00.991 strm00E3D4FC PUT prefetch_cnt=2/1
18:11:01.194 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:01.303 strm00E3D4FC Start talksprut..
18:11:01.475 strm00E3D4FC Starting silence
18:11:01.569 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:01.600 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:01.866 strm00E3D4FC Start talksprut..
18:11:01.882 strm00E3D4FC Starting silence
18:11:01.991 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:02.022 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:02.100 strm00E3D4FC PUT prefetch_cnt=5/1
18:11:02.116 strm00E3D4FC Start talksprut..
18:11:02.132 strm00E3D4FC Starting silence
18:11:02.522 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:02.522 strm00E3D4FC Start talksprut..
18:11:02.553 strm00E3D4FC Starting silence
18:11:02.600 strm00E3D4FC PUT prefetch_cnt=5/1
18:11:02.647 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:02.678 strm00E3D4FC PUT prefetch_cnt=3/1
18:11:02.710 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:02.710 strm00E3D4FC PUT prefetch_cnt=2/1
18:11:02.741 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:02.757 strm00E3D4FC PUT prefetch_cnt=2/1
18:11:02.788 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:02.803 strm00E3D4FC PUT prefetch_cnt=2/1
18:11:02.835 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:02.835 strm00E3D4FC PUT prefetch_cnt=2/1
18:11:02.913 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:02.944 strm00E3D4FC Start talksprut..
18:11:02.975 strm00E3D4FC Starting silence
18:11:02.991 strm00E3D4FC PUT prefetch_cnt=6/1
18:11:03.022 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:03.038 strm00E3D4FC PUT prefetch_cnt=2/1
18:11:03.053 strm00E3D4FC Start talksprut..
18:11:03.069 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:03.085 strm00E3D4FC Starting silence
18:11:03.100 strm00E3D4FC PUT prefetch_cnt=3/1
18:11:03.132 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:03.163 strm00E3D4FC PUT prefetch_cnt=3/1
18:11:03.210 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:03.210 strm00E3D4FC Start talksprut..
18:11:03.225 strm00E3D4FC Starting silence
18:11:03.600 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:03.632 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:03.632 strm00E3D4FC Start talksprut..
18:11:03.647 strm00E3D4FC Starting silence
18:11:04.022 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:04.054 strm00E3D4FC Start talksprut..
18:11:04.069 strm00E3D4FC Starting silence
18:11:04.085 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:04.100 strm00E3D4FC PUT prefetch_cnt=2/1
18:11:04.132 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:04.132 strm00E3D4FC PUT prefetch_cnt=2/1
18:11:04.163 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:04.194 strm00E3D4FC PUT prefetch_cnt=3/1
18:11:04.272 strm00E3D4FC Start talksprut..
18:11:04.444 strm00E3D4FC Starting silence
18:11:04.491 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:04.600 strm00E3D4FC PUT prefetch_cnt=7/1
18:11:04.850 strm00E3D4FC Start talksprut..
18:11:04.866 strm00E3D4FC Starting silence
18:11:04.882 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:05.226 strm00E3D4FC PUT prefetch_cnt=18/1
18:11:05.272 strm00E3D4FC Start talksprut..
18:11:05.288 strm00E3D4FC Starting silence
18:11:05.491 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:05.601 strm00E3D4FC PUT prefetch_cnt=7/1
18:11:05.663 strm00E3D4FC Start talksprut..
18:11:05.694 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:05.694 strm00E3D4FC Starting silence
18:11:05.694 strm00E3D4FC PUT prefetch_cnt=2/1
18:11:05.882 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:06.022 strm00E3D4FC Start talksprut..
18:11:06.054 strm00E3D4FC Starting silence
18:11:06.147 strm00E3D4FC PUT prefetch_cnt=14/1
18:11:06.163 strm00E3D4FC Start talksprut..
18:11:06.366 strm00E3D4FC Starting silence
18:11:06.538 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 1 to 172.18.1.218:4060
18:11:06.538 tdta00E32F98 Destroying txdata raw
18:11:06.772 strm00E3D4FC Start talksprut..
18:11:06.788 strm00E3D4FC Starting silence
18:11:06.929 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:07.194 strm00E3D4FC Start talksprut..
18:11:07.210 strm00E3D4FC Starting silence
18:11:07.241 strm00E3D4FC PUT prefetch_cnt=17/1
18:11:07.366 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:07.523 strm00E3D4FC PUT prefetch_cnt=9/1
18:11:07.601 strm00E3D4FC Start talksprut..
18:11:07.632 strm00E3D4FC Starting silence
18:11:07.788 strm00E3D4FC Start talksprut..
18:11:07.882 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:08.101 strm00E3D4FC Starting silence
18:11:08.273 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:08.507 strm00E3D4FC Start talksprut..
18:11:08.523 strm00E3D4FC Starting silence
18:11:08.710 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:08.929 strm00E3D4FC Start talksprut..
18:11:08.944 strm00E3D4FC Starting silence
18:11:09.101 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:09.132 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:09.351 strm00E3D4FC Start talksprut..
18:11:09.366 strm00E3D4FC Starting silence
18:11:09.523 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:09.554 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:09.773 strm00E3D4FC Start talksprut..
18:11:09.788 strm00E3D4FC Starting silence
18:11:09.945 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:09.960 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:10.195 strm00E3D4FC Start talksprut..
18:11:10.210 strm00E3D4FC Starting silence
18:11:10.351 strm00E3D4FC Start talksprut..
18:11:10.366 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:10.382 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:10.445 strm00E3D4FC PUT prefetch_cnt=4/1
18:11:10.460 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:10.523 strm00E3D4FC PUT prefetch_cnt=4/1
18:11:10.554 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:10.648 strm00E3D4FC Starting silence
18:11:10.945 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:10.960 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:11.054 strm00E3D4FC Start talksprut..
18:11:11.070 strm00E3D4FC Starting silence
18:11:11.367 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:11.382 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:11.460 strm00E3D4FC Start talksprut..
18:11:11.492 strm00E3D4FC Starting silence
18:11:11.773 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:11.804 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:11.867 strm00E3D4FC PUT prefetch_cnt=4/1
18:11:11.882 strm00E3D4FC Start talksprut..
18:11:11.913 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:11.913 strm00E3D4FC Starting silence
18:11:11.945 strm00E3D4FC PUT prefetch_cnt=3/1
18:11:11.960 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:12.304 strm00E3D4FC Start talksprut..
18:11:12.320 strm00E3D4FC Starting silence
18:11:12.367 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:12.382 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:12.445 strm00E3D4FC PUT prefetch_cnt=4/1
18:11:12.460 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:12.601 strm00E3D4FC PUT prefetch_cnt=8/1
18:11:12.726 strm00E3D4FC Start talksprut..
18:11:12.742 strm00E3D4FC Starting silence
18:11:13.148 strm00E3D4FC Start talksprut..
18:11:13.164 strm00E3D4FC Starting silence
18:11:13.320 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:13.382 strm00E3D4FC PUT prefetch_cnt=4/1
18:11:13.414 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:13.554 strm00E3D4FC Start talksprut..
18:11:13.570 strm00E3D4FC Starting silence
18:11:13.695 strm00E3D4FC PUT prefetch_cnt=16/1
18:11:13.882 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:13.960 strm00E3D4FC Start talksprut..
18:11:13.976 strm00E3D4FC PUT prefetch_cnt=6/1
18:11:13.992 strm00E3D4FC Starting silence
18:11:14.304 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:14.382 strm00E3D4FC Start talksprut..
18:11:14.414 strm00E3D4FC Starting silence
18:11:14.539 strm00E3D4FC PUT prefetch_cnt=13/1
18:11:14.804 strm00E3D4FC Start talksprut..
18:11:14.820 strm00E3D4FC Starting silence
18:11:14.882 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:14.898 strm00E3D4FC PUT prefetch_cnt=2/1
18:11:15.070 strm00E3D4FC Start talksprut..
18:11:15.086 strm00E3D4FC Starting silence
18:11:15.289 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:15.289 strm00E3D4FC Start talksprut..
18:11:15.304 strm00E3D4FC Starting silence
18:11:15.445 strm00E3D4FC PUT prefetch_cnt=9/1
18:11:15.461 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:15.539 strm00E3D4FC PUT prefetch_cnt=5/1
18:11:15.570 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:15.711 strm00E3D4FC Start talksprut..
18:11:15.726 strm00E3D4FC Starting silence
18:11:15.773 strm00E3D4FC PUT prefetch_cnt=12/1
18:11:15.804 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:15.914 strm00E3D4FC PUT prefetch_cnt=7/1
18:11:16.132 strm00E3D4FC Start talksprut..
18:11:16.148 strm00E3D4FC Starting silence
18:11:16.179 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:16.195 strm00E3D4FC PUT prefetch_cnt=2/1
18:11:16.242 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:16.461 strm00E3D4FC PUT prefetch_cnt=12/1
18:11:16.554 strm00E3D4FC Start talksprut..
18:11:16.570 strm00E3D4FC Starting silence
18:11:16.726 strm00E3D4FC Start talksprut..
18:11:16.742 strm00E3D4FC Starting silence
18:11:17.148 strm00E3D4FC Start talksprut..
18:11:17.164 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:17.164 strm00E3D4FC Starting silence
18:11:17.367 strm00E3D4FC Start talksprut..
18:11:17.414 strm00E3D4FC Starting silence
18:11:17.461 strm00E3D4FC Start talksprut..
18:11:17.492 strm00E3D4FC Starting silence
18:11:17.508 strm00E3D4FC Start talksprut..
18:11:17.523 strm00E3D4FC Starting silence
18:11:17.554 strm00E3D4FC PUT prefetch_cnt=21/1
18:11:17.664 strm00E3D4FC Start talksprut..
18:11:17.679 strm00E3D4FC Starting silence
18:11:17.711 strm00E3D4FC Start talksprut..
18:11:17.742 strm00E3D4FC Starting silence
18:11:17.820 strm00E3D4FC Start talksprut..
18:11:17.929 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:18.179 strm00E3D4FC Starting silence
18:11:18.226 strm00E3D4FC Start talksprut..
18:11:18.258 strm00E3D4FC PUT prefetch_cnt=18/1
18:11:18.679 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:18.726 strm00E3D4FC Starting silence
18:11:18.851 strm00E3D4FC PUT prefetch_cnt=10/1
18:11:18.867 strm00E3D4FC Start talksprut..
18:11:18.883 strm00E3D4FC Starting silence
18:11:18.930 strm00E3D4FC Start talksprut..
18:11:19.180 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:19.211 strm00E3D4FC Starting silence
18:11:19.258 tsx00DEA95C Timeout timer event
18:11:19.258 tsx00DEA95C State changed from Completed to Terminated, event=TIMER
18:11:19.258 dlg00DFC08C Transaction tsx00DEA95C state changed to Terminated
18:11:19.258 dlg00DFC08C Dialog destroyed
18:11:19.258 tsx00DEA95C Timeout timer event
18:11:19.258 tsx00DEA95C State changed from Terminated to Destroyed, event=TIMER
18:11:19.258 tdta00E37898 Destroying txdata Response msg 200/BYE/cseq=21791 (tdta00E37898)
18:11:19.258 tsx00DEA95C Transaction destroyed!
18:11:19.273 strm00E3D4FC Start talksprut..
18:11:19.305 strm00E3D4FC Starting silence
18:11:19.398 strm00E3D4FC PUT prefetch_cnt=12/1
18:11:19.430 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:19.430 strm00E3D4FC Start talksprut..
18:11:19.445 strm00E3D4FC Starting silence
18:11:19.476 strm00E3D4FC PUT prefetch_cnt=4/1
18:11:19.508 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:19.523 strm00E3D4FC PUT prefetch_cnt=2/1
18:11:19.523 strm00E3D4FC Start talksprut..
18:11:19.539 strm00E3D4FC Starting silence
18:11:19.586 strm00E3D4FC Start talksprut..
18:11:19.601 strm00E3D4FC Starting silence
18:11:19.664 strm00E3D4FC Start talksprut..
18:11:19.711 strm00E3D4FC Starting silence
18:11:19.726 strm00E3D4FC Start talksprut..
18:11:19.742 strm00E3D4FC Starting silence
18:11:19.789 strm00E3D4FC Start talksprut..
18:11:19.805 strm00E3D4FC Starting silence
18:11:19.805 sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=6894 (rdata00DE754C)
18:11:19.805 pjsua_core.c RX 1215 bytes Request msg INVITE/cseq=6894 (rdata00DE754C) from UDP 172.18.1.218:4060:
INVITE sip:alice at 172.18.2.74:5060 SIP/2.0
Record-Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Max-Forwards: 8
Via: SIP/2.0/UDP 172.18.1.218:4060;branch=z9hG4bK6592.1b4cd5b5.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;branch=z9hG4bK6592.dde817e2.0
Via: SIP/2.0/UDP 172.18.1.218;branch=z9hG4bK6592.91140fa5.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK6592.39f44924.0
To: sip:alice at voip3gppsrv2;tag=d77e8361ab1d4cc5894928a47ca53aa6
From: sip:bob@voip3gppsrv2;tag=15a28719e9eb4442a1d20d24ca897b37
CSeq: 6894 INVITE
Call-ID: af199956066e448d851bdb067a6ced46
Content-Length: 456
User-Agent: OpenSIPS (1.4.0-notls (i386/linux))
Contact: <sip:bob at 172.18.1.78:5060>
Content-Type: application/sdp
P-Called-Party-ID: <sip:alice at voip3gppsrv2>
v=0
o=- 3449844671 3449844671 IN IP4 172.18.1.78
s=pjmedia
c=IN IP4 172.18.1.78
t=0 0
a=X-nat:0
m=audio 4004 RTP/AVP 103 102 104 117 3 0 8 9 101
a=rtcp:4005 IN IP4 172.18.1.78
a=rtpmap:103 speex/16000
a=rtpmap:102 speex/8000
a=rtpmap:104 speex/32000
a=rtpmap:117 iLBC/8000
a=fmtp:117 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
--end msg--
18:11:19.836 strm00E3D4FC Jitter buffer empty (prefetch=1)
18:11:19.836 strm00E3D4FC PUT prefetch_cnt=1/1
18:11:19.851 dlg00E2808C Received Request msg INVITE/cseq=6894 (rdata00DE754C)
18:11:19.851 tsx00DED7CC Transaction created for Request msg INVITE/cseq=6894 (rdata00DE754C)
18:11:19.851 tsx00DED7CC Incoming Request msg INVITE/cseq=6894 (rdata00DE754C) in state Null
18:11:19.851 tsx00DED7CC State changed from Null to Trying, event=RX_MSG
18:11:19.851 dlg00E2808C Transaction tsx00DED7CC state changed to Trying
18:11:19.851 inv00E2808C Got SDP offer in Request msg INVITE/cseq=6894 (rdata00DE754C)
18:11:19.851 pjsua_call.c Call 2: received updated media offer
18:11:19.851 endpoint Response msg 200/INVITE/cseq=6894 (tdta00E19028) created
18:11:19.851 inv00E2808C SDP negotiation done, status=0
18:11:19.851 pjsua_call.c Call 2: remote NAT type is 0 (Unknown)
18:11:19.867 pjsua_media.c Media session for call 2 is destroyed
18:11:19.867 strm00E3197C VAD temporarily disabled
18:11:19.867 rtp.c pjmedia_rtp_session_init: ses=00E32B50, default_pt=103, ssrc=0x3a284172
18:11:19.867 rtp.c pjmedia_rtp_session_init: ses=00E32FC4, default_pt=103, ssrc=0x3a284172
18:11:19.867 stream.c Stream strm00E3197C created
18:11:19.867 strm00E3197C Encoder stream started
18:11:19.867 strm00E3197C Decoder stream started
18:11:19.867 pjsua_media.c Media updates, stream #0: speex (sendrecv)
18:11:19.867 conference.c Port 3 (sip:bob at voip3gppsrv2) transmitting to port 0 (Microsoft Sound Mapper - Input)
18:11:19.867 strm00E3197C Jitter buffer empty (prefetch=0)
18:11:19.867 strm00E3197C Start talksprut..
18:11:19.867 conference.c Port 0 (Microsoft Sound Mapper - Input) transmitting to port 3 (sip:bob at voip3gppsrv2)
18:11:19.867 pjsua_app.c Media for call 2 is active
18:11:19.867 inv00E2808C Sending Response msg 200/INVITE/cseq=6894 (tdta00E19028)
18:11:19.867 dlg00E2808C Sending Response msg 200/INVITE/cseq=6894 (tdta00E19028)
18:11:19.867 tsx00DED7CC Sending Response msg 200/INVITE/cseq=6894 (tdta00E19028) in state Trying
18:11:19.867 sip_resolve.c Target '172.18.1.218:4060' type=UDP resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:11:19.867 pjsua_core.c TX 1037 bytes Response msg 200/INVITE/cseq=6894 (tdta00E19028) to UDP 172.18.1.218:4060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.18.1.218:4060;received=172.18.1.218;branch=z9hG4bK6592.1b4cd5b5.0
Via: SIP/2.0/UDP 172.18.1.218:6060;rport=6060;branch=z9hG4bK6592.dde817e2.0
Via: SIP/2.0/UDP 172.18.1.218;branch=z9hG4bK6592.91140fa5.0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK6592.39f44924.0
Record-Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Call-ID: af199956066e448d851bdb067a6ced46
From: <sip:bob@voip3gppsrv2>;tag=15a28719e9eb4442a1d20d24ca897b37
To: <sip:alice at voip3gppsrv2>;tag=d77e8361ab1d4cc5894928a47ca53aa6
CSeq: 6894 INVITE
Contact: <sip:alice at 172.18.2.74:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length: 254
v=0
o=- 3449844679 3449844661 IN IP4 172.18.2.74
s=pjmedia
c=IN IP4 172.18.2.74
t=0 0
a=X-nat:0
m=audio 4004 RTP/AVP 103 101
a=rtcp:4005 IN IP4 172.18.2.74
a=rtpmap:103 speex/16000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
--end msg--
18:11:19.914 strm00E3197C RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=0
18:11:19.930 Master/sound 345 samples reduced, buf_cnt=602
18:11:19.930 Master/sound Buffer size adjusted from 947 to 602 (eff_cnt=341)
18:11:19.930 tsx00DED7CC State changed from Trying to Completed, event=TX_MSG
18:11:19.930 dlg00E2808C Transaction tsx00DED7CC state changed to Completed
18:11:19.930 sip_endpoint.c Processing incoming message: Request msg ACK/cseq=6894 (rdata00DE754C)
18:11:19.930 pjsua_core.c RX 498 bytes Request msg ACK/cseq=6894 (rdata00DE754C) from UDP 172.18.1.218:6060:
ACK sip:alice at 172.18.2.74:5060 SIP/2.0
Max-Forwards: 9
Via: SIP/2.0/UDP 172.18.1.218:6060;branch=0
Via: SIP/2.0/UDP 172.18.1.218;branch=0
Via: SIP/2.0/UDP 172.18.1.218:5065;branch=z9hG4bK6592.39f44924.0
From: sip:bob@voip3gppsrv2;tag=15a28719e9eb4442a1d20d24ca897b37
Call-ID: af199956066e448d851bdb067a6ced46
To: <sip:alice at voip3gppsrv2>;tag=d77e8361ab1d4cc5894928a47ca53aa6
CSeq: 6894 ACK
User-Agent: OpenSIPS (1.4.0-notls (i386/linux))
Content-Length: 0
P-hint: I-CSCF rr-enforced
?
--end msg--
18:11:19.945 strm00E3197C Jitter buffer empty (prefetch=0)
18:11:19.961 dlg00E2808C Received Request msg ACK/cseq=6894 (rdata00DE754C)
18:11:19.961 tsx00DED7CC Request to terminate transaction
18:11:19.961 tsx00DED7CC State changed from Completed to Terminated, event=USER
18:11:19.961 dlg00E2808C Transaction tsx00DED7CC state changed to Terminated
18:11:19.961 tsx00DED7CC Timeout timer event
18:11:19.961 tsx00DED7CC State changed from Terminated to Destroyed, event=TIMER
18:11:19.961 tdta00E19028 Destroying txdata Response msg 200/INVITE/cseq=6894 (tdta00E19028)
18:11:19.961 tsx00DED7CC Transaction destroyed!
18:11:19.961 udp00DF2F58 Remote RTCP address switched to 172.18.1.222:4005
18:11:19.961 udp00DF2F58 Remote RTCP address switched to 172.18.1.78:4005
18:11:19.961 strm00E3197C RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
18:11:19.961 strm00E3197C jb updated(2), prefetch=1, size=1
18:11:19.976 strm00E3197C RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=-1
18:11:19.976 strm00E3197C Jitter buffer reset
18:11:19.992 strm00E3197C Jitter buffer empty (prefetch=1)
18:11:20.023 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:20.039 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:20.055 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:20.070 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:20.101 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:20.101 Master/sound 527 samples reduced, buf_cnt=1355
18:11:20.117 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:20.117 Master/sound 182 samples reduced, buf_cnt=1493
18:11:20.133 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:20.133 Master/sound 370 samples reduced, buf_cnt=1443
18:11:20.164 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:20.164 Master/sound 478 samples reduced, buf_cnt=1285
18:11:37.728 Master/sound 350 samples reduced, buf_cnt=1289
18:11:37.743 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:37.743 Master/sound 9 samples reduced, buf_cnt=1600
18:11:37.759 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:37.759 Master/sound 358 samples reduced, buf_cnt=1562
18:11:37.774 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:37.774 Master/sound 377 samples reduced, buf_cnt=1505
18:11:37.806 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:37.806 Master/sound 376 samples reduced, buf_cnt=1449
18:11:37.806 endpoint Request msg BYE/cseq=13714 (tdta00E19018) created.
18:11:37.806 inv00E2808C Sending Request msg BYE/cseq=13714 (tdta00E19018)
18:11:37.806 dlg00E2808C Sending Request msg BYE/cseq=13714 (tdta00E19018)
18:11:37.806 tsx00DED7CC Transaction created for Request msg BYE/cseq=13713 (tdta00E19018)
18:11:37.806 tsx00DED7CC Sending Request msg BYE/cseq=13713 (tdta00E19018) in state Null
18:11:37.806 sip_resolve.c DNS resolver not available, target 'pcscf.voip3gppsrv2:4060' type=Unspecified will be resolved with gethostbyname()
18:11:37.806 sip_resolve.c Target 'pcscf.voip3gppsrv2:4060' type=Unspecified resolved to '172.18.1.218:4060' type=UDP (UDP transport)
18:11:37.821 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:37.821 Master/sound 371 samples reduced, buf_cnt=1398
18:11:37.837 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:37.837 Master/sound 186 samples reduced, buf_cnt=1532
18:11:37.853 pjsua_core.c TX 815 bytes Request msg BYE/cseq=13713 (tdta00E19018) to UDP 172.18.1.218:4060:
BYE sip:bob at 172.18.1.78:5060 SIP/2.0
Via: SIP/2.0/UDP 172.18.2.74:5060;rport;branch=z9hG4bKPje3a80a89760443039b093984823ae0bc
Max-Forwards: 70
From: <sip:alice@voip3gppsrv2>;tag=d77e8361ab1d4cc5894928a47ca53aa6
To: <sip:bob at voip3gppsrv2>;tag=15a28719e9eb4442a1d20d24ca897b37
Call-ID: af199956066e448d851bdb067a6ced46
CSeq: 13713 BYE
Route: <sip:mt at pcscf.voip3gppsrv2:4060;lr>
Route: <sip:mt at scscf.voip3gppsrv2:6060;lr>
Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Route: <sip:172.18.1.218:5065;lr;ftag=15a28719e9eb4442a1d20d24ca897b37>
Route: <sip:mo at scscf.voip3gppsrv2:6060;lr>
Route: <sip:mo at pcscf.voip3gppsrv2:4060;lr>
Authorization: Digest username="alice at voip3gppsrv2", realm="voip3gppsrv2", nonce="", uri="sip:bob at 172.18.1.78:5060", response=""
User-Agent: PJSUA v1.1/win32
Content-Length: 0
?
--end msg--
18:11:37.884 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:37.884 Master/sound 370 samples reduced, buf_cnt=1482
18:11:37.884 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:37.884 Master/sound 210 samples reduced, buf_cnt=1592
18:11:37.884 tsx00DED7CC State changed from Null to Calling, event=TX_MSG
18:11:37.884 dlg00E2808C Transaction tsx00DED7CC state changed to Calling
18:11:37.899 sip_endpoint.c Processing incoming message: Response msg 200/BYE/cseq=13713 (rdata00DE754C)
18:11:37.899 pjsua_core.c RX 379 bytes Response msg 200/BYE/cseq=13713 (rdata00DE754C) from UDP 172.18.1.218:4060:
SIP/2.0 200 OK From AS
Via: SIP/2.0/UDP 172.18.2.74:5060;rport=5060;branch=z9hG4bKPje3a80a89760443039b093984823ae0bc
From: <sip:alice@voip3gppsrv2>;tag=d77e8361ab1d4cc5894928a47ca53aa6
To: <sip:bob at voip3gppsrv2>;tag=15a28719e9eb4442a1d20d24ca897b37
Call-ID: af199956066e448d851bdb067a6ced46
CSeq: 13713 BYE
Server: OpenSIPS (1.4.0-notls (i386/linux))
Content-Length: 0
?
--end msg--
18:11:37.915 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:37.915 Master/sound 534 samples reduced, buf_cnt=1378
18:11:37.915 tsx00DED7CC Incoming Response msg 200/BYE/cseq=13713 (rdata00DE754C) in state Calling
18:11:37.915 tsx00DED7CC State changed from Calling to Completed, event=RX_MSG
18:11:37.915 dlg00E2808C Received Response msg 200/BYE/cseq=13713 (rdata00DE754C)
18:11:37.915 dlg00E2808C Transaction tsx00DED7CC state changed to Completed
18:11:37.915 pjsua_app.c Call 2 is DISCONNECTED [reason=200 (Normal call clearing)]
18:11:37.915 pjsua_app.c Call 2 disconnected, dumping media stats..
18:11:37.915 pjsua_app.c 
[DISCONNCTD] To: <sip:bob at voip3gppsrv2>;tag=15a28719e9eb4442a1d20d24ca897b37
Call time: 00h:00m:38s, 1st res in 78 ms, conn in 203ms
SRTP status: Not active Crypto-suite: (null)
#0 speex @16KHz, sendrecv, peer=172.18.1.78:4004
RX pt=103, stat last update: never
total 4pkt 160B (320B +IP hdr) @avg=70bps/141bps
pkt loss=0 (0.0%), discrd=1 (25.0%), dup=0 (0.0%), reord=1 (25.0%)
(msec) min avg max last dev
loss period: 0.000 0.000 0.000 0.000 0.000
jitter : -0.001 0.000 0.000 0.000 0.000
TX pt=103, ptime=20ms, stat last update: never
total 7pkt 490B (770B +IP hdr) @avg 217bps/341bps
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 : 0.000 0.000 0.000 0.000 0.000
RTT msec : 0.000 0.000 0.000 0.000 0.000
Underflow, buf_cnt=0, will generate 1 frame186 samples reduced, buf_cnt=1512 18:11:37.946 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:37.946 Master/sound 377 samples reduced, buf_cnt=1455
18:11:37.962 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:37.962 Master/sound 197 samples reduced, buf_cnt=1578
18:11:37.978 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:37.978 Master/sound 364 samples reduced, buf_cnt=1534
18:11:37.993 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:37.993 Master/sound 552 samples reduced, buf_cnt=1302
18:11:38.024 ec00DEDF98 Underflow, buf_cnt=0, will generate 1 frame
18:11:38.024 Master/sound 211 samples reduced, buf_cnt=1411


      Own a website.Get an unlimited package.Pay next to nothing.*Go to http://in.business.yahoo.com/
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.pjsip.org/pipermail/pjsip_lists.pjsip.org/attachments/20090427/2eba8698/attachment-0001.html>