Re: [Freeswitch-users] Even socket question.

[Anthony Minessale]

do you have something listening on 8084 ?


On Wed, Dec 9, 2009 at 4:35 PM, Tim Uckun <timuc...@gmail.com> wrote:

> 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/1...@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/1...@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/1...@192.168.56.3) State NEW
> 2009-12-09 14:31:53.422090 [DEBUG] sofia.c:3727 Channel
> sofia/internal/1...@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/1...@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/1...@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/1...@192.168.56.3 [BREAK]
> 2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:314
> (sofia/internal/1...@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/1...@192.168.56.3) State INIT
> 2009-12-09 14:31:53.423898 [DEBUG] mod_sofia.c:83
> sofia/internal/1...@192.168.56.3 SOFIA INIT
> 2009-12-09 14:31:53.423898 [DEBUG] mod_sofia.c:111
> (sofia/internal/1...@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/1...@192.168.56.3 [BREAK]
> 2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:338
> (sofia/internal/1...@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/1...@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/1...@192.168.56.3) State ROUTING
> 2009-12-09 14:31:53.423898 [DEBUG] mod_sofia.c:132
> sofia/internal/1...@192.168.56.3 SOFIA ROUTING
> 2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:78
> sofia/internal/1...@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/1...@192.168.56.3 parsing [default->unloop]
> continue=false
> Dialplan: sofia/internal/1...@192.168.56.3 Regex (PASS) [unloop]
> ${unroll_loops}(true) =~ /^true$/ break=on-false
> Dialplan: sofia/internal/1...@192.168.56.3 Regex (FAIL) [unloop]
> ${sip_looped_call}() =~ /^true$/ break=on-false
> Dialplan: sofia/internal/1...@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/1...@192.168.56.3 Date/Time Match (PASS)
> [tod_example] break=on-false
> Dialplan: sofia/internal/1...@192.168.56.3 Action set(open=true)
> Dialplan: sofia/internal/1...@192.168.56.3 parsing
> [default->holiday_example] continue=true
> Dialplan: month[12] =~ 1 (FAIL)
> Dialplan: sofia/internal/1...@192.168.56.3 Date/Time Match (FAIL)
> [holiday_example] break=on-false
> Dialplan: sofia/internal/1...@192.168.56.3 parsing
> [default->global-intercept] continue=false
> Dialplan: sofia/internal/1...@192.168.56.3 Regex (FAIL)
> [global-intercept] destination_number(8084) =~ /^886$/ break=on-false
> Dialplan: sofia/internal/1...@192.168.56.3 parsing
> [default->group-intercept] continue=false
> Dialplan: sofia/internal/1...@192.168.56.3 Regex (FAIL)
> [group-intercept] destination_number(8084) =~ /^\*8$/ break=on-false
> Dialplan: sofia/internal/1...@192.168.56.3 parsing
> [default->intercept-ext] continue=false
> Dialplan: sofia/internal/1...@192.168.56.3 Regex (FAIL)
> [intercept-ext] destination_number(8084) =~ /^\*\*(\d+)$/
> break=on-false
> Dialplan: sofia/internal/1...@192.168.56.3 parsing [default->redial]
> continue=false
> Dialplan: sofia/internal/1...@192.168.56.3 Regex (FAIL) [redial]
> destination_number(8084) =~ /^870$/ break=on-false
> Dialplan: sofia/internal/1...@192.168.56.3 parsing [default->global]
> continue=true
> Dialplan: sofia/internal/1...@192.168.56.3 Regex (FAIL) [global]
> ${call_debug}(false) =~ /^true$/ break=never
> Dialplan: sofia/internal/1...@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/1...@192.168.56.3 Absolute Condition [global]
> Dialplan: sofia/internal/1...@192.168.56.3 Action
> hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
> Dialplan: sofia/internal/1...@192.168.56.3 Action
>
> hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
> Dialplan: sofia/internal/1...@192.168.56.3 Action
> hash(insert/${domain_name}-last_dial/global/${uuid})
> Dialplan: sofia/internal/1...@192.168.56.3 parsing
> [default->snom-demo-2] continue=false
> Dialplan: sofia/internal/1...@192.168.56.3 Regex (FAIL) [snom-demo-2]
> destination_number(8084) =~ /^9001$/ break=on-false
> Dialplan: sofia/internal/1...@192.168.56.3 parsing
> [default->snom-demo-1] continue=false
> Dialplan: sofia/internal/1...@192.168.56.3 Regex (FAIL) [snom-demo-1]
> destination_number(8084) =~ /^9000$/ break=on-false
> Dialplan: sofia/internal/1...@192.168.56.3 parsing
> [default->eavesdrop] continue=false
> Dialplan: sofia/internal/1...@192.168.56.3 Regex (FAIL) [eavesdrop]
> destination_number(8084) =~ /^88(.*)$|^\*0(.*)$/ break=on-false
> Dialplan: sofia/internal/1...@192.168.56.3 parsing
> [default->eavesdrop] continue=false
> Dialplan: sofia/internal/1...@192.168.56.3 Regex (FAIL) [eavesdrop]
> destination_number(8084) =~ /^779$/ break=on-false
> Dialplan: sofia/internal/1...@192.168.56.3 parsing
> [default->call_return] continue=false
> Dialplan: sofia/internal/1...@192.168.56.3 Regex (FAIL) [call_return]
> destination_number(8084) =~ /^\*69$|^869$|^lcr$/ break=on-false
> Dialplan: sofia/internal/1...@192.168.56.3 parsing
> [default->del-group] continue=false
> Dialplan: sofia/internal/1...@192.168.56.3 Regex (PASS) [del-group]
> destination_number(8084) =~ /^80(\d{2})$/ break=on-false
> Dialplan: sofia/internal/1...@192.168.56.3 Action answer()
> Dialplan: sofia/internal/1...@192.168.56.3 Action
> group(delete:8...@${domain_name}:${sofia_contact(${sip_from_user}@
> ${domain_name})})
> Dialplan: sofia/internal/1...@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/1...@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/1...@192.168.56.3 [BREAK]
> 2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:341
> (sofia/internal/1...@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/1...@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/1...@192.168.56.3) State EXECUTE
> 2009-12-09 14:31:53.423898 [DEBUG] mod_sofia.c:181
> sofia/internal/1...@192.168.56.3 SOFIA EXECUTE
> 2009-12-09 14:31:53.423898 [DEBUG] switch_core_state_machine.c:159
> sofia/internal/1...@192.168.56.3 Standard EXECUTE
> EXECUTE sofia/internal/1...@192.168.56.3 set(open=true)
> 2009-12-09 14:31:53.423898 [DEBUG] mod_dptools.c:768
> sofia/internal/1...@192.168.56.3 SET [open]=[true]
> EXECUTE sofia/internal/1...@192.168.56.3
> hash(insert/192.168.56.3-spymap/1000/2fbcf6fe-b35e-4c40-92a6-9f21de3102fa)
> EXECUTE sofia/internal/1...@192.168.56.3
> hash(insert/192.168.56.3-last_dial/1000/8084)
> EXECUTE sofia/internal/1...@192.168.56.3
>
> hash(insert/192.168.56.3-last_dial/global/2fbcf6fe-b35e-4c40-92a6-9f21de3102fa)
> EXECUTE sofia/internal/1...@192.168.56.3 answer()
> 2009-12-09 14:31:53.423898 [DEBUG] mod_dptools.c:658
> sofia/internal/1...@192.168.56.3 receive message [ANSWER]
> 2009-12-09 14:31:53.423898 [DEBUG] sofia_glue.c:2381 AUDIO RTP
> [sofia/internal/1...@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/1...@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/1...@192.168.56.3 [BREAK]
> 2009-12-09 14:31:53.423898 [NOTICE] mod_dptools.c:658 Channel
> [sofia/internal/1...@192.168.56.3] has been answered
> 2009-12-09 14:31:53.423898 [DEBUG] switch_channel.c:182
> sofia/internal/1...@192.168.56.3 receive message [AUDIO_SYNC]
> EXECUTE sofia/internal/1...@192.168.56.3
> group(delete:8...@192.168.56.3:sofia/internal/sip:1...@218.101.6.157:5070
> ;rinstance=a8b6fdbc731e3b66;transport=UDP)
> EXECUTE sofia/internal/1...@192.168.56.3 gentones(%(1000, 0, 320))
> 2009-12-09 14:31:53.436374 [DEBUG] switch_core_io.c:652
> sofia/internal/1...@192.168.56.3 receive message
> [TRANSCODING_NECESSARY]
> 2009-12-09 14:31:53.436670 [DEBUG] sofia.c:3727 Channel
> sofia/internal/1...@192.168.56.3 entering state [completed][200]
> 2009-12-09 14:31:53.490803 [DEBUG] sofia.c:3727 Channel
> sofia/internal/1...@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/1...@192.168.56.3 [CS_EXECUTE] [NORMAL_CLEARING]
> 2009-12-09 14:31:54.430526 [DEBUG] switch_channel.c:1912 Send signal
> sofia/internal/1...@192.168.56.3 [KILL]
> 2009-12-09 14:31:54.430526 [DEBUG] switch_core_session.c:999 Send
> signal sofia/internal/1...@192.168.56.3 [BREAK]
> 2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:488
> (sofia/internal/1...@192.168.56.3) State HANGUP
> 2009-12-09 14:31:54.430526 [DEBUG] mod_sofia.c:358 Channel
> sofia/internal/1...@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/1...@192.168.56.3
> 2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:46
> sofia/internal/1...@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/1...@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/1...@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/1...@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/1...@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/1...@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/1...@192.168.56.3 [BREAK]
> 2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:314
> (sofia/internal/1...@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/1...@192.168.56.3) State REPORTING
> 2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:53
> sofia/internal/1...@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/1...@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/1...@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/1...@192.168.56.3 [BREAK]
> 2009-12-09 14:31:54.430526 [DEBUG] switch_core_session.c:1136 Session
> 6 (sofia/internal/1...@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/1...@192.168.56.3) Ended
> 2009-12-09 14:31:54.430526 [NOTICE] switch_core_session.c:1156 Close
> Channel sofia/internal/1...@192.168.56.3 [CS_DESTROY]
> 2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:423
> (sofia/internal/1...@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/1...@192.168.56.3) State DESTROY
> 2009-12-09 14:31:54.430526 [DEBUG] mod_sofia.c:293
> sofia/internal/1...@192.168.56.3 SOFIA DESTROY
> 2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:60
> sofia/internal/1...@192.168.56.3 Standard DESTROY
> 2009-12-09 14:31:54.430526 [DEBUG] switch_core_state_machine.c:434
> (sofia/internal/1...@192.168.56.3) State DESTROY going to sleep
>
> _______________________________________________
> FreeSWITCH-users mailing list
> FreeSWITCH-users@lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>



-- 
Anthony Minessale II

FreeSWITCH http://www.freeswitch.org/
ClueCon http://www.cluecon.com/
Twitter: http://twitter.com/FreeSWITCH_wire

AIM: anthm
MSN:anthony_miness...@hotmail.com <msn%3aanthony_miness...@hotmail.com>
GTALK/JABBER/PAYPAL:anthony.miness...@gmail.com<paypal%3aanthony.miness...@gmail.com>
IRC: irc.freenode.net #freeswitch

FreeSWITCH Developer Conference
sip:8...@conference.freeswitch.org <sip%3a...@conference.freeswitch.org>
iax:gu...@conference.freeswitch.org/888
googletalk:conf+...@conference.freeswitch.org<googletalk%3aconf%2b...@conference.freeswitch.org>
pstn:213-799-1400

_______________________________________________
FreeSWITCH-users mailing list
FreeSWITCH-users@lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org