Hi, I ended up locating the problem.. it appears when I was playing with shared_presence.. to try and get BLF working for certain tenants. What I thought would help from googling caused this issue somehow, below is what I enabled to cause the problem. In internal.xml <!--enable to use presence --> <param name="manage-presence" value="false"/> this one true <!-- send a presence probe on each register to query devices to send presence instead of sending presence with less info --> <!--<param name="presence-probe-on-register" value="true"/>--> this one enabled <!--<param name="manage-shared-appearance" value="false"/>--> this one true + enabled <!-- used to share presence info across sofia profiles --> <!-- Name of the db to use for this profile --> <!-- param name="dbname" value="shared_presence"/> --> this one + enabled <param name="presence-hosts" value="domain1.com,domain2.com,domain3.com,$${local_ip_v4}"/> Is this actually required to use BLF for a certain domain? From: Mr Nathan Downes [mailto:nathandownes@hotmail.com] Sent: Friday, 27 July 2012 9:17 PM To: 'FreeSWITCH Users Help' Subject: multi-tenant setup - call goes to wrong place 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@domain1.com , when someone from xx@domain1.com calls 201 everything appears to go correctly, domain is set and call goes to 201@domain1.com but when it first becomes an ip it sends to 201@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@domain1.com [b62db898-d6b1-11e1-be15-73f389528c7f] 2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/306@domain1.com) Running State Change CS_NEW 2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:403 (sofia/internal/306@domain1.com) State NEW 2012-07-26 09:37:35.178096 [DEBUG] sofia.c:5838 Channel sofia/internal/306@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@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@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@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@domain1.com [BREAK] 2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/306@domain1.com) Running State Change CS_INIT 2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/306@domain1.com) State INIT 2012-07-26 09:37:35.178096 [DEBUG] mod_sofia.c:85 sofia/internal/306@domain1.com SOFIA INIT 2012-07-26 09:37:35.178096 [DEBUG] mod_sofia.c:125 (sofia/internal/306@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@domain1.com [BREAK] 2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/306@domain1.com) State INIT going to sleep 2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/306@domain1.com) Running State Change CS_ROUTING 2012-07-26 09:37:35.178096 [DEBUG] switch_channel.c:1919 (sofia/internal/306@domain1.com) Callstate Change DOWN -> RINGING 2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/306@domain1.com) State ROUTING 2012-07-26 09:37:35.178096 [DEBUG] mod_sofia.c:148 sofia/internal/306@domain1.com SOFIA ROUTING 2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:104 sofia/internal/306@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@domain1.com parsing [domain1.com->unloop] continue=false Dialplan: sofia/internal/306@domain1.com parsing [domain1.com->Local_Extension] continue=false Dialplan: sofia/internal/306@domain1.com Regex (PASS) [Local_Extension] destination_number(201) =~ /(^\d{2,7}$)/ break=on-false Dialplan: sofia/internal/306@domain1.com Action set(dialed_extension=201) Dialplan: sofia/internal/306@domain1.com Action export(dialed_extension=201) Dialplan: sofia/internal/306@domain1.com Action limit(hash ${domain_name} 201 ${limit_max} ${limit_destination}) Dialplan: sofia/internal/306@domain1.com Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/306@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@domain1.com Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/306@domain1.com Action bind_meta_app(4 b s execute_extension::att_xfer XML features) Dialplan: sofia/internal/306@domain1.com Action set(ringback=${us-ring}) Dialplan: sofia/internal/306@domain1.com Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/306@domain1.com Action set(call_timeout=30) Dialplan: sofia/internal/306@domain1.com Action set(hangup_after_bridge=true) Dialplan: sofia/internal/306@domain1.com Action set(continue_on_fail=true) Dialplan: sofia/internal/306@domain1.com Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_numbe r}) Dialplan: sofia/internal/306@domain1.com Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/306@domain1.com Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/306@domain1.com Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/306@domain1.com Action bridge(user/${user_data(${destination_number}@${domain_name} attr id)}@${domain_name}) Dialplan: sofia/internal/306@domain1.com Action answer() Dialplan: sofia/internal/306@domain1.com Action sleep(1000) Dialplan: sofia/internal/306@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@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@domain1.com [BREAK] 2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/306@domain1.com) State ROUTING going to sleep 2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/306@domain1.com) Running State Change CS_EXECUTE 2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/306@domain1.com) State EXECUTE 2012-07-26 09:37:35.178096 [DEBUG] mod_sofia.c:241 sofia/internal/306@domain1.com SOFIA EXECUTE 2012-07-26 09:37:35.178096 [DEBUG] switch_core_state_machine.c:196 sofia/internal/306@domain1.com Standard EXECUTE EXECUTE sofia/internal/306@domain1.com set(call_direction=local) 2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305 sofia/internal/306@domain1.com SET [call_direction]=[local] EXECUTE sofia/internal/306@domain1.com set(open=true) 2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305 sofia/internal/306@domain1.com SET [open]=[true] EXECUTE sofia/internal/306@domain1.com hash(insert/domain1.com-spymap/306/b62db898-d6b1-11e1-be15-73f389528c7f) EXECUTE sofia/internal/306@domain1.com hash(insert/domain1.com-last_dial/306/201) EXECUTE sofia/internal/306@domain1.com hash(insert/domain1.com-last_dial/global/b62db898-d6b1-11e1-be15-73f389528c7 f) EXECUTE sofia/internal/306@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@domain1.com SET [RFC2822_DATE]=[Thu, 26 Jul 2012 09:37:35 +1000] EXECUTE sofia/internal/306@domain1.com set(dialed_extension=201) 2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305 sofia/internal/306@domain1.com SET [dialed_extension]=[201] EXECUTE sofia/internal/306@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@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@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@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@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@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@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@domain1.com SET [ringback]=[%(2000, 4000, 440.0, 480.0)] EXECUTE sofia/internal/306@domain1.com set(transfer_ringback=local_stream://moh) 2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305 sofia/internal/306@domain1.com SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/306@domain1.com set(call_timeout=30) 2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305 sofia/internal/306@domain1.com SET [call_timeout]=[30] EXECUTE sofia/internal/306@domain1.com set(hangup_after_bridge=true) 2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305 sofia/internal/306@domain1.com SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/306@domain1.com set(continue_on_fail=true) 2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305 sofia/internal/306@domain1.com SET [continue_on_fail]=[true] EXECUTE sofia/internal/306@domain1.com hash(insert/domain1.com-call_return/201/306) EXECUTE sofia/internal/306@domain1.com hash(insert/domain1.com-last_dial_ext/201/b62db898-d6b1-11e1-be15-73f389528c 7f) EXECUTE sofia/internal/306@domain1.com set(called_party_callgroup=) 2012-07-26 09:37:35.178096 [DEBUG] mod_dptools.c:1305 sofia/internal/306@domain1.com SET [called_party_callgroup]=[UNDEF] EXECUTE sofia/internal/306@domain1.com hash(insert/domain1.com-last_dial//b62db898-d6b1-11e1-be15-73f389528c7f) EXECUTE sofia/internal/306@domain1.com bridge(user/201@domain1.com) 2012-07-26 09:37:35.178096 [DEBUG] switch_channel.c:1047 sofia/internal/306@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@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@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@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@domain1.com] 2012-07-26 09:37:35.198097 [NOTICE] switch_channel.c:926 New Channel sofia/internal/sip:201@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@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@110.143.31.101:1178 [BREAK] 2012-07-26 09:37:35.198097 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:201@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@110.143.31.101:1178) State INIT 2012-07-26 09:37:35.198097 [DEBUG] mod_sofia.c:85 sofia/internal/sip:201@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@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@110.143.31.101:1178 [BREAK] 2012-07-26 09:37:35.198097 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/sip:201@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@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@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@110.143.31.101:1178 [BREAK] 2012-07-26 09:37:35.198097 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/sip:201@110.143.31.101:1178) State ROUTING 2012-07-26 09:37:35.198097 [DEBUG] mod_sofia.c:148 sofia/internal/sip:201@110.143.31.101:1178 SOFIA ROUTING 2012-07-26 09:37:35.198097 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sip:201@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@110.143.31.101:1178 [BREAK] 2012-07-26 09:37:35.198097 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/sip:201@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@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@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@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@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@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@110.143.31.101:1178 [BREAK] 2012-07-26 09:37:35.338097 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:201@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@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@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@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@domain1.com! 2012-07-26 09:37:35.338097 [DEBUG] switch_channel.c:3042 (sofia/internal/306@domain1.com) Callstate Change RINGING -> EARLY 2012-07-26 09:37:35.338097 [DEBUG] switch_core_session.c:777 Send signal sofia/internal/306@domain1.com [BREAK]