Hello, here is the complete Log of the relevant part:
[EMAIL PROTECTED]> 2008-11-10 18:12:56 [DEBUG] sofia.c:3467 sofia_handle_sip_i_invite() IP xxx.xx.xx.186 Rejected by acl "domains". Falling back to Digest auth. 2008-11-10 18:12:56 [DEBUG] sofia.c:3467 sofia_handle_sip_i_invite() IP xxx.xx.xx.186 Rejected by acl "domains". Falling back to Digest auth. 2008-11-10 18:12:56 [NOTICE] switch_channel.c:551 switch_channel_set_name() New Channel sofia/internal/[EMAIL PROTECTED] [d1508d5e-af4a-11dd-8f85-c9d27628b1ff] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:372 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) Running State Change CS_NEW 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:376 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State NEW 2008-11-10 18:12:56 [DEBUG] sofia.c:2285 sofia_handle_sip_i_state() Channel sofia/internal/[EMAIL PROTECTED] entering state [received] 2008-11-10 18:12:56 [DEBUG] sofia.c:2289 sofia_handle_sip_i_state() Remote SDP: v=0 o=root 289593248 289593248 IN IP4 xxx.xx.xx.186 s=call c=IN IP4 xxx.xx.xx.186 t=0 0 m=audio 12928 RTP/AVP 8 0 9 2 3 18 4 101 a=rtpmap:8 pcma/8000 a=rtpmap:0 pcmu/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 2008-11-10 18:12:56 [DEBUG] sofia_glue.c:2360 sofia_glue_negotiate_sdp() Audio Codec Compare [pcma:8:8000]/[G722:9:8000] 2008-11-10 18:12:56 [DEBUG] sofia_glue.c:2360 sofia_glue_negotiate_sdp() Audio Codec Compare [pcma:8:8000]/[PCMU:0:8000] 2008-11-10 18:12:56 [DEBUG] sofia_glue.c:2360 sofia_glue_negotiate_sdp() Audio Codec Compare [pcma:8:8000]/[PCMA:8:8000] 2008-11-10 18:12:56 [DEBUG] sofia_glue.c:1571 sofia_glue_tech_set_codec() Set Codec sofia/internal/[EMAIL PROTECTED] PCMA/8000 20 ms 160 samples 2008-11-10 18:12:56 [DEBUG] sofia_glue.c:2324 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2008-11-10 18:12:56 [DEBUG] sofia.c:2430 sofia_handle_sip_i_state() (sofia/internal/[EMAIL PROTECTED]) State Change CS_NEW -> CS_INIT 2008-11-10 18:12:56 [DEBUG] switch_core_session.c:776 switch_core_session_signal_state_change() Send signal sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:372 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) Running State Change CS_INIT 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:420 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State INIT 2008-11-10 18:12:56 [DEBUG] mod_sofia.c:83 sofia_on_init() sofia/internal/[EMAIL PROTECTED] SOFIA INIT 2008-11-10 18:12:56 [DEBUG] mod_sofia.c:111 sofia_on_init() (sofia/internal/[EMAIL PROTECTED]) State Change CS_INIT -> CS_ROUTING 2008-11-10 18:12:56 [DEBUG] switch_core_session.c:776 switch_core_session_signal_state_change() Send signal sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:420 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State INIT going to sleep 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:372 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) Running State Change CS_ROUTING 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:423 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State ROUTING 2008-11-10 18:12:56 [DEBUG] mod_sofia.c:130 sofia_on_routing() sofia/internal/[EMAIL PROTECTED] SOFIA ROUTING 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:64 switch_core_standard_on_routing() sofia/internal/[EMAIL PROTECTED] Standard ROUTING 2008-11-10 18:12:56 [INFO] mod_dialplan_xml.c:233 dialplan_hunt() Processing Customer1000->1001 in context default 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [unloop] true() =~ /^true$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [set_domain] ${domain_name}(my.domain.de) =~ /^$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [tod_example] ${strftime(%w)}(1) =~ /^([1-5])$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [tod_example] ${strftime(%H%M)}(1812) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [Long Distance] destination_number(1001) =~ /^(0[2-9]\d{4,13})$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [global-intercept] destination_number(1001) =~ /^886$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [group-intercept] destination_number(1001) =~ /^\*8$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [redial] destination_number(1001) =~ /^870$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [global] ${network_addr}(xxx.xx.xx.186) =~ /^$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [global] ${numbering_plan}() =~ /^$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [global] false() =~ /^true$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [snom-demo-2] destination_number(1001) =~ /^9001$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [snom-demo-1] destination_number(1001) =~ /^9000$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [eavesdrop] destination_number(1001) =~ /^88(.*)$|^\*0(.*)$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [eavesdrop] destination_number(1001) =~ /^779$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [call_return] destination_number(1001) =~ /^\*69$|^869$|^lcr$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [del-group] destination_number(1001) =~ /^80(\d{2})$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [add-group] destination_number(1001) =~ /^81(\d{2})$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [call-group-simo] destination_number(1001) =~ /^82(\d{2})$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [call-group-order] destination_number(1001) =~ /^83(\d{2})$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [extension-intercom] destination_number(1001) =~ /^8(10[01][0-9])$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [Local_Extension] destination_number(1001) =~ /^(10[01][0-9])$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [Local_Extension] destination_number(1001) =~ /^1000$/ 2008-11-10 18:12:56 [DEBUG] mod_dialplan_xml.c:119 parse_exten() Regex mismatch 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:97 switch_core_standard_on_routing() (sofia/internal/[EMAIL PROTECTED]) State Change CS_ROUTING -> CS_EXECUTE 2008-11-10 18:12:56 [DEBUG] switch_core_session.c:776 switch_core_session_signal_state_change() Send signal sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:423 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State ROUTING going to sleep 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:372 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) Running State Change CS_EXECUTE 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:430 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State EXECUTE 2008-11-10 18:12:56 [DEBUG] mod_sofia.c:173 sofia_on_execute() sofia/internal/[EMAIL PROTECTED] SOFIA EXECUTE 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:134 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Standard EXECUTE 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute set(use_profile=${cond(${acl(${network_addr} rfc1918)} == true ? nat : default)}) 2008-11-10 18:12:56 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/[EMAIL PROTECTED] Expanded String set(use_profile=default) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/[EMAIL PROTECTED] SET [use_profile]=[default] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute set_user([EMAIL PROTECTED]) 2008-11-10 18:12:56 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/[EMAIL PROTECTED] Expanded String set_user([EMAIL PROTECTED]) 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute db(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) 2008-11-10 18:12:56 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/[EMAIL PROTECTED] Expanded String db(insert/my.domain.de-spymap/1000/d1508d5e-af4a-11dd-8f85-c9d27628b1ff) 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute db(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) 2008-11-10 18:12:56 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/[EMAIL PROTECTED] Expanded String db(insert/my.domain.de-last_dial/1000/1001) 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute db(insert/${domain_name}-last_dial/global/${uuid}) 2008-11-10 18:12:56 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/[EMAIL PROTECTED] Expanded String db(insert/my.domain.de-last_dial/global/d1508d5e-af4a-11dd-8f85-c9d27628b1ff) 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute set(dialed_extension=1001) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/[EMAIL PROTECTED] SET [dialed_extension]=[1001] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute export(dialed_extension=1001) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:847 export_function() EXPORT [dialed_extension]=[1001] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute bind_meta_app(1 b s execute_extension::dx XML features) 2008-11-10 18:12:56 [INFO] switch_ivr_async.c:1536 switch_ivr_bind_dtmf_meta_session() Bound B-Leg: 1 execute_extension::dx XML features 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) 2008-11-10 18:12:56 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/[EMAIL PROTECTED] Expanded String bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1000.2008-11-10-18-12-56.wav) 2008-11-10 18:12:56 [INFO] switch_ivr_async.c:1536 switch_ivr_bind_dtmf_meta_session() Bound B-Leg: 2 record_session::/usr/local/freeswitch/recordings/1000.2008-11-10-18-12-56.wav 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute bind_meta_app(3 b s execute_extension::cf XML features) 2008-11-10 18:12:56 [INFO] switch_ivr_async.c:1536 switch_ivr_bind_dtmf_meta_session() Bound B-Leg: 3 execute_extension::cf XML features 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute set(ringback=${us-ring}) 2008-11-10 18:12:56 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/[EMAIL PROTECTED] Expanded String set(ringback=%(2000, 4000, 440.0, 480.0)) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/[EMAIL PROTECTED] SET [ringback]=[%(2000, 4000, 440.0, 480.0)] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute set(transfer_ringback=local_stream://moh) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/[EMAIL PROTECTED] SET [transfer_ringback]=[local_stream://moh] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute set(call_timeout=30) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/[EMAIL PROTECTED] SET [call_timeout]=[30] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute set(hangup_after_bridge=true) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/[EMAIL PROTECTED] SET [hangup_after_bridge]=[true] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute set(continue_on_fail=true) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/[EMAIL PROTECTED] SET [continue_on_fail]=[true] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute db(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) 2008-11-10 18:12:56 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/[EMAIL PROTECTED] Expanded String db(insert/my.domain.de-call_return/1001/1000) 2008-11-10 18:12:57 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute db(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) 2008-11-10 18:12:57 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/[EMAIL PROTECTED] Expanded String db(insert/my.domain.de-last_dial_ext/1001/d1508d5e-af4a-11dd-8f85-c9d27628b1ff) 2008-11-10 18:12:57 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute set(called_party_callgroup=${user_data([EMAIL PROTECTED] var callgroup)}) 2008-11-10 18:12:57 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/[EMAIL PROTECTED] Expanded String set(called_party_callgroup=Customer) 2008-11-10 18:12:57 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/[EMAIL PROTECTED] SET [called_party_callgroup]=[Customer] 2008-11-10 18:12:57 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute export(nolocal:sip_secure_media=${user_data([EMAIL PROTECTED] var sip_secure_media)}) 2008-11-10 18:12:57 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/[EMAIL PROTECTED] Expanded String export(nolocal:sip_secure_media=) 2008-11-10 18:12:57 [DEBUG] mod_dptools.c:847 export_function() EXPORT (REMOTE ONLY) [sip_secure_media]=[UNDEF] 2008-11-10 18:12:57 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute db(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) 2008-11-10 18:12:57 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/[EMAIL PROTECTED] Expanded String db(insert/my.domain.de-last_dial/Customer/d1508d5e-af4a-11dd-8f85-c9d27628b1ff) 2008-11-10 18:12:57 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute bridge(user/[EMAIL PROTECTED]) 2008-11-10 18:12:57 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/[EMAIL PROTECTED] Expanded String bridge(user/[EMAIL PROTECTED]) 2008-11-10 18:12:57 [DEBUG] switch_ivr_originate.c:736 switch_ivr_originate() variable string 0 = [EMAIL PROTECTED] 2008-11-10 18:12:57 [ERR] switch_ivr_originate.c:1064 switch_ivr_originate() Cannot create outgoing channel of type [error] cause: [FACILITY_NOT_SUBSCRIBED] 2008-11-10 18:12:57 [DEBUG] switch_ivr_originate.c:1615 switch_ivr_originate() Originate Resulted in Error Cause: 50 [FACILITY_NOT_SUBSCRIBED] 2008-11-10 18:12:57 [ERR] switch_ivr_originate.c:1064 switch_ivr_originate() Cannot create outgoing channel of type [user] cause: [FACILITY_NOT_SUBSCRIBED] 2008-11-10 18:12:57 [DEBUG] switch_ivr_originate.c:1615 switch_ivr_originate() Originate Resulted in Error Cause: 50 [FACILITY_NOT_SUBSCRIBED] 2008-11-10 18:12:57 [INFO] mod_dptools.c:1848 audio_bridge_function() Originate Failed. Cause: FACILITY_NOT_SUBSCRIBED 2008-11-10 18:12:57 [DEBUG] mod_dptools.c:1869 audio_bridge_function() Continue on fail [true]: Cause: FACILITY_NOT_SUBSCRIBED 2008-11-10 18:12:57 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute answer() 2008-11-10 18:12:57 [DEBUG] switch_channel.c:1712 switch_channel_perform_answer() sofia/internal/[EMAIL PROTECTED] receive message [SWITCH_MESSAGE_INDICATE_ANSWER] 2008-11-10 18:12:57 [DEBUG] sofia_glue.c:1786 sofia_glue_activate_rtp() AUDIO RTP [sofia/internal/[EMAIL PROTECTED] xxx.xx.xxx.46 port 12514 -> xxx.xx.xx.186 port 12928 codec: 8 ms: 20 2008-11-10 18:12:57 [DEBUG] switch_rtp.c:833 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms 2008-11-10 18:12:57 [DEBUG] mod_sofia.c:486 sofia_answer_channel() Local SDP sofia/internal/[EMAIL PROTECTED]: v=0 o=FreeSWITCH 1226324663 1226324664 IN IP4 xxx.xx.xxx.46 s=FreeSWITCH c=IN IP4 xxx.xx.xxx.46 t=0 0 a=sendrecv m=audio 12514 RTP/AVP 8 101 a=rtpmap:8 pcma/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 2008-11-10 18:12:57 [DEBUG] switch_core_session.c:487 switch_core_session_perform_receive_message() Send signal sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-11-10 18:12:57 [DEBUG] sofia.c:2285 sofia_handle_sip_i_state() Channel sofia/internal/[EMAIL PROTECTED] entering state [completed] 2008-11-10 18:12:57 [NOTICE] mod_dptools.c:610 answer_function() Channel [sofia/internal/[EMAIL PROTECTED] has been answered 2008-11-10 18:12:57 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute sleep(1000) 2008-11-10 18:12:57 [DEBUG] sofia.c:2285 sofia_handle_sip_i_state() Channel sofia/internal/[EMAIL PROTECTED] entering state [ready] 2008-11-10 18:12:58 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/[EMAIL PROTECTED] Execute voicemail(default ${domain_name} ${dialed_extension}) [EMAIL PROTECTED] schrieb: > Send a full debug from the FS console when a call is placed. That > should give more of a clue as to where the issue is. > > Peter P GMX wrote: > >> I receive a FACILITY_NOT_SUBSCRIBED message when I call from 1000 to 1001. >> >> I've read in the wiki: >> 50 FACILITY_NOT_SUBSCRIBED requested facility not subscribed >> [Q.850 This cause indicates that the user has requested a >> supplementary service, which is available, but the user is not >> authorized to use. >> >> I am wondering which supplementary service this could be. The invite >> message is as follows: >> ====================== >> U xxx.xx.xx.186:2054 -> xxx.xx.xxx.xx:5060 >> INVITE sip:[EMAIL PROTECTED];user=phone SIP/2.0. >> Via: SIP/2.0/UDP xxx.xx.xx.186:2054;branch=z9hG4bK-7qnms1c9aoqt;rport. >> From: "Company1000" <sip:[EMAIL PROTECTED]>;tag=pslbxvhxjo. >> To: <sip:[EMAIL PROTECTED];user=phone>. >> Call-ID: 3c267cac8c1f-smz6hpvv1e5h. >> CSeq: 2 INVITE. >> Max-Forwards: 70. >> Contact: <sip:[EMAIL PROTECTED]:2054;line=rt3bxln1>;flow-id=1. >> P-Key-Flags: keys="3". >> User-Agent: snom320/7.1.33. >> Accept: application/sdp. >> Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, >> PRACK, MESSAGE, INFO. >> Allow-Events: talk, hold, refer, call-info. >> Supported: timer, 100rel, replaces, from-change. >> Session-Expires: 3600;refresher=uas. >> Min-SE: 90. >> Proxy-Authorization: Digest >> username="1000",realm="xxx.xx.xxx.xx",nonce="201af2a0-af3f-11dd-af96-ebbe56552456",uri="sip:[EMAIL >> >> PROTECTED];user=phone",qop=auth,nc=00000001,cnonce="0f67abbc",response="d984661b55085f64e3e6f93a09762eca",algorithm=MD5. >> Content-Type: application/sdp. >> Content-Length: 370. >> . >> v=0. >> o=root 1618416056 1618416056 IN IP4 xxx.xx.xx.186. >> s=call. >> c=IN IP4 xxx.xx.xx.186. >> t=0 0. >> m=audio 12472 RTP/AVP 8 0 9 2 3 18 4 101. >> a=rtpmap:8 pcma/8000. >> a=rtpmap:0 pcmu/8000. >> a=rtpmap:9 g722/8000. >> a=rtpmap:2 g726-32/8000. >> a=rtpmap:3 gsm/8000. >> a=rtpmap:18 g729/8000. >> a=rtpmap:4 g723/8000. >> a=rtpmap:101 telephone-event/8000. >> a=fmtp:101 0-16. >> a=ptime:20. >> a=sendrecv. >> ====================== >> So there is nothing special in the SDP. >> >> Both Snom 320 phones register on the right domain (here:IP). They both >> can call their mailbox etc. They are behind a NAT on different public >> IPs. However calling each other doesn't work. >> >> Sofia status profile internal >> API CALL [sofia(status profile internal)] output: >> ================================================================================================= >> Name internal >> Domain Name N/A >> DBName sofia_reg_internal >> Pres Hosts >> Dialplan XML >> Context public >> Challenge Realm auto_from >> RTP-IP xxx.xx.xxx.xx >> SIP-IP xxx.xx.xxx.xx >> URL sip:[EMAIL PROTECTED]:5060 >> BIND-URL sip:[EMAIL PROTECTED]:5060 >> HOLD-MUSIC local_stream://moh >> CODECS G722,PCMU,PCMA,GSM >> TEL-EVENT 101 >> DTMF-MODE rfc2833 >> CNG 13 >> SESSION-TO 0 >> MAX-DIALOG 0 >> NOMEDIA false >> LATE-NEG false >> PROXY-MEDIA false >> AGGRESSIVENAT false >> STUN_ENABLED true >> STUN_AUTO_DISABLE false >> >> Registrations: >> ================================================================================================= >> Call-ID: 3c2679b578bd-8brbg608itvr >> User: [EMAIL PROTECTED] >> Contact: "Company1000" <sip:[EMAIL PROTECTED]:2054;line=145ehzt5> >> Agent: snom320/7.1.33 >> Status: Registered(UDP)(unknown) EXP(2008-11-10 16:45:40) >> Host: freeswitch >> >> Call-ID: 3c2677883993-68zb6go2xoip >> User: [EMAIL PROTECTED] >> Contact: "Company1001" <sip:[EMAIL PROTECTED]:2054;line=hcg076gv> >> Agent: snom320/7.1.33 >> Status: Registered(UDP)(unknown) EXP(2008-11-10 16:45:41) >> Host: freeswitch >> >> ================================================================================================= >> >> What can I do? >> >> Best regards >> Peter >> >> >> _______________________________________________ >> 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 >> >> > > _______________________________________________ > 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 > > _______________________________________________ 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