diff --git a/agi/agi-VDAD_ALL_outbound.agi b/agi/agi-VDAD_ALL_outbound.agi index 60aad9bc..b6ba7076 100644 --- a/agi/agi-VDAD_ALL_outbound.agi +++ b/agi/agi-VDAD_ALL_outbound.agi @@ -414,7 +414,8 @@ if ($SSsip_event_logging > 0) if ($affected_rows > 0) { - $stmtA = "SELECT invite_date,first_180_date,first_183_date,200_date,(200_date - invite_date) as dial,(first_180_date - invite_date) as prog,(first_183_date - invite_date) as pdd from vicidial_sip_event_recent where caller_code='$callerid' LIMIT 1;"; + $dial_time = 0; + $stmtA = "SELECT invite_date,first_180_date,first_183_date,200_date,TIMESTAMPDIFF(MICROSECOND,invite_date,200_date) as dial,TIMESTAMPDIFF(MICROSECOND,invite_date,first_180_date) as prog,TIMESTAMPDIFF(MICROSECOND,invite_date,first_183_date) as pdd from vicidial_sip_event_recent where caller_code='$callerid' LIMIT 1;"; $sthA = $dbhA->prepare($stmtA) or die "preparing: ",$dbhA->errstr; $sthA->execute or die "executing: $stmtA ", $dbhA->errstr; $sthArowsVSER=$sthA->rows; @@ -436,6 +437,8 @@ if ($SSsip_event_logging > 0) { if ( ($time_to_progress > 0) && ($time_to_progress != 'NULL') ) { + if ( ($dial_time <= 0) || ($dial_time == 'NULL') ) + {$dial_time = $time_to_progress;} $invite_to_ring = $time_to_progress; $ring_to_final = ($dial_time - $invite_to_ring); } @@ -443,6 +446,8 @@ if ($SSsip_event_logging > 0) { if ( ($time_to_ring > 0) && ($time_to_ring != 'NULL') ) { + if ( ($dial_time <= 0) || ($dial_time == 'NULL') ) + {$dial_time = $time_to_ring;} $invite_to_ring = $time_to_ring; $ring_to_final = ($dial_time - $invite_to_ring); } @@ -452,6 +457,9 @@ if ($SSsip_event_logging > 0) $ring_to_final = 0; } } + if ($invite_to_ring != '0') {$invite_to_ring = ($invite_to_ring / 1000000);} + if ($ring_to_final != '0') {$ring_to_final = ($ring_to_final / 1000000);} + if ($dial_time != '0') {$dial_time = ($dial_time / 1000000);} # insert a record into the vicidial_log_extended_sip table for this call $stmtA = "INSERT INTO vicidial_log_extended_sip SET call_date='$invite_date', caller_code='$callerid', invite_to_ring='$invite_to_ring', ring_to_final='$ring_to_final', invite_to_final='$dial_time', last_event_code='200';"; diff --git a/docs/SIP_EVENT_LOGGING.txt b/docs/SIP_EVENT_LOGGING.txt index b0c8df03..ca556352 100644 --- a/docs/SIP_EVENT_LOGGING.txt +++ b/docs/SIP_EVENT_LOGGING.txt @@ -1,13 +1,20 @@ -SIP EVENT LOGGING DOC Started: 2019-05-30 Updated: 2019-05-30 +SIP EVENT LOGGING DOC Started: 2019-05-30 Updated: 2019-05-31 -!!!! THIS IS A WORK IN PROGRESS, NOT FINISHED !!!! +!!!! THIS IS AN EXPERIMENTAL FEATURE, PLEASE READ ALL IMPORTANT NOTES !!!! This document will go over the details of the new SIP event logging features that were added to VICIdial for use with patched versions of Asterisk 13 -The purpose of this SIP event logging is to hopefully help to be able to better identify FAS(False Answer Supervision) and PDD(Post Dial Delay), as well as manual dial call progress updates to the agent. +The purpose of this SIP event logging is to hopefully help to be able to better identify FAS(False Answer Supervision) and PDD(Post Dial Delay), as well as manual dial call progress updates to the agent. For phase 1 of this project, which is all that is completed at this time, the basic framework of logging the SIP messages on all outbound calls is complete, as well as extended logging of answered calls. The maintenance of all involved new database log tables is also complete. + + + + +IMPORTANT VICIDIAL VERSION NOTE!!! + +You will need to be running VICIdial svn/trunk revision 3108 or newer on all of the servers in your cluster in order to use these new features @@ -168,3 +175,17 @@ MariaDB [asterisk]> SELECT * FROM vicidial_sip_event_log limit 10; | 118761 | M5301113160609819452 | SIP/proxy1-0000687b | 192.168.201.77 | 1559229196.141527 | 5c3fc41572b6d91b04f1770d175f873d@118.98.355.182:5060 | 2019-05-30 11:13:16.292730 | INVITE | | 118762 | M5301113160609819452 | SIP/proxy1-0000687b | 192.168.201.77 | 1559229196.141527 | 5c3fc41572b6d91b04f1770d175f873d@118.98.355.182:5060 | 2019-05-30 11:13:16.293336 | 100 | +--------------+----------------------+---------------------+----------------+-------------------+------------------------------------------------------+----------------------------+-----------+ + + +MariaDB [asterisk]> select * from vicidial_log_extended_sip; ++----------------------------+----------------------+----------------+---------------+-----------------+-----------------+ +| call_date | caller_code | invite_to_ring | ring_to_final | invite_to_final | last_event_code | ++----------------------------+----------------------+----------------+---------------+-----------------+-----------------+ +| 2019-05-31 14:44:41.820638 | V5311444410051765735 | 12.649792 | 9.486446 | 22.136238 | 200 | +| 2019-05-31 14:44:30.615591 | V5311444290051826986 | 3.702375 | 0.198128 | 3.900503 | 200 | +| 2019-05-31 14:44:24.227877 | V5311444230051773996 | 4.168916 | 0.169864 | 4.338780 | 200 | +| 2019-05-31 14:44:17.887899 | V5311444170051774117 | 1.588209 | 28.109085 | 29.697294 | 200 | +| 2019-05-31 14:44:09.180187 | V5311444080051793093 | 2.029566 | 29.918390 | 31.947956 | 200 | +| 2019-05-31 14:43:51.428842 | V5311443510051782192 | 0.000000 | 0.000000 | 0.771248 | 200 | ++----------------------------+----------------------+----------------+---------------+-----------------+-----------------+ + diff --git a/www/agc/vdc_db_query.php b/www/agc/vdc_db_query.php index 1d9b6fef..dfcba177 100644 --- a/www/agc/vdc_db_query.php +++ b/www/agc/vdc_db_query.php @@ -480,7 +480,7 @@ $version = '2.14-368'; $build = '190531-1045'; $php_script = 'vdc_db_query.php'; $mel=1; # Mysql Error Log enabled = 1 -$mysql_log_count=793; +$mysql_log_count=797; $one_mysql_log=0; $DB=0; $VD_login=0; @@ -6724,15 +6724,16 @@ if ($ACTION == 'manDiaLlookCaLL') $stmt="UPDATE vicidial_sip_event_recent set processed='U' where caller_code='$MDnextCID' LIMIT 1;;"; if ($DB) {echo "$stmt\n";} $rslt=mysql_to_mysqli($stmt, $link); - if ($mel > 0) {mysql_error_logging($NOW_TIME,$link,$mel,$stmt,'00XXX',$user,$server_ip,$session_name,$one_mysql_log);} + if ($mel > 0) {mysql_error_logging($NOW_TIME,$link,$mel,$stmt,'00794',$user,$server_ip,$session_name,$one_mysql_log);} $affected_rowsX = mysqli_affected_rows($link); if ($affected_rowsX > 0) { - $stmt = "SELECT invite_date,first_180_date,first_183_date,200_date,(200_date - invite_date) as dial,(first_180_date - invite_date) as prog,(first_183_date - invite_date) as pdd from vicidial_sip_event_recent where caller_code='$MDnextCID' LIMIT 1;"; + $dial_time = 0; + $stmt = "SELECT invite_date,first_180_date,first_183_date,200_date,TIMESTAMPDIFF(MICROSECOND,invite_date,200_date) as dial,TIMESTAMPDIFF(MICROSECOND,invite_date,first_180_date) as prog,TIMESTAMPDIFF(MICROSECOND,invite_date,first_183_date) as pdd from vicidial_sip_event_recent where caller_code='$MDnextCID' LIMIT 1;"; if ($DB) {echo "$stmt\n";} $rslt=mysql_to_mysqli($stmt, $link); - if ($mel > 0) {mysql_error_logging($NOW_TIME,$link,$mel,$stmt,'00XXX',$user,$server_ip,$session_name,$one_mysql_log);} + if ($mel > 0) {mysql_error_logging($NOW_TIME,$link,$mel,$stmt,'00795',$user,$server_ip,$session_name,$one_mysql_log);} $VSER_ct = mysqli_num_rows($rslt); if ($VSER_ct > 0) { @@ -6745,38 +6746,49 @@ if ($ACTION == 'manDiaLlookCaLL') $time_to_progress = $row[5]; $time_to_ring = $row[6]; - if ( ($time_to_progress > 0) && ($time_to_progress != 'NULL') ) + if ( ($dial_time > 0) and ($dial_time != 'NULL') ) { - $invite_to_ring = $time_to_progress; - $ring_to_final = ($dial_time - $invite_to_ring); - } - else - { - if ( ($time_to_ring > 0) && ($time_to_ring != 'NULL') ) + if ( ($time_to_progress > 0) and ($time_to_progress != 'NULL') ) { - $invite_to_ring = $time_to_ring; + if ( ($dial_time <= 0) or ($dial_time == 'NULL') ) + {$dial_time = $time_to_progress;} + $invite_to_ring = $time_to_progress; $ring_to_final = ($dial_time - $invite_to_ring); } else { - $invite_to_ring = 0; - $ring_to_final = 0; + if ( ($time_to_ring > 0) and ($time_to_ring != 'NULL') ) + { + if ( ($dial_time <= 0) or ($dial_time == 'NULL') ) + {$dial_time = $time_to_ring;} + $invite_to_ring = $time_to_ring; + $ring_to_final = ($dial_time - $invite_to_ring); + } + else + { + $invite_to_ring = 0; + $ring_to_final = 0; + } } + + if ($invite_to_ring != '0') {$invite_to_ring = ($invite_to_ring / 1000000);} + if ($ring_to_final != '0') {$ring_to_final = ($ring_to_final / 1000000);} + if ($dial_time != '0') {$dial_time = ($dial_time / 1000000);} + + # insert a record into the vicidial_log_extended_sip table for this call + $stmt = "INSERT INTO vicidial_log_extended_sip SET call_date='$invite_date', caller_code='$MDnextCID', invite_to_ring='$invite_to_ring', ring_to_final='$ring_to_final', invite_to_final='$dial_time', last_event_code='200';"; + if ($DB) {echo "$stmt\n";} + $rslt=mysql_to_mysqli($stmt, $link); + if ($mel > 0) {mysql_error_logging($NOW_TIME,$link,$mel,$stmt,'00796',$user,$server_ip,$session_name,$one_mysql_log);} + $affected_rowsX = mysqli_affected_rows($link); + + # flag the vicidial_sip_event_recent record as processed + $stmt = "UPDATE vicidial_sip_event_recent set processed='Y' where caller_code='$MDnextCID' LIMIT 1;"; + if ($DB) {echo "$stmt\n";} + $rslt=mysql_to_mysqli($stmt, $link); + if ($mel > 0) {mysql_error_logging($NOW_TIME,$link,$mel,$stmt,'00797',$user,$server_ip,$session_name,$one_mysql_log);} + $affected_rowsX = mysqli_affected_rows($link); } - - # insert a record into the vicidial_log_extended_sip table for this call - $stmt = "INSERT INTO vicidial_log_extended_sip SET call_date='$invite_date', caller_code='$MDnextCID', invite_to_ring='$invite_to_ring', ring_to_final='$ring_to_final', invite_to_final='$dial_time', last_event_code='200';"; - if ($DB) {echo "$stmt\n";} - $rslt=mysql_to_mysqli($stmt, $link); - if ($mel > 0) {mysql_error_logging($NOW_TIME,$link,$mel,$stmt,'00XXX',$user,$server_ip,$session_name,$one_mysql_log);} - $affected_rowsX = mysqli_affected_rows($link); - - # flag the vicidial_sip_event_recent record as processed - $stmt = "UPDATE vicidial_sip_event_recent set processed='Y' where caller_code='$MDnextCID' LIMIT 1;"; - if ($DB) {echo "$stmt\n";} - $rslt=mysql_to_mysqli($stmt, $link); - if ($mel > 0) {mysql_error_logging($NOW_TIME,$link,$mel,$stmt,'00XXX',$user,$server_ip,$session_name,$one_mysql_log);} - $affected_rowsX = mysqli_affected_rows($link); } } } diff --git a/www/vicidial/AST_timeonVDADall.php b/www/vicidial/AST_timeonVDADall.php index 1467e442..e0937444 100644 --- a/www/vicidial/AST_timeonVDADall.php +++ b/www/vicidial/AST_timeonVDADall.php @@ -113,6 +113,7 @@ # 190420-1728 - Added RS_ListenBarge options.php setting # 190513-1711 - Added ingroup filter # 190525-2133 - Added new agent time segment display +# 190531-1454 - Upgraded ingroup filter # $version = '2.14-100'; @@ -3488,6 +3489,7 @@ if ($talking_to_print > 0) $L=''; $R=''; + $filtered_ingroup=1; # assume ingroup is not filtered out if ($report_display_type=='TEXT') { @@ -3529,6 +3531,11 @@ if ($talking_to_print > 0) if ($ingrp_to_print > 0) { $row=mysqli_fetch_row($rslt); + $vac_campaign_id=$row[0]; + if (!in_array("ALL-INGROUPS", $ingroup_filter) && !in_array($vac_campaign_id, $ingroup_filter)) + { + $filtered_ingroup=0; + } $vac_campaign = sprintf("%-20s", "$row[0] - $row[2]"); $row[1] = preg_replace('/.*\-/i', '',$row[1]); $vac_stage = sprintf("%-4s", $row[1]); @@ -3543,14 +3550,18 @@ if ($talking_to_print > 0) $agentcount++; - if ($realtime_block_user_info > 0) + if ($filtered_ingroup==1) { - $Aecho .= "|$UGD $G$sessionid$EG$L$R$Aring_note[$i]| $G"._QXZ("$status",6)."$EG $CM $pausecode|$CP$SVD$G$call_time_MS$EG | $G$campaign_id$EG | $G$calls_today$EG |$INGRP\n"; - } - if ($realtime_block_user_info < 1) - { - $Aecho .= "| $G$extension$EG$Aring_note[$i]|$phoneD$G$user$EG + |$UGD $G$sessionid$EG$L$R | $G"._QXZ("$status",6)."$EG $CM $pausecode|$CP$SVD$G$call_time_MS$EG | $G$campaign_id$EG | $G$calls_today$EG |$INGRP\n"; + if ($realtime_block_user_info > 0) + { + $Aecho .= "|$UGD $G$sessionid$EG$L$R$Aring_note[$i]| $G"._QXZ("$status",6)."$EG $CM $pausecode|$CP$SVD$G$call_time_MS$EG | $G$campaign_id$EG | $G$calls_today$EG |$INGRP\n"; + } + if ($realtime_block_user_info < 1) + { + $Aecho .= "| $G$extension$EG$Aring_note[$i]|$phoneD$G$user$EG + |$UGD $G$sessionid$EG$L$R | $G"._QXZ("$status",6)."$EG $CM $pausecode|$CP$SVD$G$call_time_MS$EG | $G$campaign_id$EG | $G$calls_today$EG |$INGRP\n"; + } } + } if ($report_display_type=='HTML') { @@ -3596,6 +3607,11 @@ if ($talking_to_print > 0) if ($ingrp_to_print > 0) { $row=mysqli_fetch_row($rslt); + $vac_campaign_id=$row[0]; + if (!in_array("ALL-INGROUPS", $ingroup_filter) && !in_array($vac_campaign_id, $ingroup_filter)) + { + $filtered_ingroup=0; + } $vac_campaign = sprintf("%-20s", "$row[0] - $row[2]"); $row[1] = preg_replace('/.*\-/i', '',$row[1]); $vac_stage = sprintf("%-4s", $row[1]); @@ -3610,13 +3626,16 @@ if ($talking_to_print > 0) $agentcount++; - if ($realtime_block_user_info > 0) + if ($filtered_ingroup==1) { - $Aecho .= "$UGD $G$sessionid$EG$L$R$Aring_note[$i] $G"._QXZ("$status",6)."$EG$CM$pausecodeHTML$CP$SVD$G$call_time_MS$EG $G$campaign_id$EG $G$calls_today$EG $INGRP\n"; - } - if ($realtime_block_user_info < 1) - { - $Aecho .= " $G$extension$EG$Aring_note[$i]$phoneD$G$user$EG $G+$EG $UGD $G$sessionid$EG$L$R $G"._QXZ("$status",6)."$EG$CM$pausecodeHTML$CP$SVD$G$call_time_MS$EG $G$campaign_id$EG $G$calls_today$EG $INGRP\n"; + if ($realtime_block_user_info > 0) + { + $Aecho .= "$UGD $G$sessionid$EG$L$R$Aring_note[$i] $G"._QXZ("$status",6)."$EG$CM$pausecodeHTML$CP$SVD$G$call_time_MS$EG $G$campaign_id$EG $G$calls_today$EG $INGRP\n"; + } + if ($realtime_block_user_info < 1) + { + $Aecho .= " $G$extension$EG$Aring_note[$i]$phoneD$G$user$EG $G+$EG $UGD $G$sessionid$EG$L$R $G"._QXZ("$status",6)."$EG$CM$pausecodeHTML$CP$SVD$G$call_time_MS$EG $G$campaign_id$EG $G$calls_today$EG $INGRP\n"; + } } } $j++;