[Freeswitch-users] multi-tenant setup - call goes to wrong place
Mr Nathan Downes
nathandownes at hotmail.com
Fri Jul 27 15:16:47 MSD 2012
Hi,
I have a multi tenant setup with fusionpbx, for one domain I use extensions
that don't register just for voicemail i.e 201 at domain1.com , when someone
from xx at domain1.com calls 201 everything appears to go correctly, domain is
set and call goes to 201 at domain1.com but when it first becomes an ip it
sends to 201 at domain2.ip.address. It doesn't seem to happen with all
extensions numbered the same in different domains..
Any idea what to look for??
Log as follows.
2012-07-26 09:37:35.178096 [NOTICE] switch_channel.c:926 New Channel
sofia/internal/306 at domain1.com [b62db898-d6b1-11e1-be15-73f389528c7f]
2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:385
(sofia/internal/306 at domain1.com) Running State Change CS_NEW
2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:403
(sofia/internal/306 at domain1.com) State NEW
2012-07-26 09:37:35.178096 [DEBUG] sofia.c:5838 Channel
sofia/internal/306 at domain1.com entering state [received][100]
2012-07-26 09:37:35.178096 [DEBUG] sofia.c:5849 Remote SDP:
v=0
o=- 60255882 60255882 IN IP4 115.64.93.203
s=-
c=IN IP4 115.64.93.203
t=0 0
m=audio 55938 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
2012-07-26 09:37:35.178096 [DEBUG] sofia_glue.c:3941 Looking for zrtp-hash
2012-07-26 09:37:35.178096 [DEBUG] sofia_glue.c:3919 Deciding whether to
pass zrtp-hash between legs
2012-07-26 09:37:35.178096 [DEBUG] sofia_glue.c:3921 CF_ZRTP_PASSTHRU_REQ
not set, so not propagating zrtp-hash
2012-07-26 09:37:35.178096 [DEBUG] sofia_glue.c:5034 Audio Codec Compare
[PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000]
2012-07-26 09:37:35.178096 [DEBUG] sofia_glue.c:3020 Set Codec
sofia/internal/306 at domain1.com PCMA/8000 20 ms 160 samples 64000 bits
2012-07-26 09:37:35.178096 [DEBUG] switch_core_codec.c:111
sofia/internal/306 at domain1.com Original read codec set to PCMA:8
2012-07-26 09:37:35.178096 [DEBUG] sofia_glue.c:5155 Set 2833 dtmf send/recv
payload to 101
2012-07-26 09:37:35.178096 [DEBUG] sofia.c:6077
(sofia/internal/306 at domain1.com) State Change CS_NEW -> CS_INIT
2012-07-26 09:37:35.178096 [DEBUG] switch_core_session.c:1228 Send signal
sofia/internal/306 at domain1.com [BREAK]
2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:385
(sofia/internal/306 at domain1.com) Running State Change CS_INIT
2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:424
(sofia/internal/306 at domain1.com) State INIT
2012-07-26 09:37:35.178096 [DEBUG] mod_sofia.c:85
sofia/internal/306 at domain1.com SOFIA INIT
2012-07-26 09:37:35.178096 [DEBUG] mod_sofia.c:125
(sofia/internal/306 at domain1.com) State Change CS_INIT -> CS_ROUTING
2012-07-26 09:37:35.178096 [DEBUG] switch_core_session.c:1228 Send signal
sofia/internal/306 at domain1.com [BREAK]
2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:424
(sofia/internal/306 at domain1.com) State INIT going to sleep
2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:385
(sofia/internal/306 at domain1.com) Running State Change CS_ROUTING
2012-07-26 09:37:35.178096 [DEBUG] switch_channel.c:1919
(sofia/internal/306 at domain1.com) Callstate Change DOWN -> RINGING
2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:433
(sofia/internal/306 at domain1.com) State ROUTING
2012-07-26 09:37:35.178096 [DEBUG] mod_sofia.c:148
sofia/internal/306 at domain1.com SOFIA ROUTING
2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:104
sofia/internal/306 at domain1.com Standard ROUTING
2012-07-26 09:37:35.178096 [INFO] mod_dialplan_xml.c:485 Processing
0286249343 <306>->201 in context domain1.com
Dialplan: sofia/internal/306 at domain1.com parsing [domain1.com->unloop]
continue=false
Dialplan: sofia/internal/306 at domain1.com parsing
[domain1.com->Local_Extension] continue=false
Dialplan: sofia/internal/306 at domain1.com Regex (PASS) [Local_Extension]
destination_number(201) =~ /(^\d{2,7}$)/ break=on-false
Dialplan: sofia/internal/306 at domain1.com Action set(dialed_extension=201)
Dialplan: sofia/internal/306 at domain1.com Action export(dialed_extension=201)
Dialplan: sofia/internal/306 at domain1.com Action limit(hash ${domain_name}
201 ${limit_max} ${limit_destination})
Dialplan: sofia/internal/306 at domain1.com Action bind_meta_app(1 b s
execute_extension::dx XML features)
Dialplan: sofia/internal/306 at domain1.com Action bind_meta_app(2 b s
record_session::/usr/local/freeswitch/recordings/archive/${strftime(%Y)}/${s
trftime(%b)}/${strftime(%d)}/${uuid}.wav)
Dialplan: sofia/internal/306 at domain1.com Action bind_meta_app(3 b s
execute_extension::cf XML features)
Dialplan: sofia/internal/306 at domain1.com Action bind_meta_app(4 b s
execute_extension::att_xfer XML features)
Dialplan: sofia/internal/306 at domain1.com Action set(ringback=${us-ring})
Dialplan: sofia/internal/306 at domain1.com Action
set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/306 at domain1.com Action set(call_timeout=30)
Dialplan: sofia/internal/306 at domain1.com Action
set(hangup_after_bridge=true)
Dialplan: sofia/internal/306 at domain1.com Action set(continue_on_fail=true)
Dialplan: sofia/internal/306 at domain1.com Action
hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_numbe
r})
Dialplan: sofia/internal/306 at domain1.com Action
hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/internal/306 at domain1.com Action
set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
var callgroup)})
Dialplan: sofia/internal/306 at domain1.com Action
hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/306 at domain1.com Action
bridge(user/${user_data(${destination_number}@${domain_name} attr
id)}@${domain_name})
Dialplan: sofia/internal/306 at domain1.com Action answer()
Dialplan: sofia/internal/306 at domain1.com Action sleep(1000)
Dialplan: sofia/internal/306 at domain1.com Action voicemail(default
${domain_name} ${dialed_extension})
2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:154
(sofia/internal/306 at domain1.com) State Change CS_ROUTING -> CS_EXECUTE
2012-07-26 09:37:35.178096 [DEBUG] switch_core_session.c:1228 Send signal
sofia/internal/306 at domain1.com [BREAK]
2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:433
(sofia/internal/306 at domain1.com) State ROUTING going to sleep
2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:385
(sofia/internal/306 at domain1.com) Running State Change CS_EXECUTE
2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/306 at domain1.com) State EXECUTE
2012-07-26 09:37:35.178096 [DEBUG] mod_sofia.c:241
sofia/internal/306 at domain1.com SOFIA EXECUTE
2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:196
sofia/internal/306 at domain1.com Standard EXECUTE
EXECUTE sofia/internal/306 at domain1.com set(call_direction=local)
2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305
sofia/internal/306 at domain1.com SET [call_direction]=[local]
EXECUTE sofia/internal/306 at domain1.com set(open=true)
2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305
sofia/internal/306 at domain1.com SET [open]=[true]
EXECUTE sofia/internal/306 at domain1.com
hash(insert/domain1.com-spymap/306/b62db898-d6b1-11e1-be15-73f389528c7f)
EXECUTE sofia/internal/306 at domain1.com
hash(insert/domain1.com-last_dial/306/201)
EXECUTE sofia/internal/306 at domain1.com
hash(insert/domain1.com-last_dial/global/b62db898-d6b1-11e1-be15-73f389528c7
f)
EXECUTE sofia/internal/306 at domain1.com set(RFC2822_DATE=Thu, 26 Jul 2012
09:37:35 +1000)
2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305
sofia/internal/306 at domain1.com SET [RFC2822_DATE]=[Thu, 26 Jul 2012 09:37:35
+1000]
EXECUTE sofia/internal/306 at domain1.com set(dialed_extension=201)
2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305
sofia/internal/306 at domain1.com SET [dialed_extension]=[201]
EXECUTE sofia/internal/306 at domain1.com export(dialed_extension=201)
2012-07-26 09:37:35.178096 [DEBUG] switch_channel.c:1093 EXPORT
(export_vars) [dialed_extension]=[201]
EXECUTE sofia/internal/306 at domain1.com limit(hash domain1.com 201 2 !BUSY)
2012-07-26 09:37:35.178096 [INFO] switch_limit.c:126 incr called:
domain1.com_201 max:2, interval:0
2012-07-26 09:37:35.178096 [INFO] mod_hash.c:202 Usage for domain1.com_201
is now 1/2
EXECUTE sofia/internal/306 at domain1.com bind_meta_app(1 b s
execute_extension::dx XML features)
2012-07-26 09:37:35.178096 [INFO] switch_ivr_async.c:3328 Bound B-Leg: *1
execute_extension::dx XML features
EXECUTE sofia/internal/306 at domain1.com bind_meta_app(2 b s
record_session::/usr/local/freeswitch/recordings/archive/2012/Jul/26/b62db89
8-d6b1-11e1-be15-73f389528c7f.wav)
2012-07-26 09:37:35.178096 [INFO] switch_ivr_async.c:3328 Bound B-Leg: *2
record_session::/usr/local/freeswitch/recordings/archive/2012/Jul/26/b62db89
8-d6b1-11e1-be15-73f389528c7f.wav
EXECUTE sofia/internal/306 at domain1.com bind_meta_app(3 b s
execute_extension::cf XML features)
2012-07-26 09:37:35.178096 [INFO] switch_ivr_async.c:3328 Bound B-Leg: *3
execute_extension::cf XML features
EXECUTE sofia/internal/306 at domain1.com bind_meta_app(4 b s
execute_extension::att_xfer XML features)
2012-07-26 09:37:35.178096 [INFO] switch_ivr_async.c:3328 Bound B-Leg: *4
execute_extension::att_xfer XML features
EXECUTE sofia/internal/306 at domain1.com set(ringback=%(2000, 4000, 440.0,
480.0))
2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305
sofia/internal/306 at domain1.com SET [ringback]=[%(2000, 4000, 440.0, 480.0)]
EXECUTE sofia/internal/306 at domain1.com
set(transfer_ringback=local_stream://moh)
2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305
sofia/internal/306 at domain1.com SET [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/306 at domain1.com set(call_timeout=30)
2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305
sofia/internal/306 at domain1.com SET [call_timeout]=[30]
EXECUTE sofia/internal/306 at domain1.com set(hangup_after_bridge=true)
2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305
sofia/internal/306 at domain1.com SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/306 at domain1.com set(continue_on_fail=true)
2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305
sofia/internal/306 at domain1.com SET [continue_on_fail]=[true]
EXECUTE sofia/internal/306 at domain1.com
hash(insert/domain1.com-call_return/201/306)
EXECUTE sofia/internal/306 at domain1.com
hash(insert/domain1.com-last_dial_ext/201/b62db898-d6b1-11e1-be15-73f389528c
7f)
EXECUTE sofia/internal/306 at domain1.com set(called_party_callgroup=)
2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305
sofia/internal/306 at domain1.com SET [called_party_callgroup]=[UNDEF]
EXECUTE sofia/internal/306 at domain1.com
hash(insert/domain1.com-last_dial//b62db898-d6b1-11e1-be15-73f389528c7f)
EXECUTE sofia/internal/306 at domain1.com bridge(user/201 at domain1.com)
2012-07-26 09:37:35.178096 [DEBUG] switch_channel.c:1047
sofia/internal/306 at domain1.com EXPORTING[export_vars]
[domain_name]=[domain1.com] to event
2012-07-26 09:37:35.178096 [DEBUG] switch_channel.c:1047
sofia/internal/306 at domain1.com EXPORTING[export_vars]
[dialed_extension]=[201] to event
2012-07-26 09:37:35.178096 [DEBUG] switch_ivr_originate.c:1958 Parsing
global variables
2012-07-26 09:37:35.198097 [DEBUG] switch_channel.c:1047
sofia/internal/306 at domain1.com EXPORTING[export_vars]
[domain_name]=[domain1.com] to event
2012-07-26 09:37:35.198097 [DEBUG] switch_channel.c:1047
sofia/internal/306 at domain1.com EXPORTING[export_vars]
[dialed_extension]=[201] to event
2012-07-26 09:37:35.198097 [DEBUG] switch_ivr_originate.c:1958 Parsing
global variables
2012-07-26 09:37:35.198097 [DEBUG] switch_event.c:1470 Parsing variable
[sip_invite_domain]=[domain1.com]
2012-07-26 09:37:35.198097 [DEBUG] switch_event.c:1470 Parsing variable
[presence_id]=[201 at domain1.com]
2012-07-26 09:37:35.198097 [NOTICE] switch_channel.c:926 New Channel
sofia/internal/sip:201 at 110.143.31.101:1178
[b630218c-d6b1-11e1-be1d-73f389528c7f]
2012-07-26 09:37:35.198097 [DEBUG] mod_sofia.c:4734
(sofia/internal/sip:201 at 110.143.31.101:1178) State Change CS_NEW -> CS_INIT
2012-07-26 09:37:35.198097 [DEBUG] switch_core_session.c:1228 Send signal
sofia/internal/sip:201 at 110.143.31.101:1178 [BREAK]
2012-07-26 09:37:35.198097 [DEBUG] switch_core_state_machine.c:385
(sofia/internal/sip:201 at 110.143.31.101:1178) Running State Change CS_INIT
2012-07-26 09:37:35.198097 [DEBUG] switch_core_state_machine.c:424
(sofia/internal/sip:201 at 110.143.31.101:1178) State INIT
2012-07-26 09:37:35.198097 [DEBUG] mod_sofia.c:85
sofia/internal/sip:201 at 110.143.31.101:1178 SOFIA INIT
2012-07-26 09:37:35.198097 [DEBUG] sofia_glue.c:2602 Local SDP:
v=0
o=FreeSWITCH 1343234313 1343234314 IN IP4 203.174.163.226
s=FreeSWITCH
c=IN IP4 203.174.163.226
t=0 0
m=audio 25142 RTP/AVP 8 0 3 101 13
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
2012-07-26 09:37:35.198097 [DEBUG] mod_sofia.c:125
(sofia/internal/sip:201 at 110.143.31.101:1178) State Change CS_INIT ->
CS_ROUTING
2012-07-26 09:37:35.198097 [DEBUG] switch_core_session.c:1228 Send signal
sofia/internal/sip:201 at 110.143.31.101:1178 [BREAK]
2012-07-26 09:37:35.198097 [DEBUG] switch_core_state_machine.c:424
(sofia/internal/sip:201 at 110.143.31.101:1178) State INIT going to sleep
2012-07-26 09:37:35.198097 [DEBUG] switch_core_state_machine.c:385
(sofia/internal/sip:201 at 110.143.31.101:1178) Running State Change CS_ROUTING
2012-07-26 09:37:35.198097 [DEBUG] switch_channel.c:1919
(sofia/internal/sip:201 at 110.143.31.101:1178) Callstate Change DOWN ->
RINGING
2012-07-26 09:37:35.198097 [DEBUG] switch_core_session.c:923 Send signal
sofia/internal/sip:201 at 110.143.31.101:1178 [BREAK]
2012-07-26 09:37:35.198097 [DEBUG] switch_core_state_machine.c:433
(sofia/internal/sip:201 at 110.143.31.101:1178) State ROUTING
2012-07-26 09:37:35.198097 [DEBUG] mod_sofia.c:148
sofia/internal/sip:201 at 110.143.31.101:1178 SOFIA ROUTING
2012-07-26 09:37:35.198097 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/sip:201 at 110.143.31.101:1178) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2012-07-26 09:37:35.198097 [DEBUG] switch_core_session.c:1228 Send signal
sofia/internal/sip:201 at 110.143.31.101:1178 [BREAK]
2012-07-26 09:37:35.198097 [DEBUG] switch_core_state_machine.c:433
(sofia/internal/sip:201 at 110.143.31.101:1178) State ROUTING going to sleep
2012-07-26 09:37:35.198097 [DEBUG] switch_core_state_machine.c:385
(sofia/internal/sip:201 at 110.143.31.101:1178) Running State Change
CS_CONSUME_MEDIA
2012-07-26 09:37:35.198097 [DEBUG] switch_core_state_machine.c:452
(sofia/internal/sip:201 at 110.143.31.101:1178) State CONSUME_MEDIA
2012-07-26 09:37:35.198097 [DEBUG] switch_core_state_machine.c:452
(sofia/internal/sip:201 at 110.143.31.101:1178) State CONSUME_MEDIA going to
sleep
2012-07-26 09:37:35.198097 [DEBUG] sofia.c:5838 Channel
sofia/internal/sip:201 at 110.143.31.101:1178 entering state [calling][0]
2012-07-26 09:37:35.318096 [DEBUG] switch_core_session.c:923 Send signal
sofia/internal/sip:201 at 110.143.31.101:1178 [BREAK]
2012-07-26 09:37:35.318096 [DEBUG] switch_core_session.c:923 Send signal
sofia/internal/sip:201 at 110.143.31.101:1178 [BREAK]
2012-07-26 09:37:35.338097 [DEBUG] sofia.c:5838 Channel
sofia/internal/sip:201 at 110.143.31.101:1178 entering state [proceeding][180]
2012-07-26 09:37:35.338097 [NOTICE] sofia.c:5930 Ring-Ready
sofia/internal/sip:201 at 110.143.31.101:1178!
2012-07-26 09:37:35.338097 [INFO] switch_ivr_originate.c:1156 Sending early
media
2012-07-26 09:37:35.338097 [DEBUG] sofia_glue.c:3269 AUDIO RTP
[sofia/internal/306 at domain1.com] 203.174.163.226 port 26698 -> 115.64.93.203
port 55938 codec: 8 ms: 20
2012-07-26 09:37:35.338097 [DEBUG] switch_rtp.c:1680 Starting timer [soft]
160 bytes per 20ms
2012-07-26 09:37:35.338097 [DEBUG] sofia_glue.c:3491 Setting Jitterbuffer to
60ms (3 frames)
2012-07-26 09:37:35.338097 [DEBUG] sofia_glue.c:3533 Set 2833 dtmf send
payload to 101
2012-07-26 09:37:35.338097 [DEBUG] sofia_glue.c:3539 Set 2833 dtmf receive
payload to 101
2012-07-26 09:37:35.338097 [DEBUG] sofia_glue.c:3566
sofia/internal/306 at domain1.com Set rtp dtmf delay to 40
2012-07-26 09:37:35.338097 [DEBUG] mod_sofia.c:2606 Ring SDP:
v=0
o=FreeSWITCH 1343232757 1343232758 IN IP4 203.174.163.226
s=FreeSWITCH
c=IN IP4 203.174.163.226
t=0 0
m=audio 26698 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
a=sendrecv
2012-07-26 09:37:35.338097 [NOTICE] mod_sofia.c:2609 Pre-Answer
sofia/internal/306 at domain1.com!
2012-07-26 09:37:35.338097 [DEBUG] switch_channel.c:3042
(sofia/internal/306 at domain1.com) Callstate Change RINGING -> EARLY
2012-07-26 09:37:35.338097 [DEBUG] switch_core_session.c:777 Send signal
sofia/internal/306 at domain1.com [BREAK]
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20120727/c378da6f/attachment-0001.html
Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-users
mailing list