[Freeswitch-users] Even socket question.
Tim Uckun
timuckun at gmail.com
Wed Dec 9 14:35:31 PST 2009
Hey All. I am trying to get freeswitch to route to my socket handler
and am having a problem.
I am running freeswitch inside a virtualbox VM for testing purposes.
The vitualbox communicates with my host via the "host only" adapter.
The VM IP address is 192.168.56.3 and the laptop has the iP
192.168.56.1
I have set up both an outbound and an inbound socket handlers. The
inbound one works fine, the outbound is not working . The inbound
merely logs the event name. The outbound logs the connection and hangs
up.
I have set up an extension like this
<include>
<extension name="8084">
<condition field="destination_number" expression="^8084$">
<action application="set" data="continue_on_fail=true" /> <!--
we still need this to continue if bridging times out -->
<action application="set" data="call_timeout=5" />
<action application="socket" data="192.168.56.1:8084 sync full"/>
</condition>
</extension>
</include>
When I dial 8084 I get a lot of events being logged but the oubound
never gets the calls and never logs the call.
I have added the fs_cli output below. It looks to me like it's sending
the output to the other IP address of my laptop instead of the one I
specified in my extension but I could just be misreading that. I
have set the external IP of the freeswitch to the 56.3 address.
Here is the LSOF output
freeswitc 2468 root 31u IPv4 5785
TCP ubuntuvm01:5080 (LISTEN)
freeswitc 2468 root 33u IPv6 5791
TCP localhost:5060 (LISTEN)
freeswitc 2468 root 36u IPv4 5804
TCP 192.168.56.3:5060 (LISTEN)
freeswitc 2468 root 48u IPv4 5910
TCP 192.168.56.3:8021 (LISTEN)
freeswitc 2468 root 50u IPv4 5912
TCP *:8080 (LISTEN)
Here is the output from the fs_cli
2009-12-09 14:31:53.255579 [DEBUG] sofia.c:5224 0 acls to check for proxy
2009-12-09 14:31:53.255579 [DEBUG] sofia.c:5242 network ip is a proxy [0]
2009-12-09 14:31:53.255579 [DEBUG] sofia.c:5270 IP 192.168.56.1
Rejected by acl "domains". Falling back to Digest auth.
2009-12-09 14:31:53.357865 [DEBUG] sofia.c:5224 0 acls to check for proxy
2009-12-09 14:31:53.357865 [DEBUG] sofia.c:5242 network ip is a proxy [0]
2009-12-09 14:31:53.357865 [DEBUG] sofia.c:5270 IP 192.168.56.1
Rejected by acl "domains". Falling back to Digest auth.
2009-12-09 14:31:53.420949 [NOTICE] switch_channel.c:613 New Channel
sofia/internal/1000 at 192.168.56.3
[2fbcf6fe-b35e-4c40-92a6-9f21de3102fa]
2009-12-09 14:31:53.422090 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/1000 at 192.168.56.3) Running State Change CS_NEW
2009-12-09 14:31:53.422090 [DEBUG] switch_core_state_machine.c:320
(sofia/internal/1000 at 192.168.56.3) State NEW
2009-12-09 14:31:53.422090 [DEBUG] sofia.c:3727 Channel
sofia/internal/1000 at 192.168.56.3 entering state [received][100]
2009-12-09 14:31:53.422090 [DEBUG] sofia.c:3738 Remote SDP:
v=0
o=Z 0 0 IN IP4 218.101.6.157
s=Z
c=IN IP4 218.101.6.157
t=0 0
m=audio 8000 RTP/AVP 3 110 98 8 0 101
a=rtpmap:3 GSM/8000
a=rtpmap:110 speex/8000
a=rtpmap:98 iLBC/8000
a=fmtp:98 mode=30
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2009-12-09 14:31:53.422090 [DEBUG] sofia_glue.c:3305 Audio Codec
Compare [GSM:3:8000:20]/[G7221:115:32000:20]
2009-12-09 14:31:53.422090 [DEBUG] sofia_glue.c:3305 Audio Codec
Compare [GSM:3:8000:20]/[G7221:107:16000:20]
2009-12-09 14:31:53.422090 [DEBUG] sofia_glue.c:3305 Audio Codec
Compare [GSM:3:8000:20]/[G722:9:8000:20]
2009-12-09 14:31:53.422090 [DEBUG] sofia_glue.c:3305 Audio Codec
Compare [GSM:3:8000:20]/[PCMU:0:8000:20]
2009-12-09 14:31:53.422090 [DEBUG] sofia_glue.c:3305 Audio Codec
Compare [GSM:3:8000:20]/[PCMA:8:8000:20]
2009-12-09 14:31:53.422090 [DEBUG] sofia_glue.c:3305 Audio Codec
Compare [GSM:3:8000:20]/[GSM:3:8000:20]
2009-12-09 14:31:53.422090 [DEBUG] sofia_glue.c:2143 Set Codec
sofia/internal/1000 at 192.168.56.3 GSM/8000 20 ms 160 samples
2009-12-09 14:31:53.423898 [DEBUG] sofia_glue.c:3261 Set 2833 dtmf
payload to 101
2009-12-09 14:31:53.423898 [DEBUG] sofia.c:3885
(sofia/internal/1000 at 192.168.56.3) State Change CS_NEW -> CS_INIT
2009-12-09 14:31:53.423898 [DEBUG] switch_core_session.c:999 Send
signal sofia/internal/1000 at 192.168.56.3 [BREAK]
2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/1000 at 192.168.56.3) Running State Change CS_INIT
2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/1000 at 192.168.56.3) State INIT
2009-12-09 14:31:53.423898 [DEBUG] mod_sofia.c:83
sofia/internal/1000 at 192.168.56.3 SOFIA INIT
2009-12-09 14:31:53.423898 [DEBUG] mod_sofia.c:111
(sofia/internal/1000 at 192.168.56.3) State Change CS_INIT -> CS_ROUTING
2009-12-09 14:31:53.423898 [DEBUG] switch_core_session.c:999 Send
signal sofia/internal/1000 at 192.168.56.3 [BREAK]
2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/1000 at 192.168.56.3) State INIT going to sleep
2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/1000 at 192.168.56.3) Running State Change CS_ROUTING
2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/1000 at 192.168.56.3) State ROUTING
2009-12-09 14:31:53.423898 [DEBUG] mod_sofia.c:132
sofia/internal/1000 at 192.168.56.3 SOFIA ROUTING
2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:78
sofia/internal/1000 at 192.168.56.3 Standard ROUTING
2009-12-09 14:31:53.423898 [INFO] mod_dialplan_xml.c:408 Processing
1000->8084 in context default
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing [default->unloop]
continue=false
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (PASS) [unloop]
${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (FAIL) [unloop]
${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing
[default->tod_example] continue=true
Dialplan: day of week[4] =~ 2-6 (PASS)
Dialplan: hour[14] =~ 9-18 (PASS)
Dialplan: sofia/internal/1000 at 192.168.56.3 Date/Time Match (PASS)
[tod_example] break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 Action set(open=true)
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing
[default->holiday_example] continue=true
Dialplan: month[12] =~ 1 (FAIL)
Dialplan: sofia/internal/1000 at 192.168.56.3 Date/Time Match (FAIL)
[holiday_example] break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing
[default->global-intercept] continue=false
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (FAIL)
[global-intercept] destination_number(8084) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing
[default->group-intercept] continue=false
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (FAIL)
[group-intercept] destination_number(8084) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing
[default->intercept-ext] continue=false
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (FAIL)
[intercept-ext] destination_number(8084) =~ /^\*\*(\d+)$/
break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing [default->redial]
continue=false
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (FAIL) [redial]
destination_number(8084) =~ /^870$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing [default->global]
continue=true
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (FAIL) [global]
${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (FAIL) [global]
${sip_has_crypto}() =~
/^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never
Dialplan: sofia/internal/1000 at 192.168.56.3 Absolute Condition [global]
Dialplan: sofia/internal/1000 at 192.168.56.3 Action
hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/1000 at 192.168.56.3 Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1000 at 192.168.56.3 Action
hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing
[default->snom-demo-2] continue=false
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (FAIL) [snom-demo-2]
destination_number(8084) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing
[default->snom-demo-1] continue=false
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (FAIL) [snom-demo-1]
destination_number(8084) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing
[default->eavesdrop] continue=false
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (FAIL) [eavesdrop]
destination_number(8084) =~ /^88(.*)$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing
[default->eavesdrop] continue=false
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (FAIL) [eavesdrop]
destination_number(8084) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing
[default->call_return] continue=false
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (FAIL) [call_return]
destination_number(8084) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 parsing
[default->del-group] continue=false
Dialplan: sofia/internal/1000 at 192.168.56.3 Regex (PASS) [del-group]
destination_number(8084) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.56.3 Action answer()
Dialplan: sofia/internal/1000 at 192.168.56.3 Action
group(delete:84@${domain_name}:${sofia_contact(${sip_from_user}@${domain_name})})
Dialplan: sofia/internal/1000 at 192.168.56.3 Action gentones(%(1000, 0, 320))
2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:122
(sofia/internal/1000 at 192.168.56.3) State Change CS_ROUTING ->
CS_EXECUTE
2009-12-09 14:31:53.423898 [DEBUG] switch_core_session.c:999 Send
signal sofia/internal/1000 at 192.168.56.3 [BREAK]
2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/1000 at 192.168.56.3) State ROUTING going to sleep
2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/1000 at 192.168.56.3) Running State Change CS_EXECUTE
2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:348
(sofia/internal/1000 at 192.168.56.3) State EXECUTE
2009-12-09 14:31:53.423898 [DEBUG] mod_sofia.c:181
sofia/internal/1000 at 192.168.56.3 SOFIA EXECUTE
2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:159
sofia/internal/1000 at 192.168.56.3 Standard EXECUTE
EXECUTE sofia/internal/1000 at 192.168.56.3 set(open=true)
2009-12-09 14:31:53.423898 [DEBUG] mod_dptools.c:768
sofia/internal/1000 at 192.168.56.3 SET [open]=[true]
EXECUTE sofia/internal/1000 at 192.168.56.3
hash(insert/192.168.56.3-spymap/1000/2fbcf6fe-b35e-4c40-92a6-9f21de3102fa)
EXECUTE sofia/internal/1000 at 192.168.56.3
hash(insert/192.168.56.3-last_dial/1000/8084)
EXECUTE sofia/internal/1000 at 192.168.56.3
hash(insert/192.168.56.3-last_dial/global/2fbcf6fe-b35e-4c40-92a6-9f21de3102fa)
EXECUTE sofia/internal/1000 at 192.168.56.3 answer()
2009-12-09 14:31:53.423898 [DEBUG] mod_dptools.c:658
sofia/internal/1000 at 192.168.56.3 receive message [ANSWER]
2009-12-09 14:31:53.423898 [DEBUG] sofia_glue.c:2381 AUDIO RTP
[sofia/internal/1000 at 192.168.56.3] 192.168.50.173 port 27042 ->
218.101.6.157 port 8000 codec: 3 ms: 20
2009-12-09 14:31:53.423898 [DEBUG] switch_rtp.c:1167 Starting timer
[soft] 160 bytes per 20ms
2009-12-09 14:31:53.423898 [DEBUG] mod_sofia.c:571 Local SDP
sofia/internal/1000 at 192.168.56.3:
v=0
o=FreeSWITCH 1260370871 1260370872 IN IP4 192.168.50.173
s=FreeSWITCH
c=IN IP4 192.168.50.173
t=0 0
m=audio 27042 RTP/AVP 3 101
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
2009-12-09 14:31:53.423898 [DEBUG] switch_core_session.c:645 Send
signal sofia/internal/1000 at 192.168.56.3 [BREAK]
2009-12-09 14:31:53.423898 [NOTICE] mod_dptools.c:658 Channel
[sofia/internal/1000 at 192.168.56.3] has been answered
2009-12-09 14:31:53.423898 [DEBUG] switch_channel.c:182
sofia/internal/1000 at 192.168.56.3 receive message [AUDIO_SYNC]
EXECUTE sofia/internal/1000 at 192.168.56.3
group(delete:84 at 192.168.56.3:sofia/internal/sip:1000 at 218.101.6.157:5070;rinstance=a8b6fdbc731e3b66;transport=UDP)
EXECUTE sofia/internal/1000 at 192.168.56.3 gentones(%(1000, 0, 320))
2009-12-09 14:31:53.436374 [DEBUG] switch_core_io.c:652
sofia/internal/1000 at 192.168.56.3 receive message
[TRANSCODING_NECESSARY]
2009-12-09 14:31:53.436670 [DEBUG] sofia.c:3727 Channel
sofia/internal/1000 at 192.168.56.3 entering state [completed][200]
2009-12-09 14:31:53.490803 [DEBUG] sofia.c:3727 Channel
sofia/internal/1000 at 192.168.56.3 entering state [ready][200]
2009-12-09 14:31:53.729534 [INFO] switch_rtp.c:1987 Auto Changing port
from 218.101.6.157:8000 to 192.168.50.105:8000
2009-12-09 14:31:54.430526 [NOTICE] switch_core_state_machine.c:187
Hangup sofia/internal/1000 at 192.168.56.3 [CS_EXECUTE] [NORMAL_CLEARING]
2009-12-09 14:31:54.430526 [DEBUG] switch_channel.c:1912 Send signal
sofia/internal/1000 at 192.168.56.3 [KILL]
2009-12-09 14:31:54.430526 [DEBUG] switch_core_session.c:999 Send
signal sofia/internal/1000 at 192.168.56.3 [BREAK]
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:488
(sofia/internal/1000 at 192.168.56.3) State HANGUP
2009-12-09 14:31:54.430526 [DEBUG] mod_sofia.c:358 Channel
sofia/internal/1000 at 192.168.56.3 hanging up, cause: NORMAL_CLEARING
2009-12-09 14:31:54.430526 [DEBUG] mod_sofia.c:400 Sending BYE to
sofia/internal/1000 at 192.168.56.3
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:46
sofia/internal/1000 at 192.168.56.3 Standard HANGUP, cause:
NORMAL_CLEARING
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:488
(sofia/internal/1000 at 192.168.56.3) State HANGUP going to sleep
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:348
(sofia/internal/1000 at 192.168.56.3) State EXECUTE going to sleep
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/1000 at 192.168.56.3) Running State Change CS_HANGUP
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:465
sofia/internal/1000 at 192.168.56.3 handler already called, skipping
state handler.
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/1000 at 192.168.56.3) State Change CS_HANGUP ->
CS_REPORTING
2009-12-09 14:31:54.430526 [DEBUG] switch_core_session.c:999 Send
signal sofia/internal/1000 at 192.168.56.3 [BREAK]
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/1000 at 192.168.56.3) Running State Change CS_REPORTING
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/1000 at 192.168.56.3) State REPORTING
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:53
sofia/internal/1000 at 192.168.56.3 Standard REPORTING, cause:
NORMAL_CLEARING
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/1000 at 192.168.56.3) State REPORTING going to sleep
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:327
(sofia/internal/1000 at 192.168.56.3) State Change CS_REPORTING ->
CS_DESTROY
2009-12-09 14:31:54.430526 [DEBUG] switch_core_session.c:999 Send
signal sofia/internal/1000 at 192.168.56.3 [BREAK]
2009-12-09 14:31:54.430526 [DEBUG] switch_core_session.c:1136 Session
6 (sofia/internal/1000 at 192.168.56.3) Locked, Waiting on external
entities
2009-12-09 14:31:54.430526 [NOTICE] switch_core_session.c:1154 Session
6 (sofia/internal/1000 at 192.168.56.3) Ended
2009-12-09 14:31:54.430526 [NOTICE] switch_core_session.c:1156 Close
Channel sofia/internal/1000 at 192.168.56.3 [CS_DESTROY]
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:423
(sofia/internal/1000 at 192.168.56.3) Running State Change CS_DESTROY
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:434
(sofia/internal/1000 at 192.168.56.3) State DESTROY
2009-12-09 14:31:54.430526 [DEBUG] mod_sofia.c:293
sofia/internal/1000 at 192.168.56.3 SOFIA DESTROY
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:60
sofia/internal/1000 at 192.168.56.3 Standard DESTROY
2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:434
(sofia/internal/1000 at 192.168.56.3) State DESTROY going to sleep
More information about the FreeSWITCH-users
mailing list