Hello, here is the complete Log of the relevant part: freeswitch@freeswitch> 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/1000@my.domain.de [d1508d5e-af4a-11dd-8f85-c9d27628b1ff] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:372 switch_core_session_run() (sofia/internal/1000@my.domain.de) Running State Change CS_NEW 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:376 switch_core_session_run() (sofia/internal/1000@my.domain.de) State NEW 2008-11-10 18:12:56 [DEBUG] sofia.c:2285 sofia_handle_sip_i_state() Channel sofia/internal/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de) 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/1000@my.domain.de [BREAK] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:372 switch_core_session_run() (sofia/internal/1000@my.domain.de) Running State Change CS_INIT 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:420 switch_core_session_run() (sofia/internal/1000@my.domain.de) State INIT 2008-11-10 18:12:56 [DEBUG] mod_sofia.c:83 sofia_on_init() sofia/internal/1000@my.domain.de SOFIA INIT 2008-11-10 18:12:56 [DEBUG] mod_sofia.c:111 sofia_on_init() (sofia/internal/1000@my.domain.de) 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/1000@my.domain.de [BREAK] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:420 switch_core_session_run() (sofia/internal/1000@my.domain.de) State INIT going to sleep 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:372 switch_core_session_run() (sofia/internal/1000@my.domain.de) Running State Change CS_ROUTING 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:423 switch_core_session_run() (sofia/internal/1000@my.domain.de) State ROUTING 2008-11-10 18:12:56 [DEBUG] mod_sofia.c:130 sofia_on_routing() sofia/internal/1000@my.domain.de SOFIA ROUTING 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:64 switch_core_standard_on_routing() sofia/internal/1000@my.domain.de 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/1000@my.domain.de) 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/1000@my.domain.de [BREAK] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:423 switch_core_session_run() (sofia/internal/1000@my.domain.de) State ROUTING going to sleep 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:372 switch_core_session_run() (sofia/internal/1000@my.domain.de) Running State Change CS_EXECUTE 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:430 switch_core_session_run() (sofia/internal/1000@my.domain.de) State EXECUTE 2008-11-10 18:12:56 [DEBUG] mod_sofia.c:173 sofia_on_execute() sofia/internal/1000@my.domain.de SOFIA EXECUTE 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:134 switch_core_standard_on_execute() sofia/internal/1000@my.domain.de Standard EXECUTE 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/1000@my.domain.de 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/1000@my.domain.de Expanded String set(use_profile=default) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/1000@my.domain.de SET [use_profile]=[default] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/1000@my.domain.de Execute set_user(default@${domain_name}) 2008-11-10 18:12:56 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/1000@my.domain.de Expanded String set_user(default@my.domain.de) 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de Execute set(dialed_extension=1001) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/1000@my.domain.de SET [dialed_extension]=[1001] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de Execute set(ringback=${us-ring}) 2008-11-10 18:12:56 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de Execute set(transfer_ringback=local_stream://moh) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/1000@my.domain.de 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/1000@my.domain.de Execute set(call_timeout=30) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/1000@my.domain.de SET [call_timeout]=[30] 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/1000@my.domain.de Execute set(hangup_after_bridge=true) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/1000@my.domain.de 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/1000@my.domain.de Execute set(continue_on_fail=true) 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de Execute set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) 2008-11-10 18:12:57 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/1000@my.domain.de Expanded String set(called_party_callgroup=Customer) 2008-11-10 18:12:57 [DEBUG] mod_dptools.c:709 set_function() sofia/internal/1000@my.domain.de 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/1000@my.domain.de Execute export(nolocal:sip_secure_media=${user_data(${dialed_extension}@${domain_name} var sip_secure_media)}) 2008-11-10 18:12:57 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de 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/1000@my.domain.de Execute bridge(user/${dialed_extension}@${domain_name}) 2008-11-10 18:12:57 [DEBUG] switch_core_session.c:1213 switch_core_session_execute_application() sofia/internal/1000@my.domain.de Expanded String bridge(user/1001@my.domain.de) 2008-11-10 18:12:57 [DEBUG] switch_ivr_originate.c:736 switch_ivr_originate() variable string 0 = [presence_id=1001@my.domain.de] 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/1000@my.domain.de Execute answer() 2008-11-10 18:12:57 [DEBUG] switch_channel.c:1712 switch_channel_perform_answer() sofia/internal/1000@my.domain.de 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/1000@my.domain.de] 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/1000@my.domain.de: 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/1000@my.domain.de [BREAK] 2008-11-10 18:12:57 [DEBUG] sofia.c:2285 sofia_handle_sip_i_state() Channel sofia/internal/1000@my.domain.de entering state [completed] 2008-11-10 18:12:57 [NOTICE] mod_dptools.c:610 answer_function() Channel [sofia/internal/1000@my.domain.de] has been answered 2008-11-10 18:12:57 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/1000@my.domain.de Execute sleep(1000) 2008-11-10 18:12:57 [DEBUG] sofia.c:2285 sofia_handle_sip_i_state() Channel sofia/internal/1000@my.domain.de entering state [ready] 2008-11-10 18:12:58 [DEBUG] switch_core_state_machine.c:149 switch_core_standard_on_execute() sofia/internal/1000@my.domain.de Execute voicemail(default ${domain_name} ${dialed_extension}) peder@networkoblivion.com 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:1001@xxx.xx.xxx.xx;user=phone SIP/2.0. Via: SIP/2.0/UDP xxx.xx.xx.186:2054;branch=z9hG4bK-7qnms1c9aoqt;rport. From: "Company1000" <sip:1000@xxx.xx.xxx.xx>;tag=pslbxvhxjo. To: <sip:1001@xxx.xx.xxx.xx;user=phone>. Call-ID: 3c267cac8c1f-smz6hpvv1e5h. CSeq: 2 INVITE. Max-Forwards: 70. Contact: <sip:1000@xxx.xx.xx.186: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:1001@xxx.xx.xxx.xx;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:mod_sofia@xxx.xx.xxx.xx:5060 BIND-URL sip:mod_sofia@xxx.xx.xxx.xx: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: 1000@xxx.xx.xxx.xx Contact: "Company1000" <sip:1000@xxx.xx.xx.186: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: 1001@xxx.xx.xxx.xx Contact: "Company1001" <sip:1001@xxx.xx.xx.189: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