Disconnecting channel on incoming call issue

Dvbnhbq · June 26, 2015, 6:35pm

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.

Dvbnhbq · June 26, 2015, 6:38pm

[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [11111111111@from-internal: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 [s@macro-user-callerid: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 [s@macro-user-callerid:2] Set("PJSIP/777-00000002", "AMPUSER=777") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("PJSIP/777-00000002", "0?report") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:5] Set("PJSIP/777-00000002", "AMPUSER=777") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("PJSIP/777-00000002", "0?limit") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-user-callerid:7] Set("PJSIP/777-00000002", "AMPUSERCIDNAME=Dmitriy Stepanov") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-user-callerid:8] GotoIf("PJSIP/777-00000002", "0?report") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-user-callerid:9] Set("PJSIP/777-00000002", "AMPUSERCID=777") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-user-callerid:10] Set("PJSIP/777-00000002", "__DIAL_OPTIONS=Ttr") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:12] GotoIf("PJSIP/777-00000002", "0?limit") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@sub-ccss:1] ExecIf("PJSIP/777-00000002", "0?Return()") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-ccss:2] Set("PJSIP/777-00000002", "CCSS_SETUP=TRUE") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-ccss: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 [monitor_default@sub-ccss:1] GotoIf("PJSIP/777-00000002", "0?is_exten") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [monitor_default@sub-ccss: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 [monitor_default@sub-ccss: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 [monitor_default@sub-ccss:4] Return("PJSIP/777-00000002", "TRUE") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-ccss: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 [agent_config@sub-ccss: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 [agent_config@sub-ccss: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 [agent_config@sub-ccss: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 [agent_config@sub-ccss: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 [agent_config@sub-ccss: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 [agent_config@sub-ccss: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 [agent_config@sub-ccss: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 [agent_config@sub-ccss:8] ExecIf("PJSIP/777-00000002", "0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/777_@from-ccss-)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [agent_config@sub-ccss: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 [agent_config@sub-ccss:10] Return("PJSIP/777-00000002", "") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-ccss: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 [s@sub-ccss:6] Return("PJSIP/777-00000002", "") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid:30] Set("PJSIP/777-00000002", "CALLERID(number)=777") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:32] Set("PJSIP/777-00000002", "CDR(cnum)=777") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:34] Set("PJSIP/777-00000002", "CHANNEL(language)=en") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [11111111111@from-internal: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 [s@sub-record-check:1] GotoIf("PJSIP/777-00000002", "0?initialized") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-record-check:2] Set("PJSIP/777-00000002", "__REC_STATUS=INITIALIZED") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-record-check:3] Set("PJSIP/777-00000002", "NOW=1435341626") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-record-check:4] Set("PJSIP/777-00000002", "__DAY=26") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-record-check:5] Set("PJSIP/777-00000002", "__MONTH=06") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-record-check:6] Set("PJSIP/777-00000002", "__YEAR=2015") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-record-check:7] Set("PJSIP/777-00000002", "__TIMESTR=20150626-210026") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-record-check:8] Set("PJSIP/777-00000002", "__FROMEXTEN=777") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-record-check:9] Set("PJSIP/777-00000002", "__MON_FMT=wav") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-record-check:10] NoOp("PJSIP/777-00000002", "Recordings initialized") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [out@sub-record-check: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 [out@sub-record-check:2] Set("PJSIP/777-00000002", "RECMODE=yes") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [out@sub-record-check:3] ExecIf("PJSIP/777-00000002", "0?Goto(routewins)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [out@sub-record-check:4] ExecIf("PJSIP/777-00000002", "0?Goto(routewins)") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [out@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check:9] ExecIf("PJSIP/777-00000002", "0?Return()") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check:20] Set("PJSIP/777-00000002", "__MIXMON_ID=0x7fb75c7046d0") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [recordcheck@sub-record-check: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 [recordcheck@sub-record-check:22] Set("PJSIP/777-00000002", "__REC_STATUS=RECORDING") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [recordcheck@sub-record-check: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 [recordcheck@sub-record-check:24] Return("PJSIP/777-00000002", "") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [out@sub-record-check:6] Return("PJSIP/777-00000002", "") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [11111111111@from-internal: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 [11111111111@from-internal:4] Set("PJSIP/777-00000002", "MOHCLASS=default") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [11111111111@from-internal:5] Set("PJSIP/777-00000002", "_NODEST=") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [11111111111@from-internal: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 [s@macro-dialout-trunk:1] Set("PJSIP/777-00000002", "DIAL_TRUNK=1") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-dialout-trunk: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 [s@macro-dialout-trunk:3] GotoIf("PJSIP/777-00000002", "0?disabletrunk,1") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:4] Set("PJSIP/777-00000002", "DIAL_NUMBER=11111111111") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-dialout-trunk: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 [s@macro-dialout-trunk: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 [s@macro-dialout-trunk:7] GotoIf("PJSIP/777-00000002", "0?nomax") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:8] GotoIf("PJSIP/777-00000002", "0?chanfull") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:9] GotoIf("PJSIP/777-00000002", "0?skipoutcid") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-dialout-trunk: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 [s@macro-dialout-trunk:11] Macro("PJSIP/777-00000002", "outbound-callerid,1") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-outbound-callerid: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 [s@macro-outbound-callerid: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 [s@macro-outbound-callerid: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 [s@macro-outbound-callerid: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 [s@macro-outbound-callerid:7] Set("PJSIP/777-00000002", "USEROUTCID=") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-outbound-callerid:8] Set("PJSIP/777-00000002", "EMERGENCYCID=") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-outbound-callerid:9] Set("PJSIP/777-00000002", "TRUNKOUTCID=74996086824") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-outbound-callerid: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 [s@macro-outbound-callerid: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 [s@macro-outbound-callerid: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 [s@macro-outbound-callerid: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 [s@macro-outbound-callerid: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 [s@macro-outbound-callerid: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 [s@macro-outbound-callerid: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 [s@macro-outbound-callerid: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 [s@macro-dialout-trunk: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 [s@macro-dialout-trunk:13] Set("PJSIP/777-00000002", "OUTNUM=11111111111") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-dialout-trunk: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 [s@macro-dialout-trunk: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 [s@macro-dialout-trunk: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 [s@macro-dialout-trunk: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 [s@macro-dialout-trunk-predial-hook:1] MacroExit("PJSIP/777-00000002", "") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:18] GotoIf("PJSIP/777-00000002", "0?bypass,1") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-dialout-trunk: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 [s@macro-dialout-trunk: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 [s@macro-dialout-trunk: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 [s@macro-dialout-trunk:22] GotoIf("PJSIP/777-00000002", "0?customtrunk") in new stack
[2015-06-26 21:00:26] VERBOSE[4238][C-00000002] pbx.c: Executing [s@macro-dialout-trunk: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>

Dvbnhbq · June 26, 2015, 6:38pm

[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 [20002272222222222@from-trunk: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 [20002272222222222@from-trunk: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 [20002272222222222@from-trunk: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 [20002272222222222@from-trunk: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 [s@ext-did: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 [s@ext-did: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 [s@sub-record-check:1] GotoIf("SIP/online_sip-00000003", "0?initialized") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check:3] Set("SIP/online_sip-00000003", "NOW=1435341686") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@sub-record-check:4] Set("SIP/online_sip-00000003", "__DAY=26") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@sub-record-check:5] Set("SIP/online_sip-00000003", "__MONTH=06") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@sub-record-check:6] Set("SIP/online_sip-00000003", "__YEAR=2015") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check:8] Set("SIP/online_sip-00000003", "__FROMEXTEN=unknown") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check:10] NoOp("SIP/online_sip-00000003", "Recordings initialized") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [in@sub-record-check: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 [in@sub-record-check:2] Set("SIP/online_sip-00000003", "FROMEXTEN=unknown") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [in@sub-record-check: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 [in@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check:3] Return("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [in@sub-record-check:5] Return("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@ext-did: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 [cidlookup_2@cidlookup: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 [cidlookup_2@cidlookup:2] Set("SIP/online_sip-00000003", "CALLERID(name)=") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [cidlookup_2@cidlookup:3] Return("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@ext-did: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 [s@app-blacklist-check:1] GotoIf("SIP/online_sip-00000003", "0?blacklisted") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@app-blacklist-check: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 [s@app-blacklist-check:3] Return("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@ext-did: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 [s@ext-did: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 [s@ext-did: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 [s@ext-did: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 [s@ext-did: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 [s@ext-did: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 [s@macro-privacy-mgr:1] Set("SIP/online_sip-00000003", "KEEPCID=88888888888") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@macro-privacy-mgr: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 [s@macro-privacy-mgr: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 [s@macro-privacy-mgr: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 [s@macro-privacy-mgr:5] GotoIf("SIP/online_sip-00000003", "0?fail") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@macro-privacy-mgr: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 [s@app-blacklist-check:1] GotoIf("SIP/online_sip-00000003", "0?blacklisted") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@app-blacklist-check: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 [s@app-blacklist-check:3] Return("SIP/online_sip-00000003", "") in new stack

Dvbnhbq · June 26, 2015, 6:39pm

[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@macro-privacy-mgr: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 [s@macro-privacy-mgr:8] MacroExit("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@ext-did: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 [s@ivr-2: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 [s@ivr-2: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 [s@ivr-2:3] Set("SIP/online_sip-00000003", "__IVR_RETVM=") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@ivr-2:4] GotoIf("SIP/online_sip-00000003", "0?skip") in new stack
[2015-06-26 21:01:26] VERBOSE[4285][C-00000003] pbx.c: Executing [s@ivr-2:5] Answer("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:27] VERBOSE[4285][C-00000003] pbx.c: Executing [s@ivr-2:6] Wait("SIP/online_sip-00000003", "1") in new stack
[2015-06-26 21:01:28] VERBOSE[4285][C-00000003] pbx.c: Executing [s@ivr-2:7] Set("SIP/online_sip-00000003", "IVR_MSG=") in new stack
[2015-06-26 21:01:28] VERBOSE[4285][C-00000003] pbx.c: Executing [s@ivr-2: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 [s@ivr-2:9] ExecIf("SIP/online_sip-00000003", "0?Background()") in new stack
[2015-06-26 21:01:28] VERBOSE[4285][C-00000003] pbx.c: Executing [s@ivr-2: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 [t@ivr-2: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 [9901@ext-queues:1] Macro("SIP/online_sip-00000003", "user-callerid,") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:2] Set("SIP/online_sip-00000003", "AMPUSER=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("SIP/online_sip-00000003", "0?report") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:5] Set("SIP/online_sip-00000003", "AMPUSER=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("SIP/online_sip-00000003", "0?limit") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [s@macro-user-callerid:7] Set("SIP/online_sip-00000003", "AMPUSERCIDNAME=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:16] GotoIf("SIP/online_sip-00000003", "0?continue") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:18] Set("SIP/online_sip-00000003", "__TTL=64") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [9901@ext-queues:2] Answer("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues: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 [9901@ext-queues: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 [s@macro-blkvm-set: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 [s@macro-blkvm-set: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 [s@macro-blkvm-set: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 [s@macro-blkvm-set:4] MacroExit("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues: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 [9901@ext-queues:6] Set("SIP/online_sip-00000003", "__NODEST=9901") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:7] Set("SIP/online_sip-00000003", "QCIDPP=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:8] Set("SIP/online_sip-00000003", "VQ_CIDPP=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues: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 [9901@ext-queues:10] Set("SIP/online_sip-00000003", "QAINFO=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:11] Set("SIP/online_sip-00000003", "VQ_AINFO=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues: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 [9901@ext-queues:13] Set("SIP/online_sip-00000003", "QJOINMSG=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:14] Set("SIP/online_sip-00000003", "VQ_JOINMSG=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:15] Set("SIP/online_sip-00000003", "QRETRY=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:16] Set("SIP/online_sip-00000003", "VQ_RETRY=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:17] Set("SIP/online_sip-00000003", "QOPTIONS=t") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:18] Set("SIP/online_sip-00000003", "VQ_OPTIONS=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:19] Set("SIP/online_sip-00000003", "QGOSUB=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:20] Set("SIP/online_sip-00000003", "VQ_GOSUB=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:21] Set("SIP/online_sip-00000003", "QAGI=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:22] Set("SIP/online_sip-00000003", "VQ_AGI=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:23] Set("SIP/online_sip-00000003", "QRULE=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:24] Set("SIP/online_sip-00000003", "VQ_RULE=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:25] Set("SIP/online_sip-00000003", "QPOSITION=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:26] Set("SIP/online_sip-00000003", "VQ_POSITION=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues: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 [s@sub-record-check: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 [s@sub-record-check:10] NoOp("SIP/online_sip-00000003", "Recordings initialized") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check:3] Return("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [s@sub-record-check:20] Return("SIP/online_sip-00000003", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:28] Set("SIP/online_sip-00000003", "__CWIGNORE=TRUE") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:29] ExecIf("SIP/online_sip-00000003", "0?Playback(, )") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues: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 [9901@ext-queues:31] Set("SIP/online_sip-00000003", "QAANNOUNCE=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:32] Set("SIP/online_sip-00000003", "VQ_AANNOUNCE=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:33] Set("SIP/online_sip-00000003", "QMOH=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:34] Set("SIP/online_sip-00000003", "VQ_MOH=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues: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 [9901@ext-queues: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 [9901@ext-queues:37] Set("SIP/online_sip-00000003", "QMAXWAIT=260") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:38] Set("SIP/online_sip-00000003", "VQ_MAXWAIT=") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:39] Set("SIP/online_sip-00000003", "QUEUENUM=9901") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues:40] Set("SIP/online_sip-00000003", "QUEUEJOINTIME=1435341690") in new stack
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] pbx.c: Executing [9901@ext-queues: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/777@from-queue/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 [777@from-queue:1] Set("Local/777@from-queue-00000008;2", "QAGENT=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-queue:2] Goto("Local/777@from-queue-00000008;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 [9901@from-queue:1] Goto("Local/777@from-queue-00000008;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 [777@from-internal:1] GotoIf("Local/777@from-queue-00000008;2", "0?ext-local,777,1") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:2] Macro("Local/777@from-queue-00000008;2", "user-callerid,") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-user-callerid:1] Set("Local/777@from-queue-00000008;2", "TOUCH_MONITOR=1435341690.114") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-user-callerid:2] Set("Local/777@from-queue-00000008;2", "AMPUSER=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("Local/777@from-queue-00000008;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 [s@macro-user-callerid:16] GotoIf("Local/777@from-queue-00000008;2", "0?continue") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-user-callerid:17] ExecIf("Local/777@from-queue-00000008;2", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-user-callerid:18] Set("Local/777@from-queue-00000008;2", "__TTL=63") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-user-callerid:19] GotoIf("Local/777@from-queue-00000008;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 [s@macro-user-callerid:30] Set("Local/777@from-queue-00000008;2", "CALLERID(number)=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-user-callerid:31] Set("Local/777@from-queue-00000008;2", "CALLERID(name)=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-user-callerid:32] Set("Local/777@from-queue-00000008;2", "CDR(cnum)=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-user-callerid:33] Set("Local/777@from-queue-00000008;2", "CDR(cnam)=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-user-callerid:34] Set("Local/777@from-queue-00000008;2", "CHANNEL(language)=en") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:3] Set("Local/777@from-queue-00000008;2", "DIAL_OPTIONS=TtrM(auto-blkvm)I") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:4] Set("Local/777@from-queue-00000008;2", "CONNECTEDLINE(num,i)=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:5] Gosub("Local/777@from-queue-00000008;2", "sub-presencestate-display,s,1(777)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-presencestate-display:1] Goto("Local/777@from-queue-00000008;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 [state-unavailable@sub-presencestate-display:1] Set("Local/777@from-queue-00000008;2", "PRESENCESTATE_DISPLAY=(Unavailable)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [state-unavailable@sub-presencestate-display:2] Return("Local/777@from-queue-00000008;2", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:6] Set("Local/777@from-queue-00000008;2", "CONNECTEDLINE(name)=Dmitriy Stepanov(Unavailable)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:7] Set("Local/777@from-queue-00000008;2", "FM_DIALSTATUS=INUSE") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:8] Set("Local/777@from-queue-00000008;2", "__EXTTOCALL=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:9] Set("Local/777@from-queue-00000008;2", "__PICKUPMARK=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:10] Macro("Local/777@from-queue-00000008;2", "blkvm-setifempty,") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-blkvm-setifempty:1] GotoIf("Local/777@from-queue-00000008;2", "0?init") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-blkvm-setifempty:2] Set("Local/777@from-queue-00000008;2", "GOSUB_RETVAL=TRUE") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-blkvm-setifempty:3] MacroExit("Local/777@from-queue-00000008;2", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:11] GotoIf("Local/777@from-queue-00000008;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 [777@from-internal:14] Set("Local/777@from-queue-00000008;2", "RRNODEST=9901") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:15] Set("Local/777@from-queue-00000008;2", "__NODEST=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:16] GosubIf("Local/777@from-queue-00000008;2", "0?sub-fmsetcid,s,1()") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:17] Set("Local/777@from-queue-00000008;2", "RecordMethod=Group") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:18] Gosub("Local/777@from-queue-00000008;2", "sub-record-check,s,1(exten,777,)") in new stack

Dvbnhbq · June 26, 2015, 6:40pm

[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:1] GotoIf("Local/777@from-queue-00000008;2", "0?initialized") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:2] Set("Local/777@from-queue-00000008;2", "__REC_STATUS=INITIALIZED") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:3] Set("Local/777@from-queue-00000008;2", "NOW=1435341690") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:4] Set("Local/777@from-queue-00000008;2", "__DAY=26") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:5] Set("Local/777@from-queue-00000008;2", "__MONTH=06") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:6] Set("Local/777@from-queue-00000008;2", "__YEAR=2015") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:7] Set("Local/777@from-queue-00000008;2", "__TIMESTR=20150626-210130") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:8] Set("Local/777@from-queue-00000008;2", "__FROMEXTEN=88888888888") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:9] Set("Local/777@from-queue-00000008;2", "__MON_FMT=wav") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:10] NoOp("Local/777@from-queue-00000008;2", "Recordings initialized") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:11] ExecIf("Local/777@from-queue-00000008;2", "1?Set(ARG3=dontcare)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:12] Set("Local/777@from-queue-00000008;2", "REC_POLICY_MODE_SAVE=") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:13] ExecIf("Local/777@from-queue-00000008;2", "0?Set(REC_STATUS=NO)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@sub-record-check:14] GotoIf("Local/777@from-queue-00000008;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 [s@sub-record-check:17] GotoIf("Local/777@from-queue-00000008;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 [exten@sub-record-check:1] NoOp("Local/777@from-queue-00000008;2", "Exten Recording Check between 88888888888 and 777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [exten@sub-record-check:2] Set("Local/777@from-queue-00000008;2", "CALLTYPE=external") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [exten@sub-record-check:3] ExecIf("Local/777@from-queue-00000008;2", "0?Set(CALLTYPE=)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [exten@sub-record-check:4] Set("Local/777@from-queue-00000008;2", "CALLEE=yes") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [exten@sub-record-check:5] ExecIf("Local/777@from-queue-00000008;2", "0?Set(CALLEE=dontcare)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [exten@sub-record-check:6] GotoIf("Local/777@from-queue-00000008;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 [exten@sub-record-check:11] Gosub("Local/777@from-queue-00000008;2", "recordcheck,1(yes,external,777)") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("Local/777@from-queue-00000008;2", "Starting recording check against yes") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("Local/777@from-queue-00000008;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 [recordcheck@sub-record-check:9] ExecIf("Local/777@from-queue-00000008;2", "0?Return()") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [recordcheck@sub-record-check:10] Set("Local/777@from-queue-00000008;2", "__REC_POLICY_MODE=YES") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [recordcheck@sub-record-check:11] Goto("Local/777@from-queue-00000008;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 [recordcheck@sub-record-check:16] NoOp("Local/777@from-queue-00000008;2", "Starting recording: external, 777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [recordcheck@sub-record-check:17] Set("Local/777@from-queue-00000008;2", "AUDIOHOOK_INHERIT(MixMonitor)=yes") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [recordcheck@sub-record-check:18] Set("Local/777@from-queue-00000008;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 [recordcheck@sub-record-check:19] MixMonitor("Local/777@from-queue-00000008;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 [recordcheck@sub-record-check:20] Set("Local/777@from-queue-00000008;2", "__MIXMON_ID=0x7fb798015930") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [recordcheck@sub-record-check:21] Set("Local/777@from-queue-00000008;2", "__RECORD_ID=Local/777@from-queue-00000008;2") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [recordcheck@sub-record-check:22] Set("Local/777@from-queue-00000008;2", "__REC_STATUS=RECORDING") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [recordcheck@sub-record-check:23] Set("Local/777@from-queue-00000008;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 [recordcheck@sub-record-check:24] Return("Local/777@from-queue-00000008;2", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [exten@sub-record-check:12] Return("Local/777@from-queue-00000008;2", "") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:19] Set("Local/777@from-queue-00000008;2", "RingGroupMethod=ringallv2-prim") in new stack
[2015-06-26 21:01:30] VERBOSE[4291][C-00000003] app_mixmonitor.c: Begin MixMonitor Recording Local/777@from-queue-00000008;2
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:20] Set("Local/777@from-queue-00000008;2", "_FMGRP=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:21] GotoIf("Local/777@from-queue-00000008;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 [777@from-internal:24] Macro("Local/777@from-queue-00000008;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 [s@macro-dial-confirm:1] Set("Local/777@from-queue-00000008;2", "DB(RG/777/Local/777@from-queue-00000008;2)=RINGING") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-dial-confirm:2] Set("Local/777@from-queue-00000008;2", "__UNIQCHAN=Local/777@from-queue-00000008;2") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-dial-confirm:3] Set("Local/777@from-queue-00000008;2", "USE_CONFIRMATION=TRUE") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-dial-confirm:4] Set("Local/777@from-queue-00000008;2", "RINGGROUP_INDEX=777") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-dial-confirm:5] Set("Local/777@from-queue-00000008;2", "FORCE_CONFIRM=") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-dial-confirm:6] Set("Local/777@from-queue-00000008;2", "ARG4=") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-dial-confirm:7] Macro("Local/777@from-queue-00000008;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 [s@macro-dial:1] GotoIf("Local/777@from-queue-00000008;2", "0?dial") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-dial:2] Set("Local/777@from-queue-00000008;2", "CHANNEL(musicclass)=default") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-dial:3] AGI("Local/777@from-queue-00000008;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/777@from-queue-00000008;2>AGI Script dialparties.agi completed, returning 0
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-dial:4] NoOp("Local/777@from-queue-00000008;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 [s@macro-dial-confirm:8] NoOp("Local/777@from-queue-00000008;2", "Deleting: RG/777/Local/777@from-queue-00000008;2 RINGING") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-dial-confirm:9] Set("Local/777@from-queue-00000008;2", "USE_CONFIRMATION=") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [s@macro-dial-confirm:10] Set("Local/777@from-queue-00000008;2", "RINGGROUP_INDEX=") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:25] Set("Local/777@from-queue-00000008;2", "RingGroupMethod=") in new stack
[2015-06-26 21:01:30] VERBOSE[4289][C-00000003] pbx.c: Executing [777@from-internal:26] GotoIf("Local/777@from-queue-00000008;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 [777@from-internal:32] NoOp("Local/777@from-queue-00000008;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/777@from-queue-00000008;2' status is 'BUSY'
[2015-06-26 21:01:30] VERBOSE[4285][C-00000003] app_queue.c: Local/777@from-queue-00000008;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 [h@from-internal:1] Hangup("Local/777@from-queue-00000008;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/777@from-queue-00000008;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/777@from-queue-00000008;2
[2015-06-26 21:01:33] WARNING[2972] chan_sip.c: Retransmission timeout reached on transmission CI_23098_20002272222222222@RTK_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 CI_23098_20002272222222222@RTK_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 [h@ext-queues:1] Macro("SIP/online_sip-00000003", "hangupcall,") in new stack
[2015-06-26 21:01:33] VERBOSE[4285][C-00000003] pbx.c: Executing [s@macro-hangupcall: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 [s@macro-hangupcall: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 [s@macro-hangupcall: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 [20002272222222222@from-trunk: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 [20002272222222222@from-trunk: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 [20002272222222222@from-trunk: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 [20002272222222222@from-trunk: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 [s@ext-did: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 [s@ext-did: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 [s@sub-record-check:1] GotoIf("SIP/online_sip-00000004", "0?initialized") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check:3] Set("SIP/online_sip-00000004", "NOW=1435341698") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@sub-record-check:4] Set("SIP/online_sip-00000004", "__DAY=26") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@sub-record-check:5] Set("SIP/online_sip-00000004", "__MONTH=06") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@sub-record-check:6] Set("SIP/online_sip-00000004", "__YEAR=2015") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check:8] Set("SIP/online_sip-00000004", "__FROMEXTEN=unknown") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check:10] NoOp("SIP/online_sip-00000004", "Recordings initialized") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [in@sub-record-check: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 [in@sub-record-check:2] Set("SIP/online_sip-00000004", "FROMEXTEN=unknown") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [in@sub-record-check: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 [in@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check:3] Return("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [in@sub-record-check:5] Return("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@ext-did: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 [cidlookup_2@cidlookup: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 [cidlookup_2@cidlookup:2] Set("SIP/online_sip-00000004", "CALLERID(name)=") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [cidlookup_2@cidlookup:3] Return("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@ext-did: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 [s@app-blacklist-check:1] GotoIf("SIP/online_sip-00000004", "0?blacklisted") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@app-blacklist-check: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 [s@app-blacklist-check:3] Return("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@ext-did: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 [s@ext-did: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 [s@ext-did: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 [s@ext-did: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 [s@ext-did: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 [s@ext-did: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 [s@macro-privacy-mgr:1] Set("SIP/online_sip-00000004", "KEEPCID=88888888888") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@macro-privacy-mgr: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 [s@macro-privacy-mgr: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 [s@macro-privacy-mgr: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 [s@macro-privacy-mgr:5] GotoIf("SIP/online_sip-00000004", "0?fail") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@macro-privacy-mgr: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 [s@app-blacklist-check:1] GotoIf("SIP/online_sip-00000004", "0?blacklisted") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@app-blacklist-check: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 [s@app-blacklist-check:3] Return("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@macro-privacy-mgr: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 [s@macro-privacy-mgr:8] MacroExit("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@ext-did: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 [s@ivr-2: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 [s@ivr-2: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 [s@ivr-2:3] Set("SIP/online_sip-00000004", "__IVR_RETVM=") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@ivr-2:4] GotoIf("SIP/online_sip-00000004", "0?skip") in new stack
[2015-06-26 21:01:38] VERBOSE[4296][C-00000004] pbx.c: Executing [s@ivr-2:5] Answer("SIP/online_sip-00000004", "") in new stack
[2015-06-26 21:01:39] VERBOSE[4296][C-00000004] pbx.c: Executing [s@ivr-2:6] Wait("SIP/online_sip-00000004", "1") in new stack
[2015-06-26 21:01:40] VERBOSE[4296][C-00000004] pbx.c: Executing [s@ivr-2:7] Set("SIP/online_sip-00000004", "IVR_MSG=") in new stack
[2015-06-26 21:01:40] VERBOSE[4296][C-00000004] pbx.c: Executing [s@ivr-2:8] Set("SIP/online_sip-00000004", "TIMEOUT(digit)=3") in new stack

Dvbnhbq · June 26, 2015, 6:40pm

    [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 [s@ivr-2:9] ExecIf("SIP/online_sip-00000004", "0?Background()") in new stack
    [2015-06-26 21:01:40] VERBOSE[4296][C-00000004] pbx.c: Executing [s@ivr-2: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 [t@ivr-2: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 [9901@ext-queues:1] Macro("SIP/online_sip-00000004", "user-callerid,") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:2] Set("SIP/online_sip-00000004", "AMPUSER=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("SIP/online_sip-00000004", "0?report") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:5] Set("SIP/online_sip-00000004", "AMPUSER=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("SIP/online_sip-00000004", "0?limit") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [s@macro-user-callerid:7] Set("SIP/online_sip-00000004", "AMPUSERCIDNAME=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:16] GotoIf("SIP/online_sip-00000004", "0?continue") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:18] Set("SIP/online_sip-00000004", "__TTL=64") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [9901@ext-queues:2] Answer("SIP/online_sip-00000004", "") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues: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 [9901@ext-queues: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 [s@macro-blkvm-set: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 [s@macro-blkvm-set: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 [s@macro-blkvm-set: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 [s@macro-blkvm-set:4] MacroExit("SIP/online_sip-00000004", "") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues: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 [9901@ext-queues:6] Set("SIP/online_sip-00000004", "__NODEST=9901") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:7] Set("SIP/online_sip-00000004", "QCIDPP=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:8] Set("SIP/online_sip-00000004", "VQ_CIDPP=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues: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 [9901@ext-queues:10] Set("SIP/online_sip-00000004", "QAINFO=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:11] Set("SIP/online_sip-00000004", "VQ_AINFO=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues: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 [9901@ext-queues:13] Set("SIP/online_sip-00000004", "QJOINMSG=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:14] Set("SIP/online_sip-00000004", "VQ_JOINMSG=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:15] Set("SIP/online_sip-00000004", "QRETRY=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:16] Set("SIP/online_sip-00000004", "VQ_RETRY=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:17] Set("SIP/online_sip-00000004", "QOPTIONS=t") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:18] Set("SIP/online_sip-00000004", "VQ_OPTIONS=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:19] Set("SIP/online_sip-00000004", "QGOSUB=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:20] Set("SIP/online_sip-00000004", "VQ_GOSUB=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:21] Set("SIP/online_sip-00000004", "QAGI=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:22] Set("SIP/online_sip-00000004", "VQ_AGI=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:23] Set("SIP/online_sip-00000004", "QRULE=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:24] Set("SIP/online_sip-00000004", "VQ_RULE=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:25] Set("SIP/online_sip-00000004", "QPOSITION=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:26] Set("SIP/online_sip-00000004", "VQ_POSITION=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues: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 [s@sub-record-check: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 [s@sub-record-check:10] NoOp("SIP/online_sip-00000004", "Recordings initialized") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check:3] Return("SIP/online_sip-00000004", "") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [s@sub-record-check:20] Return("SIP/online_sip-00000004", "") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:28] Set("SIP/online_sip-00000004", "__CWIGNORE=TRUE") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:29] ExecIf("SIP/online_sip-00000004", "0?Playback(, )") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues: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 [9901@ext-queues:31] Set("SIP/online_sip-00000004", "QAANNOUNCE=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:32] Set("SIP/online_sip-00000004", "VQ_AANNOUNCE=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:33] Set("SIP/online_sip-00000004", "QMOH=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:34] Set("SIP/online_sip-00000004", "VQ_MOH=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues: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 [9901@ext-queues: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 [9901@ext-queues:37] Set("SIP/online_sip-00000004", "QMAXWAIT=260") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:38] Set("SIP/online_sip-00000004", "VQ_MAXWAIT=") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:39] Set("SIP/online_sip-00000004", "QUEUENUM=9901") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues:40] Set("SIP/online_sip-00000004", "QUEUEJOINTIME=1435341702") in new stack
    [2015-06-26 21:01:42] VERBOSE[4296][C-00000004] pbx.c: Executing [9901@ext-queues: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/777@from-queue/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 [777@from-queue:1] Set("Local/777@from-queue-00000009;2", "QAGENT=777") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-queue:2] Goto("Local/777@from-queue-00000009;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 [9901@from-queue:1] Goto("Local/777@from-queue-00000009;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 [777@from-internal:1] GotoIf("Local/777@from-queue-00000009;2", "0?ext-local,777,1") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:2] Macro("Local/777@from-queue-00000009;2", "user-callerid,") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-user-callerid:1] Set("Local/777@from-queue-00000009;2", "TOUCH_MONITOR=1435341702.133") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-user-callerid:2] Set("Local/777@from-queue-00000009;2", "AMPUSER=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("Local/777@from-queue-00000009;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 [s@macro-user-callerid:16] GotoIf("Local/777@from-queue-00000009;2", "0?continue") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-user-callerid:17] ExecIf("Local/777@from-queue-00000009;2", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-user-callerid:18] Set("Local/777@from-queue-00000009;2", "__TTL=63") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-user-callerid:19] GotoIf("Local/777@from-queue-00000009;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 [s@macro-user-callerid:30] Set("Local/777@from-queue-00000009;2", "CALLERID(number)=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-user-callerid:31] Set("Local/777@from-queue-00000009;2", "CALLERID(name)=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-user-callerid:32] Set("Local/777@from-queue-00000009;2", "CDR(cnum)=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-user-callerid:33] Set("Local/777@from-queue-00000009;2", "CDR(cnam)=88888888888") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-user-callerid:34] Set("Local/777@from-queue-00000009;2", "CHANNEL(language)=en") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:3] Set("Local/777@from-queue-00000009;2", "DIAL_OPTIONS=TtrM(auto-blkvm)I") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:4] Set("Local/777@from-queue-00000009;2", "CONNECTEDLINE(num,i)=777") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:5] Gosub("Local/777@from-queue-00000009;2", "sub-presencestate-display,s,1(777)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-presencestate-display:1] Goto("Local/777@from-queue-00000009;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 [state-unavailable@sub-presencestate-display:1] Set("Local/777@from-queue-00000009;2", "PRESENCESTATE_DISPLAY=(Unavailable)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [state-unavailable@sub-presencestate-display:2] Return("Local/777@from-queue-00000009;2", "") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:6] Set("Local/777@from-queue-00000009;2", "CONNECTEDLINE(name)=Dmitriy Stepanov(Unavailable)") in new stack
    [2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:7]
Set("Local/777@from-queue-00000009;2", "FM_DIALSTATUS=INUSE") in new stack

Dvbnhbq · June 26, 2015, 6:40pm

[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:8] Set("Local/777@from-queue-00000009;2", "__EXTTOCALL=777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:9] Set("Local/777@from-queue-00000009;2", "__PICKUPMARK=777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:10] Macro("Local/777@from-queue-00000009;2", "blkvm-setifempty,") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-blkvm-setifempty:1] GotoIf("Local/777@from-queue-00000009;2", "0?init") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-blkvm-setifempty:2] Set("Local/777@from-queue-00000009;2", "GOSUB_RETVAL=TRUE") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-blkvm-setifempty:3] MacroExit("Local/777@from-queue-00000009;2", "") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:11] GotoIf("Local/777@from-queue-00000009;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 [777@from-internal:14] Set("Local/777@from-queue-00000009;2", "RRNODEST=9901") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:15] Set("Local/777@from-queue-00000009;2", "__NODEST=777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:16] GosubIf("Local/777@from-queue-00000009;2", "0?sub-fmsetcid,s,1()") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:17] Set("Local/777@from-queue-00000009;2", "RecordMethod=Group") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:18] Gosub("Local/777@from-queue-00000009;2", "sub-record-check,s,1(exten,777,)") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:1] GotoIf("Local/777@from-queue-00000009;2", "0?initialized") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:2] Set("Local/777@from-queue-00000009;2", "__REC_STATUS=INITIALIZED") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:3] Set("Local/777@from-queue-00000009;2", "NOW=1435341702") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:4] Set("Local/777@from-queue-00000009;2", "__DAY=26") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:5] Set("Local/777@from-queue-00000009;2", "__MONTH=06") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:6] Set("Local/777@from-queue-00000009;2", "__YEAR=2015") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:7] Set("Local/777@from-queue-00000009;2", "__TIMESTR=20150626-210142") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:8] Set("Local/777@from-queue-00000009;2", "__FROMEXTEN=88888888888") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:9] Set("Local/777@from-queue-00000009;2", "__MON_FMT=wav") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:10] NoOp("Local/777@from-queue-00000009;2", "Recordings initialized") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:11] ExecIf("Local/777@from-queue-00000009;2", "1?Set(ARG3=dontcare)") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:12] Set("Local/777@from-queue-00000009;2", "REC_POLICY_MODE_SAVE=") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:13] ExecIf("Local/777@from-queue-00000009;2", "0?Set(REC_STATUS=NO)") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@sub-record-check:14] GotoIf("Local/777@from-queue-00000009;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 [s@sub-record-check:17] GotoIf("Local/777@from-queue-00000009;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 [exten@sub-record-check:1] NoOp("Local/777@from-queue-00000009;2", "Exten Recording Check between 88888888888 and 777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [exten@sub-record-check:2] Set("Local/777@from-queue-00000009;2", "CALLTYPE=external") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [exten@sub-record-check:3] ExecIf("Local/777@from-queue-00000009;2", "0?Set(CALLTYPE=)") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [exten@sub-record-check:4] Set("Local/777@from-queue-00000009;2", "CALLEE=yes") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [exten@sub-record-check:5] ExecIf("Local/777@from-queue-00000009;2", "0?Set(CALLEE=dontcare)") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [exten@sub-record-check:6] GotoIf("Local/777@from-queue-00000009;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 [exten@sub-record-check:11] Gosub("Local/777@from-queue-00000009;2", "recordcheck,1(yes,external,777)") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("Local/777@from-queue-00000009;2", "Starting recording check against yes") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("Local/777@from-queue-00000009;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 [recordcheck@sub-record-check:9] ExecIf("Local/777@from-queue-00000009;2", "0?Return()") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:10] Set("Local/777@from-queue-00000009;2", "__REC_POLICY_MODE=YES") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:11] Goto("Local/777@from-queue-00000009;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 [recordcheck@sub-record-check:16] NoOp("Local/777@from-queue-00000009;2", "Starting recording: external, 777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:17] Set("Local/777@from-queue-00000009;2", "AUDIOHOOK_INHERIT(MixMonitor)=yes") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:18] Set("Local/777@from-queue-00000009;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 [recordcheck@sub-record-check:19] MixMonitor("Local/777@from-queue-00000009;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 [recordcheck@sub-record-check:20] Set("Local/777@from-queue-00000009;2", "__MIXMON_ID=0x7fb75c6e8fd0") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:21] Set("Local/777@from-queue-00000009;2", "__RECORD_ID=Local/777@from-queue-00000009;2") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:22] Set("Local/777@from-queue-00000009;2", "__REC_STATUS=RECORDING") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [recordcheck@sub-record-check:23] Set("Local/777@from-queue-00000009;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 [recordcheck@sub-record-check:24] Return("Local/777@from-queue-00000009;2", "") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [exten@sub-record-check:12] Return("Local/777@from-queue-00000009;2", "") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:19] Set("Local/777@from-queue-00000009;2", "RingGroupMethod=ringallv2-prim") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:20] Set("Local/777@from-queue-00000009;2", "_FMGRP=777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:21] GotoIf("Local/777@from-queue-00000009;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 [777@from-internal:24] Macro("Local/777@from-queue-00000009;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 [s@macro-dial-confirm:1] Set("Local/777@from-queue-00000009;2", "DB(RG/777/Local/777@from-queue-00000009;2)=RINGING") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-dial-confirm:2] Set("Local/777@from-queue-00000009;2", "__UNIQCHAN=Local/777@from-queue-00000009;2") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-dial-confirm:3] Set("Local/777@from-queue-00000009;2", "USE_CONFIRMATION=TRUE") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-dial-confirm:4] Set("Local/777@from-queue-00000009;2", "RINGGROUP_INDEX=777") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-dial-confirm:5] Set("Local/777@from-queue-00000009;2", "FORCE_CONFIRM=") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-dial-confirm:6] Set("Local/777@from-queue-00000009;2", "ARG4=") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-dial-confirm:7] Macro("Local/777@from-queue-00000009;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 [s@macro-dial:1] GotoIf("Local/777@from-queue-00000009;2", "0?dial") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-dial:2] Set("Local/777@from-queue-00000009;2", "CHANNEL(musicclass)=default") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-dial:3] AGI("Local/777@from-queue-00000009;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/777@from-queue-00000009;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/777@from-queue-00000009;2>AGI Script dialparties.agi completed, returning 0
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-dial:4] NoOp("Local/777@from-queue-00000009;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 [s@macro-dial-confirm:8] NoOp("Local/777@from-queue-00000009;2", "Deleting: RG/777/Local/777@from-queue-00000009;2 RINGING") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-dial-confirm:9] Set("Local/777@from-queue-00000009;2", "USE_CONFIRMATION=") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [s@macro-dial-confirm:10] Set("Local/777@from-queue-00000009;2", "RINGGROUP_INDEX=") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:25] Set("Local/777@from-queue-00000009;2", "RingGroupMethod=") in new stack
[2015-06-26 21:01:42] VERBOSE[4297][C-00000004] pbx.c: Executing [777@from-internal:26] GotoIf("Local/777@from-queue-00000009;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 [777@from-internal:32] NoOp("Local/777@from-queue-00000009;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/777@from-queue-00000009;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/777@from-queue-00000009;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 [h@from-internal:1] Hangup("Local/777@from-queue-00000009;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/777@from-queue-00000009;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/777@from-queue-00000009;2
[2015-06-26 21:01:45] WARNING[2972] chan_sip.c: Retransmission timeout reached on transmission CI_23101_20002272222222222@RTK_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 CI_23101_20002272222222222@RTK_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 [h@ext-queues:1] Macro("SIP/online_sip-00000004", "hangupcall,") in new stack
[2015-06-26 21:01:45] VERBOSE[4296][C-00000004] pbx.c: Executing [s@macro-hangupcall: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 [s@macro-hangupcall: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 [s@macro-hangupcall: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 [h@from-internal: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