Inbound Calls Discrepancy

Any and all non-support discussions

Moderators: gerski, enjay, williamconley, Op3r, Staydog, gardo, mflorell, MJCoate, mcargile, Kumba, Michael_N

Inbound Calls Discrepancy

Postby ZeeTech » Tue Jan 24, 2017 11:57 am

We noticed that few calls were dropped in Inbound Queue however agents were available at that time but still calls were dropped and when I run “Export Calls Report” it showed that call was transfer to agents.
User Stats for that agents also show data for that same call with status “DROP” and same thing is reflecting if we check data from “Search For A Lead”

This is happening with multiple calls, export call report image is attached. Please advise.

https://i.imgsafe.org/786cf172aa.jpg

VERSION: 2.12-541a BUILD: 160306-1053
Asterisk 1.8.23.0-vici, libpri-1.4.15 with DAHDI Version: 2.11
Dell R720 – No additional hardware.
ZeeTech
 
Posts: 72
Joined: Sun Apr 04, 2010 5:45 am

Re: Inbound Calls Discrepancy

Postby mangamen45@gmail.com » Fri May 19, 2017 3:03 am

ZeeTech wrote:We noticed that few calls were dropped in Inbound Queue however agents were available at that time but still calls were dropped and when I run “Export Calls Report” it showed that call was transfer to agents.
User Stats for that agents also show data for that same call with status “DROP” and same thing is reflecting if we check data from “Search For A Lead”

This is happening with multiple calls, export call report image is attached. Please advise.

https://i.imgsafe.org/786cf172aa.jpg

VERSION: 2.12-541a BUILD: 160306-1053
Asterisk 1.8.23.0-vici, libpri-1.4.15 with DAHDI Version: 2.11
Dell R720 – No additional hardware.


I have same problem!
In my case i have many inbound calls where call was transfer to agents, but this call show like drop.
can help Anybody ?
mangamen45@gmail.com
 
Posts: 10
Joined: Mon May 16, 2016 7:35 am

Re: Inbound Calls Discrepancy

Postby mflorell » Fri May 19, 2017 7:40 am

You need to post the Asterisk CLI output and the agiout logfile output of an example of when this happens. There is usually a simple explanation for why it happens.
mflorell
Site Admin
 
Posts: 18335
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Re: Inbound Calls Discrepancy

Postby mangamen45@gmail.com » Fri May 26, 2017 7:24 am

mflorell wrote:You need to post the Asterisk CLI output and the agiout logfile output of an example of when this happens. There is usually a simple explanation for why it happens.

agiout log is below:
Code: Select all
2017-05-25 10:27:24|agi-DID_route.agi||INSERT INTO vicidial_did_log SET uniqueid='1495697244.1946',channel='SIP/avaya_ru-000001fe',server_ip='10.207.24.152',caller_id_number='4995505366',caller_id_name='',extension='282709',call_date='2017-05-25 10:27:24',did_id='11',did_route='IN_GROUP';|
2017-05-25 10:27:24|agi-DID_route.agi|--    DID LOG : |1|INSERT INTO vicidial_did_log SET uniqueid='1495697244.1946',channel='SIP/avaya_ru-000001fe',server_ip='10.207.24.152',caller_id_number='4995505366',caller_id_name='',extension='282709',call_date='2017-05-25 10:27:24',did_id='11',did_route='IN_GROUP';|
2017-05-25 10:27:24|agi-DID_route.agi|--    CALL LOG : |1|INSERT INTO call_log SET uniqueid='1495697244.1946', channel='SIP/avaya_ru-000001fe', channel_group='DID_INBOUND', server_ip='10.207.24.152', type='SIP', extension='282709', number_dialed='282709', caller_code='4995505366', start_time='2017-05-25 10:27:24', start_epoch='1495697244';|
2017-05-25 10:27:24|agi-DID_route.agi|exiting the DID app, transferring call to 99909*11***DID @ default
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- accountcode =
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- callerid = 4995505366
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- calleridname = unknown
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- callingani2 = 0
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- callingpres = 0
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- callingtns = 0
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- callington = 0
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- channel = SIP/avaya_ru-000001fe
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- context = default
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- dnid = 282709
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- enhanced = 0.0
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- extension = 99909*11***DID
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- language = en
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- priority = 2
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- rdnis = unknown
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- request = agi-VDAD_ALL_inbound.agi
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- threadid = 140568982378240
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- type = SIP
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- uniqueid = 1495697244.1946
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi| -- version = 1.8.23.0-vici
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|AGI Variables: |1495697244.1946|SIP/avaya_ru-000001fe|99909*11***DID|SIP|4995505366|
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|+++++ INBOUND CALL VDCL STARTED : |PMI_INCOMING_DRA|4995505366-282709|2017-05-25 10:27:24
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|Holiday check: |0|SELECT count(*) from vicidial_call_time_holidays where holiday_date='2017-05-25' and holiday_status='ACTIVE';||01052017|08052017|09052017||
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi||SELECT campaign_id FROM vicidial_campaigns where active='Y' and campaign_allow_inbound='Y';|1153424|
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|callerID changed: "Y5251027240001153424 <4995505366>"
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|0|SELECT auto_call_id from vicidial_auto_calls where uniqueid='1495697244.1946' and server_ip='10.207.24.152';|
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_auto_calls SET server_ip='10.207.24.152', campaign_id='PMI_INCOMING_DRA', status='LIVE', lead_id='1153424', uniqueid='1495697244.1946', callerid='Y5251027240001153424', channel='SIP/avaya_ru-000001fe', phone_code='7', phone_number='4995505366', call_time='2017-05-25 10:27:24', call_type='IN', stage='LIVE-0', queue_priority='97' ;|
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|1|SELECT count(*) from vicidial_auto_calls where status = 'LIVE' and campaign_id='PMI_INCOMING_DRA';|
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|1|UPDATE vicidial_auto_calls SET queue_position='1'  WHERE auto_call_id='426';|
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_closer_log SET lead_id='1153424', campaign_id='PMI_INCOMING_DRA', call_date='2017-05-25 10:27:24', start_epoch='1495697244', status='QUEUE', phone_code='7', phone_number='4995505366', user='VDCL', processed='N', xfercallid='0', uniqueid='1495697244.1946', queue_position='1',called_count='1',list_id='990' ;|
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|--    VDCL : |1153424|0|30043|insert to vicidial_closer_log
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|--  ENTER QUEUE VLE insert: |1|
|INSERT INTO vicidial_log_extended set uniqueid='1495697244.1946',server_ip='10.207.24.152',call_date='2017-05-25 10:27:24',lead_id = '1153424',caller_code='Y5251027240001153424',custom_call_id='';|
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|DID IVR time logged: 2017-05-25 10:27:24|1495697244|1|UPDATE call_log set end_time='2017-05-25 10:27:24',end_epoch='1495697244',length_in_sec=0,length_in_min='    0.00',extension='Y5251027240001153424' where uniqueid='1495697244.1946'|
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'PMI_INCOMING_DRA' and call_time < "2017-05-25 10:27:24" and lead_id != '1153424' and queue_priority >= '97' and agent_only='';|
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '1153424' and agent_only='' and ( (queue_priority > '97') or (queue_priority = '97' and call_time < "2017-05-25 10:27:24") );|
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|||SELECT conf_exten,user,extension,server_ip,last_call_time,ra_user,campaign_id,on_hook_agent,on_hook_ring_time FROM vicidial_live_agents where status IN('CLOSER','READY') and lead_id<1  and campaign_id IN('TESTINCO','GOOGLERU','GOOGLEAW','GOOGLEA2','GOOADW_2','PMI_VOLG','PMI_OUT','PMI_ADMI','PMI_TELE','PMI_DRA','PMI_SUCC','PMI_CSMS','PMI_OUT3','PMI_OUT4') and closer_campaigns LIKE "% PMI_INCOMING_DRA %" and last_update_time > '20170525102719' and vicidial_live_agents.user NOT IN('','')   order by vicidial_live_agents.last_inbound_call_finish limit 1;|
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|--    VDAD get agent: |360|0|10|20|0|0||0|update of vla table: PMI_INCOMING_DRA|
|UNLOCK TABLES;|
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found
2017-05-25 10:27:24|10:27:24|agi-VDAD_ALL_inbound.agi|ring_no_answer_agents reset
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'PMI_INCOMING_DRA' and call_time < "2017-05-25 10:27:24" and lead_id != '1153424' and queue_priority >= '97' and agent_only='';|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '1153424' and agent_only='' and ( (queue_priority > '97') or (queue_priority = '97' and call_time < "2017-05-25 10:27:24") );|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|||SELECT conf_exten,user,extension,server_ip,last_call_time,ra_user,campaign_id,on_hook_agent,on_hook_ring_time FROM vicidial_live_agents where status IN('CLOSER','READY') and lead_id<1  and campaign_id IN('TESTINCO','GOOGLERU','GOOGLEAW','GOOGLEA2','GOOADW_2','PMI_VOLG','PMI_OUT','PMI_ADMI','PMI_TELE','PMI_DRA','PMI_SUCC','PMI_CSMS','PMI_OUT3','PMI_OUT4') and closer_campaigns LIKE "% PMI_INCOMING_DRA %" and last_update_time > '20170525102719' and vicidial_live_agents.user NOT IN('','')   order by vicidial_live_agents.last_inbound_call_finish limit 1;|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|--    VDAD get agent: |360|0.25|11|20|0|0||0|update of vla table: PMI_INCOMING_DRA|
|UNLOCK TABLES;|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|ring_no_answer_agents reset
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'PMI_INCOMING_DRA' and call_time < "2017-05-25 10:27:24" and lead_id != '1153424' and queue_priority >= '97' and agent_only='';|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '1153424' and agent_only='' and ( (queue_priority > '97') or (queue_priority = '97' and call_time < "2017-05-25 10:27:24") );|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|||SELECT conf_exten,user,extension,server_ip,last_call_time,ra_user,campaign_id,on_hook_agent,on_hook_ring_time FROM vicidial_live_agents where status IN('CLOSER','READY') and lead_id<1  and campaign_id IN('TESTINCO','GOOGLERU','GOOGLEAW','GOOGLEA2','GOOADW_2','PMI_VOLG','PMI_OUT','PMI_ADMI','PMI_TELE','PMI_DRA','PMI_SUCC','PMI_CSMS','PMI_OUT3','PMI_OUT4') and closer_campaigns LIKE "% PMI_INCOMING_DRA %" and last_update_time > '20170525102719' and vicidial_live_agents.user NOT IN('','')   order by vicidial_live_agents.last_inbound_call_finish limit 1;|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|--    VDAD get agent: |360|0.5|12|20|0|0||0|update of vla table: PMI_INCOMING_DRA|
|UNLOCK TABLES;|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|ring_no_answer_agents reset
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'PMI_INCOMING_DRA' and call_time < "2017-05-25 10:27:24" and lead_id != '1153424' and queue_priority >= '97' and agent_only='';|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '1153424' and agent_only='' and ( (queue_priority > '97') or (queue_priority = '97' and call_time < "2017-05-25 10:27:24") );|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|advuriechienskaia|2017-05-25 10:01:45|SELECT conf_exten,user,extension,server_ip,last_call_time,ra_user,campaign_id,on_hook_agent,on_hook_ring_time FROM vicidial_live_agents where status IN('CLOSER','READY') and lead_id<1  and campaign_id IN('TESTINCO','GOOGLERU','GOOGLEAW','GOOGLEA2','GOOADW_2','PMI_VOLG','PMI_OUT','PMI_ADMI','PMI_TELE','PMI_DRA','PMI_SUCC','PMI_CSMS','PMI_OUT3','PMI_OUT4') and closer_campaigns LIKE "% PMI_INCOMING_DRA %" and last_update_time > '20170525102719' and vicidial_live_agents.user NOT IN('','')   order by vicidial_live_agents.last_inbound_call_finish limit 1;|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|--    VDAD get agent: |360|0.75|13|20|1|1||0|update of vla table: PMI_INCOMING_DRA|
|UNLOCK TABLES;|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|--    VDCL XFER REMOTE: |1|update of vac table: Y5251027240001153424
|UPDATE vicidial_auto_calls set status='CLOSER', stage='CLOSER-0.75' where callerid='Y5251027240001153424';|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|--    VDXL vicidial_xfer_log update: |0E0|1153424|advuriechienskaia
|UPDATE vicidial_xfer_log set closer='advuriechienskaia' where lead_id = '1153424' order by call_date desc limit 1;|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|--    closer log : |1|update of vcl table: 1153424
|UPDATE vicidial_closer_log set user='advuriechienskaia' where lead_id='1153424' order by call_date desc limit 1;|
2017-05-25 10:27:24|10:27:25|agi-VDAD_ALL_inbound.agi|--    VDCL agent alert: |VH5251027248600087|010*207*024*152*78600087|ding|"ding" <ding>|SIP/avaya_ru-000001fe|insert to vicidial_manager
2017-05-25 10:27:24|10:27:26|agi-VDAD_ALL_inbound.agi|exiting VDAD app, transferring call to 010*207*024*152*8600087
2017-05-25 10:27:24|10:27:26|agi-VDAD_ALL_inbound.agi||SELECT calls_today from vicidial_inbound_group_agents WHERE user='advuriechienskaia' and group_id='PMI_INCOMING_DRA';|
2017-05-25 10:27:24|10:27:26|agi-VDAD_ALL_inbound.agi|--    VDLIA agent calls: |2|advuriechienskaia|PMI_INCOMING_DRA|
2017-05-25 10:27:24|10:27:27|agi-VDAD_ALL_inbound.agi|--    VDCL vcl update: |1|1153424|
|UPDATE vicidial_closer_log set queue_seconds='0.75' where lead_id = '1153424' and call_date='2017-05-25 10:27:24';|
2017-05-25 10:27:27|10:27:27|agi-VDAD_ALL_inbound.agi|XXXXX VDAD transferred: start|stop  2017-05-25 10:27:24|2017-05-25 10:27:27|010*207*024*152*8600087

Asterisk CLI log is below:
Code: Select all
[May 25 10:27:24] VERBOSE[438] pbx.c: [May 25 10:27:24]     -- Executing [282709@trunkinbound:1] AGI("SIP/avaya_ru-000001fe", "agi-DID_route.agi") in new stack
[May 25 10:27:24] VERBOSE[438] res_agi.c: [May 25 10:27:24]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-DID_route.agi
[May 25 10:27:24] VERBOSE[438] res_agi.c: [May 25 10:27:24]     -- AGI Script Executing Application: (Monitor) Options: (wav,/var/spool/asterisk/monitor/MIX/20170525102724_282709_4995505366)
[May 25 10:27:24] VERBOSE[438] res_agi.c: [May 25 10:27:24]     -- <SIP/avaya_ru-000001fe>AGI Script agi-DID_route.agi completed, returning 0
[May 25 10:27:24] VERBOSE[438] pbx.c: [May 25 10:27:24]     -- Executing [99909*11***DID@default:1] Answer("SIP/avaya_ru-000001fe", "") in new stack
[May 25 10:27:24] VERBOSE[438] pbx.c: [May 25 10:27:24]     -- Executing [99909*11***DID@default:2] AGI("SIP/avaya_ru-000001fe", "agi-VDAD_ALL_inbound.agi") in new stack
[May 25 10:27:24] VERBOSE[438] res_agi.c: [May 25 10:27:24]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_inbound.agi
[May 25 10:27:24] VERBOSE[452] manager.c: [May 25 10:27:24]   == Manager 'sendcron' logged on from 127.0.0.1
mangamen45@gmail.com
 
Posts: 10
Joined: Mon May 16, 2016 7:35 am

Re: Inbound Calls Discrepancy

Postby mflorell » Fri May 26, 2017 7:40 am

You'll need to include more from the asterisk CLI, you are only including the output up to the point the call enters the queue.
mflorell
Site Admin
 
Posts: 18335
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Re: Inbound Calls Discrepancy

Postby mangamen45@gmail.com » Fri May 26, 2017 8:03 am

mflorell wrote:You'll need to include more from the asterisk CLI, you are only including the output up to the point the call enters the queue.

For first - Thank you for help, it's very pleasure

previous part of Asterisk CLI is below... but I can't find there any information about phone or lead_id ....
Code: Select all
[May 25 10:25:59] VERBOSE[32100] netsock2.c: [May 25 10:25:59]   == Using SIP RTP CoS mark 5
[May 25 10:25:59] VERBOSE[32100] app_dial.c: [May 25 10:25:59]     -- Called SIP/vulcan1/37279652881110
[May 25 10:26:00] VERBOSE[32100] app_dial.c: [May 25 10:26:00]     -- SIP/vulcan1-000001f3 is ringing
[May 25 10:26:00] VERBOSE[32069] app_dial.c: [May 25 10:26:00]     -- SIP/vulcan1-000001f2 is ringing
[May 25 10:26:00] VERBOSE[32069] app_dial.c: [May 25 10:26:00]     -- SIP/vulcan1-000001f2 is ringing
[May 25 10:26:00] VERBOSE[32069] app_dial.c: [May 25 10:26:00]     -- SIP/vulcan1-000001f2 is making progress passing it to Local/37279295946781@default-00000296;2
[May 25 10:26:00] VERBOSE[32100] app_dial.c: [May 25 10:26:00]     -- SIP/vulcan1-000001f3 is making progress passing it to Local/37279652881110@default-00000297;2
[May 25 10:26:02] VERBOSE[32133] manager.c: [May 25 10:26:02]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:02] VERBOSE[32133] manager.c: [May 25 10:26:02]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:06] VERBOSE[31556] pbx.c: [May 25 10:26:06]     -- Executing [h@default:1] AGI("Local/8600116@default-0000028d;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----72-----63") in new stack
[May 25 10:26:06] VERBOSE[31556] res_agi.c: [May 25 10:26:06]     -- <Local/8600116@default-0000028d;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----72-----63 completed, returning 0
[May 25 10:26:06] VERBOSE[31556] pbx.c: [May 25 10:26:06]   == Spawn extension (default, 37274242260009, 3) exited non-zero on 'Local/8600116@default-0000028d;1'
[May 25 10:26:06] VERBOSE[31555] pbx.c: [May 25 10:26:06]   == Spawn extension (default, 8600116, 1) exited non-zero on 'Local/8600116@default-0000028d;2'
[May 25 10:26:06] VERBOSE[31555] pbx.c: [May 25 10:26:06]     -- Executing [h@default:1] AGI("Local/8600116@default-0000028d;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:26:06] VERBOSE[31555] res_agi.c: [May 25 10:26:06]     -- <Local/8600116@default-0000028d;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:26:07] VERBOSE[32203] manager.c: [May 25 10:26:07]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:07] VERBOSE[32203] manager.c: [May 25 10:26:07]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:08] VERBOSE[32213] manager.c: [May 25 10:26:08]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:08] VERBOSE[32214] pbx.c: [May 25 10:26:08]     -- Executing [8600114@default:1] MeetMe("Local/8600114@default-00000298;2", "8600114,F") in new stack
[May 25 10:26:08] VERBOSE[32213] pbx.c: [May 25 10:26:08]        > Channel Local/8600114@default-00000298;1 was answered.
[May 25 10:26:08] VERBOSE[32215] pbx.c: [May 25 10:26:08]     -- Executing [37279257846371@default:1] AGI("Local/8600114@default-00000298;1", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:26:08] VERBOSE[32215] res_agi.c: [May 25 10:26:08]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_TELE))
[May 25 10:26:08] VERBOSE[32215] res_agi.c: [May 25 10:26:08]     -- <Local/8600114@default-00000298;1>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:26:08] VERBOSE[32215] pbx.c: [May 25 10:26:08]     -- Executing [37279257846371@default:2] Set("Local/8600114@default-00000298;1", "GLOBAL(MYGLOBALVAR372)=79257846371") in new stack
[May 25 10:26:08] VERBOSE[32215] pbx.c: [May 25 10:26:08]   == Setting global variable 'MYGLOBALVAR372' to '79257846371'
[May 25 10:26:08] VERBOSE[32215] pbx.c: [May 25 10:26:08]     -- Executing [37279257846371@default:3] Dial("Local/8600114@default-00000298;1", "SIP/vulcan1/37279257846371,,tTor") in new stack
[May 25 10:26:08] VERBOSE[32215] netsock2.c: [May 25 10:26:08]   == Using SIP RTP CoS mark 5
[May 25 10:26:08] VERBOSE[32215] app_dial.c: [May 25 10:26:08]     -- Called SIP/vulcan1/37279257846371
[May 25 10:26:09] VERBOSE[32220] manager.c: [May 25 10:26:09]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:09] VERBOSE[32221] pbx.c: [May 25 10:26:09]     -- Executing [58600114@default:1] MeetMe("Local/58600114@default-00000299;2", "8600114,Fmq") in new stack
[May 25 10:26:09] VERBOSE[32220] pbx.c: [May 25 10:26:09]        > Channel Local/58600114@default-00000299;1 was answered.
[May 25 10:26:09] VERBOSE[32222] pbx.c: [May 25 10:26:09]     -- Executing [8309@default:1] Answer("Local/58600114@default-00000299;1", "") in new stack
[May 25 10:26:09] VERBOSE[32222] pbx.c: [May 25 10:26:09]     -- Executing [8309@default:2] Monitor("Local/58600114@default-00000299;1", "wav,PMI_TELE_20170525-102607_zhukova19_9257846371") in new stack
[May 25 10:26:09] VERBOSE[32222] pbx.c: [May 25 10:26:09]     -- Executing [8309@default:3] Wait("Local/58600114@default-00000299;1", "3600") in new stack
[May 25 10:26:09] VERBOSE[32213] manager.c: [May 25 10:26:09]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:10] VERBOSE[32220] manager.c: [May 25 10:26:10]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:10] VERBOSE[3705] chan_sip.c: [May 25 10:26:10]     -- Got SIP response 480 "Temporarily Unavailable" back from 10.207.120.154:5060
[May 25 10:26:10] VERBOSE[32100] app_dial.c: [May 25 10:26:10]     -- SIP/vulcan1-000001f3 is circuit-busy
[May 25 10:26:10] VERBOSE[32100] app_dial.c: [May 25 10:26:10]   == Everyone is busy/congested at this time (1:0/1/0)
[May 25 10:26:10] VERBOSE[32100] pbx.c: [May 25 10:26:10]     -- Executing [37279652881110@default:4] Hangup("Local/37279652881110@default-00000297;2", "") in new stack
[May 25 10:26:10] VERBOSE[32100] pbx.c: [May 25 10:26:10]   == Spawn extension (default, 37279652881110, 4) exited non-zero on 'Local/37279652881110@default-00000297;2'
[May 25 10:26:10] VERBOSE[32100] pbx.c: [May 25 10:26:10]     -- Executing [h@default:1] AGI("Local/37279652881110@default-00000297;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----19-----CONGESTION----------") in new stack
[May 25 10:26:11] VERBOSE[32100] res_agi.c: [May 25 10:26:11]     -- <Local/37279652881110@default-00000297;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----19-----CONGESTION---------- completed, returning 0
[May 25 10:26:12] VERBOSE[32069] app_dial.c: [May 25 10:26:12]     -- SIP/vulcan1-000001f2 answered Local/37279295946781@default-00000296;2
[May 25 10:26:12] VERBOSE[32068] pbx.c: [May 25 10:26:12]        > Channel Local/37279295946781@default-00000296;1 was answered.
[May 25 10:26:12] VERBOSE[32237] pbx.c: [May 25 10:26:12]     -- Executing [8366@default:1] Playback("Local/37279295946781@default-00000296;1", "sip-silence") in new stack
[May 25 10:26:12] VERBOSE[32237] file.c: [May 25 10:26:12]     -- <Local/37279295946781@default-00000296;1> Playing 'sip-silence.gsm' (language 'en')
[May 25 10:26:12] VERBOSE[32069] pbx.c: [May 25 10:26:12]     -- Executing [h@default:1] AGI("Local/37279295946781@default-00000296;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----16-----0") in new stack
[May 25 10:26:12] VERBOSE[32237] pbx.c: [May 25 10:26:12]     -- Executing [8366@default:2] AGI("SIP/vulcan1-000001f2", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:26:12] VERBOSE[32237] res_agi.c: [May 25 10:26:12]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:26:12] VERBOSE[32237] res_agi.c: [May 25 10:26:12]     -- <SIP/vulcan1-000001f2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:26:12] VERBOSE[32237] pbx.c: [May 25 10:26:12]     -- Executing [8366@default:3] AGI("SIP/vulcan1-000001f2", "agi-VDAD_ALL_outbound.agi,SURVEYCAMP-----LB") in new stack
[May 25 10:26:12] VERBOSE[32237] res_agi.c: [May 25 10:26:12]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[May 25 10:26:12] VERBOSE[32215] app_dial.c: [May 25 10:26:12]     -- SIP/vulcan1-000001f4 is ringing
[May 25 10:26:12] VERBOSE[32237] res_agi.c: [May 25 10:26:12]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:26:12] VERBOSE[32099] manager.c: [May 25 10:26:12]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:12] VERBOSE[32237] res_agi.c: [May 25 10:26:12]     -- <SIP/vulcan1-000001f2>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[May 25 10:26:12] VERBOSE[32237] pbx.c: [May 25 10:26:12]     -- Executing [s@pmi_menu_for_connect:1] Answer("SIP/vulcan1-000001f2", "") in new stack
[May 25 10:26:12] VERBOSE[32237] pbx.c: [May 25 10:26:12]     -- Executing [s@pmi_menu_for_connect:2] AGI("SIP/vulcan1-000001f2", "agi-VDAD_inbound_calltime_check.agi,CALLMENU-----YES-----pmi_menu_for_connect-------------------------NO") in new stack
[May 25 10:26:12] VERBOSE[32237] res_agi.c: [May 25 10:26:12]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_inbound_calltime_check.agi
[May 25 10:26:12] VERBOSE[32237] res_agi.c: [May 25 10:26:12]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:26:12] VERBOSE[32215] app_dial.c: [May 25 10:26:12]     -- SIP/vulcan1-000001f4 is ringing
[May 25 10:26:12] VERBOSE[32215] app_dial.c: [May 25 10:26:12]     -- SIP/vulcan1-000001f4 is making progress passing it to Local/8600114@default-00000298;1
[May 25 10:26:12] VERBOSE[32237] res_agi.c: [May 25 10:26:12]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:26:12] VERBOSE[32237] res_agi.c: [May 25 10:26:12]     -- <SIP/vulcan1-000001f2>AGI Script agi-VDAD_inbound_calltime_check.agi completed, returning 0
[May 25 10:26:12] VERBOSE[32237] pbx.c: [May 25 10:26:12]     -- Executing [s@pmi_menu_for_connect:3] Set("SIP/vulcan1-000001f2", "INVCOUNT=0") in new stack
[May 25 10:26:12] VERBOSE[32237] pbx.c: [May 25 10:26:12]     -- Executing [s@pmi_menu_for_connect:4] BackGround("SIP/vulcan1-000001f2", "pmi_welcome_m_1") in new stack
[May 25 10:26:12] VERBOSE[32237] file.c: [May 25 10:26:12]     -- <SIP/vulcan1-000001f2> Playing 'pmi_welcome_m_1.slin' (language 'en')
[May 25 10:26:13] VERBOSE[32068] manager.c: [May 25 10:26:13]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:13] VERBOSE[32069] res_agi.c: [May 25 10:26:13]     -- <Local/37279295946781@default-00000296;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----16-----0 completed, returning 0
[May 25 10:26:13] VERBOSE[32069] pbx.c: [May 25 10:26:13]   == Spawn extension (default, 37279295946781, 3) exited non-zero on 'Local/37279295946781@default-00000296;2'
[May 25 10:26:14] VERBOSE[32262] manager.c: [May 25 10:26:14]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:14] VERBOSE[32263] pbx.c: [May 25 10:26:14]     -- Executing [37279772854791@default:1] AGI("Local/37279772854791@default-0000029a;2", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:26:14] VERBOSE[32263] res_agi.c: [May 25 10:26:14]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:26:14] VERBOSE[32263] res_agi.c: [May 25 10:26:14]     -- <Local/37279772854791@default-0000029a;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:26:14] VERBOSE[32263] pbx.c: [May 25 10:26:14]     -- Executing [37279772854791@default:2] Set("Local/37279772854791@default-0000029a;2", "GLOBAL(MYGLOBALVAR372)=79772854791") in new stack
[May 25 10:26:14] VERBOSE[32263] pbx.c: [May 25 10:26:14]   == Setting global variable 'MYGLOBALVAR372' to '79772854791'
[May 25 10:26:14] VERBOSE[32263] pbx.c: [May 25 10:26:14]     -- Executing [37279772854791@default:3] Dial("Local/37279772854791@default-0000029a;2", "SIP/vulcan1/37279772854791,,tTor") in new stack
[May 25 10:26:14] VERBOSE[32263] netsock2.c: [May 25 10:26:14]   == Using SIP RTP CoS mark 5
[May 25 10:26:14] VERBOSE[32263] app_dial.c: [May 25 10:26:14]     -- Called SIP/vulcan1/37279772854791
[May 25 10:26:16] WARNING[3705] chan_sip.c: Received response: "Forbidden" from '"M5251026080001140041" <sip:78007750198@10.207.24.152>;tag=as14762d7e'
[May 25 10:26:16] VERBOSE[32215] app_dial.c: [May 25 10:26:16]   == Everyone is busy/congested at this time (1:0/0/1)
[May 25 10:26:16] VERBOSE[32215] pbx.c: [May 25 10:26:16]     -- Executing [37279257846371@default:4] Hangup("Local/8600114@default-00000298;1", "") in new stack
[May 25 10:26:16] VERBOSE[32215] pbx.c: [May 25 10:26:16]   == Spawn extension (default, 37279257846371, 4) exited non-zero on 'Local/8600114@default-00000298;1'
[May 25 10:26:16] VERBOSE[32215] pbx.c: [May 25 10:26:16]     -- Executing [h@default:1] AGI("Local/8600114@default-00000298;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----21-----CHANUNAVAIL----------") in new stack
[May 25 10:26:16] VERBOSE[32215] res_agi.c: [May 25 10:26:16]     -- <Local/8600114@default-00000298;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----21-----CHANUNAVAIL---------- completed, returning 0
[May 25 10:26:16] VERBOSE[32214] pbx.c: [May 25 10:26:16]   == Spawn extension (default, 8600114, 1) exited non-zero on 'Local/8600114@default-00000298;2'
[May 25 10:26:16] VERBOSE[32214] pbx.c: [May 25 10:26:16]     -- Executing [h@default:1] AGI("Local/8600114@default-00000298;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:26:16] VERBOSE[32214] res_agi.c: [May 25 10:26:16]     -- <Local/8600114@default-00000298;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:26:16] VERBOSE[3705] chan_sip.c: [May 25 10:26:16]     -- Got SIP response 480 "Temporarily Unavailable" back from 10.207.120.154:5060
[May 25 10:26:16] VERBOSE[32019] app_dial.c: [May 25 10:26:16]     -- SIP/vulcan1-000001f1 is circuit-busy
[May 25 10:26:16] VERBOSE[32019] app_dial.c: [May 25 10:26:16]   == Everyone is busy/congested at this time (1:0/1/0)
[May 25 10:26:16] VERBOSE[32019] pbx.c: [May 25 10:26:16]     -- Executing [37279268368399@default:4] Hangup("Local/37279268368399@default-00000295;2", "") in new stack
[May 25 10:26:16] VERBOSE[32019] pbx.c: [May 25 10:26:16]   == Spawn extension (default, 37279268368399, 4) exited non-zero on 'Local/37279268368399@default-00000295;2'
[May 25 10:26:16] VERBOSE[32019] pbx.c: [May 25 10:26:16]     -- Executing [h@default:1] AGI("Local/37279268368399@default-00000295;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----19-----CONGESTION----------") in new stack
[May 25 10:26:17] VERBOSE[32019] res_agi.c: [May 25 10:26:17]     -- <Local/37279268368399@default-00000295;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----19-----CONGESTION---------- completed, returning 0
[May 25 10:26:17] VERBOSE[32018] manager.c: [May 25 10:26:17]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:17] VERBOSE[32263] app_dial.c: [May 25 10:26:17]     -- SIP/vulcan1-000001f5 is ringing
[May 25 10:26:17] VERBOSE[32263] app_dial.c: [May 25 10:26:17]     -- SIP/vulcan1-000001f5 is making progress passing it to Local/37279772854791@default-0000029a;2
[May 25 10:26:18] VERBOSE[32043] pbx.c: [May 25 10:26:18]     -- Executing [s@pmi_menu_for_connect:5] WaitExten("SIP/vulcan1-000001f0", "5") in new stack
[May 25 10:26:18] VERBOSE[32292] manager.c: [May 25 10:26:18]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:18] VERBOSE[32295] manager.c: [May 25 10:26:18]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:18] VERBOSE[32221] pbx.c: [May 25 10:26:18]   == Spawn extension (default, 58600114, 1) exited non-zero on 'Local/58600114@default-00000299;2'
[May 25 10:26:18] VERBOSE[32221] pbx.c: [May 25 10:26:18]     -- Executing [h@default:1] AGI("Local/58600114@default-00000299;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:26:18] VERBOSE[32221] res_agi.c: [May 25 10:26:18]     -- <Local/58600114@default-00000299;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:26:18] VERBOSE[32222] pbx.c: [May 25 10:26:18]   == Spawn extension (default, 8309, 3) exited non-zero on 'Local/58600114@default-00000299;1'
[May 25 10:26:18] VERBOSE[32222] pbx.c: [May 25 10:26:18]     -- Executing [h@default:1] AGI("Local/58600114@default-00000299;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:26:18] VERBOSE[32222] res_agi.c: [May 25 10:26:18]     -- <Local/58600114@default-00000299;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:26:19] VERBOSE[32292] manager.c: [May 25 10:26:19]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:19] VERBOSE[32295] manager.c: [May 25 10:26:19]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:23] VERBOSE[32330] manager.c: [May 25 10:26:23]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:23] VERBOSE[32331] pbx.c: [May 25 10:26:23]     -- Executing [8600053@default:1] MeetMe("Local/8600053@default-0000029b;2", "8600053,F") in new stack
[May 25 10:26:23] VERBOSE[32330] pbx.c: [May 25 10:26:23]        > Channel Local/8600053@default-0000029b;1 was answered.
[May 25 10:26:23] VERBOSE[32332] pbx.c: [May 25 10:26:23]     -- Executing [3779130523003@default:1] AGI("Local/8600053@default-0000029b;1", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:26:23] VERBOSE[32043] pbx.c: [May 25 10:26:23]     -- Timeout on SIP/vulcan1-000001f0, going to 't'
[May 25 10:26:23] VERBOSE[32043] pbx.c: [May 25 10:26:23]     -- Executing [t@pmi_menu_for_connect:1] Playback("SIP/vulcan1-000001f0", "pmi_goodby_m_2") in new stack
[May 25 10:26:23] VERBOSE[32043] file.c: [May 25 10:26:23]     -- <SIP/vulcan1-000001f0> Playing 'pmi_goodby_m_2.slin' (language 'en')
[May 25 10:26:23] VERBOSE[32332] res_agi.c: [May 25 10:26:23]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=GOOADW_2))
[May 25 10:26:23] VERBOSE[32332] res_agi.c: [May 25 10:26:23]     -- <Local/8600053@default-0000029b;1>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:26:23] VERBOSE[32332] pbx.c: [May 25 10:26:23]     -- Executing [3779130523003@default:2] Set("Local/8600053@default-0000029b;1", "GLOBAL(ABONNUMBER1)=79130523003") in new stack
[May 25 10:26:23] VERBOSE[32332] pbx.c: [May 25 10:26:23]   == Setting global variable 'ABONNUMBER1' to '79130523003'
[May 25 10:26:23] VERBOSE[32332] pbx.c: [May 25 10:26:23]     -- Executing [3779130523003@default:3] Dial("Local/8600053@default-0000029b;1", "SIP/vulcan1/79130523003,,tTor") in new stack
[May 25 10:26:23] VERBOSE[32332] netsock2.c: [May 25 10:26:23]   == Using SIP RTP CoS mark 5
[May 25 10:26:23] VERBOSE[32332] app_dial.c: [May 25 10:26:23]     -- Called SIP/vulcan1/79130523003
[May 25 10:26:23] VERBOSE[32337] manager.c: [May 25 10:26:23]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:23] VERBOSE[32338] pbx.c: [May 25 10:26:23]     -- Executing [58600053@default:1] MeetMe("Local/58600053@default-0000029c;2", "8600053,Fmq") in new stack
[May 25 10:26:23] VERBOSE[32337] pbx.c: [May 25 10:26:23]        > Channel Local/58600053@default-0000029c;1 was answered.
[May 25 10:26:23] VERBOSE[32339] pbx.c: [May 25 10:26:23]     -- Executing [8309@default:1] Answer("Local/58600053@default-0000029c;1", "") in new stack
[May 25 10:26:23] VERBOSE[32339] pbx.c: [May 25 10:26:23]     -- Executing [8309@default:2] Monitor("Local/58600053@default-0000029c;1", "wav,GOOADW_2_20170525-102622_medvedeva.14_9130523003") in new stack
[May 25 10:26:23] VERBOSE[32339] pbx.c: [May 25 10:26:23]     -- Executing [8309@default:3] Wait("Local/58600053@default-0000029c;1", "3600") in new stack
[May 25 10:26:24] VERBOSE[32330] manager.c: [May 25 10:26:24]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:24] VERBOSE[32337] manager.c: [May 25 10:26:24]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:26] VERBOSE[32043] pbx.c: [May 25 10:26:26]     -- Executing [t@pmi_menu_for_connect:2] AGI("SIP/vulcan1-000001f0", "cm.agi,CALLMENU-----t-----postal_code") in new stack
[May 25 10:26:26] VERBOSE[32043] res_agi.c: [May 25 10:26:26]     -- Launched AGI Script /var/lib/asterisk/agi-bin/cm.agi
[May 25 10:26:26] VERBOSE[32043] res_agi.c: [May 25 10:26:26]     -- <SIP/vulcan1-000001f0>AGI Script cm.agi completed, returning 0
[May 25 10:26:26] VERBOSE[32043] pbx.c: [May 25 10:26:26]     -- Executing [t@pmi_menu_for_connect:3] Hangup("SIP/vulcan1-000001f0", "") in new stack
[May 25 10:26:26] VERBOSE[32043] pbx.c: [May 25 10:26:26]   == Spawn extension (pmi_menu_for_connect, t, 3) exited non-zero on 'SIP/vulcan1-000001f0'
[May 25 10:26:26] VERBOSE[32043] pbx.c: [May 25 10:26:26]     -- Executing [h@pmi_menu_for_connect:1] AGI("SIP/vulcan1-000001f0", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
[May 25 10:26:26] VERBOSE[32043] res_agi.c: [May 25 10:26:26]     -- <SIP/vulcan1-000001f0>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0
[May 25 10:26:27] VERBOSE[32332] app_dial.c: [May 25 10:26:27]     -- SIP/vulcan1-000001f6 is making progress passing it to Local/8600053@default-0000029b;1
[May 25 10:26:28] VERBOSE[32375] manager.c: [May 25 10:26:28]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:29] VERBOSE[32381] manager.c: [May 25 10:26:29]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:29] VERBOSE[31561] pbx.c: [May 25 10:26:29]   == Spawn extension (default, 58600116, 1) exited non-zero on 'Local/58600116@default-0000028e;2'
[May 25 10:26:29] VERBOSE[31561] pbx.c: [May 25 10:26:29]     -- Executing [h@default:1] AGI("Local/58600116@default-0000028e;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:26:29] VERBOSE[31561] res_agi.c: [May 25 10:26:29]     -- <Local/58600116@default-0000028e;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:26:29] VERBOSE[31562] pbx.c: [May 25 10:26:29]   == Spawn extension (default, 8309, 3) exited non-zero on 'Local/58600116@default-0000028e;1'
[May 25 10:26:29] VERBOSE[31562] pbx.c: [May 25 10:26:29]     -- Executing [h@default:1] AGI("Local/58600116@default-0000028e;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:26:29] VERBOSE[31562] res_agi.c: [May 25 10:26:29]     -- <Local/58600116@default-0000028e;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:26:29] VERBOSE[32237] pbx.c: [May 25 10:26:29]   == Spawn extension (pmi_menu_for_connect, s, 4) exited non-zero on 'SIP/vulcan1-000001f2'
[May 25 10:26:29] VERBOSE[32237] pbx.c: [May 25 10:26:29]     -- Executing [h@pmi_menu_for_connect:1] AGI("SIP/vulcan1-000001f2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:26:29] VERBOSE[32237] res_agi.c: [May 25 10:26:29]     -- <SIP/vulcan1-000001f2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:26:29] VERBOSE[32375] manager.c: [May 25 10:26:29]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:30] VERBOSE[32381] manager.c: [May 25 10:26:30]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:37] VERBOSE[32438] manager.c: [May 25 10:26:37]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:37] VERBOSE[32439] pbx.c: [May 25 10:26:37]     -- Executing [37279263237610@default:1] AGI("Local/37279263237610@default-0000029d;2", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:26:37] VERBOSE[32439] res_agi.c: [May 25 10:26:37]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:26:37] VERBOSE[32439] res_agi.c: [May 25 10:26:37]     -- <Local/37279263237610@default-0000029d;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:26:37] VERBOSE[32439] pbx.c: [May 25 10:26:37]     -- Executing [37279263237610@default:2] Set("Local/37279263237610@default-0000029d;2", "GLOBAL(MYGLOBALVAR372)=79263237610") in new stack
[May 25 10:26:37] VERBOSE[32439] pbx.c: [May 25 10:26:37]   == Setting global variable 'MYGLOBALVAR372' to '79263237610'
[May 25 10:26:37] VERBOSE[32439] pbx.c: [May 25 10:26:37]     -- Executing [37279263237610@default:3] Dial("Local/37279263237610@default-0000029d;2", "SIP/vulcan1/37279263237610,,tTor") in new stack
[May 25 10:26:37] VERBOSE[32439] netsock2.c: [May 25 10:26:37]   == Using SIP RTP CoS mark 5
[May 25 10:26:37] VERBOSE[32439] app_dial.c: [May 25 10:26:37]     -- Called SIP/vulcan1/37279263237610
[May 25 10:26:40] VERBOSE[32461] manager.c: [May 25 10:26:40]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:40] VERBOSE[32462] pbx.c: [May 25 10:26:40]     -- Executing [8600055@default:1] MeetMe("Local/8600055@default-0000029e;2", "8600055,F") in new stack
[May 25 10:26:40] VERBOSE[32461] pbx.c: [May 25 10:26:40]        > Channel Local/8600055@default-0000029e;1 was answered.
[May 25 10:26:40] VERBOSE[32463] pbx.c: [May 25 10:26:40]     -- Executing [37279255152742@default:1] AGI("Local/8600055@default-0000029e;1", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:26:40] VERBOSE[32463] res_agi.c: [May 25 10:26:40]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_TELE))
[May 25 10:26:40] VERBOSE[32463] res_agi.c: [May 25 10:26:40]     -- <Local/8600055@default-0000029e;1>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:26:40] VERBOSE[32463] pbx.c: [May 25 10:26:40]     -- Executing [37279255152742@default:2] Set("Local/8600055@default-0000029e;1", "GLOBAL(MYGLOBALVAR372)=79255152742") in new stack
[May 25 10:26:40] VERBOSE[32463] pbx.c: [May 25 10:26:40]   == Setting global variable 'MYGLOBALVAR372' to '79255152742'
[May 25 10:26:40] VERBOSE[32463] pbx.c: [May 25 10:26:40]     -- Executing [37279255152742@default:3] Dial("Local/8600055@default-0000029e;1", "SIP/vulcan1/37279255152742,,tTor") in new stack
[May 25 10:26:40] VERBOSE[32463] netsock2.c: [May 25 10:26:40]   == Using SIP RTP CoS mark 5
[May 25 10:26:40] VERBOSE[32463] app_dial.c: [May 25 10:26:40]     -- Called SIP/vulcan1/37279255152742
[May 25 10:26:41] VERBOSE[32478] manager.c: [May 25 10:26:41]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:41] VERBOSE[32479] pbx.c: [May 25 10:26:41]     -- Executing [58600055@default:1] MeetMe("Local/58600055@default-0000029f;2", "8600055,Fmq") in new stack
[May 25 10:26:41] VERBOSE[32478] pbx.c: [May 25 10:26:41]        > Channel Local/58600055@default-0000029f;1 was answered.
[May 25 10:26:41] VERBOSE[32480] pbx.c: [May 25 10:26:41]     -- Executing [8309@default:1] Answer("Local/58600055@default-0000029f;1", "") in new stack
[May 25 10:26:41] VERBOSE[32480] pbx.c: [May 25 10:26:41]     -- Executing [8309@default:2] Monitor("Local/58600055@default-0000029f;1", "wav,PMI_TELE_20170525-102640_glugovskaya5_9255152742") in new stack
[May 25 10:26:41] VERBOSE[32480] pbx.c: [May 25 10:26:41]     -- Executing [8309@default:3] Wait("Local/58600055@default-0000029f;1", "3600") in new stack
[May 25 10:26:41] VERBOSE[32461] manager.c: [May 25 10:26:41]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:41] VERBOSE[32463] app_dial.c: [May 25 10:26:41]     -- SIP/vulcan1-000001f8 is making progress passing it to Local/8600055@default-0000029e;1
[May 25 10:26:42] VERBOSE[32478] manager.c: [May 25 10:26:42]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:42] VERBOSE[32492] manager.c: [May 25 10:26:42]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:42] VERBOSE[32462] pbx.c: [May 25 10:26:42]   == Spawn extension (default, 8600055, 1) exited non-zero on 'Local/8600055@default-0000029e;2'
[May 25 10:26:42] VERBOSE[32462] pbx.c: [May 25 10:26:42]     -- Executing [h@default:1] AGI("Local/8600055@default-0000029e;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:26:42] VERBOSE[32462] res_agi.c: [May 25 10:26:42]     -- <Local/8600055@default-0000029e;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:26:42] VERBOSE[32463] pbx.c: [May 25 10:26:42]   == Spawn extension (default, 37279255152742, 3) exited non-zero on 'Local/8600055@default-0000029e;1'
[May 25 10:26:42] VERBOSE[32463] pbx.c: [May 25 10:26:42]     -- Executing [h@default:1] AGI("Local/8600055@default-0000029e;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL----------") in new stack
[May 25 10:26:42] VERBOSE[32463] res_agi.c: [May 25 10:26:42]     -- <Local/8600055@default-0000029e;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL---------- completed, returning 0
[May 25 10:26:42] VERBOSE[32499] manager.c: [May 25 10:26:42]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:42] VERBOSE[32479] pbx.c: [May 25 10:26:42]   == Spawn extension (default, 58600055, 1) exited non-zero on 'Local/58600055@default-0000029f;2'
[May 25 10:26:42] VERBOSE[32479] pbx.c: [May 25 10:26:42]     -- Executing [h@default:1] AGI("Local/58600055@default-0000029f;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:26:42] VERBOSE[32500] manager.c: [May 25 10:26:42]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:42] VERBOSE[32479] res_agi.c: [May 25 10:26:42]     -- <Local/58600055@default-0000029f;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:26:42] VERBOSE[32480] pbx.c: [May 25 10:26:42]   == Spawn extension (default, 8309, 3) exited non-zero on 'Local/58600055@default-0000029f;1'
[May 25 10:26:42] VERBOSE[32480] pbx.c: [May 25 10:26:42]     -- Executing [h@default:1] AGI("Local/58600055@default-0000029f;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:26:42] VERBOSE[32480] res_agi.c: [May 25 10:26:42]     -- <Local/58600055@default-0000029f;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:26:43] VERBOSE[32332] app_dial.c: [May 25 10:26:43]     -- SIP/vulcan1-000001f6 answered Local/8600053@default-0000029b;1
[May 25 10:26:43] VERBOSE[32492] manager.c: [May 25 10:26:43]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:43] VERBOSE[32499] manager.c: [May 25 10:26:43]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:43] VERBOSE[32500] manager.c: [May 25 10:26:43]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:44] VERBOSE[32262] manager.c: [May 25 10:26:44]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:26:44] VERBOSE[32263] pbx.c: [May 25 10:26:44]   == Spawn extension (default, 37279772854791, 3) exited non-zero on 'Local/37279772854791@default-0000029a;2'
[May 25 10:26:44] VERBOSE[32263] pbx.c: [May 25 10:26:44]     -- Executing [h@default:1] AGI("Local/37279772854791@default-0000029a;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL----------") in new stack
[May 25 10:26:45] VERBOSE[32521] manager.c: [May 25 10:26:45]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:26:45] VERBOSE[32522] pbx.c: [May 25 10:26:45]     -- Executing [37279264324260@default:1] AGI("Local/37279264324260@default-000002a0;2", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:26:45] VERBOSE[32522] res_agi.c: [May 25 10:26:45]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:26:45] VERBOSE[32522] res_agi.c: [May 25 10:26:45]     -- <Local/37279264324260@default-000002a0;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:26:45] VERBOSE[32522] pbx.c: [May 25 10:26:45]     -- Executing [37279264324260@default:2] Set("Local/37279264324260@default-000002a0;2", "GLOBAL(MYGLOBALVAR372)=79264324260") in new stack
[May 25 10:26:45] VERBOSE[32522] pbx.c: [May 25 10:26:45]   == Setting global variable 'MYGLOBALVAR372' to '79264324260'
[May 25 10:26:45] VERBOSE[32522] pbx.c: [May 25 10:26:45]     -- Executing [37279264324260@default:3] Dial("Local/37279264324260@default-000002a0;2", "SIP/vulcan1/37279264324260,,tTor") in new stack
[May 25 10:26:45] VERBOSE[32522] netsock2.c: [May 25 10:26:45]   == Using SIP RTP CoS mark 5
[May 25 10:26:45] VERBOSE[32522] app_dial.c: [May 25 10:26:45]     -- Called SIP/vulcan1/37279264324260
[May 25 10:26:45] VERBOSE[32263] res_agi.c: [May 25 10:26:45]     -- <Local/37279772854791@default-0000029a;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL---------- completed, returning 0
[May 25 10:26:47] VERBOSE[32522] app_dial.c: [May 25 10:26:47]     -- SIP/vulcan1-000001f9 is making progress passing it to Local/37279264324260@default-000002a0;2
[May 25 10:26:51] VERBOSE[32332] pbx.c: [May 25 10:26:51]     -- Executing [h@default:1] AGI("Local/8600053@default-0000029b;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----28-----8") in new stack
[May 25 10:26:51] VERBOSE[32332] res_agi.c: [May 25 10:26:51]     -- <Local/8600053@default-0000029b;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----28-----8 completed, returning 0
[May 25 10:26:51] VERBOSE[32332] pbx.c: [May 25 10:26:51]   == Spawn extension (default, 3779130523003, 3) exited non-zero on 'Local/8600053@default-0000029b;1'
[May 25 10:26:51] VERBOSE[32331] pbx.c: [May 25 10:26:51]   == Spawn extension (default, 8600053, 1) exited non-zero on 'Local/8600053@default-0000029b;2'
[May 25 10:26:51] VERBOSE[32331] pbx.c: [May 25 10:26:51]     -- Executing [h@default:1] AGI("Local/8600053@default-0000029b;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:26:51] VERBOSE[32331] res_agi.c: [May 25 10:26:51]     -- <Local/8600053@default-0000029b;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:26:56] VERBOSE[3638] dnsmgr.c: [May 25 10:26:56]        > Refreshing DNS lookups.
[May 25 10:27:00] VERBOSE[32623] manager.c: [May 25 10:27:00]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:00] VERBOSE[32624] pbx.c: [May 25 10:27:00]     -- Executing [37279037002903@default:1] AGI("Local/37279037002903@default-000002a1;2", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:27:00] VERBOSE[32624] res_agi.c: [May 25 10:27:00]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:27:00] VERBOSE[32624] res_agi.c: [May 25 10:27:00]     -- <Local/37279037002903@default-000002a1;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:27:00] VERBOSE[32624] pbx.c: [May 25 10:27:00]     -- Executing [37279037002903@default:2] Set("Local/37279037002903@default-000002a1;2", "GLOBAL(MYGLOBALVAR372)=79037002903") in new stack
[May 25 10:27:00] VERBOSE[32624] pbx.c: [May 25 10:27:00]   == Setting global variable 'MYGLOBALVAR372' to '79037002903'
[May 25 10:27:00] VERBOSE[32624] pbx.c: [May 25 10:27:00]     -- Executing [37279037002903@default:3] Dial("Local/37279037002903@default-000002a1;2", "SIP/vulcan1/37279037002903,,tTor") in new stack
[May 25 10:27:00] VERBOSE[32624] netsock2.c: [May 25 10:27:00]   == Using SIP RTP CoS mark 5
[May 25 10:27:00] VERBOSE[32624] app_dial.c: [May 25 10:27:00]     -- Called SIP/vulcan1/37279037002903
[May 25 10:27:02] VERBOSE[32657] manager.c: [May 25 10:27:02]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:02] VERBOSE[32657] manager.c: [May 25 10:27:02]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:03] VERBOSE[3705] chan_sip.c: [May 25 10:27:03]     -- Got SIP response 480 "Temporarily Unavailable" back from 10.207.120.154:5060
[May 25 10:27:03] VERBOSE[32439] app_dial.c: [May 25 10:27:03]     -- SIP/vulcan1-000001f7 is circuit-busy
[May 25 10:27:03] VERBOSE[32439] app_dial.c: [May 25 10:27:03]   == Everyone is busy/congested at this time (1:0/1/0)
[May 25 10:27:03] VERBOSE[32439] pbx.c: [May 25 10:27:03]     -- Executing [37279263237610@default:4] Hangup("Local/37279263237610@default-0000029d;2", "") in new stack
[May 25 10:27:03] VERBOSE[32439] pbx.c: [May 25 10:27:03]   == Spawn extension (default, 37279263237610, 4) exited non-zero on 'Local/37279263237610@default-0000029d;2'
[May 25 10:27:03] VERBOSE[32439] pbx.c: [May 25 10:27:03]     -- Executing [h@default:1] AGI("Local/37279263237610@default-0000029d;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----19-----CONGESTION----------") in new stack
[May 25 10:27:04] VERBOSE[32439] res_agi.c: [May 25 10:27:04]     -- <Local/37279263237610@default-0000029d;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----19-----CONGESTION---------- completed, returning 0
[May 25 10:27:04] VERBOSE[32438] manager.c: [May 25 10:27:04]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:06] VERBOSE[32624] app_dial.c: [May 25 10:27:06]     -- SIP/vulcan1-000001fa is ringing
[May 25 10:27:06] VERBOSE[32624] app_dial.c: [May 25 10:27:06]     -- SIP/vulcan1-000001fa is making progress passing it to Local/37279037002903@default-000002a1;2
[May 25 10:27:07] VERBOSE[32719] manager.c: [May 25 10:27:07]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:07] VERBOSE[32719] manager.c: [May 25 10:27:07]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:07] VERBOSE[32522] app_dial.c: [May 25 10:27:07]     -- SIP/vulcan1-000001f9 is ringing
[May 25 10:27:07] VERBOSE[32522] app_dial.c: [May 25 10:27:07]     -- SIP/vulcan1-000001f9 is ringing
[May 25 10:27:08] VERBOSE[3705] chan_sip.c: [May 25 10:27:08]     -- Got SIP response 486 "Busy Here" back from 10.207.120.154:5060
[May 25 10:27:08] VERBOSE[32522] app_dial.c: [May 25 10:27:08]     -- SIP/vulcan1-000001f9 is busy
[May 25 10:27:08] VERBOSE[32522] app_dial.c: [May 25 10:27:08]   == Everyone is busy/congested at this time (1:1/0/0)
[May 25 10:27:08] VERBOSE[32522] pbx.c: [May 25 10:27:08]     -- Executing [37279264324260@default:4] Hangup("Local/37279264324260@default-000002a0;2", "") in new stack
[May 25 10:27:08] VERBOSE[32522] pbx.c: [May 25 10:27:08]   == Spawn extension (default, 37279264324260, 4) exited non-zero on 'Local/37279264324260@default-000002a0;2'
[May 25 10:27:08] VERBOSE[32522] pbx.c: [May 25 10:27:08]     -- Executing [h@default:1] AGI("Local/37279264324260@default-000002a0;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----17-----BUSY----------") in new stack
[May 25 10:27:09] VERBOSE[32522] res_agi.c: [May 25 10:27:09]     -- <Local/37279264324260@default-000002a0;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----17-----BUSY---------- completed, returning 0
[May 25 10:27:09] VERBOSE[32521] manager.c: [May 25 10:27:09]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:10] VERBOSE[32624] app_dial.c: [May 25 10:27:10]     -- SIP/vulcan1-000001fa answered Local/37279037002903@default-000002a1;2
[May 25 10:27:10] VERBOSE[32623] pbx.c: [May 25 10:27:10]        > Channel Local/37279037002903@default-000002a1;1 was answered.
[May 25 10:27:10] VERBOSE[306] pbx.c: [May 25 10:27:10]     -- Executing [8366@default:1] Playback("Local/37279037002903@default-000002a1;1", "sip-silence") in new stack
[May 25 10:27:10] VERBOSE[306] file.c: [May 25 10:27:10]     -- <Local/37279037002903@default-000002a1;1> Playing 'sip-silence.gsm' (language 'en')
[May 25 10:27:10] VERBOSE[32624] pbx.c: [May 25 10:27:10]     -- Executing [h@default:1] AGI("Local/37279037002903@default-000002a1;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----10-----0") in new stack
[May 25 10:27:10] VERBOSE[306] pbx.c: [May 25 10:27:10]     -- Executing [8366@default:2] AGI("SIP/vulcan1-000001fa", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:27:10] VERBOSE[306] res_agi.c: [May 25 10:27:10]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:27:10] VERBOSE[306] res_agi.c: [May 25 10:27:10]     -- <SIP/vulcan1-000001fa>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:27:10] VERBOSE[306] pbx.c: [May 25 10:27:10]     -- Executing [8366@default:3] AGI("SIP/vulcan1-000001fa", "agi-VDAD_ALL_outbound.agi,SURVEYCAMP-----LB") in new stack
[May 25 10:27:10] VERBOSE[306] res_agi.c: [May 25 10:27:10]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[May 25 10:27:10] VERBOSE[306] res_agi.c: [May 25 10:27:10]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:10] ERROR[306] utils.c: write() returned error: Broken pipe
[May 25 10:27:10] VERBOSE[306] res_agi.c: [May 25 10:27:10]     -- <SIP/vulcan1-000001fa>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[May 25 10:27:10] VERBOSE[306] pbx.c: [May 25 10:27:10]     -- Executing [s@pmi_menu_for_connect:1] Answer("SIP/vulcan1-000001fa", "") in new stack
[May 25 10:27:10] VERBOSE[306] pbx.c: [May 25 10:27:10]     -- Executing [s@pmi_menu_for_connect:2] AGI("SIP/vulcan1-000001fa", "agi-VDAD_inbound_calltime_check.agi,CALLMENU-----YES-----pmi_menu_for_connect-------------------------NO") in new stack
[May 25 10:27:10] VERBOSE[306] res_agi.c: [May 25 10:27:10]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_inbound_calltime_check.agi
[May 25 10:27:10] VERBOSE[306] res_agi.c: [May 25 10:27:10]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:10] VERBOSE[306] res_agi.c: [May 25 10:27:10]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:10] VERBOSE[306] res_agi.c: [May 25 10:27:10]     -- <SIP/vulcan1-000001fa>AGI Script agi-VDAD_inbound_calltime_check.agi completed, returning 0
[May 25 10:27:10] VERBOSE[306] pbx.c: [May 25 10:27:10]     -- Executing [s@pmi_menu_for_connect:3] Set("SIP/vulcan1-000001fa", "INVCOUNT=0") in new stack
[May 25 10:27:10] VERBOSE[306] pbx.c: [May 25 10:27:10]     -- Executing [s@pmi_menu_for_connect:4] BackGround("SIP/vulcan1-000001fa", "pmi_welcome_m_1") in new stack
[May 25 10:27:10] VERBOSE[306] file.c: [May 25 10:27:10]     -- <SIP/vulcan1-000001fa> Playing 'pmi_welcome_m_1.slin' (language 'en')
[May 25 10:27:10] VERBOSE[320] manager.c: [May 25 10:27:10]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:10] VERBOSE[321] pbx.c: [May 25 10:27:10]     -- Executing [37279265373151@default:1] AGI("Local/37279265373151@default-000002a2;2", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:27:10] VERBOSE[321] res_agi.c: [May 25 10:27:10]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:27:10] VERBOSE[321] res_agi.c: [May 25 10:27:10]     -- <Local/37279265373151@default-000002a2;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:27:10] VERBOSE[321] pbx.c: [May 25 10:27:10]     -- Executing [37279265373151@default:2] Set("Local/37279265373151@default-000002a2;2", "GLOBAL(MYGLOBALVAR372)=79265373151") in new stack
[May 25 10:27:10] VERBOSE[321] pbx.c: [May 25 10:27:10]   == Setting global variable 'MYGLOBALVAR372' to '79265373151'
[May 25 10:27:10] VERBOSE[321] pbx.c: [May 25 10:27:10]     -- Executing [37279265373151@default:3] Dial("Local/37279265373151@default-000002a2;2", "SIP/vulcan1/37279265373151,,tTor") in new stack
[May 25 10:27:10] VERBOSE[321] netsock2.c: [May 25 10:27:10]   == Using SIP RTP CoS mark 5
[May 25 10:27:10] VERBOSE[321] app_dial.c: [May 25 10:27:10]     -- Called SIP/vulcan1/37279265373151
[May 25 10:27:11] VERBOSE[322] manager.c: [May 25 10:27:11]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:11] VERBOSE[323] pbx.c: [May 25 10:27:11]     -- Executing [37279250388118@default:1] AGI("Local/37279250388118@default-000002a3;2", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:27:11] VERBOSE[323] res_agi.c: [May 25 10:27:11]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:27:11] VERBOSE[323] res_agi.c: [May 25 10:27:11]     -- <Local/37279250388118@default-000002a3;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:27:11] VERBOSE[323] pbx.c: [May 25 10:27:11]     -- Executing [37279250388118@default:2] Set("Local/37279250388118@default-000002a3;2", "GLOBAL(MYGLOBALVAR372)=79250388118") in new stack
[May 25 10:27:11] VERBOSE[323] pbx.c: [May 25 10:27:11]   == Setting global variable 'MYGLOBALVAR372' to '79250388118'
[May 25 10:27:11] VERBOSE[323] pbx.c: [May 25 10:27:11]     -- Executing [37279250388118@default:3] Dial("Local/37279250388118@default-000002a3;2", "SIP/vulcan1/37279250388118,,tTor") in new stack
[May 25 10:27:11] VERBOSE[323] netsock2.c: [May 25 10:27:11]   == Using SIP RTP CoS mark 5
[May 25 10:27:11] VERBOSE[323] app_dial.c: [May 25 10:27:11]     -- Called SIP/vulcan1/37279250388118
[May 25 10:27:11] VERBOSE[32623] manager.c: [May 25 10:27:11]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:11] VERBOSE[32624] res_agi.c: [May 25 10:27:11]     -- <Local/37279037002903@default-000002a1;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----10-----0 completed, returning 0
[May 25 10:27:11] VERBOSE[32624] pbx.c: [May 25 10:27:11]   == Spawn extension (default, 37279037002903, 3) exited non-zero on 'Local/37279037002903@default-000002a1;2'
[May 25 10:27:14] VERBOSE[321] app_dial.c: [May 25 10:27:14]     -- SIP/vulcan1-000001fb is ringing
[May 25 10:27:14] VERBOSE[321] app_dial.c: [May 25 10:27:14]     -- SIP/vulcan1-000001fb is ringing
[May 25 10:27:14] VERBOSE[321] app_dial.c: [May 25 10:27:14]     -- SIP/vulcan1-000001fb is making progress passing it to Local/37279265373151@default-000002a2;2
[May 25 10:27:17] VERBOSE[323] app_dial.c: [May 25 10:27:17]     -- SIP/vulcan1-000001fc is making progress passing it to Local/37279250388118@default-000002a3;2
[May 25 10:27:17] VERBOSE[323] app_dial.c: [May 25 10:27:17]     -- SIP/vulcan1-000001fc is ringing
[May 25 10:27:20] VERBOSE[306] pbx.c: [May 25 10:27:20]   == Spawn extension (pmi_menu_for_connect, s, 4) exited non-zero on 'SIP/vulcan1-000001fa'
[May 25 10:27:20] VERBOSE[306] pbx.c: [May 25 10:27:20]     -- Executing [h@pmi_menu_for_connect:1] AGI("SIP/vulcan1-000001fa", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:27:20] VERBOSE[306] res_agi.c: [May 25 10:27:20]     -- <SIP/vulcan1-000001fa>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:27:23] VERBOSE[424] manager.c: [May 25 10:27:23]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:23] VERBOSE[425] manager.c: [May 25 10:27:23]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:23] VERBOSE[32338] pbx.c: [May 25 10:27:23]   == Spawn extension (default, 58600053, 1) exited non-zero on 'Local/58600053@default-0000029c;2'
[May 25 10:27:23] VERBOSE[32338] pbx.c: [May 25 10:27:23]     -- Executing [h@default:1] AGI("Local/58600053@default-0000029c;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:27:23] VERBOSE[32338] res_agi.c: [May 25 10:27:23]     -- <Local/58600053@default-0000029c;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:27:23] VERBOSE[32339] pbx.c: [May 25 10:27:23]   == Spawn extension (default, 8309, 3) exited non-zero on 'Local/58600053@default-0000029c;1'
[May 25 10:27:23] VERBOSE[32339] pbx.c: [May 25 10:27:23]     -- Executing [h@default:1] AGI("Local/58600053@default-0000029c;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:27:23] VERBOSE[32339] res_agi.c: [May 25 10:27:23]     -- <Local/58600053@default-0000029c;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:27:23] VERBOSE[436] manager.c: [May 25 10:27:23]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:23] VERBOSE[437] pbx.c: [May 25 10:27:23]     -- Executing [37279262754526@default:1] AGI("Local/37279262754526@default-000002a4;2", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:27:23] VERBOSE[437] res_agi.c: [May 25 10:27:23]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:27:23] VERBOSE[437] res_agi.c: [May 25 10:27:23]     -- <Local/37279262754526@default-000002a4;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:27:23] VERBOSE[437] pbx.c: [May 25 10:27:23]     -- Executing [37279262754526@default:2] Set("Local/37279262754526@default-000002a4;2", "GLOBAL(MYGLOBALVAR372)=79262754526") in new stack
[May 25 10:27:23] VERBOSE[437] pbx.c: [May 25 10:27:23]   == Setting global variable 'MYGLOBALVAR372' to '79262754526'
[May 25 10:27:23] VERBOSE[437] pbx.c: [May 25 10:27:23]     -- Executing [37279262754526@default:3] Dial("Local/37279262754526@default-000002a4;2", "SIP/vulcan1/37279262754526,,tTor") in new stack
[May 25 10:27:23] VERBOSE[437] netsock2.c: [May 25 10:27:23]   == Using SIP RTP CoS mark 5
[May 25 10:27:23] VERBOSE[437] app_dial.c: [May 25 10:27:23]     -- Called SIP/vulcan1/37279262754526
[May 25 10:27:24] VERBOSE[5971] netsock2.c: [May 25 10:27:24]   == Using SIP RTP CoS mark 5
mangamen45@gmail.com
 
Posts: 10
Joined: Mon May 16, 2016 7:35 am

Re: Inbound Calls Discrepancy

Postby mflorell » Fri May 26, 2017 8:17 am

Wrong direction, need to see more output AFTER May 25 10:27:24
mflorell
Site Admin
 
Posts: 18335
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Re: Inbound Calls Discrepancy

Postby mangamen45@gmail.com » Fri May 26, 2017 8:24 am

mflorell wrote:Wrong direction, need to see more output AFTER May 25 10:27:24

https://drive.google.com/file/d/0B2XDRa ... sp=sharing - it's days full log

below aprt of this:
Code: Select all
[May 25 10:27:24] VERBOSE[5971] netsock2.c: [May 25 10:27:24]   == Using SIP RTP CoS mark 5
[May 25 10:27:24] VERBOSE[438] pbx.c: [May 25 10:27:24]     -- Executing [282709@trunkinbound:1] AGI("SIP/avaya_ru-000001fe", "agi-DID_route.agi") in new stack
[May 25 10:27:24] VERBOSE[438] res_agi.c: [May 25 10:27:24]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-DID_route.agi
[May 25 10:27:24] VERBOSE[438] res_agi.c: [May 25 10:27:24]     -- AGI Script Executing Application: (Monitor) Options: (wav,/var/spool/asterisk/monitor/MIX/20170525102724_282709_4995505366)
[May 25 10:27:24] VERBOSE[438] res_agi.c: [May 25 10:27:24]     -- <SIP/avaya_ru-000001fe>AGI Script agi-DID_route.agi completed, returning 0
[May 25 10:27:24] VERBOSE[438] pbx.c: [May 25 10:27:24]     -- Executing [99909*11***DID@default:1] Answer("SIP/avaya_ru-000001fe", "") in new stack
[May 25 10:27:24] VERBOSE[438] pbx.c: [May 25 10:27:24]     -- Executing [99909*11***DID@default:2] AGI("SIP/avaya_ru-000001fe", "agi-VDAD_ALL_inbound.agi") in new stack
[May 25 10:27:24] VERBOSE[438] res_agi.c: [May 25 10:27:24]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_inbound.agi
[May 25 10:27:24] VERBOSE[452] manager.c: [May 25 10:27:24]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:24] VERBOSE[453] pbx.c: [May 25 10:27:24]     -- Executing [8600055@default:1] MeetMe("Local/8600055@default-000002a5;2", "8600055,F") in new stack
[May 25 10:27:24] VERBOSE[452] pbx.c: [May 25 10:27:24]        > Channel Local/8600055@default-000002a5;1 was answered.
[May 25 10:27:24] VERBOSE[454] pbx.c: [May 25 10:27:24]     -- Executing [37279773611680@default:1] AGI("Local/8600055@default-000002a5;1", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:27:24] VERBOSE[454] res_agi.c: [May 25 10:27:24]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_TELE))
[May 25 10:27:24] VERBOSE[454] res_agi.c: [May 25 10:27:24]     -- <Local/8600055@default-000002a5;1>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:27:24] VERBOSE[454] pbx.c: [May 25 10:27:24]     -- Executing [37279773611680@default:2] Set("Local/8600055@default-000002a5;1", "GLOBAL(MYGLOBALVAR372)=79773611680") in new stack
[May 25 10:27:24] VERBOSE[454] pbx.c: [May 25 10:27:24]   == Setting global variable 'MYGLOBALVAR372' to '79773611680'
[May 25 10:27:24] VERBOSE[454] pbx.c: [May 25 10:27:24]     -- Executing [37279773611680@default:3] Dial("Local/8600055@default-000002a5;1", "SIP/vulcan1/37279773611680,,tTor") in new stack
[May 25 10:27:24] VERBOSE[454] netsock2.c: [May 25 10:27:24]   == Using SIP RTP CoS mark 5
[May 25 10:27:24] VERBOSE[454] app_dial.c: [May 25 10:27:24]     -- Called SIP/vulcan1/37279773611680
[May 25 10:27:24] VERBOSE[424] manager.c: [May 25 10:27:24]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:24] VERBOSE[438] res_agi.c: [May 25 10:27:24]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:24] VERBOSE[438] res_agi.c: [May 25 10:27:24]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:24] VERBOSE[425] manager.c: [May 25 10:27:24]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:25] VERBOSE[471] manager.c: [May 25 10:27:25]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:25] VERBOSE[472] pbx.c: [May 25 10:27:25]     -- Executing [58600055@default:1] MeetMe("Local/58600055@default-000002a6;2", "8600055,Fmq") in new stack
[May 25 10:27:25] VERBOSE[471] pbx.c: [May 25 10:27:25]        > Channel Local/58600055@default-000002a6;1 was answered.
[May 25 10:27:25] VERBOSE[473] pbx.c: [May 25 10:27:25]     -- Executing [8309@default:1] Answer("Local/58600055@default-000002a6;1", "") in new stack
[May 25 10:27:25] VERBOSE[473] pbx.c: [May 25 10:27:25]     -- Executing [8309@default:2] Monitor("Local/58600055@default-000002a6;1", "wav,PMI_TELE_20170525-102724_glugovskaya5_9773611680") in new stack
[May 25 10:27:25] VERBOSE[473] pbx.c: [May 25 10:27:25]     -- Executing [8309@default:3] Wait("Local/58600055@default-000002a6;1", "3600") in new stack
[May 25 10:27:25] VERBOSE[452] manager.c: [May 25 10:27:25]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:25] VERBOSE[482] manager.c: [May 25 10:27:25]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:25] VERBOSE[483] pbx.c: [May 25 10:27:25]     -- Executing [010*207*024*152*78600087@default:1] Goto("Local/010*207*024*152*78600087@default-000002a7;2", "default,78600087,1") in new stack
[May 25 10:27:25] VERBOSE[483] pbx.c: [May 25 10:27:25]     -- Goto (default,78600087,1)
[May 25 10:27:25] VERBOSE[483] pbx.c: [May 25 10:27:25]     -- Executing [78600087@default:1] MeetMe("Local/010*207*024*152*78600087@default-000002a7;2", "8600087,Fq") in new stack
[May 25 10:27:25] VERBOSE[482] pbx.c: [May 25 10:27:25]        > Channel Local/010*207*024*152*78600087@default-000002a7;1 was answered.
[May 25 10:27:25] VERBOSE[484] manager.c: [May 25 10:27:25]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:25] VERBOSE[485] pbx.c: [May 25 10:27:25]     -- Executing [83047777777777@vicidial-auto:1] Answer("Local/010*207*024*152*78600087@default-000002a7;1", "") in new stack
[May 25 10:27:25] VERBOSE[485] pbx.c: [May 25 10:27:25]     -- Executing [83047777777777@vicidial-auto:2] Playback("Local/010*207*024*152*78600087@default-000002a7;1", "ding") in new stack
[May 25 10:27:25] VERBOSE[453] pbx.c: [May 25 10:27:25]   == Spawn extension (default, 8600055, 1) exited non-zero on 'Local/8600055@default-000002a5;2'
[May 25 10:27:25] VERBOSE[453] pbx.c: [May 25 10:27:25]     -- Executing [h@default:1] AGI("Local/8600055@default-000002a5;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:27:25] VERBOSE[485] file.c: [May 25 10:27:25]     -- <Local/010*207*024*152*78600087@default-000002a7;1> Playing 'ding.gsm' (language 'en')
[May 25 10:27:25] VERBOSE[453] res_agi.c: [May 25 10:27:25]     -- <Local/8600055@default-000002a5;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:27:25] VERBOSE[454] pbx.c: [May 25 10:27:25]   == Spawn extension (default, 37279773611680, 3) exited non-zero on 'Local/8600055@default-000002a5;1'
[May 25 10:27:25] VERBOSE[454] pbx.c: [May 25 10:27:25]     -- Executing [h@default:1] AGI("Local/8600055@default-000002a5;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL----------") in new stack
[May 25 10:27:25] VERBOSE[486] manager.c: [May 25 10:27:25]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:25] VERBOSE[454] res_agi.c: [May 25 10:27:25]     -- <Local/8600055@default-000002a5;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL---------- completed, returning 0
[May 25 10:27:25] VERBOSE[485] pbx.c: [May 25 10:27:25]     -- Executing [83047777777777@vicidial-auto:3] Hangup("Local/010*207*024*152*78600087@default-000002a7;1", "") in new stack
[May 25 10:27:25] VERBOSE[485] pbx.c: [May 25 10:27:25]   == Spawn extension (vicidial-auto, 83047777777777, 3) exited non-zero on 'Local/010*207*024*152*78600087@default-000002a7;1'
[May 25 10:27:25] VERBOSE[485] pbx.c: [May 25 10:27:25]     -- Executing [h@vicidial-auto:1] AGI("Local/010*207*024*152*78600087@default-000002a7;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
[May 25 10:27:25] VERBOSE[485] res_agi.c: [May 25 10:27:25]     -- <Local/010*207*024*152*78600087@default-000002a7;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0
[May 25 10:27:25] VERBOSE[483] pbx.c: [May 25 10:27:25]   == Spawn extension (default, 78600087, 1) exited non-zero on 'Local/010*207*024*152*78600087@default-000002a7;2'
[May 25 10:27:25] VERBOSE[483] pbx.c: [May 25 10:27:25]     -- Executing [h@default:1] AGI("Local/010*207*024*152*78600087@default-000002a7;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:27:25] VERBOSE[483] res_agi.c: [May 25 10:27:25]     -- <Local/010*207*024*152*78600087@default-000002a7;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:27:26] VERBOSE[471] manager.c: [May 25 10:27:26]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:26] VERBOSE[438] res_agi.c: [May 25 10:27:26]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:26] VERBOSE[438] res_agi.c: [May 25 10:27:26]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:26] VERBOSE[482] manager.c: [May 25 10:27:26]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:26] VERBOSE[484] manager.c: [May 25 10:27:26]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:26] VERBOSE[486] manager.c: [May 25 10:27:26]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:27] VERBOSE[438] res_agi.c: [May 25 10:27:27]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:27] VERBOSE[438] res_agi.c: [May 25 10:27:27]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:27] VERBOSE[438] res_agi.c: [May 25 10:27:27]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:27] VERBOSE[438] res_agi.c: [May 25 10:27:27]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:27] VERBOSE[438] res_agi.c: [May 25 10:27:27]     -- <SIP/avaya_ru-000001fe>AGI Script agi-VDAD_ALL_inbound.agi completed, returning 0
[May 25 10:27:27] VERBOSE[438] pbx.c: [May 25 10:27:27]     -- Executing [010*207*024*152*8600087@default:1] Goto("SIP/avaya_ru-000001fe", "default,8600087,1") in new stack
[May 25 10:27:27] VERBOSE[438] pbx.c: [May 25 10:27:27]     -- Goto (default,8600087,1)
[May 25 10:27:27] VERBOSE[438] pbx.c: [May 25 10:27:27]     -- Executing [8600087@default:1] MeetMe("SIP/avaya_ru-000001fe", "8600087,F") in new stack
[May 25 10:27:40] VERBOSE[320] manager.c: [May 25 10:27:40]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:40] VERBOSE[321] pbx.c: [May 25 10:27:40]   == Spawn extension (default, 37279265373151, 3) exited non-zero on 'Local/37279265373151@default-000002a2;2'
[May 25 10:27:40] VERBOSE[321] pbx.c: [May 25 10:27:40]     -- Executing [h@default:1] AGI("Local/37279265373151@default-000002a2;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL----------") in new stack
[May 25 10:27:41] VERBOSE[323] pbx.c: [May 25 10:27:41]   == Spawn extension (default, 37279250388118, 3) exited non-zero on 'Local/37279250388118@default-000002a3;2'
[May 25 10:27:41] VERBOSE[322] manager.c: [May 25 10:27:41]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:41] VERBOSE[323] pbx.c: [May 25 10:27:41]     -- Executing [h@default:1] AGI("Local/37279250388118@default-000002a3;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL----------") in new stack
[May 25 10:27:42] VERBOSE[321] res_agi.c: [May 25 10:27:42]     -- <Local/37279265373151@default-000002a2;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL---------- completed, returning 0
[May 25 10:27:42] VERBOSE[323] res_agi.c: [May 25 10:27:42]     -- <Local/37279250388118@default-000002a3;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL---------- completed, returning 0
[May 25 10:27:44] VERBOSE[437] app_dial.c: [May 25 10:27:44]     -- SIP/vulcan1-000001fd is making progress passing it to Local/37279262754526@default-000002a4;2
[May 25 10:27:45] VERBOSE[437] app_dial.c: [May 25 10:27:45]     -- SIP/vulcan1-000001fd is ringing
[May 25 10:27:50] VERBOSE[627] manager.c: [May 25 10:27:50]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:50] VERBOSE[628] pbx.c: [May 25 10:27:50]     -- Executing [8600055@default:1] MeetMe("Local/8600055@default-000002a8;2", "8600055,F") in new stack
[May 25 10:27:50] VERBOSE[627] pbx.c: [May 25 10:27:50]        > Channel Local/8600055@default-000002a8;1 was answered.
[May 25 10:27:50] VERBOSE[629] pbx.c: [May 25 10:27:50]     -- Executing [37279681660003@default:1] AGI("Local/8600055@default-000002a8;1", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:27:50] VERBOSE[629] res_agi.c: [May 25 10:27:50]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_TELE))
[May 25 10:27:50] VERBOSE[629] res_agi.c: [May 25 10:27:50]     -- <Local/8600055@default-000002a8;1>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:27:50] VERBOSE[629] pbx.c: [May 25 10:27:50]     -- Executing [37279681660003@default:2] Set("Local/8600055@default-000002a8;1", "GLOBAL(MYGLOBALVAR372)=79681660003") in new stack
[May 25 10:27:50] VERBOSE[629] pbx.c: [May 25 10:27:50]   == Setting global variable 'MYGLOBALVAR372' to '79681660003'
[May 25 10:27:50] VERBOSE[629] pbx.c: [May 25 10:27:50]     -- Executing [37279681660003@default:3] Dial("Local/8600055@default-000002a8;1", "SIP/vulcan1/37279681660003,,tTor") in new stack
[May 25 10:27:50] VERBOSE[629] netsock2.c: [May 25 10:27:50]   == Using SIP RTP CoS mark 5
[May 25 10:27:50] VERBOSE[629] app_dial.c: [May 25 10:27:50]     -- Called SIP/vulcan1/37279681660003
[May 25 10:27:51] VERBOSE[633] manager.c: [May 25 10:27:51]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:51] VERBOSE[634] pbx.c: [May 25 10:27:51]     -- Executing [58600055@default:1] MeetMe("Local/58600055@default-000002a9;2", "8600055,Fmq") in new stack
[May 25 10:27:51] VERBOSE[633] pbx.c: [May 25 10:27:51]        > Channel Local/58600055@default-000002a9;1 was answered.
[May 25 10:27:51] VERBOSE[635] pbx.c: [May 25 10:27:51]     -- Executing [8309@default:1] Answer("Local/58600055@default-000002a9;1", "") in new stack
[May 25 10:27:51] VERBOSE[635] pbx.c: [May 25 10:27:51]     -- Executing [8309@default:2] Monitor("Local/58600055@default-000002a9;1", "wav,PMI_TELE_20170525-102750_glugovskaya5_9681660003") in new stack
[May 25 10:27:51] VERBOSE[635] pbx.c: [May 25 10:27:51]     -- Executing [8309@default:3] Wait("Local/58600055@default-000002a9;1", "3600") in new stack
[May 25 10:27:51] VERBOSE[437] app_dial.c: [May 25 10:27:51]     -- SIP/vulcan1-000001fd answered Local/37279262754526@default-000002a4;2
[May 25 10:27:51] VERBOSE[436] pbx.c: [May 25 10:27:51]        > Channel Local/37279262754526@default-000002a4;1 was answered.
[May 25 10:27:51] VERBOSE[436] manager.c: [May 25 10:27:51]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:51] VERBOSE[636] pbx.c: [May 25 10:27:51]     -- Executing [8366@default:1] Playback("Local/37279262754526@default-000002a4;1", "sip-silence") in new stack
[May 25 10:27:51] VERBOSE[636] file.c: [May 25 10:27:51]     -- <Local/37279262754526@default-000002a4;1> Playing 'sip-silence.gsm' (language 'en')
[May 25 10:27:51] VERBOSE[437] pbx.c: [May 25 10:27:51]     -- Executing [h@default:1] AGI("Local/37279262754526@default-000002a4;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----28-----0") in new stack
[May 25 10:27:51] VERBOSE[636] pbx.c: [May 25 10:27:51]     -- Executing [8366@default:2] AGI("SIP/vulcan1-000001fd", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:27:51] VERBOSE[636] res_agi.c: [May 25 10:27:51]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:27:51] VERBOSE[636] res_agi.c: [May 25 10:27:51]     -- <SIP/vulcan1-000001fd>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:27:51] VERBOSE[636] pbx.c: [May 25 10:27:51]     -- Executing [8366@default:3] AGI("SIP/vulcan1-000001fd", "agi-VDAD_ALL_outbound.agi,SURVEYCAMP-----LB") in new stack
[May 25 10:27:51] VERBOSE[636] res_agi.c: [May 25 10:27:51]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[May 25 10:27:51] VERBOSE[651] manager.c: [May 25 10:27:51]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:51] VERBOSE[652] pbx.c: [May 25 10:27:51]     -- Executing [8600114@default:1] MeetMe("Local/8600114@default-000002aa;2", "8600114,F") in new stack
[May 25 10:27:51] VERBOSE[651] pbx.c: [May 25 10:27:51]        > Channel Local/8600114@default-000002aa;1 was answered.
[May 25 10:27:51] VERBOSE[653] pbx.c: [May 25 10:27:51]     -- Executing [37279198080585@default:1] AGI("Local/8600114@default-000002aa;1", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:27:51] VERBOSE[653] res_agi.c: [May 25 10:27:51]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_TELE))
[May 25 10:27:51] VERBOSE[653] res_agi.c: [May 25 10:27:51]     -- <Local/8600114@default-000002aa;1>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:27:51] VERBOSE[653] pbx.c: [May 25 10:27:51]     -- Executing [37279198080585@default:2] Set("Local/8600114@default-000002aa;1", "GLOBAL(MYGLOBALVAR372)=79198080585") in new stack
[May 25 10:27:51] VERBOSE[653] pbx.c: [May 25 10:27:51]   == Setting global variable 'MYGLOBALVAR372' to '79198080585'
[May 25 10:27:51] VERBOSE[653] pbx.c: [May 25 10:27:51]     -- Executing [37279198080585@default:3] Dial("Local/8600114@default-000002aa;1", "SIP/vulcan1/37279198080585,,tTor") in new stack
[May 25 10:27:51] VERBOSE[653] netsock2.c: [May 25 10:27:51]   == Using SIP RTP CoS mark 5
[May 25 10:27:51] VERBOSE[653] app_dial.c: [May 25 10:27:51]     -- Called SIP/vulcan1/37279198080585
[May 25 10:27:51] VERBOSE[627] manager.c: [May 25 10:27:51]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:51] VERBOSE[636] res_agi.c: [May 25 10:27:51]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:51] VERBOSE[636] res_agi.c: [May 25 10:27:51]     -- <SIP/vulcan1-000001fd>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[May 25 10:27:51] VERBOSE[636] pbx.c: [May 25 10:27:51]     -- Executing [s@pmi_menu_for_connect:1] Answer("SIP/vulcan1-000001fd", "") in new stack
[May 25 10:27:51] VERBOSE[636] pbx.c: [May 25 10:27:51]     -- Executing [s@pmi_menu_for_connect:2] AGI("SIP/vulcan1-000001fd", "agi-VDAD_inbound_calltime_check.agi,CALLMENU-----YES-----pmi_menu_for_connect-------------------------NO") in new stack
[May 25 10:27:51] VERBOSE[636] res_agi.c: [May 25 10:27:51]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_inbound_calltime_check.agi
[May 25 10:27:51] VERBOSE[636] res_agi.c: [May 25 10:27:51]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:51] VERBOSE[636] res_agi.c: [May 25 10:27:51]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:27:52] VERBOSE[636] res_agi.c: [May 25 10:27:52]     -- <SIP/vulcan1-000001fd>AGI Script agi-VDAD_inbound_calltime_check.agi completed, returning 0
[May 25 10:27:52] VERBOSE[636] pbx.c: [May 25 10:27:52]     -- Executing [s@pmi_menu_for_connect:3] Set("SIP/vulcan1-000001fd", "INVCOUNT=0") in new stack
[May 25 10:27:52] VERBOSE[636] pbx.c: [May 25 10:27:52]     -- Executing [s@pmi_menu_for_connect:4] BackGround("SIP/vulcan1-000001fd", "pmi_welcome_m_1") in new stack
[May 25 10:27:52] VERBOSE[636] file.c: [May 25 10:27:52]     -- <SIP/vulcan1-000001fd> Playing 'pmi_welcome_m_1.slin' (language 'en')
[May 25 10:27:52] VERBOSE[662] manager.c: [May 25 10:27:52]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:52] VERBOSE[663] pbx.c: [May 25 10:27:52]     -- Executing [58600114@default:1] MeetMe("Local/58600114@default-000002ab;2", "8600114,Fmq") in new stack
[May 25 10:27:52] VERBOSE[662] pbx.c: [May 25 10:27:52]        > Channel Local/58600114@default-000002ab;1 was answered.
[May 25 10:27:52] VERBOSE[664] pbx.c: [May 25 10:27:52]     -- Executing [8309@default:1] Answer("Local/58600114@default-000002ab;1", "") in new stack
[May 25 10:27:52] VERBOSE[664] pbx.c: [May 25 10:27:52]     -- Executing [8309@default:2] Monitor("Local/58600114@default-000002ab;1", "wav,PMI_TELE_20170525-102750_zhukova19_9198080585") in new stack
[May 25 10:27:52] VERBOSE[664] pbx.c: [May 25 10:27:52]     -- Executing [8309@default:3] Wait("Local/58600114@default-000002ab;1", "3600") in new stack
[May 25 10:27:52] VERBOSE[633] manager.c: [May 25 10:27:52]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:52] VERBOSE[437] res_agi.c: [May 25 10:27:52]     -- <Local/37279262754526@default-000002a4;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----28-----0 completed, returning 0
[May 25 10:27:52] VERBOSE[437] pbx.c: [May 25 10:27:52]   == Spawn extension (default, 37279262754526, 3) exited non-zero on 'Local/37279262754526@default-000002a4;2'
[May 25 10:27:52] VERBOSE[651] manager.c: [May 25 10:27:52]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:53] VERBOSE[662] manager.c: [May 25 10:27:53]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:27:53] VERBOSE[653] app_dial.c: [May 25 10:27:53]     -- SIP/vulcan1-00000201 is making progress passing it to Local/8600114@default-000002aa;1
[May 25 10:27:53] VERBOSE[629] app_dial.c: [May 25 10:27:53]     -- SIP/vulcan1-00000200 is making progress passing it to Local/8600055@default-000002a8;1
[May 25 10:27:54] VERBOSE[696] manager.c: [May 25 10:27:54]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:54] VERBOSE[697] pbx.c: [May 25 10:27:54]     -- Executing [37279672111696@default:1] AGI("Local/37279672111696@default-000002ac;2", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:27:54] VERBOSE[697] res_agi.c: [May 25 10:27:54]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:27:54] VERBOSE[697] res_agi.c: [May 25 10:27:54]     -- <Local/37279672111696@default-000002ac;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:27:54] VERBOSE[697] pbx.c: [May 25 10:27:54]     -- Executing [37279672111696@default:2] Set("Local/37279672111696@default-000002ac;2", "GLOBAL(MYGLOBALVAR372)=79672111696") in new stack
[May 25 10:27:54] VERBOSE[697] pbx.c: [May 25 10:27:54]   == Setting global variable 'MYGLOBALVAR372' to '79672111696'
[May 25 10:27:54] VERBOSE[697] pbx.c: [May 25 10:27:54]     -- Executing [37279672111696@default:3] Dial("Local/37279672111696@default-000002ac;2", "SIP/vulcan1/37279672111696,,tTor") in new stack
[May 25 10:27:54] VERBOSE[697] netsock2.c: [May 25 10:27:54]   == Using SIP RTP CoS mark 5
[May 25 10:27:54] VERBOSE[697] app_dial.c: [May 25 10:27:54]     -- Called SIP/vulcan1/37279672111696
[May 25 10:27:55] VERBOSE[697] app_dial.c: [May 25 10:27:55]     -- SIP/vulcan1-00000202 is ringing
[May 25 10:27:55] VERBOSE[697] app_dial.c: [May 25 10:27:55]     -- SIP/vulcan1-00000202 is making progress passing it to Local/37279672111696@default-000002ac;2
[May 25 10:27:57] VERBOSE[799] manager.c: [May 25 10:27:57]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:57] VERBOSE[800] pbx.c: [May 25 10:27:57]     -- Executing [37279685881206@default:1] AGI("Local/37279685881206@default-000002ad;2", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:27:57] VERBOSE[800] res_agi.c: [May 25 10:27:57]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:27:57] VERBOSE[800] res_agi.c: [May 25 10:27:57]     -- <Local/37279685881206@default-000002ad;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:27:57] VERBOSE[800] pbx.c: [May 25 10:27:57]     -- Executing [37279685881206@default:2] Set("Local/37279685881206@default-000002ad;2", "GLOBAL(MYGLOBALVAR372)=79685881206") in new stack
[May 25 10:27:57] VERBOSE[800] pbx.c: [May 25 10:27:57]   == Setting global variable 'MYGLOBALVAR372' to '79685881206'
[May 25 10:27:57] VERBOSE[800] pbx.c: [May 25 10:27:57]     -- Executing [37279685881206@default:3] Dial("Local/37279685881206@default-000002ad;2", "SIP/vulcan1/37279685881206,,tTor") in new stack
[May 25 10:27:57] VERBOSE[800] netsock2.c: [May 25 10:27:57]   == Using SIP RTP CoS mark 5
[May 25 10:27:57] VERBOSE[800] app_dial.c: [May 25 10:27:57]     -- Called SIP/vulcan1/37279685881206
[May 25 10:27:57] VERBOSE[801] manager.c: [May 25 10:27:57]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:27:57] VERBOSE[802] pbx.c: [May 25 10:27:57]     -- Executing [37279990951992@default:1] AGI("Local/37279990951992@default-000002ae;2", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:27:57] VERBOSE[802] res_agi.c: [May 25 10:27:57]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:27:57] VERBOSE[802] res_agi.c: [May 25 10:27:57]     -- <Local/37279990951992@default-000002ae;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:27:57] VERBOSE[802] pbx.c: [May 25 10:27:57]     -- Executing [37279990951992@default:2] Set("Local/37279990951992@default-000002ae;2", "GLOBAL(MYGLOBALVAR372)=79990951992") in new stack
[May 25 10:27:57] VERBOSE[802] pbx.c: [May 25 10:27:57]   == Setting global variable 'MYGLOBALVAR372' to '79990951992'
[May 25 10:27:57] VERBOSE[802] pbx.c: [May 25 10:27:57]     -- Executing [37279990951992@default:3] Dial("Local/37279990951992@default-000002ae;2", "SIP/vulcan1/37279990951992,,tTor") in new stack
[May 25 10:27:57] VERBOSE[802] netsock2.c: [May 25 10:27:57]   == Using SIP RTP CoS mark 5
[May 25 10:27:57] VERBOSE[802] app_dial.c: [May 25 10:27:57]     -- Called SIP/vulcan1/37279990951992
[May 25 10:27:57] VERBOSE[653] app_dial.c: [May 25 10:27:57]     -- SIP/vulcan1-00000201 is ringing
[May 25 10:27:57] VERBOSE[629] app_dial.c: [May 25 10:27:57]     -- SIP/vulcan1-00000200 is ringing
[May 25 10:27:58] VERBOSE[802] app_dial.c: [May 25 10:27:58]     -- SIP/vulcan1-00000204 is making progress passing it to Local/37279990951992@default-000002ae;2
[May 25 10:28:00] VERBOSE[629] app_dial.c: [May 25 10:28:00]     -- SIP/vulcan1-00000200 answered Local/8600055@default-000002a8;1
[May 25 10:28:00] VERBOSE[800] app_dial.c: [May 25 10:28:00]     -- SIP/vulcan1-00000203 is ringing
[May 25 10:28:00] VERBOSE[800] app_dial.c: [May 25 10:28:00]     -- SIP/vulcan1-00000203 is making progress passing it to Local/37279685881206@default-000002ad;2
[May 25 10:28:01] VERBOSE[843] manager.c: [May 25 10:28:01]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:01] VERBOSE[843] manager.c: [May 25 10:28:01]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:02] VERBOSE[862] manager.c: [May 25 10:28:02]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:02] VERBOSE[863] pbx.c: [May 25 10:28:02]     -- Executing [8600116@default:1] MeetMe("Local/8600116@default-000002af;2", "8600116,F") in new stack
[May 25 10:28:02] VERBOSE[862] pbx.c: [May 25 10:28:02]        > Channel Local/8600116@default-000002af;1 was answered.
[May 25 10:28:02] VERBOSE[864] pbx.c: [May 25 10:28:02]     -- Executing [37279006778220@default:1] AGI("Local/8600116@default-000002af;1", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:28:02] VERBOSE[864] res_agi.c: [May 25 10:28:02]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=GOOGLEAW))
[May 25 10:28:02] VERBOSE[864] res_agi.c: [May 25 10:28:02]     -- <Local/8600116@default-000002af;1>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:28:02] VERBOSE[864] pbx.c: [May 25 10:28:02]     -- Executing [37279006778220@default:2] Set("Local/8600116@default-000002af;1", "GLOBAL(MYGLOBALVAR372)=79006778220") in new stack
[May 25 10:28:02] VERBOSE[864] pbx.c: [May 25 10:28:02]   == Setting global variable 'MYGLOBALVAR372' to '79006778220'
[May 25 10:28:02] VERBOSE[864] pbx.c: [May 25 10:28:02]     -- Executing [37279006778220@default:3] Dial("Local/8600116@default-000002af;1", "SIP/vulcan1/37279006778220,,tTor") in new stack
[May 25 10:28:02] VERBOSE[864] netsock2.c: [May 25 10:28:02]   == Using SIP RTP CoS mark 5
[May 25 10:28:02] VERBOSE[864] app_dial.c: [May 25 10:28:02]     -- Called SIP/vulcan1/37279006778220
[May 25 10:28:02] VERBOSE[867] manager.c: [May 25 10:28:02]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:02] VERBOSE[868] pbx.c: [May 25 10:28:02]     -- Executing [58600116@default:1] MeetMe("Local/58600116@default-000002b0;2", "8600116,Fmq") in new stack
[May 25 10:28:02] VERBOSE[867] pbx.c: [May 25 10:28:02]        > Channel Local/58600116@default-000002b0;1 was answered.
[May 25 10:28:02] VERBOSE[869] pbx.c: [May 25 10:28:02]     -- Executing [8309@default:1] Answer("Local/58600116@default-000002b0;1", "") in new stack
[May 25 10:28:02] VERBOSE[869] pbx.c: [May 25 10:28:02]     -- Executing [8309@default:2] Monitor("Local/58600116@default-000002b0;1", "wav,GOOGLEAW_20170525-102801_akhrimenko.5_9006778220") in new stack
[May 25 10:28:02] VERBOSE[869] pbx.c: [May 25 10:28:02]     -- Executing [8309@default:3] Wait("Local/58600116@default-000002b0;1", "3600") in new stack
[May 25 10:28:03] VERBOSE[874] manager.c: [May 25 10:28:03]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:03] VERBOSE[864] pbx.c: [May 25 10:28:03]   == Spawn extension (default, 37279006778220, 3) exited non-zero on 'Local/8600116@default-000002af;1'
[May 25 10:28:03] VERBOSE[864] pbx.c: [May 25 10:28:03]     -- Executing [h@default:1] AGI("Local/8600116@default-000002af;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL----------") in new stack
[May 25 10:28:03] VERBOSE[862] manager.c: [May 25 10:28:03]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:03] VERBOSE[864] res_agi.c: [May 25 10:28:03]     -- <Local/8600116@default-000002af;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL---------- completed, returning 0
[May 25 10:28:03] VERBOSE[863] pbx.c: [May 25 10:28:03]   == Spawn extension (default, 8600116, 1) exited non-zero on 'Local/8600116@default-000002af;2'
[May 25 10:28:03] VERBOSE[863] pbx.c: [May 25 10:28:03]     -- Executing [h@default:1] AGI("Local/8600116@default-000002af;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:28:03] VERBOSE[863] res_agi.c: [May 25 10:28:03]     -- <Local/8600116@default-000002af;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:28:03] VERBOSE[881] manager.c: [May 25 10:28:03]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:03] VERBOSE[867] manager.c: [May 25 10:28:03]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:03] VERBOSE[882] manager.c: [May 25 10:28:03]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:03] VERBOSE[868] pbx.c: [May 25 10:28:03]   == Spawn extension (default, 58600116, 1) exited non-zero on 'Local/58600116@default-000002b0;2'
[May 25 10:28:03] VERBOSE[868] pbx.c: [May 25 10:28:03]     -- Executing [h@default:1] AGI("Local/58600116@default-000002b0;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:28:03] VERBOSE[868] res_agi.c: [May 25 10:28:03]     -- <Local/58600116@default-000002b0;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:28:03] VERBOSE[869] pbx.c: [May 25 10:28:03]   == Spawn extension (default, 8309, 3) exited non-zero on 'Local/58600116@default-000002b0;1'
[May 25 10:28:03] VERBOSE[869] pbx.c: [May 25 10:28:03]     -- Executing [h@default:1] AGI("Local/58600116@default-000002b0;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:28:03] VERBOSE[869] res_agi.c: [May 25 10:28:03]     -- <Local/58600116@default-000002b0;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:28:04] VERBOSE[874] manager.c: [May 25 10:28:04]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:04] VERBOSE[881] manager.c: [May 25 10:28:04]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:04] VERBOSE[882] manager.c: [May 25 10:28:04]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:05] VERBOSE[3705] chan_sip.c: [May 25 10:28:05]     -- Got SIP response 480 "Temporarily Unavailable" back from 10.207.120.154:5060
[May 25 10:28:05] VERBOSE[697] app_dial.c: [May 25 10:28:05]     -- SIP/vulcan1-00000202 is circuit-busy
[May 25 10:28:05] VERBOSE[697] app_dial.c: [May 25 10:28:05]   == Everyone is busy/congested at this time (1:0/1/0)
[May 25 10:28:05] VERBOSE[697] pbx.c: [May 25 10:28:05]     -- Executing [37279672111696@default:4] Hangup("Local/37279672111696@default-000002ac;2", "") in new stack
[May 25 10:28:05] VERBOSE[697] pbx.c: [May 25 10:28:05]   == Spawn extension (default, 37279672111696, 4) exited non-zero on 'Local/37279672111696@default-000002ac;2'
[May 25 10:28:05] VERBOSE[697] pbx.c: [May 25 10:28:05]     -- Executing [h@default:1] AGI("Local/37279672111696@default-000002ac;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----19-----CONGESTION----------") in new stack
[May 25 10:28:06] VERBOSE[697] res_agi.c: [May 25 10:28:06]     -- <Local/37279672111696@default-000002ac;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----19-----CONGESTION---------- completed, returning 0
[May 25 10:28:06] VERBOSE[902] manager.c: [May 25 10:28:06]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:06] VERBOSE[902] manager.c: [May 25 10:28:06]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:06] VERBOSE[800] app_dial.c: [May 25 10:28:06]     -- SIP/vulcan1-00000203 answered Local/37279685881206@default-000002ad;2
[May 25 10:28:06] VERBOSE[799] pbx.c: [May 25 10:28:06]        > Channel Local/37279685881206@default-000002ad;1 was answered.
[May 25 10:28:06] VERBOSE[911] pbx.c: [May 25 10:28:06]     -- Executing [8366@default:1] Playback("Local/37279685881206@default-000002ad;1", "sip-silence") in new stack
[May 25 10:28:06] VERBOSE[911] file.c: [May 25 10:28:06]     -- <Local/37279685881206@default-000002ad;1> Playing 'sip-silence.gsm' (language 'en')
[May 25 10:28:06] VERBOSE[800] pbx.c: [May 25 10:28:06]     -- Executing [h@default:1] AGI("Local/37279685881206@default-000002ad;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----9-----0") in new stack
[May 25 10:28:06] VERBOSE[911] pbx.c: [May 25 10:28:06]     -- Executing [8366@default:2] AGI("SIP/vulcan1-00000203", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:28:06] VERBOSE[911] res_agi.c: [May 25 10:28:06]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:28:06] VERBOSE[911] res_agi.c: [May 25 10:28:06]     -- <SIP/vulcan1-00000203>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:28:06] VERBOSE[911] pbx.c: [May 25 10:28:06]     -- Executing [8366@default:3] AGI("SIP/vulcan1-00000203", "agi-VDAD_ALL_outbound.agi,SURVEYCAMP-----LB") in new stack
[May 25 10:28:06] VERBOSE[911] res_agi.c: [May 25 10:28:06]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[May 25 10:28:07] VERBOSE[911] res_agi.c: [May 25 10:28:07]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:28:07] VERBOSE[696] manager.c: [May 25 10:28:07]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:07] VERBOSE[911] res_agi.c: [May 25 10:28:07]     -- <SIP/vulcan1-00000203>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[May 25 10:28:07] VERBOSE[911] pbx.c: [May 25 10:28:07]     -- Executing [s@pmi_menu_for_connect:1] Answer("SIP/vulcan1-00000203", "") in new stack
[May 25 10:28:07] VERBOSE[911] pbx.c: [May 25 10:28:07]     -- Executing [s@pmi_menu_for_connect:2] AGI("SIP/vulcan1-00000203", "agi-VDAD_inbound_calltime_check.agi,CALLMENU-----YES-----pmi_menu_for_connect-------------------------NO") in new stack
[May 25 10:28:07] VERBOSE[911] res_agi.c: [May 25 10:28:07]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_inbound_calltime_check.agi
[May 25 10:28:07] VERBOSE[911] res_agi.c: [May 25 10:28:07]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:28:07] VERBOSE[911] res_agi.c: [May 25 10:28:07]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:28:07] VERBOSE[911] res_agi.c: [May 25 10:28:07]     -- <SIP/vulcan1-00000203>AGI Script agi-VDAD_inbound_calltime_check.agi completed, returning 0
[May 25 10:28:07] VERBOSE[911] pbx.c: [May 25 10:28:07]     -- Executing [s@pmi_menu_for_connect:3] Set("SIP/vulcan1-00000203", "INVCOUNT=0") in new stack
[May 25 10:28:07] VERBOSE[911] pbx.c: [May 25 10:28:07]     -- Executing [s@pmi_menu_for_connect:4] BackGround("SIP/vulcan1-00000203", "pmi_welcome_m_1") in new stack
[May 25 10:28:07] VERBOSE[911] file.c: [May 25 10:28:07]     -- <SIP/vulcan1-00000203> Playing 'pmi_welcome_m_1.slin' (language 'en')
[May 25 10:28:07] VERBOSE[799] manager.c: [May 25 10:28:07]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:07] VERBOSE[3705] chan_sip.c: [May 25 10:28:07]     -- Got SIP response 480 "Temporarily Unavailable" back from 10.207.120.154:5060
[May 25 10:28:07] VERBOSE[802] app_dial.c: [May 25 10:28:07]     -- SIP/vulcan1-00000204 is circuit-busy
[May 25 10:28:07] VERBOSE[802] app_dial.c: [May 25 10:28:07]   == Everyone is busy/congested at this time (1:0/1/0)
[May 25 10:28:07] VERBOSE[802] pbx.c: [May 25 10:28:07]     -- Executing [37279990951992@default:4] Hangup("Local/37279990951992@default-000002ae;2", "") in new stack
[May 25 10:28:07] VERBOSE[802] pbx.c: [May 25 10:28:07]   == Spawn extension (default, 37279990951992, 4) exited non-zero on 'Local/37279990951992@default-000002ae;2'
[May 25 10:28:07] VERBOSE[802] pbx.c: [May 25 10:28:07]     -- Executing [h@default:1] AGI("Local/37279990951992@default-000002ae;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----19-----CONGESTION----------") in new stack
[May 25 10:28:07] VERBOSE[800] res_agi.c: [May 25 10:28:07]     -- <Local/37279685881206@default-000002ad;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----9-----0 completed, returning 0
[May 25 10:28:07] VERBOSE[800] pbx.c: [May 25 10:28:07]   == Spawn extension (default, 37279685881206, 3) exited non-zero on 'Local/37279685881206@default-000002ad;2'
[May 25 10:28:08] VERBOSE[931] manager.c: [May 25 10:28:08]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:08] VERBOSE[932] manager.c: [May 25 10:28:08]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:08] VERBOSE[933] pbx.c: [May 25 10:28:08]     -- Executing [55558600116@default:1] MeetMeAdmin("Local/55558600116@default-000002b1;2", "8600116,K") in new stack
[May 25 10:28:08] VERBOSE[933] pbx.c: [May 25 10:28:08]     -- Executing [55558600116@default:2] Hangup("Local/55558600116@default-000002b1;2", "") in new stack
[May 25 10:28:08] VERBOSE[933] pbx.c: [May 25 10:28:08]   == Spawn extension (default, 55558600116, 2) exited non-zero on 'Local/55558600116@default-000002b1;2'
[May 25 10:28:08] VERBOSE[933] pbx.c: [May 25 10:28:08]     -- Executing [h@default:1] AGI("Local/55558600116@default-000002b1;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
[May 25 10:28:08] VERBOSE[24348] file.c: [May 25 10:28:08]     -- <SIP/avaya_ru-00000186> Playing 'conf-kicked.alaw' (language 'en')
[May 25 10:28:08] VERBOSE[933] res_agi.c: [May 25 10:28:08]     -- <Local/55558600116@default-000002b1;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0
[May 25 10:28:08] VERBOSE[802] res_agi.c: [May 25 10:28:08]     -- <Local/37279990951992@default-000002ae;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----19-----CONGESTION---------- completed, returning 0
[May 25 10:28:09] VERBOSE[931] manager.c: [May 25 10:28:09]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:09] VERBOSE[932] manager.c: [May 25 10:28:09]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:09] VERBOSE[438] pbx.c: [May 25 10:28:09]   == Spawn extension (default, 8600087, 1) exited non-zero on 'SIP/avaya_ru-000001fe'
[May 25 10:28:09] VERBOSE[438] pbx.c: [May 25 10:28:09]     -- Executing [h@default:1] AGI("SIP/avaya_ru-000001fe", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:28:09] VERBOSE[438] res_agi.c: [May 25 10:28:09]     -- <SIP/avaya_ru-000001fe>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:28:09] VERBOSE[947] manager.c: [May 25 10:28:09]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:09] VERBOSE[948] pbx.c: [May 25 10:28:09]     -- Executing [37279264356165@default:1] AGI("Local/37279264356165@default-000002b2;2", "agi://127.0.0.1:4577/call_log") in new stack
[May 25 10:28:09] VERBOSE[948] res_agi.c: [May 25 10:28:09]     -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=PMI_OUT2))
[May 25 10:28:09] VERBOSE[948] res_agi.c: [May 25 10:28:09]     -- <Local/37279264356165@default-000002b2;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[May 25 10:28:09] VERBOSE[948] pbx.c: [May 25 10:28:09]     -- Executing [37279264356165@default:2] Set("Local/37279264356165@default-000002b2;2", "GLOBAL(MYGLOBALVAR372)=79264356165") in new stack
[May 25 10:28:09] VERBOSE[948] pbx.c: [May 25 10:28:09]   == Setting global variable 'MYGLOBALVAR372' to '79264356165'
[May 25 10:28:09] VERBOSE[948] pbx.c: [May 25 10:28:09]     -- Executing [37279264356165@default:3] Dial("Local/37279264356165@default-000002b2;2", "SIP/vulcan1/37279264356165,,tTor") in new stack
[May 25 10:28:09] VERBOSE[948] netsock2.c: [May 25 10:28:09]   == Using SIP RTP CoS mark 5
[May 25 10:28:09] VERBOSE[948] app_dial.c: [May 25 10:28:09]     -- Called SIP/vulcan1/37279264356165
[May 25 10:28:09] VERBOSE[801] manager.c: [May 25 10:28:09]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:11] VERBOSE[24348] chan_dahdi.c: [May 25 10:28:11]     -- Hungup 'DAHDI/pseudo-943897817'
[May 25 10:28:11] VERBOSE[24348] pbx.c: [May 25 10:28:11]     -- Executing [8600116@default:2] Hangup("SIP/avaya_ru-00000186", "") in new stack
[May 25 10:28:11] VERBOSE[24348] pbx.c: [May 25 10:28:11]   == Spawn extension (default, 8600116, 2) exited non-zero on 'SIP/avaya_ru-00000186'
[May 25 10:28:11] VERBOSE[24348] pbx.c: [May 25 10:28:11]     -- Executing [h@default:1] AGI("SIP/avaya_ru-00000186", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
[May 25 10:28:11] VERBOSE[24348] res_agi.c: [May 25 10:28:11]     -- <SIP/avaya_ru-00000186>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0

[May 25 10:28:13] VERBOSE[5971] netsock2.c: [May 25 10:28:13]   == Using SIP RTP CoS mark 5
[May 25 10:28:13] VERBOSE[969] pbx.c: [May 25 10:28:13]     -- Executing [282709@trunkinbound:1] AGI("SIP/avaya_ru-00000207", "agi-DID_route.agi") in new stack
[May 25 10:28:13] VERBOSE[969] res_agi.c: [May 25 10:28:13]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-DID_route.agi
[May 25 10:28:13] VERBOSE[969] res_agi.c: [May 25 10:28:13]     -- AGI Script Executing Application: (Monitor) Options: (wav,/var/spool/asterisk/monitor/MIX/20170525102813_282709_4995505366)
[May 25 10:28:13] VERBOSE[969] res_agi.c: [May 25 10:28:13]     -- <SIP/avaya_ru-00000207>AGI Script agi-DID_route.agi completed, returning 0
[May 25 10:28:13] VERBOSE[969] pbx.c: [May 25 10:28:13]     -- Executing [99909*11***DID@default:1] Answer("SIP/avaya_ru-00000207", "") in new stack
[May 25 10:28:14] VERBOSE[969] pbx.c: [May 25 10:28:14]     -- Executing [99909*11***DID@default:2] AGI("SIP/avaya_ru-00000207", "agi-VDAD_ALL_inbound.agi") in new stack
[May 25 10:28:14] VERBOSE[969] res_agi.c: [May 25 10:28:14]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_inbound.agi
[May 25 10:28:14] VERBOSE[969] res_agi.c: [May 25 10:28:14]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:28:14] VERBOSE[969] res_agi.c: [May 25 10:28:14]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:28:16] VERBOSE[969] res_musiconhold.c: [May 25 10:28:16]     -- Started music on hold, class 'good_music', on SIP/avaya_ru-00000207
[May 25 10:28:16] VERBOSE[636] pbx.c: [May 25 10:28:16]     -- Executing [s@pmi_menu_for_connect:5] WaitExten("SIP/vulcan1-000001fd", "5") in new stack
[May 25 10:28:17] VERBOSE[948] app_dial.c: [May 25 10:28:17]     -- SIP/vulcan1-00000206 is ringing
[May 25 10:28:18] VERBOSE[948] app_dial.c: [May 25 10:28:18]     -- SIP/vulcan1-00000206 is ringing
[May 25 10:28:18] VERBOSE[1007] manager.c: [May 25 10:28:18]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:18] VERBOSE[1008] pbx.c: [May 25 10:28:18]     -- Executing [010*207*024*152*78600096@default:1] Goto("Local/010*207*024*152*78600096@default-000002b3;2", "default,78600096,1") in new stack
[May 25 10:28:18] VERBOSE[1008] pbx.c: [May 25 10:28:18]     -- Goto (default,78600096,1)
[May 25 10:28:18] VERBOSE[1008] pbx.c: [May 25 10:28:18]     -- Executing [78600096@default:1] MeetMe("Local/010*207*024*152*78600096@default-000002b3;2", "8600096,Fq") in new stack
[May 25 10:28:18] VERBOSE[1007] pbx.c: [May 25 10:28:18]        > Channel Local/010*207*024*152*78600096@default-000002b3;1 was answered.
[May 25 10:28:18] VERBOSE[1009] pbx.c: [May 25 10:28:18]     -- Executing [83047777777777@vicidial-auto:1] Answer("Local/010*207*024*152*78600096@default-000002b3;1", "") in new stack
[May 25 10:28:18] VERBOSE[1009] pbx.c: [May 25 10:28:18]     -- Executing [83047777777777@vicidial-auto:2] Playback("Local/010*207*024*152*78600096@default-000002b3;1", "ding") in new stack
[May 25 10:28:18] VERBOSE[1009] file.c: [May 25 10:28:18]     -- <Local/010*207*024*152*78600096@default-000002b3;1> Playing 'ding.gsm' (language 'en')
[May 25 10:28:18] VERBOSE[948] app_dial.c: [May 25 10:28:18]     -- SIP/vulcan1-00000206 is ringing
[May 25 10:28:18] VERBOSE[948] app_dial.c: [May 25 10:28:18]     -- SIP/vulcan1-00000206 is making progress passing it to Local/37279264356165@default-000002b2;2
[May 25 10:28:18] VERBOSE[1009] pbx.c: [May 25 10:28:18]     -- Executing [83047777777777@vicidial-auto:3] Hangup("Local/010*207*024*152*78600096@default-000002b3;1", "") in new stack
[May 25 10:28:18] VERBOSE[1009] pbx.c: [May 25 10:28:18]   == Spawn extension (vicidial-auto, 83047777777777, 3) exited non-zero on 'Local/010*207*024*152*78600096@default-000002b3;1'
[May 25 10:28:18] VERBOSE[1009] pbx.c: [May 25 10:28:18]     -- Executing [h@vicidial-auto:1] AGI("Local/010*207*024*152*78600096@default-000002b3;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
[May 25 10:28:18] VERBOSE[1009] res_agi.c: [May 25 10:28:18]     -- <Local/010*207*024*152*78600096@default-000002b3;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0
[May 25 10:28:18] VERBOSE[1008] pbx.c: [May 25 10:28:18]   == Spawn extension (default, 78600096, 1) exited non-zero on 'Local/010*207*024*152*78600096@default-000002b3;2'
[May 25 10:28:18] VERBOSE[1008] pbx.c: [May 25 10:28:18]     -- Executing [h@default:1] AGI("Local/010*207*024*152*78600096@default-000002b3;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:28:18] VERBOSE[1008] res_agi.c: [May 25 10:28:18]     -- <Local/010*207*024*152*78600096@default-000002b3;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:28:19] VERBOSE[969] res_musiconhold.c: [May 25 10:28:19]     -- Stopped music on hold on SIP/avaya_ru-00000207
[May 25 10:28:19] VERBOSE[969] res_agi.c: [May 25 10:28:19]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:28:19] VERBOSE[969] res_agi.c: [May 25 10:28:19]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:28:19] VERBOSE[1007] manager.c: [May 25 10:28:19]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:19] VERBOSE[969] res_agi.c: [May 25 10:28:19]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:28:19] VERBOSE[969] res_agi.c: [May 25 10:28:19]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:28:19] VERBOSE[969] res_agi.c: [May 25 10:28:19]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:28:19] VERBOSE[969] res_agi.c: [May 25 10:28:19]     -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[May 25 10:28:19] VERBOSE[969] res_agi.c: [May 25 10:28:19]     -- <SIP/avaya_ru-00000207>AGI Script agi-VDAD_ALL_inbound.agi completed, returning 0
[May 25 10:28:19] VERBOSE[969] pbx.c: [May 25 10:28:19]     -- Executing [010*207*024*152*8600096@default:1] Goto("SIP/avaya_ru-00000207", "default,8600096,1") in new stack
[May 25 10:28:19] VERBOSE[969] pbx.c: [May 25 10:28:19]     -- Goto (default,8600096,1)
[May 25 10:28:19] VERBOSE[969] pbx.c: [May 25 10:28:19]     -- Executing [8600096@default:1] MeetMe("SIP/avaya_ru-00000207", "8600096,F") in new stack
[May 25 10:28:19] VERBOSE[1019] manager.c: [May 25 10:28:19]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:19] VERBOSE[1020] pbx.c: [May 25 10:28:19]     -- Executing [58600096@default:1] MeetMe("Local/58600096@default-000002b4;2", "8600096,Fmq") in new stack
[May 25 10:28:19] VERBOSE[1019] pbx.c: [May 25 10:28:19]        > Channel Local/58600096@default-000002b4;1 was answered.
[May 25 10:28:19] VERBOSE[1021] pbx.c: [May 25 10:28:19]     -- Executing [8309@default:1] Answer("Local/58600096@default-000002b4;1", "") in new stack
[May 25 10:28:19] VERBOSE[1021] pbx.c: [May 25 10:28:19]     -- Executing [8309@default:2] Monitor("Local/58600096@default-000002b4;1", "wav,PMI_DRA_20170525-102818_szhukov_4995505366") in new stack
[May 25 10:28:19] VERBOSE[1021] pbx.c: [May 25 10:28:19]     -- Executing [8309@default:3] Wait("Local/58600096@default-000002b4;1", "3600") in new stack
[May 25 10:28:20] VERBOSE[1019] manager.c: [May 25 10:28:20]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:21] VERBOSE[636] pbx.c: [May 25 10:28:21]     -- Timeout on SIP/vulcan1-000001fd, going to 't'
[May 25 10:28:21] VERBOSE[636] pbx.c: [May 25 10:28:21]     -- Executing [t@pmi_menu_for_connect:1] Playback("SIP/vulcan1-000001fd", "pmi_goodby_m_2") in new stack
[May 25 10:28:21] VERBOSE[636] file.c: [May 25 10:28:21]     -- <SIP/vulcan1-000001fd> Playing 'pmi_goodby_m_2.slin' (language 'en')
[May 25 10:28:23] VERBOSE[1054] manager.c: [May 25 10:28:23]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:23] VERBOSE[652] pbx.c: [May 25 10:28:23]   == Spawn extension (default, 8600114, 1) exited non-zero on 'Local/8600114@default-000002aa;2'
[May 25 10:28:23] VERBOSE[652] pbx.c: [May 25 10:28:23]     -- Executing [h@default:1] AGI("Local/8600114@default-000002aa;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:28:23] VERBOSE[652] res_agi.c: [May 25 10:28:23]     -- <Local/8600114@default-000002aa;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:28:23] VERBOSE[653] pbx.c: [May 25 10:28:23]   == Spawn extension (default, 37279198080585, 3) exited non-zero on 'Local/8600114@default-000002aa;1'
[May 25 10:28:23] VERBOSE[653] pbx.c: [May 25 10:28:23]     -- Executing [h@default:1] AGI("Local/8600114@default-000002aa;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL----------") in new stack
[May 25 10:28:23] VERBOSE[1055] manager.c: [May 25 10:28:23]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:23] VERBOSE[653] res_agi.c: [May 25 10:28:23]     -- <Local/8600114@default-000002aa;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL---------- completed, returning 0
[May 25 10:28:23] VERBOSE[663] pbx.c: [May 25 10:28:23]   == Spawn extension (default, 58600114, 1) exited non-zero on 'Local/58600114@default-000002ab;2'
[May 25 10:28:23] VERBOSE[663] pbx.c: [May 25 10:28:23]     -- Executing [h@default:1] AGI("Local/58600114@default-000002ab;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:28:23] VERBOSE[663] res_agi.c: [May 25 10:28:23]     -- <Local/58600114@default-000002ab;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:28:23] VERBOSE[664] pbx.c: [May 25 10:28:23]   == Spawn extension (default, 8309, 3) exited non-zero on 'Local/58600114@default-000002ab;1'
[May 25 10:28:23] VERBOSE[664] pbx.c: [May 25 10:28:23]     -- Executing [h@default:1] AGI("Local/58600114@default-000002ab;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:28:23] VERBOSE[664] res_agi.c: [May 25 10:28:23]     -- <Local/58600114@default-000002ab;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:28:23] VERBOSE[1056] manager.c: [May 25 10:28:23]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:23] VERBOSE[636] pbx.c: [May 25 10:28:23]     -- Executing [t@pmi_menu_for_connect:2] AGI("SIP/vulcan1-000001fd", "cm.agi,CALLMENU-----t-----postal_code") in new stack
[May 25 10:28:23] VERBOSE[636] res_agi.c: [May 25 10:28:23]     -- Launched AGI Script /var/lib/asterisk/agi-bin/cm.agi
[May 25 10:28:23] VERBOSE[636] res_agi.c: [May 25 10:28:23]     -- <SIP/vulcan1-000001fd>AGI Script cm.agi completed, returning 0
[May 25 10:28:23] VERBOSE[636] pbx.c: [May 25 10:28:23]     -- Executing [t@pmi_menu_for_connect:3] Hangup("SIP/vulcan1-000001fd", "") in new stack
[May 25 10:28:23] VERBOSE[636] pbx.c: [May 25 10:28:23]   == Spawn extension (pmi_menu_for_connect, t, 3) exited non-zero on 'SIP/vulcan1-000001fd'
[May 25 10:28:23] VERBOSE[636] pbx.c: [May 25 10:28:23]     -- Executing [h@pmi_menu_for_connect:1] AGI("SIP/vulcan1-000001fd", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
[May 25 10:28:23] VERBOSE[636] res_agi.c: [May 25 10:28:23]     -- <SIP/vulcan1-000001fd>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0
[May 25 10:28:24] VERBOSE[1054] manager.c: [May 25 10:28:24]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:24] VERBOSE[1055] manager.c: [May 25 10:28:24]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:24] VERBOSE[1056] manager.c: [May 25 10:28:24]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:27] VERBOSE[911] pbx.c: [May 25 10:28:27]   == Spawn extension (pmi_menu_for_connect, s, 4) exited non-zero on 'SIP/vulcan1-00000203'
[May 25 10:28:27] VERBOSE[911] pbx.c: [May 25 10:28:27]     -- Executing [h@pmi_menu_for_connect:1] AGI("SIP/vulcan1-00000203", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[May 25 10:28:27] VERBOSE[911] res_agi.c: [May 25 10:28:27]     -- <SIP/vulcan1-00000203>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0
[May 25 10:28:39] VERBOSE[947] manager.c: [May 25 10:28:39]   == Manager 'sendcron' logged off from 127.0.0.1
[May 25 10:28:39] VERBOSE[948] pbx.c: [May 25 10:28:39]   == Spawn extension (default, 37279264356165, 3) exited non-zero on 'Local/37279264356165@default-000002b2;2'
[May 25 10:28:39] VERBOSE[948] pbx.c: [May 25 10:28:39]     -- Executing [h@default:1] AGI("Local/37279264356165@default-000002b2;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL----------") in new stack
[May 25 10:28:40] VERBOSE[1162] manager.c: [May 25 10:28:40]   == Manager 'sendcron' logged on from 127.0.0.1
[May 25 10:28:40] VERBOSE[1163] pbx.c: [May 25 10:28:40]     -- Executing [37279651470087@default:1] AGI("Local/37279651470087@default-000002b5;2", "agi://127.0.0.1:4577/call_log") in new stack
mangamen45@gmail.com
 
Posts: 10
Joined: Mon May 16, 2016 7:35 am

Re: Inbound Calls Discrepancy

Postby mflorell » Fri May 26, 2017 9:00 am

I don't see anything out of the ordinary on here. Could you post the vicidial_closer_log record for this call?

Also, I would suggest upgrading to the most recent svn/trunk version of VICIdial, there are a lot of logging bugs that have been fixed in the last 14 months.
mflorell
Site Admin
 
Posts: 18335
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Re: Inbound Calls Discrepancy

Postby mangamen45@gmail.com » Fri May 26, 2017 10:04 am

mflorell wrote:I don't see anything out of the ordinary on here. Could you post the vicidial_closer_log record for this call?

Also, I would suggest upgrading to the most recent svn/trunk version of VICIdial, there are a lot of logging bugs that have been fixed in the last 14 months.

Code: Select all
mysql> select * from vicidial_closer_log where lead_id = 1153424;
+-------------+---------+---------+------------------+---------------------+-------------+------------+---------------+--------+------------+--------------+-------------------+----------+-----------+---------------+------------+------------+-------------+-----------------+------------+----------------+--------------+
| closecallid | lead_id | list_id | campaign_id      | call_date           | start_epoch | end_epoch  | length_in_sec | status | phone_code | phone_number | user              | comments | processed | queue_seconds | user_group | xfercallid | term_reason | uniqueid        | agent_only | queue_position | called_count |
+-------------+---------+---------+------------------+---------------------+-------------+------------+---------------+--------+------------+--------------+-------------------+----------+-----------+---------------+------------+------------+-------------+-----------------+------------+----------------+--------------+
|       30043 | 1153424 |     990 | PMI_INCOMING_DRA | 2017-05-25 10:27:24 |  1495697244 | 1495697289 |            45 | DROP   | 7          | 4995505366   | advuriechienskaia | NULL     | N         |         45.00 | NULL       |          0 | CALLER      | 1495697244.1946 |            |              1 |            1 |
+-------------+---------+---------+------------------+---------------------+-------------+------------+---------------+--------+------------+--------------+-------------------+----------+-----------+---------------+------------+------------+-------------+-----------------+------------+----------------+--------------+
1 row in set (0,00 sec)

What i can check more? :)
mangamen45@gmail.com
 
Posts: 10
Joined: Mon May 16, 2016 7:35 am

Re: Inbound Calls Discrepancy

Postby mflorell » Fri May 26, 2017 10:27 am

I don't see any reasons why it is reporting as a DROP, but I would recommend upgrading and see if the problem still exists after that.
mflorell
Site Admin
 
Posts: 18335
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Re: Inbound Calls Discrepancy

Postby mangamen45@gmail.com » Sat May 27, 2017 3:28 am

mflorell wrote:I don't see any reasons why it is reporting as a DROP, but I would recommend upgrading and see if the problem still exists after that.

Thanks mflorell for your help and time!
One more, can you give me instruction or link to instruction how I can with safety update the system.
mangamen45@gmail.com
 
Posts: 10
Joined: Mon May 16, 2016 7:35 am

Re: Inbound Calls Discrepancy

Postby mflorell » Sat May 27, 2017 7:49 pm

Just update to the most recent svn/trunk code, then follow the UPGRADE document instructions. You will have to follow both the 2.12 and 2.14 upgrade instructions.

Here's a link to the svn/trunk checkout instructions:
http://wiki.vicidial.org/doku.php?id=svn
mflorell
Site Admin
 
Posts: 18335
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Re: Inbound Calls Discrepancy

Postby mangamen45@gmail.com » Thu Aug 10, 2017 6:06 am

Thank you very much!!! After update all problems with Inbound Calls gone!!!
mangamen45@gmail.com
 
Posts: 10
Joined: Mon May 16, 2016 7:35 am

Re: Inbound Calls Discrepancy

Postby mflorell » Thu Aug 10, 2017 12:29 pm

Thanks for the post-back!
mflorell
Site Admin
 
Posts: 18335
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida


Return to General Discussion

Who is online

Users browsing this forum: No registered users and 63 guests