General question, new installation

Dear All,

I am a newbie of Asterisk and FreePBX and would be grateful to anyone who could help me understanding if the way I installed my system allows me to start communicating through it.

I wrote the image on a card and installed on a Raspberry Pi, I ran a Pi setup (FS, Timezone, etc.), downloaded all the downloadable modules, updated and configured FreePBX, OS, modules, and added two users for testing purposes. I forwarded port 5060 to the Pi (it has a static address within my LAN), and ports 10000 to 11000 to support call trunks.

I have a dynamic IP service in place at no-ip.org and all settings seem to be correct - I conclude this as my mobile phone can connect to the server (the Pi) via the [dynamic address:5060] and go in ready status. So far so good.

I downloaded CSipSimple and Zoiper on two mobile phones, configured correctly (they connect and go to ready status with both apps) and tried to make a call by dialling the respective extensions. Here is where I am stuck, the call doesn’t get through. I tried both from inside the LAN [192.x.x:5060] and from the outside via [dynamic:5060] and can’t manage to make the phones ring. I am now suspecting that something is missing - or that I have done something wrong.

Does the system need to be registered on some internal server, even to communicate between extensions inside the system (say I call ext 2000 from ext 1000), considering that the two users could be connected via either a mobile network or a WiFi in different countries? I believe the geographic location of the users shouldn’t make a difference but I mentioned it just in case.

In case the system is supposed to work without connection to a service, what could I have possibly done incorrectly given the above configuration steps? If required, I can post a log.

Many thanks and kind regards.

Raul

Have you tried just doing an echo test? From one of the extensions dial *43 and see if you get the “echo test” announcement. If not it would be good to get a log file which can be found in /var/log/asterisk/full

Thanks Lee.

I ran a test by using both mobile phones running CSipSimple inside the LAN (the same where the server is located), logged in through the dynamic address and in ready status.

I have two extensions, 7100 and 7600. I first dialled 7100 from 7600 and obtained Error 503 Service Unavailable, then dialled *43 and the test was successful; I then ran the same test the other way around (from 7100 toward 7600) with the same outcome. I can see that the log can be very large even for a two minute set of activities, below is a data dump from the two minutes related to the experiment. I tried to go through it but I haven’t been able to spot what generates the error message, can you spot anything or can you point me in the right direction?

Many thanks

Raul

[2014-03-22 14:42:21] VERBOSE[2893][C-0000001b] netsock2.c: == Using SIP RTP TOS bits 184
[2014-03-22 14:42:21] VERBOSE[2893][C-0000001b] netsock2.c: == Using SIP RTP CoS mark 5
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] Set(“SIP/7600-0000001b”, “__RINGTIMER=15”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:2] Macro(“SIP/7600-0000001b”, “exten-vm,novm,7100,0,0,0”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] Macro(“SIP/7600-0000001b”, “user-callerid,”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] Set(“SIP/7600-0000001b”, “TOUCH_MONITOR=1395499341.27”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:2] Set(“SIP/7600-0000001b”, “AMPUSER=7600”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:3] GotoIf(“SIP/7600-0000001b”, “0?report”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:4] ExecIf(“SIP/7600-0000001b”, “1?Set(REALCALLERIDNUM=7600)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:5] Set(“SIP/7600-0000001b”, “AMPUSER=7600”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:6] GotoIf(“SIP/7600-0000001b”, “0?limit”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:7] Set(“SIP/7600-0000001b”, “AMPUSERCIDNAME=Olga”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:8] GotoIf(“SIP/7600-0000001b”, “0?report”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:9] Set(“SIP/7600-0000001b”, “AMPUSERCID=7600”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:10] Set(“SIP/7600-0000001b”, “__DIAL_OPTIONS=tr”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:11] Set(“SIP/7600-0000001b”, “CALLERID(all)=“Olga” <7600>”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:12] GotoIf(“SIP/7600-0000001b”, “0?limit”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:13] ExecIf(“SIP/7600-0000001b”, “0?Set(GROUP(concurrency_limit)=7600)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:14] ExecIf(“SIP/7600-0000001b”, “0?Set(CHANNEL(language)=)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:15] GosubIf(“SIP/7600-0000001b”, “7?sub-ccss,s,1(macro-exten-vm,7100)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] ExecIf(“SIP/7600-0000001b”, “0?Return()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:2] Set(“SIP/7600-0000001b”, “CCSS_SETUP=TRUE”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:3] GosubIf(“SIP/7600-0000001b”, “0?monitor_config,1(macro-exten-vm,7100):monitor_default,1(macro-exten-vm,7100)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/7600-0000001b”, “1?is_exten”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Goto (sub-ccss,monitor_default,4)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:4] Set(“SIP/7600-0000001b”, “CALLCOMPLETION(cc_monitor_policy)=generic”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:5] Set(“SIP/7600-0000001b”, “CALLCOMPLETION(cc_max_monitors)=5”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:6] Return(“SIP/7600-0000001b”, “TRUE”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:4] GosubIf(“SIP/7600-0000001b”, “7?agent_config,1():agent_default,1()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] Set(“SIP/7600-0000001b”, “CALLCOMPLETION(cc_agent_policy)=generic”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:2] Set(“SIP/7600-0000001b”, “CALLCOMPLETION(cc_offer_timer)=30”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:3] Set(“SIP/7600-0000001b”, “CALLCOMPLETION(ccbs_available_timer)=”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:4] Set(“SIP/7600-0000001b”, “CALLCOMPLETION(ccnr_available_timer)=”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:5] Set(“SIP/7600-0000001b”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack
[2014-03-22 14:42:21] WARNING[10480][C-0000001b] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:6] ExecIf(“SIP/7600-0000001b”, “1?Set(CALLCOMPLETION(cc_recall_timer)=)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:7] ExecIf(“SIP/7600-0000001b”, “1?Set(CALLCOMPLETION(cc_max_agents)=)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:8] ExecIf(“SIP/7600-0000001b”, “0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/[email protected])”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:9] Set(“SIP/7600-0000001b”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack
[2014-03-22 14:42:21] WARNING[10480][C-0000001b] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:10] Return(“SIP/7600-0000001b”, “”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:5] Set(“SIP/7600-0000001b”, “DB(AMPUSER/7600/ccss/last_number)=7100”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:6] Return(“SIP/7600-0000001b”, “”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:16] GotoIf(“SIP/7600-0000001b”, “0?continue”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:17] ExecIf(“SIP/7600-0000001b”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:18] Set(“SIP/7600-0000001b”, “__TTL=64”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:19] GotoIf(“SIP/7600-0000001b”, “1?continue”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Goto (macro-user-callerid,s,30)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:30] Set(“SIP/7600-0000001b”, “CALLERID(number)=7600”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:31] Set(“SIP/7600-0000001b”, “CALLERID(name)=Olga”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:32] Set(“SIP/7600-0000001b”, “CDR(cnum)=7600”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:33] Set(“SIP/7600-0000001b”, “CDR(cnam)=Olga”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:34] Set(“SIP/7600-0000001b”, “CHANNEL(language)=en”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:2] Set(“SIP/7600-0000001b”, “RingGroupMethod=none”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:3] Set(“SIP/7600-0000001b”, “__EXTTOCALL=7100”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:4] Set(“SIP/7600-0000001b”, “__PICKUPMARK=7100”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:5] Set(“SIP/7600-0000001b”, “RT=”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:6] ExecIf(“SIP/7600-0000001b”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]n-vm:7] ExecIf(“SIP/7600-0000001b”, “0?MacroExit()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:8] Gosub(“SIP/7600-0000001b”, “sub-record-check,s,1(exten,7100,)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] Set(“SIP/7600-0000001b”, “REC_POLICY_MODE_SAVE=”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:2] GotoIf(“SIP/7600-0000001b”, “1?check”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Goto (sub-record-check,s,7)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:7] Set(“SIP/7600-0000001b”, “__MON_FMT=wav”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:8] GotoIf(“SIP/7600-0000001b”, “1?next”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Goto (sub-record-check,s,11)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:11] ExecIf(“SIP/7600-0000001b”, “0?Return()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:12] ExecIf(“SIP/7600-0000001b”, “0?Set(__REC_POLICY_MODE=)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:13] GotoIf(“SIP/7600-0000001b”, “0?exten,1”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:14] Set(“SIP/7600-0000001b”, “__REC_STATUS=INITIALIZED”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:15] Set(“SIP/7600-0000001b”, “NOW=1395499341”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:16] Set(“SIP/7600-0000001b”, “__DAY=22”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:17] Set(“SIP/7600-0000001b”, “__MONTH=03”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:18] Set(“SIP/7600-0000001b”, “__YEAR=2014”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:19] Set(“SIP/7600-0000001b”, “__TIMESTR=20140322-144221”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:20] Set(“SIP/7600-0000001b”, “__FROMEXTEN=7600”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:21] Set(“SIP/7600-0000001b”, “__CALLFILENAME=exten-7100-7600-20140322-144221-1395499341.27”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:22] Goto(“SIP/7600-0000001b”, “exten,1”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Goto (sub-record-check,exten,1)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/7600-0000001b”, “0?callee”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:2] Set(“SIP/7600-0000001b”, “__REC_POLICY_MODE=dontcare”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:3] GotoIf(“SIP/7600-0000001b”, “1?caller”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Goto (sub-record-check,exten,10)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:10] Set(“SIP/7600-0000001b”, “__REC_POLICY_MODE=dontcare”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:11] GosubIf(“SIP/7600-0000001b”, “0?record,1(exten,7100,7600)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:12] Return(“SIP/7600-0000001b”, “”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:9] GotoIf(“SIP/7600-0000001b”, “1?macrodial”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Goto (macro-exten-vm,s,15)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:15] GosubIf(“SIP/7600-0000001b”, “0?clrheader,1()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:16] Macro(“SIP/7600-0000001b”, “dial-one,tr,7100”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] Set(“SIP/7600-0000001b”, “DEXTEN=7100”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:2] Set(“SIP/7600-0000001b”, “DIALSTATUS_CW=”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:3] GosubIf(“SIP/7600-0000001b”, “0?screen,1()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:4] GosubIf(“SIP/7600-0000001b”, “0?cf,1()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:5] GotoIf(“SIP/7600-0000001b”, “1?skip1”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Goto (macro-dial-one,s,8)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:8] GotoIf(“SIP/7600-0000001b”, “0?nodial”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:9] GotoIf(“SIP/7600-0000001b”, “0?continue”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:10] Set(“SIP/7600-0000001b”, “EXTHASCW=ENABLED”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:11] GotoIf(“SIP/7600-0000001b”, “0?next1:cwinusebusy”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Goto (macro-dial-one,s,23)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:23] GotoIf(“SIP/7600-0000001b”, “1?next3:continue”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Goto (macro-dial-one,s,24)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:24] ExecIf(“SIP/7600-0000001b”, “0?Set(DIALSTATUS_CW=BUSY)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:25] GotoIf(“SIP/7600-0000001b”, “0?nodial”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:26] GosubIf(“SIP/7600-0000001b”, “1?dstring,1():dlocal,1()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] Set(“SIP/7600-0000001b”, “DSTRING=”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:2] Set(“SIP/7600-0000001b”, “DEVICES=7100”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:3] ExecIf(“SIP/7600-0000001b”, “0?Return()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:4] ExecIf(“SIP/7600-0000001b”, “0?Set(DEVICES=100)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [dst[email protected]:5] Set(“SIP/7600-0000001b”, “LOOPCNT=1”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:6] Set(“SIP/7600-0000001b”, “ITER=1”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:7] Set(“SIP/7600-0000001b”, “THISDIAL=SIP/7100”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:8] GosubIf(“SIP/7600-0000001b”, “1?zap2dahdi,1()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] ExecIf(“SIP/7600-0000001b”, “0?Return()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:2] Set(“SIP/7600-0000001b”, “NEWDIAL=”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:3] Set(“SIP/7600-0000001b”, “LOOPCNT2=1”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:4] Set(“SIP/7600-0000001b”, “ITER2=1”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:5] Set(“SIP/7600-0000001b”, “THISPART2=SIP/7100”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:6] ExecIf(“SIP/7600-0000001b”, “0?Set(THISPART2=DAHDI/7100)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:7] Set(“SIP/7600-0000001b”, “NEWDIAL=SIP/7100&”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:8] Set(“SIP/7600-0000001b”, “ITER2=2”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:9] GotoIf(“SIP/7600-0000001b”, “0?begin2”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:10] Set(“SIP/7600-0000001b”, “THISDIAL=SIP/7100”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:11] Return(“SIP/7600-0000001b”, “”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:9] Set(“SIP/7600-0000001b”, “DSTRING=SIP/7100&”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:10] Set(“SIP/7600-0000001b”, “ITER=2”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:11] GotoIf(“SIP/7600-0000001b”, “0?begin”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:12] Set(“SIP/7600-0000001b”, “DSTRING=SIP/7100”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:13] Return(“SIP/7600-0000001b”, “”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:27] GotoIf(“SIP/7600-0000001b”, “0?nodial”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:28] GotoIf(“SIP/7600-0000001b”, “0?skiptrace”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:29] GosubIf(“SIP/7600-0000001b”, “1?ctset,1():ctclear,1()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] Set(“SIP/7600-0000001b”, “DB(CALLTRACE/7100)=7600”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:2] Return(“SIP/7600-0000001b”, “”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:30] Set(“SIP/7600-0000001b”, “D_OPTIONS=tr”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:31] ExecIf(“SIP/7600-0000001b”, “0?SIPAddHeader(Alert-Info: )”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:32] ExecIf(“SIP/7600-0000001b”, “0?SIPAddHeader()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:33] ExecIf(“SIP/7600-0000001b”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:34] GosubIf(“SIP/7600-0000001b”, “0?qwait,1()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:35] Set(“SIP/7600-0000001b”, “__CWIGNORE=”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:36] Set(“SIP/7600-0000001b”, “__KEEPCID=TRUE”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:37] GotoIf(“SIP/7600-0000001b”, “0?usegoto,1”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:38] GotoIf(“SIP/7600-0000001b”, “0?godial”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:39] Gosub(“SIP/7600-0000001b”, “sub-presencestate-display,s,1(7100)”) in new stack
[2014-03-22 14:42:21] WARNING[10480][C-0000001b] func_presencestate.c: PRESENCE_STATE unknown
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] Goto(“SIP/7600-0000001b”, “state-,1”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Goto (sub-presencestate-display,state-,1)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [state-@sub-presencestate-display:1] Set(“SIP/7600-0000001b”, “PRESENCESTATE_DISPLAY=”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [state-@sub-presencestate-display:2] Return(“SIP/7600-0000001b”, “”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:40] Set(“SIP/7600-0000001b”, “CONNECTEDLINE(name,i)=Raul”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:41] Set(“SIP/7600-0000001b”, “CONNECTEDLINE(num)=7100”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:42] Set(“SIP/7600-0000001b”, “D_OPTIONS=trI”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:43] Dial(“SIP/7600-0000001b”, “SIP/7100,trI”) in new stack
[2014-03-22 14:42:21] WARNING[10480][C-0000001b] app_dial.c: Unable to create channel of type ‘SIP’ (cause 20 - Subscriber absent)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] app_dial.c: == Everyone is busy/congested at this time (1:0/0/1)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:44] ExecIf(“SIP/7600-0000001b”, “0?MacroExit()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:45] ExecIf(“SIP/7600-0000001b”, “0?Set(DIALSTATUS=)”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:46] GosubIf(“SIP/7600-0000001b”, “0?s-CHANUNAVAIL,1()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:47] MacroExit(“SIP/7600-0000001b”, “”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:17] Set(“SIP/7600-0000001b”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:18] GosubIf(“SIP/7600-0000001b”, “0?docfu,1()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:19] GosubIf(“SIP/7600-0000001b”, “0?docfb,1()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:20] Set(“SIP/7600-0000001b”, “DIALSTATUS=CHANUNAVAIL”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:21] ExecIf(“SIP/7600-0000001b”, “0?MacroExit()”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:22] GotoIf(“SIP/7600-0000001b”, “1?s-CHANUNAVAIL,1”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Goto (macro-exten-vm,s-CHANUNAVAIL,1)
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/7600-0000001b”, “0?exit,1”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:2] PlayTones(“SIP/7600-0000001b”, “congestion”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:3] Congestion(“SIP/7600-0000001b”, “10”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] app_macro.c: == Spawn extension (macro-exten-vm, s-CHANUNAVAIL, 3) exited non-zero on ‘SIP/7600-0000001b’ in macro ‘exten-vm’
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: == Spawn extension (from-internal, 7100, 2) exited non-zero on ‘SIP/7600-0000001b’
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: – Executing [[email protected]:1] Hangup(“SIP/7600-0000001b”, “”) in new stack
[2014-03-22 14:42:21] VERBOSE[10480][C-0000001b] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/7600-0000001b’
[2014-03-22 14:42:37] VERBOSE[2893][C-0000001c] netsock2.c: == Using SIP RTP TOS bits 184
[2014-03-22 14:42:37] VERBOSE[2893][C-0000001c] netsock2.c: == Using SIP RTP CoS mark 5
[2014-03-22 14:42:37] VERBOSE[10481][C-0000001c] pbx.c: – Executing [*[email protected]:1] Answer(“SIP/7600-0000001c”, “”) in new stack
[2014-03-22 14:42:38] VERBOSE[10481][C-0000001c] pbx.c: – Executing [*[email protected]:2] Wait(“SIP/7600-0000001c”, “1”) in new stack
[2014-03-22 14:42:39] VERBOSE[10481][C-0000001c] pbx.c: – Executing [*[email protected]:3] Playback(“SIP/7600-0000001c”, “demo-echotest”) in new stack
[2014-03-22 14:42:39] VERBOSE[10481][C-0000001c] file.c: – <SIP/7600-0000001c> Playing ‘demo-echotest.ulaw’ (language ‘en’)
[2014-03-22 14:42:40] VERBOSE[10481][C-0000001c] pbx.c: == Spawn extension (from-internal, *43, 3) exited non-zero on ‘SIP/7600-0000001c’
[2014-03-22 14:42:40] VERBOSE[10481][C-0000001c] pbx.c: – Executing [[email protected]:1] Hangup(“SIP/7600-0000001c”, “”) in new stack
[2014-03-22 14:42:40] VERBOSE[10481][C-0000001c] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/7600-0000001c’
[2014-03-22 14:42:56] VERBOSE[2893][C-0000001d] netsock2.c: == Using SIP RTP TOS bits 184
[2014-03-22 14:42:56] VERBOSE[2893][C-0000001d] netsock2.c: == Using SIP RTP CoS mark 5
[2014-03-22 14:42:56] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] Set(“SIP/7100-0000001d”, “__RINGTIMER=15”) in new stack
[2014-03-22 14:42:56] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:2] Macro(“SIP/7100-0000001d”, “exten-vm,novm,7600,0,0,0”) in new stack
[2014-03-22 14:42:56] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] Macro(“SIP/7100-0000001d”, “user-callerid,”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] Set(“SIP/7100-0000001d”, “TOUCH_MONITOR=1395499376.29”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:2] Set(“SIP/7100-0000001d”, “AMPUSER=7100”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:3] GotoIf(“SIP/7100-0000001d”, “0?report”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:4] ExecIf(“SIP/7100-0000001d”, “1?Set(REALCALLERIDNUM=7100)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:5] Set(“SIP/7100-0000001d”, “AMPUSER=7100”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:6] GotoIf(“SIP/7100-0000001d”, “0?limit”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:7] Set(“SIP/7100-0000001d”, “AMPUSERCIDNAME=Raul”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:8] GotoIf(“SIP/7100-0000001d”, “0?report”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:9] Set(“SIP/7100-0000001d”, “AMPUSERCID=7100”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:10] Set(“SIP/7100-0000001d”, “__DIAL_OPTIONS=tr”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:11] Set(“SIP/7100-0000001d”, “CALLERID(all)=“Raul” <7100>”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:12] GotoIf(“SIP/7100-0000001d”, “0?limit”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:13] ExecIf(“SIP/7100-0000001d”, “0?Set(GROUP(concurrency_limit)=7100)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:14] ExecIf(“SIP/7100-0000001d”, “0?Set(CHANNEL(language)=)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:15] GosubIf(“SIP/7100-0000001d”, “7?sub-ccss,s,1(macro-exten-vm,7600)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] ExecIf(“SIP/7100-0000001d”, “0?Return()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:2] Set(“SIP/7100-0000001d”, “CCSS_SETUP=TRUE”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:3] GosubIf(“SIP/7100-0000001d”, “0?monitor_config,1(macro-exten-vm,7600):monitor_default,1(macro-exten-vm,7600)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/7100-0000001d”, “1?is_exten”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Goto (sub-ccss,monitor_default,4)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:4] Set(“SIP/7100-0000001d”, “CALLCOMPLETION(cc_monitor_policy)=generic”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:5] Set(“SIP/7100-0000001d”, “CALLCOMPLETION(cc_max_monitors)=5”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:6] Return(“SIP/7100-0000001d”, “TRUE”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:4] GosubIf(“SIP/7100-0000001d”, “7?agent_config,1():agent_default,1()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] Set(“SIP/7100-0000001d”, “CALLCOMPLETION(cc_agent_policy)=generic”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:2] Set(“SIP/7100-0000001d”, “CALLCOMPLETION(cc_offer_timer)=30”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:3] Set(“SIP/7100-0000001d”, “CALLCOMPLETION(ccbs_available_timer)=”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:4] Set(“SIP/7100-0000001d”, “CALLCOMPLETION(ccnr_available_timer)=”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:5] Set(“SIP/7100-0000001d”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack
[2014-03-22 14:42:57] WARNING[10482][C-0000001d] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:6] ExecIf(“SIP/7100-0000001d”, “1?Set(CALLCOMPLETION(cc_recall_timer)=)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:7] ExecIf(“SIP/7100-0000001d”, “1?Set(CALLCOMPLETION(cc_max_agents)=)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:8] ExecIf(“SIP/7100-0000001d”, “0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/[email protected])”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:9] Set(“SIP/7100-0000001d”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack
[2014-03-22 14:42:57] WARNING[10482][C-0000001d] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:10] Return(“SIP/7100-0000001d”, “”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:5] Set(“SIP/7100-0000001d”, “DB(AMPUSER/7100/ccss/last_number)=7600”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:6] Return(“SIP/7100-0000001d”, “”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:16] GotoIf(“SIP/7100-0000001d”, “0?continue”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:17] ExecIf(“SIP/7100-0000001d”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:18] Set(“SIP/7100-0000001d”, “__TTL=64”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:19] GotoIf(“SIP/7100-0000001d”, “1?continue”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Goto (macro-user-callerid,s,30)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:30] Set(“SIP/7100-0000001d”, “CALLERID(number)=7100”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:31] Set(“SIP/7100-0000001d”, “CALLERID(name)=Raul”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:32] Set(“SIP/7100-0000001d”, “CDR(cnum)=7100”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:33] Set(“SIP/7100-0000001d”, “CDR(cnam)=Raul”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:34] Set(“SIP/7100-0000001d”, “CHANNEL(language)=en”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:2] Set(“SIP/7100-0000001d”, “RingGroupMethod=none”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:3] Set(“SIP/7100-0000001d”, “__EXTTOCALL=7600”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:4] Set(“SIP/7100-0000001d”, “__PICKUPMARK=7600”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:5] Set(“SIP/7100-0000001d”, “RT=”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:6] ExecIf(“SIP/7100-0000001d”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:7] ExecIf(“SIP/7100-0000001d”, “0?MacroExit()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:8] Gosub(“SIP/7100-0000001d”, “sub-record-check,s,1(exten,7600,)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] Set(“SIP/7100-0000001d”, “REC_POLICY_MODE_SAVE=”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:2] GotoIf(“SIP/7100-0000001d”, “1?check”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Goto (sub-record-check,s,7)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:7] Set(“SIP/7100-0000001d”, “__MON_FMT=wav”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:8] GotoIf(“SIP/7100-0000001d”, “1?next”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Goto (sub-record-check,s,11)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:11] ExecIf(“SIP/7100-0000001d”, “0?Return()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:12] ExecIf(“SIP/7100-0000001d”, “0?Set(__REC_POLICY_MODE=)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:13] GotoIf(“SIP/7100-0000001d”, “0?exten,1”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:14] Set(“SIP/7100-0000001d”, “__REC_STATUS=INITIALIZED”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:15] Set(“SIP/7100-0000001d”, “NOW=1395499377”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:16] Set(“SIP/7100-0000001d”, “__DAY=22”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:17] Set(“SIP/7100-0000001d”, “__MONTH=03”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:18] Set(“SIP/7100-0000001d”, “__YEAR=2014”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:19] Set(“SIP/7100-0000001d”, “__TIMESTR=20140322-144257”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:20] Set(“SIP/7100-0000001d”, “__FROMEXTEN=7100”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:21] Set(“SIP/7100-0000001d”, “__CALLFILENAME=exten-7600-7100-20140322-144257-1395499376.29”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:22] Goto(“SIP/7100-0000001d”, “exten,1”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Goto (sub-record-check,exten,1)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/7100-0000001d”, “0?callee”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:2] Set(“SIP/7100-0000001d”, “__REC_POLICY_MODE=dontcare”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:3] GotoIf(“SIP/7100-0000001d”, “1?caller”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Goto (sub-record-check,exten,10)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:10] Set(“SIP/7100-0000001d”, “__REC_POLICY_MODE=dontcare”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:11] GosubIf(“SIP/7100-0000001d”, “0?record,1(exten,7600,7100)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:12] Return(“SIP/7100-0000001d”, “”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:9] GotoIf(“SIP/7100-0000001d”, “1?macrodial”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Goto (macro-exten-vm,s,15)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:15] GosubIf(“SIP/7100-0000001d”, “0?clrheader,1()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:16] Macro(“SIP/7100-0000001d”, “dial-one,tr,7600”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] Set(“SIP/7100-0000001d”, “DEXTEN=7600”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:2] Set(“SIP/7100-0000001d”, “DIALSTATUS_CW=”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:3] GosubIf(“SIP/7100-0000001d”, “0?screen,1()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:4] GosubIf(“SIP/7100-0000001d”, “0?cf,1()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:5] GotoIf(“SIP/7100-0000001d”, “1?skip1”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Goto (macro-dial-one,s,8)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:8] GotoIf(“SIP/7100-0000001d”, “0?nodial”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:9] GotoIf(“SIP/7100-0000001d”, “0?continue”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:10] Set(“SIP/7100-0000001d”, “EXTHASCW=ENABLED”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:11] GotoIf(“SIP/7100-0000001d”, “0?next1:cwinusebusy”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Goto (macro-dial-one,s,23)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:23] GotoIf(“SIP/7100-0000001d”, “1?next3:continue”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Goto (macro-dial-one,s,24)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:24] ExecIf(“SIP/7100-0000001d”, “0?Set(DIALSTATUS_CW=BUSY)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:25] GotoIf(“SIP/7100-0000001d”, “0?nodial”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:26] GosubIf(“SIP/7100-0000001d”, “1?dstring,1():dlocal,1()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] Set(“SIP/7100-0000001d”, “DSTRING=”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:2] Set(“SIP/7100-0000001d”, “DEVICES=7600”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:3] ExecIf(“SIP/7100-0000001d”, “0?Return()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:4] ExecIf(“SIP/7100-0000001d”, “0?Set(DEVICES=600)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:5] Set(“SIP/7100-0000001d”, “LOOPCNT=1”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:6] Set(“SIP/7100-0000001d”, “ITER=1”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:7] Set(“SIP/7100-0000001d”, “THISDIAL=SIP/7600”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:8] GosubIf(“SIP/7100-0000001d”, “1?zap2dahdi,1()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] ExecIf(“SIP/7100-0000001d”, “0?Return()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:2] Set(“SIP/7100-0000001d”, “NEWDIAL=”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:3] Set(“SIP/7100-0000001d”, “LOOPCNT2=1”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:4] Set(“SIP/7100-0000001d”, “ITER2=1”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:5] Set(“SIP/7100-0000001d”, “THISPART2=SIP/7600”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:6] ExecIf(“SIP/7100-0000001d”, “0?Set(THISPART2=DAHDI/7600)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:7] Set(“SIP/7100-0000001d”, “NEWDIAL=SIP/7600&”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:8] Set(“SIP/7100-0000001d”, “ITER2=2”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:9] GotoIf(“SIP/7100-0000001d”, “0?begin2”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:10] Set(“SIP/7100-0000001d”, “THISDIAL=SIP/7600”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:11] Return(“SIP/7100-0000001d”, “”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:9] Set(“SIP/7100-0000001d”, “DSTRING=SIP/7600&”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:10] Set(“SIP/7100-0000001d”, “ITER=2”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:11] GotoIf(“SIP/7100-0000001d”, “0?begin”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:12] Set(“SIP/7100-0000001d”, “DSTRING=SIP/7600”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:13] Return(“SIP/7100-0000001d”, “”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:27] GotoIf(“SIP/7100-0000001d”, “0?nodial”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:28] GotoIf(“SIP/7100-0000001d”, “0?skiptrace”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:29] GosubIf(“SIP/7100-0000001d”, “1?ctset,1():ctclear,1()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] Set(“SIP/7100-0000001d”, “DB(CALLTRACE/7600)=7100”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:2] Return(“SIP/7100-0000001d”, “”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:30] Set(“SIP/7100-0000001d”, “D_OPTIONS=tr”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:31] ExecIf(“SIP/7100-0000001d”, “0?SIPAddHeader(Alert-Info: )”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:32] ExecIf(“SIP/7100-0000001d”, “0?SIPAddHeader()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:33] ExecIf(“SIP/7100-0000001d”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:34] GosubIf(“SIP/7100-0000001d”, “0?qwait,1()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:35] Set(“SIP/7100-0000001d”, “__CWIGNORE=”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:36] Set(“SIP/7100-0000001d”, “__KEEPCID=TRUE”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:37] GotoIf(“SIP/7100-0000001d”, “0?usegoto,1”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:38] GotoIf(“SIP/7100-0000001d”, “0?godial”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:39] Gosub(“SIP/7100-0000001d”, “sub-presencestate-display,s,1(7600)”) in new stack
[2014-03-22 14:42:57] WARNING[10482][C-0000001d] func_presencestate.c: PRESENCE_STATE unknown
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] Goto(“SIP/7100-0000001d”, “state-,1”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Goto (sub-presencestate-display,state-,1)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [state-@sub-presencestate-display:1] Set(“SIP/7100-0000001d”, “PRESENCESTATE_DISPLAY=”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [state-@sub-presencestate-display:2] Return(“SIP/7100-0000001d”, “”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:40] Set(“SIP/7100-0000001d”, “CONNECTEDLINE(name,i)=Olga”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:41] Set(“SIP/7100-0000001d”, “CONNECTEDLINE(num)=7600”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:42] Set(“SIP/7100-0000001d”, “D_OPTIONS=trI”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:43] Dial(“SIP/7100-0000001d”, “SIP/7600,trI”) in new stack
[2014-03-22 14:42:57] WARNING[10482][C-0000001d] app_dial.c: Unable to create channel of type ‘SIP’ (cause 20 - Subscriber absent)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] app_dial.c: == Everyone is busy/congested at this time (1:0/0/1)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:44] ExecIf(“SIP/7100-0000001d”, “0?MacroExit()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:45] ExecIf(“SIP/7100-0000001d”, “0?Set(DIALSTATUS=)”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:46] GosubIf(“SIP/7100-0000001d”, “0?s-CHANUNAVAIL,1()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:47] MacroExit(“SIP/7100-0000001d”, “”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:17] Set(“SIP/7100-0000001d”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:18] GosubIf(“SIP/7100-0000001d”, “0?docfu,1()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:19] GosubIf(“SIP/7100-0000001d”, “0?docfb,1()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:20] Set(“SIP/7100-0000001d”, “DIALSTATUS=CHANUNAVAIL”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:21] ExecIf(“SIP/7100-0000001d”, “0?MacroExit()”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:22] GotoIf(“SIP/7100-0000001d”, “1?s-CHANUNAVAIL,1”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Goto (macro-exten-vm,s-CHANUNAVAIL,1)
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/7100-0000001d”, “0?exit,1”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:2] PlayTones(“SIP/7100-0000001d”, “congestion”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:3] Congestion(“SIP/7100-0000001d”, “10”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] app_macro.c: == Spawn extension (macro-exten-vm, s-CHANUNAVAIL, 3) exited non-zero on ‘SIP/7100-0000001d’ in macro ‘exten-vm’
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: == Spawn extension (from-internal, 7600, 2) exited non-zero on ‘SIP/7100-0000001d’
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: – Executing [[email protected]:1] Hangup(“SIP/7100-0000001d”, “”) in new stack
[2014-03-22 14:42:57] VERBOSE[10482][C-0000001d] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/7100-0000001d’
[2014-03-22 14:43:04] VERBOSE[2893][C-0000001e] netsock2.c: == Using SIP RTP TOS bits 184
[2014-03-22 14:43:04] VERBOSE[2893][C-0000001e] netsock2.c: == Using SIP RTP CoS mark 5
[2014-03-22 14:43:04] VERBOSE[10483][C-0000001e] pbx.c: – Executing [*[email protected]:1] Answer(“SIP/7100-0000001e”, “”) in new stack
[2014-03-22 14:43:05] VERBOSE[10483][C-0000001e] pbx.c: – Executing [*[email protected]:2] Wait(“SIP/7100-0000001e”, “1”) in new stack
[2014-03-22 14:43:06] VERBOSE[10483][C-0000001e] pbx.c: – Executing [*[email protected]:3] Playback(“SIP/7100-0000001e”, “demo-echotest”) in new stack
[2014-03-22 14:43:06] VERBOSE[10483][C-0000001e] file.c: – <SIP/7100-0000001e> Playing ‘demo-echotest.ulaw’ (language ‘en’)
[2014-03-22 14:43:07] VERBOSE[10483][C-0000001e] pbx.c: == Spawn extension (from-internal, *43, 3) exited non-zero on ‘SIP/7100-0000001e’
[2014-03-22 14:43:07] VERBOSE[10483][C-0000001e] pbx.c: – Executing [[email protected]:1] Hangup(“SIP/7100-0000001e”, “”) in new stack
[2014-03-22 14:43:07] VERBOSE[10483][C-0000001e] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/7100-0000001e’
[2014-03-22 14:43:16] VERBOSE[2893] chan_sip.c: – Unregistered SIP ‘7100’
[2014-03-22 14:43:29] VERBOSE[2893] chan_sip.c: – Unregistered SIP ‘7600’

Raul,

I would start a bit simpler if I were you to start… Definitely start with all test on the LAN, since NAT is another monster that should be dealt with later.

First on the main screen “FreePBX System Status”, make sure that you have 2 IP Phones online.

From there instead of getting verbose logs, from the linux prompt, type

asterisk -rvc

from the asterisk CLI type:

sip set debug on

This will allow you to see the SIP messages from the phone to the Server and back to the other phone.

your call flow should look like this

Invite ->
<- 401 Unauthorized
Invite ->
<- Trying
<- Ringing
<- 200 OK
ACK ->

If you are getting an error response after the second Invite, it could mean the credentials are incorrect. If not you have to start looking at the other side:

So the full call flow would look like

7100 FreePBX 7600
Invite ->
<- 401 Unauthorized
Invite ->
<- Trying
Invite ->
<- Trying
<- Ringing
<- Ringing

Where ever the message was last sent, and you do not get a response or you get either a 4xx 5xx or 6xx response is going to be where the problem is.

I hope this helps.

Cheers,

  • Steve

Ok the second call flow didn’t tab properly, basically just follow each message from one phone to the the other through the FreePBX, SIP is a request/response protocol so there should be a response to every request at the application layer, if you get no response it maybe a transport/ip issue, if you get a error 4xx 5xx 6xx its generally configuration of the Endpoint that issues the error or something it doesn’t like in the SIP message.

Hi Steve,

Sorry for replying late, I have been travelling and am currently reorganising my LAN, I would like to complete this job and have a clean sheet before I dive again in diagnosing the problems of my network. I should be able to complete the job by Tuesday and soon after that I will go through the steps in your message.

Thank you for now, I appreciate your help and, once more, apologies for my late reply. I will come back to you and the group as soon as I can run more tests.

Regards

Raul

At last, I have a few hours to dedicate to Asterisk. After launching the above commands ‘asterisk -rvc’ and then ‘sip set debug on’, my phones have been thrown out of the network and been unable to login since. What I get is the below messages.

If I go to the dashboard (when you click the left icon on the welcome page) I can see that there is something still connected, although now all devices are off. I even rebooted the pi but the situation persists; I tried an update/upgrade but had no luck.

I finally tried deleting the users and recreating them from fresh in a bid to try and login again but failed.

I am now no longer confident that I will be able to restore the system to its original status, I am going to rewrite the card and start from the beginning so I can keep track of every step once again.

Before I try the debugging again, what does exactly ‘asterisk -rvc’ do, and how can I reverse it when I am done? The debug command seems to be fine, it stops the debugging when I type ‘sip set debug off’.

Many thanks.

Raul

Retransmitting #4 (NAT) to 86.147.176.23:1024:
OPTIONS sip:[email protected]:56214;ob SIP/2.0
Via: SIP/2.0/UDP 86.147.176.23:5060;branch=z9hG4bK0b391906;rport
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as0684b2e2
To: sip:[email protected]:56214;ob
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-2.11.0(11.6.0)
Date: Thu, 01 May 2014 10:25:24 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


Really destroying SIP dialog ‘[email protected]:5060’ Method: OPTIONS
Reliably Transmitting (NAT) to 86.147.176.23:1024:
OPTIONS sip:[email protected]:56214;ob SIP/2.0
Via: SIP/2.0/UDP 86.147.176.23:5060;branch=z9hG4bK5ad3e905;rport
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as1ab5b3da
To: sip:[email protected]:56214;ob
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-2.11.0(11.6.0)
Date: Thu, 01 May 2014 10:25:38 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

asterisk -rvc should not do anything permanent to the configuration at all. I’m not sure why the “c” is needed here but all that “-rv” does is to connect you as a console to the asterisk daemon (that’s the “r” bit). The “v” part turns on verification. The more “v”'s the higher level of logging, so:

asterisk -rvvv sets logging to level 3 which gives you more diagnostic messages. If logging is already set to a higher level though this will not reduce it.

Thanks Lee.

I have now reinstalled and made some progress. I didn’t have to go through debugging, probably in my previous installation I must have done something wrong and that prevented me from configuring correctly.

My system is behind a router that provides NAT and I will most likely be using connections that are behind other NAT routers, so I configured as NAT [Yes], IP Configuration [Dynamic IP], Dynamic Host [Correct Hostname], Local Networks [192.168.1.0 / 255.255.255.0].

Done this I set up two extensions and tested the system with Zoiper, an Android app that I installed on two spartphones. I am able to successfully make a call between two phones located inside the LAN, with voice in both directions. When I connect a phone from the outside network I can call the other phone inside the network but am unable to make a call if both phones are outside the network (i.e. both phones connected through the mobile network) even if both of them seem to be correctly registered on the server.

I suspect that the system cannot understand how to route a call to the outside world when a device is connected that way. I don’t know if it is a trunk problem, however I configured the router to always allocate a fixed address to the server and forwarded port 5060 (the listening port) to it, as well as ports from 10500 to 11000 to the same address for the trunks.

I think the problem is more in the configuration, I need to get the system to route the calls to the external address where the client has logged in from.

Can anyone point me to a solution or help me configuring the system correctly?

As a side note, this software is very powerful and at the same time relatively simple to setup - consider that I had never seen any VoIP servers before and I am already up and running, although with limited functionality.

Quick point, you forward 10500-11000 rtp ports (audio), does that agree with the range set in your /etc/asterisk/rtp*.conf tree?

Your posted

Retransmitting #4 (NAT) to 86.147.176.23:1024:

indicates that you have your nat/routers/forwarding set up incorrectly still.

Also the extensions that you are using outside your network: are the extensions themselves set to NAT=yes?

I checked that file in /etc/asterisk and I only have a link to a file with the same name in another directory. However, I followed the link and opened the actual file and there is some text in it saying not to edit it - this reflects the content that I have seen in the link.

So I went in the dashboard > Asterisk SIP Settings and corrected ‘RTP Port Ranges’ to 10500-14500 (they were 10000-20000). The reason of this new setting is that this is as many ports I can make available to Asterisk in my network. I updated the firewall accordingly so it now forwards ports 10500-14500 to FreePBX).

There is more: thanks to Lee and his pointing out that the extensions also need to be set as NAT [Yes] I found that all extensions were in fact set to [No]. I changed that too.

I can’t test the system now but will try tomorrow, hopefully I (you guys, really) managed to fix it.

More news as soon as I run some ex-LAN tests tomorrow.

Thank you all for your help.

Raul

Thanks Lee, they were all set to [No]. I’ll test it tomorrow and see how much progress I made.

Regards

Raul