Hey, we found the error or rather the behavior we didn't expected. For our client we had to limit the maximum calls to two. And if the call hangup process is still in process, as in test step 4, the next call is invalid because it would exceed the call limit. I saw that there are discussions about the duration of a hangup and I understand that this is the desired behavior right now. But for me as a user of the library it would have helped so much to have a debug message that the call is invalid. Maybe you can add this in future versions. Cheers Frank 2014/1/9 Frank Haase <fra.haase at googlemail.com> > Hi, > > unfortunately there seems to be an error within the library when a client > tries to answer several calls. > In result there is no audio (because the media state never updates) and > the library is unable to hang up the call. > I check the hangup process many times and I'm pretty sure that I > disconnect the calls and conf slots in the right way. > > I'm using the Python bindings with a clean library, updated an hour ago. > It seems that I'm not the only one with this problem: > http://stackoverflow.com/questions/17583127/pjsip-stops-answering-calls > > Scenario to reproduce (Client A will fail): > 1. A calls B (hangs up after 5 sec) > 2. B calls A (hangs up after 5 sec) > 3. A calls B (hangs up after 5 sec) > 4. B calls A -> A will fail (sometimes you have to do this a couple more > times) > > Does anybody else have this issue? > Or can somebody see an error in the following logs? > > Here are the log files, the first real difference is at "Audio updated, > stream #0: G722 (sendrecv)". > There you can see that the good case is connecting the conf slots and the > bad case not. > > Good case log: > INVITE sip:10 at 192.168.0.102:5062;ob SIP/2.0 > Via: SIP/2.0/UDP 192.168.0.107:5060;branch=z9hG4bK6466c5b2 > Max-Forwards: 70 > From: "11" <sip:11@192.168.0.107>;tag=as08f31f2d > To: <sip:10 at 192.168.0.102:5062;ob> > Contact: <sip:11 at 192.168.0.107:5060> > Call-ID: 17fdb2920c77a6680376a069625f7f52 at 192.168.0.107:5060 > CSeq: 102 INVITE > User-Agent: Asterisk PBX 11.6.0 > Date: Thu, 09 Jan 2014 00:58:22 GMT > Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, > PUBLISH > Supported: replaces, timer > Content-Type: application/sdp > Content-Length: 307 > > v=0 > o=root 63923192 63923192 IN IP4 192.168.0.107 > s=Asterisk PBX 11.6.0 > c=IN IP4 192.168.0.107 > t=0 0 > m=audio 13140 RTP/AVP 9 18 101 > a=rtpmap:9 G722/8000 > a=rtpmap:18 G729/8000 > a=fmtp:18 annexb=no > a=rtpmap:101 telephone-event/8000 > a=fmtp:101 0-16 > a=silenceSupp:off - - - - > a=ptime:20 > a=sendrecv > > --end msg-- > 01:48:18.669 pjsua_call.c .Incoming Request msg INVITE/cseq=102 > (rdata0xb0401e44) > 01:48:18.669 tsx0xb04098b4 ...Transaction created for Request msg > INVITE/cseq=102 (rdata0xb0401e44) > 01:48:18.669 tsx0xb04098b4 ..Incoming Request msg INVITE/cseq=102 > (rdata0xb0401e44) in state Null > 01:48:18.669 tsx0xb04098b4 ...State changed from Null to Trying, > event=RX_MSG > 01:48:18.669 dlg0xb0404c0c ....Transaction tsx0xb04098b4 state changed > to Trying > 01:48:18.669 dlg0xb0404c0c ..UAS dialog created > 01:48:18.669 dlg0xb0404c0c ..Module mod-invite added as dialog usage, > data=0xb040a274 > 01:48:18.669 dlg0xb0404c0c ...Session count inc to 2 by mod-invite > 01:48:18.669 inv0xb0404c0c ..UAS invite session created for dialog > dlg0xb0404c0c > 01:48:18.669 pjsua_media.c ..Call 0: initializing media.. > 01:48:18.670 pjsua_media.c ...RTP socket reachable at 192.168.0.102:4004 > 01:48:18.670 pjsua_media.c ...RTCP socket reachable at > 192.168.0.102:4005 > 01:48:18.670 pjsua_media.c ...Media index 0 selected for audio call 0 > 01:48:18.670 pjsua_call.c ..Call 0: remote NAT type is 0 (Unknown) > 01:48:18.670 endpoint ...Response msg 100/INVITE/cseq=102 > (tdta0xb0407730) created > 01:48:18.670 dlg0xb0404c0c ...Initial answer Response msg > 100/INVITE/cseq=102 (tdta0xb0407730) > 01:48:18.670 inv0xb0404c0c ...Sending Response msg 100/INVITE/cseq=102 > (tdta0xb0407730) > 01:48:18.670 dlg0xb0404c0c ....Sending Response msg 100/INVITE/cseq=102 > (tdta0xb0407730) > 01:48:18.670 tsx0xb04098b4 ....Sending Response msg 100/INVITE/cseq=102 > (tdta0xb0407730) in state Trying > 01:48:18.670 sip_resolve.c .....Target '192.168.0.107:5060' type=UDP > resolved to '192.168.0.107:5060' type=UDP (UDP transport) > 01:48:18.670 pjsua_core.c .....TX 286 bytes Response msg > 100/INVITE/cseq=102 (tdta0xb0407730) to UDP 192.168.0.107:5060: > SIP/2.0 100 Trying > Via: SIP/2.0/UDP 192.168.0.107:5060 > ;received=192.168.0.107;branch=z9hG4bK6466c5b2 > Call-ID: 17fdb2920c77a6680376a069625f7f52 at 192.168.0.107:5060 > From: "11" <sip:11@192.168.0.107>;tag=as08f31f2d > To: <sip:10 at 192.168.0.102;ob> > CSeq: 102 INVITE > Content-Length: 0 > > > --end msg-- > 01:48:18.670 tsx0xb04098b4 .....State changed from Trying to Proceeding, > event=TX_MSG > 01:48:18.670 dlg0xb0404c0c ......Transaction tsx0xb04098b4 state changed > to Proceeding > 01:48:18.673 pjsua_aud.c !Creating file player: ./Sounds/phone.wav.. > 01:48:18.673 wav_player.c .File player './Sounds/phone.wav' created: > samp.rate=44100, ch=2, bufsize=4KB, filesize=108KB > 01:48:18.673 resample.c .resample created: high qualiy, large filter, > in/out rate=44100/16000 > 01:48:18.673 resample.c .resample created: high qualiy, large filter, > in/out rate=16000/44100 > 01:48:18.673 pjsua_aud.c .Player created, id=0, slot=1 > 01:48:18.673 pjsua_aud.c Conf connect: 1 --> 0 > 01:48:18.673 pjsua_aud.c .Set sound device: capture=-1, playback=-2 > 01:48:18.673 pjsua_aud.c ..Opening sound device PCM at 16000/1/20ms > 01:48:18.760 pjsua_aud.c ..Opening sound device PCM at 44100/1/20ms > 01:48:18.805 pa_dev.c ...Opened device HDA Intel: 92HD71B7X Analog > (hw:0,0)(ALSA)/HDA Intel: 92HD71B7X Analog (hw:0,0)(ALSA) for recording and > playback, sample rate=44100, ch=1, bits=16, 882 samples per frame, input > latency=100 ms, output latency=140 ms > 01:48:18.805 ec0x9fc5ad8 ...Creating AEC > 01:48:18.809 ec0x9fc5ad8 ...AEC created, clock_rate=44100, channel=1, > samples per frame=882, tail length=200 ms, latency=0 ms > 01:48:18.809 pa_dev.c ...Starting HDA Intel: 92HD71B7X Analog > (hw:0,0) stream.. > 01:48:18.809 pa_dev.c ...Done, status=0 > 01:48:18.809 resample.c ...resample created: high qualiy, large > filter, in/out rate=16000/44100 > 01:48:18.810 resample.c ...resample created: high qualiy, large > filter, in/out rate=44100/16000 > 01:48:18.810 conference.c .Port 1 (./Sounds/phone.wav) transmitting to > port 0 (HDA Intel: 92HD71B7X Analog (hw:0,0) (44KHz)) > 01:48:18.830 pa_dev.c !Recorder thread started > 01:48:18.833 os_core_unix.c Info: possibly re-registering existing thread > 01:48:18.833 pa_dev.c !Player thread started > 01:48:19.454 wav_player.c File port ./Sounds/phone.wav EOF > 01:48:19.454 wav_player.c File port ./Sounds/phone.wav rewinding.. > 01:48:19.530 pjsua_acc.c !Sending 2 bytes keep-alive packet for acc 0 > to 192.168.0.107:5060 > 01:48:19.530 tdta0xb0414ad0 Destroying txdata raw > 01:48:20.074 wav_player.c !File port ./Sounds/phone.wav EOF > 01:48:20.074 wav_player.c File port ./Sounds/phone.wav rewinding.. > 01:48:20.674 wav_player.c File port ./Sounds/phone.wav EOF > 01:48:20.674 wav_player.c File port ./Sounds/phone.wav rewinding.. > 01:48:20.819 pjsua_call.c !Answering call 0: code=200 > 01:48:20.819 inv0xb0404c0c ..SDP negotiation done, status=0 > 01:48:20.819 pjsua_call.c ...Call 0: remote NAT type is 0 (Unknown) > 01:48:20.819 pjsua_media.c ...Call 0: updating media.. > 01:48:20.819 pjsua_aud.c ....Audio channel update.. > 01:48:20.819 rtp.c .....pjmedia_rtp_session_init: ses=0x9fa4968, > default_pt=9, ssrc=0x252765e3 > 01:48:20.819 rtp.c .....pjmedia_rtp_session_init: ses=0x9fa4ff0, > default_pt=9, ssrc=0x252765e3 > 01:48:20.819 stream.c .....Stream strm0x9fa2ea4 created > 01:48:20.819 strm0x9fa2ea4 .....Encoder stream started > 01:48:20.819 strm0x9fa2ea4 .....Decoder stream started > 01:48:20.819 pjsua_media.c ....Audio updated, stream #0: G722 (sendrecv) > 01:48:20.820 inv0xb0404c0c ..Sending Response msg 200/INVITE/cseq=102 > (tdta0xb0407730) > 01:48:20.820 dlg0xb0404c0c ...Sending Response msg 200/INVITE/cseq=102 > (tdta0xb0407730) > 01:48:20.820 tsx0xb04098b4 ...Sending Response msg 200/INVITE/cseq=102 > (tdta0xb0407730) in state Proceeding > 01:48:20.820 pjsua_core.c ....TX 817 bytes Response msg > 200/INVITE/cseq=102 (tdta0xb0407730) to UDP 192.168.0.107:5060: > SIP/2.0 200 OK > Via: SIP/2.0/UDP 192.168.0.107:5060 > ;received=192.168.0.107;branch=z9hG4bK6466c5b2 > Call-ID: 17fdb2920c77a6680376a069625f7f52 at 192.168.0.107:5060 > From: "11" <sip:11@192.168.0.107>;tag=as08f31f2d > To: <sip:10 at 192.168.0.102;ob>;tag=ARH8ajxp8.nX0N7Ay0DXdfsZp90yQi.- > CSeq: 102 INVITE > Contact: <sip:10 at 192.168.0.102:5062;ob> > Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, > REFER, MESSAGE, OPTIONS > Supported: replaces, 100rel, timer, norefersub > Content-Type: application/sdp > Content-Length: 277 > > v=0 > o=- 3598217298 3598217299 IN IP4 192.168.0.102 > s=pjmedia > b=AS:84 > t=0 0 > a=X-nat:0 > m=audio 4004 RTP/AVP 9 101 > c=IN IP4 192.168.0.102 > b=TIAS:64000 > a=rtcp:4005 IN IP4 192.168.0.102 > a=sendrecv > a=rtpmap:9 G722/8000 > a=rtpmap:101 telephone-event/8000 > a=fmtp:101 0-15 > > --end msg-- > 01:48:20.820 tsx0xb04098b4 ....State changed from Proceeding to > Completed, event=TX_MSG > 01:48:20.820 dlg0xb0404c0c .....Transaction tsx0xb04098b4 state changed > to Completed > 01:48:20.822 pjsua_aud.c Conf disconnect: 1 -x- 0 > 01:48:20.822 conference.c .Port 1 (./Sounds/phone.wav) stop > transmitting to port 0 (HDA Intel: 92HD71B7X Analog (hw:0,0) (44KHz)) > 01:48:20.822 pjsua_aud.c Destroying player 0.. > 01:48:20.833 strm0x9fa2ea4 !Start talksprut.. > 01:48:20.869 sip_endpoint.c !Processing incoming message: Request msg > ACK/cseq=102 (rdata0xb0401e44) > 01:48:20.869 pjsua_core.c .RX 412 bytes Request msg ACK/cseq=102 > (rdata0xb0401e44) from UDP 192.168.0.107:5060: > ACK sip:10 at 192.168.0.102:5062;ob SIP/2.0 > Via: SIP/2.0/UDP 192.168.0.107:5060;branch=z9hG4bK43c5ca62 > Max-Forwards: 70 > From: "11" <sip:11@192.168.0.107>;tag=as08f31f2d > To: <sip:10 at 192.168.0.102:5062;ob>;tag=ARH8ajxp8.nX0N7Ay0DXdfsZp90yQi.- > Contact: <sip:11 at 192.168.0.107:5060> > Call-ID: 17fdb2920c77a6680376a069625f7f52 at 192.168.0.107:5060 > CSeq: 102 ACK > User-Agent: Asterisk PBX 11.6.0 > Content-Length: 0 > > > --end msg-- > 01:48:20.869 dlg0xb0404c0c .Received Request msg ACK/cseq=102 > (rdata0xb0401e44) > 01:48:20.869 tsx0xb04098b4 ..Request to terminate transaction > 01:48:20.869 tsx0xb04098b4 ...State changed from Completed to > Terminated, event=USER > 01:48:20.869 dlg0xb0404c0c ....Transaction tsx0xb04098b4 state changed > to Terminated > 01:48:20.870 sip_endpoint.c Processing incoming message: Request msg > INVITE/cseq=103 (rdata0xb0401e44) > 01:48:20.870 pjsua_core.c .RX 821 bytes Request msg INVITE/cseq=103 > (rdata0xb0401e44) from UDP 192.168.0.107:5060: > INVITE sip:10 at 192.168.0.102:5062;ob SIP/2.0 > Via: SIP/2.0/UDP 192.168.0.107:5060;branch=z9hG4bK270bd6ba > Max-Forwards: 70 > From: "11" <sip:11@192.168.0.107>;tag=as08f31f2d > To: <sip:10 at 192.168.0.102:5062;ob>;tag=ARH8ajxp8.nX0N7Ay0DXdfsZp90yQi.- > Contact: <sip:11 at 192.168.0.107:5060> > Call-ID: 17fdb2920c77a6680376a069625f7f52 at 192.168.0.107:5060 > CSeq: 103 INVITE > User-Agent: Asterisk PBX 11.6.0 > Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, > PUBLISH > Supported: replaces, timer > Content-Type: application/sdp > Content-Length: 259 > > v=0 > o=root 63923192 63923193 IN IP4 192.168.0.111 > s=Asterisk PBX 11.6.0 > c=IN IP4 192.168.0.111 > t=0 0 > m=audio 4036 RTP/AVP 9 101 > a=rtpmap:9 G722/8000 > a=rtpmap:101 telephone-event/8000 > a=fmtp:101 0-16 > a=silenceSupp:off - - - - > a=ptime:20 > a=sendrecv > > --end msg-- > 01:48:20.870 dlg0xb0404c0c .Received Request msg INVITE/cseq=103 > (rdata0xb0401e44) > 01:48:20.870 tsx0xb040879c ...Transaction created for Request msg > INVITE/cseq=103 (rdata0xb0401e44) > 01:48:20.870 tsx0xb040879c ..Incoming Request msg INVITE/cseq=103 > (rdata0xb0401e44) in state Null > 01:48:20.870 tsx0xb040879c ...State changed from Null to Trying, > event=RX_MSG > 01:48:20.870 dlg0xb0404c0c ....Transaction tsx0xb040879c state changed > to Trying > 01:48:20.870 inv0xb0404c0c .....Got SDP offer in Request msg > INVITE/cseq=103 (rdata0xb0401e44) > 01:48:20.870 pjsua_call.c .....Call 0: received updated media offer > 01:48:20.870 pjsua_media.c ......Call 0: re-initializing media.. > 01:48:20.871 pjsua_media.c .......Media index 0 selected for audio call 0 > 01:48:20.871 endpoint .....Response msg 200/INVITE/cseq=103 > (tdta0xb0415e20) created > 01:48:20.872 inv0xb0404c0c .....SDP negotiation done, status=0 > 01:48:20.872 pjsua_call.c ......Call 0: remote NAT type is 0 (Unknown) > 01:48:20.872 pjsua_media.c ......Call 0: updating media.. > 01:48:20.872 strm0x9fa2ea4 ........JB summary: > size=0/eff=0 prefetch=0 level=0 > delay (min/max/avg/dev)=0/0/0/0 ms > burst (min/max/avg/dev)=0/0/0/0 frames > lost=0 discard=0 empty=0 > 01:48:20.872 pjsua_media.c ........Media stream call00:0 is destroyed > 01:48:20.872 pjsua_aud.c .......Audio channel update.. > 01:48:20.872 rtp.c ........pjmedia_rtp_session_init: > ses=0xb04215b8, default_pt=9, ssrc=0x252765e3 > 01:48:20.872 rtp.c ........pjmedia_rtp_session_init: > ses=0xb0418f40, default_pt=9, ssrc=0x252765e3 > 01:48:20.872 stream.c ........Stream strm0xb0418184 created > 01:48:20.872 strm0xb0418184 ........Encoder stream started > 01:48:20.872 strm0xb0418184 ........Decoder stream started > 01:48:20.872 pjsua_media.c .......Audio updated, stream #0: G722 > (sendrecv) > 01:48:20.873 pjsua_aud.c ......Conf connect: 0 --> 1 > 01:48:20.873 conference.c .......Port 0 (HDA Intel: 92HD71B7X Analog > (hw:0,0) (44KHz)) transmitting to port 1 (sip:11 at 192.168.0.107) > 01:48:20.873 pjsua_aud.c ......Conf connect: 1 --> 0 > 01:48:20.873 conference.c .......Port 1 (sip:11 at 192.168.0.107) > transmitting to port 0 (HDA Intel: 92HD71B7X Analog (hw:0,0) (44KHz)) > 01:48:20.873 pjsua_aud.c ......Creating recorder 1389228500.87.wav.. > 01:48:20.873 wav_writer.c .......File writer '1389228500.87.wav' > created: samp.rate=16000, bufsize=4KB > 01:48:20.873 pjsua_aud.c .......Recorder created, id=0, slot=2 > 01:48:20.873 pjsua_aud.c ......Conf connect: 1 --> 2 > 01:48:20.873 conference.c .......Port 1 (sip:11 at 192.168.0.107) > transmitting to port 2 (1389228500.87.wav) > 01:48:20.873 pjsua_aud.c ......Conf connect: 2 --> 1 > 01:48:20.873 conference.c .......Port 2 (1389228500.87.wav) > transmitting to port 1 (sip:11 at 192.168.0.107) > 01:48:20.873 inv0xb0404c0c ......Sending Response msg > 200/INVITE/cseq=103 (tdta0xb0415e20) > 01:48:20.873 dlg0xb0404c0c .......Sending Response msg > 200/INVITE/cseq=103 (tdta0xb0415e20) > 01:48:20.873 tsx0xb040879c .......Sending Response msg > 200/INVITE/cseq=103 (tdta0xb0415e20) in state Trying > 01:48:20.873 sip_resolve.c ........Target '192.168.0.107:5060' type=UDP > resolved to '192.168.0.107:5060' type=UDP (UDP transport) > 01:48:20.873 pjsua_core.c ........TX 817 bytes Response msg > 200/INVITE/cseq=103 (tdta0xb0415e20) to UDP 192.168.0.107:5060: > SIP/2.0 200 OK > Via: SIP/2.0/UDP 192.168.0.107:5060 > ;received=192.168.0.107;branch=z9hG4bK270bd6ba > Call-ID: 17fdb2920c77a6680376a069625f7f52 at 192.168.0.107:5060 > From: "11" <sip:11@192.168.0.107>;tag=as08f31f2d > To: <sip:10 at 192.168.0.102;ob>;tag=ARH8ajxp8.nX0N7Ay0DXdfsZp90yQi.- > CSeq: 103 INVITE > Contact: <sip:10 at 192.168.0.102:5062;ob> > Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, > REFER, MESSAGE, OPTIONS > Supported: replaces, 100rel, timer, norefersub > Content-Type: application/sdp > Content-Length: 277 > > v=0 > o=- 3598217298 3598217300 IN IP4 192.168.0.102 > s=pjmedia > b=AS:84 > t=0 0 > a=X-nat:0 > m=audio 4004 RTP/AVP 9 101 > c=IN IP4 192.168.0.102 > b=TIAS:64000 > a=rtcp:4005 IN IP4 192.168.0.102 > a=sendrecv > a=rtpmap:9 G722/8000 > a=rtpmap:101 telephone-event/8000 > a=fmtp:101 0-15 > > --end msg-- > 01:48:20.874 tsx0xb040879c ........State changed from Trying to > Completed, event=TX_MSG > 01:48:20.874 dlg0xb0404c0c .........Transaction tsx0xb040879c state > changed to Completed > 01:48:20.874 strm0xb0418184 !Jitter buffer is bufferring (prefetch=0), plc > invoked > 01:48:20.874 strm0xb0418184 Start talksprut.. > 01:48:20.924 tsx0xb04098b4 !Timeout timer event > 01:48:20.924 tsx0xb04098b4 .State changed from Terminated to Destroyed, > event=TIMER > 01:48:20.924 tdta0xb0407730 ..Destroying txdata Response msg > 200/INVITE/cseq=102 (tdta0xb0407730) > 01:48:20.924 tsx0xb04098b4 Transaction destroyed! > 01:48:20.924 sip_endpoint.c Processing incoming message: Request msg > ACK/cseq=103 (rdata0xb0401e44) > 01:48:20.924 pjsua_core.c .RX 412 bytes Request msg ACK/cseq=103 > (rdata0xb0401e44) from UDP 192.168.0.107:5060: > ACK sip:10 at 192.168.0.102:5062;ob SIP/2.0 > Via: SIP/2.0/UDP 192.168.0.107:5060;branch=z9hG4bK3a20e93c > Max-Forwards: 70 > From: "11" <sip:11@192.168.0.107>;tag=as08f31f2d > To: <sip:10 at 192.168.0.102:5062;ob>;tag=ARH8ajxp8.nX0N7Ay0DXdfsZp90yQi.- > Contact: <sip:11 at 192.168.0.107:5060> > Call-ID: 17fdb2920c77a6680376a069625f7f52 at 192.168.0.107:5060 > CSeq: 103 ACK > User-Agent: Asterisk PBX 11.6.0 > Content-Length: 0 > > > --end msg-- > 01:48:20.924 dlg0xb0404c0c .Received Request msg ACK/cseq=103 > (rdata0xb0401e44) > 01:48:20.924 tsx0xb040879c ..Request to terminate transaction > 01:48:20.924 tsx0xb040879c ...State changed from Completed to > Terminated, event=USER > 01:48:20.924 dlg0xb0404c0c ....Transaction tsx0xb040879c state changed > to Terminated > 01:48:20.974 tsx0xb040879c Timeout timer event > 01:48:20.975 tsx0xb040879c .State changed from Terminated to Destroyed, > event=TIMER > 01:48:20.975 tdta0xb0415e20 ..Destroying txdata Response msg > 200/INVITE/cseq=103 (tdta0xb0415e20) > 01:48:20.975 tsx0xb040879c Transaction destroyed! > 01:48:20.977 strm0xb0418184 !RTP status: badpt=0, badssrc=0, dup=0, > outorder=0, probation=-1, restart=0 > 01:48:20.993 strm0xb0418184 !Jitter buffer starts returning normal frames > (after 6 empty/lost) > 01:48:21.014 strm0xb0418184 Jitter buffer empty (prefetch=0), plc invoked > 01:48:21.021 stream.c !G722 codec used, remote samples per frame > detected = 80 > 01:48:21.026 sip_endpoint.c !Processing incoming message: Request msg > INVITE/cseq=104 (rdata0xb0412b9c) > 01:48:21.026 pjsua_core.c .RX 821 bytes Request msg INVITE/cseq=104 > (rdata0xb0412b9c) from UDP 192.168.0.107:5060: > INVITE sip:10 at 192.168.0.102:5062;ob SIP/2.0 > Via: SIP/2.0/UDP 192.168.0.107:5060;branch=z9hG4bK1f74322f > Max-Forwards: 70 > From: "11" <sip:11@192.168.0.107>;tag=as08f31f2d > To: <sip:10 at 192.168.0.102:5062;ob>;tag=ARH8ajxp8.nX0N7Ay0DXdfsZp90yQi.- > Contact: <sip:11 at 192.168.0.107:5060> > Call-ID: 17fdb2920c77a6680376a069625f7f52 at 192.168.0.107:5060 > CSeq: 104 INVITE > User-Agent: Asterisk PBX 11.6.0 > Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, > PUBLISH > Supported: replaces, timer > Content-Type: application/sdp > Content-Length: 259 > > v=0 > o=root 63923192 63923194 IN IP4 192.168.0.111 > s=Asterisk PBX 11.6.0 > c=IN IP4 192.168.0.111 > t=0 0 > m=audio 4036 RTP/AVP 9 101 > a=rtpmap:9 G722/8000 > a=rtpmap:101 telephone-event/8000 > a=fmtp:101 0-16 > a=silenceSupp:off - - - - > a=ptime:20 > a=sendrecv > > --end msg-- > 01:48:21.026 dlg0xb0404c0c .Received Request msg INVITE/cseq=104 > (rdata0xb0412b9c) > 01:48:21.026 tsx0xb04098b4 ...Transaction created for Request msg > INVITE/cseq=104 (rdata0xb0412b9c) > 01:48:21.026 tsx0xb04098b4 ..Incoming Request msg INVITE/cseq=104 > (rdata0xb0412b9c) in state Null > 01:48:21.026 tsx0xb04098b4 ...State changed from Null to Trying, > event=RX_MSG > 01:48:21.026 dlg0xb0404c0c ....Transaction tsx0xb04098b4 state changed > to Trying > 01:48:21.026 inv0xb0404c0c .....Got SDP offer in Request msg > INVITE/cseq=104 (rdata0xb0412b9c) > 01:48:21.026 pjsua_call.c .....Call 0: received updated media offer > 01:48:21.026 pjsua_media.c ......Call 0: re-initializing media.. > 01:48:21.026 pjsua_media.c .......Media index 0 selected for audio call 0 > 01:48:21.026 endpoint .....Response msg 200/INVITE/cseq=104 > (tdta0xb041ba50) created > 01:48:21.026 inv0xb0404c0c .....SDP negotiation done, status=0 > 01:48:21.026 pjsua_call.c ......Call 0: remote NAT type is 0 (Unknown) > 01:48:21.026 pjsua_media.c ......Call 0: updating media.. > 01:48:21.027 pjsua_media.c .......Call 0: stream #0 (audio) unchanged. > 01:48:21.027 pjsua_media.c .......Audio updated, stream #0: G722 > (sendrecv) > 01:48:21.027 pjsua_aud.c ......Conf disconnect: 1 -x- 2 > 01:48:21.027 conference.c .......Port 1 (sip:11 at 192.168.0.107) stop > transmitting to port 2 (1389228500.87.wav) > 01:48:21.027 pjsua_aud.c ......Conf disconnect: 2 -x- 1 > 01:48:21.027 conference.c .......Port 2 (1389228500.87.wav) stop > transmitting to port 1 (sip:11 at 192.168.0.107) > 01:48:21.027 pjsua_aud.c ......Destroying recorder 0.. > 01:48:21.029 pjsua_aud.c ......Conf disconnect: 1 -x- 0 > 01:48:21.029 conference.c .......Port 1 (sip:11 at 192.168.0.107) stop > transmitting to port 0 (HDA Intel: 92HD71B7X Analog (hw:0,0) (44KHz)) > 01:48:21.029 pjsua_aud.c ......Conf disconnect: 0 -x- 1 > 01:48:21.029 conference.c .......Port 0 (HDA Intel: 92HD71B7X Analog > (hw:0,0) (44KHz)) stop transmitting to port 1 (sip:11 at 192.168.0.107) > 01:48:21.029 Master/sound .......Delay buffer is reset > 01:48:21.029 pjsua_aud.c ......Conf connect: 0 --> 1 > 01:48:21.029 conference.c .......Port 0 (HDA Intel: 92HD71B7X Analog > (hw:0,0) (44KHz)) transmitting to port 1 (sip:11 at 192.168.0.107) > 01:48:21.029 pjsua_aud.c ......Conf connect: 1 --> 0 > 01:48:21.029 conference.c .......Port 1 (sip:11 at 192.168.0.107) > transmitting to port 0 (HDA Intel: 92HD71B7X Analog (hw:0,0) (44KHz)) > 01:48:21.033 strm0xb0418184 !Jitter buffer starts returning normal frames > (after 1 empty/lost) > 01:48:21.036 pjsua_aud.c !......Creating recorder 1389228501.04.wav.. > 01:48:21.036 wav_writer.c .......File writer '1389228501.04.wav' > created: samp.rate=16000, bufsize=4KB > 01:48:21.036 pjsua_aud.c .......Recorder created, id=0, slot=2 > 01:48:21.036 pjsua_aud.c ......Conf connect: 1 --> 2 > 01:48:21.036 conference.c .......Port 1 (sip:11 at 192.168.0.107) > transmitting to port 2 (1389228501.04.wav) > 01:48:21.036 pjsua_aud.c ......Conf connect: 2 --> 1 > 01:48:21.036 conference.c .......Port 2 (1389228501.04.wav) > transmitting to port 1 (sip:11 at 192.168.0.107) > 01:48:21.036 inv0xb0404c0c ......Sending Response msg > 200/INVITE/cseq=104 (tdta0xb041ba50) > 01:48:21.036 dlg0xb0404c0c .......Sending Response msg > 200/INVITE/cseq=104 (tdta0xb041ba50) > 01:48:21.036 tsx0xb04098b4 .......Sending Response msg > 200/INVITE/cseq=104 (tdta0xb041ba50) in state Trying > 01:48:21.036 sip_resolve.c ........Target '192.168.0.107:5060' type=UDP > resolved to '192.168.0.107:5060' type=UDP (UDP transport) > 01:48:21.036 pjsua_core.c ........TX 817 bytes Response msg > 200/INVITE/cseq=104 (tdta0xb041ba50) to UDP 192.168.0.107:5060: > SIP/2.0 200 OK > Via: SIP/2.0/UDP 192.168.0.107:5060 > ;received=192.168.0.107;branch=z9hG4bK1f74322f > Call-ID: 17fdb2920c77a6680376a069625f7f52 at 192.168.0.107:5060 > From: "11" <sip:11@192.168.0.107>;tag=as08f31f2d > To: <sip:10 at 192.168.0.102;ob>;tag=ARH8ajxp8.nX0N7Ay0DXdfsZp90yQi.- > CSeq: 104 INVITE > Contact: <sip:10 at 192.168.0.102:5062;ob> > Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, > REFER, MESSAGE, OPTIONS > Supported: replaces, 100rel, timer, norefersub > Content-Type: application/sdp > Content-Length: 277 > > v=0 > o=- 3598217298 3598217301 IN IP4 192.168.0.102 > s=pjmedia > b=AS:84 > t=0 0 > a=X-nat:0 > m=audio 4004 RTP/AVP 9 101 > c=IN IP4 192.168.0.102 > b=TIAS:64000 > a=rtcp:4005 IN IP4 192.168.0.102 > a=sendrecv > a=rtpmap:9 G722/8000 > a=rtpmap:101 telephone-event/8000 > a=fmtp:101 0-15 > > --end msg-- > 01:48:21.036 tsx0xb04098b4 ........State changed from Trying to > Completed, event=TX_MSG > 01:48:21.036 dlg0xb0404c0c .........Transaction tsx0xb04098b4 state > changed to Completed > 01:48:21.052 strm0xb0418184 !Jitter buffer empty (prefetch=0), plc invoked > 01:48:21.072 strm0xb0418184 Jitter buffer starts returning normal frames > (after 1 empty/lost) > 01:48:21.087 sip_endpoint.c !Processing incoming message: Request msg > ACK/cseq=104 (rdata0xb0412b9c) > 01:48:21.087 pjsua_core.c .RX 412 bytes Request msg ACK/cseq=104 > (rdata0xb0412b9c) from UDP 192.168.0.107:5060: > ACK sip:10 at 192.168.0.102:5062;ob SIP/2.0 > Via: SIP/2.0/UDP 192.168.0.107:5060;branch=z9hG4bK72e33611 > Max-Forwards: 70 > From: "11" <sip:11@192.168.0.107>;tag=as08f31f2d > To: <sip:10 at 192.168.0.102:5062;ob>;tag=ARH8ajxp8.nX0N7Ay0DXdfsZp90yQi.- > Contact: <sip:11 at 192.168.0.107:5060> > Call-ID: 17fdb2920c77a6680376a069625f7f52 at 192.168.0.107:5060 > CSeq: 104 ACK > User-Agent: Asterisk PBX 11.6.0 > Content-Length: 0 > > > > Bad case log: > INVITE sip:10 at 192.168.0.102:5062;ob SIP/2.0 > Via: SIP/2.0/UDP 192.168.0.107:5060;branch=z9hG4bK2535482e > Max-Forwards: 70 > From: "11" <sip:11@192.168.0.107>;tag=as4eccd05c > To: <sip:10 at 192.168.0.102:5062;ob> > Contact: <sip:11 at 192.168.0.107:5060> > Call-ID: 4ddc01fa545970931399514d02b0274f at 192.168.0.107:5060 > CSeq: 102 INVITE > User-Agent: Asterisk PBX 11.6.0 > Date: Thu, 09 Jan 2014 01:00:15 GMT > Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, > PUBLISH > Supported: replaces, timer > Content-Type: application/sdp > Content-Length: 309 > > v=0 > o=root 272953138 272953138 IN IP4 192.168.0.107 > s=Asterisk PBX 11.6.0 > c=IN IP4 192.168.0.107 > t=0 0 > m=audio 10836 RTP/AVP 9 18 101 > a=rtpmap:9 G722/8000 > a=rtpmap:18 G729/8000 > a=fmtp:18 annexb=no > a=rtpmap:101 telephone-event/8000 > a=fmtp:101 0-16 > a=silenceSupp:off - - - - > a=ptime:20 > a=sendrecv > > --end msg-- > 01:50:12.466 pjsua_call.c .Incoming Request msg INVITE/cseq=102 > (rdata0xb04063ec) > 01:50:12.466 tsx0xb0418ad4 ...Transaction created for Request msg > INVITE/cseq=102 (rdata0xb04063ec) > 01:50:12.466 tsx0xb0418ad4 ..Incoming Request msg INVITE/cseq=102 > (rdata0xb04063ec) in state Null > 01:50:12.466 tsx0xb0418ad4 ...State changed from Null to Trying, > event=RX_MSG > 01:50:12.466 dlg0xb041ca54 ....Transaction tsx0xb0418ad4 state changed > to Trying > 01:50:12.466 dlg0xb041ca54 ..UAS dialog created > 01:50:12.466 dlg0xb041ca54 ..Module mod-invite added as dialog usage, > data=0xb040bea4 > 01:50:12.466 dlg0xb041ca54 ...Session count inc to 2 by mod-invite > 01:50:12.466 inv0xb041ca54 ..UAS invite session created for dialog > dlg0xb041ca54 > 01:50:12.466 pjsua_media.c ..Call 0: initializing media.. > 01:50:12.466 pjsua_media.c ...RTP socket reachable at 192.168.0.102:4020 > 01:50:12.466 pjsua_media.c ...RTCP socket reachable at > 192.168.0.102:4021 > 01:50:12.466 pjsua_media.c ...Media index 0 selected for audio call 0 > 01:50:12.467 pjsua_call.c ..Call 0: remote NAT type is 0 (Unknown) > 01:50:12.467 endpoint ...Response msg 100/INVITE/cseq=102 > (tdta0xb0401d50) created > 01:50:12.467 dlg0xb041ca54 ...Initial answer Response msg > 100/INVITE/cseq=102 (tdta0xb0401d50) > 01:50:12.467 inv0xb041ca54 ...Sending Response msg 100/INVITE/cseq=102 > (tdta0xb0401d50) > 01:50:12.467 dlg0xb041ca54 ....Sending Response msg 100/INVITE/cseq=102 > (tdta0xb0401d50) > 01:50:12.467 tsx0xb0418ad4 ....Sending Response msg 100/INVITE/cseq=102 > (tdta0xb0401d50) in state Trying > 01:50:12.467 sip_resolve.c .....Target '192.168.0.107:5060' type=UDP > resolved to '192.168.0.107:5060' type=UDP (UDP transport) > 01:50:12.467 pjsua_core.c .....TX 286 bytes Response msg > 100/INVITE/cseq=102 (tdta0xb0401d50) to UDP 192.168.0.107:5060: > SIP/2.0 100 Trying > Via: SIP/2.0/UDP 192.168.0.107:5060 > ;received=192.168.0.107;branch=z9hG4bK2535482e > Call-ID: 4ddc01fa545970931399514d02b0274f at 192.168.0.107:5060 > From: "11" <sip:11@192.168.0.107>;tag=as4eccd05c > To: <sip:10 at 192.168.0.102;ob> > CSeq: 102 INVITE > Content-Length: 0 > > > --end msg-- > 01:50:12.467 tsx0xb0418ad4 .....State changed from Trying to Proceeding, > event=TX_MSG > 01:50:12.467 dlg0xb041ca54 ......Transaction tsx0xb0418ad4 state changed > to Proceeding > 01:50:12.469 pjsua_aud.c !Creating file player: ./Sounds/phone.wav.. > 01:50:12.469 wav_player.c .File player './Sounds/phone.wav' created: > samp.rate=44100, ch=2, bufsize=4KB, filesize=108KB > 01:50:12.469 resample.c .resample created: high qualiy, large filter, > in/out rate=44100/16000 > 01:50:12.469 resample.c .resample created: high qualiy, large filter, > in/out rate=16000/44100 > 01:50:12.469 pjsua_aud.c .Player created, id=0, slot=1 > 01:50:12.469 pjsua_aud.c Conf connect: 1 --> 0 > 01:50:12.469 pjsua_aud.c .Set sound device: capture=-1, playback=-2 > 01:50:12.469 pjsua_aud.c ..Opening sound device PCM at 16000/1/20ms > 01:50:12.556 pjsua_aud.c ..Opening sound device PCM at 44100/1/20ms > 01:50:12.601 pa_dev.c ...Opened device HDA Intel: 92HD71B7X Analog > (hw:0,0)(ALSA)/HDA Intel: 92HD71B7X Analog (hw:0,0)(ALSA) for recording and > playback, sample rate=44100, ch=1, bits=16, 882 samples per frame, input > latency=100 ms, output latency=140 ms > 01:50:12.601 ec0x9fc3a00 ...Creating AEC > 01:50:12.606 ec0x9fc3a00 ...AEC created, clock_rate=44100, channel=1, > samples per frame=882, tail length=200 ms, latency=0 ms > 01:50:12.606 pa_dev.c ...Starting HDA Intel: 92HD71B7X Analog > (hw:0,0) stream.. > 01:50:12.606 pa_dev.c ...Done, status=0 > 01:50:12.606 resample.c ...resample created: high qualiy, large > filter, in/out rate=16000/44100 > 01:50:12.606 resample.c ...resample created: high qualiy, large > filter, in/out rate=44100/16000 > 01:50:12.606 conference.c .Port 1 (./Sounds/phone.wav) transmitting to > port 0 (HDA Intel: 92HD71B7X Analog (hw:0,0) (44KHz)) > 01:50:12.626 pa_dev.c !Recorder thread started > 01:50:12.630 os_core_unix.c Info: possibly re-registering existing thread > 01:50:12.630 pa_dev.c !Player thread started > 01:50:13.250 wav_player.c File port ./Sounds/phone.wav EOF > 01:50:13.250 wav_player.c File port ./Sounds/phone.wav rewinding.. > 01:50:13.293 pjsua_call.c !Answering call 0: code=200 > 01:50:13.293 inv0xb041ca54 ..SDP negotiation done, status=0 > 01:50:13.293 pjsua_call.c ...Call 0: remote NAT type is 0 (Unknown) > 01:50:13.293 pjsua_media.c ...Call 0: updating media.. > 01:50:13.293 pjsua_aud.c ....Audio channel update.. > 01:50:13.293 rtp.c .....pjmedia_rtp_session_init: ses=0xa0c9d78, > default_pt=9, ssrc=0x12c09f5f > 01:50:13.293 rtp.c .....pjmedia_rtp_session_init: ses=0xa0ca400, > default_pt=9, ssrc=0x12c09f5f > 01:50:13.293 stream.c .....Stream strm0x9d05174 created > 01:50:13.293 strm0x9d05174 .....Encoder stream started > 01:50:13.293 strm0x9d05174 .....Decoder stream started > 01:50:13.293 pjsua_media.c ....Audio updated, stream #0: G722 (sendrecv) > 01:50:13.293 inv0xb041ca54 ..Sending Response msg 200/INVITE/cseq=102 > (tdta0xb0401d50) > 01:50:13.293 dlg0xb041ca54 ...Sending Response msg 200/INVITE/cseq=102 > (tdta0xb0401d50) > 01:50:13.293 tsx0xb0418ad4 ...Sending Response msg 200/INVITE/cseq=102 > (tdta0xb0401d50) in state Proceeding > 01:50:13.293 pjsua_core.c ....TX 817 bytes Response msg > 200/INVITE/cseq=102 (tdta0xb0401d50) to UDP 192.168.0.107:5060: > SIP/2.0 200 OK > Via: SIP/2.0/UDP 192.168.0.107:5060 > ;received=192.168.0.107;branch=z9hG4bK2535482e > Call-ID: 4ddc01fa545970931399514d02b0274f at 192.168.0.107:5060 > From: "11" <sip:11@192.168.0.107>;tag=as4eccd05c > To: <sip:10 at 192.168.0.102;ob>;tag=JG1iaNLT-oOKC381jNGKGnGnLSY6QDd2 > CSeq: 102 INVITE > Contact: <sip:10 at 192.168.0.102:5062;ob> > Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, > REFER, MESSAGE, OPTIONS > Supported: replaces, 100rel, timer, norefersub > Content-Type: application/sdp > Content-Length: 277 > > v=0 > o=- 3598217412 3598217413 IN IP4 192.168.0.102 > s=pjmedia > b=AS:84 > t=0 0 > a=X-nat:0 > m=audio 4020 RTP/AVP 9 101 > c=IN IP4 192.168.0.102 > b=TIAS:64000 > a=rtcp:4021 IN IP4 192.168.0.102 > a=sendrecv > a=rtpmap:9 G722/8000 > a=rtpmap:101 telephone-event/8000 > a=fmtp:101 0-15 > > --end msg-- > 01:50:13.293 tsx0xb0418ad4 ....State changed from Proceeding to > Completed, event=TX_MSG > 01:50:13.293 dlg0xb041ca54 .....Transaction tsx0xb0418ad4 state changed > to Completed > 01:50:13.294 pjsua_aud.c Conf disconnect: 1 -x- 0 > 01:50:13.294 conference.c .Port 1 (./Sounds/phone.wav) stop > transmitting to port 0 (HDA Intel: 92HD71B7X Analog (hw:0,0) (44KHz)) > 01:50:13.294 pjsua_aud.c Destroying player 0.. > 01:50:13.308 strm0x9d05174 !Start talksprut.. > 01:50:13.327 sip_endpoint.c !Processing incoming message: Request msg > ACK/cseq=102 (rdata0xb04063ec) > 01:50:13.327 pjsua_core.c .RX 412 bytes Request msg ACK/cseq=102 > (rdata0xb04063ec) from UDP 192.168.0.107:5060: > ACK sip:10 at 192.168.0.102:5062;ob SIP/2.0 > Via: SIP/2.0/UDP 192.168.0.107:5060;branch=z9hG4bK516a89c0 > Max-Forwards: 70 > From: "11" <sip:11@192.168.0.107>;tag=as4eccd05c > To: <sip:10 at 192.168.0.102:5062;ob>;tag=JG1iaNLT-oOKC381jNGKGnGnLSY6QDd2 > Contact: <sip:11 at 192.168.0.107:5060> > Call-ID: 4ddc01fa545970931399514d02b0274f at 192.168.0.107:5060 > CSeq: 102 ACK > User-Agent: Asterisk PBX 11.6.0 > Content-Length: 0 > > > --end msg-- > 01:50:13.327 dlg0xb041ca54 .Received Request msg ACK/cseq=102 > (rdata0xb04063ec) > 01:50:13.327 tsx0xb0418ad4 ..Request to terminate transaction > 01:50:13.327 tsx0xb0418ad4 ...State changed from Completed to > Terminated, event=USER > 01:50:13.327 dlg0xb041ca54 ....Transaction tsx0xb0418ad4 state changed > to Terminated > 01:50:13.327 sip_endpoint.c Processing incoming message: Request msg > INVITE/cseq=103 (rdata0xb04063ec) > 01:50:13.327 pjsua_core.c .RX 823 bytes Request msg INVITE/cseq=103 > (rdata0xb04063ec) from UDP 192.168.0.107:5060: > INVITE sip:10 at 192.168.0.102:5062;ob SIP/2.0 > Via: SIP/2.0/UDP 192.168.0.107:5060;branch=z9hG4bK0c04680f > Max-Forwards: 70 > From: "11" <sip:11@192.168.0.107>;tag=as4eccd05c > To: <sip:10 at 192.168.0.102:5062;ob>;tag=JG1iaNLT-oOKC381jNGKGnGnLSY6QDd2 > Contact: <sip:11 at 192.168.0.107:5060> > Call-ID: 4ddc01fa545970931399514d02b0274f at 192.168.0.107:5060 > CSeq: 103 INVITE > User-Agent: Asterisk PBX 11.6.0 > Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, > PUBLISH > Supported: replaces, timer > Content-Type: application/sdp > Content-Length: 261 > > v=0 > o=root 272953138 272953139 IN IP4 192.168.0.111 > s=Asterisk PBX 11.6.0 > c=IN IP4 192.168.0.111 > t=0 0 > m=audio 4052 RTP/AVP 9 101 > a=rtpmap:9 G722/8000 > a=rtpmap:101 telephone-event/8000 > a=fmtp:101 0-16 > a=silenceSupp:off - - - - > a=ptime:20 > a=sendrecv > > --end msg-- > 01:50:13.327 dlg0xb041ca54 .Received Request msg INVITE/cseq=103 > (rdata0xb04063ec) > 01:50:13.327 tsx0xb0414b34 ...Transaction created for Request msg > INVITE/cseq=103 (rdata0xb04063ec) > 01:50:13.327 tsx0xb0414b34 ..Incoming Request msg INVITE/cseq=103 > (rdata0xb04063ec) in state Null > 01:50:13.327 tsx0xb0414b34 ...State changed from Null to Trying, > event=RX_MSG > 01:50:13.327 dlg0xb041ca54 ....Transaction tsx0xb0414b34 state changed > to Trying > 01:50:13.327 inv0xb041ca54 .....Got SDP offer in Request msg > INVITE/cseq=103 (rdata0xb04063ec) > 01:50:13.327 pjsua_call.c .....Call 0: received updated media offer > 01:50:13.327 pjsua_media.c ......Call 0: re-initializing media.. > 01:50:13.327 pjsua_media.c .......Media index 0 selected for audio call 0 > 01:50:13.327 endpoint .....Response msg 200/INVITE/cseq=103 > (tdta0xb04209e8) created > 01:50:13.327 inv0xb041ca54 .....SDP negotiation done, status=0 > 01:50:13.327 pjsua_call.c ......Call 0: remote NAT type is 0 (Unknown) > 01:50:13.328 pjsua_media.c ......Call 0: updating media.. > 01:50:13.328 strm0x9d05174 ........JB summary: > size=0/eff=0 prefetch=0 level=0 > delay (min/max/avg/dev)=0/0/0/0 ms > burst (min/max/avg/dev)=0/0/0/0 frames > lost=0 discard=0 empty=0 > 01:50:13.328 pjsua_media.c ........Media stream call00:0 is destroyed > 01:50:13.328 pjsua_aud.c .......Audio channel update.. > 01:50:13.328 rtp.c ........pjmedia_rtp_session_init: > ses=0xb0423ce0, default_pt=9, ssrc=0x12c09f5f > 01:50:13.328 rtp.c ........pjmedia_rtp_session_init: > ses=0xb0424368, default_pt=9, ssrc=0x12c09f5f > 01:50:13.328 stream.c ........Stream strm0xb042221c created > 01:50:13.328 strm0xb042221c ........Encoder stream started > 01:50:13.328 strm0xb042221c ........Decoder stream started > 01:50:13.328 pjsua_media.c .......Audio updated, stream #0: G722 > (sendrecv) > 01:50:13.328 inv0xb041ca54 ......Sending Response msg > 200/INVITE/cseq=103 (tdta0xb04209e8) > 01:50:13.329 dlg0xb041ca54 .......Sending Response msg > 200/INVITE/cseq=103 (tdta0xb04209e8) > 01:50:13.329 tsx0xb0414b34 .......Sending Response msg > 200/INVITE/cseq=103 (tdta0xb04209e8) in state Trying > 01:50:13.329 sip_resolve.c ........Target '192.168.0.107:5060' type=UDP > resolved to '192.168.0.107:5060' type=UDP (UDP transport) > 01:50:13.329 pjsua_core.c ........TX 817 bytes Response msg > 200/INVITE/cseq=103 (tdta0xb04209e8) to UDP 192.168.0.107:5060: > SIP/2.0 200 OK > Via: SIP/2.0/UDP 192.168.0.107:5060 > ;received=192.168.0.107;branch=z9hG4bK0c04680f > Call-ID: 4ddc01fa545970931399514d02b0274f at 192.168.0.107:5060 > From: "11" <sip:11@192.168.0.107>;tag=as4eccd05c > To: <sip:10 at 192.168.0.102;ob>;tag=JG1iaNLT-oOKC381jNGKGnGnLSY6QDd2 > CSeq: 103 INVITE > Contact: <sip:10 at 192.168.0.102:5062;ob> > Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, > REFER, MESSAGE, OPTIONS > Supported: replaces, 100rel, timer, norefersub > Content-Type: application/sdp > Content-Length: 277 > > v=0 > o=- 3598217412 3598217414 IN IP4 192.168.0.102 > s=pjmedia > b=AS:84 > t=0 0 > a=X-nat:0 > m=audio 4020 RTP/AVP 9 101 > c=IN IP4 192.168.0.102 > b=TIAS:64000 > a=rtcp:4021 IN IP4 192.168.0.102 > a=sendrecv > a=rtpmap:9 G722/8000 > a=rtpmap:101 telephone-event/8000 > a=fmtp:101 0-15 > > --end msg-- > 01:50:13.329 tsx0xb0414b34 ........State changed from Trying to > Completed, event=TX_MSG > 01:50:13.329 dlg0xb041ca54 .........Transaction tsx0xb0414b34 state > changed to Completed > 01:50:13.332 strm0xb042221c !Start talksprut.. > 01:50:13.379 tsx0xb0418ad4 !Timeout timer event > 01:50:13.380 tsx0xb0418ad4 .State changed from Terminated to Destroyed, > event=TIMER > 01:50:13.380 tdta0xb0401d50 ..Destroying txdata Response msg > 200/INVITE/cseq=102 (tdta0xb0401d50) > 01:50:13.380 tsx0xb0418ad4 Transaction destroyed! > 01:50:13.380 sip_endpoint.c Processing incoming message: Request msg > ACK/cseq=103 (rdata0xb04063ec) > 01:50:13.380 pjsua_core.c .RX 412 bytes Request msg ACK/cseq=103 > (rdata0xb04063ec) from UDP 192.168.0.107:5060: > ACK sip:10 at 192.168.0.102:5062;ob SIP/2.0 > Via: SIP/2.0/UDP 192.168.0.107:5060;branch=z9hG4bK4a686cc5 > Max-Forwards: 70 > From: "11" <sip:11@192.168.0.107>;tag=as4eccd05c > To: <sip:10 at 192.168.0.102:5062;ob>;tag=JG1iaNLT-oOKC381jNGKGnGnLSY6QDd2 > Contact: <sip:11 at 192.168.0.107:5060> > Call-ID: 4ddc01fa545970931399514d02b0274f at 192.168.0.107:5060 > CSeq: 103 ACK > User-Agent: Asterisk PBX 11.6.0 > Content-Length: 0 > > > --end msg-- > 01:50:13.380 dlg0xb041ca54 .Received Request msg ACK/cseq=103 > (rdata0xb04063ec) > 01:50:13.380 tsx0xb0414b34 ..Request to terminate transaction > 01:50:13.380 tsx0xb0414b34 ...State changed from Completed to > Terminated, event=USER > 01:50:13.380 dlg0xb041ca54 ....Transaction tsx0xb0414b34 state changed > to Terminated > 01:50:13.418 strm0xb042221c !RTP status: badpt=0, badssrc=0, dup=0, > outorder=0, probation=-1, restart=0 > 01:50:13.419 stream.c G722 codec used, remote samples per frame > detected = 80 > 01:50:13.430 tsx0xb0414b34 !Timeout timer event > 01:50:13.430 tsx0xb0414b34 .State changed from Terminated to Destroyed, > event=TIMER > 01:50:13.430 tdta0xb04209e8 ..Destroying txdata Response msg > 200/INVITE/cseq=103 (tdta0xb04209e8) > 01:50:13.430 tsx0xb0414b34 Transaction destroyed! > 01:50:13.482 sip_endpoint.c Processing incoming message: Request msg > INVITE/cseq=104 (rdata0xb0412b9c) > 01:50:13.482 pjsua_core.c .RX 823 bytes Request msg INVITE/cseq=104 > (rdata0xb0412b9c) from UDP 192.168.0.107:5060: > INVITE sip:10 at 192.168.0.102:5062;ob SIP/2.0 > Via: SIP/2.0/UDP 192.168.0.107:5060;branch=z9hG4bK3ada0d52 > Max-Forwards: 70 > From: "11" <sip:11@192.168.0.107>;tag=as4eccd05c > To: <sip:10 at 192.168.0.102:5062;ob>;tag=JG1iaNLT-oOKC381jNGKGnGnLSY6QDd2 > Contact: <sip:11 at 192.168.0.107:5060> > Call-ID: 4ddc01fa545970931399514d02b0274f at 192.168.0.107:5060 > CSeq: 104 INVITE > User-Agent: Asterisk PBX 11.6.0 > Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, > PUBLISH > Supported: replaces, timer > Content-Type: application/sdp > Content-Length: 261 > > v=0 > o=root 272953138 272953140 IN IP4 192.168.0.111 > s=Asterisk PBX 11.6.0 > c=IN IP4 192.168.0.111 > t=0 0 > m=audio 4052 RTP/AVP 9 101 > a=rtpmap:9 G722/8000 > a=rtpmap:101 telephone-event/8000 > a=fmtp:101 0-16 > a=silenceSupp:off - - - - > a=ptime:20 > a=sendrecv > > --end msg-- > 01:50:13.482 dlg0xb041ca54 .Received Request msg INVITE/cseq=104 > (rdata0xb0412b9c) > 01:50:13.482 tsx0xb0418ad4 ...Transaction created for Request msg > INVITE/cseq=104 (rdata0xb0412b9c) > 01:50:13.482 tsx0xb0418ad4 ..Incoming Request msg INVITE/cseq=104 > (rdata0xb0412b9c) in state Null > 01:50:13.482 tsx0xb0418ad4 ...State changed from Null to Trying, > event=RX_MSG > 01:50:13.482 dlg0xb041ca54 ....Transaction tsx0xb0418ad4 state changed > to Trying > 01:50:13.482 inv0xb041ca54 .....Got SDP offer in Request msg > INVITE/cseq=104 (rdata0xb0412b9c) > 01:50:13.482 pjsua_call.c .....Call 0: received updated media offer > 01:50:13.482 pjsua_media.c ......Call 0: re-initializing media.. > 01:50:13.482 pjsua_media.c .......Media index 0 selected for audio call 0 > 01:50:13.482 endpoint .....Response msg 200/INVITE/cseq=104 > (tdta0xb04209e8) created > 01:50:13.482 inv0xb041ca54 .....SDP negotiation done, status=0 > 01:50:13.482 pjsua_call.c ......Call 0: remote NAT type is 0 (Unknown) > 01:50:13.482 pjsua_media.c ......Call 0: updating media.. > 01:50:13.482 pjsua_media.c .......Call 0: stream #0 (audio) unchanged. > 01:50:13.482 pjsua_media.c .......Audio updated, stream #0: G722 > (sendrecv) > 01:50:13.482 inv0xb041ca54 ......Sending Response msg > 200/INVITE/cseq=104 (tdta0xb04209e8) > 01:50:13.482 dlg0xb041ca54 .......Sending Response msg > 200/INVITE/cseq=104 (tdta0xb04209e8) > 01:50:13.482 tsx0xb0418ad4 .......Sending Response msg > 200/INVITE/cseq=104 (tdta0xb04209e8) in state Trying > 01:50:13.482 sip_resolve.c ........Target '192.168.0.107:5060' type=UDP > resolved to '192.168.0.107:5060' type=UDP (UDP transport) > 01:50:13.482 pjsua_core.c ........TX 817 bytes Response msg > 200/INVITE/cseq=104 (tdta0xb04209e8) to UDP 192.168.0.107:5060: > SIP/2.0 200 OK > Via: SIP/2.0/UDP 192.168.0.107:5060 > ;received=192.168.0.107;branch=z9hG4bK3ada0d52 > Call-ID: 4ddc01fa545970931399514d02b0274f at 192.168.0.107:5060 > From: "11" <sip:11@192.168.0.107>;tag=as4eccd05c > To: <sip:10 at 192.168.0.102;ob>;tag=JG1iaNLT-oOKC381jNGKGnGnLSY6QDd2 > CSeq: 104 INVITE > Contact: <sip:10 at 192.168.0.102:5062;ob> > Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, > REFER, MESSAGE, OPTIONS > Supported: replaces, 100rel, timer, norefersub > Content-Type: application/sdp > Content-Length: 277 > > v=0 > o=- 3598217412 3598217415 IN IP4 192.168.0.102 > s=pjmedia > b=AS:84 > t=0 0 > a=X-nat:0 > m=audio 4020 RTP/AVP 9 101 > c=IN IP4 192.168.0.102 > b=TIAS:64000 > a=rtcp:4021 IN IP4 192.168.0.102 > a=sendrecv > a=rtpmap:9 G722/8000 > a=rtpmap:101 telephone-event/8000 > a=fmtp:101 0-15 > > --end msg-- > 01:50:13.483 tsx0xb0418ad4 ........State changed from Trying to > Completed, event=TX_MSG > 01:50:13.483 dlg0xb041ca54 .........Transaction tsx0xb0418ad4 state > changed to Completed > 01:50:13.533 sip_endpoint.c Processing incoming message: Request msg > ACK/cseq=104 (rdata0xb0412b9c) > 01:50:13.533 pjsua_core.c .RX 412 bytes Request msg ACK/cseq=104 > (rdata0xb0412b9c) from UDP 192.168.0.107:5060: > ACK sip:10 at 192.168.0.102:5062;ob SIP/2.0 > Via: SIP/2.0/UDP 192.168.0.107:5060;branch=z9hG4bK7082f339 > Max-Forwards: 70 > From: "11" <sip:11@192.168.0.107>;tag=as4eccd05c > To: <sip:10 at 192.168.0.102:5062;ob>;tag=JG1iaNLT-oOKC381jNGKGnGnLSY6QDd2 > Contact: <sip:11 at 192.168.0.107:5060> > Call-ID: 4ddc01fa545970931399514d02b0274f at 192.168.0.107:5060 > CSeq: 104 ACK > User-Agent: Asterisk PBX 11.6.0 > Content-Length: 0 > > > --end msg-- > > > Any help would be greatly appreciated! > > Cheers > Frank > -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://lists.pjsip.org/pipermail/pjsip_lists.pjsip.org/attachments/20140118/eb3e85f1/attachment-0001.html>
