[Freeswitch-users] FreeSWITCH-users Digest, Vol 40, Issue 129

Wed Oct 14 16:31:43 PDT 2009

Hello, a few weeks ago I asked about a setup, and about using the 
freeswitch package on pfSense. Since then I have received most of my 
hardware and started setting up freeswitch.

First my setup
WWW --> 1st pfsense box <-- private (192.168.2.xxx) --> pfsense w 
freeswtich <-- Test (192.168.3.xxx) --> phones

pfsense w freeswtich Port Addresses
WAN 192.168.2.210
LAN 192.168.3.1

this is setup to simulate a pfsense box hooked up to an external network.

here are the things I have done.

1st attempt
#1 set my WAN IP port to fixed in pfsense (192.168.2.210)
#2 set my soft phone to register to 192.168.2.210 (The phones registered 
and showed up in the status section)
#3 Tried to make a call to extension 1004, the soft phone tells me that 
it is "Temporally Unavailable 480).

2nd attempt
#1 set my WAN IP port to fixed in pfsense (192.168.2.210)
#2 deleted the lan.xml profile
#3 rebooted freeswitch.
#4 set my soft phone to register to 192.168.2.210 (The phones registered 
and showed up in the status section)
#5 Tried to make a call to extension 1004, the soft phone tells me that 
it is "Temporally Unavailable 480).

3rd attempt
#1 set my WAN IP port to fixed in pfsense (192.168.2.210)
#2 edited the internal.xml file as described in the multi-home tutorial 
(192.168.3.1 is my phone lan address)
    <param name="rtp-ip" value="192.168.3.1"/>
    <param name="sip-ip" value="192.168.3.1"/>
    <param name="ext-rtp-ip" value="192.168.3.1"/>
    <param name="ext-sip-ip" value="192.168.3.1"/>
#3 rebooted freeswitch.
#4 set my soft phone to register to 192.168.2.210 (The phone would not 
register)
#5 set my soft phone to register to 192.168.3.1 (The phone registered 
and showed up in the status section)
#6 Tried to make a call to extension 1004, the soft phone tells me that 
it is "Temporally Unavailable 480).
#7 edited the file /usr/local/freeswitch/conf/directory/default.xml
  <domain name="192.168.3.1">
#8 rebooted freeswitch.
#9 set my soft phone to register to 192.168.2.210 (The phone would not 
register)
#10 set my soft phone to register to 192.168.3.1 (The phone would not 
register got a forbidden error)
#11 did some reading and found a place in the vars tab to change the domain
#12 edited the file in the vars tab
  <X-PRE-PROCESS cmd="set" data="domain=192.168.3.1"/>
#13 rebooted freeswitch.
#14 set my soft phone to register to 192.168.2.210 (The phone would not 
register)
#15 set my soft phone to register to 192.168.3.1 (The phone registered 
and showed up in the status section)
#16 Tried to make a call to extension 1004, the soft phone tells me that 
it is "Temporally Unavailable 480).

here is part of the log file:
2009-10-14 22:18:43.560147 [DEBUG] sofia.c:910 Write lock lan
2009-10-14 22:18:43.563938 [NOTICE] sofia.c:917 Waiting for worker thread
2009-10-14 22:18:43.563938 [DEBUG] sofia.c:975 Write unlock lan
2009-10-14 22:26:00.23234 [DEBUG] sofia.c:4549 IP 192.168.3.199 Rejected 
by acl "domains". Falling back to Digest auth.
2009-10-14 22:26:00.55225 [DEBUG] sofia.c:4549 IP 192.168.3.199 Rejected 
by acl "domains". Falling back to Digest auth.
2009-10-14 22:26:00.55225 [NOTICE] switch_channel.c:602 New Channel 
sofia/internal/1001 at 192.168.2.210 [8aa7cd8c-10b9-de11-a0e9-00a0cc5a11e3]
2009-10-14 22:26:00.55225 [DEBUG] sofia.c:5196 Setting NAT mode based on 
rfc1918.auto
2009-10-14 22:26:00.55225 [DEBUG] sofia.c:3210 Channel 
sofia/internal/1001 at 192.168.2.210 entering state [received][100]
2009-10-14 22:26:00.55225 [DEBUG] sofia.c:3217 Remote SDP:
v=0
o=- 78902911 78902911 IN IP4 192.168.189.1
s=http://www.portsip.com
c=IN IP4 192.168.189.1
t=0 0
m=audio 21328 RTP/AVP 0 8 18 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
m=video 40216 RTP/AVP 34 125
a=rtpmap:34 H263/90000
a=fmtp:34 CIF=2
a=rtpmap:125 H264/90000
a=fmtp:125 profile-level-id=42e015

2009-10-14 22:26:00.55225 [DEBUG] sofia_glue.c:3081 Audio Codec Compare 
[PCMU:0:8000:20]/[G7221:115:32000:20]
2009-10-14 22:26:00.55225 [DEBUG] sofia_glue.c:3081 Audio Codec Compare 
[PCMU:0:8000:20]/[G7221:107:16000:20]
2009-10-14 22:26:00.55225 [DEBUG] sofia_glue.c:3081 Audio Codec Compare 
[PCMU:0:8000:20]/[G722:9:8000:20]
2009-10-14 22:26:00.55225 [DEBUG] sofia_glue.c:3081 Audio Codec Compare 
[PCMU:0:8000:20]/[PCMU:0:8000:20]
2009-10-14 22:26:00.55225 [DEBUG] sofia_glue.c:2039 Set Codec 
sofia/internal/1001 at 192.168.2.210 PCMU/8000 20 ms 160 samples
2009-10-14 22:26:00.55225 [DEBUG] sofia_glue.c:3041 Set 2833 dtmf 
payload to 101
2009-10-14 22:26:00.55225 [DEBUG] sofia.c:3376 
(sofia/internal/1001 at 192.168.2.210) State Change CS_NEW -> CS_INIT
2009-10-14 22:26:00.55225 [DEBUG] switch_core_session.c:933 Send signal 
sofia/internal/1001 at 192.168.2.210 [BREAK]
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:397 
(sofia/internal/1001 at 192.168.2.210) Running State Change CS_INIT
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:480 
(sofia/internal/1001 at 192.168.2.210) State INIT
2009-10-14 22:26:00.63551 [DEBUG] mod_sofia.c:83 
sofia/internal/1001 at 192.168.2.210 SOFIA INIT
2009-10-14 22:26:00.63551 [DEBUG] mod_sofia.c:111 
(sofia/internal/1001 at 192.168.2.210) State Change CS_INIT -> CS_ROUTING
2009-10-14 22:26:00.63551 [DEBUG] switch_core_session.c:933 Send signal 
sofia/internal/1001 at 192.168.2.210 [BREAK]
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:480 
(sofia/internal/1001 at 192.168.2.210) State INIT going to sleep
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:397 
(sofia/internal/1001 at 192.168.2.210) Running State Change CS_ROUTING
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:483 
(sofia/internal/1001 at 192.168.2.210) State ROUTING
2009-10-14 22:26:00.63551 [DEBUG] mod_sofia.c:130 
sofia/internal/1001 at 192.168.2.210 SOFIA ROUTING
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:78 
sofia/internal/1001 at 192.168.2.210 Standard ROUTING
2009-10-14 22:26:00.63551 [INFO] mod_dialplan_xml.c:252 Processing 
1001->1004 in context public
Dialplan: sofia/internal/1001 at 192.168.2.210 parsing [public->unloop] 
continue=false
Dialplan: sofia/internal/1001 at 192.168.2.210 Regex (PASS) [unloop] 
${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001 at 192.168.2.210 Regex (FAIL) [unloop] 
${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001 at 192.168.2.210 parsing 
[public->outside_call] continue=true
Dialplan: sofia/internal/1001 at 192.168.2.210 Absolute Condition 
[outside_call]
Dialplan: sofia/internal/1001 at 192.168.2.210 Action set(outside_call=true)
Dialplan: sofia/internal/1001 at 192.168.2.210 parsing [public->call_debug] 
continue=true
Dialplan: sofia/internal/1001 at 192.168.2.210 Regex (FAIL) [call_debug] 
${call_debug}(false) =~ /^true$/ break=never
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:114 
(sofia/internal/1001 at 192.168.2.210) State Change CS_ROUTING -> CS_EXECUTE
2009-10-14 22:26:00.63551 [DEBUG] switch_core_session.c:933 Send signal 
sofia/internal/1001 at 192.168.2.210 [BREAK]
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:483 
(sofia/internal/1001 at 192.168.2.210) State ROUTING going to sleep
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:397 
(sofia/internal/1001 at 192.168.2.210) Running State Change CS_EXECUTE
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:490 
(sofia/internal/1001 at 192.168.2.210) State EXECUTE
2009-10-14 22:26:00.63551 [DEBUG] mod_sofia.c:173 
sofia/internal/1001 at 192.168.2.210 SOFIA EXECUTE
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:151 
sofia/internal/1001 at 192.168.2.210 Standard EXECUTE
EXECUTE sofia/internal/1001 at 192.168.2.210 set(outside_call=true)
2009-10-14 22:26:00.63551 [DEBUG] mod_dptools.c:748 
sofia/internal/1001 at 192.168.2.210 SET [outside_call]=[true]
2009-10-14 22:26:00.63551 [NOTICE] switch_core_state_machine.c:179 
Hangup sofia/internal/1001 at 192.168.2.210 [CS_EXECUTE] [NORMAL_CLEARING]
2009-10-14 22:26:00.63551 [DEBUG] switch_channel.c:1683 Send signal 
sofia/internal/1001 at 192.168.2.210 [KILL]
2009-10-14 22:26:00.63551 [DEBUG] switch_core_session.c:933 Send signal 
sofia/internal/1001 at 192.168.2.210 [BREAK]
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:490 
(sofia/internal/1001 at 192.168.2.210) State EXECUTE going to sleep
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:397 
(sofia/internal/1001 at 192.168.2.210) Running State Change CS_HANGUP
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:433 
(sofia/internal/1001 at 192.168.2.210) State HANGUP
2009-10-14 22:26:00.63551 [DEBUG] mod_sofia.c:338 Channel 
sofia/internal/1001 at 192.168.2.210 hanging up, cause: NORMAL_CLEARING
2009-10-14 22:26:00.63551 [DEBUG] mod_sofia.c:414 Responding to INVITE 
with: 480
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:46 
sofia/internal/1001 at 192.168.2.210 Standard HANGUP, cause: NORMAL_CLEARING
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:433 
(sofia/internal/1001 at 192.168.2.210) State HANGUP going to sleep
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:475 
(sofia/internal/1001 at 192.168.2.210) State Change CS_HANGUP -> CS_REPORTING
2009-10-14 22:26:00.63551 [DEBUG] switch_core_session.c:933 Send signal 
sofia/internal/1001 at 192.168.2.210 [BREAK]
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:397 
(sofia/internal/1001 at 192.168.2.210) Running State Change CS_REPORTING
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:607 
(sofia/internal/1001 at 192.168.2.210) State REPORTING
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:53 
sofia/internal/1001 at 192.168.2.210 Standard REPORTING, cause: NORMAL_CLEARING
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:607 
(sofia/internal/1001 at 192.168.2.210) State REPORTING going to sleep
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:410 
(sofia/internal/1001 at 192.168.2.210) State Change CS_REPORTING -> CS_DESTROY
2009-10-14 22:26:00.63551 [DEBUG] switch_core_session.c:1067 Session 2 
(sofia/internal/1001 at 192.168.2.210) Locked, Waiting on external entities
2009-10-14 22:26:00.63551 [NOTICE] switch_core_session.c:1085 Session 2 
(sofia/internal/1001 at 192.168.2.210) Ended
2009-10-14 22:26:00.63551 [NOTICE] switch_core_session.c:1087 Close 
Channel sofia/internal/1001 at 192.168.2.210 [CS_DESTROY]
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:559 
(sofia/internal/1001 at 192.168.2.210) State DESTROY
2009-10-14 22:26:00.63551 [DEBUG] mod_sofia.c:255 
sofia/internal/1001 at 192.168.2.210 SOFIA DESTROY
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:60 
sofia/internal/1001 at 192.168.2.210 Standard DESTROY
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:559 
(sofia/internal/1001 at 192.168.2.210) State DESTROY going to sleep
2009-10-14 22:26:00.63551 [DEBUG] switch_core_state_machine.c:559 
(sofia/internal/1001 at 192.168.2.210) State DESTROY going to sleep

I am at a loss, any help would be welcome.

Orien Love