Custom AGI script for outbound call checks stopped working

mattjfrank · April 10, 2015, 3:55pm

In December sometime I applied an update to FreePBX actually many and I’m not sure when exactly it broke or what update broke it. I have an AGI script that checks all outbound calls for against sql databases of existing customers, do not call list etc and then it completes the call.

The issue is when making calls using this script, the calls do not get recorded. No matter the settings for forcing call recording. I know that some stuff changed late last year with call recording so I’m guessing that is where the issue is.

Below is my agi script. Can anyone see anything that could be causing the issue? Call recording works as expected when not passed through the script. I’ve made many changes to this script to try to figure out the issue so this is not exactly what was working before an update but does work now just doesn’t record the call.

(In case anyone wonders the random caller id just uses some metrics to determine which of the caller id’s to use to ensure better utilization of inbound did trunks)

Here is the extensions_custom.conf

exten => _1NXXNXXXXXX,n,AGI(numsearch2.php,${EXTEN})
exten => _NXXNXXXXXX,n,AGI(numsearch2.php,${EXTEN})

Here is the agi script

#!/usr/bin/php -q
<?php set_time_limit(0); require('phpagi.php');

$agi = new AGI();
$agi->answer();

$numtosearch = $argv[1];
$thelength = strlen($numtosearch);

if($agi_callerid == ‘’) {

$randomCIDs = array(“NUMBER1”, “NUMBER2”, “NUMBER3”);
srand(time());
$setRandomCID = (rand()%3);
$RandomCIDis = $randomCIDs[$setRandomCID];
$randomizeCID = $agi->set_callerid(“$RandomCIDis”);
}

$agi->verbose(“SETTING CALLER ID TO $RandomCIDis”);

$agi->verbose(“NUMBER LOOKUP SCRIPT INITIATED”);
$agi->verbose(“NUMBER DIALED IS $numtosearch”);

$connection = mysql_connect(“HOST”,“USER”,“PASS”);
$db = mysql_select_db(“DB”, $connection);

if($thelength == “7”){
$numtosearch2 = “402-”.substr($numtosearch, 0, 3).“-”.substr($numtosearch, 3, 4).“”;
$num2call = “$numtosearch2”;
$callthisnum = substr($numtosearch2, -12);
}

if($thelength == “10”){
$numtosearch2 = substr($numtosearch, 0, 3).“-”.substr($numtosearch, 3, 3).“-”.substr($numtosearch, 6, 4).“”;
$num2call = “$numtosearch2”;
$callthisnum = substr($numtosearch2, -12);

}

if($thelength == “11”){
$numtosearch2 = substr($numtosearch, 1, 3).“-”.substr($numtosearch, 4, 3).“-”.substr($numtosearch, 7, 4).“”;
$num2call = “$numtosearch2”;
$callthisnum = substr($numtosearch2, -12);

}

if($thelength == “12”){
$numtosearch2 = substr($numtosearch, 2, 3).“-”.substr($numtosearch, 5, 3).“-”.substr($numtosearch, 8, 4).“”;
$num2call = “$numtosearch2”;
$callthisnum = substr($numtosearch2, -14);
}

$result9 = mysql_query(“SELECT * FROM TABLEISHERE WHERE phonenumber = ‘$numtosearch2’”);
$countResults9 = mysql_num_rows($result9);

$agi->verbose(“CHECKING DO NOT CALL LIST”);
if($countResults9 > ‘0’) {
$agi->verbose(“$numtosearch2 FOUND ON OUR DO NOT CALL LIST”);
$agi->verbose(“HANGING UP CALL TO $numtosearch2”);
$agi->stream_file(‘custom/donotcall’);
$agi->hangup();
exit;
}else {
$agi->verbose(“$numtosearch2 NOT FOUND ON DO NOT CALL LIST”);
}

$agi->verbose(“CHECKING CUSTOMER DATABASE”);

$result0 = mysql_query(“SELECT * FROM TABLEISHERE WHERE Pnumber = ‘$numtosearch2’ or Altphone = ‘$numtosearch2’”);

$countResults0 = mysql_num_rows($result0);

$countResults = $countResults0 + $countResults1 + $countResults2 + $countResults3 + $countResults4 + $countResults5;

//$agi->verbose(“Searching $numtosearch2”);

if($countResults >= ‘1’){
$agi->verbose(“$numtosearch2 FOUND IN CUSTOMER DATABASE”);

$agi->exec(‘Read’, ‘keypress1,custom/numsearch,1,1,20’);

$keypress = $agi->get_variable(keypress1);

if ($keypress[‘data’] == ‘1’)
{
$agi->verbose(“CALLING $numtosearch2 USER OVERRIDE DETECTED”);
$randomizeCID;
$agi->exec(“Dial”,“Local/$callthisnum”);
exit;
}

else

{
$agi->verbose(“HANING UP $numtosearch2 NO INPUT DETECTED”);
$agi->stream_file(‘goodbye’);
$agi->hangup();
exit;
}

}
else
{
$agi->verbose(“$numtosearch2 NOT FOUND IN CUSTOMER DATABASE”);
$agi->verbose(“CALLING $numtosearch2”);
$randomizeCID;
$agi->exec(“Dial”,“Local/$callthisnum”);
exit;

}
?>

dicko · April 10, 2015, 4:46pm

Have you checked a call after

agi set debug on

? The script is very verbose in it’s output.

mattjfrank · May 6, 2015, 3:24am

I finally had a chance to look at this more tonight.

The only thing I’m getting that is likely related but I’m not sure why is

[2015-05-05 22:22:07] NOTICE[13937][C-0001adc6]: chan_local.c:971 local_call: No such extension/context XXX-XXX-XXXX@default while calling Local channel

dicko · May 6, 2015, 3:41am

Neither the default context exists in FreePBX nor will any extension with “-” in it be generally acceptable, you need to get rid of them, there is no “-” on a telephone dialpad .

Sorry but you need to rewrite the script to suit what you have. Either you haven’t turned agi debugging on, you neglected to post that bit or you are hopelessly confused as to how it all works, I would contact the author of the code you are using.

mattjfrank · November 3, 2015, 9:48pm

I’m still having this issue. To clarify a few things. I wrote this script, what it does is take any outbound call and checks the number against a do not call list and existing customer list. But forget all that because I’ve been able to determine it’s not at all relevant because even this simple part of the script replicates the same issue.

#!/usr/bin/php -q
<?php
set_time_limit(0);
require('phpagi.php');
$agi = new AGI();
$agi->answer();

$numtosearch = $argv[1];
$callthisnum = "$numtosearch";
$thelength = strlen($numtosearch);


$agi->exec("Dial","LOCAL/$callthisnum");

?>

Here is the issue.
If a call is placed 1NXXNXXXXXX and passed through this script the call does not record.
If a call is placed as NXXNXXXXX and passed through this script it does record.

Here is how the script is called from /etc/asterisk/extensions_custom.conf

exten => _1NXXNXXXXXX,n,AGI(numsearch2.php,${EXTEN})
exten => _NXXNXXXXXX,n,AGI(numsearch2.php,${EXTEN})

Here is output when the call records

-- Executing [712NXXXXXX@from-internal:1] Macro("SIP/7250-000313d7", "user-callerid,LIMIT,EXTERNAL,") in new stack
-- Executing [s@macro-user-callerid:1] Set("SIP/7250-000313d7", "TOUCH_MONITOR=1446586991.715665") in new stack
-- Executing [s@macro-user-callerid:2] Set("SIP/7250-000313d7", "AMPUSER=7250") in new stack
-- Executing [s@macro-user-callerid:3] GotoIf("SIP/7250-000313d7", "0?report") in new stack
-- Executing [s@macro-user-callerid:4] ExecIf("SIP/7250-000313d7", "1?Set(REALCALLERIDNUM=7250)") in new stack
-- Executing [s@macro-user-callerid:5] Set("SIP/7250-000313d7", "AMPUSER=7250") in new stack
-- Executing [s@macro-user-callerid:6] GotoIf("SIP/7250-000313d7", "0?limit") in new stack
-- Executing [s@macro-user-callerid:7] Set("SIP/7250-000313d7", "AMPUSERCIDNAME=7250 matt") in new stack
-- Executing [s@macro-user-callerid:8] GotoIf("SIP/7250-000313d7", "0?report") in new stack
-- Executing [s@macro-user-callerid:9] Set("SIP/7250-000313d7", "AMPUSERCID=7250") in new stack
-- Executing [s@macro-user-callerid:10] Set("SIP/7250-000313d7", "__DIAL_OPTIONS=Ttr") in new stack
-- Executing [s@macro-user-callerid:11] Set("SIP/7250-000313d7", "CALLERID(all)="7250 matt" <7250>") in new stack
-- Executing [s@macro-user-callerid:12] GotoIf("SIP/7250-000313d7", "0?limit") in new stack
-- Executing [s@macro-user-callerid:13] ExecIf("SIP/7250-000313d7", "1?Set(GROUP(concurrency_limit)=7250)") in new stack
-- Executing [s@macro-user-callerid:14] GotoIf("SIP/7250-000313d7", "1?continue") in new stack
-- Goto (macro-user-callerid,s,27)
-- Executing [s@macro-user-callerid:27] Set("SIP/7250-000313d7", "CALLERID(number)=7250") in new stack
-- Executing [s@macro-user-callerid:28] Set("SIP/7250-000313d7", "CALLERID(name)=7250 matt") in new stack
-- Executing [s@macro-user-callerid:29] Set("SIP/7250-000313d7", "CDR(cnum)=7250") in new stack
-- Executing [s@macro-user-callerid:30] Set("SIP/7250-000313d7", "CDR(cnam)=7250 matt") in new stack
-- Executing [s@macro-user-callerid:31] Set("SIP/7250-000313d7", "CHANNEL(language)=en") in new stack
-- Executing [712NXXXXXX@from-internal:2] Gosub("SIP/7250-000313d7", "sub-record-check,s,1(out,712NXXXXXX,force)") in new stack
-- Executing [s@sub-record-check:1] GotoIf("SIP/7250-000313d7", "0?initialized") in new stack
-- Executing [s@sub-record-check:2] Set("SIP/7250-000313d7", "__REC_STATUS=INITIALIZED") in new stack
-- Executing [s@sub-record-check:3] Set("SIP/7250-000313d7", "NOW=1446586991") in new stack
-- Executing [s@sub-record-check:4] Set("SIP/7250-000313d7", "__DAY=03") in new stack
-- Executing [s@sub-record-check:5] Set("SIP/7250-000313d7", "__MONTH=11") in new stack
-- Executing [s@sub-record-check:6] Set("SIP/7250-000313d7", "__YEAR=2015") in new stack
-- Executing [s@sub-record-check:7] Set("SIP/7250-000313d7", "__TIMESTR=20151103-154311") in new stack
-- Executing [s@sub-record-check:8] Set("SIP/7250-000313d7", "__FROMEXTEN=7250") in new stack
-- Executing [s@sub-record-check:9] Set("SIP/7250-000313d7", "__MON_FMT=wav") in new stack
-- Executing [s@sub-record-check:10] NoOp("SIP/7250-000313d7", "Recordings initialized") in new stack
-- Executing [s@sub-record-check:11] ExecIf("SIP/7250-000313d7", "0?Set(ARG3=dontcare)") in new stack
-- Executing [s@sub-record-check:12] Set("SIP/7250-000313d7", "REC_POLICY_MODE_SAVE=") in new stack
-- Executing [s@sub-record-check:13] ExecIf("SIP/7250-000313d7", "0?Set(REC_STATUS=NO)") in new stack
-- Executing [s@sub-record-check:14] GotoIf("SIP/7250-000313d7", "3?checkaction") in new stack
-- Goto (sub-record-check,s,17)
-- Executing [s@sub-record-check:17] GotoIf("SIP/7250-000313d7", "1?sub-record-check,out,1") in new stack
-- Goto (sub-record-check,out,1)
-- Executing [out@sub-record-check:1] NoOp("SIP/7250-000313d7", "Outbound Recording Check from 7250 to 712NXXXXXX") in new stack
-- Executing [out@sub-record-check:2] Set("SIP/7250-000313d7", "RECMODE=force") in new stack
-- Executing [out@sub-record-check:3] ExecIf("SIP/7250-000313d7", "0?Goto(routewins)") in new stack
-- Executing [out@sub-record-check:4] ExecIf("SIP/7250-000313d7", "1?Goto(routewins)") in new stack
-- Goto (sub-record-check,out,7)
-- Executing [out@sub-record-check:7] Gosub("SIP/7250-000313d7", "recordcheck,1(force,out,712NXXXXXX)") in new stack
-- Executing [recordcheck@sub-record-check:1] NoOp("SIP/7250-000313d7", "Starting recording check against force") in new stack
-- Executing [recordcheck@sub-record-check:2] Goto("SIP/7250-000313d7", "force") in new stack
-- Goto (sub-record-check,recordcheck,5)
-- Executing [recordcheck@sub-record-check:5] Set("SIP/7250-000313d7", "__REC_POLICY_MODE=FORCE") in new stack
-- Executing [recordcheck@sub-record-check:6] GotoIf("SIP/7250-000313d7", "1?startrec") in new stack
-- Goto (sub-record-check,recordcheck,16)
-- Executing [recordcheck@sub-record-check:16] NoOp("SIP/7250-000313d7", "Starting recording: out, 712NXXXXXX") in new stack
-- Executing [recordcheck@sub-record-check:17] Set("SIP/7250-000313d7", "AUDIOHOOK_INHERIT(MixMonitor)=yes") in new stack
-- Executing [recordcheck@sub-record-check:18] Set("SIP/7250-000313d7", "__CALLFILENAME=out-712NXXXXXX-7250-20151103-154311-1446586991.715665") in new stack
-- Executing [recordcheck@sub-record-check:19] MixMonitor("SIP/7250-000313d7", "2015/11/03/out-712NXXXXXX-7250-20151103-154311-1446586991.715665.wav,ai(LOCAL_MIXMON_ID),") in new stack
-- Executing [recordcheck@sub-record-check:20] Set("SIP/7250-000313d7", "__MIXMON_ID=0x7f44e844d7f0") in new stack
-- Executing [recordcheck@sub-record-check:21] Set("SIP/7250-000313d7", "__RECORD_ID=SIP/7250-000313d7") in new stack
-- Executing [recordcheck@sub-record-check:22] Set("SIP/7250-000313d7", "__REC_STATUS=RECORDING") in new stack
-- Executing [recordcheck@sub-record-check:23] Set("SIP/7250-000313d7", "CDR(recordingfile)=out-712NXXXXXX-7250-20151103-154311-1446586991.715665.wav") in new stack
-- Executing [recordcheck@sub-record-check:24] Return("SIP/7250-000313d7", "") in new stack
-- Executing [out@sub-record-check:8] Return("SIP/7250-000313d7", "") in new stack
-- Executing [712NXXXXXX@from-internal:3] AGI("SIP/7250-000313d7", "numsearch2.php,712NXXXXXX") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/numsearch2.php
== Begin MixMonitor Recording SIP/7250-000313d7
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('ANSWER',{ts '2015-11-03 15:43:11.116861'},'7250 matt','7250','7250','','712NXXXXXX','712NXXXXXX','from-internal','SIP/7250-000313d7','AGI','numsearch2.php,712NXXXXXX',3,'','1446586991.715665','1446586991.715665','','','')]
   > 0x7f44895cc520 -- Probation passed - setting RTP source address to xxx.xxx.xxx.xxx:10272
-- AGI Script Executing Application: (Dial) Options: (LOCAL/712NXXXXXX)
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_START',{ts '2015-11-03 15:43:11.203486'},'','','','','','712NXXXXXX','default','Local/712NXXXXXX@default-0003ebdc;1','','',3,'','1446586991.715666','1446586991.715665','','','')]
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_START',{ts '2015-11-03 15:43:11.206141'},'','','','','','712NXXXXXX','default','Local/712NXXXXXX@default-0003ebdc;2','','',3,'','1446586991.715667','1446586991.715665','','','')]
[2015-11-03 15:43:11] NOTICE[31129][C-00044d92]: chan_local.c:971 local_call: No such extension/context 712NXXXXXX@default while calling Local channel
-- Couldn't call LOCAL/712NXXXXXX
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('HANGUP',{ts '2015-11-03 15:43:11.208517'},'','712NXXXXXX','','','','712NXXXXXX','default','Local/712NXXXXXX@default-0003ebdc;1','AppDial','(Outgoing Line)',3,'','1446586991.715666','1446586991.715665','','','')]
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('HANGUP',{ts '2015-11-03 15:43:11.209530'},'7250 matt','7250','7250','','','712NXXXXXX','default','Local/712NXXXXXX@default-0003ebdc;2','','',3,'','1446586991.715667','1446586991.715665','','','')]
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_END',{ts '2015-11-03 15:43:11.210122'},'7250 matt','7250','7250','','','712NXXXXXX','default','Local/712NXXXXXX@default-0003ebdc;2','','',3,'','1446586991.715667','1446586991.715665','','','')]
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_END',{ts '2015-11-03 15:43:11.210685'},'','712NXXXXXX','','','','712NXXXXXX','default','Local/712NXXXXXX@default-0003ebdc;1','AppDial','(Outgoing Line)',3,'','1446586991.715666','1446586991.715665','','','')]
== Everyone is busy/congested at this time (0:0/0/0)
-- <SIP/7250-000313d7>AGI Script numsearch2.php completed, returning 0
-- Executing [712NXXXXXX@from-internal:4] Set("SIP/7250-000313d7", "_NODEST=") in new stack
-- Executing [712NXXXXXX@from-internal:5] Macro("SIP/7250-000313d7", "dialout-trunk,2,1712NXXXXXX,,off") in new stack
-- Executing [s@macro-dialout-trunk:1] Set("SIP/7250-000313d7", "DIAL_TRUNK=2") in new stack
-- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/7250-000313d7", "0?sub-pincheck,s,1()") in new stack
-- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/7250-000313d7", "0?disabletrunk,1") in new stack
-- Executing [s@macro-dialout-trunk:4] Set("SIP/7250-000313d7", "DIAL_NUMBER=1712NXXXXXX") in new stack
-- Executing [s@macro-dialout-trunk:5] Set("SIP/7250-000313d7", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
-- Executing [s@macro-dialout-trunk:6] Set("SIP/7250-000313d7", "OUTBOUND_GROUP=OUT_2") in new stack
-- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/7250-000313d7", "0?nomax") in new stack
-- Executing [s@macro-dialout-trunk:8] GotoIf("SIP/7250-000313d7", "0?chanfull") in new stack
-- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/7250-000313d7", "0?skipoutcid") in new stack
-- Executing [s@macro-dialout-trunk:10] Set("SIP/7250-000313d7", "DIAL_TRUNK_OPTIONS=Tt") in new stack
-- Executing [s@macro-dialout-trunk:11] Macro("SIP/7250-000313d7", "outbound-callerid,2") in new stack
-- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/7250-000313d7", "0?Set(CALLERPRES()=)") in new stack
-- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/7250-000313d7", "0?Set(REALCALLERIDNUM=7250)") in new stack
-- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/7250-000313d7", "1?normcid") in new stack
-- Goto (macro-outbound-callerid,s,6)
-- Executing [s@macro-outbound-callerid:6] Set("SIP/7250-000313d7", "USEROUTCID=877NXXXXXX") in new stack
-- Executing [s@macro-outbound-callerid:7] Set("SIP/7250-000313d7", "EMERGENCYCID=") in new stack
-- Executing [s@macro-outbound-callerid:8] Set("SIP/7250-000313d7", "TRUNKOUTCID=") in new stack
-- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/7250-000313d7", "1?trunkcid") in new stack
-- Goto (macro-outbound-callerid,s,14)
-- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/7250-000313d7", "0?Set(CALLERID(all)=)") in new stack
-- Executing [s@macro-outbound-callerid:15] ExecIf("SIP/7250-000313d7", "1?Set(CALLERID(all)=877NXXXXXX)") in new stack
-- Executing [s@macro-outbound-callerid:16] ExecIf("SIP/7250-000313d7", "0?Set(CALLERID(all)=)") in new stack
-- Executing [s@macro-outbound-callerid:17] ExecIf("SIP/7250-000313d7", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack
-- Executing [s@macro-outbound-callerid:18] Set("SIP/7250-000313d7", "CDR(outbound_cnum)=877NXXXXXX") in new stack
-- Executing [s@macro-outbound-callerid:19] Set("SIP/7250-000313d7", "CDR(outbound_cnam)=") in new stack
-- Executing [s@macro-dialout-trunk:12] GosubIf("SIP/7250-000313d7", "1?sub-flp-2,s,1()") in new stack
-- Executing [s@sub-flp-2:1] ExecIf("SIP/7250-000313d7", "1?Set(TARGET_FLP_2=+1712NXXXXXX)") in new stack
-- Executing [s@sub-flp-2:2] GotoIf("SIP/7250-000313d7", "1?match") in new stack
-- Goto (sub-flp-2,s,4)
-- Executing [s@sub-flp-2:4] Set("SIP/7250-000313d7", "DIAL_NUMBER=+1712NXXXXXX") in new stack
-- Executing [s@sub-flp-2:5] Return("SIP/7250-000313d7", "") in new stack
-- Executing [s@macro-dialout-trunk:13] Set("SIP/7250-000313d7", "OUTNUM=+1712NXXXXXX") in new stack
-- Executing [s@macro-dialout-trunk:14] Set("SIP/7250-000313d7", "custom=SIP/bandwidth") in new stack
-- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/7250-000313d7", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^)Tt)") in new stack
-- Executing [s@macro-dialout-trunk:16] ExecIf("SIP/7250-000313d7", "0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))") in new stack
-- Executing [s@macro-dialout-trunk:17] Macro("SIP/7250-000313d7", "dialout-trunk-predial-hook,") in new stack
-- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/7250-000313d7", "") in new stack
-- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/7250-000313d7", "0?bypass,1") in new stack
-- Executing [s@macro-dialout-trunk:19] ExecIf("SIP/7250-000313d7", "1?Set(CONNECTEDLINE(num,i)=+1712NXXXXXX)") in new stack
-- Executing [s@macro-dialout-trunk:20] ExecIf("SIP/7250-000313d7", "1?Set(CONNECTEDLINE(name,i)=CID:877NXXXXXX)") in new stack
-- Executing [s@macro-dialout-trunk:21] GotoIf("SIP/7250-000313d7", "0?customtrunk") in new stack
-- Executing [s@macro-dialout-trunk:22] Dial("SIP/7250-000313d7", "SIP/bandwidth/+1712NXXXXXX,300,Tt") in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_START',{ts '2015-11-03 15:43:11.227148'},'','','','','','s','from-pstn','SIP/bandwidth-000313d8','','',3,'','1446586991.715668','1446586991.715665','','','')]
-- Called SIP/bandwidth/+1712NXXXXXX
   > 0x7f44e8c0e0a0 -- Probation passed - setting RTP source address to 67.231.13.72:41142
-- SIP/bandwidth-000313d8 is making progress passing it to SIP/7250-000313d7
   > 0x7f44e8c0e0a0 -- Probation passed - setting RTP source address to 67.231.13.72:41142
-- SIP/bandwidth-000313d8 is making progress passing it to SIP/7250-000313d7
   > 0x7f44895cc520 -- Switching RTP source address to 10.16.10.15:4058
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('ANSWER',{ts '2015-11-03 15:43:19.22982'},'CID:877NXXXXXX','712NXXXXXX','','','','712NXXXXXX','from-pstn','SIP/bandwidth-000313d8','AppDial','(Outgoing Line)',3,'','1446586991.715668','1446586991.715665','','','')]
-- SIP/bandwidth-000313d8 answered SIP/7250-000313d7
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('BRIDGE_START',{ts '2015-11-03 15:43:19.26550'},'','877NXXXXXX','7250','','712NXXXXXX','s','macro-dialout-trunk','SIP/7250-000313d7','Dial','SIP/bandwidth/+1712NXXXXXX,300,Tt',3,'','1446586991.715665','1446586991.715665','SIP/bandwidth-000313d8','','')]
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('BRIDGE_END',{ts '2015-11-03 15:43:29.605584'},'','877NXXXXXX','7250','','712NXXXXXX','s','macro-dialout-trunk','SIP/7250-000313d7','Dial','SIP/bandwidth/+1712NXXXXXX,300,Tt',3,'','1446586991.715665','1446586991.715665','SIP/bandwidth-000313d8','','')]
-- Executing [h@macro-dialout-trunk:1] Macro("SIP/7250-000313d7", "hangupcall,") in new stack
-- Executing [s@macro-hangupcall:1] ExecIf("SIP/7250-000313d7", "0?Set(CDR(recordingfile)=out-712NXXXXXX-7250-20151103-154311-1446586991.715665.wav)") in new stack
-- Executing [s@macro-hangupcall:2] GotoIf("SIP/7250-000313d7", "1?theend") in new stack
-- Goto (macro-hangupcall,s,4)
-- Executing [s@macro-hangupcall:4] Hangup("SIP/7250-000313d7", "") in new stack
== Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/7250-000313d7' in macro 'hangupcall'
== Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on 'SIP/7250-000313d7'
   > [INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,uniqueid,recordingfile,cnum,cnam,outbound_cnum) VALUES ({ ts '2015-11-03 15:43:11' },'7250','7250','712NXXXXXX','from-internal','SIP/7250-000313d7','SIP/bandwidth-000313d8','Dial','SIP/bandwidth/+1712NXXXXXX,300,Tt',18,10,'ANSWERED',3,'1446586991.715665','out-712NXXXXXX-7250-20151103-154311-1446586991.715665.wav','7250','7250 matt','877NXXXXXX')]
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('HANGUP',{ts '2015-11-03 15:43:29.612352'},'CID:877NXXXXXX','712NXXXXXX','','','','','macro-dialout-trunk','SIP/bandwidth-000313d8','AppDial','(Outgoing Line)',3,'','1446586991.715668','1446586991.715665','','','')]
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_END',{ts '2015-11-03 15:43:29.612687'},'CID:877NXXXXXX','712NXXXXXX','','','','','macro-dialout-trunk','SIP/bandwidth-000313d8','AppDial','(Outgoing Line)',3,'','1446586991.715668','1446586991.715665','','','')]
== Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on 'SIP/7250-000313d7' in macro 'dialout-trunk'
== Spawn extension (from-internal, 712NXXXXXX, 5) exited non-zero on 'SIP/7250-000313d7'
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('HANGUP',{ts '2015-11-03 15:43:29.613368'},'','877NXXXXXX','7250','','712NXXXXXX','712NXXXXXX','from-internal','SIP/7250-000313d7','','',3,'','1446586991.715665','1446586991.715665','','','')]
== MixMonitor close filestream (mixed)
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_END',{ts '2015-11-03 15:43:29.615359'},'','877NXXXXXX','7250','','712NXXXXXX','712NXXXXXX','from-internal','SIP/7250-000313d7','','',3,'','1446586991.715665','1446586991.715665','','','')]
   > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('LINKEDID_END',{ts '2015-11-03 15:43:29.615712'},'','877NXXXXXX','7250','','712NXXXXXX','712NXXXXXX','from-internal','SIP/7250-000313d7','','',3,'','1446586991.715665','1446586991.715665','','','')]
== End MixMonitor Recording SIP/7250-000313d7
voice*CLI>

mattjfrank · November 3, 2015, 9:48pm

Here is output when call doesn’t record

  -- Executing [1712NXXXXXX@from-internal:1] Macro("SIP/7250-000313cb", "user-callerid,LIMIT,EXTERNAL,") in new stack
  -- Executing [s@macro-user-callerid:1] Set("SIP/7250-000313cb", "TOUCH_MONITOR=1446586750.715627") in new stack
  -- Executing [s@macro-user-callerid:2] Set("SIP/7250-000313cb", "AMPUSER=7250") in new stack
  -- Executing [s@macro-user-callerid:3] GotoIf("SIP/7250-000313cb", "0?report") in new stack
  -- Executing [s@macro-user-callerid:4] ExecIf("SIP/7250-000313cb", "1?Set(REALCALLERIDNUM=7250)") in new stack
  -- Executing [s@macro-user-callerid:5] Set("SIP/7250-000313cb", "AMPUSER=7250") in new stack
  -- Executing [s@macro-user-callerid:6] GotoIf("SIP/7250-000313cb", "0?limit") in new stack
  -- Executing [s@macro-user-callerid:7] Set("SIP/7250-000313cb", "AMPUSERCIDNAME=7250 matt") in new stack
  -- Executing [s@macro-user-callerid:8] GotoIf("SIP/7250-000313cb", "0?report") in new stack
  -- Executing [s@macro-user-callerid:9] Set("SIP/7250-000313cb", "AMPUSERCID=7250") in new stack
  -- Executing [s@macro-user-callerid:10] Set("SIP/7250-000313cb", "__DIAL_OPTIONS=Ttr") in new stack
  -- Executing [s@macro-user-callerid:11] Set("SIP/7250-000313cb", "CALLERID(all)="7250 matt" <7250>") in new stack
  -- Executing [s@macro-user-callerid:12] GotoIf("SIP/7250-000313cb", "0?limit") in new stack
  -- Executing [s@macro-user-callerid:13] ExecIf("SIP/7250-000313cb", "1?Set(GROUP(concurrency_limit)=7250)") in new stack
  -- Executing [s@macro-user-callerid:14] GotoIf("SIP/7250-000313cb", "1?continue") in new stack
  -- Goto (macro-user-callerid,s,27)
  -- Executing [s@macro-user-callerid:27] Set("SIP/7250-000313cb", "CALLERID(number)=7250") in new stack
  -- Executing [s@macro-user-callerid:28] Set("SIP/7250-000313cb", "CALLERID(name)=7250 matt") in new stack
  -- Executing [s@macro-user-callerid:29] Set("SIP/7250-000313cb", "CDR(cnum)=7250") in new stack
  -- Executing [s@macro-user-callerid:30] Set("SIP/7250-000313cb", "CDR(cnam)=7250 matt") in new stack
  -- Executing [s@macro-user-callerid:31] Set("SIP/7250-000313cb", "CHANNEL(language)=en") in new stack
  -- Executing [1712NXXXXXX@from-internal:2] AGI("SIP/7250-000313cb", "numsearch2.php,1712NXXXXXX") in new stack
  -- Launched AGI Script /var/lib/asterisk/agi-bin/numsearch2.php
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('ANSWER',{ts '2015-11-03 15:39:10.478680'},'7250 matt','7250','7250','','1712NXXXXXX','1712NXXXXXX','from-internal','SIP/7250-000313cb','AGI','numsearch2.php,1712NXXXXXX',3,'','1446586750.715627','1446586750.715627','','','')]
     > 0x7f44895cc520 -- Probation passed - setting RTP source address to xxx.xxx.xxx.xxx:12081
  -- AGI Script Executing Application: (Dial) Options: (LOCAL/1712NXXXXXX)
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_START',{ts '2015-11-03 15:39:10.572712'},'','','','','','1712NXXXXXX','default','Local/1712NXXXXXX@default-0003ebcf;1','','',3,'','1446586750.715628','1446586750.715627','','','')]
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_START',{ts '2015-11-03 15:39:10.574384'},'','','','','','1712NXXXXXX','default','Local/1712NXXXXXX@default-0003ebcf;2','','',3,'','1446586750.715629','1446586750.715627','','','')]
[2015-11-03 15:39:10] NOTICE[30971][C-00044d87]: chan_local.c:971 local_call: No such extension/context 1712NXXXXXX@default while calling Local channel
  -- Couldn't call LOCAL/1712NXXXXXX
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('HANGUP',{ts '2015-11-03 15:39:10.576407'},'','1712NXXXXXX','','','','1712NXXXXXX','default','Local/1712NXXXXXX@default-0003ebcf;1','AppDial','(Outgoing Line)',3,'','1446586750.715628','1446586750.715627','','','')]
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('HANGUP',{ts '2015-11-03 15:39:10.577362'},'7250 matt','7250','7250','','','1712NXXXXXX','default','Local/1712NXXXXXX@default-0003ebcf;2','','',3,'','1446586750.715629','1446586750.715627','','','')]
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_END',{ts '2015-11-03 15:39:10.578369'},'7250 matt','7250','7250','','','1712NXXXXXX','default','Local/1712NXXXXXX@default-0003ebcf;2','','',3,'','1446586750.715629','1446586750.715627','','','')]
== Everyone is busy/congested at this time (0:0/0/0)
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_END',{ts '2015-11-03 15:39:10.579339'},'','1712NXXXXXX','','','','1712NXXXXXX','default','Local/1712NXXXXXX@default-0003ebcf;1','AppDial','(Outgoing Line)',3,'','1446586750.715628','1446586750.715627','','','')]
  -- <SIP/7250-000313cb>AGI Script numsearch2.php completed, returning 0
  -- Executing [1712NXXXXXX@from-internal:3] Set("SIP/7250-000313cb", "MOHCLASS=default") in new stack
  -- Executing [1712NXXXXXX@from-internal:4] Set("SIP/7250-000313cb", "_NODEST=") in new stack
  -- Executing [1712NXXXXXX@from-internal:5] Macro("SIP/7250-000313cb", "dialout-trunk,2,1712NXXXXXX,,off") in new stack
  -- Executing [s@macro-dialout-trunk:1] Set("SIP/7250-000313cb", "DIAL_TRUNK=2") in new stack
  -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/7250-000313cb", "0?sub-pincheck,s,1()") in new stack
  -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/7250-000313cb", "0?disabletrunk,1") in new stack
  -- Executing [s@macro-dialout-trunk:4] Set("SIP/7250-000313cb", "DIAL_NUMBER=1712NXXXXXX") in new stack
  -- Executing [s@macro-dialout-trunk:5] Set("SIP/7250-000313cb", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
  -- Executing [s@macro-dialout-trunk:6] Set("SIP/7250-000313cb", "OUTBOUND_GROUP=OUT_2") in new stack
  -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/7250-000313cb", "0?nomax") in new stack
  -- Executing [s@macro-dialout-trunk:8] GotoIf("SIP/7250-000313cb", "0?chanfull") in new stack
  -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/7250-000313cb", "0?skipoutcid") in new stack
  -- Executing [s@macro-dialout-trunk:10] Set("SIP/7250-000313cb", "DIAL_TRUNK_OPTIONS=Tt") in new stack
  -- Executing [s@macro-dialout-trunk:11] Macro("SIP/7250-000313cb", "outbound-callerid,2") in new stack
  -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/7250-000313cb", "0?Set(CALLERPRES()=)") in new stack
  -- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/7250-000313cb", "0?Set(REALCALLERIDNUM=7250)") in new stack
  -- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/7250-000313cb", "1?normcid") in new stack
  -- Goto (macro-outbound-callerid,s,6)
  -- Executing [s@macro-outbound-callerid:6] Set("SIP/7250-000313cb", "USEROUTCID=1877NXXXXXX") in new stack
  -- Executing [s@macro-outbound-callerid:7] Set("SIP/7250-000313cb", "EMERGENCYCID=") in new stack
  -- Executing [s@macro-outbound-callerid:8] Set("SIP/7250-000313cb", "TRUNKOUTCID=") in new stack
  -- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/7250-000313cb", "1?trunkcid") in new stack
  -- Goto (macro-outbound-callerid,s,14)
  -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/7250-000313cb", "0?Set(CALLERID(all)=)") in new stack
  -- Executing [s@macro-outbound-callerid:15] ExecIf("SIP/7250-000313cb", "1?Set(CALLERID(all)=1877NXXXXXX)") in new stack
  -- Executing [s@macro-outbound-callerid:16] ExecIf("SIP/7250-000313cb", "0?Set(CALLERID(all)=)") in new stack
  -- Executing [s@macro-outbound-callerid:17] ExecIf("SIP/7250-000313cb", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack
  -- Executing [s@macro-outbound-callerid:18] Set("SIP/7250-000313cb", "CDR(outbound_cnum)=1877NXXXXXX") in new stack
  -- Executing [s@macro-outbound-callerid:19] Set("SIP/7250-000313cb", "CDR(outbound_cnam)=") in new stack
  -- Executing [s@macro-dialout-trunk:12] GosubIf("SIP/7250-000313cb", "1?sub-flp-2,s,1()") in new stack
  -- Executing [s@sub-flp-2:1] ExecIf("SIP/7250-000313cb", "1?Set(TARGET_FLP_2=+1712NXXXXXX)") in new stack
  -- Executing [s@sub-flp-2:2] GotoIf("SIP/7250-000313cb", "1?match") in new stack
  -- Goto (sub-flp-2,s,4)
  -- Executing [s@sub-flp-2:4] Set("SIP/7250-000313cb", "DIAL_NUMBER=+1712NXXXXXX") in new stack
  -- Executing [s@sub-flp-2:5] Return("SIP/7250-000313cb", "") in new stack
  -- Executing [s@macro-dialout-trunk:13] Set("SIP/7250-000313cb", "OUTNUM=+1712NXXXXXX") in new stack
  -- Executing [s@macro-dialout-trunk:14] Set("SIP/7250-000313cb", "custom=SIP/bandwidth") in new stack
  -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/7250-000313cb", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)") in new stack
  -- Executing [s@macro-dialout-trunk:16] ExecIf("SIP/7250-000313cb", "0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))") in new stack
  -- Executing [s@macro-dialout-trunk:17] Macro("SIP/7250-000313cb", "dialout-trunk-predial-hook,") in new stack
  -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/7250-000313cb", "") in new stack
  -- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/7250-000313cb", "0?bypass,1") in new stack
  -- Executing [s@macro-dialout-trunk:19] ExecIf("SIP/7250-000313cb", "1?Set(CONNECTEDLINE(num,i)=+1712NXXXXXX)") in new stack
  -- Executing [s@macro-dialout-trunk:20] ExecIf("SIP/7250-000313cb", "1?Set(CONNECTEDLINE(name,i)=CID:1877NXXXXXX)") in new stack
  -- Executing [s@macro-dialout-trunk:21] GotoIf("SIP/7250-000313cb", "0?customtrunk") in new stack
  -- Executing [s@macro-dialout-trunk:22] Dial("SIP/7250-000313cb", "SIP/bandwidth/+1712NXXXXXX,300,Tt") in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_START',{ts '2015-11-03 15:39:10.593957'},'','','','','','s','from-pstn','SIP/bandwidth-000313cc','','',3,'','1446586750.715630','1446586750.715627','','','')]
  -- Called SIP/bandwidth/+1712NXXXXXX
     > 0x7f44e8bdd380 -- Probation passed - setting RTP source address to 67.231.13.72:39880
  -- SIP/bandwidth-000313cc is making progress passing it to SIP/7250-000313cb
     > 0x7f44e8bdd380 -- Probation passed - setting RTP source address to 67.231.13.72:39880
  -- SIP/bandwidth-000313cc is making progress passing it to SIP/7250-000313cb
     > 0x7f44895cc520 -- Switching RTP source address to 10.16.10.15:4054
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('ANSWER',{ts '2015-11-03 15:39:18.783155'},'CID:1877NXXXXXX','1712NXXXXXX','','','','1712NXXXXXX','from-pstn','SIP/bandwidth-000313cc','AppDial','(Outgoing Line)',3,'','1446586750.715630','1446586750.715627','','','')]
  -- SIP/bandwidth-000313cc answered SIP/7250-000313cb
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('BRIDGE_START',{ts '2015-11-03 15:39:18.786343'},'','1877NXXXXXX','7250','','1712NXXXXXX','s','macro-dialout-trunk','SIP/7250-000313cb','Dial','SIP/bandwidth/+1712NXXXXXX,300,Tt',3,'','1446586750.715627','1446586750.715627','SIP/bandwidth-000313cc','','')]
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('BRIDGE_END',{ts '2015-11-03 15:39:23.178742'},'','1877NXXXXXX','7250','','1712NXXXXXX','s','macro-dialout-trunk','SIP/7250-000313cb','Dial','SIP/bandwidth/+1712NXXXXXX,300,Tt',3,'','1446586750.715627','1446586750.715627','SIP/bandwidth-000313cc','','')]
  -- Executing [h@macro-dialout-trunk:1] Macro("SIP/7250-000313cb", "hangupcall,") in new stack
  -- Executing [s@macro-hangupcall:1] ExecIf("SIP/7250-000313cb", "0?Set(CDR(recordingfile)=.)") in new stack
  -- Executing [s@macro-hangupcall:2] GotoIf("SIP/7250-000313cb", "1?theend") in new stack
  -- Goto (macro-hangupcall,s,4)
  -- Executing [s@macro-hangupcall:4] Hangup("SIP/7250-000313cb", "") in new stack
== Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/7250-000313cb' in macro 'hangupcall'
== Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on 'SIP/7250-000313cb'
     > [INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,uniqueid,cnum,cnam,outbound_cnum) VALUES ({ ts '2015-11-03 15:39:10' },'7250','7250','1712NXXXXXX','from-internal','SIP/7250-000313cb','SIP/bandwidth-000313cc','Dial','SIP/bandwidth/+1712NXXXXXX,300,Tt',13,5,'ANSWERED',3,'1446586750.715627','7250','7250 matt','1877NXXXXXX')]
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('HANGUP',{ts '2015-11-03 15:39:23.186999'},'CID:1877NXXXXXX','1712NXXXXXX','','','','','macro-dialout-trunk','SIP/bandwidth-000313cc','AppDial','(Outgoing Line)',3,'','1446586750.715630','1446586750.715627','','','')]
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_END',{ts '2015-11-03 15:39:23.187649'},'CID:1877NXXXXXX','1712NXXXXXX','','','','','macro-dialout-trunk','SIP/bandwidth-000313cc','AppDial','(Outgoing Line)',3,'','1446586750.715630','1446586750.715627','','','')]
== Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on 'SIP/7250-000313cb' in macro 'dialout-trunk'
== Spawn extension (from-internal, 1712NXXXXXX, 5) exited non-zero on 'SIP/7250-000313cb'
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('HANGUP',{ts '2015-11-03 15:39:23.189657'},'','1877NXXXXXX','7250','','1712NXXXXXX','1712NXXXXXX','from-internal','SIP/7250-000313cb','','',3,'','1446586750.715627','1446586750.715627','','','')]
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('CHAN_END',{ts '2015-11-03 15:39:23.190973'},'','1877NXXXXXX','7250','','1712NXXXXXX','1712NXXXXXX','from-internal','SIP/7250-000313cb','','',3,'','1446586750.715627','1446586750.715627','','','')]
     > [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES ('LINKEDID_END',{ts '2015-11-03 15:39:23.191250'},'','1877NXXXXXX','7250','','1712NXXXXXX','1712NXXXXXX','from-internal','SIP/7250-000313cb','','',3,'','1446586750.715627','1446586750.715627','','','')]
voice*CLI>

dicko · November 3, 2015, 10:11pm

As I said before, turn on AGI debugging and liberally sprinkle your code with debugging output.

If you care to post the whole AGI script, someone might be able to help you.

mattjfrank · November 3, 2015, 10:14pm

AGI debug was on for those copy and paste. The entire code is up a few posts, but as I said it has nothing to do with the code because even with only those few lines of code the same behavior is exhibited.

dicko · November 3, 2015, 10:18pm

I see no attempts at debug output, AGI writes to stdout and reads from stdin, php can do that also.

Start here:-

http://www.voip-info.org/wiki/view/Asterisk+AGI+php

mattjfrank · November 3, 2015, 10:31pm

debug

voiceCLI> agi set debug on
AGI Debugging Enabled
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_START’,{ts ‘2015-11-03 16:28:31.930844’},‘7250 matt’,‘7250’,‘’,‘’,‘’,‘1712NXXXXXX’,‘from-internal’,‘SIP/7250-000313f7’,‘’,‘’,3,‘’,‘1446589711.715831’,‘1446589711.715831’,‘’,‘’,‘’)]
– Executing [1712NXXXXXX@from-internal:1] Macro(“SIP/7250-000313f7”, “user-callerid,LIMIT,EXTERNAL,”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/7250-000313f7”, “TOUCH_MONITOR=1446589711.715831”) in new stack
– Executing [s@macro-user-callerid:2] Set(“SIP/7250-000313f7”, “AMPUSER=7250”) in new stack
– Executing [s@macro-user-callerid:3] GotoIf(“SIP/7250-000313f7”, “0?report”) in new stack
– Executing [s@macro-user-callerid:4] ExecIf(“SIP/7250-000313f7”, “1?Set(REALCALLERIDNUM=7250)”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/7250-000313f7”, “AMPUSER=7250”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/7250-000313f7”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:7] Set(“SIP/7250-000313f7”, “AMPUSERCIDNAME=7250 matt”) in new stack
– Executing [s@macro-user-callerid:8] GotoIf(“SIP/7250-000313f7”, “0?report”) in new stack
– Executing [s@macro-user-callerid:9] Set(“SIP/7250-000313f7”, “AMPUSERCID=7250”) in new stack
– Executing [s@macro-user-callerid:10] Set(“SIP/7250-000313f7”, “__DIAL_OPTIONS=Ttr”) in new stack
– Executing [s@macro-user-callerid:11] Set(“SIP/7250-000313f7”, “CALLERID(all)=“7250 matt” <7250>”) in new stack
– Executing [s@macro-user-callerid:12] GotoIf(“SIP/7250-000313f7”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:13] ExecIf(“SIP/7250-000313f7”, “1?Set(GROUP(concurrency_limit)=7250)”) in new stack
– Executing [s@macro-user-callerid:14] GotoIf(“SIP/7250-000313f7”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,27)
– Executing [s@macro-user-callerid:27] Set(“SIP/7250-000313f7”, “CALLERID(number)=7250”) in new stack
– Executing [s@macro-user-callerid:28] Set(“SIP/7250-000313f7”, “CALLERID(name)=7250 matt”) in new stack
– Executing [s@macro-user-callerid:29] Set(“SIP/7250-000313f7”, “CDR(cnum)=7250”) in new stack
– Executing [s@macro-user-callerid:30] Set(“SIP/7250-000313f7”, “CDR(cnam)=7250 matt”) in new stack
– Executing [s@macro-user-callerid:31] Set(“SIP/7250-000313f7”, “CHANNEL(language)=en”) in new stack
– Executing [1712NXXXXXX@from-internal:2] AGI(“SIP/7250-000313f7”, “numsearch2.php,1712NXXXXXX”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/numsearch2.php
<SIP/7250-000313f7>AGI Tx >> agi_request: numsearch2.php
<SIP/7250-000313f7>AGI Tx >> agi_channel: SIP/7250-000313f7
<SIP/7250-000313f7>AGI Tx >> agi_language: en
<SIP/7250-000313f7>AGI Tx >> agi_type: SIP
<SIP/7250-000313f7>AGI Tx >> agi_uniqueid: 1446589711.715831
<SIP/7250-000313f7>AGI Tx >> agi_version: 11.16.0
<SIP/7250-000313f7>AGI Tx >> agi_callerid: 7250
<SIP/7250-000313f7>AGI Tx >> agi_calleridname: 7250 matt
<SIP/7250-000313f7>AGI Tx >> agi_callingpres: 0
<SIP/7250-000313f7>AGI Tx >> agi_callingani2: 0
<SIP/7250-000313f7>AGI Tx >> agi_callington: 0
<SIP/7250-000313f7>AGI Tx >> agi_callingtns: 0
<SIP/7250-000313f7>AGI Tx >> agi_dnid: 1712NXXXXXX
<SIP/7250-000313f7>AGI Tx >> agi_rdnis: unknown
<SIP/7250-000313f7>AGI Tx >> agi_context: from-internal
<SIP/7250-000313f7>AGI Tx >> agi_extension: 1712NXXXXXX
<SIP/7250-000313f7>AGI Tx >> agi_priority: 2
<SIP/7250-000313f7>AGI Tx >> agi_enhanced: 0.0
<SIP/7250-000313f7>AGI Tx >> agi_accountcode:
<SIP/7250-000313f7>AGI Tx >> agi_threadid: 139932559197952
<SIP/7250-000313f7>AGI Tx >> agi_arg_1: 1712NXXXXXX
<SIP/7250-000313f7>AGI Tx >>
<SIP/7250-000313f7>AGI Rx << ANSWER
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘ANSWER’,{ts ‘2015-11-03 16:28:31.976075’},‘7250 matt’,‘7250’,‘7250’,‘’,‘1712NXXXXXX’,‘1712NXXXXXX’,‘from-internal’,‘SIP/7250-000313f7’,‘AGI’,‘numsearch2.php,1712NXXXXXX’,3,‘’,‘1446589711.715831’,‘1446589711.715831’,‘’,‘’,‘’)]
> 0x7f44895cc520 – Probation passed - setting RTP source address to xxx.xxx.xxx.xxx:41245
<SIP/7250-000313f7>AGI Tx >> 200 result=0
<SIP/7250-000313f7>AGI Rx << EXEC Dial LOCAL/1712NXXXXXX
– AGI Script Executing Application: (Dial) Options: (LOCAL/1712NXXXXXX)
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_START’,{ts ‘2015-11-03 16:28:32.59664’},‘’,‘’,‘’,‘’,‘’,‘1712NXXXXXX’,‘default’,‘Local/1712NXXXXXX@default-0003ec1f;1’,‘’,‘’,3,‘’,‘1446589712.715832’,‘1446589711.715831’,‘’,‘’,‘’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_START’,{ts ‘2015-11-03 16:28:32.61460’},‘’,‘’,‘’,‘’,‘’,‘1712NXXXXXX’,‘default’,‘Local/1712NXXXXXX@default-0003ec1f;2’,‘’,‘’,3,‘’,‘1446589712.715833’,‘1446589711.715831’,‘’,‘’,‘’)]
[2015-11-03 16:28:32] NOTICE[32678][C-00044dde]: chan_local.c:971 local_call: No such extension/context 1712NXXXXXX@default while calling Local channel
– Couldn’t call LOCAL/1712NXXXXXX
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘HANGUP’,{ts ‘2015-11-03 16:28:32.63292’},‘’,‘1712NXXXXXX’,‘’,‘’,‘’,‘1712NXXXXXX’,‘default’,‘Local/1712NXXXXXX@default-0003ec1f;1’,‘AppDial’,‘(Outgoing Line)’,3,‘’,‘1446589712.715832’,‘1446589711.715831’,‘’,‘’,‘’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘HANGUP’,{ts ‘2015-11-03 16:28:32.64163’},‘7250 matt’,‘7250’,‘7250’,‘’,‘’,‘1712NXXXXXX’,‘default’,‘Local/1712NXXXXXX@default-0003ec1f;2’,‘’,‘’,3,‘’,‘1446589712.715833’,‘1446589711.715831’,‘’,‘’,‘’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_END’,{ts ‘2015-11-03 16:28:32.64828’},‘7250 matt’,‘7250’,‘7250’,‘’,‘’,‘1712NXXXXXX’,‘default’,‘Local/1712NXXXXXX@default-0003ec1f;2’,‘’,‘’,3,‘’,‘1446589712.715833’,‘1446589711.715831’,‘’,‘’,‘’)]
== Everyone is busy/congested at this time (0:0/0/0)
<SIP/7250-000313f7>AGI Tx >> 200 result=0
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_END’,{ts ‘2015-11-03 16:28:32.65281’},‘’,‘1712NXXXXXX’,‘’,‘’,‘’,‘1712NXXXXXX’,‘default’,‘Local/1712NXXXXXX@default-0003ec1f;1’,‘AppDial’,‘(Outgoing Line)’,3,‘’,‘1446589712.715832’,‘1446589711.715831’,‘’,‘’,‘’)]
– <SIP/7250-000313f7>AGI Script numsearch2.php completed, returning 0
– Executing [1712NXXXXXX@from-internal:3] Set(“SIP/7250-000313f7”, “MOHCLASS=default”) in new stack
– Executing [1712NXXXXXX@from-internal:4] Set(“SIP/7250-000313f7”, “_NODEST=”) in new stack
– Executing [1712NXXXXXX@from-internal:5] Macro(“SIP/7250-000313f7”, “dialout-trunk,2,1712NXXXXXX,off”) in new stack
– Executing [s@macro-dialout-trunk:1] Set(“SIP/7250-000313f7”, “DIAL_TRUNK=2”) in new stack
– Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/7250-000313f7”, “0?sub-pincheck,s,1()”) in new stack
– Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/7250-000313f7”, “0?disabletrunk,1”) in new stack
– Executing [s@macro-dialout-trunk:4] Set(“SIP/7250-000313f7”, “DIAL_NUMBER=1712NXXXXXX”) in new stack
– Executing [s@macro-dialout-trunk:5] Set(“SIP/7250-000313f7”, “DIAL_TRUNK_OPTIONS=Ttr”) in new stack
– Executing [s@macro-dialout-trunk:6] Set(“SIP/7250-000313f7”, “OUTBOUND_GROUP=OUT_2”) in new stack
– Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/7250-000313f7”, “0?nomax”) in new stack
– Executing [s@macro-dialout-trunk:8] GotoIf(“SIP/7250-000313f7”, “0?chanfull”) in new stack
– Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/7250-000313f7”, “0?skipoutcid”) in new stack
– Executing [s@macro-dialout-trunk:10] Set(“SIP/7250-000313f7”, “DIAL_TRUNK_OPTIONS=Tt”) in new stack
– Executing [s@macro-dialout-trunk:11] Macro(“SIP/7250-000313f7”, “outbound-callerid,2”) in new stack
– Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/7250-000313f7”, “0?Set(CALLERPRES()=)”) in new stack
– Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/7250-000313f7”, “0?Set(REALCALLERIDNUM=7250)”) in new stack
– Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/7250-000313f7”, “1?normcid”) in new stack
– Goto (macro-outbound-callerid,s,6)
– Executing [s@macro-outbound-callerid:6] Set(“SIP/7250-000313f7”, “USEROUTCID=877NXXXXXX”) in new stack
– Executing [s@macro-outbound-callerid:7] Set(“SIP/7250-000313f7”, “EMERGENCYCID=”) in new stack
– Executing [s@macro-outbound-callerid:8] Set(“SIP/7250-000313f7”, “TRUNKOUTCID=”) in new stack
– Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/7250-000313f7”, “1?trunkcid”) in new stack
– Goto (macro-outbound-callerid,s,14)
– Executing [s@macro-outbound-callerid:14] ExecIf(“SIP/7250-000313f7”, “0?Set(CALLERID(all)=)”) in new stack
– Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/7250-000313f7”, “1?Set(CALLERID(all)=877NXXXXXX)”) in new stack
– Executing [s@macro-outbound-callerid:16] ExecIf(“SIP/7250-000313f7”, “0?Set(CALLERID(all)=)”) in new stack
– Executing [s@macro-outbound-callerid:17] ExecIf(“SIP/7250-000313f7”, “0?Set(CALLERPRES()=prohib_passed_screen)”) in new stack
– Executing [s@macro-outbound-callerid:18] Set(“SIP/7250-000313f7”, “CDR(outbound_cnum)=877NXXXXXX”) in new stack
– Executing [s@macro-outbound-callerid:19] Set(“SIP/7250-000313f7”, “CDR(outbound_cnam)=”) in new stack
– Executing [s@macro-dialout-trunk:12] GosubIf(“SIP/7250-000313f7”, “1?sub-flp-2,s,1()”) in new stack
– Executing [s@sub-flp-2:1] ExecIf(“SIP/7250-000313f7”, “1?Set(TARGET_FLP_2=+1712NXXXXXX)”) in new stack
– Executing [s@sub-flp-2:2] GotoIf(“SIP/7250-000313f7”, “1?match”) in new stack
– Goto (sub-flp-2,s,4)
– Executing [s@sub-flp-2:4] Set(“SIP/7250-000313f7”, “DIAL_NUMBER=+1712NXXXXXX”) in new stack
– Executing [s@sub-flp-2:5] Return(“SIP/7250-000313f7”, “”) in new stack
– Executing [s@macro-dialout-trunk:13] Set(“SIP/7250-000313f7”, “OUTNUM=+1712NXXXXXX”) in new stack
– Executing [s@macro-dialout-trunk:14] Set(“SIP/7250-000313f7”, “custom=SIP/bandwidth”) in new stack
– Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/7250-000313f7”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)”) in new stack
– Executing [s@macro-dialout-trunk:16] ExecIf(“SIP/7250-000313f7”, “0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))”) in new stack
– Executing [s@macro-dialout-trunk:17] Macro(“SIP/7250-000313f7”, “dialout-trunk-predial-hook,”) in new stack
– Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/7250-000313f7”, “”) in new stack
– Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/7250-000313f7”, “0?bypass,1”) in new stack
– Executing [s@macro-dialout-trunk:19] ExecIf(“SIP/7250-000313f7”, “1?Set(CONNECTEDLINE(num,i)=+1712NXXXXXX)”) in new stack
– Executing [s@macro-dialout-trunk:20] ExecIf(“SIP/7250-000313f7”, “1?Set(CONNECTEDLINE(name,i)=CID:877NXXXXXX)”) in new stack
– Executing [s@macro-dialout-trunk:21] GotoIf(“SIP/7250-000313f7”, “0?customtrunk”) in new stack
– Executing [s@macro-dialout-trunk:22] Dial(“SIP/7250-000313f7”, “SIP/bandwidth/+1712NXXXXXX,300,Tt”) in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_START’,{ts ‘2015-11-03 16:28:32.78111’},‘’,‘’,‘’,‘’,‘’,‘s’,‘from-pstn’,‘SIP/bandwidth-000313f8’,‘’,‘’,3,‘’,‘1446589712.715834’,‘1446589711.715831’,‘’,‘’,‘’)]
– Called SIP/bandwidth/+1712NXXXXXX
– SIP/bandwidth-000313f8 is making progress passing it to SIP/7250-000313f7
> 0x7f44e8b31340 – Probation passed - setting RTP source address to 67.231.9.73:50942
– SIP/bandwidth-000313f8 is making progress passing it to SIP/7250-000313f7
> 0x7f44895cc520 – Switching RTP source address to 10.16.10.15:4064
– SIP/bandwidth-000313f8 answered SIP/7250-000313f7
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘ANSWER’,{ts ‘2015-11-03 16:28:40.452676’},‘CID:877NXXXXXX’,‘1712NXXXXXX’,‘’,‘’,‘’,‘1712NXXXXXX’,‘from-pstn’,‘SIP/bandwidth-000313f8’,‘AppDial’,‘(Outgoing Line)’,3,‘’,‘1446589712.715834’,‘1446589711.715831’,‘’,‘’,‘’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘BRIDGE_START’,{ts ‘2015-11-03 16:28:40.452960’},‘’,‘877NXXXXXX’,‘7250’,‘’,‘1712NXXXXXX’,‘s’,‘macro-dialout-trunk’,‘SIP/7250-000313f7’,‘Dial’,‘SIP/bandwidth/+1712NXXXXXX,300,Tt’,3,‘’,‘1446589711.715831’,‘1446589711.715831’,‘SIP/bandwidth-000313f8’,‘’,‘’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘BRIDGE_END’,{ts ‘2015-11-03 16:28:43.32330’},‘’,‘877NXXXXXX’,‘7250’,‘’,‘1712NXXXXXX’,‘s’,‘macro-dialout-trunk’,‘SIP/7250-000313f7’,‘Dial’,‘SIP/bandwidth/+1712NXXXXXX,300,Tt’,3,‘’,‘1446589711.715831’,‘1446589711.715831’,‘SIP/bandwidth-000313f8’,‘’,‘’)]
– Executing [h@macro-dialout-trunk:1] Macro(“SIP/7250-000313f7”, “hangupcall,”) in new stack
– Executing [s@macro-hangupcall:1] ExecIf(“SIP/7250-000313f7”, “0?Set(CDR(recordingfile)=.)”) in new stack
– Executing [s@macro-hangupcall:2] GotoIf(“SIP/7250-000313f7”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,4)
– Executing [s@macro-hangupcall:4] Hangup(“SIP/7250-000313f7”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/7250-000313f7’ in macro ‘hangupcall’
== Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on ‘SIP/7250-000313f7’
> [INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,uniqueid,cnum,cnam,outbound_cnum) VALUES ({ ts ‘2015-11-03 16:28:31’ },‘7250’,‘7250’,‘1712NXXXXXX’,‘from-internal’,‘SIP/7250-000313f7’,‘SIP/bandwidth-000313f8’,‘Dial’,‘SIP/bandwidth/+1712NXXXXXX,300,Tt’,12,3,‘ANSWERED’,3,‘1446589711.715831’,‘7250’,‘7250 matt’,‘877NXXXXXX’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘HANGUP’,{ts ‘2015-11-03 16:28:43.40489’},‘CID:877NXXXXXX’,‘1712NXXXXXX’,‘’,‘’,‘’,‘’,‘macro-dialout-trunk’,‘SIP/bandwidth-000313f8’,‘AppDial’,‘(Outgoing Line)’,3,‘’,‘1446589712.715834’,‘1446589711.715831’,‘’,‘’,‘’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_END’,{ts ‘2015-11-03 16:28:43.41462’},‘CID:877NXXXXXX’,‘1712NXXXXXX’,‘’,‘’,‘’,‘’,‘macro-dialout-trunk’,‘SIP/bandwidth-000313f8’,‘AppDial’,‘(Outgoing Line)’,3,‘’,‘1446589712.715834’,‘1446589711.715831’,‘’,‘’,‘’)]
== Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on ‘SIP/7250-000313f7’ in macro ‘dialout-trunk’
== Spawn extension (from-internal, 1712NXXXXXX, 5) exited non-zero on ‘SIP/7250-000313f7’
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘HANGUP’,{ts ‘2015-11-03 16:28:43.44143’},‘’,‘877NXXXXXX’,‘7250’,‘’,‘1712NXXXXXX’,‘1712NXXXXXX’,‘from-internal’,‘SIP/7250-000313f7’,‘’,‘’,3,‘’,‘1446589711.715831’,‘1446589711.715831’,‘’,‘’,‘’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_END’,{ts ‘2015-11-03 16:28:43.45657’},‘’,‘877NXXXXXX’,‘7250’,‘’,‘1712NXXXXXX’,‘1712NXXXXXX’,‘from-internal’,‘SIP/7250-000313f7’,‘’,‘’,3,‘’,‘1446589711.715831’,‘1446589711.715831’,‘’,‘’,‘’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘LINKEDID_END’,{ts ‘2015-11-03 16:28:43.45992’},‘’,‘877NXXXXXX’,‘7250’,‘’,‘1712NXXXXXX’,‘1712NXXXXXX’,‘from-internal’,‘SIP/7250-000313f7’,‘’,‘’,3,‘’,‘1446589711.715831’,‘1446589711.715831’,‘’,‘’,‘’)]
voiceCLI>

dicko · November 3, 2015, 11:38pm

OK, I would suggest you get two ssh sessions going on one,

tailf /var/log/asterisk/full|grep -E “AGI”

on the other,

rasterisk -x

Now, you will see why further debug output is needed . . . the lines in your tailf that start with

AGI Tx >>
AGI Rx <<

will be what Asterisk sends to your script (Tx) and what you send to asterisk (Rx), Waht you posted gives

– Executing [1712NXXXXXX@from-internal:2] AGI(“SIP/7250-000313f7”, “numsearch2.php,1712NXXXXXX”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/numsearch2.php
AGI Tx >> agi_request: numsearch2.php
AGI Tx >> agi_channel: SIP/7250-000313f7
AGI Tx >> agi_language: en
AGI Tx >> agi_type: SIP
AGI Tx >> agi_uniqueid: 1446589711.715831
AGI Tx >> agi_version: 11.16.0
AGI Tx >> agi_callerid: 7250
AGI Tx >> agi_calleridname: 7250 matt
AGI Tx >> agi_callingpres: 0
AGI Tx >> agi_callingani2: 0
AGI Tx >> agi_callington: 0
AGI Tx >> agi_callingtns: 0
AGI Tx >> agi_dnid: 1712NXXXXXX
AGI Tx >> agi_rdnis: unknown
AGI Tx >> agi_context: from-internal
AGI Tx >> agi_extension: 1712NXXXXXX
AGI Tx >> agi_priority: 2
AGI Tx >> agi_enhanced: 0.0
AGI Tx >> agi_accountcode:
AGI Tx >> agi_threadid: 139932559197952
AGI Tx >> agi_arg_1: 1712NXXXXXX
AGI Tx >>
AGI Rx << ANSWER
[INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘ANSWER’,{ts ‘2015-11-03 16:28:31.976075’},‘7250 matt’,‘7250’,‘7250’,’’,‘1712NXXXXXX’,‘1712NXXXXXX’,‘from-internal’,‘SIP/7250-000313f7’,‘AGI’,‘numsearch2.php,1712NXXXXXX’,3,’’,‘1446589711.715831’,‘1446589711.715831’,’’,’’,’’)]
0x7f44895cc520 – Probation passed - setting RTP source address to xxx.xxx.xxx.xxx:41245
AGI Tx >> 200 result=0
AGI Rx << EXEC Dial LOCAL/1712NXXXXXX
– AGI Script Executing Application: (Dial) Options: (LOCAL/1712NXXXXXX)
[INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_START’,{ts ‘2015-11-03 16:28:32.59664’},’’,’’,’’,’’,’’,‘1712NXXXXXX’,‘default’,‘Local/1712NXXXXXX@default-0003ec1f;1’,’’,’’,3,’’,‘1446589712.715832’,‘1446589711.715831’,’’,’’,’’)]
[INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_START’,{ts ‘2015-11-03 16:28:32.61460’},’’,’’,’’,’’,’’,‘1712NXXXXXX’,‘default’,‘Local/1712NXXXXXX@default-0003ec1f;2’,’’,’’,3,’’,‘1446589712.715833’,‘1446589711.715831’,’’,’’,’’)]
[2015-11-03 16:28:32] NOTICE[32678][C-00044dde]: chan_local.c:971 local_call: No such extension/context 1712NXXXXXX@default while calling Local channel
– Couldn’t call LOCAL/1712NXXXXXX

AGI Tx >> 200 result=0
[INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_END’,{ts ‘2015-11-03 16:28:32.65281’},’’,‘1712NXXXXXX’,’’,’’,’’,‘1712NXXXXXX’,‘default’,‘Local/1712NXXXXXX@default-0003ec1f;1’,‘AppDial’,’(Outgoing Line)’,3,’’,‘1446589712.715832’,‘1446589711.715831’,’’,’’,’’)]
– AGI Script numsearch2.php completed, returning 0
– Executing [1712NXXXXXX@from-internal:3] Set(“SIP/7250-000313f7”, “MOHCLASS=default”) in new stack
– Executing [1712NXXXXXX@from-internal:4] Set(“SIP/7250-000313f7”, “_NODEST=”) in new stack
– Executing [1712NXXXXXX@from-internal:5] Macro(“SIP/7250-000313f7”, “dialout-trunk,2,1712NXXXXXX,off”) in new stack
– Executing [s@macro-dialout-trunk:1] Set(“SIP/7250-000313f7”, “DIAL_TRUNK=2”) in new stack

In your log:-

[2015-11-03 16:28:32] NOTICE[32678][C-00044dde]: chan_local.c:971 local_call: No such extension/context 1712NXXXXXX@default while calling Local channel

(I thought I told you that already, no? )

lgaetz · November 4, 2015, 12:32pm

The recording issue probably has nothing to do with the AGI script, I suspect it is the way you are calling it. What context are you using in extensions_custom.conf to call the AGI file? The proper way to do this is by using the context:

[macro-dialout-trunk-predial-hook]

mattjfrank · November 4, 2015, 3:23pm

Here is my entire extensions_custom.conf

;outbound call check
exten => _1NXXNXXXXXX,n,AGI(numsearch2.php,${EXTEN})
exten => _NXXNXXXXXX,n,AGI(numsearch2.php,${EXTEN})

;routes inbound calls based on their caller id
exten => _7299,n,AGI(autocidroute.php)

;timeclock
exten => _8463,n,AGI(timeclock.php)

danielf · November 4, 2015, 3:42pm

Hi,

Your problem lies in your dialplan:

;outbound call check
exten => _1NXXNXXXXXX,n,AGI(numsearch2.php,${EXTEN})
exten => _NXXNXXXXXX,n,AGI(numsearch2.php,${EXTEN})

Please fix the second line to:

exten => _1NXXNXXXXXX,1,AGI(numsearch2.php,${EXTEN})
exten => _NXXNXXXXXX,1,AGI(numsearch2.php,${EXTEN})

Please report back.

Thank you,

Daniel Friedman
Trixton LTD.

mattjfrank · November 4, 2015, 3:49pm

Thanks @danielf that didn’t change the end result… The first line is the one that is actually not working properly if that helps at all.

Both lines call the script and work as expected but the first line for some reason doesn’t initiate call recording.

danielf · November 4, 2015, 3:51pm

Hi,

Did you make a dialplan reload after the change? If yes, please provide a log with real numbers.

Thank you,

Daniel Friedman
Trixton LTD.

mattjfrank · November 4, 2015, 3:53pm

Yes I did, but it appears you made a slight change from when you first posted and I started the update. It appears to be fixed changing the n in each line to 1… I need to do further testing but so far it’s working.

danielf · November 4, 2015, 3:59pm

Hi,

Yes, I had a typo, sorry for that. Anyway, I believe that you have a problem with your AGI script. You are getting an error like that: local_call: No such extension/context 1712NXXXXXX@default

Did you checked that you are using the from-internal context?

Thank you,

Daniel Friedman
Trixton LTD.

mattjfrank · November 4, 2015, 4:19pm

you are correct. I’m not sure how to confirm I’m using the context. Even though Im getting the errors everything works.

danielf · November 4, 2015, 4:22pm

Hi,

Yes, it is working because it is falling back to the from-internal context which your extension belongs to. I suggest you to recheck again all of your scripts. Please do not forget that every time you are starting a new pattern in a context you should start it with a “1” and not “n”.

Thank you,

Daniel Friedman
Trixton LTD.