VoIP Mailing List Archives

[mkitchin.public at gma...]

I'm working on an alternative to a $120,000 Cisco phone system that my

company is looking at. I got Freeswitch installed on CentOS last week
using the Quick and Dirty instructions. That part was painless. We had a
few 7940s laying around. After some wrestling with it, I got the latest
SIP firmware installed and what I hoped was a functional config
(attached). X-Lite phones can call each other no problem. 7940s can call
X-Lite no problem. Anytime I try and call a 7940, it goes straight to
voicemail. I attached a log file that shows the activity when trying to
call a7940 from X-Lite.
X-Lite is at 10.86.10.58. 7940 is at 10.86.11.50. Freeswitch is
nshplpbx1.unix/10.85.0.53. Everything is on the same LAN. Different
subnets, but no firewalls.
I didn't see anything that said posting attachments was frowned upon. I
apologize if it isn't appropriate. I'm guessing this is something simple
and I'm just clueless on how to diagnose the issue.
I'm not tied to using this model for good, but it is what we had laying
around. Any help would be greatly appreciated. Next step is configuring
it to talk to Verizon VOIP over a DS3.

Thanks,
Matthew Kitchin


dsi> sh conf
------ Current *FLASH* Configuration ------

Platform : Cisco Systems, Inc. IP Phone CP-7940G
Elapsed Time: 01:01:06

dhcp_server : Disabled
my_ip_addr : 10.86.11.50
subnet_mask : 255.255.0.0
defaultgw : 10.86.0.1
dyn_dns_addr_1 : 0.0.0.0
dyn_dns_addr_2 : 0.0.0.0
dns_addr : 10.85.0.11
dns_backup_1: 10.85.0.10
primary_tftp_addr : 10.86.10.58
dyn_tftp_addr : 0.0.0.0
my_mac_addr : 0012:7f98:eaa9
domain_name : dsi-corp.net
my_name : SIP00127F98EAA9
Status Flags : 12300001

image_version : "P003-8-12-00"
FirmLoadID : "PC030301"
DSPLoadID : "PS03AT38"
network_media_type : Auto
network_port2_type : Hub/Switch
dscpForAudio : 184
phone_label : "Matthew Kitchin"
tftp_cfg_dir : ""
phone_password : **********
phone_prompt : "dsi"
language : english
sntp_mode : Unicast
sntp_server : 10.85.0.10
time_zone : CST
dst_offset : 01/00
dst_start_month : March
dst_start_day : 0
dst_start_day_of_week : Sunday
dst_start_week_of_month : 8
dst_start_time : 02/00
dst_stop_month : October
dst_stop_day : 0
dst_stop_day_of_week : Sunday
dst_stop_week_of_month : 8
dst_stop_time : 02/00
dst_auto_adjust : 1
time_format_24hr : 1
date_format : M/D/Y
nat_enable : 0
nat_address : UNPROVISIONED
voip_control_port : 5060
start_media_port : 16384
end_media_port : 32766
sync : "1"
xml_card_dir : ""
xml_card_file : "CARD.XML"
telnet_level : 1
services_url : ""
directory_url : ""
logo_url : ""
http_proxy_addr : UNPROVISIONED
http_proxy_port : 80
garp_enable : 0
enable_vad : 0
dial_template : "dialplan"
callerid_blocking : 0
anonymous_call_block : 0
autocomplete : 0
messages_uri : ""
dnd_control : 2
preferred_codec : g711ulaw
dtmf_outofband : avt_always
dtmf_avt_payload : 101
dtmf_db_level : 3
dtmf_inband : 0
call_manager1_addr : "UNPROVISIONED"
call_manager2_addr : "UNPROVISIONED"
call_manager3_addr : "UNPROVISIONED"
call_manager1_sip_port : 5060
call_manager2_sip_port : 5060
call_manager3_sip_port : 5060
call_manager5_addr : "UNPROVISIONED"
call_manager5_sip_port : 5060
call_manager4_addr : "UNPROVISIONED"
call_manager4_sip_port : 0
line1_name : "1008"
line2_name : "1001"
line1_authname : "1008"
line2_authname : "1001"
line1_password : **********
line2_password : **********
line1_shortname : "1008"
line2_shortname : "1001"
line1_displayname : "1008"
line2_displayname : "UNPROVISIONED"
line1_contact : "UNPROVISIONED"
line2_contact : "UNPROVISIONED"
proxy1_address : "nshplpbx1.unix"
proxy2_address : "nshplpbx1.unix"
proxy1_port : 5060
proxy2_port : 5060
sip_retx : 10
sip_invite_retx : 6
timer_t1 : 500
timer_t2 : 4000
timer_invite_expires : 180
timer_register_expires : 3600
proxy_register : 1
proxy_backup : ""
proxy_emergency : ""
proxy_backup_port : 5060
proxy_emergency_port : 5060
outbound_proxy : UNPROVISIONED
outbound_proxy_port : 5060
nat_received_processing : 0
mwi_status : 0
call_waiting : 1
user_info : phone
cnf_join_enable : 0
remote_party_id : 1
semi_attended_transfer : 1
transfer_onhook_enabled : 0
call_hold_ringback : 3
stutter_msg_waiting : 0
cfwd_url : ""
call_stats : 0
auto_answer : 0
local_cfwd_enable : 1
timer_register_delta : 5
sip_max_forwards : 70
rfc_2543_hold : 0
version_stamp : ""
timer_keepalive_expires : 120
connection_monitor_duration : 120
encrypt_key : **********

2009-11-03 15:39:50.762957 [DEBUG] sofia.c:5067 0 acls to check for proxy
2009-11-03 15:39:50.762957 [DEBUG] sofia.c:5085 network ip is a proxy [0]
2009-11-03 15:39:50.762957 [DEBUG] sofia.c:5113 IP 10.86.10.58 Rejected by acl "domains". Falling back to Digest auth.
2009-11-03 15:39:50.780028 [DEBUG] sofia.c:5067 0 acls to check for proxy
2009-11-03 15:39:50.780028 [DEBUG] sofia.c:5085 network ip is a proxy [0]
2009-11-03 15:39:50.780028 [DEBUG] sofia.c:5113 IP 10.86.10.58 Rejected by acl "domains". Falling back to Digest auth.
2009-11-03 15:39:50.797901 [NOTICE] switch_channel.c:613 New Channel sofia/internal/1000@nshplpbx1.unix [8c133ad4-67cf-4ffa-8655-56ffa0e3933d]
2009-11-03 15:39:50.799061 [DEBUG] sofia.c:5812 Setting NAT mode based on nat.auto
2009-11-03 15:39:50.799061 [DEBUG] sofia.c:3588 Channel sofia/internal/1000@nshplpbx1.unix entering state [received][100]
2009-11-03 15:39:50.799061 [DEBUG] sofia.c:3599 Remote SDP:
v=0
o=- 8 2 IN IP4 10.86.10.58
s=CounterPath X-Lite 3.0
c=IN IP4 10.86.10.58
t=0 0
m=audio 37250 RTP/AVP 107 0 8 101
a=rtpmap:107 BV32/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=alt:1 1 : cwKnUvoi NsQWtT4P 10.86.10.58 37250

2009-11-03 15:39:50.799061 [DEBUG] sofia_glue.c:3160 Audio Codec Compare [BV32:107:16000:0]/[G7221:115:32000:20]
2009-11-03 15:39:50.799061 [DEBUG] sofia_glue.c:3160 Audio Codec Compare [BV32:107:16000:0]/[G7221:107:16000:20]
2009-11-03 15:39:50.799061 [DEBUG] sofia_glue.c:3160 Audio Codec Compare [BV32:107:16000:0]/[G722:9:8000:20]
2009-11-03 15:39:50.799061 [DEBUG] sofia_glue.c:3160 Audio Codec Compare [BV32:107:16000:0]/[PCMU:0:8000:20]
2009-11-03 15:39:50.799061 [DEBUG] sofia_glue.c:3160 Audio Codec Compare [BV32:107:16000:0]/[PCMA:8:8000:20]
2009-11-03 15:39:50.799061 [DEBUG] sofia_glue.c:3160 Audio Codec Compare [BV32:107:16000:0]/[GSM:3:8000:20]
2009-11-03 15:39:50.799061 [DEBUG] sofia_glue.c:3160 Audio Codec Compare [PCMU:0:8000:0]/[G7221:115:32000:20]
2009-11-03 15:39:50.799061 [DEBUG] sofia_glue.c:3160 Audio Codec Compare [PCMU:0:8000:0]/[G7221:107:16000:20]
2009-11-03 15:39:50.799061 [DEBUG] sofia_glue.c:3160 Audio Codec Compare [PCMU:0:8000:0]/[G722:9:8000:20]
2009-11-03 15:39:50.799061 [DEBUG] sofia_glue.c:3160 Audio Codec Compare [PCMU:0:8000:0]/[PCMU:0:8000:20]
2009-11-03 15:39:50.799061 [DEBUG] sofia_glue.c:2102 Set Codec sofia/internal/1000@nshplpbx1.unix PCMU/8000 20 ms 160 samples
2009-11-03 15:39:50.799061 [DEBUG] sofia_glue.c:3120 Set 2833 dtmf payload to 101
2009-11-03 15:39:50.799061 [DEBUG] sofia.c:3744 (sofia/internal/1000@nshplpbx1.unix) State Change CS_NEW -> CS_INIT
2009-11-03 15:39:50.799061 [DEBUG] switch_core_session.c:1003 Send signal sofia/internal/1000@nshplpbx1.unix [BREAK]
2009-11-03 15:39:50.799061 [DEBUG] switch_core_state_machine.c:306 (sofia/internal/1000@nshplpbx1.unix) Running State Change CS_INIT
2009-11-03 15:39:50.799061 [DEBUG] switch_core_state_machine.c:330 (sofia/internal/1000@nshplpbx1.unix) State INIT
2009-11-03 15:39:50.799061 [DEBUG] mod_sofia.c:83 sofia/internal/1000@nshplpbx1.unix SOFIA INIT
2009-11-03 15:39:50.799061 [DEBUG] mod_sofia.c:111 (sofia/internal/1000@nshplpbx1.unix) State Change CS_INIT -> CS_ROUTING
2009-11-03 15:39:50.799061 [DEBUG] switch_core_session.c:1003 Send signal sofia/internal/1000@nshplpbx1.unix [BREAK]
2009-11-03 15:39:50.800189 [DEBUG] switch_core_state_machine.c:330 (sofia/internal/1000@nshplpbx1.unix) State INIT going to sleep
2009-11-03 15:39:50.800189 [DEBUG] switch_core_state_machine.c:306 (sofia/internal/1000@nshplpbx1.unix) Running State Change CS_ROUTING
2009-11-03 15:39:50.800189 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/1000@nshplpbx1.unix) State ROUTING
2009-11-03 15:39:50.800189 [DEBUG] mod_sofia.c:130 sofia/internal/1000@nshplpbx1.unix SOFIA ROUTING
2009-11-03 15:39:50.800189 [DEBUG] switch_core_state_machine.c:78 sofia/internal/1000@nshplpbx1.unix Standard ROUTING
2009-11-03 15:39:50.800189 [INFO] mod_dialplan_xml.c:397 Processing 1000->1008 in context default
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->unloop] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->tod_example] continue=true
Dialplan: day of week[3] =~ 2-6 (PASS)
Dialplan: hour[15] =~ 9-18 (PASS)
Dialplan: sofia/internal/1000@nshplpbx1.unix Date/Time Match (PASS) [tod_example] break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix Action set(open=true)
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->global-intercept] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [global-intercept] destination_number(1008) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->group-intercept] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [group-intercept] destination_number(1008) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->intercept-ext] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [intercept-ext] destination_number(1008) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->redial] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [redial] destination_number(1008) =~ /^870$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->global] continue=true
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never
Dialplan: sofia/internal/1000@nshplpbx1.unix Absolute Condition [global]
Dialplan: sofia/internal/1000@nshplpbx1.unix Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/1000@nshplpbx1.unix Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1000@nshplpbx1.unix Action hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->snom-demo-2] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [snom-demo-2] destination_number(1008) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->snom-demo-1] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [snom-demo-1] destination_number(1008) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [eavesdrop] destination_number(1008) =~ /^88(.*)$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [eavesdrop] destination_number(1008) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->call_return] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [call_return] destination_number(1008) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->del-group] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [del-group] destination_number(1008) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->add-group] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [add-group] destination_number(1008) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->call-group-simo] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [call-group-simo] destination_number(1008) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->call-group-order] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [call-group-order] destination_number(1008) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->extension-intercom] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (FAIL) [extension-intercom] destination_number(1008) =~ /^8(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix parsing [default->Local_Extension] continue=false
Dialplan: sofia/internal/1000@nshplpbx1.unix Regex (PASS) [Local_Extension] destination_number(1008) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1000@nshplpbx1.unix Action set(dialed_extension=1008)
Dialplan: sofia/internal/1000@nshplpbx1.unix Action export(dialed_extension=1008)
Dialplan: sofia/internal/1000@nshplpbx1.unix Action bind_meta_app(1 b s execute_extension::dx XML features)
Dialplan: sofia/internal/1000@nshplpbx1.unix Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
Dialplan: sofia/internal/1000@nshplpbx1.unix Action bind_meta_app(3 b s execute_extension::cf XML features)
Dialplan: sofia/internal/1000@nshplpbx1.unix Action set(ringback=${us-ring})
Dialplan: sofia/internal/1000@nshplpbx1.unix Action set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/1000@nshplpbx1.unix Action set(call_timeout=30)
Dialplan: sofia/internal/1000@nshplpbx1.unix Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/1000@nshplpbx1.unix Action set(continue_on_fail=true)
Dialplan: sofia/internal/1000@nshplpbx1.unix Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
Dialplan: sofia/internal/1000@nshplpbx1.unix Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/internal/1000@nshplpbx1.unix Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
Dialplan: sofia/internal/1000@nshplpbx1.unix Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1000@nshplpbx1.unix Action bridge(user/${dialed_extension}@${domain_name})
Dialplan: sofia/internal/1000@nshplpbx1.unix Action answer()
Dialplan: sofia/internal/1000@nshplpbx1.unix Action sleep(1000)
Dialplan: sofia/internal/1000@nshplpbx1.unix Action voicemail(default ${domain_name} ${dialed_extension})
2009-11-03 15:39:50.801914 [DEBUG] switch_core_state_machine.c:114 (sofia/internal/1000@nshplpbx1.unix) State Change CS_ROUTING -> CS_EXECUTE
2009-11-03 15:39:50.801914 [DEBUG] switch_core_session.c:1003 Send signal sofia/internal/1000@nshplpbx1.unix [BREAK]
2009-11-03 15:39:50.801914 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/1000@nshplpbx1.unix) State ROUTING going to sleep
2009-11-03 15:39:50.801914 [DEBUG] switch_core_state_machine.c:306 (sofia/internal/1000@nshplpbx1.unix) Running State Change CS_EXECUTE
2009-11-03 15:39:50.801914 [DEBUG] switch_core_state_machine.c:340 (sofia/internal/1000@nshplpbx1.unix) State EXECUTE
2009-11-03 15:39:50.801914 [DEBUG] mod_sofia.c:173 sofia/internal/1000@nshplpbx1.unix SOFIA EXECUTE
2009-11-03 15:39:50.801914 [DEBUG] switch_core_state_machine.c:151 sofia/internal/1000@nshplpbx1.unix Standard EXECUTE
EXECUTE sofia/internal/1000@nshplpbx1.unix set(open=true)
2009-11-03 15:39:50.803724 [DEBUG] mod_dptools.c:763 sofia/internal/1000@nshplpbx1.unix SET [open]=[true]
EXECUTE sofia/internal/1000@nshplpbx1.unix hash(insert/10.85.0.53-spymap/1000/8c133ad4-67cf-4ffa-8655-56ffa0e3933d)
EXECUTE sofia/internal/1000@nshplpbx1.unix hash(insert/10.85.0.53-last_dial/1000/1008)
EXECUTE sofia/internal/1000@nshplpbx1.unix hash(insert/10.85.0.53-last_dial/global/8c133ad4-67cf-4ffa-8655-56ffa0e3933d)
EXECUTE sofia/internal/1000@nshplpbx1.unix set(dialed_extension=1008)
2009-11-03 15:39:50.803724 [DEBUG] mod_dptools.c:763 sofia/internal/1000@nshplpbx1.unix SET [dialed_extension]=[1008]
EXECUTE sofia/internal/1000@nshplpbx1.unix export(dialed_extension=1008)
2009-11-03 15:39:50.803724 [DEBUG] mod_dptools.c:846 EXPORT [dialed_extension]=[1008]
EXECUTE sofia/internal/1000@nshplpbx1.unix bind_meta_app(1 b s execute_extension::dx XML features)
2009-11-03 15:39:50.804911 [INFO] switch_ivr_async.c:2151 Bound B-Leg: 1 execute_extension::dx XML features
EXECUTE sofia/internal/1000@nshplpbx1.unix bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1000.2009-11-03-15-39-50.wav)
2009-11-03 15:39:50.804911 [INFO] switch_ivr_async.c:2151 Bound B-Leg: 2 record_session::/usr/local/freeswitch/recordings/1000.2009-11-03-15-39-50.wav
EXECUTE sofia/internal/1000@nshplpbx1.unix bind_meta_app(3 b s execute_extension::cf XML features)
2009-11-03 15:39:50.804911 [INFO] switch_ivr_async.c:2151 Bound B-Leg: 3 execute_extension::cf XML features
EXECUTE sofia/internal/1000@nshplpbx1.unix set(ringback=%(2000,4000,440.0,480.0))
2009-11-03 15:39:50.804911 [DEBUG] mod_dptools.c:763 sofia/internal/1000@nshplpbx1.unix SET [ringback]=[%(2000,4000,440.0,480.0)]
EXECUTE sofia/internal/1000@nshplpbx1.unix set(transfer_ringback=local_stream://moh)
2009-11-03 15:39:50.804911 [DEBUG] mod_dptools.c:763 sofia/internal/1000@nshplpbx1.unix SET [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/1000@nshplpbx1.unix set(call_timeout=30)
2009-11-03 15:39:50.804911 [DEBUG] mod_dptools.c:763 sofia/internal/1000@nshplpbx1.unix SET [call_timeout]=[30]
EXECUTE sofia/internal/1000@nshplpbx1.unix set(hangup_after_bridge=true)
2009-11-03 15:39:50.806131 [DEBUG] mod_dptools.c:763 sofia/internal/1000@nshplpbx1.unix SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/1000@nshplpbx1.unix set(continue_on_fail=true)
2009-11-03 15:39:50.806131 [DEBUG] mod_dptools.c:763 sofia/internal/1000@nshplpbx1.unix SET [continue_on_fail]=[true]
EXECUTE sofia/internal/1000@nshplpbx1.unix hash(insert/10.85.0.53-call_return/1008/1000)
EXECUTE sofia/internal/1000@nshplpbx1.unix hash(insert/10.85.0.53-last_dial_ext/1008/8c133ad4-67cf-4ffa-8655-56ffa0e3933d)
EXECUTE sofia/internal/1000@nshplpbx1.unix set(called_party_callgroup=techsupport)
2009-11-03 15:39:50.806131 [DEBUG] mod_dptools.c:763 sofia/internal/1000@nshplpbx1.unix SET [called_party_callgroup]=[techsupport]
EXECUTE sofia/internal/1000@nshplpbx1.unix hash(insert/10.85.0.53-last_dial/techsupport/8c133ad4-67cf-4ffa-8655-56ffa0e3933d)
EXECUTE sofia/internal/1000@nshplpbx1.unix bridge(user/1008@10.85.0.53)
2009-11-03 15:39:50.812162 [DEBUG] switch_ivr_originate.c:1333 variable string 0 = [presence_id=1008@10.85.0.53]
2009-11-03 15:39:50.812162 [NOTICE] switch_channel.c:613 New Channel sofia/internal/sip:1008@10.86.11.50:5060 [32661f42-b0a9-4179-867d-156b46ae71ce]
2009-11-03 15:39:50.812162 [DEBUG] mod_sofia.c:3061 (sofia/internal/sip:1008@10.86.11.50:5060) State Change CS_NEW -> CS_INIT
2009-11-03 15:39:50.812162 [DEBUG] switch_core_session.c:1003 Send signal sofia/internal/sip:1008@10.86.11.50:5060 [BREAK]
2009-11-03 15:39:50.812162 [DEBUG] switch_core_state_machine.c:306 (sofia/internal/sip:1008@10.86.11.50:5060) Running State Change CS_INIT
2009-11-03 15:39:50.812162 [DEBUG] switch_core_state_machine.c:330 (sofia/internal/sip:1008@10.86.11.50:5060) State INIT
2009-11-03 15:39:50.812162 [DEBUG] mod_sofia.c:83 sofia/internal/sip:1008@10.86.11.50:5060 SOFIA INIT
2009-11-03 15:39:50.812162 [DEBUG] sofia_glue.c:1761 sip:1008@10.86.11.50:51061;user=phone;transport=udp Setting proxy route to sofia/internal/sip:1008@10.86.11.50:5060
2009-11-03 15:39:50.814226 [DEBUG] mod_sofia.c:111 (sofia/internal/sip:1008@10.86.11.50:5060) State Change CS_INIT -> CS_ROUTING
2009-11-03 15:39:50.814226 [DEBUG] switch_core_session.c:1003 Send signal sofia/internal/sip:1008@10.86.11.50:5060 [BREAK]
2009-11-03 15:39:50.814226 [DEBUG] sofia.c:3588 Channel sofia/internal/sip:1008@10.86.11.50:5060 entering state [calling][0]
2009-11-03 15:39:50.814226 [DEBUG] switch_core_state_machine.c:330 (sofia/internal/sip:1008@10.86.11.50:5060) State INIT going to sleep
2009-11-03 15:39:50.814226 [DEBUG] switch_core_state_machine.c:306 (sofia/internal/sip:1008@10.86.11.50:5060) Running State Change CS_ROUTING
2009-11-03 15:39:50.814226 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/sip:1008@10.86.11.50:5060) State ROUTING
2009-11-03 15:39:50.814226 [DEBUG] mod_sofia.c:130 sofia/internal/sip:1008@10.86.11.50:5060 SOFIA ROUTING
2009-11-03 15:39:50.814226 [DEBUG] switch_ivr_originate.c:66 (sofia/internal/sip:1008@10.86.11.50:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2009-11-03 15:39:50.814226 [DEBUG] switch_core_session.c:1003 Send signal sofia/internal/sip:1008@10.86.11.50:5060 [BREAK]
2009-11-03 15:39:50.814226 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/sip:1008@10.86.11.50:5060) State ROUTING going to sleep
2009-11-03 15:39:50.814226 [DEBUG] switch_core_state_machine.c:306 (sofia/internal/sip:1008@10.86.11.50:5060) Running State Change CS_CONSUME_MEDIA
2009-11-03 15:39:50.814226 [DEBUG] switch_core_state_machine.c:352 (sofia/internal/sip:1008@10.86.11.50:5060) State CONSUME_MEDIA
2009-11-03 15:39:50.814226 [DEBUG] switch_core_state_machine.c:352 (sofia/internal/sip:1008@10.86.11.50:5060) State CONSUME_MEDIA going to sleep
2009-11-03 15:39:50.817484 [DEBUG] sofia.c:3588 Channel sofia/internal/sip:1008@10.86.11.50:5060 entering state [terminated][503]
2009-11-03 15:39:50.817484 [NOTICE] sofia.c:4187 Hangup sofia/internal/sip:1008@10.86.11.50:5060 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
2009-11-03 15:39:50.817484 [DEBUG] switch_channel.c:1896 Send signal sofia/internal/sip:1008@10.86.11.50:5060 [KILL]
2009-11-03 15:39:50.817484 [DEBUG] switch_core_session.c:1003 Send signal sofia/internal/sip:1008@10.86.11.50:5060 [BREAK]
2009-11-03 15:39:50.817484 [DEBUG] switch_core_state_machine.c:451 thread mismatch skipping state handler.
2009-11-03 15:39:50.817484 [DEBUG] switch_ivr_originate.c:2543 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2009-11-03 15:39:50.817484 [ERR] switch_ivr_originate.c:1829 Cannot create outgoing channel of type [user] cause: [NORMAL_TEMPORARY_FAILURE]
2009-11-03 15:39:50.817484 [DEBUG] switch_ivr_originate.c:2543 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2009-11-03 15:39:50.817484 [INFO] mod_dptools.c:2290 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE
2009-11-03 15:39:50.817484 [DEBUG] mod_dptools.c:2312 Continue on fail [true]: Cause: NORMAL_TEMPORARY_FAILURE
EXECUTE sofia/internal/1000@nshplpbx1.unix answer()
2009-11-03 15:39:50.817484 [DEBUG] mod_dptools.c:653 sofia/internal/1000@nshplpbx1.unix receive message [ANSWER]
2009-11-03 15:39:50.817484 [DEBUG] sofia_glue.c:2336 AUDIO RTP [sofia/internal/1000@nshplpbx1.unix] 10.85.0.53 port 24712 -> 10.86.10.58 port 37250 codec: 0 ms: 20
2009-11-03 15:39:50.817484 [DEBUG] switch_rtp.c:1155 Starting timer [soft] 160 bytes per 20ms
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:306 (sofia/internal/sip:1008@10.86.11.50:5060) Running State Change CS_HANGUP
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/sip:1008@10.86.11.50:5060) State HANGUP
2009-11-03 15:39:50.818924 [DEBUG] mod_sofia.c:329 sofia/internal/sip:1008@10.86.11.50:5060 Overriding SIP cause 503 with 503 from the other leg
2009-11-03 15:39:50.818924 [DEBUG] mod_sofia.c:361 Channel sofia/internal/sip:1008@10.86.11.50:5060 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:46 sofia/internal/sip:1008@10.86.11.50:5060 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/sip:1008@10.86.11.50:5060) State HANGUP going to sleep
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:325 (sofia/internal/sip:1008@10.86.11.50:5060) State Change CS_HANGUP -> CS_REPORTING
2009-11-03 15:39:50.818924 [DEBUG] switch_core_session.c:1003 Send signal sofia/internal/sip:1008@10.86.11.50:5060 [BREAK]
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:306 (sofia/internal/sip:1008@10.86.11.50:5060) Running State Change CS_REPORTING
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/sip:1008@10.86.11.50:5060) State REPORTING
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:53 sofia/internal/sip:1008@10.86.11.50:5060 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/sip:1008@10.86.11.50:5060) State REPORTING going to sleep
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:319 (sofia/internal/sip:1008@10.86.11.50:5060) State Change CS_REPORTING -> CS_DESTROY
2009-11-03 15:39:50.818924 [DEBUG] switch_core_session.c:1003 Send signal sofia/internal/sip:1008@10.86.11.50:5060 [BREAK]
2009-11-03 15:39:50.818924 [DEBUG] switch_core_session.c:1140 Session 32 (sofia/internal/sip:1008@10.86.11.50:5060) Locked, Waiting on external entities
2009-11-03 15:39:50.818924 [NOTICE] switch_core_session.c:1158 Session 32 (sofia/internal/sip:1008@10.86.11.50:5060) Ended
2009-11-03 15:39:50.818924 [NOTICE] switch_core_session.c:1160 Close Channel sofia/internal/sip:1008@10.86.11.50:5060 [CS_DESTROY]
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1008@10.86.11.50:5060) Running State Change CS_DESTROY
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:426 (sofia/internal/sip:1008@10.86.11.50:5060) State DESTROY
2009-11-03 15:39:50.818924 [DEBUG] mod_sofia.c:278 sofia/internal/sip:1008@10.86.11.50:5060 SOFIA DESTROY
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:60 sofia/internal/sip:1008@10.86.11.50:5060 Standard DESTROY
2009-11-03 15:39:50.818924 [DEBUG] switch_core_state_machine.c:426 (sofia/internal/sip:1008@10.86.11.50:5060) State DESTROY going to sleep
2009-11-03 15:39:50.820304 [DEBUG] mod_sofia.c:569 Local SDP sofia/internal/1000@nshplpbx1.unix:
v=0
o=FreeSWITCH 1257259678 1257259679 IN IP4 10.85.0.53
s=FreeSWITCH
c=IN IP4 10.85.0.53
t=0 0
m=audio 24712 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

2009-11-03 15:39:50.821960 [DEBUG] sofia.c:3588 Channel sofia/internal/1000@nshplpbx1.unix entering state [completed][200]
2009-11-03 15:39:50.821960 [DEBUG] switch_core_session.c:664 Send signal sofia/internal/1000@nshplpbx1.unix [BREAK]
2009-11-03 15:39:50.821960 [NOTICE] mod_dptools.c:653 Channel [sofia/internal/1000@nshplpbx1.unix] has been answered
2009-11-03 15:39:50.821960 [DEBUG] switch_channel.c:182 sofia/internal/1000@nshplpbx1.unix receive message [AUDIO_SYNC]
EXECUTE sofia/internal/1000@nshplpbx1.unix sleep(1000)
2009-11-03 15:39:50.821960 [DEBUG] switch_channel.c:182 sofia/internal/1000@nshplpbx1.unix receive message [AUDIO_SYNC]
2009-11-03 15:39:50.867612 [DEBUG] switch_rtp.c:1917 Correct ip/port confirmed.
2009-11-03 15:39:50.926503 [DEBUG] sofia.c:3588 Channel sofia/internal/1000@nshplpbx1.unix entering state [ready][200]
EXECUTE sofia/internal/1000@nshplpbx1.unix voicemail(default 10.85.0.53 1008)
2009-11-03 15:39:51.840356 [DEBUG] mod_voicemail.c:799 [default] rwlock
2009-11-03 15:39:51.840356 [DEBUG] switch_channel.c:182 sofia/internal/1000@nshplpbx1.unix receive message [AUDIO_SYNC]
2009-11-03 15:39:51.959567 [DEBUG] switch_ivr_play_say.c:118 No language specified - Using [en]
2009-11-03 15:39:51.961607 [DEBUG] switch_ivr_play_say.c:273 Handle play-file:[voicemail/vm-person.wav] (en:en)
2009-11-03 15:39:51.961607 [DEBUG] switch_ivr_play_say.c:1136 Codec Activated L16@8000hz 1 channels 20ms
2009-11-03 15:39:51.961607 [DEBUG] switch_core_io.c:660 sofia/internal/1000@nshplpbx1.unix receive message [TRANSCODING_NECESSARY]
2009-11-03 15:39:53.319706 [DEBUG] switch_ivr_play_say.c:1428 done playing file
2009-11-03 15:39:53.439693 [DEBUG] switch_ivr_play_say.c:273 Handle say:[1008] (en:en)
2009-11-03 15:39:53.439693 [DEBUG] switch_ivr_play_say.c:1136 Codec Activated L16@8000hz 1 channels 20ms
2009-11-03 15:39:53.439693 [DEBUG] switch_core_io.c:660 sofia/internal/1000@nshplpbx1.unix receive message [TRANSCODING_NECESSARY]
2009-11-03 15:39:53.899622 [DEBUG] switch_ivr_play_say.c:1428 done playing file
2009-11-03 15:39:53.899622 [DEBUG] switch_ivr_play_say.c:1136 Codec Activated L16@8000hz 1 channels 20ms
2009-11-03 15:39:53.899622 [DEBUG] switch_core_io.c:660 sofia/internal/1000@nshplpbx1.unix receive message [TRANSCODING_NECESSARY]
2009-11-03 15:39:54.127652 [NOTICE] sofia.c:328 Hangup sofia/internal/1000@nshplpbx1.unix [CS_EXECUTE] [NORMAL_CLEARING]
2009-11-03 15:39:54.127652 [DEBUG] switch_channel.c:1896 Send signal sofia/internal/1000@nshplpbx1.unix [KILL]
2009-11-03 15:39:54.127652 [DEBUG] switch_core_session.c:1003 Send signal sofia/internal/1000@nshplpbx1.unix [BREAK]
2009-11-03 15:39:54.127652 [DEBUG] switch_core_state_machine.c:451 thread mismatch skipping state handler.
2009-11-03 15:39:54.139706 [DEBUG] switch_ivr_play_say.c:1428 done playing file
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:340 (sofia/internal/1000@nshplpbx1.unix) State EXECUTE going to sleep
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:306 (sofia/internal/1000@nshplpbx1.unix) Running State Change CS_HANGUP
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1000@nshplpbx1.unix) State HANGUP
2009-11-03 15:39:54.239929 [DEBUG] mod_sofia.c:329 sofia/internal/1000@nshplpbx1.unix Overriding SIP cause 480 with 503 from the other leg
2009-11-03 15:39:54.239929 [DEBUG] mod_sofia.c:361 Channel sofia/internal/1000@nshplpbx1.unix hanging up, cause: NORMAL_CLEARING
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:46 sofia/internal/1000@nshplpbx1.unix Standard HANGUP, cause: NORMAL_CLEARING
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1000@nshplpbx1.unix) State HANGUP going to sleep
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:325 (sofia/internal/1000@nshplpbx1.unix) State Change CS_HANGUP -> CS_REPORTING
2009-11-03 15:39:54.239929 [DEBUG] switch_core_session.c:1003 Send signal sofia/internal/1000@nshplpbx1.unix [BREAK]
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:306 (sofia/internal/1000@nshplpbx1.unix) Running State Change CS_REPORTING
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/1000@nshplpbx1.unix) State REPORTING
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:53 sofia/internal/1000@nshplpbx1.unix Standard REPORTING, cause: NORMAL_CLEARING
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/1000@nshplpbx1.unix) State REPORTING going to sleep
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:319 (sofia/internal/1000@nshplpbx1.unix) State Change CS_REPORTING -> CS_DESTROY
2009-11-03 15:39:54.239929 [DEBUG] switch_core_session.c:1003 Send signal sofia/internal/1000@nshplpbx1.unix [BREAK]
2009-11-03 15:39:54.239929 [DEBUG] switch_core_session.c:1140 Session 31 (sofia/internal/1000@nshplpbx1.unix) Locked, Waiting on external entities
2009-11-03 15:39:54.239929 [NOTICE] switch_core_session.c:1158 Session 31 (sofia/internal/1000@nshplpbx1.unix) Ended
2009-11-03 15:39:54.239929 [NOTICE] switch_core_session.c:1160 Close Channel sofia/internal/1000@nshplpbx1.unix [CS_DESTROY]
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1000@nshplpbx1.unix) Running State Change CS_DESTROY
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:426 (sofia/internal/1000@nshplpbx1.unix) State DESTROY
2009-11-03 15:39:54.239929 [DEBUG] mod_sofia.c:278 sofia/internal/1000@nshplpbx1.unix SOFIA DESTROY
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@nshplpbx1.unix Standard DESTROY
2009-11-03 15:39:54.239929 [DEBUG] switch_core_state_machine.c:426 (sofia/internal/1000@nshplpbx1.unix) State DESTROY going to sleep
]0;root@NSHPLPBX1:/usr/local/freeswitch/log[root@NSHPLPBX1 log]# _______________________________________________
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

[msc at freeswitch.org]

On Tue, Nov 3, 2009 at 2:19 PM, mkitchin.public@gmail.com (mkitchin.public@gmail.com) <mkitchin.public@gmail.com (mkitchin.public@gmail.com)> wrote:

[mkitchin.public at gma...]

Michael Collins wrote:

[peter at cindyandpeter...]

Matthew,

I'm about in the same boat as you are, just on a smaller scale. We have a
ton of Nortel telephony gear, but it's time to move out of the 90's and
enter this millennium. My Cisco quote was in the same ballpark as yours.

The Cisco stuff is mature, rock solid, meshes very well with their network
gear and is actually relatively easy to set up and maintain if you know your
way around IOS. I just refuse to pay that kind of money for yet another
semi-proprietary solution.

After looking at various asterisk distributions, SipX, 3CX and
what-have-you, I've come to the conclusion that FreeSWITCH is by far the
most advanced platform out there. Its architecture and performance is
literally light years ahead of the rest and I have yet to come up with
something that it can't do. But all that comes at a price: The learning
curve is like scaling a brick wall. The developers and the community are
great and available, but just starting out with SIP and voip in general,
this may not be the best platform. So let the blasphemy begin

SipX was a breeze to install (insert CD, boot, next next next...) and looks
pretty solid. I believe they actually use FreeSWITCH for their voicemail and
conferencing, internally. I just couldn't get my head around their GUI, ACD
was too basic and had all kinds of issues getting stuff to "just work".

3CX (Windows Only) was completely painless. It just worked. But I'm still
not convinced that I want to run all my voice on a single windows box. Plus
it's not free/open/etc and I don't want to lock myself in again.

Although it's an asterisk based solution, I found trixbox to be very easy.
Setup is automatic and everything "just worked". The GUI is simple and
logical enough that I can let somebody else handle the day-to-day phone
setup and basic admin. I have my doubts about it scaling to 250 users,
though.

This may be a completely flawed strategy and I may very well be shooting
myself in the foot by doing this, but I plan on piloting a trixbox install
with a dozen or so users and see how stable it is. I'll keep a FreeSWITCH
box next to it for the more advanced stuff. Once I get more comfortable with
the intricacies of SIP and get some time to code a basic GUI for FreeSWITCH,
I have a feeling that that trixbox is going to get phased out...

Peter


-----Original Message-----
From: freeswitch-users-bounces@lists.freeswitch.org
[mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of
mkitchin.public@gmail.com
Sent: Tuesday, November 03, 2009 11:10 PM
To: freeswitch-users@lists.freeswitch.org
Subject: Re: [Freeswitch-users] Newbie trying to setup Cisco 7940 phones

Michael Collins wrote:

[jason at jasonjgw.net]

Peter J. Zandvoort <peter@cindyandpeter.com> wrote:

[sicfslist at gmail.com]

Peter,

Did you look at http://www.cudatel.com? Probably just what you are
looking for. GUI goodness based on FS.

SDR

Peter J. Zandvoort wrote:

[peter at cindyandpeter...]

Absolutely agreed. To use Matthew's original car metaphor: When you just got
your learner's permit, the old Chevy may be a better choice than the
Ferrari.


-----Original Message-----
From: freeswitch-users-bounces@lists.freeswitch.org
[mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Jason
White
Sent: Wednesday, November 04, 2009 1:42 AM
To: freeswitch-users@lists.freeswitch.org
Subject: Re: [Freeswitch-users] Newbie trying to setup Cisco 7940 phones

Peter J. Zandvoort <peter@cindyandpeter.com> wrote:

[mastermind202 at gmail...]

I had the exact same problem with the Cisco phones not being able to
receive calls.

I fixed it by messing around with the NAT settings in the internal
sofia profile. From what I remember,
I just removed the <param name="apply-nat-acl" value="nat.auto"/> line
and everything worked fine.

-- mm_202.

On Wed, Nov 4, 2009 at 11:33 AM, Peter J. Zandvoort
<peter@cindyandpeter.com> wrote:

[mkitchin.public at gma...]

I hate to say it, but I had to give in and try sipx. the ease of
provisioning phones and the ability for helpdesk staff to reset
passwords and such through a gui looks like it is too good for me to
pass on.

mm_202 wrote: