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