- FreeSWITCH-users - FreeSWITCH Mailing Lists

Possible registration/presence bug - Sometimes get "Originate Failed. Cause: USER_NOT_REGISTERED" when extension registration is present
by Phil Quesinberry 02 Apr '12

02 Apr '12

Hi, I've noticed what appears to be a bug which I wanted to bring to your attention. Sometimes when FS is started, extensions can't be called even after they've registered. This doesn't happen all the time. and restarting FS always solves the problem. Just to be clear - this problem only sometimes occurs when FS has been started/restarted, like after an update. Once FS has "started successfully" and sees presence for registered extensions, it continues to work fine. It's all or nothing - no extensions can be dialed when this issue is present, whether they're local or NATted. If one extension can be reached, you can reach them all (if they're registered, of course). See debug info below on an attempt to dial a local (no NAT) extension - this was one of the recent beta git pulls and the problem has been present through several updates. Let me know if you need any additional info. freeswitch@internal> show registrations reg_user,realm,token,url,expires,network_ip,network_port,network_proto,hostn ame 102,192.168.1.6,a7289b6393a8023e,sofia/internal/sip:102@192.168.1.4:5060;tra nsport=udp,1333338853,192.168.1.4,5060,udp,server.home 257,192.168.1.6,aab02ec49af03567,sofia/internal/sip:257@74.93.222.182:5060;t ransport=udp,1333338709,74.93.xx.xx,5060,udp,server.home 2001,192.168.1.6,bae1af9975ebfa50,sofia/internal/sip:2001@192.168.1.4:5060;t ransport=udp,1333338743,192.168.1.4,5060,udp,server.home 227,192.168.1.6,42db21f84f52e3ef,sofia/internal/sip:227@74.93.222.182:1066;t ransport=udp,1333338747,74.93.xx.xx,1066,udp,server.home 226,192.168.1.6,25619841fc53c75e,sofia/internal/sip:226@74.93.222.182:1068;t ransport=udp,1333338751,74.93.xx.xx,1068,udp,server.home 225,192.168.1.6,308cce2ca1734cdc,sofia/internal/sip:225@74.93.222.182:1067;t ransport=udp,1333338751,74.93.xx.xx,1067,udp,server.home 3900,192.168.1.6,54667b49ca74cabe,sofia/internal/sip:3900@173.66.100.94:5462 9;transport=udp;fs_nat=yes,1333338762,173.66.xx.xx,54629,udp,server.home 3901,192.168.1.6,6dc54f7994ffb61a,sofia/internal/sip:3901@173.66.100.94:6480 ;transport=udp;fs_nat=yes,1333338779,173.66.xx.xx,6480,udp,server.home 519,192.168.1.6,45249b30-85ddd13a@10.0.0.159,sofia/internal/sip:519@74.93.22 2.182:1062,1333338779,74.93.xx.xx,1062,udp,server.home 9 total. 2012-04-01 23:50:41.449612 [DEBUG] sofia.c:7576 IP 192.168.1.4 Rejected by acl "domains". Falling back to Digest auth. 2012-04-01 23:50:41.449612 [WARNING] sofia_reg.c:1422 SIP auth challenge (INVITE) on sofia profile 'internal' for [2001(a)192.168.1.6] from ip 192.168.1.4 2012-04-01 23:50:41.549553 [DEBUG] sofia.c:7576 IP 192.168.1.4 Rejected by acl "domains". Falling back to Digest auth. 2012-04-01 23:50:41.549553 [NOTICE] switch_channel.c:926 New Channel sofia/internal/102@192.168.1.6:5060 [9a9a3bde-116c-4100-b269-a6be7455c6c1] 2012-04-01 23:50:41.549553 [DEBUG] sofia.c:5541 Channel sofia/internal/102@192.168.1.6:5060 entering state [received][100] 2012-04-01 23:50:41.549553 [DEBUG] sofia.c:5552 Remote SDP: v=0 o=MxSIP 0 1 IN IP4 192.168.1.4 s=SIP Call c=IN IP4 192.168.1.4 t=0 0 m=audio 16384 RTP/AVP 0 110 8 9 a=rtpmap:0 PCMU/8000 a=rtpmap:110 PCMU/16000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=silenceSupp:off - - - - a=ptime:20 2012-04-01 23:50:41.549553 [DEBUG] sofia.c:5746 (sofia/internal/102@192.168.1.6:5060) State Change CS_NEW -> CS_INIT 2012-04-01 23:50:41.549553 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/102@192.168.1.6:5060 [BREAK] 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/102@192.168.1.6:5060) Running State Change CS_INIT 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/102@192.168.1.6:5060) State INIT 2012-04-01 23:50:41.549553 [DEBUG] mod_sofia.c:85 sofia/internal/102@192.168.1.6:5060 SOFIA INIT 2012-04-01 23:50:41.549553 [DEBUG] mod_sofia.c:125 (sofia/internal/102@192.168.1.6:5060) State Change CS_INIT -> CS_ROUTING 2012-04-01 23:50:41.549553 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/102@192.168.1.6:5060 [BREAK] 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/102@192.168.1.6:5060) State INIT going to sleep 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/102@192.168.1.6:5060) Running State Change CS_ROUTING 2012-04-01 23:50:41.549553 [DEBUG] switch_channel.c:1886 (sofia/internal/102@192.168.1.6:5060) Callstate Change DOWN -> RINGING 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/102@192.168.1.6:5060) State ROUTING 2012-04-01 23:50:41.549553 [DEBUG] mod_sofia.c:148 sofia/internal/102@192.168.1.6:5060 SOFIA ROUTING 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:104 sofia/internal/102@192.168.1.6:5060 Standard ROUTING 2012-04-01 23:50:41.549553 [INFO] mod_dialplan_xml.c:485 Processing Phil <102>->2001 in context default Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->unloop] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->call_direction] continue=true Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [call_direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 ANTI-Action set(call_direction=local) Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->tod_example] continue=true Dialplan: sofia/internal/102@192.168.1.6:5060 Date/TimeMatch (FAIL) [tod_example] break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->holiday_example] continue=true Dialplan: sofia/internal/102@192.168.1.6:5060 Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [group-intercept] destination_number(2001) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->redial] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [redial] destination_number(2001) =~ /^(redial|\*870)$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->global] continue=true Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/internal/102@192.168.1.6:5060 Absolute Condition [global] Dialplan: sofia/internal/102@192.168.1.6:5060 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/102@192.168.1.6:5060 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_numbe r}) Dialplan: sofia/internal/102@192.168.1.6:5060 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/102@192.168.1.6:5060 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [snom-demo-2] destination_number(2001) =~ /^\*9001$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [snom-demo-1] destination_number(2001) =~ /^\*9000$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->call_privacy] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [call_privacy] destination_number(2001) =~ /^\*67(\d+)$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->call_return] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [call_return] destination_number(2001) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->del-group] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [del-group] destination_number(2001) =~ /^\*\*80(\d{2})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->add-group] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [add-group] destination_number(2001) =~ /^\*\*81(\d{2})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [call-group-simo] destination_number(2001) =~ /^\*\*82(\d{2})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [call-group-order] destination_number(2001) =~ /^\*83(\d{2})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [intercept-ext] destination_number(2001) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->Local_Extension_Skinny] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [Local_Extension_Skinny] destination_number(2001) =~ /^(11[01][0-9])$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->send_to_voicemail] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [send_to_voicemail] destination_number(2001) =~ /^\*99(\d{2,7})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->enum.9.10d] continue=true Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [enum.9.10d] destination_number(2001) =~ /^9(\d{10})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->enum.9.11d] continue=true Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [enum.9.11d] destination_number(2001) =~ /^9(\d{11})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->SipBroker.SIPDial] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [SipBroker.SIPDial] destination_number(2001) =~ /^([*]\d{5,})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->SipBroker.Toll_Free] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [SipBroker.Toll_Free] destination_number(2001) =~ /^91?(8(00|66|77|88)[2-9]\d{6})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->TollFreeGateway] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [TollFreeGateway] destination_number(2001) =~ /^91?(8(00|55|66|77|88)[2-9]\d{6})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->FlowRoute.91d10or11] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [FlowRoute.91d10or11] destination_number(2001) =~ /^91?(\d{10})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->HL7519.9.10d] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [HL7519.9.10d] caller_id_number(102) =~ /519/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->HL7519.9.11d] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [HL7519.9.11d] caller_id_number(102) =~ /519/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->HL7612.9.10d] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (PASS) [HL7612.9.10d] ${toll_allow}(local,domestic) =~ /local/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [HL7612.9.10d] destination_number(2001) =~ /^9(\d{10})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->HL7612.9.11d] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (PASS) [HL7612.9.11d] ${toll_allow}(local,domestic) =~ /local/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [HL7612.9.11d] destination_number(2001) =~ /^9(\d{11})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->enum.7d7] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [enum.7d7] destination_number(2001) =~ /^7(\d{7})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->xmpp.8d10] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [xmpp.8d10] destination_number(2001) =~ /^8(\d{10})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->xmpp.8d11] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [xmpp.8d11] destination_number(2001) =~ /^8(\d{11})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->Talking Clock Time] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [Talking Clock Time] destination_number(2001) =~ /^9170$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->Talking Clock Date] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [Talking Clock Date] destination_number(2001) =~ /^9171$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->Talking Clock Date and Time] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [Talking Clock Date and Time] destination_number(2001) =~ /^9172$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->Recordings] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [Recordings] destination_number(2001) =~ /^\*(732)$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->Company_Directory] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [Company_Directory] destination_number(2001) =~ /^5001$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->Hersch_Lauren_Main] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [Hersch_Lauren_Main] destination_number(2001) =~ /^5000$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->Holiday_Announcement] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [Holiday_Announcement] destination_number(2001) =~ /^5010$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->Ring all admin phones.park] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [Ring all admin phones.park] destination_number(2001) =~ /^\*1001$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->Ring all admin phones] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [Ring all admin phones] destination_number(2001) =~ /^1001$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->group_dial_sales] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [group_dial_sales] destination_number(2001) =~ /^\*2000$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->group_dial_support] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [group_dial_support] destination_number(2001) =~ /^\*2001$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->group_dial_billing] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [group_dial_billing] destination_number(2001) =~ /^\*2002$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->operator] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [operator] destination_number(2001) =~ /^operator$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->vmain] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [vmain] destination_number(2001) =~ /^vmain$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->vmain1] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [vmain1] destination_number(2001) =~ /^vmain1$|^\*97$|^\*4000$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->vmain2] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [vmain2] destination_number(2001) =~ /^vmain2$|^\*98$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->sip_uri] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [sip_uri] destination_number(2001) =~ /^sip:(.*)$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->nb_conferences] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [nb_conferences] destination_number(2001) =~ /^\*(30\d{2})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->wb_conferences] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [wb_conferences] destination_number(2001) =~ /^\*(31\d{2})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->uwb_conferences] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [uwb_conferences] destination_number(2001) =~ /^\*(32\d{2})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->cdquality_conferences] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [cdquality_conferences] destination_number(2001) =~ /^\*(33\d{2})$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(2001) =~ /^\*9(888|8888|1616|3232)$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->ivr_demo] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [ivr_demo] destination_number(2001) =~ /^\*5000$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->dynamic_conference] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [dynamic_conference] destination_number(2001) =~ /^\*5001$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->rtp_multicast_page] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [rtp_multicast_page] destination_number(2001) =~ /^pagegroup$|^\*7243$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->parking_slots] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [parking_slots] destination_number(2001) =~ /^(\*59[0-9][0-9])$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->valet_park_in] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [valet_park_in] destination_number(2001) =~ /^\*(6000)$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->valet_park_out] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [valet_park_out] destination_number(2001) =~ /^\*(60\d\d)$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->park] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [park] destination_number(2001) =~ /park\+(\d+)/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->unpark] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [unpark] destination_number(2001) =~ /^parking$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->park] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [park] destination_number(2001) =~ /callpark/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->unpark] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [unpark] destination_number(2001) =~ /pickup/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->wait] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [wait] destination_number(2001) =~ /^wait$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->fax_receive] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [fax_receive] destination_number(2001) =~ /^\*9178$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->fax_transmit] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [fax_transmit] destination_number(2001) =~ /^\*9179$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->ringback_180] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [ringback_180] destination_number(2001) =~ /^\*9180$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->ringback_183_uk_ring] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [ringback_183_uk_ring] destination_number(2001) =~ /^\*9181$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->ringback_183_music_ring] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [ringback_183_music_ring] destination_number(2001) =~ /^\*9182$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(2001) =~ /^\*9183$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->ringback_post_answer_music] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [ringback_post_answer_music] destination_number(2001) =~ /^\*9184$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->ClueCon] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [ClueCon] destination_number(2001) =~ /^\*9191$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->show_info] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [show_info] destination_number(2001) =~ /^\*9192$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->video_record] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [video_record] destination_number(2001) =~ /^\*9193$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->video_playback] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [video_playback] destination_number(2001) =~ /^\*9194$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->delay_echo] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [delay_echo] destination_number(2001) =~ /^\*9195$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->echo] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [echo] destination_number(2001) =~ /^\*9196$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->milliwatt] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [milliwatt] destination_number(2001) =~ /^\*9197$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->tone_stream] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [tone_stream] destination_number(2001) =~ /^\*9198$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->zrtp_enrollement] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [zrtp_enrollement] destination_number(2001) =~ /^\*9787$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->hold_music] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (FAIL) [hold_music] destination_number(2001) =~ /^\*9664$/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/102@192.168.1.6:5060 Regex (PASS) [Local_Extension] destination_number(2001) =~ /(^\d{2,7}$)/ break=on-false Dialplan: sofia/internal/102@192.168.1.6:5060 Action set(dialed_extension=2001) Dialplan: sofia/internal/102@192.168.1.6:5060 Action export(dialed_extension=2001) Dialplan: sofia/internal/102@192.168.1.6:5060 Action limit(db ${domain_name} 2001 ${limit_max} ${limit_destination}) Dialplan: sofia/internal/102@192.168.1.6:5060 Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/102@192.168.1.6:5060 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/102@192.168.1.6:5060 Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/102@192.168.1.6:5060 Action bind_meta_app(4 b s execute_extension::att_xfer XML features) Dialplan: sofia/internal/102@192.168.1.6:5060 Action set(ringback=%(2000, 4000, 440.0, 480.0)) Dialplan: sofia/internal/102@192.168.1.6:5060 Action set(transfer_ringback=%(2000, 4000, 440.0, 480.0)) Dialplan: sofia/internal/102@192.168.1.6:5060 Action set(call_timeout=24) Dialplan: sofia/internal/102@192.168.1.6:5060 Action set(hangup_after_bridge=true) Dialplan: sofia/internal/102@192.168.1.6:5060 Action set(continue_on_fail=true) Dialplan: sofia/internal/102@192.168.1.6:5060 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_numbe r}) Dialplan: sofia/internal/102@192.168.1.6:5060 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/102@192.168.1.6:5060 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/102@192.168.1.6:5060 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/102@192.168.1.6:5060 Action bridge(user/${user_data(${destination_number}@${domain_name} attr id)}@${domain_name}) Dialplan: sofia/internal/102@192.168.1.6:5060 Action answer() Dialplan: sofia/internal/102@192.168.1.6:5060 Action sleep(1000) Dialplan: sofia/internal/102@192.168.1.6:5060 Action voicemail(default ${domain_name} ${dialed_extension}) 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:154 (sofia/internal/102@192.168.1.6:5060) State Change CS_ROUTING -> CS_EXECUTE 2012-04-01 23:50:41.549553 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/102@192.168.1.6:5060 [BREAK] 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/102@192.168.1.6:5060) State ROUTING going to sleep 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/102@192.168.1.6:5060) Running State Change CS_EXECUTE 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/102@192.168.1.6:5060) State EXECUTE 2012-04-01 23:50:41.549553 [DEBUG] mod_sofia.c:241 sofia/internal/102@192.168.1.6:5060 SOFIA EXECUTE 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:192 sofia/internal/102@192.168.1.6:5060 Standard EXECUTE EXECUTE sofia/internal/102@192.168.1.6:5060 set(call_direction=local) 2012-04-01 23:50:41.549553 [DEBUG] mod_dptools.c:1281 sofia/internal/102@192.168.1.6:5060 SET [call_direction]=[local] EXECUTE sofia/internal/102@192.168.1.6:5060 hash(insert/192.168.1.6-spymap/102/9a9a3bde-116c-4100-b269-a6be7455c6c1) EXECUTE sofia/internal/102@192.168.1.6:5060 hash(insert/192.168.1.6-last_dial/102/2001) EXECUTE sofia/internal/102@192.168.1.6:5060 hash(insert/192.168.1.6-last_dial/global/9a9a3bde-116c-4100-b269-a6be7455c6c 1) EXECUTE sofia/internal/102@192.168.1.6:5060 set(RFC2822_DATE=Sun, 01 Apr 2012 23:50:41 -0400) 2012-04-01 23:50:41.549553 [DEBUG] mod_dptools.c:1281 sofia/internal/102@192.168.1.6:5060 SET [RFC2822_DATE]=[Sun, 01 Apr 2012 23:50:41 -0400] EXECUTE sofia/internal/102@192.168.1.6:5060 set(dialed_extension=2001) 2012-04-01 23:50:41.549553 [DEBUG] mod_dptools.c:1281 sofia/internal/102@192.168.1.6:5060 SET [dialed_extension]=[2001] EXECUTE sofia/internal/102@192.168.1.6:5060 export(dialed_extension=2001) 2012-04-01 23:50:41.549553 [DEBUG] switch_channel.c:1093 EXPORT (export_vars) [dialed_extension]=[2001] EXECUTE sofia/internal/102@192.168.1.6:5060 limit(db 192.168.1.6 2001 5 ) 2012-04-01 23:50:41.549553 [INFO] switch_limit.c:126 incr called: 192.168.1.6_2001 max:5, interval:0 2012-04-01 23:50:41.569549 [INFO] mod_db.c:197 Usage for 192.168.1.6_2001 is now 1/5 EXECUTE sofia/internal/102@192.168.1.6:5060 bind_meta_app(1 b s execute_extension::dx XML features) 2012-04-01 23:50:41.569549 [INFO] switch_ivr_async.c:3204 Bound B-Leg: *1 execute_extension::dx XML features EXECUTE sofia/internal/102@192.168.1.6:5060 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/archive/2012/Apr/01/9a9a3bd e-116c-4100-b269-a6be7455c6c1.wav) 2012-04-01 23:50:41.569549 [INFO] switch_ivr_async.c:3204 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/archive/2012/Apr/01/9a9a3bd e-116c-4100-b269-a6be7455c6c1.wav EXECUTE sofia/internal/102@192.168.1.6:5060 bind_meta_app(3 b s execute_extension::cf XML features) 2012-04-01 23:50:41.569549 [INFO] switch_ivr_async.c:3204 Bound B-Leg: *3 execute_extension::cf XML features EXECUTE sofia/internal/102@192.168.1.6:5060 bind_meta_app(4 b s execute_extension::att_xfer XML features) 2012-04-01 23:50:41.569549 [INFO] switch_ivr_async.c:3204 Bound B-Leg: *4 execute_extension::att_xfer XML features EXECUTE sofia/internal/102@192.168.1.6:5060 set(ringback=%(2000, 4000, 440.0, 480.0)) 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281 sofia/internal/102@192.168.1.6:5060 SET [ringback]=[%(2000, 4000, 440.0, 480.0)] EXECUTE sofia/internal/102@192.168.1.6:5060 set(transfer_ringback=%(2000, 4000, 440.0, 480.0)) 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281 sofia/internal/102@192.168.1.6:5060 SET [transfer_ringback]=[%(2000, 4000, 440.0, 480.0)] EXECUTE sofia/internal/102@192.168.1.6:5060 set(call_timeout=24) 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281 sofia/internal/102@192.168.1.6:5060 SET [call_timeout]=[24] EXECUTE sofia/internal/102@192.168.1.6:5060 set(hangup_after_bridge=true) 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281 sofia/internal/102@192.168.1.6:5060 SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/102@192.168.1.6:5060 set(continue_on_fail=true) 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281 sofia/internal/102@192.168.1.6:5060 SET [continue_on_fail]=[true] EXECUTE sofia/internal/102@192.168.1.6:5060 hash(insert/192.168.1.6-call_return/2001/102) EXECUTE sofia/internal/102@192.168.1.6:5060 hash(insert/192.168.1.6-last_dial_ext/2001/9a9a3bde-116c-4100-b269-a6be7455c 6c1) EXECUTE sofia/internal/102@192.168.1.6:5060 set(called_party_callgroup=) 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281 sofia/internal/102@192.168.1.6:5060 SET [called_party_callgroup]=[UNDEF] EXECUTE sofia/internal/102@192.168.1.6:5060 hash(insert/192.168.1.6-last_dial//9a9a3bde-116c-4100-b269-a6be7455c6c1) EXECUTE sofia/internal/102@192.168.1.6:5060 bridge(user/2001(a)192.168.1.6) 2012-04-01 23:50:41.569549 [DEBUG] switch_channel.c:1047 sofia/internal/102@192.168.1.6:5060 EXPORTING[export_vars] [dialed_extension]=[2001] to event 2012-04-01 23:50:41.569549 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables 2012-04-01 23:50:41.569549 [DEBUG] switch_channel.c:1047 sofia/internal/102@192.168.1.6:5060 EXPORTING[export_vars] [dialed_extension]=[2001] to event 2012-04-01 23:50:41.569549 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables 2012-04-01 23:50:41.569549 [DEBUG] switch_event.c:1522 Parsing variable [sip_invite_domain]=[192.168.1.6] 2012-04-01 23:50:41.569549 [DEBUG] switch_event.c:1522 Parsing variable [presence_id]=[2001(a)192.168.1.6] 2012-04-01 23:50:41.569549 [NOTICE] switch_ivr_originate.c:2459 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED] 2012-04-01 23:50:41.569549 [DEBUG] switch_ivr_originate.c:3364 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED] 2012-04-01 23:50:41.569549 [NOTICE] switch_ivr_originate.c:2459 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED] 2012-04-01 23:50:41.569549 [DEBUG] switch_ivr_originate.c:3364 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED] 2012-04-01 23:50:41.569549 [INFO] mod_dptools.c:2922 Originate Failed. Cause: USER_NOT_REGISTERED EXECUTE sofia/internal/102@192.168.1.6:5060 answer() 2012-04-01 23:50:41.569549 [DEBUG] sofia_glue.c:4876 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] 2012-04-01 23:50:41.569549 [DEBUG] sofia_glue.c:2996 Set Codec sofia/internal/102@192.168.1.6:5060 PCMU/8000 20 ms 160 samples 64000 bits 2012-04-01 23:50:41.569549 [DEBUG] switch_core_codec.c:111 sofia/internal/102@192.168.1.6:5060 Original read codec set to PCMU:0 2012-04-01 23:50:41.569549 [DEBUG] sofia_glue.c:5008 No 2833 in SDP. Disable 2833 dtmf and switch to INFO 2012-04-01 23:50:41.569549 [DEBUG] sofia_glue.c:3248 AUDIO RTP [sofia/internal/102@192.168.1.6:5060] 192.168.1.6 port 23164 -> 192.168.1.4 port 16384 codec: 0 ms: 20 2012-04-01 23:50:41.569549 [DEBUG] switch_rtp.c:1661 Starting timer [soft] 160 bytes per 20ms 2012-04-01 23:50:41.569549 [NOTICE] sofia_glue.c:4022 Pre-Answer sofia/internal/102@192.168.1.6:5060! 2012-04-01 23:50:41.569549 [DEBUG] switch_channel.c:2932 (sofia/internal/102@192.168.1.6:5060) Callstate Change RINGING -> EARLY 2012-04-01 23:50:41.569549 [DEBUG] mod_sofia.c:750 Local SDP sofia/internal/102@192.168.1.6:5060: v=0 o=FreeSWITCH 1333315477 1333315478 IN IP4 192.168.1.6 s=FreeSWITCH c=IN IP4 192.168.1.6 t=0 0 m=audio 23164 RTP/AVP 0 a=rtpmap:0 PCMU/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 2012-04-01 23:50:41.569549 [DEBUG] switch_core_session.c:731 Send signal sofia/internal/102@192.168.1.6:5060 [BREAK] 2012-04-01 23:50:41.569549 [DEBUG] switch_channel.c:3190 (sofia/internal/102@192.168.1.6:5060) Callstate Change EARLY -> ACTIVE 2012-04-01 23:50:41.569549 [NOTICE] mod_dptools.c:1135 Channel [sofia/internal/102@192.168.1.6:5060] has been answered 2012-04-01 23:50:41.569549 [DEBUG] switch_core_session.c:877 Send signal sofia/internal/102@192.168.1.6:5060 [BREAK] 2012-04-01 23:50:41.569549 [DEBUG] sofia.c:5541 Channel sofia/internal/102@192.168.1.6:5060 entering state [completed][200] EXECUTE sofia/internal/102@192.168.1.6:5060 sleep(1000) 2012-04-01 23:50:41.649589 [DEBUG] switch_core_session.c:877 Send signal sofia/internal/102@192.168.1.6:5060 [BREAK] 2012-04-01 23:50:41.649589 [DEBUG] switch_core_session.c:877 Send signal sofia/internal/102@192.168.1.6:5060 [BREAK] 2012-04-01 23:50:41.649589 [DEBUG] switch_core_session.c:877 Send signal sofia/internal/102@192.168.1.6:5060 [BREAK] 2012-04-01 23:50:41.669832 [DEBUG] sofia.c:5541 Channel sofia/internal/102@192.168.1.6:5060 entering state [ready][200] 2012-04-01 23:50:41.849781 [DEBUG] switch_rtp.c:3224 Correct ip/port confirmed. EXECUTE sofia/internal/102@192.168.1.6:5060 voicemail(default 192.168.1.6 2001) 2012-04-01 23:50:42.689527 [DEBUG] switch_ivr_play_say.c:1306 Codec Activated L16@8000hz 1 channels 20ms 2012-04-01 23:50:46.249491 [DEBUG] switch_core_session.c:877 Send signal sofia/internal/102@192.168.1.6:5060 [BREAK] 2012-04-01 23:50:46.269490 [DEBUG] switch_channel.c:2848 (sofia/internal/102@192.168.1.6:5060) Callstate Change ACTIVE -> HANGUP 2012-04-01 23:50:46.269490 [NOTICE] sofia.c:628 Hangup sofia/internal/102@192.168.1.6:5060 [CS_EXECUTE] [NORMAL_CLEARING] 2012-04-01 23:50:46.269490 [DEBUG] switch_channel.c:2871 Send signal sofia/internal/102@192.168.1.6:5060 [KILL] 2012-04-01 23:50:46.269490 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/102@192.168.1.6:5060 [BREAK] 2012-04-01 23:50:46.269490 [DEBUG] switch_ivr_play_say.c:1678 done playing file /usr/local/freeswitch/storage/voicemail/default/192.168.1.6/2001/greeting_1. wav 2012-04-01 23:50:46.269490 [DEBUG] switch_core_session.c:2287 sofia/internal/102@192.168.1.6:5060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/102@192.168.1.6:5060) State EXECUTE going to sleep 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/102@192.168.1.6:5060) Running State Change CS_HANGUP 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/102@192.168.1.6:5060) State HANGUP 2012-04-01 23:50:46.269490 [DEBUG] mod_sofia.c:469 Channel sofia/internal/102@192.168.1.6:5060 hanging up, cause: NORMAL_CLEARING 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:47 sofia/internal/102@192.168.1.6:5060 Standard HANGUP, cause: NORMAL_CLEARING 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/102@192.168.1.6:5060) State HANGUP going to sleep 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:393 (sofia/internal/102@192.168.1.6:5060) State Change CS_HANGUP -> CS_REPORTING 2012-04-01 23:50:46.269490 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/102@192.168.1.6:5060 [BREAK] 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/102@192.168.1.6:5060) Running State Change CS_REPORTING 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/102@192.168.1.6:5060) State REPORTING 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:79 sofia/internal/102@192.168.1.6:5060 Standard REPORTING, cause: NORMAL_CLEARING 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/102@192.168.1.6:5060) State REPORTING going to sleep 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:387 (sofia/internal/102@192.168.1.6:5060) State Change CS_REPORTING -> CS_DESTROY 2012-04-01 23:50:46.289510 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/102@192.168.1.6:5060 [BREAK] 2012-04-01 23:50:46.289510 [DEBUG] switch_core_session.c:1382 Session 13 (sofia/internal/102@192.168.1.6:5060) Locked, Waiting on external entities 2012-04-01 23:50:46.289510 [NOTICE] switch_core_session.c:1400 Session 13 (sofia/internal/102@192.168.1.6:5060) Ended 2012-04-01 23:50:46.289510 [NOTICE] switch_core_session.c:1402 Close Channel sofia/internal/102@192.168.1.6:5060 [CS_DESTROY] 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/102@192.168.1.6:5060) Callstate Change HANGUP -> DOWN 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:494 (sofia/internal/102@192.168.1.6:5060) Running State Change CS_DESTROY 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/102@192.168.1.6:5060) State DESTROY 2012-04-01 23:50:46.289510 [DEBUG] mod_sofia.c:374 sofia/internal/102@192.168.1.6:5060 SOFIA DESTROY 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:86 sofia/internal/102@192.168.1.6:5060 Standard DESTROY 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/102@192.168.1.6:5060) State DESTROY going to sleep freeswitch@internal> /bye [root@server bin]# Regards, Phil Quesinberry Q Systems Engineering, Inc. Electronic Controls and Embedded Systems Development (410) 969-8002 http://www.qsystemsengineering.com

4 4

Bridging connection analog line->freeswitch->outbound and getting meaningful data
by Marcus Mülbüsch 02 Apr '12

02 Apr '12

Hello all, before I ask my question: We have an old "Sangoma Technologies Corp. A104u Quad T1/E1 AFT" card. Getting a newer card for this server is out of question. To make it run we had to use "WANPIPE Release: 3.3.14.11" and could get it to work only with "FreeSWITCH Version 1.0.4 (exported)" and thus use openzap instead of freetdm. Duh. Now, there also is an "Digium, Inc. Wildcard TDM2400P 24-port analog card" in the server. Everything is up and running (finally), and we can successfully accept calls on the analog card, and freeswitch switches it through the Digital or VoIP lines outbound. However, there is the matter that we do not get meaningful (for us) billing data in the CDR: "${start_stamp}" and "${end_stamp}" are correct, but the "${answer_stamp}" shows the time where the incoming call is accepted by freeswitch. Since the call is accepted we also never get another "${hangup_cause}" than "NORMAL_CLEARING". However, we would like to have the time (and hangup_cause) where the *outbound* connection is answered. This is especially annoying if the outbound connection is refused; for example because the line is busy. How is it possible to bring freeswitch to use the outgoing connection to record the answer_stamp? Am I doing something completely wrong? Any help or pointers are thankfully accepeted! Marcus

2 1

problems LuaSql in FreeSwitch
by Sardor Tukhtaev 02 Apr '12

02 Apr '12

Hello everybody, The problem arises from connecting to the database (Oracle). In the console [fs_cli] this error: >>> 2012-03-28 17:21:57.558786 [ERR] mod_lua.cpp: 198 C: \ Program Files \ FreeSWITCH \ scr ipts / db_connect.lua: 4: module 'luasql.oci8' not found: no field package.preload ['luasql.oci8'] no file '. \ luasql \ oci8.lua' no file 'C: \ Program Files \ FreeSWITCH \ lua \ luasql \ oci8.lua' no file 'C: \ Program Files \ FreeSWITCH \ lua \ luasql \ oci8 \ init.lua' no file 'C: \ Program Files \ FreeSWITCH \ luasql \ oci8.lua' no file 'C: \ Program Files \ FreeSWITCH \ luasql \ oci8 \ init.lua' no file 'C: \ Program Files \ Lua \ 5.1 \ lua \ luasql \ oci8.luac' no file '. \ luasql \ oci8.dll' no file '. \ luasql \ oci851.dll' no file 'C: \ Program Files \ FreeSWITCH \ luasql \ oci8.dll' no file 'C: \ Program Files \ FreeSWITCH \ luasql \ oci851.dll' no file 'C: \ Program Files \ FreeSWITCH \ clibs \ luasql \ oci8.dll' no file 'C: \ Program Files \ FreeSWITCH \ clibs \ luasql \ oci851.dll' no file 'C: \ Program Files \ FreeSWITCH \ loadall.dll' no file 'C: \ Program Files \ FreeSWITCH \ clibs \ loadall.dll' no file '. \ luasql.dll' no file '. \ luasql51.dll' no file 'C: \ Program Files \ FreeSWITCH \ luasql.dll' no file 'C: \ Program Files \ FreeSWITCH \ luasql51.dll' no file 'C: \ Program Files \ FreeSWITCH \ clibs \ luasql.dll' no file 'C: \ Program Files \ FreeSWITCH \ clibs \ luasql51.dll' no file 'C: \ Program Files \ FreeSWITCH \ loadall.dll' no file 'C: \ Program Files \ FreeSWITCH \ clibs \ loadall.dll' stack traceback: [C]: in function 'require' C: \ Program Files \ FreeSWITCH \ scripts / db_connect.lua: 4: in main chunk These files I didn't find. Set version LuaForWindows_v5.1.4-45 There was written, that it supports Oracle. However,the files with the extension[oci8] I haven't found. Could you help me with this problem. Thanks in advance.

2 1

mod_cdr_cvs
by Miha 02 Apr '12

02 Apr '12

Hi, as I needed quick solution to put cdr to mysql I have used perl script which is at the and of wiki page of mod_cdr_cvs. As I have now 500 registrations on FS there are a lot of cdr files created in log/cdr-cvs/. I will need a little more time to create my script and parser for xml_cdr so I have one question. Can I delete all thous cdr-cvs files? Will FS created Master file when the first call will be made after I will deleted all cdr-cvs files? Thank you! Regards, Miha

1 0

(no subject)
by sylver_b 02 Apr '12

02 Apr '12

<a href="http://c1.00364.com/blog.old/wp-content/plugins/extended-comment-options/02…"> http://c1.00364.com/blog.old/wp-content/plugins/extended-comment-options/02…</a>

1 0

fax tone testing
by Anita Hall 02 Apr '12

02 Apr '12

Hi I suspect that my telco set-up is acting funny and I want to use spectral analysis to confirm the culprit :) What is the best way to generate Fax tones from a dialplan and then record them at the other end? Also, where can I get a list of the all the tones and duration which are used in Fax. Thanks. regards, Anita

1 0

Cisco UCM 7.1 3pcc hold problem
by Wesley Akio 02 Apr '12

02 Apr '12

Hi all, I'm trying SIP Trunk between CUCM 7.1 and FS. Unfortunately MTP is not an option, what leaves me with a whole lot of problems. The one I'm currently banging my head with is hold. I do not have the traces here, I'll have my hands on them tomorrow... Meanwhile what happens is the following: CISCO -> FS ->INVITE - no SDP <-Trying <-Ringing <-200 - SDP ->ACK - SDP At this point the call is setup and things work as they should. Cisco tries hold with freeswitch ->INVITE - SDP with IP 0.0.0.0 <-200 - SPD as usual -> ACK - no SDP the call is On hold, freeswitch is playing MOH microseconds later, cisco tries to recover the call and connect to its MOH server: -> INVITE - no SDP <- 200 - SDP as usual -> ACK - Valid SDP pointing to a moh server At this point freeswitch continues peacefully to play it's own MOH Cisco is sending RTP but FS is ignoring it >From this point on the call is lost and will remain on MOH until someone hangs up... any atempt to recover the call fails. I'm sorry for the lack of traces as pcaps, i'll add the tomorrow... Have someone gone through this problem or have any idea on what can i try? Best, Wesley Akio TuntsCorp.com

1 0

Drive by DTMF
by Brian Foster 01 Apr '12

01 Apr '12

INDIANAPOLIS, INDIANA - EndigoVoIP, a division of Endigo Communications, has released a module for the open source telephony toolkit FreeSWITCH that gives a user the ability to control a full sized automobile using the buttons found on any telephone and a live video feed. Mod_drivebydtmf, currently in beta status, will give the user to control almost every function of a car. Keys one and three are used for left and right turn signals, keys 2 and 8 will be used for acceleration and braking, and keys 4 and 6 will be used to turn the vehicle left and right. The module will also use the star key for an IVR that will be used to control various other functions of the car, including gear selection, locking and unlocking the doors on the car, and rolling down and up the power windows. The pound (hash) key will be used as a panic button, which will stop the car, place the car in park, shut off the engine, lock the doors, and call emergency services. Although the company says the module is in beta, it encourages telecommunications administrators to deploy the module on a production system. "There shouldn't be many bugs with the module, although we have witnessed a few accidents due to the car not applying the brakes," says CEO Brian Foster, "but we believe the error was due to a misconfiguration of the module or driver error." The company expects to see this the module used in a wide variety of applications, from controlling UPS trucks on their delivery route to driving the biggest military tanks on earth. According to sources, the company expects to come out of beta by the end of the year. And of course, EndigoVoIP will release the module as open source under a Mozilla license. -BDF

3 3

Commands to show RTP statistics
by Weikai Xie 01 Apr '12

01 Apr '12

Hi, Is there any commands or means in Freeswitch which can be used to show the recent send/recv RTP statistics, such as packets loss rate, bandwidth, etc, on a channel? I've tried look for related commands in the wiki but can't get a clue. Regards, Weikai Xie

2 1

no-way audio when accepting a call with iLBC
by Stanislav Kutil 01 Apr '12

01 Apr '12

I'm experiencing no-way audio when using iLBC codec with FS. interesting snippet from the dump: we receive this INVITE, note iLBC is included both as payload 98 and payload 102. INVITE sip:1203@192.168.1.245:4956;rinstance=018EE99B SIP/2.0 Via: SIP/2.0/UDP 93.185.48.4;rport;branch=z9hG4bKSvyXBN2p9cZNp Route: <sip:1203@78.80.18.10:10142>;rinstance=018EE99B Max-Forwards: 69 From: "Extension 1205" <sip:1205@pbx.acrobits.cz>;tag=43Bm32867KUBS To: <sip:1203@192.168.1.245:4956;rinstance=018EE99B> Call-ID: 2ec155bb-f612-122f-3292-001a929b68ca CSeq: 26276632 INVITE Contact: <sip:mod_sofia@93.185.48.4:5060> User-Agent: FreeSWITCH-mod_sofia/1.1.beta1-git-a239914 2012-03-26 10-53-39 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 486 X-FS-Support: update_display,send_info Remote-Party-ID: "Extension 1205" <sip:1205@pbx.acrobits.cz>;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1333204589 1333204590 IN IP4 93.185.48.4 s=FreeSWITCH c=IN IP4 93.185.48.4 t=0 0 m=audio 20804 RTP/AVP 0 8 9 98 3 99 100 102 101 13 a=rtpmap:98 iLBC/8000 a=fmtp:98 mode=20 a=rtpmap:99 G7221/32000 a=fmtp:99 bitrate=48000 a=rtpmap:100 G7221/16000 a=fmtp:100 bitrate=32000 a=rtpmap:102 iLBC/8000 a=fmtp:102 mode=20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 m=video 22668 RTP/AVP 34 103 a=rtpmap:34 H263/90000 a=rtpmap:103 H264/90000 we pick 102 version: SIP/2.0 200 OK Via: SIP/2.0/UDP 93.185.48.4;rport=5060;branch=z9hG4bKSvyXBN2p9cZNp;received=93.185.48.4 Contact: <sip:1203@192.168.1.245:4956> From: "Extension 1205" <sip:1205@pbx.acrobits.cz>;tag=43Bm32867KUBS Call-ID: 2ec155bb-f612-122f-3292-001a929b68ca CSeq: 26276632 INVITE To: <sip:1203@192.168.1.245:4956;rinstance=018EE99B>;tag=8466C9086B8AF5AE5586CEC0F3CFB45C Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY Supported: replaces, path Content-Type: application/sdp Content-Length: 307 v=0 o=- 03870 51862 IN IP4 10.39.33.21 s=tinvgxd c=IN IP4 10.39.33.21 t=0 0 m=audio 51132 RTP/AVP 102 101 a=rtpmap:101 TELEPHONE-EVENT/8000 a=rtpmap:102 ILBC/8000 a=fmtp:101 0-15 a=fmtp:102 mode=20 a=ptime:20 a=sendrecv m=video 0 RTP/AVP 34 103 a=rtpmap:103 H264/90000 a=rtpmap:34 H263/90000 the NAT traversal feature of FS to send audio back to where it is send does not kick in in this case so the iLBC stream from us is ignored by FS and iLBC stream from FS goes to some private IP (we are not on the same private network as FS) 1) as soon as we send a re-INVITE it fixes itself (now only 102 is included) 2) If we declare the correct public IP in the SDP it also works. 3) other codecs work fine So to me the problem can either be the dual payload, or iLBC vs ILBC. I think the latter is correct btw. Thanks, Stan

1 0