[Freeswitch-users] FACILITY_NOT_SUBSCRIBED

Peter P GMX Prometheus001 at gmx.net
Mon Nov 10 09:17:20 PST 2008


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
>
>   




More information about the FreeSWITCH-users mailing list