[Freeswitch-users] FACILITY_NOT_SUBSCRIBED
Peter P GMX
Prometheus001 at gmx.net
Mon Nov 10 09:50:48 PST 2008
Addendum:
I fixed the "sip_secure_media=[undef]" problem. However no change.
Best regards
peter
Peter P GMX schrieb:
> Hello,
>
> here is the complete Log of the relevant part:
>
> freeswitch at 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 at 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 at 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 at my.domain.de) State NEW
> 2008-11-10 18:12:56 [DEBUG] sofia.c:2285 sofia_handle_sip_i_state()
> Channel sofia/internal/1000 at 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 at 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 at 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 at my.domain.de [BREAK]
> 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:372
> switch_core_session_run() (sofia/internal/1000 at 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 at my.domain.de) State INIT
> 2008-11-10 18:12:56 [DEBUG] mod_sofia.c:83 sofia_on_init()
> sofia/internal/1000 at my.domain.de SOFIA INIT
> 2008-11-10 18:12:56 [DEBUG] mod_sofia.c:111 sofia_on_init()
> (sofia/internal/1000 at 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 at my.domain.de [BREAK]
> 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:420
> switch_core_session_run() (sofia/internal/1000 at 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 at 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 at my.domain.de) State ROUTING
> 2008-11-10 18:12:56 [DEBUG] mod_sofia.c:130 sofia_on_routing()
> sofia/internal/1000 at 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 at 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 at 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 at my.domain.de [BREAK]
> 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:423
> switch_core_session_run() (sofia/internal/1000 at 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 at 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 at my.domain.de) State EXECUTE
> 2008-11-10 18:12:56 [DEBUG] mod_sofia.c:173 sofia_on_execute()
> sofia/internal/1000 at 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 at 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 at 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 at 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 at 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 at 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 at my.domain.de Expanded String
> set_user(default at my.domain.de)
> 2008-11-10 18:12:56 [DEBUG] switch_core_state_machine.c:149
> switch_core_standard_on_execute() sofia/internal/1000 at 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 at 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 at 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 at 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 at 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 at 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 at my.domain.de
> Execute set(dialed_extension=1001)
> 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function()
> sofia/internal/1000 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at my.domain.de
> Execute set(call_timeout=30)
> 2008-11-10 18:12:56 [DEBUG] mod_dptools.c:709 set_function()
> sofia/internal/1000 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at my.domain.de Expanded String
> bridge(user/1001 at my.domain.de)
> 2008-11-10 18:12:57 [DEBUG] switch_ivr_originate.c:736
> switch_ivr_originate() variable string 0 = [presence_id=1001 at 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 at my.domain.de
> Execute answer()
> 2008-11-10 18:12:57 [DEBUG] switch_channel.c:1712
> switch_channel_perform_answer() sofia/internal/1000 at 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 at 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 at 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 at my.domain.de [BREAK]
> 2008-11-10 18:12:57 [DEBUG] sofia.c:2285 sofia_handle_sip_i_state()
> Channel sofia/internal/1000 at my.domain.de entering state [completed]
> 2008-11-10 18:12:57 [NOTICE] mod_dptools.c:610 answer_function() Channel
> [sofia/internal/1000 at 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 at 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 at 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 at my.domain.de
> Execute voicemail(default ${domain_name} ${dialed_extension})
>
>
>
>
>
>
>
>
>
>
>
>
> peder at 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 at 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 at xxx.xx.xxx.xx>;tag=pslbxvhxjo.
>>> To: <sip:1001 at xxx.xx.xxx.xx;user=phone>.
>>> Call-ID: 3c267cac8c1f-smz6hpvv1e5h.
>>> CSeq: 2 INVITE.
>>> Max-Forwards: 70.
>>> Contact: <sip:1000 at 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 at 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 at xxx.xx.xxx.xx:5060
>>> BIND-URL sip:mod_sofia at 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 at xxx.xx.xxx.xx
>>> Contact: "Company1000" <sip:1000 at 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 at xxx.xx.xxx.xx
>>> Contact: "Company1001" <sip:1001 at 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 at 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 at 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 at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
>
More information about the FreeSWITCH-users
mailing list