[Freeswitch-users] Conference Dial In Isn't Working (mod_conference)

Jan Riedinger riedinger at sns.eu
Sat Apr 3 08:14:59 PDT 2010 

If I dial in to a conference from my Cisco IP Phone 7940 all is working 
as it should.

However, if I dial in via a voip carrier, the calls are disconnect with 
disconnect cause "facility rejected" by the voip carrier. It seems that 
Freeswitch tries to change some parameters of the call setup, which is 
refused. You find below the console log output. Do you have an idea, 
what I have to change to get it working?

I know that it is working in prinicple, because I can setup outgoing 
conferences via the voip carrier.

Thank you very much in advance
     Jan



=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2010.04.03 16:56:10 
=~=~=~=~=~=~=~=~=~=~=~=
2010-04-03 16:56:07.593334 [NOTICE] switch_channel.c:669 New 
Channel sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 
[27446b50-dc2a-4088-83f2-7b7cc8f014e8]
2010-04-03 16:56:07.593334 [DEBUG] sofia.c:4153 Channel 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 entering state [received][100]
2010-04-03 16:56:07.593334 [DEBUG] sofia.c:4164 Remote SDP:
v=0

o=- 1270306567 1270306567 IN IP4 XXX.XX.XX.X6

s=-

c=IN IP4 XXX.XX.XX.X6

t=0 0

m=audio 19188 RTP/AVP 18 4 8 0 101

a=rtpmap:18 G729/8000

a=rtpmap:4 G723/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15


2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [G729:18:8000:20]/[G7221:115:32000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [G729:18:8000:20]/[G7221:107:16000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [G729:18:8000:20]/[G722:9:8000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [G729:18:8000:20]/[PCMU:0:8000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [G729:18:8000:20]/[PCMA:8:8000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [G729:18:8000:20]/[GSM:3:8000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [G723:4:8000:20]/[G7221:115:32000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [G723:4:8000:20]/[G7221:107:16000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [G723:4:8000:20]/[G722:9:8000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [G723:4:8000:20]/[PCMU:0:8000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [G723:4:8000:20]/[PCMA:8:8000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [G723:4:8000:20]/[GSM:3:8000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [PCMA:8:8000:20]/[G7221:115:32000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [PCMA:8:8000:20]/[G7221:107:16000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [PCMA:8:8000:20]/[G722:9:8000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [PCMA:8:8000:20]/[PCMU:0:8000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3585 Audio Codec 
Compare [PCMA:8:8000:20]/[PCMA:8:8000:20]
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:2354 Set Codec 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 PCMA/8000 20 ms 160 samples
2010-04-03 16:56:07.593334 [DEBUG] sofia_glue.c:3524 Set 2833 
dtmf send/recv payload to 101
2010-04-03 16:56:07.593334 [DEBUG] sofia.c:4310 
(sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) State Change CS_NEW -> CS_INIT
2010-04-03 16:56:07.593334 [DEBUG] switch_core_session.c:1018 
Send signal sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 [BREAK]
2010-04-03 16:56:07.593334 [DEBUG] 
switch_core_state_machine.c:314 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
Running State Change CS_INIT
2010-04-03 16:56:07.593334 [DEBUG] 
switch_core_state_machine.c:338 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State INIT
2010-04-03 16:56:07.593334 [DEBUG] mod_sofia.c:83 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 SOFIA INIT
2010-04-03 16:56:07.593334 [DEBUG] mod_sofia.c:117 
(sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) State Change CS_INIT -> CS_ROUTING
2010-04-03 16:56:07.593334 [DEBUG] switch_core_session.c:1018 
Send signal sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 [BREAK]
2010-04-03 16:56:07.593334 [DEBUG] 
switch_core_state_machine.c:338 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State INIT going to sleep
2010-04-03 16:56:07.593334 [DEBUG] 
switch_core_state_machine.c:314 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
Running State Change CS_ROUTING
2010-04-03 16:56:07.593334 [DEBUG] 
switch_core_state_machine.c:341 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State ROUTING
2010-04-03 16:56:07.593334 [DEBUG] mod_sofia.c:140 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 SOFIA ROUTING
2010-04-03 16:56:07.593334 [DEBUG] 
switch_core_state_machine.c:77 sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 
Standard ROUTING
2010-04-03 16:56:07.593334 [INFO] mod_dialplan_xml.c:418 
Processing 49XXXXXXX6->49331YYYYYY in context public
Dialplan: sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 parsing 
[public->unloop] continue=false
Dialplan: sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 Regex (PASS) 
[unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 Regex (FAIL) 
[unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 parsing 
[public->outside_call] continue=true
Dialplan: sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 Absolute 
Condition [outside_call]
Dialplan: sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 Action 
set(outside_call=true)
Dialplan: sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 parsing 
[public->call_debug] continue=true
Dialplan: sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 Regex (FAIL) 
[call_debug] ${call_debug}(false) =~ /^true$/ break=never
...
Dialplan: sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 parsing 
[public->sns_conference] continue=false
Dialplan: sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 Regex (PASS) 
[sns_conference] destination_number(49331YYYYYY) =~ /^(49331YYYYYY)$/ 
break=on-false
Dialplan: sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 Action answer()
Dialplan: sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 Action 
set(conference_enforce_security=false)
Dialplan: sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 Action 
conference(49331YYYYYY-${domain_name}@default)
2010-04-03 16:56:07.596335 [DEBUG] 
switch_core_state_machine.c:119 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State Change CS_ROUTING -> CS_EXECUTE
2010-04-03 16:56:07.596335 [DEBUG] switch_core_session.c:1018 
Send signal sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 [BREAK]
2010-04-03 16:56:07.596335 [DEBUG] 
switch_core_state_machine.c:341 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State ROUTING going to sleep
2010-04-03 16:56:07.596335 [DEBUG] 
switch_core_state_machine.c:314 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
Running State Change CS_EXECUTE
2010-04-03 16:56:07.596335 [DEBUG] 
switch_core_state_machine.c:348 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State EXECUTE
2010-04-03 16:56:07.596335 [DEBUG] mod_sofia.c:226 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 SOFIA EXECUTE
2010-04-03 16:56:07.596335 [DEBUG] 
switch_core_state_machine.c:157 sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 
Standard EXECUTE
EXECUTE sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 
set(outside_call=true)
2010-04-03 16:56:07.596335 [DEBUG] mod_dptools.c:816 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 SET [outside_call]=[true]
EXECUTE sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 answer()
2010-04-03 16:56:07.596335 [DEBUG] sofia_glue.c:2594 AUDIO RTP 
[sofia/external/49XXXXXXX6 at XXX.XX.XX.X6] XXX.XX.XX.X7 port 17138 -> 
XXX.XX.XX.X6 port 19188 codec: 8 ms: 20
2010-04-03 16:56:07.596335 [DEBUG] switch_rtp.c:1182 Starting 
timer [soft] 160 bytes per 20ms
2010-04-03 16:56:07.599335 [DEBUG] sofia_glue.c:2774 Set 2833 
dtmf send payload to 101
2010-04-03 16:56:07.599335 [DEBUG] sofia_glue.c:2779 Set 2833 
dtmf receive payload to 101
2010-04-03 16:56:07.599335 [DEBUG] mod_sofia.c:636 Local SDP 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6:
v=0
o=FreeSWITCH 1270289429 1270289430 IN IP4 XXX.XX.XX.X7
s=FreeSWITCH
c=IN IP4 XXX.XX.XX.X7
t=0 0
m=audio 17138 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

2010-04-03 16:56:07.599335 [DEBUG] sofia.c:4153 Channel 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 entering state [completed][200]
2010-04-03 16:56:07.599335 [DEBUG] switch_core_session.c:638 
Send signal sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 [BREAK]
2010-04-03 16:56:07.599335 [NOTICE] mod_dptools.c:719 Channel 
[sofia/external/49XXXXXXX6 at XXX.XX.XX.X6] has been answered
EXECUTE sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 
set(conference_enforce_security=false)
2010-04-03 16:56:07.599335 [DEBUG] mod_dptools.c:816 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 SET 
[conference_enforce_security]=[false]
EXECUTE sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 
conference(49331YYYYYY-XXX.XX.XX.X7 at default)
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:5671 
Installing default caller control action 'mute' bound to '0'.
2010-04-03 16:56:07.599335 [DEBUG] switch_ivr.c:1616 max len 1
2010-04-03 16:56:07.599335 [DEBUG] switch_ivr.c:1620 min len 1
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:5671 
Installing default caller control action 'deaf mute' bound to '*'.
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:5671 
Installing default caller control action 'energy up' bound to '9'.
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:5671 
Installing default caller control action 'energy equ' bound to '8'.
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:5671 
Installing default caller control action 'energy dn' bound to '7'.
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:5671 
Installing default caller control action 'vol talk up' bound to '3'.
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:5671 
Installing default caller control action 'vol talk zero' bound to '2'.
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:5671 
Installing default caller control action 'vol talk dn' bound to '1'.
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:5671 
Installing default caller control action 'vol listen up' bound to '6'.
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:5671 
Installing default caller control action 'vol listen zero' bound to '5'.
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:5671 
Installing default caller control action 'vol listen dn' bound to '4'.
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:5671 
Installing default caller control action 'hangup' bound to '#'.
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:4990 Raw 
Codec Activation Success L16 at 8000hz 1 channel 20ms
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:5035 Raw 
Codec Activation Success L16 at 8000hz 1 channel 20ms
2010-04-03 16:56:07.599335 [DEBUG] switch_core_codec.c:122 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 Push codec L16:10
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:994 Setup 
timer success interval: 20  samples: 160
2010-04-03 16:56:07.599335 [DEBUG] switch_core_session.c:638 
Send signal sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 [BREAK]
2010-04-03 16:56:07.599335 [DEBUG] mod_conference.c:2202 Setup 
timer soft success interval: 20  samples: 160
2010-04-03 16:56:07.617340 [DEBUG] sofia.c:4153 Channel 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 entering state [ready][200]
2010-04-03 16:56:07.839332 [NOTICE] sofia.c:481 Hangup 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 [CS_EXECUTE] [FACILITY_REJECTED]
2010-04-03 16:56:07.839332 [DEBUG] switch_channel.c:2071 Send 
signal sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 [KILL]
2010-04-03 16:56:07.839332 [DEBUG] switch_core_session.c:1018 
Send signal sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 [BREAK]
2010-04-03 16:56:07.848341 [DEBUG] mod_conference.c:2473 Channel 
leaving conference, cause: FACILITY_REJECTED
2010-04-03 16:56:07.851332 [DEBUG] switch_core_codec.c:146 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 Restore previous codec PCMA:8.
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:348 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State EXECUTE going to sleep
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:314 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
Running State Change CS_HANGUP
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:499 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State HANGUP
2010-04-03 16:56:07.851332 [DEBUG] mod_sofia.c:408 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 Overriding SIP cause 501 with 200 
from the other leg
2010-04-03 16:56:07.851332 [DEBUG] mod_sofia.c:414 Channel 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 hanging up, cause: FACILITY_REJECTED
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:46 sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 
Standard HANGUP, cause: FACILITY_REJECTED
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:499 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State HANGUP going to sleep
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:333 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State Change CS_HANGUP -> CS_REPORTING
2010-04-03 16:56:07.851332 [DEBUG] switch_core_session.c:1018 
Send signal sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 [BREAK]
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:314 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
Running State Change CS_REPORTING
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:590 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State REPORTING
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:53 sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 
Standard REPORTING, cause: FACILITY_REJECTED
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:590 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State REPORTING going to sleep
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:327 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State Change CS_REPORTING -> CS_DESTROY
2010-04-03 16:56:07.851332 [DEBUG] switch_core_session.c:1018 
Send signal sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 [BREAK]
2010-04-03 16:56:07.851332 [DEBUG] switch_core_session.c:1161 
Session 7 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) Locked, Waiting on 
external entities
2010-04-03 16:56:07.851332 [NOTICE] switch_core_session.c:1179 
Session 7 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) Ended
2010-04-03 16:56:07.851332 [NOTICE] switch_core_session.c:1181 
Close Channel sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 [CS_DESTROY]
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:428 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
Running State Change CS_DESTROY
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:439 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State DESTROY
2010-04-03 16:56:07.851332 [DEBUG] mod_sofia.c:341 
sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 SOFIA DESTROY
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:60 sofia/external/49XXXXXXX6 at XXX.XX.XX.X6 
Standard DESTROY
2010-04-03 16:56:07.851332 [DEBUG] 
switch_core_state_machine.c:439 (sofia/external/49XXXXXXX6 at XXX.XX.XX.X6) 
State DESTROY going to sleep
2010-04-03 16:56:07.866331 [DEBUG] mod_conference.c:1361 Write 
Lock ON
2010-04-03 16:56:07.866331 [DEBUG] mod_conference.c:1364 Write 
Lock OFF


-- 
Jan Riedinger                           Phone :  +49-30-39 73 19 66
Dipl.-Inf. | Managing Director          Fax   :  +49-30-39 73 19 64
                                        E-Mail:  riedinger at sns.eu
SNS Consult GmbH                        ICQ   :  163-237-041
Südwestkorso 49a                        MSN   :  jan at sns-consult.de
14197 Berlin GERMANY                    Skype :  Jan Riedinger

AG Charlottenburg - HRB 71973

More information about the FreeSWITCH-users mailing list