When I say it doesn't work, I mean that I can only connect the "answering machine". It doesn't ring. Following the fs_cli trace... (from logs): ... 2011-12-01 13:42:18.918274 [DEBUG] sofia.c:7267 IP 90.36.1.89 Rejected by acl "domains". Falling back to Digest auth. 2011-12-01 13:42:29.258256 [DEBUG] sofia.c:7267 IP 90.36.1.89 Rejected by acl "domains". Falling back to Digest auth. 2011-12-01 13:42:29.258256 [NOTICE] switch_channel.c:920 New Channel sofia/internal/1004@connexur.dyndns.org [ee2049ee-1c19-11e1-abcd-1f494360f62d] 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_NEW 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:380 (sofia/internal/1004@connexur.dyndns.org) State NEW 2011-12-01 13:42:29.268425 [DEBUG] sofia.c:8186 Setting NAT mode based on nat.auto 2011-12-01 13:42:29.268425 [DEBUG] sofia.c:5282 Channel sofia/internal/1004@connexur.dyndns.org entering state [received][100] 2011-12-01 13:42:29.268425 [DEBUG] sofia.c:5293 Remote SDP: v=0 o=- 9 2 IN IP4 192.168.1.10 s=CounterPath X-Lite 3.0 c=IN IP4 192.168.1.10 t=0 0 m=audio 64860 RTP/AVP 107 119 0 98 8 3 101 a=rtpmap:107 BV32/16000 a=rtpmap:119 BV32-FEC/16000 a=rtpmap:98 iLBC/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=alt:1 1 : PBDGzwKZ EILmrBFJ 192.168.1.10 64860 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[G7221:115:32000:20:48000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[G7221:107:16000:20:32000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[G722:9:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[PCMU:0:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[PCMA:8:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[GSM:3:8000:20:13200] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[PCMA:8:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[GSM:3:8000:20:13200] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32-FEC:119:16000:20:0]/[G7221:115:32000:20:48000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32-FEC:119:16000:20:0]/[G7221:107:16000:20:32000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32-FEC:119:16000:20:0]/[G722:9:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32-FEC:119:16000:20:0]/[PCMU:0:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32-FEC:119:16000:20:0]/[PCMA:8:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32-FEC:119:16000:20:0]/[GSM:3:8000:20:13200] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [PCMU:0:8000:20:64000]/[G7221:115:32000:20:48000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [PCMU:0:8000:20:64000]/[G7221:107:16000:20:32000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:2864 Set Codec sofia/internal/1004@connexur.dyndns.org PCMU/8000 20 ms 160 samples 64000 bits 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4871 Set 2833 dtmf send/recv payload to 101 2011-12-01 13:42:29.268425 [DEBUG] sofia.c:5505 (sofia/internal/1004@connexur.dyndns.org) State Change CS_NEW -> CS_INIT 2011-12-01 13:42:29.268425 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_INIT 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/1004@connexur.dyndns.org) State INIT 2011-12-01 13:42:29.268425 [DEBUG] mod_sofia.c:85 sofia/internal/1004@connexur.dyndns.org SOFIA INIT 2011-12-01 13:42:29.268425 [DEBUG] mod_sofia.c:125 (sofia/internal/1004@connexur.dyndns.org) State Change CS_INIT -> CS_ROUTING 2011-12-01 13:42:29.268425 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/1004@connexur.dyndns.org) State INIT going to sleep 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_ROUTING 2011-12-01 13:42:29.268425 [DEBUG] switch_channel.c:1871 (sofia/internal/1004@connexur.dyndns.org) Callstate Change DOWN -> RINGING 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/1004@connexur.dyndns.org) State ROUTING 2011-12-01 13:42:29.268425 [DEBUG] mod_sofia.c:148 sofia/internal/1004@connexur.dyndns.org SOFIA ROUTING 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1004@connexur.dyndns.org Standard ROUTING 2011-12-01 13:42:29.268425 [INFO] mod_dialplan_xml.c:481 Processing 1004 <1004>->1001 in context default Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->unloop] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->tod_example] continue=true Dialplan: sofia/internal/1004@connexur.dyndns.org Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(open=true) Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->holiday_example] continue=true Dialplan: sofia/internal/1004@connexur.dyndns.org Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [global-intercept] destination_number(1001) =~ /^886$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->redial] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [redial] destination_number(1001) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->global] continue=true Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=n$ Dialplan: sofia/internal/1004@connexur.dyndns.org Absolute Condition [global] Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [snom-demo-1] destination_number(1001) =~ /^9000$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^779$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->call_return] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [call_return] destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->del-group] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [del-group] destination_number(1001) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->add-group] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [add-group] destination_number(1001) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [call-group-simo] destination_number(1001) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [call-group-order] destination_number(1001) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [extension-intercom] destination_number(1001) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (PASS) [Local_Extension] destination_number(1001) =~ /^(10[01][0-9]|1100)$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(dialed_extension=1001) Dialplan: sofia/internal/1004@connexur.dyndns.org Action export(dialed_extension=1001) Dialplan: sofia/internal/1004@connexur.dyndns.org Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/1004@connexur.dyndns.org Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime$ Dialplan: sofia/internal/1004@connexur.dyndns.org Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/1004@connexur.dyndns.org Action bind_meta_app(4 b s execute_extension::att_xfer XML features) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(ringback=${us-ring}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(call_timeout=30) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(hangup_after_bridge=true) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(continue_on_fail=true) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-last_dial_ext/global/${uuid}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action answer() Dialplan: sofia/internal/1004@connexur.dyndns.org Action sleep(1000) Dialplan: sofia/internal/1004@connexur.dyndns.org Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension}) 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:154 (sofia/internal/1004@connexur.dyndns.org) State Change CS_ROUTING -> CS_EXECUTE 2011-12-01 13:42:29.268425 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/1004@connexur.dyndns.org) State ROUTING going to sleep 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_EXECUTE 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/1004@connexur.dyndns.org) State EXECUTE 2011-12-01 13:42:29.268425 [DEBUG] mod_sofia.c:241 sofia/internal/1004@connexur.dyndns.org SOFIA EXECUTE 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:192 sofia/internal/1004@connexur.dyndns.org Standard EXECUTE EXECUTE sofia/internal/1004@connexur.dyndns.org set(open=true) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [open]=[true] EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-spymap/1004/ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial/1004/1001) EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial/global/ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org set(RFC2822_DATE=Thu, 01 Dec 2011 13:42:29 +0100) EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial/global/ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org set(RFC2822_DATE=Thu, 01 Dec 2011 13:42:29 +0100) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [RFC2822_DATE]=[Thu, 01 Dec 2011 13:42:29 +0100] EXECUTE sofia/internal/1004@connexur.dyndns.org set(dialed_extension=1001) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [dialed_extension]=[1001] EXECUTE sofia/internal/1004@connexur.dyndns.org export(dialed_extension=1001) 2011-12-01 13:42:29.268425 [DEBUG] switch_channel.c:1087 EXPORT (export_vars) [dialed_extension]=[1001] EXECUTE sofia/internal/1004@connexur.dyndns.org bind_meta_app(1 b s execute_extension::dx XML features) 2011-12-01 13:42:29.268425 [INFO] switch_ivr_async.c:3130 Bound B-Leg: *1 execute_extension::dx XML features EXECUTE sofia/internal/1004@connexur.dyndns.org bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1004.2011-12-01-13-42-29.wav) 2011-12-01 13:42:29.268425 [INFO] switch_ivr_async.c:3130 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1004.2011-12-01-13-42-29.wav EXECUTE sofia/internal/1004@connexur.dyndns.org bind_meta_app(3 b s execute_extension::cf XML features) 2011-12-01 13:42:29.268425 [INFO] switch_ivr_async.c:3130 Bound B-Leg: *3 execute_extension::cf XML features EXECUTE sofia/internal/1004@connexur.dyndns.org bind_meta_app(4 b s execute_extension::att_xfer XML features) 2011-12-01 13:42:29.268425 [INFO] switch_ivr_async.c:3130 Bound B-Leg: *4 execute_extension::att_xfer XML features EXECUTE sofia/internal/1004@connexur.dyndns.org set(ringback=%(2000,4000,440.0,480.0)) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [ringback]=[%(2000,4000,440.0,480.0)] EXECUTE sofia/internal/1004@connexur.dyndns.org set(transfer_ringback=local_stream://moh) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/1004@connexur.dyndns.org set(call_timeout=30) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [call_timeout]=[30] EXECUTE sofia/internal/1004@connexur.dyndns.org set(hangup_after_bridge=true) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/1004@connexur.dyndns.org set(continue_on_fail=true) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [continue_on_fail]=[true] EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-call_return/1001/1004) EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial_ext/1001/ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial_ext//ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial_ext/global/ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org set(called_party_callgroup=techsupport) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [called_party_callgroup]=[techsupport] EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial/techsupport/ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org bridge(user/1001@91.204.116.116) 2011-12-01 13:42:29.268425 [DEBUG] switch_channel.c:1041 sofia/internal/1004@connexur.dyndns.org EXPORTING[export_vars] [dialed_extension]=[1001] to event 2011-12-01 13:42:29.268425 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables 2011-12-01 13:42:29.268425 [DEBUG] switch_channel.c:1041 sofia/internal/1004@connexur.dyndns.org EXPORTING[export_vars] [dialed_extension]=[1001] to event 2011-12-01 13:42:29.268425 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables 2011-12-01 13:42:29.268425 [DEBUG] switch_event.c:1521 Parsing variable [sip_invite_domain]=[91.204.116.116] 2011-12-01 13:42:29.268425 [DEBUG] switch_event.c:1521 Parsing variable [presence_id]=[1001@91.204.116.116] 2011-12-01 13:42:29.268425 [NOTICE] switch_ivr_originate.c:2459 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED] 2011-12-01 13:42:29.268425 [DEBUG] switch_ivr_originate.c:3367 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED] 2011-12-01 13:42:29.268425 [NOTICE] switch_ivr_originate.c:2459 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED] 2011-12-01 13:42:29.268425 [DEBUG] switch_ivr_originate.c:3367 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED] 2011-12-01 13:42:29.268425 [INFO] mod_dptools.c:2838 Originate Failed. Cause: USER_NOT_REGISTERED EXECUTE sofia/internal/1004@connexur.dyndns.org answer() 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:3116 AUDIO RTP [sofia/internal/1004@connexur.dyndns.org] 91.204.116.116 port 21454 -> 192.168.1.10 port 6486$ 2011-12-01 13:42:29.268425 [DEBUG] switch_rtp.c:1642 Starting timer [soft] 160 bytes per 20ms 2011-12-01 13:42:29.293791 [DEBUG] sofia_glue.c:3382 Set 2833 dtmf send payload to 101 2011-12-01 13:42:29.293791 [DEBUG] sofia_glue.c:3388 Set 2833 dtmf receive payload to 101 2011-12-01 13:42:29.293791 [DEBUG] mod_sofia.c:746 Local SDP sofia/internal/1004@connexur.dyndns.org: v=0 o=FreeSWITCH 1322721895 1322721896 IN IP4 91.204.116.116 s=FreeSWITCH c=IN IP4 91.204.116.116 t=0 0 c=IN IP4 91.204.116.116 t=0 0 m=audio 21454 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 2011-12-01 13:42:29.293791 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.293791 [DEBUG] sofia.c:5282 Channel sofia/internal/1004@connexur.dyndns.org entering state [completed][200] 2011-12-01 13:42:29.293791 [DEBUG] switch_core_session.c:726 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.293791 [DEBUG] switch_channel.c:3175 (sofia/internal/1004@connexur.dyndns.org) Callstate Change RINGING -> ACTIVE 2011-12-01 13:42:29.293791 [NOTICE] mod_dptools.c:1071 Channel [sofia/internal/1004@connexur.dyndns.org] has been answered EXECUTE sofia/internal/1004@connexur.dyndns.org sleep(1000) 2011-12-01 13:42:29.568264 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.568264 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.568264 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.578421 [DEBUG] sofia.c:5282 Channel sofia/internal/1004@connexur.dyndns.org entering state [ready][200] 2011-12-01 13:42:29.658301 [INFO] switch_rtp.c:3170 Auto Changing port from 192.168.1.10:64860 to 90.36.1.89:64860 EXECUTE sofia/internal/1004@connexur.dyndns.org bridge(loopback/app=voicemail:default 91.204.116.116 1001) 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:1041 sofia/internal/1004@connexur.dyndns.org EXPORTING[export_vars] [dialed_extension]=[1001] to event 2011-12-01 13:42:30.298263 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables 2011-12-01 13:42:30.298263 [NOTICE] switch_channel.c:920 New Channel loopback/app=voicemail:default 91.204.116.116 1001-a [eebdaf40-1c19-11e1-abd8-1f494360f$ 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:145 loopback/app=voicemail:default 91.204.116.116 1001-a setup codec PCMU/8000/20 2011-12-01 13:42:30.298263 [NOTICE] switch_channel.c:918 Rename Channel loopback/app=voicemail:default 91.204.116.116 1001-a->loopback/voicemail-a [eebdaf40$ 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:973 (loopback/voicemail-a) State Change CS_NEW -> CS_INIT 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-a) Running State Change CS_INIT 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:401 (loopback/voicemail-a) State INIT 2011-12-01 13:42:30.298263 [NOTICE] switch_channel.c:920 New Channel loopback/voicemail-b [eebdc6ba-1c19-11e1-abdc-1f494360f62d] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:145 loopback/voicemail-b setup codec PCMU/8000/20 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:258 (loopback/voicemail-b) State Change CS_NEW -> CS_INIT 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-b) Running State Change CS_INIT 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:401 (loopback/voicemail-b) State INIT 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:304 (loopback/voicemail-b) State Change CS_INIT -> CS_ROUTING 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:401 (loopback/voicemail-b) State INIT going to sleep 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-b) Running State Change CS_ROUTING 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:1871 (loopback/voicemail-b) Callstate Change DOWN -> RINGING 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:410 (loopback/voicemail-b) State ROUTING 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:336 loopback/voicemail-b CHANNEL ROUTING 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:355 (loopback/voicemail-b) State Change CS_ROUTING -> CS_EXECUTE 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:410 (loopback/voicemail-b) State ROUTING going to sleep 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-b) Running State Change CS_EXECUTE 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:417 (loopback/voicemail-b) State EXECUTE 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:375 loopback/voicemail-b CHANNEL EXECUTE 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:192 loopback/voicemail-b Standard EXECUTE 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:375 loopback/voicemail-b CHANNEL EXECUTE 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:192 loopback/voicemail-b Standard EXECUTE EXECUTE loopback/voicemail-b pre_answer() 2011-12-01 13:42:30.298263 [NOTICE] mod_loopback.c:760 Pre-Answer loopback/voicemail-a! 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:2917 (loopback/voicemail-a) Callstate Change DOWN -> EARLY 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:2959 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:726 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:30.298263 [NOTICE] mod_dptools.c:1097 Pre-Answer loopback/voicemail-b! 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:2917 (loopback/voicemail-b) Callstate Change RINGING -> EARLY 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:2959 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] EXECUTE loopback/voicemail-b voicemail(default 91.204.116.116 1001) 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:304 (loopback/voicemail-a) State Change CS_INIT -> CS_ROUTING 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:401 (loopback/voicemail-a) State INIT going to sleep 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-a) Running State Change CS_ROUTING 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:1871 (loopback/voicemail-a) Callstate Change EARLY -> RINGING 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:410 (loopback/voicemail-a) State ROUTING 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:336 loopback/voicemail-a CHANNEL ROUTING 2011-12-01 13:42:30.298263 [DEBUG] switch_ivr_originate.c:66 (loopback/voicemail-a) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:410 (loopback/voicemail-a) State ROUTING going to sleep 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-a) Running State Change CS_CONSUME_MEDIA 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:1875 (loopback/voicemail-a) Callstate Change RINGING -> EARLY 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:429 (loopback/voicemail-a) State CONSUME_MEDIA 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:535 CHANNEL CONSUME_MEDIA 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:429 (loopback/voicemail-a) State CONSUME_MEDIA going to sleep 2011-12-01 13:42:30.308562 [DEBUG] switch_ivr_originate.c:3269 Originate Resulted in Success: [loopback/voicemail-a] 2011-12-01 13:42:30.308562 [DEBUG] switch_core_session.c:726 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:30.308562 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:30.308562 [DEBUG] switch_core_session.c:726 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:30.308562 [DEBUG] switch_ivr_bridge.c:1270 (loopback/voicemail-a) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2011-12-01 13:42:30.308562 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:30.308562 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:30.308562 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-a) Running State Change CS_EXCHANGE_MEDIA 2011-12-01 13:42:30.308562 [DEBUG] switch_core_state_machine.c:420 (loopback/voicemail-a) State EXCHANGE_MEDIA 2011-12-01 13:42:30.308562 [DEBUG] mod_loopback.c:497 CHANNEL LOOPBACK 2011-12-01 13:42:30.398283 [DEBUG] switch_ivr_play_say.c:67 No language specified - Using [en] 2011-12-01 13:42:30.409312 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[voicemail/vm-person.wav] (en:en) 2011-12-01 13:42:30.409312 [DEBUG] switch_ivr_play_say.c:1302 Codec Activated L16@8000hz 1 channels 20ms 2011-12-01 13:42:31.798263 [DEBUG] switch_ivr_play_say.c:1672 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-person.wav 2011-12-01 13:42:31.898264 [DEBUG] switch_ivr_play_say.c:244 Handle say:[1001] (en:en) 2011-12-01 13:42:31.898264 [DEBUG] switch_ivr_play_say.c:1302 Codec Activated L16@8000hz 1 channels 20ms 2011-12-01 13:42:33.398281 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:33.418917 [DEBUG] switch_channel.c:2833 (sofia/internal/1004@connexur.dyndns.org) Callstate Change ACTIVE -> HANGUP 2011-12-01 13:42:33.418917 [NOTICE] sofia.c:572 Hangup sofia/internal/1004@connexur.dyndns.org [CS_EXECUTE] [NORMAL_CLEARING] 2011-12-01 13:42:33.418917 [DEBUG] switch_channel.c:2856 Send signal sofia/internal/1004@connexur.dyndns.org [KILL] 2011-12-01 13:42:33.418917 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:33.418917 [DEBUG] switch_ivr_bridge.c:586 BRIDGE THREAD DONE [sofia/internal/1004@connexur.dyndns.org] 2011-12-01 13:42:33.418917 [DEBUG] switch_ivr_bridge.c:611 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:33.418917 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_ivr_bridge.c:586 BRIDGE THREAD DONE [loopback/voicemail-a] 2011-12-01 13:42:33.438243 [DEBUG] switch_ivr_bridge.c:611 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:33.438243 [DEBUG] switch_ivr_bridge.c:586 BRIDGE THREAD DONE [loopback/voicemail-a] 2011-12-01 13:42:33.438243 [DEBUG] switch_ivr_bridge.c:611 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:33.438243 [DEBUG] switch_channel.c:2833 (loopback/voicemail-a) Callstate Change EARLY -> HANGUP 2011-12-01 13:42:33.438243 [NOTICE] switch_ivr_bridge.c:666 Hangup loopback/voicemail-a [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2011-12-01 13:42:33.438243 [DEBUG] switch_channel.c:2856 Send signal loopback/voicemail-a [KILL] 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:420 (loopback/voicemail-a) State EXCHANGE_MEDIA going to sleep 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-a) Running State Change CS_HANGUP 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:602 (loopback/voicemail-a) State HANGUP 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:427 loopback/voicemail-a CHANNEL HANGUP 2011-12-01 13:42:33.438243 [DEBUG] switch_channel.c:2833 (loopback/voicemail-b) Callstate Change EARLY -> HANGUP 2011-12-01 13:42:33.438243 [NOTICE] mod_loopback.c:438 Hangup loopback/voicemail-b [CS_EXECUTE] [NORMAL_CLEARING] 2011-12-01 13:42:33.438243 [DEBUG] switch_channel.c:2856 Send signal loopback/voicemail-b [KILL] 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:47 loopback/voicemail-a Standard HANGUP, cause: NORMAL_CLEARING 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:602 (loopback/voicemail-a) State HANGUP going to sleep 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:393 (loopback/voicemail-a) State Change CS_HANGUP -> CS_REPORTING 2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-a) Running State Change CS_REPORTING 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:662 (loopback/voicemail-a) State REPORTING 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:79 loopback/voicemail-a Standard REPORTING, cause: NORMAL_CLEARING 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:662 (loopback/voicemail-a) State REPORTING going to sleep 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:387 (loopback/voicemail-a) State Change CS_REPORTING -> CS_DESTROY 2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1377 Session 145 (loopback/voicemail-a) Locked, Waiting on external entities 2011-12-01 13:42:33.450220 [DEBUG] switch_ivr_bridge.c:1348 sofia/internal/1004@connexur.dyndns.org skip receive message [UNBRIDGE] (channel is hungup alrea$ 2011-12-01 13:42:33.450220 [DEBUG] switch_core_session.c:2272 sofia/internal/1004@connexur.dyndns.org skip receive message [APPLICATION_EXEC_COMPLETE] (chan$ 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/1004@connexur.dyndns.org) State EXECUTE going to sleep 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_HANGUP 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/1004@connexur.dyndns.org) State HANGUP 2011-12-01 13:42:33.450220 [DEBUG] mod_sofia.c:459 sofia/internal/1004@connexur.dyndns.org Overriding SIP cause 480 with 200 from the other leg 2011-12-01 13:42:33.450220 [DEBUG] mod_sofia.c:465 Channel sofia/internal/1004@connexur.dyndns.org hanging up, cause: NORMAL_CLEARING 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:47 sofia/internal/1004@connexur.dyndns.org Standard HANGUP, cause: NORMAL_CLEARING 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/1004@connexur.dyndns.org) State HANGUP going to sleep 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:393 (sofia/internal/1004@connexur.dyndns.org) State Change CS_HANGUP -> CS_REPORTING 2011-12-01 13:42:33.450220 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_REPORTING 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1004@connexur.dyndns.org) State REPORTING 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:79 sofia/internal/1004@connexur.dyndns.org Standard REPORTING, cause: NORMAL_CLEARING 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1004@connexur.dyndns.org) State REPORTING going to sleep 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:387 (sofia/internal/1004@connexur.dyndns.org) State Change CS_REPORTING -> CS_DESTROY 2011-12-01 13:42:33.450220 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:33.450220 [DEBUG] switch_core_session.c:1377 Session 144 (sofia/internal/1004@connexur.dyndns.org) Locked, Waiting on external entities 2011-12-01 13:42:33.450220 [NOTICE] switch_core_session.c:1395 Session 144 (sofia/internal/1004@connexur.dyndns.org) Ended 2011-12-01 13:42:33.450220 [NOTICE] switch_core_session.c:1397 Close Channel sofia/internal/1004@connexur.dyndns.org [CS_DESTROY] 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/1004@connexur.dyndns.org) Callstate Change HANGUP -> DOWN 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:494 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_DESTROY 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/1004@connexur.dyndns.org) State DESTROY 2011-12-01 13:42:33.450220 [DEBUG] mod_sofia.c:370 sofia/internal/1004@connexur.dyndns.org SOFIA DESTROY 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/1004@connexur.dyndns.org) State DESTROY 2011-12-01 13:42:33.450220 [DEBUG] mod_sofia.c:370 sofia/internal/1004@connexur.dyndns.org SOFIA DESTROY 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:86 sofia/internal/1004@connexur.dyndns.org Standard DESTROY 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/1004@connexur.dyndns.org) State DESTROY going to sleep 2011-12-01 13:42:33.458337 [DEBUG] switch_ivr_play_say.c:1672 done playing file file_string://digits/1.wav!digits/0.wav!digits/0.wav!digits/1.wav 2011-12-01 13:42:33.548273 [DEBUG] switch_core_session.c:2272 loopback/voicemail-b skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup alrea$ 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:417 (loopback/voicemail-b) State EXECUTE going to sleep 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-b) Running State Change CS_HANGUP 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:602 (loopback/voicemail-b) State HANGUP 2011-12-01 13:42:33.548273 [DEBUG] mod_loopback.c:427 loopback/voicemail-b CHANNEL HANGUP 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:47 loopback/voicemail-b Standard HANGUP, cause: NORMAL_CLEARING 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:602 (loopback/voicemail-b) State HANGUP going to sleep 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:393 (loopback/voicemail-b) State Change CS_HANGUP -> CS_REPORTING 2011-12-01 13:42:33.548273 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:33.548273 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-b) Running State Change CS_REPORTING 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:662 (loopback/voicemail-b) State REPORTING 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:79 loopback/voicemail-b Standard REPORTING, cause: NORMAL_CLEARING 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:662 (loopback/voicemail-b) State REPORTING going to sleep 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:387 (loopback/voicemail-b) State Change CS_REPORTING -> CS_DESTROY 2011-12-01 13:42:33.548273 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:33.548273 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:33.548273 [DEBUG] switch_core_session.c:1377 Session 146 (loopback/voicemail-b) Locked, Waiting on external entities 2011-12-01 13:42:33.548273 [NOTICE] switch_core_session.c:1395 Session 146 (loopback/voicemail-b) Ended 2011-12-01 13:42:33.548273 [NOTICE] switch_core_session.c:1397 Close Channel loopback/voicemail-b [CS_DESTROY] 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:491 (loopback/voicemail-b) Callstate Change HANGUP -> DOWN 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:494 (loopback/voicemail-b) Running State Change CS_DESTROY 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:504 (loopback/voicemail-b) State DESTROY 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:86 loopback/voicemail-b Standard DESTROY 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:504 (loopback/voicemail-b) State DESTROY going to sleep 2011-12-01 13:42:33.559551 [NOTICE] switch_core_session.c:1395 Session 145 (loopback/voicemail-a) Ended 2011-12-01 13:42:33.559551 [NOTICE] switch_core_session.c:1397 Close Channel loopback/voicemail-a [CS_DESTROY] 2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:491 (loopback/voicemail-a) Callstate Change HANGUP -> DOWN 2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:494 (loopback/voicemail-a) Running State Change CS_DESTROY 2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:504 (loopback/voicemail-a) State DESTROY 2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:86 loopback/voicemail-a Standard DESTROY 2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:504 (loopback/voicemail-a) State DESTROY going to sleep -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/Freeswitch-installed-ATA-regis... Sent from the freeswitch-users mailing list archive at Nabble.com.

On 01/12/11 13:37, Peter Olsson wrote:

I think this is fixed in latest git. I had a similar problem, and it was fixed yesterday.

/Peter

-----Ursprungligt meddelande----- Peter,

Yes, I just found FS3727. Cheers! Alex -- This message is intended only for the addressee and may contain confidential information. Unless you are that person, you may not disclose its contents or use it in any way and are requested to delete the message along with any attachments and notify us immediately. "Transact" is operated by Integrated Financial Arrangements plc Domain House, 5-7 Singer Street, London EC2A 4BQ Tel: (020) 7608 4900 Fax: (020) 7608 5300 (Registered office: as above; Registered in England and Wales under number: 3727592) Authorised and regulated by the Financial Services Authority (entered on the FSA Register; number: 190856)

I'm sorry but in my case, the phone that is called doesn't ring. It only goes to the voicemail -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/Freeswitch-installed-ATA-regis... Sent from the freeswitch-users mailing list archive at Nabble.com.

I think we need other kind of details... Logs, SIP traces etc.. :) /Peter -----Ursprungligt meddelande----- Från: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] För obbyone Skickat: den 2 december 2011 09:54 Till: freeswitch-users@lists.freeswitch.org Ämne: Re: [Freeswitch-users] Freeswitch installed, ATA registered but no call are possible... Hi, Just a detail. Freeswitch is running on a VMWare virtual machine. Is it the problem ? Thanks... -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/Freeswitch-installed-ATA-regis... Sent from the freeswitch-users mailing list archive at Nabble.com. _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com 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 !DSPAM:4ed8925932761429410865!

It's pretty clear in the logs :) The user is not registered (USER_NOT_REGISTERED). So you will need to get the user registered before calling it. /Peter -----Ursprungligt meddelande----- Från: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] För obbyone Skickat: den 2 december 2011 10:15 Till: freeswitch-users@lists.freeswitch.org Ämne: Re: [Freeswitch-users] Freeswitch installed, ATA registered but no call are possible... Hi, Logs have already been sent on my second message. I send it back here (thanks) : 2011-12-01 13:42:18.918274 [DEBUG] sofia.c:7267 IP 90.36.1.89 Rejected by acl "domains". Falling back to Digest auth. 2011-12-01 13:42:29.258256 [DEBUG] sofia.c:7267 IP 90.36.1.89 Rejected by acl "domains". Falling back to Digest auth. 2011-12-01 13:42:29.258256 [NOTICE] switch_channel.c:920 New Channel sofia/internal/1004@connexur.dyndns.org [ee2049ee-1c19-11e1-abcd-1f494360f62d] 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_NEW 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:380 (sofia/internal/1004@connexur.dyndns.org) State NEW 2011-12-01 13:42:29.268425 [DEBUG] sofia.c:8186 Setting NAT mode based on nat.auto 2011-12-01 13:42:29.268425 [DEBUG] sofia.c:5282 Channel sofia/internal/1004@connexur.dyndns.org entering state [received][100] 2011-12-01 13:42:29.268425 [DEBUG] sofia.c:5293 Remote SDP: v=0 o=- 9 2 IN IP4 192.168.1.10 s=CounterPath X-Lite 3.0 c=IN IP4 192.168.1.10 t=0 0 m=audio 64860 RTP/AVP 107 119 0 98 8 3 101 a=rtpmap:107 BV32/16000 a=rtpmap:119 BV32-FEC/16000 a=rtpmap:98 iLBC/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=alt:1 1 : PBDGzwKZ EILmrBFJ 192.168.1.10 64860 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[G7221:115:32000:20:48000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[G7221:107:16000:20:32000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[G722:9:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[PCMU:0:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[PCMA:8:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[GSM:3:8000:20:13200] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[PCMA:8:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32:107:16000:20:0]/[GSM:3:8000:20:13200] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32-FEC:119:16000:20:0]/[G7221:115:32000:20:48000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32-FEC:119:16000:20:0]/[G7221:107:16000:20:32000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32-FEC:119:16000:20:0]/[G722:9:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32-FEC:119:16000:20:0]/[PCMU:0:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32-FEC:119:16000:20:0]/[PCMA:8:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [BV32-FEC:119:16000:20:0]/[GSM:3:8000:20:13200] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [PCMU:0:8000:20:64000]/[G7221:115:32000:20:48000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [PCMU:0:8000:20:64000]/[G7221:107:16000:20:32000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:2864 Set Codec sofia/internal/1004@connexur.dyndns.org PCMU/8000 20 ms 160 samples 64000 bits 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4871 Set 2833 dtmf send/recv payload to 101 2011-12-01 13:42:29.268425 [DEBUG] sofia.c:5505 (sofia/internal/1004@connexur.dyndns.org) State Change CS_NEW -> CS_INIT 2011-12-01 13:42:29.268425 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_INIT 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/1004@connexur.dyndns.org) State INIT 2011-12-01 13:42:29.268425 [DEBUG] mod_sofia.c:85 sofia/internal/1004@connexur.dyndns.org SOFIA INIT 2011-12-01 13:42:29.268425 [DEBUG] mod_sofia.c:125 (sofia/internal/1004@connexur.dyndns.org) State Change CS_INIT -> CS_ROUTING 2011-12-01 13:42:29.268425 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/1004@connexur.dyndns.org) State INIT going to sleep 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_ROUTING 2011-12-01 13:42:29.268425 [DEBUG] switch_channel.c:1871 (sofia/internal/1004@connexur.dyndns.org) Callstate Change DOWN -> RINGING 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/1004@connexur.dyndns.org) State ROUTING 2011-12-01 13:42:29.268425 [DEBUG] mod_sofia.c:148 sofia/internal/1004@connexur.dyndns.org SOFIA ROUTING 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1004@connexur.dyndns.org Standard ROUTING 2011-12-01 13:42:29.268425 [INFO] mod_dialplan_xml.c:481 Processing 1004 <1004>->1001 in context default Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->unloop] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->tod_example] continue=true Dialplan: sofia/internal/1004@connexur.dyndns.org Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(open=true) Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->holiday_example] continue=true Dialplan: sofia/internal/1004@connexur.dyndns.org Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [global-intercept] destination_number(1001) =~ /^886$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->redial] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [redial] destination_number(1001) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->global] continue=true Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=n$ Dialplan: sofia/internal/1004@connexur.dyndns.org Absolute Condition [global] Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [snom-demo-1] destination_number(1001) =~ /^9000$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^779$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->call_return] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [call_return] destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->del-group] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [del-group] destination_number(1001) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->add-group] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [add-group] destination_number(1001) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [call-group-simo] destination_number(1001) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [call-group-order] destination_number(1001) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (FAIL) [extension-intercom] destination_number(1001) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/1004@connexur.dyndns.org Regex (PASS) [Local_Extension] destination_number(1001) =~ /^(10[01][0-9]|1100)$/ break=on-false Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(dialed_extension=1001) Dialplan: sofia/internal/1004@connexur.dyndns.org Action export(dialed_extension=1001) Dialplan: sofia/internal/1004@connexur.dyndns.org Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/1004@connexur.dyndns.org Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime$ Dialplan: sofia/internal/1004@connexur.dyndns.org Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/1004@connexur.dyndns.org Action bind_meta_app(4 b s execute_extension::att_xfer XML features) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(ringback=${us-ring}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(call_timeout=30) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(hangup_after_bridge=true) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(continue_on_fail=true) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-last_dial_ext/global/${uuid}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/internal/1004@connexur.dyndns.org Action answer() Dialplan: sofia/internal/1004@connexur.dyndns.org Action sleep(1000) Dialplan: sofia/internal/1004@connexur.dyndns.org Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension}) 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:154 (sofia/internal/1004@connexur.dyndns.org) State Change CS_ROUTING -> CS_EXECUTE 2011-12-01 13:42:29.268425 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/1004@connexur.dyndns.org) State ROUTING going to sleep 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_EXECUTE 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/1004@connexur.dyndns.org) State EXECUTE 2011-12-01 13:42:29.268425 [DEBUG] mod_sofia.c:241 sofia/internal/1004@connexur.dyndns.org SOFIA EXECUTE 2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:192 sofia/internal/1004@connexur.dyndns.org Standard EXECUTE EXECUTE sofia/internal/1004@connexur.dyndns.org set(open=true) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [open]=[true] EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-spymap/1004/ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial/1004/1001) EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial/global/ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org set(RFC2822_DATE=Thu, 01 Dec 2011 13:42:29 +0100) EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial/global/ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org set(RFC2822_DATE=Thu, 01 Dec 2011 13:42:29 +0100) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [RFC2822_DATE]=[Thu, 01 Dec 2011 13:42:29 +0100] EXECUTE sofia/internal/1004@connexur.dyndns.org set(dialed_extension=1001) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [dialed_extension]=[1001] EXECUTE sofia/internal/1004@connexur.dyndns.org export(dialed_extension=1001) 2011-12-01 13:42:29.268425 [DEBUG] switch_channel.c:1087 EXPORT (export_vars) [dialed_extension]=[1001] EXECUTE sofia/internal/1004@connexur.dyndns.org bind_meta_app(1 b s execute_extension::dx XML features) 2011-12-01 13:42:29.268425 [INFO] switch_ivr_async.c:3130 Bound B-Leg: *1 execute_extension::dx XML features EXECUTE sofia/internal/1004@connexur.dyndns.org bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1004.2011-12-01-13-42-29.wav) 2011-12-01 13:42:29.268425 [INFO] switch_ivr_async.c:3130 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1004.2011-12-01-13-42-29.wav EXECUTE sofia/internal/1004@connexur.dyndns.org bind_meta_app(3 b s execute_extension::cf XML features) 2011-12-01 13:42:29.268425 [INFO] switch_ivr_async.c:3130 Bound B-Leg: *3 execute_extension::cf XML features EXECUTE sofia/internal/1004@connexur.dyndns.org bind_meta_app(4 b s execute_extension::att_xfer XML features) 2011-12-01 13:42:29.268425 [INFO] switch_ivr_async.c:3130 Bound B-Leg: *4 execute_extension::att_xfer XML features EXECUTE sofia/internal/1004@connexur.dyndns.org set(ringback=%(2000,4000,440.0,480.0)) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [ringback]=[%(2000,4000,440.0,480.0)] EXECUTE sofia/internal/1004@connexur.dyndns.org set(transfer_ringback=local_stream://moh) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/1004@connexur.dyndns.org set(call_timeout=30) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [call_timeout]=[30] EXECUTE sofia/internal/1004@connexur.dyndns.org set(hangup_after_bridge=true) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/1004@connexur.dyndns.org set(continue_on_fail=true) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [continue_on_fail]=[true] EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-call_return/1001/1004) EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial_ext/1001/ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial_ext//ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial_ext/global/ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org set(called_party_callgroup=techsupport) 2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204 sofia/internal/1004@connexur.dyndns.org SET [called_party_callgroup]=[techsupport] EXECUTE sofia/internal/1004@connexur.dyndns.org hash(insert/91.204.116.116-last_dial/techsupport/ee2049ee-1c19-11e1-abcd-1f494360f62d) EXECUTE sofia/internal/1004@connexur.dyndns.org bridge(user/1001@91.204.116.116) 2011-12-01 13:42:29.268425 [DEBUG] switch_channel.c:1041 sofia/internal/1004@connexur.dyndns.org EXPORTING[export_vars] [dialed_extension]=[1001] to event 2011-12-01 13:42:29.268425 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables 2011-12-01 13:42:29.268425 [DEBUG] switch_channel.c:1041 sofia/internal/1004@connexur.dyndns.org EXPORTING[export_vars] [dialed_extension]=[1001] to event 2011-12-01 13:42:29.268425 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables 2011-12-01 13:42:29.268425 [DEBUG] switch_event.c:1521 Parsing variable [sip_invite_domain]=[91.204.116.116] 2011-12-01 13:42:29.268425 [DEBUG] switch_event.c:1521 Parsing variable [presence_id]=[1001@91.204.116.116] 2011-12-01 13:42:29.268425 [NOTICE] switch_ivr_originate.c:2459 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED] 2011-12-01 13:42:29.268425 [DEBUG] switch_ivr_originate.c:3367 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED] 2011-12-01 13:42:29.268425 [NOTICE] switch_ivr_originate.c:2459 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED] 2011-12-01 13:42:29.268425 [DEBUG] switch_ivr_originate.c:3367 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED] 2011-12-01 13:42:29.268425 [INFO] mod_dptools.c:2838 Originate Failed. Cause: USER_NOT_REGISTERED EXECUTE sofia/internal/1004@connexur.dyndns.org answer() 2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:3116 AUDIO RTP [sofia/internal/1004@connexur.dyndns.org] 91.204.116.116 port 21454 -> 192.168.1.10 port 6486$ 2011-12-01 13:42:29.268425 [DEBUG] switch_rtp.c:1642 Starting timer [soft] 160 bytes per 20ms 2011-12-01 13:42:29.293791 [DEBUG] sofia_glue.c:3382 Set 2833 dtmf send payload to 101 2011-12-01 13:42:29.293791 [DEBUG] sofia_glue.c:3388 Set 2833 dtmf receive payload to 101 2011-12-01 13:42:29.293791 [DEBUG] mod_sofia.c:746 Local SDP sofia/internal/1004@connexur.dyndns.org: v=0 o=FreeSWITCH 1322721895 1322721896 IN IP4 91.204.116.116 s=FreeSWITCH c=IN IP4 91.204.116.116 t=0 0 c=IN IP4 91.204.116.116 t=0 0 m=audio 21454 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 2011-12-01 13:42:29.293791 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.293791 [DEBUG] sofia.c:5282 Channel sofia/internal/1004@connexur.dyndns.org entering state [completed][200] 2011-12-01 13:42:29.293791 [DEBUG] switch_core_session.c:726 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.293791 [DEBUG] switch_channel.c:3175 (sofia/internal/1004@connexur.dyndns.org) Callstate Change RINGING -> ACTIVE 2011-12-01 13:42:29.293791 [NOTICE] mod_dptools.c:1071 Channel [sofia/internal/1004@connexur.dyndns.org] has been answered EXECUTE sofia/internal/1004@connexur.dyndns.org sleep(1000) 2011-12-01 13:42:29.568264 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.568264 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.568264 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:29.578421 [DEBUG] sofia.c:5282 Channel sofia/internal/1004@connexur.dyndns.org entering state [ready][200] 2011-12-01 13:42:29.658301 [INFO] switch_rtp.c:3170 Auto Changing port from 192.168.1.10:64860 to 90.36.1.89:64860 EXECUTE sofia/internal/1004@connexur.dyndns.org bridge(loopback/app=voicemail:default 91.204.116.116 1001) 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:1041 sofia/internal/1004@connexur.dyndns.org EXPORTING[export_vars] [dialed_extension]=[1001] to event 2011-12-01 13:42:30.298263 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables 2011-12-01 13:42:30.298263 [NOTICE] switch_channel.c:920 New Channel loopback/app=voicemail:default 91.204.116.116 1001-a [eebdaf40-1c19-11e1-abd8-1f494360f$ 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:145 loopback/app=voicemail:default 91.204.116.116 1001-a setup codec PCMU/8000/20 2011-12-01 13:42:30.298263 [NOTICE] switch_channel.c:918 Rename Channel loopback/app=voicemail:default 91.204.116.116 1001-a->loopback/voicemail-a [eebdaf40$ 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:973 (loopback/voicemail-a) State Change CS_NEW -> CS_INIT 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-a) Running State Change CS_INIT 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:401 (loopback/voicemail-a) State INIT 2011-12-01 13:42:30.298263 [NOTICE] switch_channel.c:920 New Channel loopback/voicemail-b [eebdc6ba-1c19-11e1-abdc-1f494360f62d] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:145 loopback/voicemail-b setup codec PCMU/8000/20 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:258 (loopback/voicemail-b) State Change CS_NEW -> CS_INIT 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-b) Running State Change CS_INIT 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:401 (loopback/voicemail-b) State INIT 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:304 (loopback/voicemail-b) State Change CS_INIT -> CS_ROUTING 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:401 (loopback/voicemail-b) State INIT going to sleep 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-b) Running State Change CS_ROUTING 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:1871 (loopback/voicemail-b) Callstate Change DOWN -> RINGING 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:410 (loopback/voicemail-b) State ROUTING 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:336 loopback/voicemail-b CHANNEL ROUTING 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:355 (loopback/voicemail-b) State Change CS_ROUTING -> CS_EXECUTE 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:410 (loopback/voicemail-b) State ROUTING going to sleep 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-b) Running State Change CS_EXECUTE 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:417 (loopback/voicemail-b) State EXECUTE 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:375 loopback/voicemail-b CHANNEL EXECUTE 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:192 loopback/voicemail-b Standard EXECUTE 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:375 loopback/voicemail-b CHANNEL EXECUTE 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:192 loopback/voicemail-b Standard EXECUTE EXECUTE loopback/voicemail-b pre_answer() 2011-12-01 13:42:30.298263 [NOTICE] mod_loopback.c:760 Pre-Answer loopback/voicemail-a! 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:2917 (loopback/voicemail-a) Callstate Change DOWN -> EARLY 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:2959 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:726 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:30.298263 [NOTICE] mod_dptools.c:1097 Pre-Answer loopback/voicemail-b! 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:2917 (loopback/voicemail-b) Callstate Change RINGING -> EARLY 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:2959 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] EXECUTE loopback/voicemail-b voicemail(default 91.204.116.116 1001) 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:304 (loopback/voicemail-a) State Change CS_INIT -> CS_ROUTING 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:401 (loopback/voicemail-a) State INIT going to sleep 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-a) Running State Change CS_ROUTING 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:1871 (loopback/voicemail-a) Callstate Change EARLY -> RINGING 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:410 (loopback/voicemail-a) State ROUTING 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:336 loopback/voicemail-a CHANNEL ROUTING 2011-12-01 13:42:30.298263 [DEBUG] switch_ivr_originate.c:66 (loopback/voicemail-a) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:410 (loopback/voicemail-a) State ROUTING going to sleep 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-a) Running State Change CS_CONSUME_MEDIA 2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:1875 (loopback/voicemail-a) Callstate Change RINGING -> EARLY 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:429 (loopback/voicemail-a) State CONSUME_MEDIA 2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:535 CHANNEL CONSUME_MEDIA 2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:429 (loopback/voicemail-a) State CONSUME_MEDIA going to sleep 2011-12-01 13:42:30.308562 [DEBUG] switch_ivr_originate.c:3269 Originate Resulted in Success: [loopback/voicemail-a] 2011-12-01 13:42:30.308562 [DEBUG] switch_core_session.c:726 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:30.308562 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:30.308562 [DEBUG] switch_core_session.c:726 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:30.308562 [DEBUG] switch_ivr_bridge.c:1270 (loopback/voicemail-a) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2011-12-01 13:42:30.308562 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:30.308562 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:30.308562 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-a) Running State Change CS_EXCHANGE_MEDIA 2011-12-01 13:42:30.308562 [DEBUG] switch_core_state_machine.c:420 (loopback/voicemail-a) State EXCHANGE_MEDIA 2011-12-01 13:42:30.308562 [DEBUG] mod_loopback.c:497 CHANNEL LOOPBACK 2011-12-01 13:42:30.398283 [DEBUG] switch_ivr_play_say.c:67 No language specified - Using [en] 2011-12-01 13:42:30.409312 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[voicemail/vm-person.wav] (en:en) 2011-12-01 13:42:30.409312 [DEBUG] switch_ivr_play_say.c:1302 Codec Activated L16@8000hz 1 channels 20ms 2011-12-01 13:42:31.798263 [DEBUG] switch_ivr_play_say.c:1672 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-person.wav 2011-12-01 13:42:31.898264 [DEBUG] switch_ivr_play_say.c:244 Handle say:[1001] (en:en) 2011-12-01 13:42:31.898264 [DEBUG] switch_ivr_play_say.c:1302 Codec Activated L16@8000hz 1 channels 20ms 2011-12-01 13:42:33.398281 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:33.418917 [DEBUG] switch_channel.c:2833 (sofia/internal/1004@connexur.dyndns.org) Callstate Change ACTIVE -> HANGUP 2011-12-01 13:42:33.418917 [NOTICE] sofia.c:572 Hangup sofia/internal/1004@connexur.dyndns.org [CS_EXECUTE] [NORMAL_CLEARING] 2011-12-01 13:42:33.418917 [DEBUG] switch_channel.c:2856 Send signal sofia/internal/1004@connexur.dyndns.org [KILL] 2011-12-01 13:42:33.418917 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:33.418917 [DEBUG] switch_ivr_bridge.c:586 BRIDGE THREAD DONE [sofia/internal/1004@connexur.dyndns.org] 2011-12-01 13:42:33.418917 [DEBUG] switch_ivr_bridge.c:611 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:33.418917 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_ivr_bridge.c:586 BRIDGE THREAD DONE [loopback/voicemail-a] 2011-12-01 13:42:33.438243 [DEBUG] switch_ivr_bridge.c:611 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:33.438243 [DEBUG] switch_ivr_bridge.c:586 BRIDGE THREAD DONE [loopback/voicemail-a] 2011-12-01 13:42:33.438243 [DEBUG] switch_ivr_bridge.c:611 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:33.438243 [DEBUG] switch_channel.c:2833 (loopback/voicemail-a) Callstate Change EARLY -> HANGUP 2011-12-01 13:42:33.438243 [NOTICE] switch_ivr_bridge.c:666 Hangup loopback/voicemail-a [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2011-12-01 13:42:33.438243 [DEBUG] switch_channel.c:2856 Send signal loopback/voicemail-a [KILL] 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:420 (loopback/voicemail-a) State EXCHANGE_MEDIA going to sleep 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-a) Running State Change CS_HANGUP 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:602 (loopback/voicemail-a) State HANGUP 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:427 loopback/voicemail-a CHANNEL HANGUP 2011-12-01 13:42:33.438243 [DEBUG] switch_channel.c:2833 (loopback/voicemail-b) Callstate Change EARLY -> HANGUP 2011-12-01 13:42:33.438243 [NOTICE] mod_loopback.c:438 Hangup loopback/voicemail-b [CS_EXECUTE] [NORMAL_CLEARING] 2011-12-01 13:42:33.438243 [DEBUG] switch_channel.c:2856 Send signal loopback/voicemail-b [KILL] 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:47 loopback/voicemail-a Standard HANGUP, cause: NORMAL_CLEARING 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:602 (loopback/voicemail-a) State HANGUP going to sleep 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:393 (loopback/voicemail-a) State Change CS_HANGUP -> CS_REPORTING 2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-a) Running State Change CS_REPORTING 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:662 (loopback/voicemail-a) State REPORTING 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:79 loopback/voicemail-a Standard REPORTING, cause: NORMAL_CLEARING 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:662 (loopback/voicemail-a) State REPORTING going to sleep 2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:387 (loopback/voicemail-a) State Change CS_REPORTING -> CS_DESTROY 2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-a [BREAK] 2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-a CHANNEL KILL 2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1377 Session 145 (loopback/voicemail-a) Locked, Waiting on external entities 2011-12-01 13:42:33.450220 [DEBUG] switch_ivr_bridge.c:1348 sofia/internal/1004@connexur.dyndns.org skip receive message [UNBRIDGE] (channel is hungup alrea$ 2011-12-01 13:42:33.450220 [DEBUG] switch_core_session.c:2272 sofia/internal/1004@connexur.dyndns.org skip receive message [APPLICATION_EXEC_COMPLETE] (chan$ 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/1004@connexur.dyndns.org) State EXECUTE going to sleep 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_HANGUP 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/1004@connexur.dyndns.org) State HANGUP 2011-12-01 13:42:33.450220 [DEBUG] mod_sofia.c:459 sofia/internal/1004@connexur.dyndns.org Overriding SIP cause 480 with 200 from the other leg 2011-12-01 13:42:33.450220 [DEBUG] mod_sofia.c:465 Channel sofia/internal/1004@connexur.dyndns.org hanging up, cause: NORMAL_CLEARING 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:47 sofia/internal/1004@connexur.dyndns.org Standard HANGUP, cause: NORMAL_CLEARING 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/1004@connexur.dyndns.org) State HANGUP going to sleep 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:393 (sofia/internal/1004@connexur.dyndns.org) State Change CS_HANGUP -> CS_REPORTING 2011-12-01 13:42:33.450220 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_REPORTING 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1004@connexur.dyndns.org) State REPORTING 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:79 sofia/internal/1004@connexur.dyndns.org Standard REPORTING, cause: NORMAL_CLEARING 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1004@connexur.dyndns.org) State REPORTING going to sleep 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:387 (sofia/internal/1004@connexur.dyndns.org) State Change CS_REPORTING -> CS_DESTROY 2011-12-01 13:42:33.450220 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1004@connexur.dyndns.org [BREAK] 2011-12-01 13:42:33.450220 [DEBUG] switch_core_session.c:1377 Session 144 (sofia/internal/1004@connexur.dyndns.org) Locked, Waiting on external entities 2011-12-01 13:42:33.450220 [NOTICE] switch_core_session.c:1395 Session 144 (sofia/internal/1004@connexur.dyndns.org) Ended 2011-12-01 13:42:33.450220 [NOTICE] switch_core_session.c:1397 Close Channel sofia/internal/1004@connexur.dyndns.org [CS_DESTROY] 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/1004@connexur.dyndns.org) Callstate Change HANGUP -> DOWN 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:494 (sofia/internal/1004@connexur.dyndns.org) Running State Change CS_DESTROY 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/1004@connexur.dyndns.org) State DESTROY 2011-12-01 13:42:33.450220 [DEBUG] mod_sofia.c:370 sofia/internal/1004@connexur.dyndns.org SOFIA DESTROY 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/1004@connexur.dyndns.org) State DESTROY 2011-12-01 13:42:33.450220 [DEBUG] mod_sofia.c:370 sofia/internal/1004@connexur.dyndns.org SOFIA DESTROY 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:86 sofia/internal/1004@connexur.dyndns.org Standard DESTROY 2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/1004@connexur.dyndns.org) State DESTROY going to sleep 2011-12-01 13:42:33.458337 [DEBUG] switch_ivr_play_say.c:1672 done playing file file_string://digits/1.wav!digits/0.wav!digits/0.wav!digits/1.wav 2011-12-01 13:42:33.548273 [DEBUG] switch_core_session.c:2272 loopback/voicemail-b skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup alrea$ 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:417 (loopback/voicemail-b) State EXECUTE going to sleep 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-b) Running State Change CS_HANGUP 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:602 (loopback/voicemail-b) State HANGUP 2011-12-01 13:42:33.548273 [DEBUG] mod_loopback.c:427 loopback/voicemail-b CHANNEL HANGUP 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:47 loopback/voicemail-b Standard HANGUP, cause: NORMAL_CLEARING 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:602 (loopback/voicemail-b) State HANGUP going to sleep 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:393 (loopback/voicemail-b) State Change CS_HANGUP -> CS_REPORTING 2011-12-01 13:42:33.548273 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:33.548273 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:362 (loopback/voicemail-b) Running State Change CS_REPORTING 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:662 (loopback/voicemail-b) State REPORTING 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:79 loopback/voicemail-b Standard REPORTING, cause: NORMAL_CLEARING 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:662 (loopback/voicemail-b) State REPORTING going to sleep 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:387 (loopback/voicemail-b) State Change CS_REPORTING -> CS_DESTROY 2011-12-01 13:42:33.548273 [DEBUG] switch_core_session.c:1177 Send signal loopback/voicemail-b [BREAK] 2011-12-01 13:42:33.548273 [DEBUG] mod_loopback.c:475 loopback/voicemail-b CHANNEL KILL 2011-12-01 13:42:33.548273 [DEBUG] switch_core_session.c:1377 Session 146 (loopback/voicemail-b) Locked, Waiting on external entities 2011-12-01 13:42:33.548273 [NOTICE] switch_core_session.c:1395 Session 146 (loopback/voicemail-b) Ended 2011-12-01 13:42:33.548273 [NOTICE] switch_core_session.c:1397 Close Channel loopback/voicemail-b [CS_DESTROY] 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:491 (loopback/voicemail-b) Callstate Change HANGUP -> DOWN 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:494 (loopback/voicemail-b) Running State Change CS_DESTROY 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:504 (loopback/voicemail-b) State DESTROY 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:86 loopback/voicemail-b Standard DESTROY 2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:504 (loopback/voicemail-b) State DESTROY going to sleep 2011-12-01 13:42:33.559551 [NOTICE] switch_core_session.c:1395 Session 145 (loopback/voicemail-a) Ended 2011-12-01 13:42:33.559551 [NOTICE] switch_core_session.c:1397 Close Channel loopback/voicemail-a [CS_DESTROY] 2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:491 (loopback/voicemail-a) Callstate Change HANGUP -> DOWN 2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:494 (loopback/voicemail-a) Running State Change CS_DESTROY 2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:504 (loopback/voicemail-a) State DESTROY 2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:86 loopback/voicemail-a Standard DESTROY 2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:504 (loopback/voicemail-a) State DESTROY going to sleep ... -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/Freeswitch-installed-ATA-regis... Sent from the freeswitch-users mailing list archive at Nabble.com. _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com 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 !DSPAM:4ed8965c32769010918511!

On 03/12/11 16:31, obbyone wrote:

Hi,

The trace I gave was not a good one. The one I show now Is a good sample. Any attempt to dial "1001" results only in a response by voicemail. Any answer ?

Thanks

<trace snipped> From your trace, it looks like your ATAs are connecting to your external profile (something.dyndns.org:5080). Are you trying to connect your ATAs somewhere "out on the internet", possibly NAT'ed to a NAT'ed or otherwise Freeswitch server? If the ATAs are on the LAN local to your FS box you should be using the internal profile and default SIP port of 5060 on the ATAs. If so you need to read up on the NAT scenarios if you don't UPNP compatible routers at both ends of the connection (or don't want to use STUN at both ends). It's tricky but it is possible to get it working even with NAT on both sides. I just got it working. Cheers Alex

On 06/12/11 16:50, obbyone wrote:

Hi, In fact, freeswitch is installed on a virtual serveur (VMWare) that has a fixed external IP. Every ATA's are behind a different ADSL modem same as if it was also on an external IP. I'm a newbie on freeswitch so is there someone who can take me by the hand and help me to handle this issue...

Thanks

Hi, Does the FS VM have a fixed IP or is it natted? I suspect the latter. I would follow the guide on the Wiki about "NAT scenarios", specifically the one about double NAT. You will need to create another profile for this: http://wiki.freeswitch.org/wiki/General_NAT_example_scenarios You also need to forward your chosen SIP port for the profile (eg 5090) and the RTP ports (16384-32768) to the real IP of the FS VM. Cheers Alex -- This message is intended only for the addressee and may contain confidential information. Unless you are that person, you may not disclose its contents or use it in any way and are requested to delete the message along with any attachments and notify us immediately. "Transact" is operated by Integrated Financial Arrangements plc Domain House, 5-7 Singer Street, London EC2A 4BQ Tel: (020) 7608 4900 Fax: (020) 7608 5300 (Registered office: as above; Registered in England and Wales under number: 3727592) Authorised and regulated by the Financial Services Authority (entered on the FSA Register; number: 190856)

On 06/12/11 23:07, obbyone wrote:

Alex Crow wrote

...

On 06/12/11 16:50, obbyone wrote:

...

Hi, In fact, freeswitch is installed on a virtual serveur (VMWare) that has a fixed external IP. Every ATA's are behind a different ADSL modem same as if it was also on an external IP. I'm a newbie on freeswitch so is there someone who can take me by the hand and help me to handle this issue...

Thanks Hi,

Does the FS VM have a fixed IP or is it natted?

I suspect the latter. I would follow the guide on the Wiki about "NAT scenarios", specifically the one about double NAT. You will need to create another profile for this: http://wiki.freeswitch.org/wiki/General_NAT_example_scenarios

You also need to forward your chosen SIP port for the profile (eg 5090) and the RTP ports (16384-32768) to the real IP of the FS VM.

Cheers

Alex

-- This message is intended only for the addressee and may contain confidential information. Unless you are that person, you may not disclose its contents or use it in any way and are requested to delete the message along with any attachments and notify us immediately.

"Transact" is operated by Integrated Financial Arrangements plc Domain House, 5-7 Singer Street, London EC2A 4BQ Tel: (020) 7608 4900 Fax: (020) 7608 5300 (Registered office: as above; Registered in England and Wales under number: 3727592) Authorised and regulated by the Financial Services Authority (entered on the FSA Register; number: 190856)

_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@ http://www.freeswitchsolutions.com

FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com

Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com

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

In my case the FS VM has a fixed IP. Do I have to follow the same advice ?

Thanks

Sorry, I was unclear. I meant a private (RFC1918) IP. If it does, you will have to follow the double-nat scenario (unless the routing on VMWare (is it ESXi?) supports uPNP or NAT-PMP). If you can give the VM a *public* IP, you don't need to do that, then you only have to worry about NAT traversal at the ATA end. Cheers Alex -- This message is intended only for the addressee and may contain confidential information. Unless you are that person, you may not disclose its contents or use it in any way and are requested to delete the message along with any attachments and notify us immediately. "Transact" is operated by Integrated Financial Arrangements plc Domain House, 5-7 Singer Street, London EC2A 4BQ Tel: (020) 7608 4900 Fax: (020) 7608 5300 (Registered office: as above; Registered in England and Wales under number: 3727592) Authorised and regulated by the Financial Services Authority (entered on the FSA Register; number: 190856)