BBB 1.1 and CanvasLMS integration.

245 views

Skip to first unread message

pimp...@gmail.com

unread,

Mar 10, 2017, 9:40:14 PM3/10/17

to BigBlueButton-Setup

first of all, Greetings to all the bigbluebutton community.

here its my problem, im integrating canvasLMS and BBB. the Plugin for BBB in Canvas its not working very good. i know that Canvas use a DialPlan of 20 Digits

so i edited this Files in BBB:

sudo nano /opt/freeswitch/conf/dialplan/default/bbb_conference.xml

</condition>

</extension>

</include>

and this:

sudo nano /opt/freeswitch/conf/dialplan/default/bbb_echo_test.xml

<action application="bind_digit_action" data="direct_from_echo,1,exec:exe$

</condition>

</extension>

</include>

then i do

sudo bbb-conf --clean

Then

sudo /opt/freeswitch/bin/fs_cli

and in Canvas i créate a new conference and Join.

the conference ask me: How do you want to join the audio?

Click => Mic

in the Audio Test this its my debug:

========================================

2017-03-11 00:30:44.416507 [NOTICE] switch_channel.c:1104 New Channel sofia/external/uftpxxxeg0c7...@domain.com [08717b11-3e65-4392-abc3-e1427218d1bc]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_NEW (Cur 1 Tot 1)

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:9819 sofia/external/uftpxxxeg0c7...@domain.com receiving invite from BBB_PUBLIC_IP:40574 version: 1.6.15 git bec4538 2017-02-14 17:37:45Z 64bit

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:11131 Setting NAT mode based on websockets

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7...@domain.com entering state [received][100]

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:7052 Remote SDP:

v=0

o=mozilla...THIS_IS_SDPARTA-52.0 4184808154025650606 0 IN IP4 0.0.0.0

s=-

t=0 0

a=sendrecv

a=fingerprint:sha-256 12:56:3F:66:14:A1:77:F8:24:61:EF:FF:1C:AB:79:F4:49:3C:1C:89:5C:DC:7D:B3:C4:45:D4:C0:E9:D5:EB:89

a=ice-options:trickle

a=msid-semantic:WMS *

m=audio 49974 UDP/TLS/RTP/SAVPF 109 9 0 8 101

c=IN IP4 MY_PUBLIC_IP

a=rtpmap:109 opus/48000/2

a=fmtp:109 maxplaybackrate=48000;stereo=1;useinbandfec=1

a=rtpmap:9 G722/8000/1

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=candidate:0 1 UDP 2122252543 10.0.1.101 49974 typ host

a=candidate:0 2 UDP 2122252542 10.0.1.101 64539 typ host

a=candidate:1 1 UDP 1686052863 MY_PUBLIC_IP 49974 typ srflx raddr 10.0.1.101 rport 49974

a=candidate:1 2 UDP 1686052862 MY_PUBLIC_IP 64539 typ srflx raddr 10.0.1.101 rport 64539

a=end-of-candidates

a=extmap:1/sendonly urn:ietf:params:rtp-hdrext:ssrc-audio-level

a=ice-pwd:f57af048421fcca7f8ab98617106cb6b

a=ice-ufrag:dfb58be6

a=mid:sdparta_0

a=msid:{277c09ea-6374-ad45-a1b3-66fcdc92ce7e} {f6c03516-ea83-bf4b-8ea9-727a43dfe46e}

a=rtcp:64539 IN IP4 MY_PUBLIC_IP

a=rtcp-mux

a=setup:actpass

a=ssrc:597463825 cname:{82ee3a23-023e-8747-b358-0b83a6f15f7a}

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:7444 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_NEW -> CS_INIT

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:603 (sofia/external/uftpxxxeg0c7...@domain.com) State NEW

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_INIT (Cur 1 Tot 1)

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7...@domain.com) State INIT

2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:90 sofia/external/uftpxxxeg0c7...@domain.com SOFIA INIT

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:40 sofia/external/uftpxxxeg0c7...@domain.com Standard INIT

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:48 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_INIT -> CS_ROUTING

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7...@domain.com) State INIT going to sleep

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_ROUTING (Cur 1 Tot 1)

2017-03-11 00:30:44.416507 [DEBUG] switch_channel.c:2249 (sofia/external/uftpxxxeg0c7...@domain.com) Callstate Change DOWN -> RINGING

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7...@domain.com) State ROUTING

2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:143 sofia/external/uftpxxxeg0c7...@domain.com SOFIA ROUTING

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:236 sofia/external/uftpxxxeg0c7...@domain.com Standard ROUTING

2017-03-11 00:30:44.416507 [INFO] mod_dialplan_xml.c:637 Processing uftpxxxeg0c7_1-bbbID-MY_NAME <uftpxxxeg0c7_1-bbbID-MY_NAME>->919610000000000036 in context public

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->unloop] continue=false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->outside_call] continue=true

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Absolute Condition [outside_call]

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action set(outside_call=true)

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->bbb_sp_call] continue=true

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (FAIL) [bbb_sp_call] network_addr(BBB_PUBLIC_IP) =~ /172.31.15.62/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->bbb_webrtc_call] continue=true

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [bbb_webrtc_call] ${sip_via_protocol}(wss) =~ /^wss?$/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action set(bbb_authorized=true)

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action transfer(${destination_number} XML default)

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:286 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_ROUTING -> CS_EXECUTE

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7...@domain.com) State ROUTING going to sleep

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_EXECUTE (Cur 1 Tot 1)

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7...@domain.com) State EXECUTE

2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:198 sofia/external/uftpxxxeg0c7...@domain.com SOFIA EXECUTE

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:328 sofia/external/uftpxxxeg0c7...@domain.com Standard EXECUTE

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com set(outside_call=true)

2017-03-11 00:30:44.416507 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7...@domain.com [outside_call]=[true]

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com export(RFC2822_DATE=Sat, 11 Mar 2017 00:30:44 +0000)

2017-03-11 00:30:44.416507 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Sat, 11 Mar 2017 00:30:44 +0000]

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com set(bbb_authorized=true)

2017-03-11 00:30:44.416507 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7...@domain.com [bbb_authorized]=[true]

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com transfer(919610000000000036 XML default)

2017-03-11 00:30:44.416507 [DEBUG] switch_ivr.c:2160 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_EXECUTE -> CS_ROUTING

2017-03-11 00:30:44.416507 [NOTICE] switch_ivr.c:2167 Transfer sofia/external/uftpxxxeg0c7...@domain.com to XML[919610000000000036@default]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7...@domain.com) State EXECUTE going to sleep

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_ROUTING (Cur 1 Tot 1)

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7...@domain.com) State ROUTING

2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:143 sofia/external/uftpxxxeg0c7...@domain.com SOFIA ROUTING

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:236 sofia/external/uftpxxxeg0c7...@domain.com Standard ROUTING

2017-03-11 00:30:44.416507 [INFO] mod_dialplan_xml.c:637 Processing uftpxxxeg0c7_1-bbbID-MY_NAME <uftpxxxeg0c7_1-bbbID-MY_NAME>->919610000000000036 in context default

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [default->unloop] continue=false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [default->bbb_conferences] continue=false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [bbb_conferences] ${bbb_authorized}(true) =~ /true/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [bbb_conferences] destination_number(919610000000000036) =~ /^(\d{5,20})$/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action set(jitterbuffer_msec=20:400)

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action answer()

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action conference(919610000000000036@cdquality)

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:286 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_ROUTING -> CS_EXECUTE

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7...@domain.com) State ROUTING going to sleep

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_EXECUTE (Cur 1 Tot 1)

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7...@domain.com) State EXECUTE

2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:198 sofia/external/uftpxxxeg0c7...@domain.com SOFIA EXECUTE

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:328 sofia/external/uftpxxxeg0c7...@domain.com Standard EXECUTE

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com set(jitterbuffer_msec=20:400)

2017-03-11 00:30:44.416507 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7...@domain.com [jitterbuffer_msec]=[20:400]

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com answer()

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [opus:109:48000:20:0:2]/[opus:116:48000:20:0:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [opus:109:48000:20:0:2]/[SPEEX:99:16000:20:42200:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [opus:109:48000:20:0:2]/[SPEEX:99:8000:20:24600:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [opus:109:48000:20:0:2]/[G722:9:8000:20:64000:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [opus:109:48000:20:0:2]/[PCMU:0:8000:20:64000:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [opus:109:48000:20:0:2]/[PCMA:8:8000:20:64000:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [G722:9:8000:20:64000:1]/[SPEEX:99:16000:20:42200:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [G722:9:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[SPEEX:99:16000:20:42200:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[SPEEX:99:16000:20:42200:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4316 Set telephone-event payload to 101@8000

2017-03-11 00:30:44.416507 [DEBUG] mod_opus.c:586 Opus encoder: set bitrate to local settings [120000bps]

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3047 Set Codec sofia/external/uftpxxxeg0c7...@domain.com opus/48000 20 ms 960 samples 0 bits 2 channels

2017-03-11 00:30:44.416507 [DEBUG] switch_core_codec.c:111 sofia/external/uftpxxxeg0c7...@domain.com Original read codec set to opus:116

2017-03-11 00:30:44.416507 [WARNING] switch_core_media.c:3425 NO candidate ACL defined, Defaulting to wan.auto

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: UDP type: host addr: 10.0.1.101:49974

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 2 proto: UDP type: host addr: 10.0.1.101:64539

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: UDP type: srflx addr: MY_PUBLIC_IP:49974

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 2 proto: UDP type: srflx addr: MY_PUBLIC_IP:64539

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3497 Searching for rtp candidate.

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3502 Choose rtp candidate, index 1, MY_PUBLIC_IP:49974

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3276 sofia/external/uftpxxxeg0c7...@domain.com choosing family v4

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3513 Choose same candidate, index 2, for rtcp based on rtcp-mux attribute MY_PUBLIC_IP:49974

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3558 setting remote audio ice addr to index 1 MY_PUBLIC_IP:49974 based on candidate

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3579 Setting remote rtcp audio addr to MY_PUBLIC_IP:49974 based on candidate

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4718 sofia/external/uftpxxxeg0c7...@domain.com Set 2833 dtmf send payload to 101 recv payload to 101

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:6732 AUDIO RTP [sofia/external/uftpxxxeg0c7...@domain.com] 172.31.15.62 port 24192 -> MY_PUBLIC_IP port 49974 codec: 109 ms: 20

2017-03-11 00:30:44.416507 [DEBUG] switch_rtp.c:3878 Starting timer [soft] 960 bytes per 20ms

2017-03-11 00:30:44.416507 [INFO] switch_core_media.c:6914 Activating Audio ICE

2017-03-11 00:30:44.416507 [NOTICE] switch_rtp.c:4367 Activating RTP audio ICE: dfb58be6:fP6O7hhIYDR2hzV8 MY_PUBLIC_IP:49974

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:6957 Activating RTCP PORT 49974

2017-03-11 00:30:44.416507 [DEBUG] switch_rtp.c:4264 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 49974

2017-03-11 00:30:44.416507 [INFO] switch_core_media.c:6965 Skipping RTCP ICE (Same as RTP)

2017-03-11 00:30:44.416507 [INFO] switch_rtp.c:3371 Activate RTP/RTCP audio DTLS client

2017-03-11 00:30:44.416507 [INFO] switch_rtp.c:3505 Changing audio DTLS state from OFF to HANDSHAKE

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:2017 Setting Jitterbuffer to 20ms (1 frames) (20 max frames)

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:7038 sofia/external/uftpxxxeg0c7...@domain.com Set 2833 dtmf send payload to 101

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:7045 sofia/external/uftpxxxeg0c7...@domain.com Set 2833 dtmf receive payload to 101

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:7068 sofia/external/uftpxxxeg0c7...@domain.com Set rtp dtmf delay to 40

2017-03-11 00:30:44.416507 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/uftpxxxeg0c7...@domain.com!

2017-03-11 00:30:44.416507 [DEBUG] switch_channel.c:3473 (sofia/external/uftpxxxeg0c7...@domain.com) Callstate Change RINGING -> EARLY

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:6715 Audio params are unchanged for sofia/external/uftpxxxeg0c7...@domain.com.

2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/uftpxxxeg0c7...@domain.com:

v=0

o=FreeSWITCH 1489168052 1489168053 IN IP4 BBB_PUBLIC_IP

s=FreeSWITCH

c=IN IP4 BBB_PUBLIC_IP

t=0 0

a=msid-semantic: WMS ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3

m=audio 24192 UDP/TLS/RTP/SAVPF 109 101

a=rtpmap:109 opus/48000/2

a=fmtp:109 useinbandfec=1; stereo=1

a=rtpmap:101 telephone-event/8000

a=ptime:20

a=sendrecv

a=fingerprint:sha-256 BD:69:8F:F2:86:19:DA:AC:6A:1B:97:8B:23:E5:2A:C4:76:44:89:67:39:5F:92:23:60:18:85:A9:DC:BA:85:11

a=setup:active

a=rtcp-mux

a=rtcp:24192 IN IP4 BBB_PUBLIC_IP

a=ice-ufrag:fP6O7hhIYDR2hzV8

a=ice-pwd:yPolVyFtIH47UZYZEUEB2L9Q

a=candidate:6781037934 1 udp 659136 BBB_PUBLIC_IP 24192 typ host generation 0

a=end-of-candidates

a=ssrc:1757939060 cname:094pXfktHjcLzm40

a=ssrc:1757939060 msid:ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3 a0

a=ssrc:1757939060 mslabel:ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3

a=ssrc:1757939060 label:ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3a0

2017-03-11 00:30:44.436578 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7...@domain.com entering state [completed][200]

2017-03-11 00:30:44.616576 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7...@domain.com entering state [ready][200]

2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3162 Changing audio DTLS state from HANDSHAKE to SETUP

2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3071 audio Fingerprint Verified.

2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3690 Activating Audio Secure RTP SEND

2017-03-11 00:30:44.916591 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80

2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3668 Activating Audio Secure RTP RECV

2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3111 Changing audio DTLS state from SETUP to READY

2017-03-11 00:30:44.916591 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80

2017-03-11 00:30:44.916591 [NOTICE] mod_dptools.c:1309 Channel [sofia/external/uftpxxxeg0c7...@domain.com] has been answered

2017-03-11 00:30:44.916591 [DEBUG] switch_channel.c:3772 (sofia/external/uftpxxxeg0c7...@domain.com) Callstate Change EARLY -> ACTIVE

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com conference(919610000000000036@cdquality)

2017-03-11 00:30:44.916591 [DEBUG] mod_conference.c:3077 using channel sound prefix: /opt/freeswitch/share/freeswitch/sounds/en/us/callie

2017-03-11 00:30:44.916591 [DEBUG] conference_member.c:1679 Raw Codec Activation Success L16@48000hz 2 channel 20ms

2017-03-11 00:30:44.916591 [DEBUG] conference_member.c:1726 Raw Codec Activation Success L16@48000hz 1 channel 20ms

2017-03-11 00:30:44.916591 [DEBUG] switch_core_codec.c:223 sofia/external/uftpxxxeg0c7...@domain.com Push codec L16:100

2017-03-11 00:30:44.916591 [DEBUG] mod_conference.c:220 Setup timer success interval: 20 samples: 960

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '0' to 'mute'

2017-03-11 00:30:44.936568 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 0/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ece8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '*' to 'deaf mute'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding */conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ed18

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '9' to 'energy up'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 9/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ed48

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '8' to 'energy equ'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 8/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ed78

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '7' to 'energy dn'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 7/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007eda8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '3' to 'vol talk up'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 3/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007edd8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '2' to 'vol talk zero'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 2/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee08

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '1' to 'vol talk dn'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 1/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee38

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '6' to 'vol listen up'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 6/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee68

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '5' to 'vol listen zero'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 5/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee98

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '4' to 'vol listen dn'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 4/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007eec8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '#' to 'hangup'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding #/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007eef8

2017-03-11 00:30:44.936568 [DEBUG] conference_loop.c:1140 Setup timer soft success interval: 20 samples: 960 from codec opus

2017-03-11 00:30:44.936568 [DEBUG] switch_rtp.c:1878 rtcp_stats_init: audio ssrc[597463825] base_seq[16029]

========================================

I dont hear nothing in the echo test

Click yes

Transferring… (in Voice: Negative 1)

and this is the debug file of that part of entering in the conference.

========================================

2017-03-11 00:32:37.156572 [INFO] switch_channel.c:515 RECV DTMF 1:800

2017-03-11 00:32:37.156572 [DEBUG] sofia.c:9547 INFO DTMF(1)

2017-03-11 00:32:37.156572 [DEBUG] conference_member.c:1411 Queueing file '/opt/freeswitch/share/freeswitch/sounds/en/us/callie/currency/negative.wav' for play

2017-03-11 00:32:37.156572 [DEBUG] conference_member.c:1411 Queueing file '/opt/freeswitch/share/freeswitch/sounds/en/us/callie/digits/1.wav' for play

2017-03-11 00:32:42.176578 [NOTICE] sofia.c:1012 Hangup sofia/external/uftpxxxeg0c7...@domain.com [CS_EXECUTE] [NORMAL_CLEARING]

2017-03-11 00:32:42.176578 [INFO] conference_loop.c:1455 Channel leaving conference, cause: NORMAL_CLEARING

2017-03-11 00:32:42.176578 [DEBUG] mod_conference.c:2259 sofia/external/uftpxxxeg0c7...@domain.com skip receive message [UNBRIDGE] (channel is hungup already)

2017-03-11 00:32:42.176578 [DEBUG] switch_core_media.c:9643 sofia/external/uftpxxxeg0c7...@domain.com skip receive message [HARD_MUTE] (channel is hungup already)

2017-03-11 00:32:42.176578 [DEBUG] switch_core_codec.c:248 sofia/external/uftpxxxeg0c7...@domain.com Restore previous codec opus:116.

2017-03-11 00:32:42.176578 [DEBUG] switch_core_session.c:2814 sofia/external/uftpxxxeg0c7...@domain.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7...@domain.com) State EXECUTE going to sleep

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_HANGUP (Cur 1 Tot 1)

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:850 (sofia/external/uftpxxxeg0c7...@domain.com) Callstate Change ACTIVE -> HANGUP

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:852 (sofia/external/uftpxxxeg0c7...@domain.com) State HANGUP

2017-03-11 00:32:42.176578 [DEBUG] mod_sofia.c:438 Channel sofia/external/uftpxxxeg0c7...@domain.com hanging up, cause: NORMAL_CLEARING

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:60 sofia/external/uftpxxxeg0c7...@domain.com Standard HANGUP, cause: NORMAL_CLEARING

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:852 (sofia/external/uftpxxxeg0c7...@domain.com) State HANGUP going to sleep

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:619 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_HANGUP -> CS_REPORTING

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_REPORTING (Cur 1 Tot 1)

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:938 (sofia/external/uftpxxxeg0c7...@domain.com) State REPORTING

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:174 sofia/external/uftpxxxeg0c7...@domain.com Standard REPORTING, cause: NORMAL_CLEARING

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:938 (sofia/external/uftpxxxeg0c7...@domain.com) State REPORTING going to sleep

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:610 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_REPORTING -> CS_DESTROY

2017-03-11 00:32:42.176578 [DEBUG] switch_core_session.c:1664 Session 1 (sofia/external/uftpxxxeg0c7...@domain.com) Locked, Waiting on external entities

2017-03-11 00:32:42.176578 [NOTICE] switch_core_session.c:1682 Session 1 (sofia/external/uftpxxxeg0c7...@domain.com) Ended

2017-03-11 00:32:42.176578 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/uftpxxxeg0c7...@domain.com [CS_DESTROY]

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:741 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_DESTROY (Cur 0 Tot 1)

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:751 (sofia/external/uftpxxxeg0c7...@domain.com) State DESTROY

2017-03-11 00:32:42.176578 [DEBUG] mod_sofia.c:343 sofia/external/uftpxxxeg0c7...@domain.com SOFIA DESTROY

2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:694 Opus decoder stats: Frames[5853] PLC[2] FEC[0]

2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:709 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] FEC frames (only for debug mode) [0]

2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:694 Opus decoder stats: Frames[0] PLC[0] FEC[0]

2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:709 Opus encoder stats: Frames[5861] Bytes encoded[1385636] Encoded length ms[117220] Average encoded bitrate bps[94744] FEC frames (only for debug mode) [0]

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:181 sofia/external/uftpxxxeg0c7...@domain.com Standard DESTROY

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:751 (sofia/external/uftpxxxeg0c7...@domain.com) State DESTROY going to sleep

2017-03-11 00:32:42.176578 [DEBUG] mod_conference.c:822 Write Lock ON

2017-03-11 00:32:42.176578 [DEBUG] mod_conference.c:825 Write Lock OFF

2017-03-11 00:32:43.436588 [NOTICE] switch_channel.c:1104 New Channel sofia/external/uftpxxxeg0c7...@domain.com [4628b180-e34d-4b66-99e5-2f5506e0f0f6]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_NEW (Cur 1 Tot 2)

2017-03-11 00:32:43.436588 [DEBUG] sofia.c:9819 sofia/external/uftpxxxeg0c7...@domain.com receiving invite from BBB_PUBLIC_IP:40580 version: 1.6.15 git bec4538 2017-02-14 17:37:45Z 64bit

2017-03-11 00:32:43.436588 [DEBUG] sofia.c:11131 Setting NAT mode based on websockets

2017-03-11 00:32:43.436588 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7...@domain.com entering state [received][100]

2017-03-11 00:32:43.436588 [DEBUG] sofia.c:7052 Remote SDP:

v=0

o=mozilla...THIS_IS_SDPARTA-52.0 4576051777087576220 0 IN IP4 0.0.0.0

s=-

t=0 0

a=sendrecv

a=fingerprint:sha-256 64:5D:74:63:74:42:B5:96:F0:C5:15:DA:46:DE:9F:7C:BB:C4:91:46:80:F1:40:24:0B:1C:1F:AB:C1:27:E5:9D

a=ice-options:trickle

a=msid-semantic:WMS *

m=audio 55070 UDP/TLS/RTP/SAVPF 109 9 0 8 101

c=IN IP4 MY_PUBLIC_IP

a=rtpmap:109 opus/48000/2

a=fmtp:109 maxplaybackrate=48000;stereo=1;useinbandfec=1

a=rtpmap:9 G722/8000/1

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=candidate:0 1 UDP 2122252543 10.0.1.101 55070 typ host

a=candidate:0 2 UDP 2122252542 10.0.1.101 62023 typ host

a=candidate:1 1 UDP 1686052863 MY_PUBLIC_IP 55070 typ srflx raddr 10.0.1.101 rport 55070

a=candidate:1 2 UDP 1686052862 MY_PUBLIC_IP 62023 typ srflx raddr 10.0.1.101 rport 62023

a=end-of-candidates

a=extmap:1/sendonly urn:ietf:params:rtp-hdrext:ssrc-audio-level

a=ice-pwd:284d5f90de80449aec2a875aad40a4eb

a=ice-ufrag:778a6bef

a=mid:sdparta_0

a=msid:{277c09ea-6374-ad45-a1b3-66fcdc92ce7e} {f6c03516-ea83-bf4b-8ea9-727a43dfe46e}

a=rtcp:62023 IN IP4 MY_PUBLIC_IP

a=rtcp-mux

a=setup:actpass

a=ssrc:3625017290 cname:{e9de971d-c8e6-184e-99cf-d64cea9cac5c}

2017-03-11 00:32:43.436588 [DEBUG] sofia.c:7444 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_NEW -> CS_INIT

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:603 (sofia/external/uftpxxxeg0c7...@domain.com) State NEW

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_INIT (Cur 1 Tot 2)

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7...@domain.com) State INIT

2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:90 sofia/external/uftpxxxeg0c7...@domain.com SOFIA INIT

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:40 sofia/external/uftpxxxeg0c7...@domain.com Standard INIT

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:48 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_INIT -> CS_ROUTING

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7...@domain.com) State INIT going to sleep

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_ROUTING (Cur 1 Tot 2)

2017-03-11 00:32:43.436588 [DEBUG] switch_channel.c:2249 (sofia/external/uftpxxxeg0c7...@domain.com) Callstate Change DOWN -> RINGING

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7...@domain.com) State ROUTING

2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:143 sofia/external/uftpxxxeg0c7...@domain.com SOFIA ROUTING

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:236 sofia/external/uftpxxxeg0c7...@domain.com Standard ROUTING

2017-03-11 00:32:43.436588 [INFO] mod_dialplan_xml.c:637 Processing uftpxxxeg0c7_1-bbbID-MY_NAME <uftpxxxeg0c7_1-bbbID-MY_NAME>->10000000000036 in context public

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->unloop] continue=false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->outside_call] continue=true

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Absolute Condition [outside_call]

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action set(outside_call=true)

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->bbb_sp_call] continue=true

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (FAIL) [bbb_sp_call] network_addr(BBB_PUBLIC_IP) =~ /172.31.15.62/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->bbb_webrtc_call] continue=true

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [bbb_webrtc_call] ${sip_via_protocol}(wss) =~ /^wss?$/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action set(bbb_authorized=true)

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action transfer(${destination_number} XML default)

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:286 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_ROUTING -> CS_EXECUTE

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7...@domain.com) State ROUTING going to sleep

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_EXECUTE (Cur 1 Tot 2)

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7...@domain.com) State EXECUTE

2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:198 sofia/external/uftpxxxeg0c7...@domain.com SOFIA EXECUTE

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:328 sofia/external/uftpxxxeg0c7...@domain.com Standard EXECUTE

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com set(outside_call=true)

2017-03-11 00:32:43.436588 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7...@domain.com [outside_call]=[true]

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com export(RFC2822_DATE=Sat, 11 Mar 2017 00:32:43 +0000)

2017-03-11 00:32:43.436588 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Sat, 11 Mar 2017 00:32:43 +0000]

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com set(bbb_authorized=true)

2017-03-11 00:32:43.436588 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7...@domain.com [bbb_authorized]=[true]

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com transfer(10000000000036 XML default)

2017-03-11 00:32:43.436588 [DEBUG] switch_ivr.c:2160 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_EXECUTE -> CS_ROUTING

2017-03-11 00:32:43.436588 [NOTICE] switch_ivr.c:2167 Transfer sofia/external/uftpxxxeg0c7...@domain.com to XML[10000000000036@default]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7...@domain.com) State EXECUTE going to sleep

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_ROUTING (Cur 1 Tot 2)

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7...@domain.com) State ROUTING

2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:143 sofia/external/uftpxxxeg0c7...@domain.com SOFIA ROUTING

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:236 sofia/external/uftpxxxeg0c7...@domain.com Standard ROUTING

2017-03-11 00:32:43.436588 [INFO] mod_dialplan_xml.c:637 Processing uftpxxxeg0c7_1-bbbID-MY_NAME <uftpxxxeg0c7_1-bbbID-MY_NAME>->10000000000036 in context default

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [default->unloop] continue=false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [default->bbb_conferences] continue=false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [bbb_conferences] ${bbb_authorized}(true) =~ /true/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [bbb_conferences] destination_number(10000000000036) =~ /^(\d{5,20})$/ break=on-false

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action set(jitterbuffer_msec=20:400)

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action answer()

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action conference(10000000000036@cdquality)

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:286 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_ROUTING -> CS_EXECUTE

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7...@domain.com) State ROUTING going to sleep

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_EXECUTE (Cur 1 Tot 2)

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7...@domain.com) State EXECUTE

2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:198 sofia/external/uftpxxxeg0c7...@domain.com SOFIA EXECUTE

2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:328 sofia/external/uftpxxxeg0c7...@domain.com Standard EXECUTE

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com set(jitterbuffer_msec=20:400)

2017-03-11 00:32:43.436588 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7...@domain.com [jitterbuffer_msec]=[20:400]

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com answer()

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [opus:109:48000:20:0:2]/[opus:116:48000:20:0:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [opus:109:48000:20:0:2]/[SPEEX:99:16000:20:42200:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [opus:109:48000:20:0:2]/[SPEEX:99:8000:20:24600:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [opus:109:48000:20:0:2]/[G722:9:8000:20:64000:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [opus:109:48000:20:0:2]/[PCMU:0:8000:20:64000:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [opus:109:48000:20:0:2]/[PCMA:8:8000:20:64000:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [G722:9:8000:20:64000:1]/[SPEEX:99:16000:20:42200:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [G722:9:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[SPEEX:99:16000:20:42200:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[SPEEX:99:16000:20:42200:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4316 Set telephone-event payload to 101@8000

2017-03-11 00:32:43.436588 [DEBUG] mod_opus.c:586 Opus encoder: set bitrate to local settings [120000bps]

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3047 Set Codec sofia/external/uftpxxxeg0c7...@domain.com opus/48000 20 ms 960 samples 0 bits 2 channels

2017-03-11 00:32:43.436588 [DEBUG] switch_core_codec.c:111 sofia/external/uftpxxxeg0c7...@domain.com Original read codec set to opus:116

2017-03-11 00:32:43.436588 [WARNING] switch_core_media.c:3425 NO candidate ACL defined, Defaulting to wan.auto

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: UDP type: host addr: 10.0.1.101:55070

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 2 proto: UDP type: host addr: 10.0.1.101:62023

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: UDP type: srflx addr: MY_PUBLIC_IP:55070

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 2 proto: UDP type: srflx addr: MY_PUBLIC_IP:62023

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3497 Searching for rtp candidate.

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3502 Choose rtp candidate, index 1, MY_PUBLIC_IP:55070

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3276 sofia/external/uftpxxxeg0c7...@domain.com choosing family v4

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3513 Choose same candidate, index 2, for rtcp based on rtcp-mux attribute MY_PUBLIC_IP:55070

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3558 setting remote audio ice addr to index 1 MY_PUBLIC_IP:55070 based on candidate

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3579 Setting remote rtcp audio addr to MY_PUBLIC_IP:55070 based on candidate

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4718 sofia/external/uftpxxxeg0c7...@domain.com Set 2833 dtmf send payload to 101 recv payload to 101

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:6732 AUDIO RTP [sofia/external/uftpxxxeg0c7...@domain.com] 172.31.15.62 port 20594 -> MY_PUBLIC_IP port 55070 codec: 109 ms: 20

2017-03-11 00:32:43.436588 [DEBUG] switch_rtp.c:3878 Starting timer [soft] 960 bytes per 20ms

2017-03-11 00:32:43.436588 [INFO] switch_core_media.c:6914 Activating Audio ICE

2017-03-11 00:32:43.436588 [NOTICE] switch_rtp.c:4367 Activating RTP audio ICE: 778a6bef:pLatUwCKJpDnLYHo MY_PUBLIC_IP:55070

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:6957 Activating RTCP PORT 55070

2017-03-11 00:32:43.436588 [DEBUG] switch_rtp.c:4264 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 55070

2017-03-11 00:32:43.436588 [INFO] switch_core_media.c:6965 Skipping RTCP ICE (Same as RTP)

2017-03-11 00:32:43.436588 [INFO] switch_rtp.c:3371 Activate RTP/RTCP audio DTLS client

2017-03-11 00:32:43.436588 [INFO] switch_rtp.c:3505 Changing audio DTLS state from OFF to HANDSHAKE

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:2017 Setting Jitterbuffer to 20ms (1 frames) (20 max frames)

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:7038 sofia/external/uftpxxxeg0c7...@domain.com Set 2833 dtmf send payload to 101

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:7045 sofia/external/uftpxxxeg0c7...@domain.com Set 2833 dtmf receive payload to 101

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:7068 sofia/external/uftpxxxeg0c7...@domain.com Set rtp dtmf delay to 40

2017-03-11 00:32:43.436588 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/uftpxxxeg0c7...@domain.com!

2017-03-11 00:32:43.436588 [DEBUG] switch_channel.c:3473 (sofia/external/uftpxxxeg0c7...@domain.com) Callstate Change RINGING -> EARLY

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:6715 Audio params are unchanged for sofia/external/uftpxxxeg0c7...@domain.com.

2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/uftpxxxeg0c7...@domain.com:

v=0

o=FreeSWITCH 1489171769 1489171770 IN IP4 BBB_PUBLIC_IP

s=FreeSWITCH

c=IN IP4 BBB_PUBLIC_IP

t=0 0

a=msid-semantic: WMS QpObJMGdVHrMYv9A0o5qejvi0mW2Nwvu

m=audio 20594 UDP/TLS/RTP/SAVPF 109 101

a=rtpmap:109 opus/48000/2

a=fmtp:109 useinbandfec=1; stereo=1

a=rtpmap:101 telephone-event/8000

a=ptime:20

a=sendrecv

a=fingerprint:sha-256 BD:69:8F:F2:86:19:DA:AC:6A:1B:97:8B:23:E5:2A:C4:76:44:89:67:39:5F:92:23:60:18:85:A9:DC:BA:85:11

a=setup:active

a=rtcp-mux

a=rtcp:20594 IN IP4 BBB_PUBLIC_IP

a=ice-ufrag:pLatUwCKJpDnLYHo

a=ice-pwd:Y4ABXQZnnZDg0j0fU1zFn2gW

a=candidate:6204423931 1 udp 659136 BBB_PUBLIC_IP 20594 typ host generation 0

a=end-of-candidates

a=ssrc:1758090875 cname:M9wlM2pxAHap3aPU

a=ssrc:1758090875 msid:QpObJMGdVHrMYv9A0o5qejvi0mW2Nwvu a0

a=ssrc:1758090875 mslabel:QpObJMGdVHrMYv9A0o5qejvi0mW2Nwvu

a=ssrc:1758090875 label:QpObJMGdVHrMYv9A0o5qejvi0mW2Nwvua0

2017-03-11 00:32:43.456580 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7...@domain.com entering state [completed][200]

2017-03-11 00:32:43.716578 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7...@domain.com entering state [ready][200]

2017-03-11 00:32:44.156577 [INFO] switch_rtp.c:3162 Changing audio DTLS state from HANDSHAKE to SETUP

2017-03-11 00:32:44.156577 [INFO] switch_rtp.c:3071 audio Fingerprint Verified.

2017-03-11 00:32:44.156577 [INFO] switch_rtp.c:3690 Activating Audio Secure RTP SEND

2017-03-11 00:32:44.156577 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80

2017-03-11 00:32:44.156577 [INFO] switch_rtp.c:3668 Activating Audio Secure RTP RECV

2017-03-11 00:32:44.156577 [INFO] switch_rtp.c:3111 Changing audio DTLS state from SETUP to READY

2017-03-11 00:32:44.156577 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80

2017-03-11 00:32:44.156577 [NOTICE] mod_dptools.c:1309 Channel [sofia/external/uftpxxxeg0c7...@domain.com] has been answered

2017-03-11 00:32:44.156577 [DEBUG] switch_channel.c:3772 (sofia/external/uftpxxxeg0c7...@domain.com) Callstate Change EARLY -> ACTIVE

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com conference(10000000000036@cdquality)

2017-03-11 00:32:44.156577 [DEBUG] mod_conference.c:3077 using channel sound prefix: /opt/freeswitch/share/freeswitch/sounds/en/us/callie

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:1679 Raw Codec Activation Success L16@48000hz 2 channel 20ms

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:1726 Raw Codec Activation Success L16@48000hz 1 channel 20ms

2017-03-11 00:32:44.156577 [DEBUG] switch_core_codec.c:223 sofia/external/uftpxxxeg0c7...@domain.com Push codec L16:100

2017-03-11 00:32:44.156577 [DEBUG] mod_conference.c:220 Setup timer success interval: 20 samples: 960

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '0' to 'mute'

2017-03-11 00:32:44.156577 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 0/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c3c0

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '*' to 'deaf mute'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding */conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c3f0

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '9' to 'energy up'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 9/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c420

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '8' to 'energy equ'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 8/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c450

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '7' to 'energy dn'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 7/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c480

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '3' to 'vol talk up'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 3/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c4b0

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '2' to 'vol talk zero'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 2/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c4e0

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '1' to 'vol talk dn'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 1/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c510

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '6' to 'vol listen up'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 6/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c540

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '5' to 'vol listen zero'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 5/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c570

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '4' to 'vol listen dn'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 4/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c5a0

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '#' to 'hangup'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding #/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c5d0

2017-03-11 00:32:44.156577 [DEBUG] conference_loop.c:1140 Setup timer soft success interval: 20 samples: 960 from codec opus

2017-03-11 00:32:44.196560 [DEBUG] switch_rtp.c:1878 rtcp_stats_init: audio ssrc[3625017290] base_seq[4149]

2017-03-11 00:33:16.076569 [DEBUG] switch_core_media.c:2504 [VBR]: Correcting calculated ptime value from [40] to [20] to compensate for [1] lost packet(s)

========================================

In a couple of seconds BBB says I'm the only one at the conference. And the audio works perfect. I feel like I'm still not setting the correct parameters for the echo test and the conference to work.

I have tried several parameters of the freeswitch page.

https://freeswitch.org/confluence/display/FREESWITCH/Regular+Expression

In some cases the echo test works. But not the conference audio.

i test this solution with no success

https://github.com/instructure/canvas-lms/issues/478

and this one

https://groups.google.com/forum/#!topic/bigbluebutton-users/j1QLOAtLctg

any sugestions

best regards to all

Pimpigola

unread,

Mar 11, 2017, 12:12:16 AM3/11/17

to bigbluebu...@googlegroups.com

Fix it like this:

sudo nano /opt/freeswitch/conf/dialplan/default/bbb_conference.xml

</condition>

</extension>

</include>

sudo nano /opt/freeswitch/conf/dialplan/default/bbb_echo_test.xml

<action application="bind_digit_action" data="direct_from_echo,1,exec:exe$

</condition>

</extension>

</include>

--
You received this message because you are subscribed to a topic in the Google Groups "BigBlueButton-Setup" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/bigbluebutton-setup/-VKYEWlDgIM/unsubscribe.
To unsubscribe from this group and all its topics, send an email to bigbluebutton-s...@googlegroups.com.
To post to this group, send email to bigbluebu...@googlegroups.com.
Visit this group at https://groups.google.com/group/bigbluebutton-setup.
For more options, visit https://groups.google.com/d/optout.

Fred Dixon

unread,

Mar 11, 2017, 8:14:24 AM3/11/17

to bigbluebu...@googlegroups.com

Thanks for sharing this.

Regards,.. Fred

Fix it like this:

2017-03-11 00:30:44.416507 [NOTICE] switch_channel.c:1104 New Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [08717b11-3e65-4392-abc3-e1427218d1bc]
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_NEW (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] sofia.c:9819 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com receiving invite from BBB_PUBLIC_IP:40574 version: 1.6.15 git bec4538 2017-02-14 17:37:45Z 64bit

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:11131 Setting NAT mode based on websockets

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com entering state [received][100]

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:7444 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_NEW -> CS_INIT
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:603 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State NEW
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_INIT (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State INIT
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:90 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA INIT
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:40 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard INIT
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:48 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_INIT -> CS_ROUTING
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State INIT going to sleep
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_ROUTING (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_channel.c:2249 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Callstate Change DOWN -> RINGING
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State ROUTING
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:143 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA ROUTING
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:236 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard ROUTING

2017-03-11 00:30:44.416507 [INFO] mod_dialplan_xml.c:637 Processing uftpxxxeg0c7_1-bbbID-MY_NAME <uftpxxxeg0c7_1-bbbID-MY_NAME>->919610000000000036 in context public

Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [public->unloop] continue=false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [public->outside_call] continue=true
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Absolute Condition [outside_call]
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action set(outside_call=true)
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [public->bbb_sp_call] continue=true
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (FAIL) [bbb_sp_call] network_addr(BBB_PUBLIC_IP) =~ /172.31.15.62/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [public->bbb_webrtc_call] continue=true
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [bbb_webrtc_call] ${sip_via_protocol}(wss) =~ /^wss?$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action set(bbb_authorized=true)
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action transfer(${destination_number} XML default)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:286 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_ROUTING -> CS_EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State ROUTING going to sleep
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_EXECUTE (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:198 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:328 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard EXECUTE
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com set(outside_call=true)
2017-03-11 00:30:44.416507 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [outside_call]=[true]
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com export(RFC2822_DATE=Sat, 11 Mar 2017 00:30:44 +0000)

2017-03-11 00:30:44.416507 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Sat, 11 Mar 2017 00:30:44 +0000]

EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com set(bbb_authorized=true)
2017-03-11 00:30:44.416507 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [bbb_authorized]=[true]
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com transfer(919610000000000036 XML default)
2017-03-11 00:30:44.416507 [DEBUG] switch_ivr.c:2160 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_EXECUTE -> CS_ROUTING
2017-03-11 00:30:44.416507 [NOTICE] switch_ivr.c:2167 Transfer sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com to XML[919610000000000036@default]
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State EXECUTE going to sleep
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_ROUTING (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State ROUTING
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:143 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA ROUTING
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:236 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard ROUTING

2017-03-11 00:30:44.416507 [INFO] mod_dialplan_xml.c:637 Processing uftpxxxeg0c7_1-bbbID-MY_NAME <uftpxxxeg0c7_1-bbbID-MY_NAME>->919610000000000036 in context default

Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [default->unloop] continue=false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [default->bbb_conferences] continue=false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [bbb_conferences] ${bbb_authorized}(true) =~ /true/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [bbb_conferences] destination_number(919610000000000036) =~ /^(\d{5,20})$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action set(jitterbuffer_msec=20:400)
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action answer()
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action conference(919610000000000036@cdquality)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:286 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_ROUTING -> CS_EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State ROUTING going to sleep
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_EXECUTE (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:198 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:328 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard EXECUTE
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com set(jitterbuffer_msec=20:400)
2017-03-11 00:30:44.416507 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [jitterbuffer_msec]=[20:400]
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com answer()

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3047 Set Codec sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com opus/48000 20 ms 960 samples 0 bits 2 channels
2017-03-11 00:30:44.416507 [DEBUG] switch_core_codec.c:111 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Original read codec set to opus:116

2017-03-11 00:30:44.416507 [WARNING] switch_core_media.c:3425 NO candidate ACL defined, Defaulting to wan.auto
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: UDP type: host addr: 10.0.1.101:49974
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 2 proto: UDP type: host addr: 10.0.1.101:64539
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: UDP type: srflx addr: MY_PUBLIC_IP:49974
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 2 proto: UDP type: srflx addr: MY_PUBLIC_IP:64539
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3497 Searching for rtp candidate.
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3502 Choose rtp candidate, index 1, MY_PUBLIC_IP:49974

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3276 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com choosing family v4

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3513 Choose same candidate, index 2, for rtcp based on rtcp-mux attribute MY_PUBLIC_IP:49974
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3558 setting remote audio ice addr to index 1 MY_PUBLIC_IP:49974 based on candidate
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3579 Setting remote rtcp audio addr to MY_PUBLIC_IP:49974 based on candidate

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4718 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Set 2833 dtmf send payload to 101 recv payload to 101
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:6732 AUDIO RTP [sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com] 172.31.15.62 port 24192 -> MY_PUBLIC_IP port 49974 codec: 109 ms: 20

2017-03-11 00:30:44.416507 [DEBUG] switch_rtp.c:3878 Starting timer [soft] 960 bytes per 20ms
2017-03-11 00:30:44.416507 [INFO] switch_core_media.c:6914 Activating Audio ICE
2017-03-11 00:30:44.416507 [NOTICE] switch_rtp.c:4367 Activating RTP audio ICE: dfb58be6:fP6O7hhIYDR2hzV8 MY_PUBLIC_IP:49974
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:6957 Activating RTCP PORT 49974
2017-03-11 00:30:44.416507 [DEBUG] switch_rtp.c:4264 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 49974
2017-03-11 00:30:44.416507 [INFO] switch_core_media.c:6965 Skipping RTCP ICE (Same as RTP)
2017-03-11 00:30:44.416507 [INFO] switch_rtp.c:3371 Activate RTP/RTCP audio DTLS client
2017-03-11 00:30:44.416507 [INFO] switch_rtp.c:3505 Changing audio DTLS state from OFF to HANDSHAKE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:2017 Setting Jitterbuffer to 20ms (1 frames) (20 max frames)

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:7038 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Set 2833 dtmf send payload to 101
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:7045 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Set 2833 dtmf receive payload to 101
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:7068 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Set rtp dtmf delay to 40
2017-03-11 00:30:44.416507 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com!
2017-03-11 00:30:44.416507 [DEBUG] switch_channel.c:3473 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Callstate Change RINGING -> EARLY
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:6715 Audio params are unchanged for sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com.
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com:

v=0
o=FreeSWITCH 1489168052 1489168053 IN IP4 BBB_PUBLIC_IP
s=FreeSWITCH
c=IN IP4 BBB_PUBLIC_IP
t=0 0
a=msid-semantic: WMS ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3
m=audio 24192 UDP/TLS/RTP/SAVPF 109 101
a=rtpmap:109 opus/48000/2
a=fmtp:109 useinbandfec=1; stereo=1
a=rtpmap:101 telephone-event/8000
a=ptime:20
a=sendrecv
a=fingerprint:sha-256 BD:69:8F:F2:86:19:DA:AC:6A:1B:97:8B:23:E5:2A:C4:76:44:89:67:39:5F:92:23:60:18:85:A9:DC:BA:85:11
a=setup:active
a=rtcp-mux
a=rtcp:24192 IN IP4 BBB_PUBLIC_IP
a=ice-ufrag:fP6O7hhIYDR2hzV8
a=ice-pwd:yPolVyFtIH47UZYZEUEB2L9Q
a=candidate:6781037934 1 udp 659136 BBB_PUBLIC_IP 24192 typ host generation 0
a=end-of-candidates
a=ssrc:1757939060 cname:094pXfktHjcLzm40
a=ssrc:1757939060 msid:ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3 a0
a=ssrc:1757939060 mslabel:ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3
a=ssrc:1757939060 label:ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3a0

2017-03-11 00:30:44.436578 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com entering state [completed][200]
2017-03-11 00:30:44.616576 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com entering state [ready][200]

2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3162 Changing audio DTLS state from HANDSHAKE to SETUP
2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3071 audio Fingerprint Verified.
2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3690 Activating Audio Secure RTP SEND
2017-03-11 00:30:44.916591 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80
2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3668 Activating Audio Secure RTP RECV
2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3111 Changing audio DTLS state from SETUP to READY
2017-03-11 00:30:44.916591 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80

2017-03-11 00:30:44.916591 [NOTICE] mod_dptools.c:1309 Channel [sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com] has been answered
2017-03-11 00:30:44.916591 [DEBUG] switch_channel.c:3772 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Callstate Change EARLY -> ACTIVE
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com conference(919610000000000036@cdquality)

2017-03-11 00:30:44.916591 [DEBUG] mod_conference.c:3077 using channel sound prefix: /opt/freeswitch/share/freeswitch/sounds/en/us/callie
2017-03-11 00:30:44.916591 [DEBUG] conference_member.c:1679 Raw Codec Activation Success L16@48000hz 2 channel 20ms
2017-03-11 00:30:44.916591 [DEBUG] conference_member.c:1726 Raw Codec Activation Success L16@48000hz 1 channel 20ms

2017-03-11 00:30:44.916591 [DEBUG] switch_core_codec.c:223 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Push codec L16:100

2017-03-11 00:30:44.916591 [DEBUG] mod_conference.c:220 Setup timer success interval: 20 samples: 960

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '0' to 'mute'

2017-03-11 00:30:44.936568 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf'
2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 0/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ece8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '*' to 'deaf mute'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding */conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ed18

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '9' to 'energy up'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 9/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ed48

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '8' to 'energy equ'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 8/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ed78

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '7' to 'energy dn'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 7/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007eda8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '3' to 'vol talk up'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 3/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007edd8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '2' to 'vol talk zero'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 2/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee08

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '1' to 'vol talk dn'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 1/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee38

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '6' to 'vol listen up'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 6/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee68

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '5' to 'vol listen zero'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 5/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee98

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '4' to 'vol listen dn'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 4/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007eec8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '#' to 'hangup'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding #/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007eef8
2017-03-11 00:30:44.936568 [DEBUG] conference_loop.c:1140 Setup timer soft success interval: 20 samples: 960 from codec opus
2017-03-11 00:30:44.936568 [DEBUG] switch_rtp.c:1878 rtcp_stats_init: audio ssrc[597463825] base_seq[16029]

========================================

I dont hear nothing in the echo test

Click yes

Transferring… (in Voice: Negative 1)

and this is the debug file of that part of entering in the conference.

========================================

2017-03-11 00:32:37.156572 [INFO] switch_channel.c:515 RECV DTMF 1:800
2017-03-11 00:32:37.156572 [DEBUG] sofia.c:9547 INFO DTMF(1)
2017-03-11 00:32:37.156572 [DEBUG] conference_member.c:1411 Queueing file '/opt/freeswitch/share/freeswitch/sounds/en/us/callie/currency/negative.wav' for play
2017-03-11 00:32:37.156572 [DEBUG] conference_member.c:1411 Queueing file '/opt/freeswitch/share/freeswitch/sounds/en/us/callie/digits/1.wav' for play

2017-03-11 00:32:42.176578 [NOTICE] sofia.c:1012 Hangup sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [CS_EXECUTE] [NORMAL_CLEARING]

2017-03-11 00:32:42.176578 [INFO] conference_loop.c:1455 Channel leaving conference, cause: NORMAL_CLEARING

2017-03-11 00:32:42.176578 [DEBUG] mod_conference.c:2259 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com skip receive message [UNBRIDGE] (channel is hungup already)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_media.c:9643 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com skip receive message [HARD_MUTE] (channel is hungup already)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_codec.c:248 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Restore previous codec opus:116.
2017-03-11 00:32:42.176578 [DEBUG] switch_core_session.c:2814 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State EXECUTE going to sleep
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_HANGUP (Cur 1 Tot 1)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:850 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Callstate Change ACTIVE -> HANGUP
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:852 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State HANGUP
2017-03-11 00:32:42.176578 [DEBUG] mod_sofia.c:438 Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com hanging up, cause: NORMAL_CLEARING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:60 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard HANGUP, cause: NORMAL_CLEARING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:852 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State HANGUP going to sleep
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:619 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_HANGUP -> CS_REPORTING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_REPORTING (Cur 1 Tot 1)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:938 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State REPORTING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:174 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard REPORTING, cause: NORMAL_CLEARING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:938 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State REPORTING going to sleep
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:610 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_REPORTING -> CS_DESTROY
2017-03-11 00:32:42.176578 [DEBUG] switch_core_session.c:1664 Session 1 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Locked, Waiting on external entities
2017-03-11 00:32:42.176578 [NOTICE] switch_core_session.c:1682 Session 1 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Ended
2017-03-11 00:32:42.176578 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [CS_DESTROY]
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:741 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_DESTROY (Cur 0 Tot 1)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:751 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State DESTROY
2017-03-11 00:32:42.176578 [DEBUG] mod_sofia.c:343 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA DESTROY

2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:694 Opus decoder stats: Frames[5853] PLC[2] FEC[0]
2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:709 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] FEC frames (only for debug mode) [0]
2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:694 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:709 Opus encoder stats: Frames[5861] Bytes encoded[1385636] Encoded length ms[117220] Average encoded bitrate bps[94744] FEC frames (only for debug mode) [0]

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:181 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard DESTROY
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:751 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State DESTROY going to sleep

2017-03-11 00:32:42.176578 [DEBUG] mod_conference.c:822 Write Lock ON
2017-03-11 00:32:42.176578 [DEBUG] mod_conference.c:825 Write Lock OFF

2017-03-11 00:32:43.436588 [NOTICE] switch_channel.c:1104 New Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [4628b180-e34d-4b66-99e5-2f5506e0f0f6]
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_NEW (Cur 1 Tot 2)
2017-03-11 00:32:43.436588 [DEBUG] sofia.c:9819 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com receiving invite from BBB_PUBLIC_IP:40580 version: 1.6.15 git bec4538 2017-02-14 17:37:45Z 64bit

2017-03-11 00:32:43.436588 [DEBUG] sofia.c:11131 Setting NAT mode based on websockets

2017-03-11 00:32:43.436588 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com entering state [received][100]

2017-03-11 00:32:43.436588 [DEBUG] sofia.c:7444 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_NEW -> CS_INIT
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:603 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State NEW
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_INIT (Cur 1 Tot 2)
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State INIT
2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:90 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA INIT
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:40 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard INIT
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:48 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_INIT -> CS_ROUTING
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State INIT going to sleep
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_ROUTING (Cur 1 Tot 2)
2017-03-11 00:32:43.436588 [DEBUG] switch_channel.c:2249 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Callstate Change DOWN -> RINGING
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State ROUTING
2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:143 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA ROUTING
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:236 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard ROUTING

2017-03-11 00:32:43.436588 [INFO] mod_dialplan_xml.c:637 Processing uftpxxxeg0c7_1-bbbID-MY_NAME <uftpxxxeg0c7_1-bbbID-MY_NAME>->10000000000036 in context public

Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [public->unloop] continue=false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [public->outside_call] continue=true
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Absolute Condition [outside_call]
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action set(outside_call=true)
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [public->bbb_sp_call] continue=true
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (FAIL) [bbb_sp_call] network_addr(BBB_PUBLIC_IP) =~ /172.31.15.62/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [public->bbb_webrtc_call] continue=true
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [bbb_webrtc_call] ${sip_via_protocol}(wss) =~ /^wss?$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action set(bbb_authorized=true)
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action transfer(${destination_number} XML default)
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:286 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_ROUTING -> CS_EXECUTE
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State ROUTING going to sleep
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_EXECUTE (Cur 1 Tot 2)
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State EXECUTE
2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:198 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA EXECUTE
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:328 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard EXECUTE
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com set(outside_call=true)
2017-03-11 00:32:43.436588 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [outside_call]=[true]
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com export(RFC2822_DATE=Sat, 11 Mar 2017 00:32:43 +0000)

2017-03-11 00:32:43.436588 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Sat, 11 Mar 2017 00:32:43 +0000]

EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com set(bbb_authorized=true)
2017-03-11 00:32:43.436588 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [bbb_authorized]=[true]
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com transfer(10000000000036 XML default)
2017-03-11 00:32:43.436588 [DEBUG] switch_ivr.c:2160 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_EXECUTE -> CS_ROUTING
2017-03-11 00:32:43.436588 [NOTICE] switch_ivr.c:2167 Transfer sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com to XML[10000000000036@default]
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State EXECUTE going to sleep
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_ROUTING (Cur 1 Tot 2)
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State ROUTING
2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:143 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA ROUTING
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:236 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard ROUTING

2017-03-11 00:32:43.436588 [INFO] mod_dialplan_xml.c:637 Processing uftpxxxeg0c7_1-bbbID-MY_NAME <uftpxxxeg0c7_1-bbbID-MY_NAME>->10000000000036 in context default

Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [default->unloop] continue=false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [default->bbb_conferences] continue=false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [bbb_conferences] ${bbb_authorized}(true) =~ /true/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [bbb_conferences] destination_number(10000000000036) =~ /^(\d{5,20})$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action set(jitterbuffer_msec=20:400)
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action answer()
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action conference(10000000000036@cdquality)
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:286 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_ROUTING -> CS_EXECUTE
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State ROUTING going to sleep
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_EXECUTE (Cur 1 Tot 2)
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State EXECUTE
2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:198 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA EXECUTE
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:328 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard EXECUTE
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com set(jitterbuffer_msec=20:400)
2017-03-11 00:32:43.436588 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [jitterbuffer_msec]=[20:400]
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com answer()

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3047 Set Codec sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com opus/48000 20 ms 960 samples 0 bits 2 channels
2017-03-11 00:32:43.436588 [DEBUG] switch_core_codec.c:111 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Original read codec set to opus:116

2017-03-11 00:32:43.436588 [WARNING] switch_core_media.c:3425 NO candidate ACL defined, Defaulting to wan.auto
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: UDP type: host addr: 10.0.1.101:55070
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 2 proto: UDP type: host addr: 10.0.1.101:62023
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: UDP type: srflx addr: MY_PUBLIC_IP:55070
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 2 proto: UDP type: srflx addr: MY_PUBLIC_IP:62023
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3497 Searching for rtp candidate.
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3502 Choose rtp candidate, index 1, MY_PUBLIC_IP:55070

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3276 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com choosing family v4

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3513 Choose same candidate, index 2, for rtcp based on rtcp-mux attribute MY_PUBLIC_IP:55070
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3558 setting remote audio ice addr to index 1 MY_PUBLIC_IP:55070 based on candidate
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:3579 Setting remote rtcp audio addr to MY_PUBLIC_IP:55070 based on candidate

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:4718 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Set 2833 dtmf send payload to 101 recv payload to 101
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:6732 AUDIO RTP [sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com] 172.31.15.62 port 20594 -> MY_PUBLIC_IP port 55070 codec: 109 ms: 20

2017-03-11 00:32:43.436588 [DEBUG] switch_rtp.c:3878 Starting timer [soft] 960 bytes per 20ms
2017-03-11 00:32:43.436588 [INFO] switch_core_media.c:6914 Activating Audio ICE
2017-03-11 00:32:43.436588 [NOTICE] switch_rtp.c:4367 Activating RTP audio ICE: 778a6bef:pLatUwCKJpDnLYHo MY_PUBLIC_IP:55070
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:6957 Activating RTCP PORT 55070
2017-03-11 00:32:43.436588 [DEBUG] switch_rtp.c:4264 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 55070
2017-03-11 00:32:43.436588 [INFO] switch_core_media.c:6965 Skipping RTCP ICE (Same as RTP)
2017-03-11 00:32:43.436588 [INFO] switch_rtp.c:3371 Activate RTP/RTCP audio DTLS client
2017-03-11 00:32:43.436588 [INFO] switch_rtp.c:3505 Changing audio DTLS state from OFF to HANDSHAKE
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:2017 Setting Jitterbuffer to 20ms (1 frames) (20 max frames)

2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:7038 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Set 2833 dtmf send payload to 101
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:7045 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Set 2833 dtmf receive payload to 101
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:7068 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Set rtp dtmf delay to 40
2017-03-11 00:32:43.436588 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com!
2017-03-11 00:32:43.436588 [DEBUG] switch_channel.c:3473 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Callstate Change RINGING -> EARLY
2017-03-11 00:32:43.436588 [DEBUG] switch_core_media.c:6715 Audio params are unchanged for sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com.
2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com:

v=0
o=FreeSWITCH 1489171769 1489171770 IN IP4 BBB_PUBLIC_IP
s=FreeSWITCH
c=IN IP4 BBB_PUBLIC_IP
t=0 0
a=msid-semantic: WMS QpObJMGdVHrMYv9A0o5qejvi0mW2Nwvu
m=audio 20594 UDP/TLS/RTP/SAVPF 109 101
a=rtpmap:109 opus/48000/2
a=fmtp:109 useinbandfec=1; stereo=1
a=rtpmap:101 telephone-event/8000
a=ptime:20
a=sendrecv
a=fingerprint:sha-256 BD:69:8F:F2:86:19:DA:AC:6A:1B:97:8B:23:E5:2A:C4:76:44:89:67:39:5F:92:23:60:18:85:A9:DC:BA:85:11
a=setup:active
a=rtcp-mux
a=rtcp:20594 IN IP4 BBB_PUBLIC_IP
a=ice-ufrag:pLatUwCKJpDnLYHo
a=ice-pwd:Y4ABXQZnnZDg0j0fU1zFn2gW
a=candidate:6204423931 1 udp 659136 BBB_PUBLIC_IP 20594 typ host generation 0
a=end-of-candidates
a=ssrc:1758090875 cname:M9wlM2pxAHap3aPU
a=ssrc:1758090875 msid:QpObJMGdVHrMYv9A0o5qejvi0mW2Nwvu a0
a=ssrc:1758090875 mslabel:QpObJMGdVHrMYv9A0o5qejvi0mW2Nwvu
a=ssrc:1758090875 label:QpObJMGdVHrMYv9A0o5qejvi0mW2Nwvua0

2017-03-11 00:32:43.456580 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com entering state [completed][200]
2017-03-11 00:32:43.716578 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com entering state [ready][200]

2017-03-11 00:32:44.156577 [INFO] switch_rtp.c:3162 Changing audio DTLS state from HANDSHAKE to SETUP
2017-03-11 00:32:44.156577 [INFO] switch_rtp.c:3071 audio Fingerprint Verified.
2017-03-11 00:32:44.156577 [INFO] switch_rtp.c:3690 Activating Audio Secure RTP SEND
2017-03-11 00:32:44.156577 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80
2017-03-11 00:32:44.156577 [INFO] switch_rtp.c:3668 Activating Audio Secure RTP RECV
2017-03-11 00:32:44.156577 [INFO] switch_rtp.c:3111 Changing audio DTLS state from SETUP to READY
2017-03-11 00:32:44.156577 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80

2017-03-11 00:32:44.156577 [NOTICE] mod_dptools.c:1309 Channel [sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com] has been answered
2017-03-11 00:32:44.156577 [DEBUG] switch_channel.c:3772 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Callstate Change EARLY -> ACTIVE
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com conference(10000000000036@cdquality)

2017-03-11 00:32:44.156577 [DEBUG] mod_conference.c:3077 using channel sound prefix: /opt/freeswitch/share/freeswitch/sounds/en/us/callie
2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:1679 Raw Codec Activation Success L16@48000hz 2 channel 20ms
2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:1726 Raw Codec Activation Success L16@48000hz 1 channel 20ms

2017-03-11 00:32:44.156577 [DEBUG] switch_core_codec.c:223 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Push codec L16:100

2017-03-11 00:32:44.156577 [DEBUG] mod_conference.c:220 Setup timer success interval: 20 samples: 960

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '0' to 'mute'

2017-03-11 00:32:44.156577 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf'
2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 0/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c3c0

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '*' to 'deaf mute'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding */conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c3f0

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '9' to 'energy up'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 9/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c420

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '8' to 'energy equ'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 8/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c450

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '7' to 'energy dn'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 7/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c480

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '3' to 'vol talk up'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 3/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c4b0

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '2' to 'vol talk zero'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 2/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c4e0

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '1' to 'vol talk dn'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 1/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c510

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '6' to 'vol listen up'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 6/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c540

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '5' to 'vol listen zero'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 5/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c570

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '4' to 'vol listen dn'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 4/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c5a0

2017-03-11 00:32:44.156577 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '#' to 'hangup'

2017-03-11 00:32:44.156577 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding #/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007c5d0
2017-03-11 00:32:44.156577 [DEBUG] conference_loop.c:1140 Setup timer soft success interval: 20 samples: 960 from codec opus
2017-03-11 00:32:44.196560 [DEBUG] switch_rtp.c:1878 rtcp_stats_init: audio ssrc[3625017290] base_seq[4149]
2017-03-11 00:33:16.076569 [DEBUG] switch_core_media.c:2504 [VBR]: Correcting calculated ptime value from [40] to [20] to compensate for [1] lost packet(s)

========================================

In a couple of seconds BBB says I'm the only one at the conference. And the audio works perfect. I feel like I'm still not setting the correct parameters for the echo test and the conference to work.

I have tried several parameters of the freeswitch page.

https://freeswitch.org/confluence/display/FREESWITCH/Regular+Expression

In some cases the echo test works. But not the conference audio.

i test this solution with no success

https://github.com/instructure/canvas-lms/issues/478

and this one

https://groups.google.com/forum/#!topic/bigbluebutton-users/j1QLOAtLctg

any sugestions

best regards to all

--

You received this message because you are subscribed to a topic in the Google Groups "BigBlueButton-Setup" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/bigbluebutton-setup/-VKYEWlDgIM/unsubscribe.

To unsubscribe from this group and all its topics, send an email to bigbluebutton-setup+unsub...@googlegroups.com.
To post to this group, send email to bigbluebutton-setup@googlegroups.com.

Visit this group at https://groups.google.com/group/bigbluebutton-setup.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "BigBlueButton-Setup" group.
To unsubscribe from this group and stop receiving emails from it, send an email to bigbluebutton-setup+unsub...@googlegroups.com.
To post to this group, send email to bigbluebutton-setup@googlegroups.com.

Visit this group at https://groups.google.com/group/bigbluebutton-setup.
For more options, visit https://groups.google.com/d/optout.

BigBlueButton Developer

http://bigbluebutton.org/

@bigbluebutton

Emrah Emirtekin

unread,

Feb 21, 2018, 3:19:53 PM2/21/18

to BigBlueButton-Setup

Hi Fred,

I installed Canvas LMS latest stable version and then I enabled BBB plugin.

It works, but webRTC dosen't work correctly.

I am getting error "WebRTC issue: Error 1004:"

Same BBB server works successfully on sakai + webRTC.

I edited destination_number below files, canvas + webRTC work successfully, and then I noticed that sakai + webRTC don't work correctly.

/opt/freeswitch/conf/dialplan/default/bbb_conference.xml

/opt/freeswitch/conf/dialplan/default/bbb_echo_test.xml

...

Chad Pilkey

unread,

Feb 21, 2018, 4:19:41 PM2/21/18

to BigBlueButton-Setup

The default value for the destination_number uses "(\d{5,6}) which means look for a 5 to 6 digits. Changing the content of the curly braces to "{5,20}" should just expand the option to look for 5 to 20 digits. If it's set correctly it should work in both scenarios. Make sure you've set it to {5,20} and not just {20}.

Fred Dixon

unread,

Feb 21, 2018, 8:04:57 PM2/21/18

to bigbluebu...@googlegroups.com

Hi Emrah,

Also, can you test BigBlueButton with the built-in API examples (install bbb-demo) and see if you still get the error 1004.

Regards,... Fred

--

You received this message because you are subscribed to the Google Groups "BigBlueButton-Setup" group.
To unsubscribe from this group and stop receiving emails from it, send an email to bigbluebutton-setup+unsub...@googlegroups.com.
To post to this group, send email to bigbluebutton-setup@googlegroups.com.
Visit this group at https://groups.google.com/group/bigbluebutton-setup.
For more options, visit https://groups.google.com/d/optout.

eemirtekin

unread,

Feb 22, 2018, 3:48:54 AM2/22/18

to bigbluebu...@googlegroups.com

Hi Fred,

I am not getting this error with bbb-demo and sakai bbb-tool.

Our problem is canvas bbb-plugin.

When I create meeting on canvas, I am getting error code 1004.

I changed

and it works correctly.

And When I created a meeting on sakai server, we hear sound negative one?

Meanwhile, we use Sakai and Canvas as a lms at our university :)

Fix it like this:

2017-03-11 00:30:44.416507 [NOTICE] switch_channel.c:1104 New Channel sofia/external/uftpxxxeg0c7...@domain.com [08717b11-3e65-4392-abc3-e1427218d1bc]
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_NEW (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] sofia.c:9819 sofia/external/uftpxxxeg0c7...@domain.com receiving invite from BBB_PUBLIC_IP:40574 version: 1.6.15 git bec4538 2017-02-14 17:37:45Z 64bit

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:11131 Setting NAT mode based on websockets

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7...@domain.com entering state [received][100]

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:7444 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_NEW -> CS_INIT
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:603 (sofia/external/uftpxxxeg0c7...@domain.com) State NEW
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_INIT (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7...@domain.com) State INIT
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:90 sofia/external/uftpxxxeg0c7...@domain.com SOFIA INIT
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:40 sofia/external/uftpxxxeg0c7...@domain.com Standard INIT
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:48 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_INIT -> CS_ROUTING
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7...@domain.com) State INIT going to sleep
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_ROUTING (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_channel.c:2249 (sofia/external/uftpxxxeg0c7...@domain.com) Callstate Change DOWN -> RINGING
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7...@domain.com) State ROUTING
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:143 sofia/external/uftpxxxeg0c7...@domain.com SOFIA ROUTING
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:236 sofia/external/uftpxxxeg0c7...@domain.com Standard ROUTING

2017-03-11 00:30:44.416507 [INFO] mod_dialplan_xml.c:637 Processing uftpxxxeg0c7_1-bbbID-MY_NAME <uftpxxxeg0c7_1-bbbID-MY_NAME>->919610000000000036 in context public

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->unloop] continue=false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->outside_call] continue=true
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Absolute Condition [outside_call]
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action set(outside_call=true)
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->bbb_sp_call] continue=true
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (FAIL) [bbb_sp_call] network_addr(BBB_PUBLIC_IP) =~ /172.31.15.62/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->bbb_webrtc_call] continue=true
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [bbb_webrtc_call] ${sip_via_protocol}(wss) =~ /^wss?$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action set(bbb_authorized=true)
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action transfer(${destination_number} XML default)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:286 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_ROUTING -> CS_EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7...@domain.com) State ROUTING going to sleep
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_EXECUTE (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7...@domain.com) State EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:198 sofia/external/uftpxxxeg0c7...@domain.com SOFIA EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:328 sofia/external/uftpxxxeg0c7...@domain.com Standard EXECUTE
EXECUTE sofia/external/uftpxxxeg0c7...@domain.com set(outside_call=true)
2017-03-11 00:30:44.416507 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7...@domain.com [outside_call]=[true]

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com export(RFC2822_DATE=Sat, 11 Mar 2017 00:30:44 +0000)

2017-03-11 00:30:44.416507 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Sat, 11 Mar 2017 00:30:44 +0000]

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com set(bbb_authorized=true)
2017-03-11 00:30:44.416507 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7...@domain.com [bbb_authorized]=[true]

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com transfer(919610000000000036 XML default)
2017-03-11 00:30:44.416507 [DEBUG] switch_ivr.c:2160 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_EXECUTE -> CS_ROUTING
2017-03-11 00:30:44.416507 [NOTICE] switch_ivr.c:2167 Transfer sofia/external/uftpxxxeg0c7...@domain.com to XML[919610000000000036@default]
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7...@domain.com) State EXECUTE going to sleep
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_ROUTING (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7...@domain.com) State ROUTING
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:143 sofia/external/uftpxxxeg0c7...@domain.com SOFIA ROUTING
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:236 sofia/external/uftpxxxeg0c7...@domain.com Standard ROUTING

2017-03-11 00:30:44.416507 [INFO] mod_dialplan_xml.c:637 Processing uftpxxxeg0c7_1-bbbID-MY_NAME <uftpxxxeg0c7_1-bbbID-MY_NAME>->919610000000000036 in context default

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [default->unloop] continue=false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [default->bbb_conferences] continue=false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [bbb_conferences] ${bbb_authorized}(true) =~ /true/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [bbb_conferences] destination_number(919610000000000036) =~ /^(\d{5,20})$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action set(jitterbuffer_msec=20:400)
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action answer()

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Action conference(919610000000000036@cdquality)

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:286 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_ROUTING -> CS_EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7...@domain.com) State ROUTING going to sleep
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_EXECUTE (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7...@domain.com) State EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:198 sofia/external/uftpxxxeg0c7...@domain.com SOFIA EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:328 sofia/external/uftpxxxeg0c7...@domain.com Standard EXECUTE

EXECUTE sofia/external/uftpxxxeg0c7...@domain.com set(jitterbuffer_msec=20:400)
2017-03-11 00:30:44.416507 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7...@domain.com [jitterbuffer_msec]=[20:400]
EXECUTE sofia/external/uftpxxxeg0c7...@domain.com answer()

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3047 Set Codec sofia/external/uftpxxxeg0c7...@domain.com opus/48000 20 ms 960 samples 0 bits 2 channels
2017-03-11 00:30:44.416507 [DEBUG] switch_core_codec.c:111 sofia/external/uftpxxxeg0c7...@domain.com Original read codec set to opus:116

2017-03-11 00:30:44.416507 [WARNING] switch_core_media.c:3425 NO candidate ACL defined, Defaulting to wan.auto
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: UDP type: host addr: 10.0.1.101:49974
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 2 proto: UDP type: host addr: 10.0.1.101:64539
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: UDP type: srflx addr: MY_PUBLIC_IP:49974
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 2 proto: UDP type: srflx addr: MY_PUBLIC_IP:64539
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3497 Searching for rtp candidate.
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3502 Choose rtp candidate, index 1, MY_PUBLIC_IP:49974

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3276 sofia/external/uftpxxxeg0c7...@domain.com choosing family v4

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3513 Choose same candidate, index 2, for rtcp based on rtcp-mux attribute MY_PUBLIC_IP:49974
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3558 setting remote audio ice addr to index 1 MY_PUBLIC_IP:49974 based on candidate
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3579 Setting remote rtcp audio addr to MY_PUBLIC_IP:49974 based on candidate

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4718 sofia/external/uftpxxxeg0c7...@domain.com Set 2833 dtmf send payload to 101 recv payload to 101
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:6732 AUDIO RTP [sofia/external/uftpxxxeg0c7...@domain.com] 172.31.15.62 port 24192 -> MY_PUBLIC_IP port 49974 codec: 109 ms: 20

2017-03-11 00:30:44.416507 [DEBUG] switch_rtp.c:3878 Starting timer [soft] 960 bytes per 20ms
2017-03-11 00:30:44.416507 [INFO] switch_core_media.c:6914 Activating Audio ICE
2017-03-11 00:30:44.416507 [NOTICE] switch_rtp.c:4367 Activating RTP audio ICE: dfb58be6:fP6O7hhIYDR2hzV8 MY_PUBLIC_IP:49974
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:6957 Activating RTCP PORT 49974
2017-03-11 00:30:44.416507 [DEBUG] switch_rtp.c:4264 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 49974
2017-03-11 00:30:44.416507 [INFO] switch_core_media.c:6965 Skipping RTCP ICE (Same as RTP)
2017-03-11 00:30:44.416507 [INFO] switch_rtp.c:3371 Activate RTP/RTCP audio DTLS client
2017-03-11 00:30:44.416507 [INFO] switch_rtp.c:3505 Changing audio DTLS state from OFF to HANDSHAKE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:2017 Setting Jitterbuffer to 20ms (1 frames) (20 max frames)

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:7038 sofia/external/uftpxxxeg0c7...@domain.com Set 2833 dtmf send payload to 101
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:7045 sofia/external/uftpxxxeg0c7...@domain.com Set 2833 dtmf receive payload to 101
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:7068 sofia/external/uftpxxxeg0c7...@domain.com Set rtp dtmf delay to 40
2017-03-11 00:30:44.416507 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/uftpxxxeg0c7...@domain.com!
2017-03-11 00:30:44.416507 [DEBUG] switch_channel.c:3473 (sofia/external/uftpxxxeg0c7...@domain.com) Callstate Change RINGING -> EARLY
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:6715 Audio params are unchanged for sofia/external/uftpxxxeg0c7...@domain.com.
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/uftpxxxeg0c7...@domain.com:

v=0
o=FreeSWITCH 1489168052 1489168053 IN IP4 BBB_PUBLIC_IP
s=FreeSWITCH
c=IN IP4 BBB_PUBLIC_IP
t=0 0
a=msid-semantic: WMS ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3
m=audio 24192 UDP/TLS/RTP/SAVPF 109 101
a=rtpmap:109 opus/48000/2
a=fmtp:109 useinbandfec=1; stereo=1
a=rtpmap:101 telephone-event/8000
a=ptime:20
a=sendrecv
a=fingerprint:sha-256 BD:69:8F:F2:86:19:DA:AC:6A:1B:97:8B:23:E5:2A:C4:76:44:89:67:39:5F:92:23:60:18:85:A9:DC:BA:85:11
a=setup:active
a=rtcp-mux
a=rtcp:24192 IN IP4 BBB_PUBLIC_IP
a=ice-ufrag:fP6O7hhIYDR2hzV8
a=ice-pwd:yPolVyFtIH47UZYZEUEB2L9Q
a=candidate:6781037934 1 udp 659136 BBB_PUBLIC_IP 24192 typ host generation 0
a=end-of-candidates
a=ssrc:1757939060 cname:094pXfktHjcLzm40
a=ssrc:1757939060 msid:ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3 a0
a=ssrc:1757939060 mslabel:ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3
a=ssrc:1757939060 label:ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3a0

2017-03-11 00:30:44.436578 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7...@domain.com entering state [completed][200]
2017-03-11 00:30:44.616576 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7...@domain.com entering state [ready][200]

2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3162 Changing audio DTLS state from HANDSHAKE to SETUP
2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3071 audio Fingerprint Verified.
2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3690 Activating Audio Secure RTP SEND
2017-03-11 00:30:44.916591 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80
2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3668 Activating Audio Secure RTP RECV
2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3111 Changing audio DTLS state from SETUP to READY
2017-03-11 00:30:44.916591 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80

2017-03-11 00:30:44.916591 [NOTICE] mod_dptools.c:1309 Channel [sofia/external/uftpxxxeg0c7...@domain.com] has been answered
2017-03-11 00:30:44.916591 [DEBUG] switch_channel.c:3772 (sofia/external/uftpxxxeg0c7...@domain.com) Callstate Change EARLY -> ACTIVE
EXECUTE sofia/external/uftpxxxeg0c7...@domain.com conference(919610000000000036@cdquality)

2017-03-11 00:30:44.916591 [DEBUG] mod_conference.c:3077 using channel sound prefix: /opt/freeswitch/share/freeswitch/sounds/en/us/callie
2017-03-11 00:30:44.916591 [DEBUG] conference_member.c:1679 Raw Codec Activation Success L16@48000hz 2 channel 20ms
2017-03-11 00:30:44.916591 [DEBUG] conference_member.c:1726 Raw Codec Activation Success L16@48000hz 1 channel 20ms

2017-03-11 00:30:44.916591 [DEBUG] switch_core_codec.c:223 sofia/external/uftpxxxeg0c7...@domain.com Push codec L16:100

2017-03-11 00:30:44.916591 [DEBUG] mod_conference.c:220 Setup timer success interval: 20 samples: 960

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '0' to 'mute'

2017-03-11 00:30:44.936568 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf'
2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 0/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ece8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '*' to 'deaf mute'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding */conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ed18

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '9' to 'energy up'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 9/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ed48

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '8' to 'energy equ'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 8/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ed78

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '7' to 'energy dn'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 7/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007eda8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '3' to 'vol talk up'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 3/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007edd8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '2' to 'vol talk zero'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 2/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee08

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '1' to 'vol talk dn'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 1/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee38

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '6' to 'vol listen up'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 6/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee68

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '5' to 'vol listen zero'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 5/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee98

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '4' to 'vol listen dn'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 4/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007eec8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7...@domain.com binding '#' to 'hangup'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding #/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007eef8
2017-03-11 00:30:44.936568 [DEBUG] conference_loop.c:1140 Setup timer soft success interval: 20 samples: 960 from codec opus
2017-03-11 00:30:44.936568 [DEBUG] switch_rtp.c:1878 rtcp_stats_init: audio ssrc[597463825] base_seq[16029]

========================================

I dont hear nothing in the echo test

Click yes

Transferring… (in Voice: Negative 1)

and this is the debug file of that part of entering in the conference.

========================================

2017-03-11 00:32:37.156572 [INFO] switch_channel.c:515 RECV DTMF 1:800
2017-03-11 00:32:37.156572 [DEBUG] sofia.c:9547 INFO DTMF(1)
2017-03-11 00:32:37.156572 [DEBUG] conference_member.c:1411 Queueing file '/opt/freeswitch/share/freeswitch/sounds/en/us/callie/currency/negative.wav' for play
2017-03-11 00:32:37.156572 [DEBUG] conference_member.c:1411 Queueing file '/opt/freeswitch/share/freeswitch/sounds/en/us/callie/digits/1.wav' for play

2017-03-11 00:32:42.176578 [NOTICE] sofia.c:1012 Hangup sofia/external/uftpxxxeg0c7...@domain.com [CS_EXECUTE] [NORMAL_CLEARING]

2017-03-11 00:32:42.176578 [INFO] conference_loop.c:1455 Channel leaving conference, cause: NORMAL_CLEARING

2017-03-11 00:32:42.176578 [DEBUG] mod_conference.c:2259 sofia/external/uftpxxxeg0c7...@domain.com skip receive message [UNBRIDGE] (channel is hungup already)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_media.c:9643 sofia/external/uftpxxxeg0c7...@domain.com skip receive message [HARD_MUTE] (channel is hungup already)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_codec.c:248 sofia/external/uftpxxxeg0c7...@domain.com Restore previous codec opus:116.
2017-03-11 00:32:42.176578 [DEBUG] switch_core_session.c:2814 sofia/external/uftpxxxeg0c7...@domain.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7...@domain.com) State EXECUTE going to sleep
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_HANGUP (Cur 1 Tot 1)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:850 (sofia/external/uftpxxxeg0c7...@domain.com) Callstate Change ACTIVE -> HANGUP
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:852 (sofia/external/uftpxxxeg0c7...@domain.com) State HANGUP
2017-03-11 00:32:42.176578 [DEBUG] mod_sofia.c:438 Channel sofia/external/uftpxxxeg0c7...@domain.com hanging up, cause: NORMAL_CLEARING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:60 sofia/external/uftpxxxeg0c7...@domain.com Standard HANGUP, cause: NORMAL_CLEARING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:852 (sofia/external/uftpxxxeg0c7...@domain.com) State HANGUP going to sleep
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:619 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_HANGUP -> CS_REPORTING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_REPORTING (Cur 1 Tot 1)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:938 (sofia/external/uftpxxxeg0c7...@domain.com) State REPORTING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:174 sofia/external/uftpxxxeg0c7...@domain.com Standard REPORTING, cause: NORMAL_CLEARING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:938 (sofia/external/uftpxxxeg0c7...@domain.com) State REPORTING going to sleep
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:610 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_REPORTING -> CS_DESTROY
2017-03-11 00:32:42.176578 [DEBUG] switch_core_session.c:1664 Session 1 (sofia/external/uftpxxxeg0c7...@domain.com) Locked, Waiting on external entities
2017-03-11 00:32:42.176578 [NOTICE] switch_core_session.c:1682 Session 1 (sofia/external/uftpxxxeg0c7...@domain.com) Ended
2017-03-11 00:32:42.176578 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/uftpxxxeg0c7...@domain.com [CS_DESTROY]
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:741 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_DESTROY (Cur 0 Tot 1)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:751 (sofia/external/uftpxxxeg0c7...@domain.com) State DESTROY
2017-03-11 00:32:42.176578 [DEBUG] mod_sofia.c:343 sofia/external/uftpxxxeg0c7...@domain.com SOFIA DESTROY

2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:694 Opus decoder stats: Frames[5853] PLC[2] FEC[0]
2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:709 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] FEC frames (only for debug mode) [0]
2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:694 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:709 Opus encoder stats: Frames[5861] Bytes encoded[1385636] Encoded length ms[117220] Average encoded bitrate bps[94744] FEC frames (only for debug mode) [0]

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:181 sofia/external/uftpxxxeg0c7...@domain.com Standard DESTROY
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:751 (sofia/external/uftpxxxeg0c7...@domain.com) State DESTROY going to sleep

2017-03-11 00:32:42.176578 [DEBUG] mod_conference.c:822 Write Lock ON
2017-03-11 00:32:42.176578 [DEBUG] mod_conference.c:825 Write Lock OFF

2017-03-11 00:32:43.436588 [NOTICE] switch_channel.c:1104 New Channel sofia/external/uftpxxxeg0c7...@domain.com [4628b180-e34d-4b66-99e5-2f5506e0f0f6]
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_NEW (Cur 1 Tot 2)
2017-03-11 00:32:43.436588 [DEBUG] sofia.c:9819 sofia/external/uftpxxxeg0c7...@domain.com receiving invite from BBB_PUBLIC_IP:40580 version: 1.6.15 git bec4538 2017-02-14 17:37:45Z 64bit

2017-03-11 00:32:43.436588 [DEBUG] sofia.c:11131 Setting NAT mode based on websockets

2017-03-11 00:32:43.436588 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7...@domain.com entering state [received][100]

2017-03-11 00:32:43.436588 [DEBUG] sofia.c:7444 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_NEW -> CS_INIT
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:603 (sofia/external/uftpxxxeg0c7...@domain.com) State NEW
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_INIT (Cur 1 Tot 2)
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7...@domain.com) State INIT
2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:90 sofia/external/uftpxxxeg0c7...@domain.com SOFIA INIT
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:40 sofia/external/uftpxxxeg0c7...@domain.com Standard INIT
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:48 (sofia/external/uftpxxxeg0c7...@domain.com) State Change CS_INIT -> CS_ROUTING
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7...@domain.com) State INIT going to sleep
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7...@domain.com) Running State Change CS_ROUTING (Cur 1 Tot 2)
2017-03-11 00:32:43.436588 [DEBUG] switch_channel.c:2249 (sofia/external/uftpxxxeg0c7...@domain.com) Callstate Change DOWN -> RINGING
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7...@domain.com) State ROUTING
2017-03-11 00:32:43.436588 [DEBUG] mod_sofia.c:143 sofia/external/uftpxxxeg0c7...@domain.com SOFIA ROUTING
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:236 sofia/external/uftpxxxeg0c7...@domain.com Standard ROUTING

2017-03-11 00:32:43.436588 [INFO] mod_dialplan_xml.c:637 Processing uftpxxxeg0c7_1-bbbID-MY_NAME <uftpxxxeg0c7_1-bbbID-MY_NAME>->10000000000036 in context public

Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->unloop] continue=false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7...@domain.com parsing [public->outside_call] continue=true
Dialplan:
...

--
You received this message because you are subscribed to the Google Groups "BigBlueButton-Setup" group.

To unsubscribe from this group and stop receiving emails from it, send an email to bigbluebutton-s...@googlegroups.com.

To post to this group, send email to bigbluebu...@googlegroups.com.

Visit this group at https://groups.google.com/group/bigbluebutton-setup.
For more options, visit https://groups.google.com/d/optout.

--
BigBlueButton Developer
http://bigbluebutton.org/
@bigbluebutton

--

You received this message because you are subscribed to a topic in the Google Groups "BigBlueButton-Setup" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/bigbluebutton-setup/-VKYEWlDgIM/unsubscribe.

To unsubscribe from this group and all its topics, send an email to bigbluebutton-s...@googlegroups.com.
To post to this group, send email to bigbluebu...@googlegroups.com.

Chad Pilkey

unread,

Feb 22, 2018, 12:10:52 PM2/22/18

to BigBlueButton-Setup

When it's set to {5,20}, can you join the audio when using the demos?

Fix it like this:

2017-03-11 00:30:44.416507 [NOTICE] switch_channel.c:1104 New Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [08717b11-3e65-4392-abc3-e1427218d1bc]
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_NEW (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] sofia.c:9819 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com receiving invite from BBB_PUBLIC_IP:40574 version: 1.6.15 git bec4538 2017-02-14 17:37:45Z 64bit

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:11131 Setting NAT mode based on websockets

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com entering state [received][100]

2017-03-11 00:30:44.416507 [DEBUG] sofia.c:7444 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_NEW -> CS_INIT
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:603 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State NEW
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_INIT (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State INIT
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:90 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA INIT
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:40 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard INIT
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:48 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_INIT -> CS_ROUTING
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:627 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State INIT going to sleep
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_ROUTING (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_channel.c:2249 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Callstate Change DOWN -> RINGING
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State ROUTING
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:143 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA ROUTING
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:236 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard ROUTING

2017-03-11 00:30:44.416507 [INFO] mod_dialplan_xml.c:637 Processing uftpxxxeg0c7_1-bbbID-MY_NAME <uftpxxxeg0c7_1-bbbID-MY_NAME>->919610000000000036 in context public

Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [public->unloop] continue=false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [public->outside_call] continue=true
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Absolute Condition [outside_call]
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action set(outside_call=true)
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [public->bbb_sp_call] continue=true
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (FAIL) [bbb_sp_call] network_addr(BBB_PUBLIC_IP) =~ /172.31.15.62/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [public->bbb_webrtc_call] continue=true
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [bbb_webrtc_call] ${sip_via_protocol}(wss) =~ /^wss?$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action set(bbb_authorized=true)
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action transfer(${destination_number} XML default)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:286 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_ROUTING -> CS_EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State ROUTING going to sleep
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_EXECUTE (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:198 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:328 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard EXECUTE
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com set(outside_call=true)
2017-03-11 00:30:44.416507 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [outside_call]=[true]

EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com export(RFC2822_DATE=Sat, 11 Mar 2017 00:30:44 +0000)

2017-03-11 00:30:44.416507 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Sat, 11 Mar 2017 00:30:44 +0000]

EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com set(bbb_authorized=true)
2017-03-11 00:30:44.416507 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [bbb_authorized]=[true]

EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com transfer(919610000000000036 XML default)
2017-03-11 00:30:44.416507 [DEBUG] switch_ivr.c:2160 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_EXECUTE -> CS_ROUTING
2017-03-11 00:30:44.416507 [NOTICE] switch_ivr.c:2167 Transfer sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com to XML[919610000000000036@default]
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State EXECUTE going to sleep
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_ROUTING (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State ROUTING
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:143 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA ROUTING
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:236 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard ROUTING

2017-03-11 00:30:44.416507 [INFO] mod_dialplan_xml.c:637 Processing uftpxxxeg0c7_1-bbbID-MY_NAME <uftpxxxeg0c7_1-bbbID-MY_NAME>->919610000000000036 in context default

Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [default->unloop] continue=false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com parsing [default->bbb_conferences] continue=false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [bbb_conferences] ${bbb_authorized}(true) =~ /true/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Regex (PASS) [bbb_conferences] destination_number(919610000000000036) =~ /^(\d{5,20})$/ break=on-false
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action set(jitterbuffer_msec=20:400)
Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action answer()

Dialplan: sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Action conference(919610000000000036@cdquality)

2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:286 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_ROUTING -> CS_EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:643 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State ROUTING going to sleep
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_EXECUTE (Cur 1 Tot 1)
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:198 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA EXECUTE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_state_machine.c:328 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard EXECUTE

EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com set(jitterbuffer_msec=20:400)
2017-03-11 00:30:44.416507 [DEBUG] mod_dptools.c:1527 SET sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [jitterbuffer_msec]=[20:400]
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com answer()

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3047 Set Codec sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com opus/48000 20 ms 960 samples 0 bits 2 channels
2017-03-11 00:30:44.416507 [DEBUG] switch_core_codec.c:111 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Original read codec set to opus:116

2017-03-11 00:30:44.416507 [WARNING] switch_core_media.c:3425 NO candidate ACL defined, Defaulting to wan.auto
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: UDP type: host addr: 10.0.1.101:49974
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 2 proto: UDP type: host addr: 10.0.1.101:64539
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: UDP type: srflx addr: MY_PUBLIC_IP:49974
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 2 proto: UDP type: srflx addr: MY_PUBLIC_IP:64539
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3497 Searching for rtp candidate.
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3502 Choose rtp candidate, index 1, MY_PUBLIC_IP:49974

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3276 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com choosing family v4

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3513 Choose same candidate, index 2, for rtcp based on rtcp-mux attribute MY_PUBLIC_IP:49974
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3558 setting remote audio ice addr to index 1 MY_PUBLIC_IP:49974 based on candidate
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:3579 Setting remote rtcp audio addr to MY_PUBLIC_IP:49974 based on candidate

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:4718 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Set 2833 dtmf send payload to 101 recv payload to 101
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:6732 AUDIO RTP [sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com] 172.31.15.62 port 24192 -> MY_PUBLIC_IP port 49974 codec: 109 ms: 20

2017-03-11 00:30:44.416507 [DEBUG] switch_rtp.c:3878 Starting timer [soft] 960 bytes per 20ms
2017-03-11 00:30:44.416507 [INFO] switch_core_media.c:6914 Activating Audio ICE
2017-03-11 00:30:44.416507 [NOTICE] switch_rtp.c:4367 Activating RTP audio ICE: dfb58be6:fP6O7hhIYDR2hzV8 MY_PUBLIC_IP:49974
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:6957 Activating RTCP PORT 49974
2017-03-11 00:30:44.416507 [DEBUG] switch_rtp.c:4264 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 49974
2017-03-11 00:30:44.416507 [INFO] switch_core_media.c:6965 Skipping RTCP ICE (Same as RTP)
2017-03-11 00:30:44.416507 [INFO] switch_rtp.c:3371 Activate RTP/RTCP audio DTLS client
2017-03-11 00:30:44.416507 [INFO] switch_rtp.c:3505 Changing audio DTLS state from OFF to HANDSHAKE
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:2017 Setting Jitterbuffer to 20ms (1 frames) (20 max frames)

2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:7038 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Set 2833 dtmf send payload to 101
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:7045 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Set 2833 dtmf receive payload to 101
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:7068 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Set rtp dtmf delay to 40
2017-03-11 00:30:44.416507 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com!
2017-03-11 00:30:44.416507 [DEBUG] switch_channel.c:3473 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Callstate Change RINGING -> EARLY
2017-03-11 00:30:44.416507 [DEBUG] switch_core_media.c:6715 Audio params are unchanged for sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com.
2017-03-11 00:30:44.416507 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com:

v=0
o=FreeSWITCH 1489168052 1489168053 IN IP4 BBB_PUBLIC_IP
s=FreeSWITCH
c=IN IP4 BBB_PUBLIC_IP
t=0 0
a=msid-semantic: WMS ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3
m=audio 24192 UDP/TLS/RTP/SAVPF 109 101
a=rtpmap:109 opus/48000/2
a=fmtp:109 useinbandfec=1; stereo=1
a=rtpmap:101 telephone-event/8000
a=ptime:20
a=sendrecv
a=fingerprint:sha-256 BD:69:8F:F2:86:19:DA:AC:6A:1B:97:8B:23:E5:2A:C4:76:44:89:67:39:5F:92:23:60:18:85:A9:DC:BA:85:11
a=setup:active
a=rtcp-mux
a=rtcp:24192 IN IP4 BBB_PUBLIC_IP
a=ice-ufrag:fP6O7hhIYDR2hzV8
a=ice-pwd:yPolVyFtIH47UZYZEUEB2L9Q
a=candidate:6781037934 1 udp 659136 BBB_PUBLIC_IP 24192 typ host generation 0
a=end-of-candidates
a=ssrc:1757939060 cname:094pXfktHjcLzm40
a=ssrc:1757939060 msid:ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3 a0
a=ssrc:1757939060 mslabel:ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3
a=ssrc:1757939060 label:ZmrbyYl4FB9SdpktB3VfIrkCKQwjdOR3a0

2017-03-11 00:30:44.436578 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com entering state [completed][200]
2017-03-11 00:30:44.616576 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com entering state [ready][200]

2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3162 Changing audio DTLS state from HANDSHAKE to SETUP
2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3071 audio Fingerprint Verified.
2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3690 Activating Audio Secure RTP SEND
2017-03-11 00:30:44.916591 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80
2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3668 Activating Audio Secure RTP RECV
2017-03-11 00:30:44.916591 [INFO] switch_rtp.c:3111 Changing audio DTLS state from SETUP to READY
2017-03-11 00:30:44.916591 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80

2017-03-11 00:30:44.916591 [NOTICE] mod_dptools.c:1309 Channel [sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com] has been answered
2017-03-11 00:30:44.916591 [DEBUG] switch_channel.c:3772 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Callstate Change EARLY -> ACTIVE
EXECUTE sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com conference(919610000000000036@cdquality)

2017-03-11 00:30:44.916591 [DEBUG] mod_conference.c:3077 using channel sound prefix: /opt/freeswitch/share/freeswitch/sounds/en/us/callie
2017-03-11 00:30:44.916591 [DEBUG] conference_member.c:1679 Raw Codec Activation Success L16@48000hz 2 channel 20ms
2017-03-11 00:30:44.916591 [DEBUG] conference_member.c:1726 Raw Codec Activation Success L16@48000hz 1 channel 20ms

2017-03-11 00:30:44.916591 [DEBUG] switch_core_codec.c:223 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Push codec L16:100

2017-03-11 00:30:44.916591 [DEBUG] mod_conference.c:220 Setup timer success interval: 20 samples: 960

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '0' to 'mute'

2017-03-11 00:30:44.936568 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf'
2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 0/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ece8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '*' to 'deaf mute'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding */conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ed18

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '9' to 'energy up'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 9/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ed48

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '8' to 'energy equ'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 8/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ed78

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '7' to 'energy dn'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 7/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007eda8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '3' to 'vol talk up'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 3/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007edd8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '2' to 'vol talk zero'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 2/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee08

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '1' to 'vol talk dn'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 1/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee38

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '6' to 'vol listen up'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 6/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee68

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '5' to 'vol listen zero'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 5/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007ee98

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '4' to 'vol listen dn'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 4/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007eec8

2017-03-11 00:30:44.936568 [DEBUG] conference_member.c:128 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com binding '#' to 'hangup'

2017-03-11 00:30:44.936568 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding #/conf/0 callback: 0x7f9c2860ff10 data: 0x7f9c2007eef8
2017-03-11 00:30:44.936568 [DEBUG] conference_loop.c:1140 Setup timer soft success interval: 20 samples: 960 from codec opus
2017-03-11 00:30:44.936568 [DEBUG] switch_rtp.c:1878 rtcp_stats_init: audio ssrc[597463825] base_seq[16029]

========================================

I dont hear nothing in the echo test

Click yes

Transferring… (in Voice: Negative 1)

and this is the debug file of that part of entering in the conference.

========================================

2017-03-11 00:32:37.156572 [INFO] switch_channel.c:515 RECV DTMF 1:800
2017-03-11 00:32:37.156572 [DEBUG] sofia.c:9547 INFO DTMF(1)
2017-03-11 00:32:37.156572 [DEBUG] conference_member.c:1411 Queueing file '/opt/freeswitch/share/freeswitch/sounds/en/us/callie/currency/negative.wav' for play
2017-03-11 00:32:37.156572 [DEBUG] conference_member.c:1411 Queueing file '/opt/freeswitch/share/freeswitch/sounds/en/us/callie/digits/1.wav' for play

2017-03-11 00:32:42.176578 [NOTICE] sofia.c:1012 Hangup sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [CS_EXECUTE] [NORMAL_CLEARING]

2017-03-11 00:32:42.176578 [INFO] conference_loop.c:1455 Channel leaving conference, cause: NORMAL_CLEARING

2017-03-11 00:32:42.176578 [DEBUG] mod_conference.c:2259 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com skip receive message [UNBRIDGE] (channel is hungup already)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_media.c:9643 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com skip receive message [HARD_MUTE] (channel is hungup already)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_codec.c:248 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Restore previous codec opus:116.
2017-03-11 00:32:42.176578 [DEBUG] switch_core_session.c:2814 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:650 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State EXECUTE going to sleep
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_HANGUP (Cur 1 Tot 1)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:850 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Callstate Change ACTIVE -> HANGUP
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:852 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State HANGUP
2017-03-11 00:32:42.176578 [DEBUG] mod_sofia.c:438 Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com hanging up, cause: NORMAL_CLEARING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:60 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard HANGUP, cause: NORMAL_CLEARING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:852 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State HANGUP going to sleep
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:619 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_HANGUP -> CS_REPORTING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_REPORTING (Cur 1 Tot 1)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:938 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State REPORTING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:174 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard REPORTING, cause: NORMAL_CLEARING
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:938 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State REPORTING going to sleep
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:610 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State Change CS_REPORTING -> CS_DESTROY
2017-03-11 00:32:42.176578 [DEBUG] switch_core_session.c:1664 Session 1 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Locked, Waiting on external entities
2017-03-11 00:32:42.176578 [NOTICE] switch_core_session.c:1682 Session 1 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Ended
2017-03-11 00:32:42.176578 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [CS_DESTROY]
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:741 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_DESTROY (Cur 0 Tot 1)
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:751 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State DESTROY
2017-03-11 00:32:42.176578 [DEBUG] mod_sofia.c:343 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com SOFIA DESTROY

2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:694 Opus decoder stats: Frames[5853] PLC[2] FEC[0]
2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:709 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] FEC frames (only for debug mode) [0]
2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:694 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2017-03-11 00:32:42.176578 [DEBUG] mod_opus.c:709 Opus encoder stats: Frames[5861] Bytes encoded[1385636] Encoded length ms[117220] Average encoded bitrate bps[94744] FEC frames (only for debug mode) [0]

2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:181 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com Standard DESTROY
2017-03-11 00:32:42.176578 [DEBUG] switch_core_state_machine.c:751 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) State DESTROY going to sleep

2017-03-11 00:32:42.176578 [DEBUG] mod_conference.c:822 Write Lock ON
2017-03-11 00:32:42.176578 [DEBUG] mod_conference.c:825 Write Lock OFF

2017-03-11 00:32:43.436588 [NOTICE] switch_channel.c:1104 New Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com [4628b180-e34d-4b66-99e5-2f5506e0f0f6]
2017-03-11 00:32:43.436588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/uftpxxxeg0c7_1-bbbI...@domain.com) Running State Change CS_NEW (Cur 1 Tot 2)
2017-03-11 00:32:43.436588 [DEBUG] sofia.c:9819 sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com receiving invite from BBB_PUBLIC_IP:40580 version: 1.6.15 git bec4538 2017-02-14 17:37:45Z 64bit

2017-03-11 00:32:43.436588 [DEBUG] sofia.c:11131 Setting NAT mode based on websockets

2017-03-11 00:32:43.436588 [DEBUG] sofia.c:7042 Channel sofia/external/uftpxxxeg0c7_1-bbbID...@domain.com entering state [received][100]

...

eemirtekin

unread,

Feb 22, 2018, 12:12:24 PM2/22/18

to bigbluebu...@googlegroups.com

Yes

--

You received this message because you are subscribed to a topic in the Google Groups "BigBlueButton-Setup" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/bigbluebutton-setup/-VKYEWlDgIM/unsubscribe.

To unsubscribe from this group and all its topics, send an email to bigbluebutton-setup+unsub...@googlegroups.com.
To post to this group, send email to bigbluebutton-setup@googlegroups.com.

Chad Pilkey

unread,

Feb 22, 2018, 12:19:58 PM2/22/18

to BigBlueButton-Setup

That's very strange. Canvas and the demos work, but Sakai doesn't.

I wonder what voiceBridge Sakai uses. Can you start a meeting from Sakai and open the browser developer tools (F12), switch to the Network tab. Look for a request to /enter and find the response for that. There should be one property that is "voicebridge". Can you tell me the value please. If the Network tab is empty you'll need to reload the page and then look for the /enter request.