Disconnecting channel on incoming call issue

Hello. I’m not sure is this asterisk issue or FreePBX, but please help me with that.

Here is the case description and log below.
Internal extension 777 is an agent in queue with Follow-Me set to 444444444444 and 555555555555 external numbers.
777 calls outbound number 11111111111 via trunk ‘online’, 11111111111 answers, and they have a conversation during about 1 minute. Then suddenly (21:01:26) a call from the trunk from 88888888888 arrives.
This call is put in queue and transferred to 777 as this is the only agent for this queue.
OK. At that moment 11111111111 is disconnected from the channel, despite he didn’t do that, and at his side call is hanged up.
At the same moment 777 starts to hear 88888888888, which he didn’t expect.
6 seconds after that 88888888888 is disconnected, despite he didn’t do this, as well.
777 hears silence.
After that 777 hangs up.

The problem is: 88888888888 is not expected to interrupt conversation between 777 and 11111111111, he normally must be put in queue and be held listening music-on-hold, while calling to follow-me numbers.

[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:1] Macro("PJSIP/777-00000002", "user-callerid,LIMIT,EXTERNAL,") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:1] Set("PJSIP/777-00000002", "TOUCH_MONITOR=1435341626.98") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:2] Set("PJSIP/777-00000002", "AMPUSER=777") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:3] GotoIf("PJSIP/777-00000002", "0?report") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:4] ExecIf("PJSIP/777-00000002", "1?Set(REALCALLERIDNUM=777)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:5] Set("PJSIP/777-00000002", "AMPUSER=777") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:6] GotoIf("PJSIP/777-00000002", "0?limit") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:7] Set("PJSIP/777-00000002", "AMPUSERCIDNAME=Dmitriy Stepanov") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:8] GotoIf("PJSIP/777-00000002", "0?report") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:9] Set("PJSIP/777-00000002", "AMPUSERCID=777") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:10] Set("PJSIP/777-00000002", "__DIAL_OPTIONS=Ttr") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:11] Set("PJSIP/777-00000002", "CALLERID(all)="Dmitriy Stepanov" <777>") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:12] GotoIf("PJSIP/777-00000002", "0?limit") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:13] ExecIf("PJSIP/777-00000002", "1?Set(GROUP(concurrency_limit)=777)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:14] GosubIf("PJSIP/777-00000002", "7?sub-ccss,s,1(from-internal,)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:1] ExecIf("PJSIP/777-00000002", "0?Return()") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:2] Set("PJSIP/777-00000002", "CCSS_SETUP=TRUE") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:3] GosubIf("PJSIP/777-00000002", "0?monitor_config,1(from-internal,):monitor_default,1(from-internal,)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/777-00000002", "0?is_exten") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:2] Set("PJSIP/777-00000002", "CALLCOMPLETION(cc_monitor_policy)=always") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:3] Set("PJSIP/777-00000002", "CALLCOMPLETION(cc_max_monitors)=5") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:4] Return("PJSIP/777-00000002", "TRUE") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:4] GosubIf("PJSIP/777-00000002", "7?agent_config,1():agent_default,1()") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:1] Set("PJSIP/777-00000002", "CALLCOMPLETION(cc_agent_policy)=generic") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:2] Set("PJSIP/777-00000002", "CALLCOMPLETION(cc_offer_timer)=30") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:3] Set("PJSIP/777-00000002", "CALLCOMPLETION(ccbs_available_timer)=") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:4] Set("PJSIP/777-00000002", "CALLCOMPLETION(ccnr_available_timer)=") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:5] Set("PJSIP/777-00000002", "CALLCOMPLETION(cc_callback_macro)=ccss-default") in new stack
[2015-06-26 21:00:26] WARNING[4238][C-00000002] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:6] ExecIf("PJSIP/777-00000002", "1?Set(CALLCOMPLETION(cc_recall_timer)=)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:7] ExecIf("PJSIP/777-00000002", "1?Set(CALLCOMPLETION(cc_max_agents)=)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:8] ExecIf("PJSIP/777-00000002", "0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/[email protected])") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:9] Set("PJSIP/777-00000002", "CALLCOMPLETION(cc_callback_macro)=ccss-default") in new stack
[2015-06-26 21:00:26] WARNING[4238][C-00000002] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:10] Return("PJSIP/777-00000002", "") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:5] Set("PJSIP/777-00000002", "DB(AMPUSER/777/ccss/last_number)=") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:6] Return("PJSIP/777-00000002", "") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:15] ExecIf("PJSIP/777-00000002", "1?Set(CHANNEL(language)=en)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:16] GotoIf("PJSIP/777-00000002", "1?continue") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Goto (macro-user-callerid,s,30)
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:30] Set("PJSIP/777-00000002", "CALLERID(number)=777") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:31] Set("PJSIP/777-00000002", "CALLERID(name)=Dmitriy Stepanov") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:32] Set("PJSIP/777-00000002", "CDR(cnum)=777") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:33] Set("PJSIP/777-00000002", "CDR(cnam)=Dmitriy Stepanov") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:34] Set("PJSIP/777-00000002", "CHANNEL(language)=en") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:2] Gosub("PJSIP/777-00000002", "sub-record-check,s,1(out,11111111111,dontcare)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/777-00000002", "0?initialized") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:2] Set("PJSIP/777-00000002", "__REC_STATUS=INITIALIZED") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:3] Set("PJSIP/777-00000002", "NOW=1435341626") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:4] Set("PJSIP/777-00000002", "__DAY=26") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:5] Set("PJSIP/777-00000002", "__MONTH=06") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:6] Set("PJSIP/777-00000002", "__YEAR=2015") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:7] Set("PJSIP/777-00000002", "__TIMESTR=20150626-210026") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:8] Set("PJSIP/777-00000002", "__FROMEXTEN=777") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:9] Set("PJSIP/777-00000002", "__MON_FMT=wav") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:10] NoOp("PJSIP/777-00000002", "Recordings initialized") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:11] ExecIf("PJSIP/777-00000002", "0?Set(ARG3=dontcare)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:12] Set("PJSIP/777-00000002", "REC_POLICY_MODE_SAVE=") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:13] ExecIf("PJSIP/777-00000002", "0?Set(REC_STATUS=NO)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:14] GotoIf("PJSIP/777-00000002", "3?checkaction") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Goto (sub-record-check,s,17)
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:17] GotoIf("PJSIP/777-00000002", "1?sub-record-check,out,1") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Goto (sub-record-check,out,1)
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:1] NoOp("PJSIP/777-00000002", "Outbound Recording Check from 777 to 11111111111") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:2] Set("PJSIP/777-00000002", "RECMODE=yes") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/777-00000002", "0?Goto(routewins)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:4] ExecIf("PJSIP/777-00000002", "0?Goto(routewins)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:5] Gosub("PJSIP/777-00000002", "recordcheck,1(yes,out,11111111111)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:1] NoOp("PJSIP/777-00000002", "Starting recording check against yes") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:2] Goto("PJSIP/777-00000002", "yes") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Goto (sub-record-check,recordcheck,9)
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:9] ExecIf("PJSIP/777-00000002", "0?Return()") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:10] Set("PJSIP/777-00000002", "__REC_POLICY_MODE=YES") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:11] Goto("PJSIP/777-00000002", "startrec") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Goto (sub-record-check,recordcheck,16)
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:16] NoOp("PJSIP/777-00000002", "Starting recording: out, 11111111111") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:17] Set("PJSIP/777-00000002", "AUDIOHOOK_INHERIT(MixMonitor)=yes") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:18] Set("PJSIP/777-00000002", "__CALLFILENAME=out-11111111111-777-20150626-210026-1435341626.98") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:19] MixMonitor("PJSIP/777-00000002", "2015/06/26/out-11111111111-777-20150626-210026-1435341626.98.wav,ai(LOCAL_MIXMON_ID),") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:20] Set("PJSIP/777-00000002", "__MIXMON_ID=0x7fb75c7046d0") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:21] Set("PJSIP/777-00000002", "__RECORD_ID=PJSIP/777-00000002") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:22] Set("PJSIP/777-00000002", "__REC_STATUS=RECORDING") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:23] Set("PJSIP/777-00000002", "CDR(recordingfile)=out-11111111111-777-20150626-210026-1435341626.98.wav") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:24] Return("PJSIP/777-00000002", "") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:6] Return("PJSIP/777-00000002", "") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/777-00000002", "0 ?Set(CDR(accountcode)=)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:4] Set("PJSIP/777-00000002", "MOHCLASS=default") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:5] Set("PJSIP/777-00000002", "_NODEST=") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:6] Macro("PJSIP/777-00000002", "dialout-trunk,1,11111111111,,on") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:1] Set("PJSIP/777-00000002", "DIAL_TRUNK=1") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:2] GosubIf("PJSIP/777-00000002", "0?sub-pincheck,s,1()") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:3] GotoIf("PJSIP/777-00000002", "0?disabletrunk,1") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:4] Set("PJSIP/777-00000002", "DIAL_NUMBER=11111111111") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:5] Set("PJSIP/777-00000002", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:6] Set("PJSIP/777-00000002", "OUTBOUND_GROUP=OUT_1") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:7] GotoIf("PJSIP/777-00000002", "0?nomax") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:8] GotoIf("PJSIP/777-00000002", "0?chanfull") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:9] GotoIf("PJSIP/777-00000002", "0?skipoutcid") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:10] Set("PJSIP/777-00000002", "DIAL_TRUNK_OPTIONS=Tt") in new stack
[2015-06-26 21:00:26] VERBOSE[4244][C-00000002] app_mixmonitor.c: Begin MixMonitor Recording PJSIP/777-00000002
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:11] Macro("PJSIP/777-00000002", "outbound-callerid,1") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:1] ExecIf("PJSIP/777-00000002", "0?Set(CALLERPRES(name-pres)=)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:2] ExecIf("PJSIP/777-00000002", "0?Set(CALLERPRES(num-pres)=)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/777-00000002", "0?Set(REALCALLERIDNUM=777)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:4] GotoIf("PJSIP/777-00000002", "1?normcid") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Goto (macro-outbound-callerid,s,7)
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:7] Set("PJSIP/777-00000002", "USEROUTCID=") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:8] Set("PJSIP/777-00000002", "EMERGENCYCID=") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:9] Set("PJSIP/777-00000002", "TRUNKOUTCID=74996086824") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:10] GotoIf("PJSIP/777-00000002", "1?trunkcid") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Goto (macro-outbound-callerid,s,15)
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:15] ExecIf("PJSIP/777-00000002", "1?Set(CALLERID(all)=74996086824)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:16] ExecIf("PJSIP/777-00000002", "0?Set(CALLERID(all)=)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:17] ExecIf("PJSIP/777-00000002", "1?Set(CALLERID(all)=74996086824)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:18] ExecIf("PJSIP/777-00000002", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:19] ExecIf("PJSIP/777-00000002", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:20] Set("PJSIP/777-00000002", "CDR(outbound_cnum)=74996086824") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:21] Set("PJSIP/777-00000002", "CDR(outbound_cnam)=") in new stack
[2015-06-26 21:00:26] WARNING[2869] func_cdr.c: CDR requires a value (CDR(variable)=value)
)[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:12] GosubIf("PJSIP/777-00000002", "0?sub-flp-1,s,1()") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:13] Set("PJSIP/777-00000002", "OUTNUM=11111111111") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:14] Set("PJSIP/777-00000002", "custom=SIP/online_sip") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:15] ExecIf("PJSIP/777-00000002", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:16] ExecIf("PJSIP/777-00000002", "0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:17] Macro("PJSIP/777-00000002", "dialout-trunk-predial-hook,") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:1] MacroExit("PJSIP/777-00000002", "") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:18] GotoIf("PJSIP/777-00000002", "0?bypass,1") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:19] ExecIf("PJSIP/777-00000002", "1?Set(CONNECTEDLINE(num,i)=11111111111)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:20] ExecIf("PJSIP/777-00000002", "1?Set(CONNECTEDLINE(name,i)=CID:74996086824)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:21] ExecIf("PJSIP/777-00000002", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)74996086824)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:22] GotoIf("PJSIP/777-00000002", "0?customtrunk") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:23] Dial("PJSIP/777-00000002", "SIP/online_sip/11111111111,300,Tt") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] netsock2.c: Using SIP RTP TOS bits 184
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] netsock2.c: Using SIP RTP CoS mark 5
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] app_dial.c: Called SIP/online_sip/11111111111
[2015-06-26 21:00:30] VERBOSE[4238][C-00000002] app_dial.c: SIP/online_sip-00000002 is making progress passing it to PJSIP/777-00000002
[2015-06-26 21:00:33] VERBOSE[4238][C-00000002] app_dial.c: SIP/online_sip-00000002 answered PJSIP/777-00000002
[2015-06-26 21:00:33] VERBOSE[4238][C-00000002] bridge_channel.c: Channel PJSIP/777-00000002 joined 'simple_bridge' basic-bridge <76d2a85a-7d1f-4a4f-a432-3756b2632681>
[2015-06-26 21:00:33] VERBOSE[4247][C-00000002] bridge_channel.c: Channel SIP/online_sip-00000002 joined 'simple_bridge' basic-bridge <76d2a85a-7d1f-4a4f-a432-3756b2632681>
[2015-06-26 21:01:26] VERBOSE[2972][C-00000003] netsock2.c: Using SIP RTP TOS bits 184
[2015-06-26 21:01:26] VERBOSE[2972][C-00000003] netsock2.c: Using SIP RTP CoS mark 5
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] NoOp("SIP/online_sip-00000003", "Catch-All DID Match - Found 20002272222222222 - You probably want a DID for this.") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Log("SIP/online_sip-00000003", "WARNING,Friendly Scanner from 77.37.128.18") in new stack
[2015-06-26 21:01:26] WARNING[4285][C-00000003] Ext. 20002272222222222: Friendly Scanner from 77.37.128.18
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] Set("SIP/online_sip-00000003", "__FROM_DID=20002272222222222") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:4] Goto("SIP/online_sip-00000003", "ext-did,s,1") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Goto (ext-did,s,1)
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] ExecIf("SIP/online_sip-00000003", "0?Set(__FROM_DID=s)") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Gosub("SIP/online_sip-00000003", "sub-record-check,s,1(in,s,dontcare)") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] GotoIf("SIP/online_sip-00000003", "0?initialized") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000003", "__REC_STATUS=INITIALIZED") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] Set("SIP/online_sip-00000003", "NOW=1435341686") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:4] Set("SIP/online_sip-00000003", "__DAY=26") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:5] Set("SIP/online_sip-00000003", "__MONTH=06") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:6] Set("SIP/online_sip-00000003", "__YEAR=2015") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:7] Set("SIP/online_sip-00000003", "__TIMESTR=20150626-210126") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:8] Set("SIP/online_sip-00000003", "__FROMEXTEN=unknown") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:9] Set("SIP/online_sip-00000003", "__MON_FMT=wav") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:10] NoOp("SIP/online_sip-00000003", "Recordings initialized") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:11] ExecIf("SIP/online_sip-00000003", "0?Set(ARG3=dontcare)") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:12] Set("SIP/online_sip-00000003", "REC_POLICY_MODE_SAVE=") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:13] ExecIf("SIP/online_sip-00000003", "0?Set(REC_STATUS=NO)") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:14] GotoIf("SIP/online_sip-00000003", "2?checkaction") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Goto (sub-record-check,s,17)
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:17] GotoIf("SIP/online_sip-00000003", "1?sub-record-check,in,1") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Goto (sub-record-check,in,1)
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] NoOp("SIP/online_sip-00000003", "Inbound Recording Check to s") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000003", "FROMEXTEN=unknown") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] ExecIf("SIP/online_sip-00000003", "11?Set(FROMEXTEN=88888888888)") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:4] Gosub("SIP/online_sip-00000003", "recordcheck,1(dontcare,in,s)") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] NoOp("SIP/online_sip-00000003", "Starting recording check against dontcare") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Goto("SIP/online_sip-00000003", "dontcare") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Goto (sub-record-check,recordcheck,3)
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] Return("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:5] Return("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] Gosub("SIP/online_sip-00000003", "cidlookup,cidlookup_2,1()") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] Set("SIP/online_sip-00000003", "CURLOPT(httptimeout)=7") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000003", "CALLERID(name)=") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] Return("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:4] Gosub("SIP/online_sip-00000003", "app-blacklist-check,s,1()") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] GotoIf("SIP/online_sip-00000003", "0?blacklisted") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000003", "CALLED_BLACKLIST=1") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] Return("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:5] Set("SIP/online_sip-00000003", "CDR(did)=20002272222222222") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:6] ExecIf("SIP/online_sip-00000003", "1 ?Set(CALLERID(name)=88888888888)") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:7] Set("SIP/online_sip-00000003", "CHANNEL(musicclass)=default") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:8] Set("SIP/online_sip-00000003", "__MOHCLASS=default") in new stack
[2015-06-26 21:01:26] WARNING[4285][C-00000003] func_channel.c: Unknown or unavailable item requested: 'reversecharge'
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:9] GotoIf("SIP/online_sip-00000003", "0?macro-hangupcall") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:10] Macro("SIP/online_sip-00000003", "privacy-mgr,3,10") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] Set("SIP/online_sip-00000003", "KEEPCID=88888888888") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000003", "TESTCID=89266734399.000000") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] ExecIf("SIP/online_sip-00000003", "0?Set(CALLERID(num)=)") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:4] PrivacyManager("SIP/online_sip-00000003", "3,10") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] app_privacy.c: CallerID number present: Skipping
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:5] GotoIf("SIP/online_sip-00000003", "0?fail") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:6] GosubIf("SIP/online_sip-00000003", "1?app-blacklist-check,s,1()") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] GotoIf("SIP/online_sip-00000003", "0?blacklisted") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000003", "CALLED_BLACKLIST=1") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] Return("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:7] Set("SIP/online_sip-00000003", "CALLERID(num-pres)=allowed_passed_screen") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:8] MacroExit("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:11] Goto("SIP/online_sip-00000003", "ivr-2,s,1") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Goto (ivr-2,s,1)
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] Set("SIP/online_sip-00000003", "_IVR_CONTEXT_ivr-2=") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000003", "_IVR_CONTEXT=ivr-2") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] Set("SIP/online_sip-00000003", "__IVR_RETVM=") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:4] GotoIf("SIP/online_sip-00000003", "0?skip") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:5] Answer("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:27] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:6] Wait("SIP/online_sip-00000003", "1") in new stack
[2015-06-26 21:01:28] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:7] Set("SIP/online_sip-00000003", "IVR_MSG=") in new stack
[2015-06-26 21:01:28] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:8] Set("SIP/online_sip-00000003", "TIMEOUT(digit)=3") in new stack
[2015-06-26 21:01:28] VERBOSE[4285][C-00000003] func_timeout.c: Digit timeout set to 3.000
[2015-06-26 21:01:28] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:9] ExecIf("SIP/online_sip-00000003", "0?Background()") in new stack
[2015-06-26 21:01:28] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:10] WaitExten("SIP/online_sip-00000003", "2,") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Timeout on SIP/online_sip-00000003, going to 't'
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] Goto("SIP/online_sip-00000003", "ext-queues,9901,1") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Goto (ext-queues,9901,1)
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] Macro("SIP/online_sip-00000003", "user-callerid,") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] Set("SIP/online_sip-00000003", "TOUCH_MONITOR=1435341686.108") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000003", "AMPUSER=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] GotoIf("SIP/online_sip-00000003", "0?report") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:4] ExecIf("SIP/online_sip-00000003", "1?Set(REALCALLERIDNUM=88888888888)") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:5] Set("SIP/online_sip-00000003", "AMPUSER=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:6] GotoIf("SIP/online_sip-00000003", "0?limit") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:7] Set("SIP/online_sip-00000003", "AMPUSERCIDNAME=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:8] GotoIf("SIP/online_sip-00000003", "1?report") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Goto (macro-user-callerid,s,16)
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:16] GotoIf("SIP/online_sip-00000003", "0?continue") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:17] ExecIf("SIP/online_sip-00000003", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:18] Set("SIP/online_sip-00000003", "__TTL=64") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:19] GotoIf("SIP/online_sip-00000003", "1?continue") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Goto (macro-user-callerid,s,30)
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:30] Set("SIP/online_sip-00000003", "CALLERID(number)=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:31] Set("SIP/online_sip-00000003", "CALLERID(name)=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:32] Set("SIP/online_sip-00000003", "CDR(cnum)=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:33] Set("SIP/online_sip-00000003", "CDR(cnam)=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:34] Set("SIP/online_sip-00000003", "CHANNEL(language)=en") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Answer("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] ExecIf("SIP/online_sip-00000003", "1?Set(__QUEUEWAIT=1435341690)") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:4] Macro("SIP/online_sip-00000003", "blkvm-set,reset") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] ExecIf("SIP/online_sip-00000003", "1?Set(__BLKVM_CHANNEL=SIP/online_sip-00000003)") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000003", "SHARED(BLKVM,SIP/online_sip-00000003)=TRUE") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] Set("SIP/online_sip-00000003", "GOSUB_RETVAL=TRUE") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:4] MacroExit("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:5] ExecIf("SIP/online_sip-00000003", "1?Set(_DIAL_OPTIONS=TtrM(auto-blkvm))") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:6] Set("SIP/online_sip-00000003", "__NODEST=9901") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:7] Set("SIP/online_sip-00000003", "QCIDPP=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:8] Set("SIP/online_sip-00000003", "VQ_CIDPP=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:9] ExecIf("SIP/online_sip-00000003", "0?Macro(prepend-cid,)") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:10] Set("SIP/online_sip-00000003", "QAINFO=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:11] Set("SIP/online_sip-00000003", "VQ_AINFO=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:12] ExecIf("SIP/online_sip-00000003", "0?Set(__ALERT_INFO=)") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:13] Set("SIP/online_sip-00000003", "QJOINMSG=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:14] Set("SIP/online_sip-00000003", "VQ_JOINMSG=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:15] Set("SIP/online_sip-00000003", "QRETRY=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:16] Set("SIP/online_sip-00000003", "VQ_RETRY=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:17] Set("SIP/online_sip-00000003", "QOPTIONS=t") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:18] Set("SIP/online_sip-00000003", "VQ_OPTIONS=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:19] Set("SIP/online_sip-00000003", "QGOSUB=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:20] Set("SIP/online_sip-00000003", "VQ_GOSUB=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:21] Set("SIP/online_sip-00000003", "QAGI=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:22] Set("SIP/online_sip-00000003", "VQ_AGI=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:23] Set("SIP/online_sip-00000003", "QRULE=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:24] Set("SIP/online_sip-00000003", "VQ_RULE=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:25] Set("SIP/online_sip-00000003", "QPOSITION=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:26] Set("SIP/online_sip-00000003", "VQ_POSITION=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:27] Gosub("SIP/online_sip-00000003", "sub-record-check,s,1(q,9901,dontcare)") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] GotoIf("SIP/online_sip-00000003", "11?initialized") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Goto (sub-record-check,s,10)
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:10] NoOp("SIP/online_sip-00000003", "Recordings initialized") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:11] ExecIf("SIP/online_sip-00000003", "0?Set(ARG3=dontcare)") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:12] Set("SIP/online_sip-00000003", "REC_POLICY_MODE_SAVE=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:13] ExecIf("SIP/online_sip-00000003", "0?Set(REC_STATUS=NO)") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:14] GotoIf("SIP/online_sip-00000003", "1?checkaction") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Goto (sub-record-check,s,17)
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:17] GotoIf("SIP/online_sip-00000003", "0?sub-record-check,q,1") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:18] NoOp("SIP/online_sip-00000003", "Generic q Recording Check - 88888888888 9901") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:19] Gosub("SIP/online_sip-00000003", "recordcheck,1(dontcare,q,9901)") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] NoOp("SIP/online_sip-00000003", "Starting recording check against dontcare") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:2] Goto("SIP/online_sip-00000003", "dontcare") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Goto (sub-record-check,recordcheck,3)
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] Return("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:20] Return("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:28] Set("SIP/online_sip-00000003", "__CWIGNORE=TRUE") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:29] ExecIf("SIP/online_sip-00000003", "0?Playback(, )") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:30] QueueLog("SIP/online_sip-00000003", "9901,1435341686.108,NONE,DID,20002272222222222") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:31] Set("SIP/online_sip-00000003", "QAANNOUNCE=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:32] Set("SIP/online_sip-00000003", "VQ_AANNOUNCE=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:33] Set("SIP/online_sip-00000003", "QMOH=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:34] Set("SIP/online_sip-00000003", "VQ_MOH=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:35] ExecIf("SIP/online_sip-00000003", "0?Set(__MOHCLASS=)") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:36] ExecIf("SIP/online_sip-00000003", "1?Set(CHANNEL(musicclass)=default)") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:37] Set("SIP/online_sip-00000003", "QMAXWAIT=260") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:38] Set("SIP/online_sip-00000003", "VQ_MAXWAIT=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:39] Set("SIP/online_sip-00000003", "QUEUENUM=9901") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:40] Set("SIP/online_sip-00000003", "QUEUEJOINTIME=1435341690") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:41] Queue("SIP/online_sip-00000003", "9901,t,,,260,,,,,") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/online_sip-00000003'
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] app_queue.c: Called Local/[email protected]/n
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] app_queue.c: -- LazyMembers debugging - Numbusies: 0, Nummems: 0
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:1] Set("Local/[email protected];2", "QAGENT=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:2] Goto("Local/[email protected];2", "9901,1") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Goto (from-queue,9901,1)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:1] Goto("Local/[email protected];2", "from-internal,777,1") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Goto (from-internal,777,1)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:1] GotoIf("Local/[email protected];2", "0?ext-local,777,1") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:2] Macro("Local/[email protected];2", "user-callerid,") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:1] Set("Local/[email protected];2", "TOUCH_MONITOR=1435341690.114") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]lerid:2] Set("Local/[email protected];2", "AMPUSER=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:3] GotoIf("Local/[email protected];2", "1?report") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Goto (macro-user-callerid,s,16)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:16] GotoIf("Local/[email protected];2", "0?continue") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:17] ExecIf("Local/[email protected];2", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:18] Set("Local/[email protected];2", "__TTL=63") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:19] GotoIf("Local/[email protected];2", "1?continue") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Goto (macro-user-callerid,s,30)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:30] Set("Local/[email protected];2", "CALLERID(number)=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:31] Set("Local/[email protected];2", "CALLERID(name)=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:32] Set("Local/[email protected];2", "CDR(cnum)=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:33] Set("Local/[email protected];2", "CDR(cnam)=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:34] Set("Local/[email protected];2", "CHANNEL(language)=en") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:3] Set("Local/[email protected];2", "DIAL_OPTIONS=TtrM(auto-blkvm)I") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:4] Set("Local/[email protected];2", "CONNECTEDLINE(num,i)=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:5] Gosub("Local/[email protected];2", "sub-presencestate-display,s,1(777)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:1] Goto("Local/[email protected];2", "state-unavailable,1") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Goto (sub-presencestate-display,state-unavailable,1)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:1] Set("Local/[email protected];2", "PRESENCESTATE_DISPLAY=(Unavailable)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:2] Return("Local/[email protected];2", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:6] Set("Local/[email protected];2", "CONNECTEDLINE(name)=Dmitriy Stepanov(Unavailable)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:7] Set("Local/[email protected];2", "FM_DIALSTATUS=INUSE") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:8] Set("Local/[email protected];2", "__EXTTOCALL=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:9] Set("Local/[email protected];2", "__PICKUPMARK=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:10] Macro("Local/[email protected];2", "blkvm-setifempty,") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:1] GotoIf("Local/[email protected];2", "0?init") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:2] Set("Local/[email protected];2", "GOSUB_RETVAL=TRUE") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:3] MacroExit("Local/[email protected];2", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:11] GotoIf("Local/[email protected];2", "1?skipov") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Goto (from-internal,777,14)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:14] Set("Local/[email protected];2", "RRNODEST=9901") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:15] Set("Local/[email protected];2", "__NODEST=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:16] GosubIf("Local/[email protected];2", "0?sub-fmsetcid,s,1()") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:17] Set("Local/[email protected];2", "RecordMethod=Group") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:18] Gosub("Local/[email protected];2", "sub-record-check,s,1(exten,777,)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:1] GotoIf("Local/[email protected];2", "0?initialized") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:2] Set("Local/[email protected];2", "__REC_STATUS=INITIALIZED") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:3] Set("Local/[email protected];2", "NOW=1435341690") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:4] Set("Local/[email protected];2", "__DAY=26") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:5] Set("Local/[email protected];2", "__MONTH=06") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:6] Set("Local/[email protected];2", "__YEAR=2015") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:7] Set("Local/[email protected];2", "__TIMESTR=20150626-210130") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:8] Set("Local/[email protected];2", "__FROMEXTEN=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:9] Set("Local/[email protected];2", "__MON_FMT=wav") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:10] NoOp("Local/[email protected];2", "Recordings initialized") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:11] ExecIf("Local/[email protected];2", "1?Set(ARG3=dontcare)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:12] Set("Local/[email protected];2", "REC_POLICY_MODE_SAVE=") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:13] ExecIf("Local/[email protected];2", "0?Set(REC_STATUS=NO)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:14] GotoIf("Local/[email protected];2", "5?checkaction") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Goto (sub-record-check,s,17)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:17] GotoIf("Local/[email protected];2", "1?sub-record-check,exten,1") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Goto (sub-record-check,exten,1)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:1] NoOp("Local/[email protected];2", "Exten Recording Check between 88888888888 and 777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:2] Set("Local/[email protected];2", "CALLTYPE=external") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?Set(CALLTYPE=)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:4] Set("Local/[email protected];2", "CALLEE=yes") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:5] ExecIf("Local/[email protected];2", "0?Set(CALLEE=dontcare)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:6] GotoIf("Local/[email protected];2", "1?callee") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Goto (sub-record-check,exten,11)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:11] Gosub("Local/[email protected];2", "recordcheck,1(yes,external,777)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:1] NoOp("Local/[email protected];2", "Starting recording check against yes") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:2] Goto("Local/[email protected];2", "yes") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Goto (sub-record-check,recordcheck,9)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:9] ExecIf("Local/[email protected];2", "0?Return()") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:10] Set("Local/[email protected];2", "__REC_POLICY_MODE=YES") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:11] Goto("Local/[email protected];2", "startrec") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Goto (sub-record-check,recordcheck,16)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:16] NoOp("Local/[email protected];2", "Starting recording: external, 777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:17] Set("Local/[email protected];2", "AUDIOHOOK_INHERIT(MixMonitor)=yes") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:18] Set("Local/[email protected];2", "__CALLFILENAME=external-777-88888888888-20150626-210130-1435341690.114") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:19] MixMonitor("Local/[email protected];2", "2015/06/26/external-777-88888888888-20150626-210130-1435341690.114.wav,ai(LOCAL_MIXMON_ID),") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:20] Set("Local/[email protected];2", "__MIXMON_ID=0x7fb798015930") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:21] Set("Local/[email protected];2", "__RECORD_ID=Local/[email protected];2") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:22] Set("Local/[email protected];2", "__REC_STATUS=RECORDING") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:23] Set("Local/[email protected];2", "CDR(recordingfile)=external-777-88888888888-20150626-210130-1435341690.114.wav") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:24] Return("Local/[email protected];2", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:12] Return("Local/[email protected];2", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:19] Set("Local/[email protected];2", "RingGroupMethod=ringallv2-prim") in new stack
[2015-06-26 21:01:30] VERBOSE[4291][C-00000003] app_mixmonitor.c: Begin MixMonitor Recording Local/[email protected];2
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:20] Set("Local/[email protected];2", "_FMGRP=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:21] GotoIf("Local/[email protected];2", "1?doconfirm") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Goto (from-internal,777,24)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:24] Macro("Local/[email protected];2", "dial-confirm,35,TtrM(auto-blkvm)I,777-555555555555-444444444444,777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:1] Set("Local/[email protected];2", "DB(RG/777/Local/[email protected];2)=RINGING") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:2] Set("Local/[email protected];2", "__UNIQCHAN=Local/[email protected];2") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:3] Set("Local/[email protected];2", "USE_CONFIRMATION=TRUE") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:4] Set("Local/[email protected];2", "RINGGROUP_INDEX=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:5] Set("Local/[email protected];2", "FORCE_CONFIRM=") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]nfirm:6] Set("Local/[email protected];2", "ARG4=") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:7] Macro("Local/[email protected];2", "dial,35,TtrM(auto-blkvm)I,777-555555555555-444444444444") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:1] GotoIf("Local/[email protected];2", "0?dial") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:2] Set("Local/[email protected];2", "CHANNEL(musicclass)=default") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:3] AGI("Local/[email protected];2", "dialparties.agi") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Caller ID name is '88888888888' number is '88888888888'
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Methodology of ring is 'ringallv2-prim'
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Added extension 777 to extension map
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Added extension 555555555555 to extension map
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Added extension 444444444444 to extension map
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Extension 777 cf is disabled
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Extension 555555555555 cf is disabled
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Extension 444444444444 cf is disabled
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Extension 777 do not disturb is disabled
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Extension 555555555555 do not disturb is disabled
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Extension 444444444444 do not disturb is disabled
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: EXTENSION_STATE: 1 (INUSE)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Extension 777 has ExtensionState: 1
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: EXTENSION_STATE: 1 (INUSE)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Extension 777 has ExtensionState: 1
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 777
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Extension 777 is not available to be called
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Extension 777 has call waiting disabled
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: dialparties.agi: Filtered ARG3:
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] res_agi.c: <Local/[email protected];2>AGI Script dialparties.agi completed, returning 0
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:4] NoOp("Local/[email protected];2", "Returned from dialparties with no extensions to call and DIALSTATUS: BUSY") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:8] NoOp("Local/[email protected];2", "Deleting: RG/777/Local/[email protected];2 RINGING") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:9] Set("Local/[email protected];2", "USE_CONFIRMATION=") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:10] Set("Local/[email protected];2", "RINGGROUP_INDEX=") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:25] Set("Local/[email protected];2", "RingGroupMethod=") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:26] GotoIf("Local/[email protected];2", "1?nodest") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Goto (from-internal,777,32)
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:32] NoOp("Local/[email protected];2", "SKIPPING DEST, CALL CAME FROM Q/RG: 9901") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Auto fallthrough, channel 'Local/[email protected];2' status is 'BUSY'
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] app_queue.c: Local/[email protected];1 is busy
[2015-06-26 21:01:30] WARNING[4289][C-00000003] translate.c: no samples for alawtolin
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] app_queue.c: Nobody picked up in 0 ms
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] app_queue.c: -- LazyMembers debugging - Numbusies: 0, Nummems: 0
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [[email protected]:1] Hangup("Local/[email protected];2", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on 'Local/[email protected];2'
[2015-06-26 21:01:30] VERBOSE[4291][C-00000003] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2015-06-26 21:01:30] VERBOSE[4291][C-00000003] app_mixmonitor.c: End MixMonitor Recording Local/[email protected];2
[2015-06-26 21:01:33] WARNING[2972] chan_sip.c: Retransmission timeout reached on transmission [email protected]_8568 for seqno 23098 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6400ms with no response
[2015-06-26 21:01:33] WARNING[2972] chan_sip.c: Hanging up call [email protected]_8568 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
[2015-06-26 21:01:33] VERBOSE[4285][C-00000003] res_musiconhold.c: Stopped music on hold on SIP/online_sip-00000003
[2015-06-26 21:01:33] VERBOSE[4285][C-00000003] pbx.c: Spawn extension (ext-queues, 9901, 41) exited non-zero on 'SIP/online_sip-00000003'
[2015-06-26 21:01:33] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] Macro("SIP/online_sip-00000003", "hangupcall,") in new stack
[2015-06-26 21:01:33] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:1] GotoIf("SIP/online_sip-00000003", "1?theend") in new stack
[2015-06-26 21:01:33] VERBOSE[4285][C-00000003] pbx.c: Goto (macro-hangupcall,s,3)
[2015-06-26 21:01:33] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:3] ExecIf("SIP/online_sip-00000003", "0?Set(CDR(recordingfile)=)") in new stack
[2015-06-26 21:01:33] VERBOSE[4285][C-00000003] pbx.c: Executing [[email protected]:4] Hangup("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:33] VERBOSE[4285][C-00000003] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/online_sip-00000003' in macro 'hangupcall'
[2015-06-26 21:01:33] VERBOSE[4285][C-00000003] pbx.c: Spawn extension (ext-queues, h, 1) exited non-zero on 'SIP/online_sip-00000003'
[2015-06-26 21:01:38] VERBOSE[2972][C-00000004] netsock2.c: Using SIP RTP TOS bits 184
[2015-06-26 21:01:38] VERBOSE[2972][C-00000004] netsock2.c: Using SIP RTP CoS mark 5
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] NoOp("SIP/online_sip-00000004", "Catch-All DID Match - Found 20002272222222222 - You probably want a DID for this.") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Log("SIP/online_sip-00000004", "WARNING,Friendly Scanner from 77.37.128.18") in new stack
[2015-06-26 21:01:38] WARNING[4296][C-00000004] Ext. 20002272222222222: Friendly Scanner from 77.37.128.18
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] Set("SIP/online_sip-00000004", "__FROM_DID=20002272222222222") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:4] Goto("SIP/online_sip-00000004", "ext-did,s,1") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Goto (ext-did,s,1)
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] ExecIf("SIP/online_sip-00000004", "0?Set(__FROM_DID=s)") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Gosub("SIP/online_sip-00000004", "sub-record-check,s,1(in,s,dontcare)") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] GotoIf("SIP/online_sip-00000004", "0?initialized") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000004", "__REC_STATUS=INITIALIZED") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] Set("SIP/online_sip-00000004", "NOW=1435341698") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:4] Set("SIP/online_sip-00000004", "__DAY=26") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:5] Set("SIP/online_sip-00000004", "__MONTH=06") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:6] Set("SIP/online_sip-00000004", "__YEAR=2015") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:7] Set("SIP/online_sip-00000004", "__TIMESTR=20150626-210138") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:8] Set("SIP/online_sip-00000004", "__FROMEXTEN=unknown") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:9] Set("SIP/online_sip-00000004", "__MON_FMT=wav") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:10] NoOp("SIP/online_sip-00000004", "Recordings initialized") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:11] ExecIf("SIP/online_sip-00000004", "0?Set(ARG3=dontcare)") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:12] Set("SIP/online_sip-00000004", "REC_POLICY_MODE_SAVE=") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:13] ExecIf("SIP/online_sip-00000004", "0?Set(REC_STATUS=NO)") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:14] GotoIf("SIP/online_sip-00000004", "2?checkaction") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Goto (sub-record-check,s,17)
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:17] GotoIf("SIP/online_sip-00000004", "1?sub-record-check,in,1") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Goto (sub-record-check,in,1)
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] NoOp("SIP/online_sip-00000004", "Inbound Recording Check to s") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000004", "FROMEXTEN=unknown") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] ExecIf("SIP/online_sip-00000004", "11?Set(FROMEXTEN=88888888888)") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:4] Gosub("SIP/online_sip-00000004", "recordcheck,1(dontcare,in,s)") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] NoOp("SIP/online_sip-00000004", "Starting recording check against dontcare") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Goto("SIP/online_sip-00000004", "dontcare") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Goto (sub-record-check,recordcheck,3)
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] Return("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:5] Return("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] Gosub("SIP/online_sip-00000004", "cidlookup,cidlookup_2,1()") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] Set("SIP/online_sip-00000004", "CURLOPT(httptimeout)=7") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000004", "CALLERID(name)=") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] Return("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:4] Gosub("SIP/online_sip-00000004", "app-blacklist-check,s,1()") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] GotoIf("SIP/online_sip-00000004", "0?blacklisted") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000004", "CALLED_BLACKLIST=1") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] Return("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:5] Set("SIP/online_sip-00000004", "CDR(did)=20002272222222222") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:6] ExecIf("SIP/online_sip-00000004", "1 ?Set(CALLERID(name)=88888888888)") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:7] Set("SIP/online_sip-00000004", "CHANNEL(musicclass)=default") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:8] Set("SIP/online_sip-00000004", "__MOHCLASS=default") in new stack
[2015-06-26 21:01:38] WARNING[4296][C-00000004] func_channel.c: Unknown or unavailable item requested: 'reversecharge'
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:9] GotoIf("SIP/online_sip-00000004", "0?macro-hangupcall") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:10] Macro("SIP/online_sip-00000004", "privacy-mgr,3,10") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] Set("SIP/online_sip-00000004", "KEEPCID=88888888888") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000004", "TESTCID=89266734399.000000") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] ExecIf("SIP/online_sip-00000004", "0?Set(CALLERID(num)=)") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:4] PrivacyManager("SIP/online_sip-00000004", "3,10") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] app_privacy.c: CallerID number present: Skipping
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:5] GotoIf("SIP/online_sip-00000004", "0?fail") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:6] GosubIf("SIP/online_sip-00000004", "1?app-blacklist-check,s,1()") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] GotoIf("SIP/online_sip-00000004", "0?blacklisted") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000004", "CALLED_BLACKLIST=1") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] Return("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:7] Set("SIP/online_sip-00000004", "CALLERID(num-pres)=allowed_passed_screen") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:8] MacroExit("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:11] Goto("SIP/online_sip-00000004", "ivr-2,s,1") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Goto (ivr-2,s,1)
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] Set("SIP/online_sip-00000004", "_IVR_CONTEXT_ivr-2=") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000004", "_IVR_CONTEXT=ivr-2") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] Set("SIP/online_sip-00000004", "__IVR_RETVM=") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:4] GotoIf("SIP/online_sip-00000004", "0?skip") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:5] Answer("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:39] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:6] Wait("SIP/online_sip-00000004", "1") in new stack
[2015-06-26 21:01:40] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:7] Set("SIP/online_sip-00000004", "IVR_MSG=") in new stack
[2015-06-26 21:01:40] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:8] Set("SIP/online_sip-00000004", "TIMEOUT(digit)=3") in new stack
    [2015-06-26 21:01:40] VERBOSE[4296][C-00000004] func_timeout.c: Digit timeout set to 3.000
    [2015-06-26 21:01:40] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:9] ExecIf("SIP/online_sip-00000004", "0?Background()") in new stack
    [2015-06-26 21:01:40] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:10] WaitExten("SIP/online_sip-00000004", "2,") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Timeout on SIP/online_sip-00000004, going to 't'
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] Goto("SIP/online_sip-00000004", "ext-queues,9901,1") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Goto (ext-queues,9901,1)
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] Macro("SIP/online_sip-00000004", "user-callerid,") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] Set("SIP/online_sip-00000004", "TOUCH_MONITOR=1435341698.127") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000004", "AMPUSER=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] GotoIf("SIP/online_sip-00000004", "0?report") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:4] ExecIf("SIP/online_sip-00000004", "1?Set(REALCALLERIDNUM=88888888888)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:5] Set("SIP/online_sip-00000004", "AMPUSER=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:6] GotoIf("SIP/online_sip-00000004", "0?limit") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:7] Set("SIP/online_sip-00000004", "AMPUSERCIDNAME=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:8] GotoIf("SIP/online_sip-00000004", "1?report") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Goto (macro-user-callerid,s,16)
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:16] GotoIf("SIP/online_sip-00000004", "0?continue") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:17] ExecIf("SIP/online_sip-00000004", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:18] Set("SIP/online_sip-00000004", "__TTL=64") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:19] GotoIf("SIP/online_sip-00000004", "1?continue") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Goto (macro-user-callerid,s,30)
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:30] Set("SIP/online_sip-00000004", "CALLERID(number)=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:31] Set("SIP/online_sip-00000004", "CALLERID(name)=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:32] Set("SIP/online_sip-00000004", "CDR(cnum)=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:33] Set("SIP/online_sip-00000004", "CDR(cnam)=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:34] Set("SIP/online_sip-00000004", "CHANNEL(language)=en") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Answer("SIP/online_sip-00000004", "") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] ExecIf("SIP/online_sip-00000004", "1?Set(__QUEUEWAIT=1435341702)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:4] Macro("SIP/online_sip-00000004", "blkvm-set,reset") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] ExecIf("SIP/online_sip-00000004", "1?Set(__BLKVM_CHANNEL=SIP/online_sip-00000004)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Set("SIP/online_sip-00000004", "SHARED(BLKVM,SIP/online_sip-00000004)=TRUE") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] Set("SIP/online_sip-00000004", "GOSUB_RETVAL=TRUE") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:4] MacroExit("SIP/online_sip-00000004", "") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:5] ExecIf("SIP/online_sip-00000004", "1?Set(_DIAL_OPTIONS=TtrM(auto-blkvm))") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:6] Set("SIP/online_sip-00000004", "__NODEST=9901") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:7] Set("SIP/online_sip-00000004", "QCIDPP=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:8] Set("SIP/online_sip-00000004", "VQ_CIDPP=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:9] ExecIf("SIP/online_sip-00000004", "0?Macro(prepend-cid,)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:10] Set("SIP/online_sip-00000004", "QAINFO=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:11] Set("SIP/online_sip-00000004", "VQ_AINFO=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:12] ExecIf("SIP/online_sip-00000004", "0?Set(__ALERT_INFO=)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:13] Set("SIP/online_sip-00000004", "QJOINMSG=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:14] Set("SIP/online_sip-00000004", "VQ_JOINMSG=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:15] Set("SIP/online_sip-00000004", "QRETRY=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:16] Set("SIP/online_sip-00000004", "VQ_RETRY=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:17] Set("SIP/online_sip-00000004", "QOPTIONS=t") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:18] Set("SIP/online_sip-00000004", "VQ_OPTIONS=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:19] Set("SIP/online_sip-00000004", "QGOSUB=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:20] Set("SIP/online_sip-00000004", "VQ_GOSUB=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:21] Set("SIP/online_sip-00000004", "QAGI=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:22] Set("SIP/online_sip-00000004", "VQ_AGI=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:23] Set("SIP/online_sip-00000004", "QRULE=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:24] Set("SIP/online_sip-00000004", "VQ_RULE=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:25] Set("SIP/online_sip-00000004", "QPOSITION=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:26] Set("SIP/online_sip-00000004", "VQ_POSITION=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:27] Gosub("SIP/online_sip-00000004", "sub-record-check,s,1(q,9901,dontcare)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] GotoIf("SIP/online_sip-00000004", "11?initialized") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Goto (sub-record-check,s,10)
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:10] NoOp("SIP/online_sip-00000004", "Recordings initialized") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:11] ExecIf("SIP/online_sip-00000004", "0?Set(ARG3=dontcare)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:12] Set("SIP/online_sip-00000004", "REC_POLICY_MODE_SAVE=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:13] ExecIf("SIP/online_sip-00000004", "0?Set(REC_STATUS=NO)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:14] GotoIf("SIP/online_sip-00000004", "1?checkaction") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Goto (sub-record-check,s,17)
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:17] GotoIf("SIP/online_sip-00000004", "0?sub-record-check,q,1") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:18] NoOp("SIP/online_sip-00000004", "Generic q Recording Check - 88888888888 9901") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:19] Gosub("SIP/online_sip-00000004", "recordcheck,1(dontcare,q,9901)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] NoOp("SIP/online_sip-00000004", "Starting recording check against dontcare") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:2] Goto("SIP/online_sip-00000004", "dontcare") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Goto (sub-record-check,recordcheck,3)
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] Return("SIP/online_sip-00000004", "") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:20] Return("SIP/online_sip-00000004", "") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:28] Set("SIP/online_sip-00000004", "__CWIGNORE=TRUE") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:29] ExecIf("SIP/online_sip-00000004", "0?Playback(, )") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:30] QueueLog("SIP/online_sip-00000004", "9901,1435341698.127,NONE,DID,20002272222222222") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:31] Set("SIP/online_sip-00000004", "QAANNOUNCE=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:32] Set("SIP/online_sip-00000004", "VQ_AANNOUNCE=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:33] Set("SIP/online_sip-00000004", "QMOH=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:34] Set("SIP/online_sip-00000004", "VQ_MOH=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:35] ExecIf("SIP/online_sip-00000004", "0?Set(__MOHCLASS=)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:36] ExecIf("SIP/online_sip-00000004", "1?Set(CHANNEL(musicclass)=default)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:37] Set("SIP/online_sip-00000004", "QMAXWAIT=260") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:38] Set("SIP/online_sip-00000004", "VQ_MAXWAIT=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9[email protected]:39] Set("SIP/online_sip-00000004", "QUEUENUM=9901") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:40] Set("SIP/online_sip-00000004", "QUEUEJOINTIME=1435341702") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:41] Queue("SIP/online_sip-00000004", "9901,t,,,260,,,,,") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/online_sip-00000004'
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] app_queue.c: Called Local/[email protected]/n
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] app_queue.c: -- LazyMembers debugging - Numbusies: 0, Nummems: 0
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:1] Set("Local/[email protected];2", "QAGENT=777") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:2] Goto("Local/[email protected];2", "9901,1") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Goto (from-queue,9901,1)
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:1] Goto("Local/[email protected];2", "from-internal,777,1") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Goto (from-internal,777,1)
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:1] GotoIf("Local/[email protected];2", "0?ext-local,777,1") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:2] Macro("Local/[email protected];2", "user-callerid,") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:1] Set("Local/[email protected];2", "TOUCH_MONITOR=1435341702.133") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:2] Set("Local/[email protected];2", "AMPUSER=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:3] GotoIf("Local/[email protected];2", "1?report") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Goto (macro-user-callerid,s,16)
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:16] GotoIf("Local/[email protected];2", "0?continue") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:17] ExecIf("Local/[email protected];2", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:18] Set("Local/[email protected];2", "__TTL=63") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:19] GotoIf("Local/[email protected];2", "1?continue") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Goto (macro-user-callerid,s,30)
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:30] Set("Local/[email protected];2", "CALLERID(number)=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:31] Set("Local/[email protected];2", "CALLERID(name)=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:32] Set("Local/[email protected];2", "CDR(cnum)=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:33] Set("Local/[email protected];2", "CDR(cnam)=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:34] Set("Local/[email protected];2", "CHANNEL(language)=en") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:3] Set("Local/[email protected];2", "DIAL_OPTIONS=TtrM(auto-blkvm)I") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:4] Set("Local/[email protected];2", "CONNECTEDLINE(num,i)=777") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:5] Gosub("Local/[email protected];2", "sub-presencestate-display,s,1(777)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:1] Goto("Local/[email protected];2", "state-unavailable,1") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Goto (sub-presencestate-display,state-unavailable,1)
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:1] Set("Local/[email protected];2", "PRESENCESTATE_DISPLAY=(Unavailable)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:2] Return("Local/[email protected];2", "") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:6] Set("Local/[email protected];2", "CONNECTEDLINE(name)=Dmitriy Stepanov(Unavailable)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:7]
Set("Local/[email protected];2", "FM_DIALSTATUS=INUSE") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:8] Set("Local/[email protected];2", "__EXTTOCALL=777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:9] Set("Local/[email protected];2", "__PICKUPMARK=777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:10] Macro("Local/[email protected];2", "blkvm-setifempty,") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:1] GotoIf("Local/[email protected];2", "0?init") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:2] Set("Local/[email protected];2", "GOSUB_RETVAL=TRUE") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:3] MacroExit("Local/[email protected];2", "") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:11] GotoIf("Local/[email protected];2", "1?skipov") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Goto (from-internal,777,14)
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:14] Set("Local/[email protected];2", "RRNODEST=9901") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:15] Set("Local/[email protected];2", "__NODEST=777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:16] GosubIf("Local/[email protected];2", "0?sub-fmsetcid,s,1()") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:17] Set("Local/[email protected];2", "RecordMethod=Group") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:18] Gosub("Local/[email protected];2", "sub-record-check,s,1(exten,777,)") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:1] GotoIf("Local/[email protected];2", "0?initialized") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:2] Set("Local/[email protected];2", "__REC_STATUS=INITIALIZED") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:3] Set("Local/[email protected];2", "NOW=1435341702") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:4] Set("Local/[email protected];2", "__DAY=26") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:5] Set("Local/[email protected];2", "__MONTH=06") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:6] Set("Local/[email protected];2", "__YEAR=2015") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:7] Set("Local/[email protected];2", "__TIMESTR=20150626-210142") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:8] Set("Local/[email protected];2", "__FROMEXTEN=88888888888") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:9] Set("Local/[email protected];2", "__MON_FMT=wav") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:10] NoOp("Local/[email protected];2", "Recordings initialized") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:11] ExecIf("Local/[email protected];2", "1?Set(ARG3=dontcare)") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:12] Set("Local/[email protected];2", "REC_POLICY_MODE_SAVE=") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:13] ExecIf("Local/[email protected];2", "0?Set(REC_STATUS=NO)") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:14] GotoIf("Local/[email protected];2", "5?checkaction") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Goto (sub-record-check,s,17)
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:17] GotoIf("Local/[email protected];2", "1?sub-record-check,exten,1") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Goto (sub-record-check,exten,1)
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:1] NoOp("Local/[email protected];2", "Exten Recording Check between 88888888888 and 777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:2] Set("Local/[email protected];2", "CALLTYPE=external") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?Set(CALLTYPE=)") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:4] Set("Local/[email protected];2", "CALLEE=yes") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:5] ExecIf("Local/[email protected];2", "0?Set(CALLEE=dontcare)") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:6] GotoIf("Local/[email protected];2", "1?callee") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Goto (sub-record-check,exten,11)
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:11] Gosub("Local/[email protected];2", "recordcheck,1(yes,external,777)") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:1] NoOp("Local/[email protected];2", "Starting recording check against yes") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:2] Goto("Local/[email protected];2", "yes") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Goto (sub-record-check,recordcheck,9)
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:9] ExecIf("Local/[email protected];2", "0?Return()") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:10] Set("Local/[email protected];2", "__REC_POLICY_MODE=YES") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:11] Goto("Local/[email protected];2", "startrec") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Goto (sub-record-check,recordcheck,16)
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:16] NoOp("Local/[email protected];2", "Starting recording: external, 777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:17] Set("Local/[email protected];2", "AUDIOHOOK_INHERIT(MixMonitor)=yes") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:18] Set("Local/[email protected];2", "__CALLFILENAME=external-777-88888888888-20150626-210142-1435341702.133") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:19] MixMonitor("Local/[email protected];2", "2015/06/26/external-777-88888888888-20150626-210142-1435341702.133.wav,ai(LOCAL_MIXMON_ID),") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:20] Set("Local/[email protected];2", "__MIXMON_ID=0x7fb75c6e8fd0") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:21] Set("Local/[email protected];2", "__RECORD_ID=Local/[email protected];2") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:22] Set("Local/[email protected];2", "__REC_STATUS=RECORDING") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:23] Set("Local/[email protected];2", "CDR(recordingfile)=external-777-88888888888-20150626-210142-1435341702.133.wav") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:24] Return("Local/[email protected];2", "") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:12] Return("Local/[email protected];2", "") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:19] Set("Local/[email protected];2", "RingGroupMethod=ringallv2-prim") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:20] Set("Local/[email protected];2", "_FMGRP=777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:21] GotoIf("Local/[email protected];2", "1?doconfirm") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Goto (from-internal,777,24)
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:24] Macro("Local/[email protected];2", "dial-confirm,35,TtrM(auto-blkvm)I,777-555555555555-444444444444,777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:1] Set("Local/[email protected];2", "DB(RG/777/Local/[email protected];2)=RINGING") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:2] Set("Local/[email protected];2", "__UNIQCHAN=Local/[email protected];2") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:3] Set("Local/[email protected];2", "USE_CONFIRMATION=TRUE") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:4] Set("Local/[email protected];2", "RINGGROUP_INDEX=777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:5] Set("Local/[email protected];2", "FORCE_CONFIRM=") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:6] Set("Local/[email protected];2", "ARG4=") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:7] Macro("Local/[email protected];2", "dial,35,TtrM(auto-blkvm)I,777-555555555555-444444444444") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:1] GotoIf("Local/[email protected];2", "0?dial") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:2] Set("Local/[email protected];2", "CHANNEL(musicclass)=default") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:3] AGI("Local/[email protected];2", "dialparties.agi") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2015-06-26 21:01:42] VERBOSE[4298][C-00000004] app_mixmonitor.c: Begin MixMonitor Recording Local/[email protected];2
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Caller ID name is '88888888888' number is '88888888888'
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Methodology of ring is 'ringallv2-prim'
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Added extension 777 to extension map
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Added extension 555555555555 to extension map
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Added extension 444444444444 to extension map
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Extension 777 cf is disabled
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Extension 555555555555 cf is disabled
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Extension 444444444444 cf is disabled
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Extension 777 do not disturb is disabled
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Extension 555555555555 do not disturb is disabled
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Extension 444444444444 do not disturb is disabled
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: EXTENSION_STATE: 1 (INUSE)
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Extension 777 has ExtensionState: 1
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: EXTENSION_STATE: 1 (INUSE)
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Extension 777 has ExtensionState: 1
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Checking CW and CFB status for extension 777
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Extension 777 is not available to be called
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Extension 777 has call waiting disabled
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: dialparties.agi: Filtered ARG3:
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] res_agi.c: <Local/[email protected];2>AGI Script dialparties.agi completed, returning 0
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:4] NoOp("Local/[email protected];2", "Returned from dialparties with no extensions to call and DIALSTATUS: BUSY") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:8] NoOp("Local/[email protected];2", "Deleting: RG/777/Local/[email protected];2 RINGING") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:9] Set("Local/[email protected];2", "USE_CONFIRMATION=") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:10] Set("Local/[email protected];2", "RINGGROUP_INDEX=") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:25] Set("Local/[email protected];2", "RingGroupMethod=") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:26] GotoIf("Local/[email protected];2", "1?nodest") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Goto (from-internal,777,32)
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:32] NoOp("Local/[email protected];2", "SKIPPING DEST, CALL CAME FROM Q/RG: 9901") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Auto fallthrough, channel 'Local/[email protected];2' status is 'BUSY'
[2015-06-26 21:01:42] WARNING[4297][C-00000004] translate.c: no samples for alawtolin
[2015-06-26 21:01:42] VERBOSE[4296][C-00000004] app_queue.c: Local/[email protected];1 is busy
[2015-06-26 21:01:42] VERBOSE[4296][C-00000004] app_queue.c: Nobody picked up in 0 ms
[2015-06-26 21:01:42] VERBOSE[4296][C-00000004] app_queue.c: -- LazyMembers debugging - Numbusies: 0, Nummems: 0
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [[email protected]:1] Hangup("Local/[email protected];2", "") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on 'Local/[email protected];2'
[2015-06-26 21:01:42] VERBOSE[4298][C-00000004] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2015-06-26 21:01:42] VERBOSE[4298][C-00000004] app_mixmonitor.c: End MixMonitor Recording Local/[email protected];2
[2015-06-26 21:01:45] WARNING[2972] chan_sip.c: Retransmission timeout reached on transmission [email protected]_8570 for seqno 23101 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6399ms with no response
[2015-06-26 21:01:45] WARNING[2972] chan_sip.c: Hanging up call [email protected]_8570 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
[2015-06-26 21:01:45] VERBOSE[4296][C-00000004] res_musiconhold.c: Stopped music on hold on SIP/online_sip-00000004
[2015-06-26 21:01:45] VERBOSE[4296][C-00000004] pbx.c: Spawn extension (ext-queues, 9901, 41) exited non-zero on 'SIP/online_sip-00000004'
[2015-06-26 21:01:45] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] Macro("SIP/online_sip-00000004", "hangupcall,") in new stack
[2015-06-26 21:01:45] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:1] GotoIf("SIP/online_sip-00000004", "1?theend") in new stack
[2015-06-26 21:01:45] VERBOSE[4296][C-00000004] pbx.c: Goto (macro-hangupcall,s,3)
[2015-06-26 21:01:45] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:3] ExecIf("SIP/online_sip-00000004", "0?Set(CDR(recordingfile)=)") in new stack
[2015-06-26 21:01:45] VERBOSE[4296][C-00000004] pbx.c: Executing [[email protected]:4] Hangup("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:45] VERBOSE[4296][C-00000004] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/online_sip-00000004' in macro 'hangupcall'
[2015-06-26 21:01:45] VERBOSE[4296][C-00000004] pbx.c: Spawn extension (ext-queues, h, 1) exited non-zero on 'SIP/online_sip-00000004'
[2015-06-26 21:02:09] VERBOSE[4238][C-00000002] bridge_channel.c: Channel PJSIP/777-00000002 left 'simple_bridge' basic-bridge <76d2a85a-7d1f-4a4f-a432-3756b2632681>
[2015-06-26 21:02:09] VERBOSE[4238][C-00000002] app_macro.c: Spawn extension (macro-dialout-trunk, s, 23) exited non-zero on 'PJSIP/777-00000002' in macro 'dialout-trunk'
[2015-06-26 21:02:09] VERBOSE[4238][C-00000002] pbx.c: Spawn extension (from-internal, 11111111111, 6) exited non-zero on 'PJSIP/777-00000002'
[2015-06-26 21:02:09] VERBOSE[4238][C-00000002] pbx.c: Executing [[email protected]:1] Hangup("PJSIP/777-00000002", "") in new stack
[2015-06-26 21:02:09] VERBOSE[4238][C-00000002] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on 'PJSIP/777-00000002'
[2015-06-26 21:02:09] VERBOSE[4247][C-00000002] bridge_channel.c: Channel SIP/online_sip-00000002 left 'simple_bridge' basic-bridge <76d2a85a-7d1f-4a4f-a432-3756b2632681>
[2015-06-26 21:02:09] VERBOSE[4244][C-00000002] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2015-06-26 21:02:09] VERBOSE[4244][C-00000002] app_mixmonitor.c: End MixMonitor Recording PJSIP/777-00000002