Re: Accoustic echo cancelation

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

 

Hello,

I changed to Raspberry Pi 3, and the echo situation is the same; Echo not cancelled!

Can find in the logs any clue why is this happening?


Thanks.




15:15:51.161 os_core_unix.c !pjlib 2.4.5 for POSIX initialized
15:15:51.164 sip_endpoint.c  .Creating endpoint instance...
15:15:51.165          pjlib  .select() I/O Queue created (0x15b8bf8)
15:15:51.166 sip_endpoint.c  .Module "mod-msg-print" registered
15:15:51.166 sip_transport.  .Transport manager created.
15:15:51.167   pjsua_core.c  .PJSUA state changed: NULL --> CREATED
15:15:51.167 sip_endpoint.c  .Module "mod-pjsua-log" registered
15:15:51.168 sip_endpoint.c  .Module "mod-tsx-layer" registered
15:15:51.168 sip_endpoint.c  .Module "mod-stateful-util" registered
15:15:51.169 sip_endpoint.c  .Module "mod-ua" registered
15:15:51.169 sip_endpoint.c  .Module "mod-100rel" registered
15:15:51.170 sip_endpoint.c  .Module "mod-pjsua" registered
15:15:51.170 sip_endpoint.c  .Module "mod-invite" registered
15:15:51.265     alsa_dev.c  ..Added sound device sysdefault:CARD=ALSA
15:15:51.270     alsa_dev.c  ..Added sound device dmix:CARD=ALSA,DEV=0
15:15:51.273     alsa_dev.c  ..Added sound device dmix:CARD=ALSA,DEV=1
15:15:51.278     alsa_dev.c  ..Added sound device hw:CARD=ALSA,DEV=0
15:15:51.279     alsa_dev.c  ..Added sound device hw:CARD=ALSA,DEV=1
15:15:51.279     alsa_dev.c  ..Added sound device plughw:CARD=ALSA,DEV=0
15:15:51.280     alsa_dev.c  ..Added sound device plughw:CARD=ALSA,DEV=1
15:15:51.289     alsa_dev.c  ..Added sound device sysdefault:CARD=Device
15:15:51.291     alsa_dev.c  ..Added sound device front:CARD=Device,DEV=0
15:15:51.292     alsa_dev.c  ..Added sound device surround21:CARD=Device,DEV=0
15:15:51.294     alsa_dev.c  ..Added sound device surround40:CARD=Device,DEV=0
15:15:51.296     alsa_dev.c  ..Added sound device surround41:CARD=Device,DEV=0
15:15:51.298     alsa_dev.c  ..Added sound device surround50:CARD=Device,DEV=0
15:15:51.300     alsa_dev.c  ..Added sound device surround51:CARD=Device,DEV=0
15:15:51.301     alsa_dev.c  ..Added sound device surround71:CARD=Device,DEV=0
15:15:51.304     alsa_dev.c  ..Added sound device iec958:CARD=Device,DEV=0
15:15:51.309     alsa_dev.c  ..Added sound device dmix:CARD=Device,DEV=0
15:15:51.313     alsa_dev.c  ..Added sound device dsnoop:CARD=Device,DEV=0
15:15:51.314     alsa_dev.c  ..Added sound device hw:CARD=Device,DEV=0
15:15:51.314     alsa_dev.c  ..Added sound device plughw:CARD=Device,DEV=0
15:15:51.315     alsa_dev.c  ..ALSA driver found 20 devices
15:15:51.315     alsa_dev.c  ..ALSA initialized
15:15:51.315          pjlib  ..select() I/O Queue created (0x15eed6c)
15:15:51.315   conference.c  ..Creating conference bridge with 254 ports
15:15:51.315   Master/sound  ..Using delay buffer with WSOLA.
15:15:51.329 sip_endpoint.c  .Module "mod-evsub" registered
15:15:51.329 sip_endpoint.c  .Module "mod-presence" registered
15:15:51.329        evsub.c  .Event pkg "presence" registered by mod-presence
15:15:51.329 sip_endpoint.c  .Module "mod-mwi" registered
15:15:51.329        evsub.c  .Event pkg "message-summary" registered by mod-mwi
15:15:51.330 sip_endpoint.c  .Module "mod-refer" registered
15:15:51.330        evsub.c  .Event pkg "refer" registered by mod-refer
15:15:51.330 sip_endpoint.c  .Module "mod-pjsua-pres" registered
15:15:51.330 sip_endpoint.c  .Module "mod-pjsua-im" registered
15:15:51.330 sip_endpoint.c  .Module "mod-pjsua-options" registered
15:15:51.330   pjsua_core.c  .1 SIP worker threads created
15:15:51.330   pjsua_core.c  .pjsua version 2.4.5 for Linux-4.1.19/armv7l/glibc-2.19 initialized
15:15:51.330   pjsua_core.c  .PJSUA state changed: CREATED --> INIT
15:15:51.331   pjsua_core.c  SIP UDP socket reachable at 192.168.1.206:5060
15:15:51.331   udp0x15d9210  SIP UDP transport started, published address is 192.168.1.206:5060
15:15:51.331   pjsua_core.c  PJSUA state changed: INIT --> STARTING
15:15:51.331 sip_endpoint.c  .Module "mod-unsolicited-mwi" registered
15:15:51.331   pjsua_core.c  .PJSUA state changed: STARTING --> RUNNING
15:15:51.331    pjsua_acc.c  Adding account: id=sip:511@raspbx
15:15:51.331    pjsua_acc.c  .Account sip:511@raspbx added with id 0
15:15:51.331    pjsua_acc.c  .Acc 0: setting registration..
15:15:51.331       endpoint  ..Request msg REGISTER/cseq=8445 (tdta0x15f7748) created.
15:15:51.331   tsx0x15f87b4  ...Transaction created for Request msg REGISTER/cseq=8446 (tdta0x15f7748)
15:15:51.331   tsx0x15f87b4  ..Sending Request msg REGISTER/cseq=8446 (tdta0x15f7748) in state Null
15:15:51.331  sip_resolve.c  ...DNS resolver not available, target 'raspbx:0' type=Unspecified will be resolved with getaddrinfo()
15:15:51.335  sip_resolve.c  ...Target 'raspbx:0' type=Unspecified resolved to '192.168.1.40:5060' type=UDP (UDP transport)
15:15:51.335   pjsua_core.c  ...TX 462 bytes Request msg REGISTER/cseq=8446 (tdta0x15f7748) to UDP 192.168.1.40:5060:
REGISTER sip:raspbx SIP/2.0
Via: SIP/2.0/UDP 192.168.1.206:5060;rport;branch=z9hG4bKPjfsCydZd0rmC.rZym0JPeO1Udl8Y5BaG6
Max-Forwards: 70
From: <sip:511@raspbx>;tag=JT0sL4JEZWqfHHd9YDnOOp1Tcbmneb.b
To: <sip:511@raspbx>
Call-ID: 1qDB9TlQQxR-djUWVFjpQpJ7OlylITVQ
CSeq: 8446 REGISTER
Contact: <sip:511@192.168.1.206:5060;ob>
Expires: 300
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Content-Length:  0


--end msg--
15:15:51.335   tsx0x15f87b4  ...State changed from Null to Calling, event=TX_MSG
15:15:51.336    pjsua_acc.c  ..Acc 0: Registration sent
15:15:51.336   pjsua_call.c  Making call with acc #0 to sip:501@raspbx
15:15:51.336    pjsua_aud.c  .Set sound device: capture=-1, playback=-2
15:15:51.336    pjsua_aud.c  ..Opening sound device PCM@16000/1/20ms
15:15:51.336     alsa_dev.c  ...open_playback: Open playback device 'sysdefault:CARD=Device'
15:15:51.340 sip_endpoint.c !Processing incoming message: Response msg 401/REGISTER/cseq=8446 (rdata0x15f4bf4)
15:15:51.340   pjsua_core.c  .RX 557 bytes Response msg 401/REGISTER/cseq=8446 (rdata0x15f4bf4) from UDP 192.168.1.40:5060:
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.206:5060;branch=z9hG4bKPjfsCydZd0rmC.rZym0JPeO1Udl8Y5BaG6;received=192.168.1.206;rport=5060
From: <sip:511@raspbx>;tag=JT0sL4JEZWqfHHd9YDnOOp1Tcbmneb.b
To: <sip:511@raspbx>;tag=as530f6e44
Call-ID: 1qDB9TlQQxR-djUWVFjpQpJ7OlylITVQ
CSeq: 8446 REGISTER
Server: FPBX-13.0.105(11.22.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="49ee1c7e"
Content-Length: 0


--end msg--
15:15:51.340   tsx0x15f87b4  .Incoming Response msg 401/REGISTER/cseq=8446 (rdata0x15f4bf4) in state Calling
15:15:51.340   tsx0x15f87b4  ..State changed from Calling to Completed, event=RX_MSG
15:15:51.341     alsa_dev.c !...Opened device alsa(sysdefault:CARD=Device) for playing, sample rate=16000, ch=1, bits=16, period size=320 frames, latency=149 ms
15:15:51.341     alsa_dev.c  ...open_capture: Open capture device 'sysdefault:CARD=Device'
15:15:51.347     alsa_dev.c  ...Opened device alsa(sysdefault:CARD=Device) for capture, sample rate=16000, ch=1, bits=16, period size=320 frames, latency=106 ms
15:15:51.347    ec0x160f6b0  ...Creating AEC
15:15:51.348    ec0x160f6b0  ...AEC created, clock_rate=16000, channel=1, samples per frame=320, tail length=200 ms, latency=0 ms
15:15:51.349          speex !warning: discarded first playback frame
15:15:51.349     alsa_dev.c !ca_thread_func(1784): Set thread priority for audio capture thread.
15:15:51.349   dlg0x16392bc !.UAC dialog created
15:15:51.349          speex !warning: discarded first playback frame
15:15:51.349   dlg0x16392bc !..Session count inc to 2 by mod-pjsua
15:15:51.349  pjsua_media.c  .Call 0: initializing media..
15:15:51.349          speex !warning: discarded first playback frame
15:15:51.349          speex  warning: discarded first playback frame
15:15:51.349  pjsua_media.c !..RTP socket reachable at 192.168.1.206:4000
15:15:51.350  pjsua_media.c  ..RTCP socket reachable at 192.168.1.206:4001
15:15:51.350  pjsua_media.c  ..Media index 0 selected for audio call 0
15:15:51.350   dlg0x16392bc  ..Session count dec to 2 by mod-pjsua
15:15:51.350   dlg0x16392bc  .Module mod-invite added as dialog usage, data="">
15:15:51.350   dlg0x16392bc  ..Session count inc to 4 by mod-invite
15:15:51.350          speex !warning: discarded first playback frame
15:15:51.350   dlg0x16392bc !.Module mod-100rel added as dialog usage, data="">
15:15:51.350   dlg0x16392bc  .100rel module attached
15:15:51.350   inv0x16392bc  .UAC invite session created for dialog dlg0x16392bc
15:15:51.350       endpoint  .Request msg INVITE/cseq=29025 (tdta0x163f278) created.
15:15:51.350   inv0x16392bc  ..Sending Request msg INVITE/cseq=29025 (tdta0x163f278)
15:15:51.350   dlg0x16392bc  ...Sending Request msg INVITE/cseq=29025 (tdta0x163f278)
15:15:51.350   tsx0x164128c  ....Transaction created for Request msg INVITE/cseq=29024 (tdta0x163f278)
15:15:51.350   tsx0x164128c  ...Sending Request msg INVITE/cseq=29024 (tdta0x163f278) in state Null
15:15:51.350  sip_resolve.c  ....DNS resolver not available, target 'raspbx:0' type=Unspecified will be resolved with getaddrinfo()
15:15:51.350          speex !warning: discarded first playback frame
15:15:51.350          speex  warning: discarded first playback frame
15:15:51.351          speex  warning: discarded first playback frame
15:15:51.353  sip_resolve.c !....Target 'raspbx:0' type=Unspecified resolved to '192.168.1.40:5060' type=UDP (UDP transport)
15:15:51.353   pjsua_core.c  ....TX 1038 bytes Request msg INVITE/cseq=29024 (tdta0x163f278) to UDP 192.168.1.40:5060:
INVITE sip:501@raspbx SIP/2.0
Via: SIP/2.0/UDP 192.168.1.206:5060;rport;branch=z9hG4bKPjo41IhhWHdzIpp4.RQWgPgFY8FZQZcuqT
Max-Forwards: 70
From: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
To: sip:501@raspbx
Contact: <sip:511@192.168.1.206:5060;ob>
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 29024 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
Content-Type: application/sdp
Content-Length:   476

v=0
o=- 3670326951 3670326951 IN IP4 192.168.1.206
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 98 97 99 104 3 0 8 9 96
c=IN IP4 192.168.1.206
b=TIAS:64000
a=rtcp:4001 IN IP4 192.168.1.206
a=sendrecv
a=rtpmap:98 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:99 speex/32000
a=rtpmap:104 iLBC/8000
a=fmtp:104 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16

--end msg--
15:15:51.354   tsx0x164128c  ....State changed from Null to Calling, event=TX_MSG
15:15:51.354   dlg0x16392bc  .....Transaction tsx0x164128c state changed to Calling
15:15:51.354            APP  .......Call 0 state=CALLING
15:15:51.354  tsx0x759004cc !....Transaction created for Request msg REGISTER/cseq=8447 (tdta0x15f7748)
15:15:51.354  tsx0x759004cc  ...Sending Request msg REGISTER/cseq=8447 (tdta0x15f7748) in state Null
15:15:51.354       endpoint  ....Request msg REGISTER/cseq=8447 (tdta0x15f7748): skipping target resolution because address is already set
15:15:51.354   pjsua_core.c  ....TX 614 bytes Request msg REGISTER/cseq=8447 (tdta0x15f7748) to UDP 192.168.1.40:5060:
REGISTER sip:raspbx SIP/2.0
Via: SIP/2.0/UDP 192.168.1.206:5060;rport;branch=z9hG4bKPje3xDRkVFhCWHqmP51R0l0J5tm5xbEUV0
Max-Forwards: 70
From: <sip:511@raspbx>;tag=JT0sL4JEZWqfHHd9YDnOOp1Tcbmneb.b
To: <sip:511@raspbx>
Call-ID: 1qDB9TlQQxR-djUWVFjpQpJ7OlylITVQ
CSeq: 8447 REGISTER
Contact: <sip:511@192.168.1.206:5060;ob>
Expires: 300
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Authorization: Digest username="511", realm="asterisk", nonce="49ee1c7e", uri="sip:raspbx", response="386f40db749e77f0b76493b32be1bec4", algorithm=MD5
Content-Length:  0


--end msg--
15:15:51.355  tsx0x759004cc  ....State changed from Null to Calling, event=TX_MSG
15:15:51.356 sip_endpoint.c  Processing incoming message: Response msg 401/INVITE/cseq=29024 (rdata0x75900ea4)
15:15:51.356   pjsua_core.c  .RX 552 bytes Response msg 401/INVITE/cseq=29024 (rdata0x75900ea4) from UDP 192.168.1.40:5060:
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.206:5060;branch=z9hG4bKPjo41IhhWHdzIpp4.RQWgPgFY8FZQZcuqT;received=192.168.1.206;rport=5060
From: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
To: sip:501@raspbx;tag=as394db5e7
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 29024 INVITE
Server: FPBX-13.0.105(11.22.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="797624bb"
Content-Length: 0


--end msg--
15:15:51.356   tsx0x164128c  .Incoming Response msg 401/INVITE/cseq=29024 (rdata0x75900ea4) in state Calling
15:15:51.356       endpoint  ..Request msg ACK/cseq=29024 (tdta0x75902dd8) created.
15:15:51.356   pjsua_core.c  ..TX 314 bytes Request msg ACK/cseq=29024 (tdta0x75902dd8) to UDP 192.168.1.40:5060:
ACK sip:501@raspbx SIP/2.0
Via: SIP/2.0/UDP 192.168.1.206:5060;rport;branch=z9hG4bKPjo41IhhWHdzIpp4.RQWgPgFY8FZQZcuqT
Max-Forwards: 70
From: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
To: sip:501@raspbx;tag=as394db5e7
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 29024 ACK
Content-Length:  0


--end msg--
15:15:51.356   tsx0x164128c  ..State changed from Calling to Completed, event=RX_MSG
15:15:51.356   dlg0x16392bc  ...Received Response msg 401/INVITE/cseq=29024 (rdata0x75900ea4)
15:15:51.356   dlg0x16392bc  ...Transaction tsx0x164128c state changed to Completed
15:15:51.356   inv0x16392bc  .....Sending Request msg INVITE/cseq=29024 (tdta0x163f278)
15:15:51.356   dlg0x16392bc  ......Sending Request msg INVITE/cseq=29024 (tdta0x163f278)
15:15:51.357  tsx0x75905d8c  .......Transaction created for Request msg INVITE/cseq=29025 (tdta0x163f278)
15:15:51.357  tsx0x75905d8c  ......Sending Request msg INVITE/cseq=29025 (tdta0x163f278) in state Null
15:15:51.357       endpoint  .......Request msg INVITE/cseq=29025 (tdta0x163f278): skipping target resolution because address is already set
15:15:51.357   pjsua_core.c  .......TX 1194 bytes Request msg INVITE/cseq=29025 (tdta0x163f278) to UDP 192.168.1.40:5060:
INVITE sip:501@raspbx SIP/2.0
Via: SIP/2.0/UDP 192.168.1.206:5060;rport;branch=z9hG4bKPj25ndgyQYBLQeeXnFJzkwI.tkuqVIdLlT
Max-Forwards: 70
From: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
To: sip:501@raspbx
Contact: <sip:511@192.168.1.206:5060;ob>
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 29025 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
Authorization: Digest username="511", realm="asterisk", nonce="797624bb", uri="sip:501@raspbx", response="83914e6eeabdce07c48a30693069235a", algorithm=MD5
Content-Type: application/sdp
Content-Length:   476

v=0
o=- 3670326951 3670326951 IN IP4 192.168.1.206
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 98 97 99 104 3 0 8 9 96
c=IN IP4 192.168.1.206
b=TIAS:64000
a=rtcp:4001 IN IP4 192.168.1.206
a=sendrecv
a=rtpmap:98 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:99 speex/32000
a=rtpmap:104 iLBC/8000
a=fmtp:104 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16

--end msg--
15:15:51.357  tsx0x75905d8c  .......State changed from Null to Calling, event=TX_MSG
15:15:51.357   dlg0x16392bc  ........Transaction tsx0x75905d8c state changed to Calling
15:15:51.358 sip_endpoint.c  Processing incoming message: Request msg OPTIONS/cseq=102 (rdata0x75900ea4)
15:15:51.358   pjsua_core.c  .RX 556 bytes Request msg OPTIONS/cseq=102 (rdata0x75900ea4) from UDP 192.168.1.40:5060:
OPTIONS sip:511@192.168.1.206:5060;ob SIP/2.0
Via: SIP/2.0/UDP 192.168.1.40:5060;branch=z9hG4bK0adbcd60
Max-Forwards: 70
From: "Unknown" <sip:Unknown@192.168.1.40>;tag=as3da53871
To: <sip:511@192.168.1.206:5060;ob>
CSeq: 102 OPTIONS
User-Agent: FPBX-13.0.105(11.22.0)
Date: Fri, 22 Apr 2016 15:15:51 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


--end msg--
15:15:51.358       endpoint  .Response msg 200/OPTIONS/cseq=102 (tdta0x75906738) created
15:15:51.358  sip_resolve.c  .Target '192.168.1.40:5060' type=UDP resolved to '192.168.1.40:5060' type=UDP (UDP transport)
15:15:51.358   pjsua_core.c  .TX 683 bytes Response msg 200/OPTIONS/cseq=102 (tdta0x75906738) to UDP 192.168.1.40:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.40:5060;received=192.168.1.40;branch=z9hG4bK0adbcd60
From: "Unknown" <sip:Unknown@192.168.1.40>;tag=as3da53871
To: <sip:511@192.168.1.206;ob>;tag=z9hG4bK0adbcd60
CSeq: 102 OPTIONS
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain
Supported: replaces, 100rel, timer, norefersub
Allow-Events: presence, message-summary, refer
Content-Length:  0


--end msg--
15:15:51.359 tdta0x75906738  .Destroying txdata Response msg 200/OPTIONS/cseq=102 (tdta0x75906738)
15:15:51.359 sip_endpoint.c  Processing incoming message: Response msg 200/REGISTER/cseq=8447 (rdata0x75900ea4)
15:15:51.359   pjsua_core.c  .RX 576 bytes Response msg 200/REGISTER/cseq=8447 (rdata0x75900ea4) from UDP 192.168.1.40:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.206:5060;branch=z9hG4bKPje3xDRkVFhCWHqmP51R0l0J5tm5xbEUV0;received=192.168.1.206;rport=5060
From: <sip:511@raspbx>;tag=JT0sL4JEZWqfHHd9YDnOOp1Tcbmneb.b
To: <sip:511@raspbx>;tag=as530f6e44
Call-ID: 1qDB9TlQQxR-djUWVFjpQpJ7OlylITVQ
CSeq: 8447 REGISTER
Server: FPBX-13.0.105(11.22.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Expires: 300
Contact: <sip:511@192.168.1.206:5060;ob>;expires=300
Date: Fri, 22 Apr 2016 15:15:51 GMT
Content-Length: 0


--end msg--
15:15:51.359  tsx0x759004cc  .Incoming Response msg 200/REGISTER/cseq=8447 (rdata0x75900ea4) in state Calling
15:15:51.359  tsx0x759004cc  ..State changed from Calling to Completed, event=RX_MSG
15:15:51.359    pjsua_acc.c  ....SIP outbound status for acc 0 is not active
15:15:51.359    pjsua_acc.c  ....sip:511@raspbx: registration success, status=200 (OK), will re-register in 300 seconds
15:15:51.359    pjsua_acc.c  ....Keep-alive timer started for acc 0, destination:192.168.1.40:5060, interval:15s
15:15:51.362 sip_endpoint.c  Processing incoming message: Response msg 100/INVITE/cseq=29025 (rdata0x75900ea4)
15:15:51.363   pjsua_core.c  .RX 530 bytes Response msg 100/INVITE/cseq=29025 (rdata0x75900ea4) from UDP 192.168.1.40:5060:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.206:5060;branch=z9hG4bKPj25ndgyQYBLQeeXnFJzkwI.tkuqVIdLlT;received=192.168.1.206;rport=5060
From: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
To: sip:501@raspbx
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 29025 INVITE
Server: FPBX-13.0.105(11.22.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Content-Length: 0


--end msg--
15:15:51.363  tsx0x75905d8c  .Incoming Response msg 100/INVITE/cseq=29025 (rdata0x75900ea4) in state Calling
15:15:51.363  tsx0x75905d8c  ..State changed from Calling to Proceeding, event=RX_MSG
15:15:51.363   dlg0x16392bc  ...Received Response msg 100/INVITE/cseq=29025 (rdata0x75900ea4)
15:15:51.363   dlg0x16392bc  ...Transaction tsx0x75905d8c state changed to Proceeding
15:15:51.621          speex !warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:15:51.958 sip_endpoint.c !Processing incoming message: Response msg 180/INVITE/cseq=29025 (rdata0x75900ea4)
15:15:51.958   pjsua_core.c  .RX 546 bytes Response msg 180/INVITE/cseq=29025 (rdata0x75900ea4) from UDP 192.168.1.40:5060:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.1.206:5060;branch=z9hG4bKPj25ndgyQYBLQeeXnFJzkwI.tkuqVIdLlT;received=192.168.1.206;rport=5060
From: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
To: sip:501@raspbx;tag=as542398d9
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 29025 INVITE
Server: FPBX-13.0.105(11.22.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Content-Length: 0


--end msg--
15:15:51.958  tsx0x75905d8c  .Incoming Response msg 180/INVITE/cseq=29025 (rdata0x75900ea4) in state Proceeding
15:15:51.958  tsx0x75905d8c  ..State changed from Proceeding to Proceeding, event=RX_MSG
15:15:51.958   dlg0x16392bc  ...Received Response msg 180/INVITE/cseq=29025 (rdata0x75900ea4)
15:15:51.958   dlg0x16392bc  ....Route-set updated
15:15:51.958   dlg0x16392bc  ...Transaction tsx0x75905d8c state changed to Proceeding
15:15:51.958            APP  .....Call 0 state=EARLY
15:15:51.975 sip_endpoint.c  Processing incoming message: Response msg 180/INVITE/cseq=29025 (rdata0x75900ea4)
15:15:51.975   pjsua_core.c  .RX 546 bytes Response msg 180/INVITE/cseq=29025 (rdata0x75900ea4) from UDP 192.168.1.40:5060:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.1.206:5060;branch=z9hG4bKPj25ndgyQYBLQeeXnFJzkwI.tkuqVIdLlT;received=192.168.1.206;rport=5060
From: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
To: sip:501@raspbx;tag=as542398d9
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 29025 INVITE
Server: FPBX-13.0.105(11.22.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Content-Length: 0


--end msg--
15:15:51.975  tsx0x75905d8c  .Incoming Response msg 180/INVITE/cseq=29025 (rdata0x75900ea4) in state Proceeding
15:15:51.975  tsx0x75905d8c  ..State changed from Proceeding to Proceeding, event=RX_MSG
15:15:51.975   dlg0x16392bc  ...Received Response msg 180/INVITE/cseq=29025 (rdata0x75900ea4)
15:15:51.975   dlg0x16392bc  ...Transaction tsx0x75905d8c state changed to Proceeding
15:15:51.975            APP  .....Call 0 state=EARLY
15:15:56.208   sound_port.c !EC suspended because of inactivity
15:15:56.355   tsx0x15f87b4 !Timeout timer event
15:15:56.355   tsx0x15f87b4  .State changed from Completed to Terminated, event=TIMER
15:15:56.355   tsx0x15f87b4  Timeout timer event
15:15:56.355   tsx0x15f87b4  .State changed from Terminated to Destroyed, event=TIMER
15:15:56.355   tsx0x15f87b4  Transaction destroyed!
15:15:56.359  tsx0x759004cc  Timeout timer event
15:15:56.359  tsx0x759004cc  .State changed from Completed to Terminated, event=TIMER
15:15:56.359  tsx0x759004cc  Timeout timer event
15:15:56.359  tsx0x759004cc  .State changed from Terminated to Destroyed, event=TIMER
15:15:56.360  tdta0x15f7748  ..Destroying txdata Request msg REGISTER/cseq=8447 (tdta0x15f7748)
15:15:56.360  tsx0x759004cc  Transaction destroyed!
15:15:56.821 sip_endpoint.c  Processing incoming message: Response msg 200/INVITE/cseq=29025 (rdata0x75900ea4)
15:15:56.821   pjsua_core.c  .RX 868 bytes Response msg 200/INVITE/cseq=29025 (rdata0x75900ea4) from UDP 192.168.1.40:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.206:5060;branch=z9hG4bKPj25ndgyQYBLQeeXnFJzkwI.tkuqVIdLlT;received=192.168.1.206;rport=5060
From: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
To: sip:501@raspbx;tag=as542398d9
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 29025 INVITE
Server: FPBX-13.0.105(11.22.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Content-Type: application/sdp
Require: timer
Content-Length: 278

v=0
o=root 535804958 535804958 IN IP4 192.168.1.40
s=Asterisk PBX 11.22.0
c=IN IP4 192.168.1.40
t=0 0
m=audio 11492 RTP/AVP 0 8 3 96
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=ptime:20
a=sendrecv

--end msg--
15:15:56.822  tsx0x75905d8c  .Incoming Response msg 200/INVITE/cseq=29025 (rdata0x75900ea4) in state Proceeding
15:15:56.822  tsx0x75905d8c  ..State changed from Proceeding to Terminated, event=RX_MSG
15:15:56.822   dlg0x16392bc  ...Received Response msg 200/INVITE/cseq=29025 (rdata0x75900ea4)
15:15:56.822   dlg0x16392bc  ....Route-set updated
15:15:56.822   dlg0x16392bc  ....Route-set frozen
15:15:56.822   dlg0x16392bc  ...Transaction tsx0x75905d8c state changed to Terminated
15:15:56.822            APP  .....Call 0 state=CONNECTING
15:15:56.822   inv0x16392bc  ....Got SDP answer in Response msg 200/INVITE/cseq=29025 (rdata0x75900ea4)
15:15:56.822   inv0x16392bc  ....SDP negotiation done, status=0
15:15:56.822   pjsua_call.c  .....Call 0: remote NAT type is 0 (Unknown)
15:15:56.822  pjsua_media.c  .....Call 0: updating media..
15:15:56.822    pjsua_aud.c  ......Audio channel update..
15:15:56.823 strm0x75906f64  .......VAD temporarily disabled
15:15:56.823          rtp.c  .......pjmedia_rtp_session_init: ses=0x75908e10, default_pt=0, ssrc=0xab2fd6c
15:15:56.823          rtp.c  .......pjmedia_rtp_session_init: ses=0x75909498, default_pt=0, ssrc=0xab2fd6c
15:15:56.823       stream.c  .......Stream strm0x75906f64 created
15:15:56.823 strm0x75906f64  .......Encoder stream started
15:15:56.823 strm0x75906f64  .......Decoder stream started
15:15:56.823     resample.c  .......resample created: high qualiy, large filter, in/out rate=8000/16000
15:15:56.823     resample.c  .......resample created: high qualiy, large filter, in/out rate=16000/8000
15:15:56.823  pjsua_media.c  ......Audio updated, stream #0: PCMU (sendrecv)
15:15:56.823    pjsua_aud.c  .....Conf connect: 1 --> 0
15:15:56.823   conference.c  ......Port 1 (sip:501@raspbx) transmitting to port 0 (sysdefault:CARD=Device)
15:15:56.823    pjsua_aud.c  .....Conf connect: 0 --> 1
15:15:56.823   conference.c  ......Port 0 (sysdefault:CARD=Device) transmitting to port 1 (sip:501@raspbx)
15:15:56.823   inv0x16392bc  ....Received Response msg 200/INVITE/cseq=29025 (rdata0x75900ea4), sending ACK
15:15:56.823       endpoint  ....Request msg ACK/cseq=29025 (tdta0x7590b278) created.
15:15:56.823   dlg0x16392bc  .....Sending Request msg ACK/cseq=29025 (tdta0x7590b278)
15:15:56.824  sip_resolve.c  .....Target '192.168.1.40:5060' type=Unspecified resolved to '192.168.1.40:5060' type=UDP (UDP transport)
15:15:56.824   pjsua_core.c  .....TX 325 bytes Request msg ACK/cseq=29025 (tdta0x7590b278) to UDP 192.168.1.40:5060:
Via: SIP/2.0/UDP 192.168.1.206:5060;rport;branch=z9hG4bKPjYOGWeWMsizsLN90zENMCIHvD7CX9OhHd
Max-Forwards: 70
From: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
To: sip:501@raspbx;tag=as542398d9
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 29025 ACK
Content-Length:  0


--end msg--
15:15:56.824            APP  .....Call 0 state=CONFIRMED
15:15:56.824   pjsua_call.c  .Call 0 sending re-INVITE for updating media session to use only one codec
15:15:56.824       endpoint  ..Request msg INVITE/cseq=29027 (tdta0x7590f410) created.
15:15:56.824   inv0x16392bc  ..Sending Request msg INVITE/cseq=29027 (tdta0x7590f410)
15:15:56.824   dlg0x16392bc  ...Sending Request msg INVITE/cseq=29027 (tdta0x7590f410)
15:15:56.824  tsx0x75911424  ....Transaction created for Request msg INVITE/cseq=29026 (tdta0x7590f410)
15:15:56.824  tsx0x75911424  ...Sending Request msg INVITE/cseq=29026 (tdta0x7590f410) in state Null
15:15:56.825  sip_resolve.c  ....Target '192.168.1.40:5060' type=Unspecified resolved to '192.168.1.40:5060' type=UDP (UDP transport)
15:15:56.825   pjsua_core.c  ....TX 876 bytes Request msg INVITE/cseq=29026 (tdta0x7590f410) to UDP 192.168.1.40:5060:
Via: SIP/2.0/UDP 192.168.1.206:5060;rport;branch=z9hG4bKPjJkhmkaN5vX4mSGZxY64zCXV0L2uEApnR
Max-Forwards: 70
From: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
To: sip:501@raspbx;tag=as542398d9
Contact: <sip:511@192.168.1.206:5060;ob>
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 29026 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800;refresher=uas
Min-SE: 90
Content-Type: application/sdp
Content-Length:   274

v=0
o=- 3670326951 3670326952 IN IP4 192.168.1.206
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 0 96
c=IN IP4 192.168.1.206
b=TIAS:64000
a=rtcp:4001 IN IP4 192.168.1.206
a=rtpmap:0 PCMU/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=sendrecv

--end msg--
15:15:56.825  tsx0x75911424  ....State changed from Null to Calling, event=TX_MSG
15:15:56.825   dlg0x16392bc  .....Transaction tsx0x75911424 state changed to Calling
15:15:56.825  tsx0x75905d8c  Timeout timer event
15:15:56.825  tsx0x75905d8c  .State changed from Terminated to Destroyed, event=TIMER
15:15:56.825  tsx0x75905d8c  Transaction destroyed!
15:15:56.827   Master/sound !Underflow, buf_cnt=0, will generate 1 frame
15:15:56.827 sip_endpoint.c !Processing incoming message: Response msg 100/INVITE/cseq=29026 (rdata0x75900ea4)
15:15:56.827   pjsua_core.c  .RX 545 bytes Response msg 100/INVITE/cseq=29026 (rdata0x75900ea4) from UDP 192.168.1.40:5060:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.206:5060;branch=z9hG4bKPjJkhmkaN5vX4mSGZxY64zCXV0L2uEApnR;received=192.168.1.206;rport=5060
From: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
To: sip:501@raspbx;tag=as542398d9
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 29026 INVITE
Server: FPBX-13.0.105(11.22.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Content-Length: 0


--end msg--
15:15:56.828  tsx0x75911424  .Incoming Response msg 100/INVITE/cseq=29026 (rdata0x75900ea4) in state Calling
15:15:56.828  tsx0x75911424  ..State changed from Calling to Proceeding, event=RX_MSG
15:15:56.828   dlg0x16392bc  ...Received Response msg 100/INVITE/cseq=29026 (rdata0x75900ea4)
15:15:56.828   dlg0x16392bc  ...Transaction tsx0x75911424 state changed to Proceeding
15:15:56.828 sip_endpoint.c  Processing incoming message: Response msg 200/INVITE/cseq=29026 (rdata0x75900ea4)
15:15:56.828   pjsua_core.c  .RX 821 bytes Response msg 200/INVITE/cseq=29026 (rdata0x75900ea4) from UDP 192.168.1.40:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.206:5060;branch=z9hG4bKPjJkhmkaN5vX4mSGZxY64zCXV0L2uEApnR;received=192.168.1.206;rport=5060
From: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
To: sip:501@raspbx;tag=as542398d9
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 29026 INVITE
Server: FPBX-13.0.105(11.22.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Content-Type: application/sdp
Require: timer
Content-Length: 231

v=0
o=root 535804958 535804959 IN IP4 192.168.1.40
s=Asterisk PBX 11.22.0
c=IN IP4 192.168.1.40
t=0 0
m=audio 11492 RTP/AVP 0 96
a=rtpmap:0 PCMU/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=ptime:20
a=sendrecv

--end msg--
15:15:56.828  tsx0x75911424  .Incoming Response msg 200/INVITE/cseq=29026 (rdata0x75900ea4) in state Proceeding
15:15:56.828  tsx0x75911424  ..State changed from Proceeding to Terminated, event=RX_MSG
15:15:56.828   dlg0x16392bc  ...Received Response msg 200/INVITE/cseq=29026 (rdata0x75900ea4)
15:15:56.828   dlg0x16392bc  ...Transaction tsx0x75911424 state changed to Terminated
15:15:56.828   inv0x16392bc  ....Got SDP answer in Response msg 200/INVITE/cseq=29026 (rdata0x75900ea4)
15:15:56.829   inv0x16392bc  ....SDP negotiation done, status=0
15:15:56.829   pjsua_call.c  .....Call 0: remote NAT type is 0 (Unknown)
15:15:56.829  pjsua_media.c  .....Call 0: updating media..
15:15:56.829  pjsua_media.c  ......Call 0: stream #0 (audio) unchanged.
15:15:56.829  pjsua_media.c  ......Audio updated, stream #0: PCMU (sendrecv)
15:15:56.829    pjsua_aud.c  .....Conf connect: 1 --> 0
15:15:56.830 strm0x75906f64 !Jitter buffer is bufferring (prefetch=0), plc invoked
15:15:56.831 strm0x75906f64  Start talksprut..
15:15:56.831    pjsua_aud.c !.....Conf connect: 0 --> 1
15:15:56.831   inv0x16392bc  ....Received Response msg 200/INVITE/cseq=29026 (rdata0x75900ea4), sending ACK
15:15:56.831 tdta0x7590b278  ....Destroying txdata Request msg ACK/cseq=29025 (tdta0x7590b278)
15:15:56.832       endpoint  ....Request msg ACK/cseq=29026 (tdta0x7590b278) created.
15:15:56.832   dlg0x16392bc  .....Sending Request msg ACK/cseq=29026 (tdta0x7590b278)
15:15:56.832  sip_resolve.c  .....Target '192.168.1.40:5060' type=Unspecified resolved to '192.168.1.40:5060' type=UDP (UDP transport)
15:15:56.832   pjsua_core.c  .....TX 325 bytes Request msg ACK/cseq=29026 (tdta0x7590b278) to UDP 192.168.1.40:5060:
Via: SIP/2.0/UDP 192.168.1.206:5060;rport;branch=z9hG4bKPjVYL7VSyqEDEdWcmHoiX-FMI5Kon7SJSQ
Max-Forwards: 70
From: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
To: sip:501@raspbx;tag=as542398d9
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 29026 ACK
Content-Length:  0


--end msg--
15:15:56.832  tsx0x75911424  Timeout timer event
15:15:56.832  tsx0x75911424  .State changed from Terminated to Destroyed, event=TIMER
15:15:56.832 tdta0x7590f410  ..Destroying txdata Request msg INVITE/cseq=29026 (tdta0x7590f410)
15:15:56.832  tsx0x75911424  Transaction destroyed!
15:15:56.843 strm0x75906f64 !RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=0
15:15:56.848 strm0x75906f64 !Jitter buffer starts returning normal frames (after 1 empty/lost)
15:15:56.849   sound_port.c  EC activated
15:15:56.850          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:15:57.468 strm0x75906f64  VAD re-enabled
15:15:57.470 strm0x75906f64  Starting silence
15:16:01.437   silencedet.c  Re-adjust threshold (in silence)to 0
15:16:02.461 strm0x75906f64  Start talksprut..
15:16:02.482 strm0x75906f64  Starting silence
15:16:02.824          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:03.037          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:03.144          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:03.357          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:03.464          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:03.677          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:03.784          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:03.997          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:04.104          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:04.317          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:04.424          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:04.637          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:04.745          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:05.298          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:05.385          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:05.448   silencedet.c  Re-adjust threshold (in silence)to 0
15:16:05.618          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:05.705          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:05.938          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:06.003          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:06.359    pjsua_acc.c !Sending 2 bytes keep-alive packet for acc 0 to 192.168.1.40:5060
15:16:06.360 tdta0x7590f410  Destroying txdata raw
15:16:07.474 strm0x75906f64 !Start talksprut..
15:16:07.496 strm0x75906f64  Starting silence
15:16:09.459   silencedet.c  Re-adjust threshold (in silence)to 0
15:16:10.398   silencedet.c  Starting talk burst (level=25 threshold=0)
15:16:10.398 strm0x75906f64  Start talksprut..
15:16:11.230   silencedet.c  Starting silence (level=0 threshold=0)
15:16:11.231 strm0x75906f64  Starting silence
15:16:11.614   silencedet.c  Starting talk burst (level=1021 threshold=0)
15:16:11.614 strm0x75906f64  Start talksprut..
15:16:12.787   silencedet.c  Starting silence (level=0 threshold=0)
15:16:12.787 strm0x75906f64  Starting silence
15:16:13.022   silencedet.c  Starting talk burst (level=1 threshold=0)
15:16:13.022 strm0x75906f64  Start talksprut..
15:16:21.024   silencedet.c  Re-adjust threshold (in talk burst)to 60
15:16:21.360    pjsua_acc.c !Sending 2 bytes keep-alive packet for acc 0 to 192.168.1.40:5060
15:16:21.360 tdta0x7590f410  Destroying txdata raw
15:16:23.357   tsx0x164128c  Timeout timer event
15:16:23.357   tsx0x164128c  .State changed from Completed to Terminated, event=TIMER
15:16:23.357   dlg0x16392bc  ..Transaction tsx0x164128c state changed to Terminated
15:16:23.357   tsx0x164128c  Timeout timer event
15:16:23.357   tsx0x164128c  .State changed from Terminated to Destroyed, event=TIMER
15:16:23.357 tdta0x75902dd8  ..Destroying txdata Request msg ACK/cseq=29024 (tdta0x75902dd8)
15:16:23.357   tsx0x164128c  Transaction destroyed!
15:16:27.189   silencedet.c !Starting silence (level=9 threshold=24)
15:16:27.190 strm0x75906f64  Starting silence
15:16:27.232   silencedet.c  Starting talk burst (level=59 threshold=24)
15:16:27.233 strm0x75906f64  Start talksprut..
15:16:28.532 strm0x75906f64  Frame lost, recovered!
15:16:28.532 strm0x75906f64  Jitter buffer starts returning normal frames (after 1 empty/lost)
15:16:29.215 strm0x75906f64  Frame lost, recovered!
15:16:29.215 strm0x75906f64  Jitter buffer starts returning normal frames (after 1 empty/lost)
15:16:31.201   silencedet.c  Starting silence (level=13 threshold=22)
15:16:31.201 strm0x75906f64  Starting silence
15:16:32.204   silencedet.c  Starting talk burst (level=44 threshold=22)
15:16:32.204 strm0x75906f64  Start talksprut..
15:16:36.361    pjsua_acc.c !Sending 2 bytes keep-alive packet for acc 0 to 192.168.1.40:5060
15:16:36.361 tdta0x75902dd8  Destroying txdata raw
15:16:47.670 strm0x75906f64 !Frame lost, recovered!
15:16:47.692 strm0x75906f64  Jitter buffer starts returning normal frames (after 1 empty/lost)
15:16:47.694          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:47.907          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:47.928   silencedet.c  Re-adjust threshold (in talk burst)to 131
15:16:47.950          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:48.204 strm0x75906f64  Frame lost, recovered!
15:16:48.204 strm0x75906f64  Jitter buffer starts returning normal frames (after 1 empty/lost)
15:16:48.227          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:48.270          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:48.547          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:49.401          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:49.550   silencedet.c  Starting silence (level=70 threshold=150)
15:16:49.551 strm0x75906f64  Starting silence
15:16:49.742   silencedet.c  Starting talk burst (level=183 threshold=150)
15:16:49.742 strm0x75906f64  Start talksprut..
15:16:50.488          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:50.531          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:50.808          speex  warning: Had to discard a playback frame (your application is buggy and/or got xruns)
15:16:50.830   silencedet.c  Starting silence (level=102 threshold=136)
15:16:50.830 strm0x75906f64  Starting silence
15:16:50.851   silencedet.c  Starting talk burst (level=383 threshold=136)
15:16:50.851 strm0x75906f64  Start talksprut..
15:16:50.852          speex  warning: Auto-filling the buffer (your application is buggy and/or got xruns)
15:16:51.361    pjsua_acc.c !Sending 2 bytes keep-alive packet for acc 0 to 192.168.1.40:5060
15:16:51.362 tdta0x75902dd8  Destroying txdata raw
15:16:51.364 sip_endpoint.c  Processing incoming message: Request msg OPTIONS/cseq=102 (rdata0x75900ea4)
15:16:51.364   pjsua_core.c  .RX 556 bytes Request msg OPTIONS/cseq=102 (rdata0x75900ea4) from UDP 192.168.1.40:5060:
OPTIONS sip:511@192.168.1.206:5060;ob SIP/2.0
Via: SIP/2.0/UDP 192.168.1.40:5060;branch=z9hG4bK23a8c463
Max-Forwards: 70
From: "Unknown" <sip:Unknown@192.168.1.40>;tag=as03d7c32a
To: <sip:511@192.168.1.206:5060;ob>
CSeq: 102 OPTIONS
User-Agent: FPBX-13.0.105(11.22.0)
Date: Fri, 22 Apr 2016 15:16:51 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


--end msg--
15:16:51.364       endpoint  .Response msg 200/OPTIONS/cseq=102 (tdta0x75902dd8) created
15:16:51.365  sip_resolve.c  .Target '192.168.1.40:5060' type=UDP resolved to '192.168.1.40:5060' type=UDP (UDP transport)
15:16:51.365   pjsua_core.c  .TX 683 bytes Response msg 200/OPTIONS/cseq=102 (tdta0x75902dd8) to UDP 192.168.1.40:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.40:5060;received=192.168.1.40;branch=z9hG4bK23a8c463
From: "Unknown" <sip:Unknown@192.168.1.40>;tag=as03d7c32a
To: <sip:511@192.168.1.206;ob>;tag=z9hG4bK23a8c463
CSeq: 102 OPTIONS
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain
Supported: replaces, 100rel, timer, norefersub
Allow-Events: presence, message-summary, refer
Content-Length:  0


--end msg--
15:16:51.366 tdta0x75902dd8  .Destroying txdata Response msg 200/OPTIONS/cseq=102 (tdta0x75902dd8)
15:16:54.307   silencedet.c !Starting silence (level=11 threshold=52)
15:16:54.307 strm0x75906f64  Starting silence
15:16:54.693   silencedet.c  Starting talk burst (level=57 threshold=52)
15:16:54.693 strm0x75906f64  Start talksprut..
15:16:55.672   silencedet.c  Starting silence (level=12 threshold=22)
15:16:55.672 strm0x75906f64  Starting silence
15:16:55.971   silencedet.c  Starting talk burst (level=311 threshold=22)
15:16:55.971 strm0x75906f64  Start talksprut..
15:16:57.828   silencedet.c  Starting silence (level=6 threshold=16)
15:16:57.828 strm0x75906f64  Starting silence
15:16:58.383   silencedet.c  Starting talk burst (level=24 threshold=16)
15:16:58.383 strm0x75906f64  Start talksprut..
15:16:59.535   silencedet.c  Starting silence (level=8 threshold=16)
15:16:59.535 strm0x75906f64  Starting silence
15:17:01.241   silencedet.c  Starting talk burst (level=23 threshold=16)
15:17:01.241 strm0x75906f64  Start talksprut..
15:17:02.929 sip_endpoint.c !Processing incoming message: Request msg BYE/cseq=102 (rdata0x75900ea4)
15:17:02.929   pjsua_core.c  .RX 566 bytes Request msg BYE/cseq=102 (rdata0x75900ea4) from UDP 192.168.1.40:5060:
BYE sip:511@192.168.1.206:5060;ob SIP/2.0
Via: SIP/2.0/UDP 192.168.1.40:5060;branch=z9hG4bK0a6a8a66;rport
Max-Forwards: 70
From: sip:501@raspbx;tag=as542398d9
To: sip:511@raspbx;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
CSeq: 102 BYE
User-Agent: FPBX-13.0.105(11.22.0)
Proxy-Authorization: Digest username="511", realm="asterisk", algorithm=MD5, uri="sip:raspbx", nonce="797624bb", response="e04670429476a52beb51a5e711d6ecc2"
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0


--end msg--
15:17:02.930   dlg0x16392bc  .Received Request msg BYE/cseq=102 (rdata0x75900ea4)
15:17:02.930  tsx0x759004cc  ...Transaction created for Request msg BYE/cseq=102 (rdata0x75900ea4)
15:17:02.930  tsx0x759004cc  ..Incoming Request msg BYE/cseq=102 (rdata0x75900ea4) in state Null
15:17:02.930  tsx0x759004cc  ...State changed from Null to Trying, event=RX_MSG
15:17:02.930   dlg0x16392bc  ....Transaction tsx0x759004cc state changed to Trying
15:17:02.930       endpoint  .....Response msg 200/BYE/cseq=102 (tdta0x75902dd8) created
15:17:02.930   dlg0x16392bc  ......Sending Response msg 200/BYE/cseq=102 (tdta0x75902dd8)
15:17:02.930  tsx0x759004cc  ......Sending Response msg 200/BYE/cseq=102 (tdta0x75902dd8) in state Trying
15:17:02.930   pjsua_core.c  .......TX 286 bytes Response msg 200/BYE/cseq=102 (tdta0x75902dd8) to UDP 192.168.1.40:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.40:5060;rport=5060;received=192.168.1.40;branch=z9hG4bK0a6a8a66
Call-ID: Un2yyi.sLCyhioVAiMYvsHDk6MpgeFIU
From: <sip:501@raspbx>;tag=as542398d9
To: <sip:511@raspbx>;tag=xMC7e5Vl1OklvvUsXswDdv0561uYcJ5b
CSeq: 102 BYE
Content-Length:  0


--end msg--
15:17:02.930  tsx0x759004cc  .......State changed from Trying to Completed, event=TX_MSG
15:17:02.930   dlg0x16392bc  ........Transaction tsx0x759004cc state changed to Completed
15:17:02.930            APP  ......Call 0 state=DISCONNCTD
15:17:02.930  pjsua_media.c  ......Call 0: deinitializing media..
15:17:02.930 strm0x75906f64  ........JB summary:
  size=0/eff=0 prefetch=0 level=4
  delay (min/max/avg/dev)=20/60/46/12 ms
  burst (min/max/avg/dev)=2/4/2/0 frames
  lost=4 discard=0 empty=1
15:17:02.931  pjsua_media.c  ........Media stream call00:0 is destroyed
15:17:02.931 tdta0x7590b278  .....Destroying txdata Request msg ACK/cseq=29026 (tdta0x7590b278)
15:17:02.931  tdta0x163f278  .....Destroying txdata Request msg INVITE/cseq=29025 (tdta0x163f278)
15:17:02.931   dlg0x16392bc  ......Session count dec to 3 by mod-invite
15:17:03.930    pjsua_aud.c  Closing sound device after idle for 1 second(s)
15:17:03.930    pjsua_aud.c  .Closing sysdefault:CARD=Device sound playback device and sysdefault:CARD=Device sound capture device
15:17:06.362    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 0 to 192.168.1.40:5060
15:17:06.363 tdta0x75906b48  Destroying txdata raw
15:17:21.363    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 0 to 192.168.1.40:5060
15:17:21.364 tdta0x75906b48  Destroying txdata raw
15:17:34.930  tsx0x759004cc  Timeout timer event
15:17:34.931  tsx0x759004cc  .State changed from Completed to Terminated, event=TIMER
15:17:34.931   dlg0x16392bc  ..Transaction tsx0x759004cc state changed to Terminated
15:17:34.932   dlg0x16392bc  ...Dialog destroyed
15:17:34.935  tsx0x759004cc  Timeout timer event
15:17:34.935  tsx0x759004cc  .State changed from Terminated to Destroyed, event=TIMER
15:17:34.935 tdta0x75902dd8  ..Destroying txdata Response msg 200/BYE/cseq=102 (tdta0x75902dd8)
15:17:34.936  tsx0x759004cc  Transaction destroyed!
15:17:36.364    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 0 to 192.168.1.40:5060
15:17:36.365 tdta0x75902dd8  Destroying txdata raw
15:17:51.365    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 0 to 192.168.1.40:5060
15:17:51.366 tdta0x75902dd8  Destroying txdata raw
15:17:51.368 sip_endpoint.c  Processing incoming message: Request msg OPTIONS/cseq=102 (rdata0x75900ea4)
15:17:51.368   pjsua_core.c  .RX 556 bytes Request msg OPTIONS/cseq=102 (rdata0x75900ea4) from UDP 192.168.1.40:5060:
OPTIONS sip:511@192.168.1.206:5060;ob SIP/2.0
Via: SIP/2.0/UDP 192.168.1.40:5060;branch=z9hG4bK29b1e896
Max-Forwards: 70
From: "Unknown" <sip:Unknown@192.168.1.40>;tag=as2d99b8a5
To: <sip:511@192.168.1.206:5060;ob>
CSeq: 102 OPTIONS
User-Agent: FPBX-13.0.105(11.22.0)
Date: Fri, 22 Apr 2016 15:17:51 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


--end msg--
15:17:51.368       endpoint  .Response msg 200/OPTIONS/cseq=102 (tdta0x75902dd8) created
15:17:51.368  sip_resolve.c  .Target '192.168.1.40:5060' type=UDP resolved to '192.168.1.40:5060' type=UDP (UDP transport)
15:17:51.368   pjsua_core.c  .TX 683 bytes Response msg 200/OPTIONS/cseq=102 (tdta0x75902dd8) to UDP 192.168.1.40:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.40:5060;received=192.168.1.40;branch=z9hG4bK29b1e896
From: "Unknown" <sip:Unknown@192.168.1.40>;tag=as2d99b8a5
To: <sip:511@192.168.1.206;ob>;tag=z9hG4bK29b1e896
CSeq: 102 OPTIONS
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain
Supported: replaces, 100rel, timer, norefersub
Allow-Events: presence, message-summary, refer
Content-Length:  0


--end msg--
15:17:51.368 tdta0x75902dd8  .Destroying txdata Response msg 200/OPTIONS/cseq=102 (tdta0x75902dd8)
q
15:17:55.938   pjsua_core.c !Shutting down, flags=0...
15:17:55.939   pjsua_core.c  PJSUA state changed: RUNNING --> CLOSING
15:17:55.946   pjsua_call.c  .Hangup all calls..
15:17:55.947  pjsua_media.c  .Call 0: deinitializing media..
15:17:55.947   pjsua_pres.c  .Shutting down presence..
15:17:55.948    pjsua_acc.c  .Acc 0: setting unregistration..
15:17:55.949       endpoint  ..Request msg REGISTER/cseq=8447 (tdta0x15f7748) created.
15:17:55.949   tsx0x15f87b4  ...Transaction created for Request msg REGISTER/cseq=8448 (tdta0x15f7748)
15:17:55.949   tsx0x15f87b4  ..Sending Request msg REGISTER/cseq=8448 (tdta0x15f7748) in state Null
15:17:55.950  sip_resolve.c  ...DNS resolver not available, target 'raspbx:0' type=Unspecified will be resolved with getaddrinfo()
15:17:55.954  sip_resolve.c  ...Target 'raspbx:0' type=Unspecified resolved to '192.168.1.40:5060' type=UDP (UDP transport)
15:17:55.954   pjsua_core.c  ...TX 362 bytes Request msg REGISTER/cseq=8448 (tdta0x15f7748) to UDP 192.168.1.40:5060:
REGISTER sip:raspbx SIP/2.0
Via: SIP/2.0/UDP 192.168.1.206:5060;rport;branch=z9hG4bKPjD0xKIpOAvkMbWiuktb3DE58fOxm9h.1v
Max-Forwards: 70
From: <sip:511@raspbx>;tag=faxrODRGdph6M4sR8flQIdZv7GfYZC1U
To: <sip:511@raspbx>
Call-ID: 1qDB9TlQQxR-djUWVFjpQpJ7OlylITVQ
CSeq: 8448 REGISTER
Contact: <sip:511@192.168.1.206:5060;ob>
Expires: 0
Content-Length:  0


--end msg--
15:17:55.960   tsx0x15f87b4  ...State changed from Null to Calling, event=TX_MSG
15:17:55.960    pjsua_acc.c  ..Acc 0: Unregistration sent
15:17:55.961 sip_endpoint.c  .Processing incoming message: Response msg 401/REGISTER/cseq=8448 (rdata0x75900ea4)
15:17:55.961   pjsua_core.c  ..RX 557 bytes Response msg 401/REGISTER/cseq=8448 (rdata0x75900ea4) from UDP 192.168.1.40:5060:
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.206:5060;branch=z9hG4bKPjD0xKIpOAvkMbWiuktb3DE58fOxm9h.1v;received=192.168.1.206;rport=5060
From: <sip:511@raspbx>;tag=faxrODRGdph6M4sR8flQIdZv7GfYZC1U
To: <sip:511@raspbx>;tag=as29d71240
Call-ID: 1qDB9TlQQxR-djUWVFjpQpJ7OlylITVQ
CSeq: 8448 REGISTER
Server: FPBX-13.0.105(11.22.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="568148a3"
Content-Length: 0


--end msg--
15:17:55.962   tsx0x15f87b4  ..Incoming Response msg 401/REGISTER/cseq=8448 (rdata0x75900ea4) in state Calling
15:17:55.963   tsx0x15f87b4  ...State changed from Calling to Completed, event=RX_MSG
15:17:55.963   tsx0x15f9744  .....Transaction created for Request msg REGISTER/cseq=8449 (tdta0x15f7748)
15:17:55.963   tsx0x15f9744  ....Sending Request msg REGISTER/cseq=8449 (tdta0x15f7748) in state Null
15:17:55.963       endpoint  .....Request msg REGISTER/cseq=8449 (tdta0x15f7748): skipping target resolution because address is already set
15:17:55.963   pjsua_core.c  .....TX 514 bytes Request msg REGISTER/cseq=8449 (tdta0x15f7748) to UDP 192.168.1.40:5060:
REGISTER sip:raspbx SIP/2.0
Via: SIP/2.0/UDP 192.168.1.206:5060;rport;branch=z9hG4bKPj28sWaDKbpFKzgM2UtgEgUEfzzWXkthw1
Max-Forwards: 70
From: <sip:511@raspbx>;tag=faxrODRGdph6M4sR8flQIdZv7GfYZC1U
To: <sip:511@raspbx>
Call-ID: 1qDB9TlQQxR-djUWVFjpQpJ7OlylITVQ
CSeq: 8449 REGISTER
Contact: <sip:511@192.168.1.206:5060;ob>
Expires: 0
Authorization: Digest username="511", realm="asterisk", nonce="568148a3", uri="sip:raspbx", response="ce31a0154031b709fd332ceaed3ff8ba", algorithm=MD5
Content-Length:  0


--end msg--
15:17:55.964   tsx0x15f9744  .....State changed from Null to Calling, event=TX_MSG
15:17:56.465   tsx0x15f9744  .Retransmit timer event
15:17:56.465   tsx0x15f9744  ..Retransmiting Request msg REGISTER/cseq=8449 (tdta0x15f7748), count=0, restart?=1
15:17:56.466   pjsua_core.c  ..TX 514 bytes Request msg REGISTER/cseq=8449 (tdta0x15f7748) to UDP 192.168.1.40:5060:
REGISTER sip:raspbx SIP/2.0
Via: SIP/2.0/UDP 192.168.1.206:5060;rport;branch=z9hG4bKPj28sWaDKbpFKzgM2UtgEgUEfzzWXkthw1
Max-Forwards: 70
From: <sip:511@raspbx>;tag=faxrODRGdph6M4sR8flQIdZv7GfYZC1U
To: <sip:511@raspbx>
Call-ID: 1qDB9TlQQxR-djUWVFjpQpJ7OlylITVQ
CSeq: 8449 REGISTER
Contact: <sip:511@192.168.1.206:5060;ob>
Expires: 0
Authorization: Digest username="511", realm="asterisk", nonce="568148a3", uri="sip:raspbx", response="ce31a0154031b709fd332ceaed3ff8ba", algorithm=MD5
Content-Length:  0


--end msg--
15:17:56.568 sip_endpoint.c  .Processing incoming message: Response msg 200/REGISTER/cseq=8449 (rdata0x15fa104)
15:17:56.568   pjsua_core.c  ..RX 520 bytes Response msg 200/REGISTER/cseq=8449 (rdata0x15fa104) from UDP 192.168.1.40:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.206:5060;branch=z9hG4bKPj28sWaDKbpFKzgM2UtgEgUEfzzWXkthw1;received=192.168.1.206;rport=5060
From: <sip:511@raspbx>;tag=faxrODRGdph6M4sR8flQIdZv7GfYZC1U
To: <sip:511@raspbx>;tag=as29d71240
Call-ID: 1qDB9TlQQxR-djUWVFjpQpJ7OlylITVQ
CSeq: 8449 REGISTER
Server: FPBX-13.0.105(11.22.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Expires: 0
Date: Fri, 22 Apr 2016 15:17:56 GMT
Content-Length: 0


--end msg--
15:17:56.569   tsx0x15f9744  ..Incoming Response msg 200/REGISTER/cseq=8449 (rdata0x15fa104) in state Calling
15:17:56.569   tsx0x15f9744  ...State changed from Calling to Completed, event=RX_MSG
15:17:56.569    pjsua_acc.c  .....sip:511@raspbx: unregistration success
15:17:56.570 sip_endpoint.c  .Processing incoming message: Response msg 200/REGISTER/cseq=8449 (rdata0x15fa104)
15:17:56.570   pjsua_core.c  ..RX 520 bytes Response msg 200/REGISTER/cseq=8449 (rdata0x15fa104) from UDP 192.168.1.40:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.206:5060;branch=z9hG4bKPj28sWaDKbpFKzgM2UtgEgUEfzzWXkthw1;received=192.168.1.206;rport=5060
From: <sip:511@raspbx>;tag=faxrODRGdph6M4sR8flQIdZv7GfYZC1U
To: <sip:511@raspbx>;tag=as29d71240
Call-ID: 1qDB9TlQQxR-djUWVFjpQpJ7OlylITVQ
CSeq: 8449 REGISTER
Server: FPBX-13.0.105(11.22.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Expires: 0
Date: Fri, 22 Apr 2016 15:17:56 GMT
Content-Length: 0


--end msg--
15:17:56.571   tsx0x15f9744  ..Incoming Response msg 200/REGISTER/cseq=8449 (rdata0x15fa104) in state Completed
15:17:56.994   pjsua_core.c  .Destroying...
15:17:56.995  pjsua_media.c  .Shutting down media..
15:17:57.392 sip_endpoint.c  .Destroying endpoing instance..
15:17:57.392 sip_transactio  .Stopping transaction layer module
15:17:57.393   tsx0x15f87b4  .Request to terminate transaction
15:17:57.393   tsx0x15f87b4  ..State changed from Completed to Terminated, event=USER
15:17:57.393   tsx0x15f87b4  .Transaction destroyed!
15:17:57.394   tsx0x15f9744  .Request to terminate transaction
15:17:57.394   tsx0x15f9744  ..State changed from Completed to Terminated, event=USER
15:17:57.394  tdta0x15f7748  .Destroying txdata Request msg REGISTER/cseq=8449 (tdta0x15f7748)
15:17:57.394   tsx0x15f9744  .Transaction destroyed!
15:17:57.394 sip_transactio  .Stopped transaction layer module
15:17:57.394 sip_endpoint.c  .Module "mod-unsolicited-mwi" unregistered
15:17:57.394 sip_endpoint.c  .Module "mod-pjsua-options" unregistered
15:17:57.394 sip_endpoint.c  .Module "mod-pjsua-im" unregistered
15:17:57.394 sip_endpoint.c  .Module "mod-pjsua-pres" unregistered
15:17:57.395 sip_endpoint.c  .Module "mod-pjsua" unregistered
15:17:57.395 sip_endpoint.c  .Module "mod-stateful-util" unregistered
15:17:57.395 sip_endpoint.c  .Module "mod-refer" unregistered
15:17:57.395 sip_endpoint.c  .Module "mod-mwi" unregistered
15:17:57.395 sip_endpoint.c  .Module "mod-presence" unregistered
15:17:57.395 sip_endpoint.c  .Module "mod-evsub" unregistered
15:17:57.395 sip_endpoint.c  .Module "mod-invite" unregistered
15:17:57.395 sip_endpoint.c  .Module "mod-100rel" unregistered
15:17:57.395 sip_endpoint.c  .Module "mod-ua" unregistered
15:17:57.396 sip_transactio  .Transaction layer module destroyed
15:17:57.396 sip_endpoint.c  .Module "mod-tsx-layer" unregistered
15:17:57.396 sip_endpoint.c  .Module "mod-msg-print" unregistered
15:17:57.396 sip_endpoint.c  .Module "mod-pjsua-log" unregistered
15:17:57.396 sip_transport.  .Destroying transport manager
15:17:57.397   udp0x15d9210  .SIP UDP transport destroyed
15:17:57.398 sip_endpoint.c  .Endpoint 0x15b0d4c destroyed
15:17:57.398   pjsua_core.c  .PJSUA state changed: CLOSING --> NULL
15:17:57.398   pjsua_core.c  .PJSUA destroyed...




Alexandre Gonçalves

............................................................................................................................


2016-04-14 15:28 GMT+01:00 Alexandre Gonçalves <alexandre@xxxxxxxxxxxxxxxxxx>:
Indeed I'm using a Raspberry (model 1). I've also a model 3, and I'm going to try.

Later I post the results.

Thanks.


Alexandre Gonçalves

............................................................................................................................


2016-04-14 15:12 GMT+01:00 Bill Gardner <billg@xxxxxxxxxxxx>:
Other raspberry users have encountered this issue. I think it's either a buffer issue with ALSA device, or you're running out of CPU. In my experience with PJSIP, one of the most useful debugging statistics is to see a count of audio recording and playback callbacks. That will tell you if media is flowing in both directions to from device, and also if PJSIP is keeping up or running out of CPU. But it is not built-in. - Bill



On 4/12/2016 10:32 AM, Alexandre Gonçalves wrote:
Running with root privilegies, the warning went away:

14:18:12.516     alsa_dev.c !ca_thread_func(2765): Set thread priority for audio capture thread.
14:18:12.517          speex !warning: discarded first playback frame
14:18:12.521          speex  warning: discarded first playback frame
14:18:12.524          speex  warning: discarded first playback frame
14:18:12.526          speex !warning: discarded first playback frame


But the speex warning continues. 

In my code, I have this callback function defined:

static void on_call_media_state(pjsua_call_id call_id) {
    pjsua_call_info ci;

    pjsua_call_get_info(call_id, &ci);

    if (ci.media_status == PJSUA_CALL_MEDIA_ACTIVE) {
        // When media is active, connect call to sound device.
        pjsua_conf_connect(ci.conf_slot, 0);
        pjsua_conf_connect(0, ci.conf_slot);
    }
}


The connection with pjsua_conf_connect, shouldn't be with the frames after being processed by the aec?


Thanks.

Alexandre Gonçalves

............................................................................................................................


2016-04-12 15:04 GMT+01:00 Bill Gardner <billg@xxxxxxxxxxxx>:
Oh, ALSA dev. I don't have much of any experience with this, but it is a frequent topic on the list. You might want to browse through the archives. I note the following in the log:

On 4/12/2016 9:56 AM, Alexandre Gonçalves wrote:
13:53:51.963     alsa_dev.c !ca_thread_func(2733): Set thread priority for audio capture thread.
13:53:51.965     alsa_dev.c  Unable to increase thread priority, root access needed.

If the audio thread priority isn't high enough, you could get underruns which would cause the speex warnings you see.

Bill


_______________________________________________
Visit our blog: http://blog.pjsip.org

pjsip mailing list
pjsip@xxxxxxxxxxxxxxx
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org



_______________________________________________
Visit our blog: http://blog.pjsip.org

pjsip mailing list
pjsip@xxxxxxxxxxxxxxx
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org


_______________________________________________
Visit our blog: http://blog.pjsip.org

pjsip mailing list
pjsip@xxxxxxxxxxxxxxx
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org



_______________________________________________
Visit our blog: http://blog.pjsip.org

pjsip mailing list
pjsip@xxxxxxxxxxxxxxx
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org
[Index of Archives]     [Asterisk Users]     [Asterisk App Development]     [Linux ARM Kernel]     [Linux ARM]     [Linux Omap]     [Fedora ARM]     [IETF Annouce]     [Security]     [Bugtraq]     [Linux]     [Linux OMAP]     [Linux MIPS]     [Linux API]
  Powered by Linux