How to account for all inbound calls? uniqueid mismatches?

[njr]

Hello all,

Summary: How can I track the full journey of a call through the system, from the did log possibly through the IVR log to the closer log? More importantly, how can I figure out what happened to the calls that don't complete that journey?

Long version: (and sorry that it's still meandering after trying to condense it, I went down a lot of rabbit holes here)
I was asked by management what I though would be an easy enough question to answer: Why are there more total calls in the Inbound DID report than there are in any of the closer reports counting dispositions?
My initial assumption was callers hanging up at the IVR, and therefore never making it to an agent/queue. And/or hanging up so quickly that even that can't register.

But, I can't piece together the data to back it up after many hours of querying the DB trying to get anything sensible to add up.

I'm going to use real numbers but exclude PII to try to show what I've done so far:
DID inbound reports show 1471 total calls across all DIDs.
Any closer-type reports show 1271 calls with a disposition across all in-groups.
Inbound IVR report shows 1366 total calls across all IVRs. However, not all calls hit an IVR. Some sales calls from a specific ad campaign go directly to an in-group, meaning this number alone can't really be used for trying to find what happened to the calls.

I decide to start querying the DB directly to try to find some answers.

Code: Select all

SELECT call_date, uniqueid FROM vicidial_did_log WHERE call_date >= '2024-12-11 00:00:00' and call_date <= '2024-12-11 23:59:59'

yields 1471 results. Great.

Code: Select all

SELECT call_date, uniqueid FROM vicidial_closer_log WHERE call_date >= '2024-12-11 00:00:00' AND call_date <= '2024-12-11 23:59:59'

yields 1271. Great.

So, theoretically, closer_log should be a subset of did_log, right? I assumed (and later checked to be true) that call_date would not be the same, but uniqueid should be I would imagine.

Code: Select all

(SELECT uniqueid FROM vicidial_did_log WHERE call_date >= '2024-12-11 00:00:00' and call_date <= '2024-12-11 23:59:59' )
EXCEPT
(SELECT uniqueid FROM vicidial_closer_log WHERE call_date >= '2024-12-11 00:00:00' AND call_date <= '2024-12-11 23:59:59')

yields...396.

and indeed, the same bit with INTERSECT yields 1075, which when added to 396 gets back to 1471.

So now, the calls that have a matching uniqueid are 196 less than the total calls that were dispositioned. How? Why? Does uniqueid get reassigned at some point?

So I try checking instead against live_inbound_log for IVR matches.

Code: Select all

(SELECT  uniqueid FROM vicidial_did_log WHERE call_date >= '2024-12-11 00:00:00' and call_date <= '2024-12-11 23:59:59' )
INTERSECT
(select  uniqueid from live_inbound_log where start_time >= '2024-12-11 00:00:00' and start_time <= '2024-12-11 23:59:59')

yields 1366. Cool. At least all of the ones in the IVR log are accounted for in did_log.
What about my theory that the difference in the reports is from people dropping off at the IVR? Well, IVR - closer should be 200 if that were true.

Code: Select all

(select distinct uniqueid from live_inbound_log where start_time >= '2024-12-11 00:00:00' and start_time <= '2024-12-11 23:59:59' )
EXCEPT
(SELECT uniqueid FROM vicidial_closer_log WHERE call_date >= '2024-12-11 00:00:00' and call_date <= '2024-12-11 23:59:59' )

yields 372. But again, not all calls hit an IVR.

Then I remember that did_log has a column did_route which is either CALLMENU or IN_GROUP. I decide to check the breakdown according to vicidial_did_log.
WHERE did_route='CALLMENU' yields 1333 calls (not 1366, which was something else unexpected, why would it be 33 off when it matched earlier when intersecting? Does did_route get updated in some scenarios?)
WHERE did_route='IN_GROUP' yields 131
I found 7 calls that went to NA_EXTEN as well, so total is 1471.

Alright, so next I check did_route=IN_GROUP against closer_log, as these should all be there unless something crazy happens, right?

Code: Select all

(SELECT uniqueid FROM vicidial_did_log WHERE call_date >= '2024-12-11 00:00:00' and call_date <= '2024-12-11 23:59:59' AND did_route='IN_GROUP')
EXCEPT
(SELECT uniqueid FROM vicidial_closer_log WHERE call_date >= '2024-12-11 00:00:00' and call_date <= '2024-12-11 23:59:59' )

yields 9 calls that for some reason didn't make it to a queue/agent. I looked them up in vicidial_did_agent_log and they all have user VDCL but no other obvious similarities that would show a misconfiguration. From call log, they are all between 0 and 8 seconds, so, maybe just too short? I'm not sure.
Anyway, this still leaves, I guess, 193 calls unaccounted for. I'm not sure what other things to try in order to figure out what happened to them.

I did other iterations of intersect/except between did_log, closer_log, and live_inbound but nothing that added up to anything that made sense to me.

Any ideas of other queries to try? Or completely different approaches? Heck, is there just a way to enable drop lists for calls that don't get past an IVR? Or is my thinking about this just incorrect in general?
Any insights at all appreciated. Thanks!

[njr]

Well, as per usual, writing out the problem in a forum post let me to some kind of a solution, although I'm still not 100% sure my counts are correct.

It turns out that AFTHRS, which is routing to another in-group, is causing more uniqueids to spawn which are in closer_log but not in did_log. It also can sometimes cause double-counting in IVR logs, depending on the setup exactly.
I figured this out after writing a query to list every call and its uniqueid, data, did_route, ivr_time, and disposition and spit it out to a table. I also unioned did_log with closer_log since I already knew that closer_log had more in it than did_log was showing.
I could then visually see that after every AFTHRS where was another uniqueid with *no* did_route.

Anyway, in case anyone wants it, here's a very quick, very ugly, not-even-a-datepicker report as a proof of concept. It shows the call flow through the system from left to right, and classifies each as:
- Successful Calls: Any call with at least one disposition from closer_log in any step
- IVR Drop: did_route='CALLMENU', has IVR (earliest_ivr_time not null), no dispositions
- Quick Drop:
* (CALLMENU with no IVR) or (IN_GROUP with no dispositions)
AND short call_duration (e.g., < 5s, set by a variable)
- Problem Calls: everything else

There's no authentication, and I did no safety checks (although there is no input, so, it should probably be safe, but, I make no guarantees, warranties, claims of safety nor functionality, etc.) Needs to go somewhere with access to dbconnect_mysqli.php and the dates need to be manually entered at the top of the code.
At the very least, the sql/processing itself would be a decent starting point I think to making your own if desired.

Code: Select all

<?php
require_once("dbconnect_mysqli.php");
global $link;

// Date range
$start = '2024-12-11 00:00:00';
$end   = '2024-12-11 23:59:59';

$sql = "
WITH did_calls AS (
    SELECT uniqueid, call_date, did_route, caller_id_number
    FROM vicidial_did_log
    WHERE call_date BETWEEN '$start' AND '$end'
),
closer_agg AS (
    SELECT uniqueid,
           GROUP_CONCAT(status ORDER BY call_date) AS all_dispositions,
           MIN(call_date) AS earliest_closer_call_date,
           MAX(call_date) AS latest_closer_call_date
    FROM vicidial_closer_log
    WHERE call_date BETWEEN '$start' AND '$end'
    GROUP BY uniqueid
),
ivr_agg AS (
    SELECT uniqueid,
           MIN(start_time) AS earliest_ivr_time,
           MAX(start_time) AS latest_ivr_time,
           COUNT(*) AS ivr_steps
    FROM live_inbound_log
    WHERE start_time BETWEEN '$start' AND '$end'
    GROUP BY uniqueid
),
call_union AS (
    SELECT uniqueid FROM did_calls
    UNION
    SELECT uniqueid FROM vicidial_closer_log
    WHERE call_date BETWEEN '$start' AND '$end'
)
SELECT
    cu.uniqueid,
    d.call_date AS did_call_date,
    d.did_route,
    d.caller_id_number,
    i.earliest_ivr_time,
    i.latest_ivr_time,
    i.ivr_steps,
    c.all_dispositions,
    c.earliest_closer_call_date,
    c.latest_closer_call_date,
    cd.call_duration
FROM call_union cu
LEFT JOIN did_calls d ON cu.uniqueid = d.uniqueid
LEFT JOIN ivr_agg i ON cu.uniqueid = i.uniqueid
LEFT JOIN closer_agg c ON cu.uniqueid = c.uniqueid
LEFT JOIN (
    SELECT uniqueid, (end_epoch - start_epoch) AS call_duration
    FROM call_log
    WHERE start_time BETWEEN '$start' AND '$end'
) cd ON cu.uniqueid = cd.uniqueid
ORDER BY cu.uniqueid;
";

$result = mysqli_query($link, $sql);
if (!$result) {
    die("Query failed: " . mysqli_error($link));
}

$callFlows = [];
$successfulCalls = 0;
$ivrDrop = 0;
$quickDrop = 0;
$problemCalls = 0;
$quickDropThreshold = 5;

while ($row = mysqli_fetch_assoc($result)) {
    $uniqueid          = $row['uniqueid'];
    $did_route         = $row['did_route'];
    $earliest_ivr_time = $row['earliest_ivr_time'];
    $all_dispositions  = $row['all_dispositions'];
    $call_duration     = $row['call_duration'];
    $did_call_date     = $row['did_call_date'];
    $caller_id_number  = $row['caller_id_number'];

    // Determine category
    // - Successful Calls: Any call with at least one disposition from closer_log in any step
    // - IVR Drop: did_route='CALLMENU', has IVR (earliest_ivr_time not null), no dispositions
    // - Quick Drop:
    //    * (CALLMENU with no IVR) or (IN_GROUP with no dispositions)
    //    AND short call_duration (e.g., < 5s, set above)
    // - Problem Calls: everything else
    if (!empty($all_dispositions)) {
        // Successful Calls
        $category = "Successful";
        $successfulCalls++;
    } else if ($did_route === 'CALLMENU' && !empty($earliest_ivr_time) && empty($all_dispositions)) {
        // IVR Drop
        $category = "IVR Drop";
        $ivrDrop++;
    } else if (
        (
            ($did_route === 'CALLMENU' && empty($earliest_ivr_time))
            || ($did_route === 'IN_GROUP' && empty($all_dispositions))
        )
        && (is_null($call_duration) || $call_duration < $quickDropThreshold)
    ) {
        // Quick Drop
        $category = "Quick Drop";
        $quickDrop++;
    } else {
        // Problem Calls
        $category = "Problem Calls";
        $problemCalls++;
    }

    $callFlows[] = [
        'uniqueid'          => $uniqueid,
        'did_route'         => $did_route,
        'caller_id_number'  => $caller_id_number,
        'earliest_ivr_time' => $earliest_ivr_time,
        'all_dispositions'  => $all_dispositions,
        'call_duration'     => $call_duration,
        'did_call_date'     => $did_call_date,
        'category'          => $category
    ];
}

mysqli_close($link);

// Now we chain successive calls together AFTER we have done the classification and counting.
// The categories and counts above are final and will not change.
// We simply rearrange the display.

$chainedCalls = [];
$lastCallIndex = null;

foreach ($callFlows as $flow) {
    $did_route = $flow['did_route'];
    $disposStr = $flow['all_dispositions'];
    $dispositions = (!empty($disposStr)) ? explode(',', $disposStr) : [];

    // Start a new chain if this call has a did_route or if we haven't started one yet
    if (!empty($did_route) || $lastCallIndex === null) {
        // Begin a new chain
        $chain = [
            'uniqueids'         => [$flow['uniqueid']],
            'did_route'         => $flow['did_route'],
            'caller_id_number'  => $flow['caller_id_number'],
            'earliest_ivr_time' => $flow['earliest_ivr_time'],
            'did_call_date'     => $flow['did_call_date'],
            'call_duration'     => $flow['call_duration'],
            'category'          => $flow['category'],
            'steps'             => [$dispositions] // first step's dispositions
        ];
        $chainedCalls[] = $chain;
        $lastCallIndex = count($chainedCalls) - 1;
    } else {
        // Append to the last chain - this row has no did_route, just add steps
        $chainedCalls[$lastCallIndex]['uniqueids'][] = $flow['uniqueid'];
        $chainedCalls[$lastCallIndex]['steps'][] = $dispositions;
        // We do NOT change the category or counts. The category and counts are already done.
    }
}

// Find max steps for table columns
$maxSteps = 0;
foreach ($chainedCalls as $chain) {
    $stepCount = count($chain['steps']);
    if ($stepCount > $maxSteps) {
        $maxSteps = $stepCount;
    }
}

// Print top-level metrics (already calculated)
echo "<h1>Daily Call Flow Report for $start - $end</h1>";
echo "<p>Successful Calls: $successfulCalls</p>";
echo "<p>IVR Drops: $ivrDrop</p>";
echo "<p>Quick Drops: $quickDrop</p>";
echo "<p>Problem Calls: $problemCalls</p>";

// Print chained results
echo "<table border='1' cellpadding='5' cellspacing='0'>";
echo "<tr>
        <th>First UniqueID</th>
        <th>Caller Number</th>
        <th>DID Route</th>
        <th>Call Date</th>
        <th>Earliest IVR</th>
        <th>Call Duration (s)</th>
        <th>Category</th>";

// Add dynamic columns for steps
for ($i = 1; $i <= $maxSteps; $i++) {
    echo "<th>Step $i Dispositions</th>";
}

echo "</tr>";

foreach ($chainedCalls as $chain) {
    echo "<tr>";
    $firstUniqueID = count($chain['uniqueids']) > 0 ? $chain['uniqueids'][0] : '';
    $did_route = $chain['did_route'];
    $caller_id_number = $chain['caller_id_number'];
    $did_call_date = $chain['did_call_date'];
    $earliest_ivr_time = $chain['earliest_ivr_time'];
    $call_duration = $chain['call_duration'];
    $category = $chain['category'];

    echo "<td>$firstUniqueID</td>";
    echo "<td>$caller_id_number</td>";
    echo "<td>$did_route</td>";
    echo "<td>$did_call_date</td>";
    echo "<td>$earliest_ivr_time</td>";
    echo "<td>$call_duration</td>";
    echo "<td>$category</td>";

    $stepCount = count($chain['steps']);
    for ($i = 0; $i < $maxSteps; $i++) {
        if ($i < $stepCount) {
            $stepDispos = $chain['steps'][$i];
            $stepStr = (!empty($stepDispos)) ? implode(' -> ', $stepDispos) : '';
            echo "<td>$stepStr</td>";
        } else {
            echo "<td></td>";
        }
    }
    echo "</tr>";
}
echo "</table>";
?>


[williamconley]

Interesting concept.

You can also (sometimes) use the file-based logs for certain types of tracking in case that helps in future upgrades to your concept.

I wonder if it would be worthwhile to assign every call a non-asterisk UniqueID at "ring" or "answer" and link that ID to all future events/destinations. Not a quick solution, but could make some future troubleshooters Very Happy IMHO.

[njr]

Ah, yeah, good point about the other logs.
As for a non-asterisk unique id, I would really love it if it stored the call-id from the SIP header....that would make me Very Happy right now haha.

[njr]

Well, if anybody else wants to be able to find call-id, here you go. It will log the corresponding pairs of SIP CALL-ID and vici uniqueid.

Make a new table in your DB:

Code: Select all

CREATE TABLE vicidial_callid_log (
    uniqueid VARCHAR(50) NOT NULL,        -- Asterisk unique ID
    sip_call_id VARCHAR(255) NOT NULL,   -- SIP Call-ID
    log_date TIMESTAMP DEFAULT CURRENT_TIMESTAMP, -- Timestamp of the log
    PRIMARY KEY (uniqueid),
    INDEX (sip_call_id)                  -- Optional index for faster lookup by Call-ID
);

Create /var/lib/asterisk/agi-bin/agi-log-callid.agi and put in the following:

Code: Select all

#!/usr/bin/perl
use strict;
use warnings;
use Asterisk::AGI;
use DBI;

# Initialize AGI
my $AGI = new Asterisk::AGI;

# Get passed arguments
my $uniqueid = $ARGV[0] // 'UNKNOWN';
my $sip_call_id = $ARGV[1] // 'UNKNOWN';

# Load configuration from astguiclient.conf
my $PATHconf = '/etc/astguiclient.conf';
open(my $conf_fh, '<', $PATHconf) or die "Can't open $PATHconf: $!\n";
my %conf;
while (<$conf_fh>) {
    s/ |>|\n|\r|\t|\#.*|;.*//gi;  # Clean up each line
    next unless $_;
    my ($key, $value) = split(/=/, $_, 2);
    $conf{$key} = $value;
}
close($conf_fh);

# Extract database configuration
my $VARDB_server   = $conf{'VARDB_server'}   || '127.0.0.1';
my $VARDB_database = $conf{'VARDB_database'} || 'asterisk';
my $VARDB_user     = $conf{'VARDB_user'}     || 'cron';
my $VARDB_pass     = $conf{'VARDB_pass'}     || '';
my $VARDB_port     = $conf{'VARDB_port'}     || '3306';

# Connect to the database
my $dbh = DBI->connect(
    "DBI:mysql:$VARDB_database:$VARDB_server:$VARDB_port",
    $VARDB_user,
    $VARDB_pass,
    { RaiseError => 1, AutoCommit => 1 }
) or die "Couldn't connect to database: " . DBI->errstr;

# Sanitize inputs
$sip_call_id =~ s/'|"//g;

# Insert the Call-ID and UniqueID into the custom table
my $stmt = "INSERT INTO vicidial_callid_log (uniqueid, sip_call_id) VALUES (?, ?)";
my $sth = $dbh->prepare($stmt);
$sth->execute($uniqueid, $sip_call_id);

# Debug output (optional)
$AGI->verbose("Logged Call-ID: $sip_call_id, UniqueID: $uniqueid", 1);

# Disconnect from the database
$dbh->disconnect;

exit;

modify dialplan in extensions.conf to:

Code: Select all

[trunkinbound]
; DID call routing process
exten => _X.,1,Set(SIPCallID=${SIP_HEADER(Call-ID)})       ; Extract SIP Call-ID
exten => _X.,n,AGI(agi-log-callid.agi,${UNIQUEID},${SIPCallID}) ; Log Call-ID and UniqueID
exten => _X.,n,AGI(agi-DID_route.agi)                     ; Existing DID routing process
exten => _X.,n,Hangup()

essentially just adding two lines to it. I'm purposely doing this before DID_route on my system because I want to make sure there's not something happening there that's causing my weird numbers. You decide what's best for you.

run

Code: Select all

/var/lib/asterisk/agi-bin/agi-log-callid.agi TEST_UNIQUEID TEST_CALLID

and make sure you see it in the DB. Can delete that row if you see it, now that you know DB connection is good.

Then reload your dialplan, and watch as it populates.

I kept the table super bare-bones so that it can just be joined with whatever else as needed, but you could certainly log more things to it if desired.

One feature/bug is the verbose line. I have it in there so I can grep asterisk messages and find the call-id. Completely optional, can be removed.

[williamconley]

darn good postback!