[asterisk-users] AGI script fails on IAX channels (from call file).
Jonas Arndt
jonas_arndt at comcast.net
Fri Sep 14 16:00:59 CDT 2007
Hi Guys,
I have already tried this one on the developers list. I have not been
successful getting much back there and I have notified them that I will
post this on the users list instead. Hopefully somebody have tried
something similar and can help out.
I am developing AGI scripts on Asterisk and have run into some very
strange behaviour and I think this is a bug, but I am not completely
sure. Any suggestions are highly appreciated.
Let me first state the ground here
Facts
1. I am on asterisk 1.4.11
2. What I am trying to do works on SIP phones and SIP channels
3. What I am trying to do FAILS on IAX phone (iaxy) and IAX channels
Having stated this let's now only focus on the IAX channel. To avoid
lengthy code reading I will state the problem first and then later the code.
I have an AGI scrip that takes a single input parameter. You can call it
from the dial plan like
exten => *66,2,AGI(test.agi|670507)
This AGI script starts with a "SAY DIGITS" on the parameter "670507".
Then it gives you a choice with some "STREAM FILE" and finally a "GET
DATA". Once you have made your choice the AGI script tells you what you
chose and hangs up.
That's it. Really handy little script, right. This is obviously made
just to demonstrate the problem I am having. Note again, only for IAX.
Problem
1. This does work when the the IAX based phone executes the script
from the dial plan. Then there is no problem what so ever replying
to with DTMF from the phone.
2. This DOES NOT work if I execute the AGI script from a call file. I
get the phone call to the IAX based phone and the streams work
fine. I just CANNOT reply with DTMF in the "GET DATA" part. It
just times out.
Tracing with
> iax2 set debug on
Reveals that I get a "/Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 004
Type: DTMF_E"/ every time I press a key in both cases (execution from
the dial plan or call file), but it times out when it is executed from a
call file.
Now some data: I am sorry if there is some garbage in the traces. I have
tried to cut out stuff that shouldn't be of any concern, but I was
scared to cut too much.
Call File
=================== Call File ==========================
channel: Local/3455 at internal
maxretries: 3
retrytime: 60
waittime: 60
callerid: "Test" <*66>
application: AGI
data: test.agi|670507
================= End Call File ========================
Perl AGI Scrip
============ test.agi =================================
#!/usr/bin/perl
use strict;
use Time::Local;
$|=1;
# Setup some variables
my %AGI; my $DEBUG=1;
my $DEBUGOUT = "filehandle";
my $debugfile="/tmp/agi_debug.log";
############ check_result ##########
# Use this to check the result of #
# a sent command #
# I pretty much stole this from #
# the regular agi-test.agi #
####################################
sub checkresult {
my ($res) = @_;
my $retval;
chomp $res;
if ($res =~ /^200/) {
$res =~ /result=(-?\d+)/;
if (!length($1)) {
print DEBUGOUT "FAIL ($res)\n";
exit(1);
} elsif ($DEBUG=1){
print DEBUGOUT "PASS ($1)\n";
}
} else {
print STDERR "FAIL (unexpected result '$res')\n";
exit(1);
}
}
############ send_file #############
# Use this to send a wave file on #
# the channel #
# #
####################################
sub send_file {
my ($myfile) = @_;
chomp($myfile);
if ($DEBUG == 1 ) {
print DEBUGOUT "Sending stream $myfile \n";
}
print "STREAM FILE $myfile \"0123456789\"\n";
my $result = <STDIN>;
&checkresult($result);
}
############ hangup ###############
# Use this to hand up a channel #
# the channel #
# #
####################################
sub hangup {
if ($DEBUG == 1 ) {
print DEBUGOUT "Hanging up \n";
}
print "HANGUP \"\" \n";
my $result = <STDIN>;
&checkresult($result);
}
############ say_digits ############
# Use this to say a digits #
# over the channel #
# #
####################################
sub say_digits {
my ($mynumber) = @_;
chomp($mynumber);
if ($DEBUG == 1 ) {
print DEBUGOUT "Saying digits $mynumber \n";
}
print "SAY DIGITS $mynumber \"0123456789\"\n";
my $result = <STDIN>;
&checkresult($result);
}
######## get_data ##################
# Feed with (file, maxnumbers) #
# where file is the sound file #
# to be played and maxnumbers is #
# the maximum amount of digits to #
# allow in the answer #
####################################
sub get_data {
my @mydata = @_;
my $myfile = $mydata[0];
my $mymax = $mydata[1];
if ($DEBUG == 1 ) {
print DEBUGOUT "Getting data \n";
}
print "GET DATA $myfile 15000 $mymax \n";
my $result = <STDIN>;
&checkresult($result);
$result =~ /result=(-?\d+)/;
return $1;
}
########### init_agi ###############
# Use this to initialize the AGI #
# variable #
# #
####################################
sub init_agi {
while(<STDIN>) {
chomp;
last unless length($_);
if (/^agi_(\w+)\:\s+(.*)$/) {
$AGI{$1} = $2;
}
}
}
########### main program ###########
# Here goes the main program #
# #
####################################
my $numargs = $#ARGV + 1;
if ($DEBUG == 1) {
open (DEBUGOUT, '>', $debugfile) or die "Cannot open $debugfile for
write :$!";
}
# Start by reading in the stuff Asterisk is sending
&init_agi(); # Comment out in case of debug outside Asterisk
# If DEBUG is set, dump the AGI variable
if ($DEBUG == 1) {
foreach my $i (sort keys %AGI) {
print DEBUGOUT " -- $i = $AGI{$i}\n";
}
}
# Welcome people on the channel
&send_file ("welcome");
# Say the digits that you got as an argument
&say_digits($ARGV[0]);
# Put out the choices
&send_file("press-1");
&send_file("or");
# Now try to read from the channel
# This is where it fails if it is called from a call file
my $response = &get_data("press-2",1);
if ($response == 1) {
&send_file("you-entered");
&send_file("digits/1");
} else{
&send_file("you-entered");
&send_file("digits/2");
}
&send_file("goodbye");
&hangup();
if ($DEBUG ==1) {
close $DEBUGOUT;
}
============ end test.agi=============================
Trace of working session (note how the DTMF is received)
===================== iax_succ.trc ===================
-- Accepting DIAL from 192.168.2.58, formats = 0x4
-- Executing [*66 at internal:1] Answer("IAX2/3455-2", "") in new stack
-- Executing [*66 at internal:2] AGI("IAX2/3455-2", "test.agi|670507")
in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/test.agi
AGI Tx >> agi_request: test.agi
AGI Tx >> agi_channel: IAX2/3455-2
AGI Tx >> agi_language: en
AGI Tx >> agi_type: IAX2
AGI Tx >> agi_uniqueid: 1189547184.357
AGI Tx >> agi_callerid: 3455
AGI Tx >> agi_calleridname: Ronja
AGI Tx >> agi_callingpres: 1
AGI Tx >> agi_callingani2: 0
AGI Tx >> agi_callington: 0
AGI Tx >> agi_callingtns: 0
AGI Tx >> agi_dnid: unknown
AGI Tx >> agi_rdnis: unknown
AGI Tx >> agi_context: internal
AGI Tx >> agi_extension: *66
AGI Tx >> agi_priority: 2
AGI Tx >> agi_enhanced: 0.0
AGI Tx >> agi_accountcode:
AGI Tx >>
AGI Tx >> 200 result=0 endpos=7680
AGI Rx << SAY DIGITS 670507 "0123456789"
-- <IAX2/3455-2> Playing 'digits/6' (language 'en')
-- <IAX2/3455-2> Playing 'digits/7' (language 'en')
Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 006 Type: IAX Subclass: PING
Timestamp: 04903ms SCall: 01881 DCall: 00002 [192.168.2.58:4569]
Tx-Frame Retry[000] -- OSeqno: 006 ISeqno: 006 Type: IAX Subclass: PONG
Timestamp: 04903ms SCall: 00002 DCall: 01881 [192.168.2.58:4569]
RR_JITTER : 0
RR_LOSS : 0
RR_PKTS : 1
RR_DELAY : 40
RR_DROPPED : 0
RR_OUTOFORDER : 0
Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 007 Type: IAX Subclass: ACK
Timestamp: 04903ms SCall: 01881 DCall: 00002 [192.168.2.58:4569]
-- <IAX2/3455-2> Playing 'digits/0' (language 'en')
-- <IAX2/3455-2> Playing 'digits/5' (language 'en')
-- <IAX2/3455-2> Playing 'digits/0' (language 'en')
-- <IAX2/3455-2> Playing 'digits/7' (language 'en')
AGI Tx >> 200 result=0
AGI Rx << STREAM FILE press-1 "0123456789"
-- Playing 'press-1' (escape_digits=0123456789) (sample_offset 0)
AGI Tx >> 200 result=0 endpos=7360
AGI Rx << STREAM FILE or "0123456789"
-- Playing 'or' (escape_digits=0123456789) (sample_offset 0)
AGI Tx >> 200 result=0 endpos=4480
AGI Rx << GET DATA press-2 15000 1
-- <IAX2/3455-2> Playing 'press-2' (language 'en')
Tx-Frame Retry[000] -- OSeqno: 007 ISeqno: 006 Type: IAX Subclass: LAGRQ
Timestamp: 10024ms SCall: 00002 DCall: 01881 [192.168.2.58:4569]
Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 008 Type: IAX Subclass: LAGRP
Timestamp: 10024ms SCall: 01881 DCall: 00002 [192.168.2.58:4569]
Tx-Frame Retry[-01] -- OSeqno: 008 ISeqno: 007 Type: IAX Subclass: ACK
Timestamp: 10024ms SCall: 00002 DCall: 01881 [192.168.2.58:4569]
Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 008 Type: DTMF_E Subclass: 2
Timestamp: 12123ms SCall: 01881 DCall: 00002 [192.168.2.58:4569]
Tx-Frame Retry[-01] -- OSeqno: 008 ISeqno: 008 Type: IAX Subclass: ACK
Timestamp: 12123ms SCall: 00002 DCall: 01881 [192.168.2.58:4569]
AGI Tx >> 200 result=2
AGI Rx << STREAM FILE you-entered "0123456789"
-- Playing 'you-entered' (escape_digits=0123456789) (sample_offset 0)
================= end iax_succ.trc ===================
Trace of failing (from call file). Here DTMF are logged but AGI fails to
care about them
================= iax_fail.trc =======================
-- Launched AGI Script /var/lib/asterisk/agi-bin/test.agi
AGI Tx >> agi_request: test.agi
AGI Tx >> agi_channel: Local/3455 at internal-e501,1
AGI Tx >> agi_language: en
AGI Tx >> agi_type: Local
AGI Tx >> agi_uniqueid: 1189546755.353
AGI Tx >> agi_callerid: *66
AGI Tx >> agi_calleridname: Test
AGI Tx >> agi_callingpres: 0
AGI Tx >> agi_callingani2: 0
AGI Tx >> agi_callington: 0
AGI Tx >> agi_callingtns: 0
AGI Tx >> agi_dnid: unknown
AGI Tx >> agi_rdnis: unknown
AGI Tx >> agi_context: internal
AGI Tx >> agi_extension: 3455
AGI Tx >> agi_priority: 1
AGI Tx >> agi_enhanced: 0.0
AGI Tx >> agi_accountcode:
AGI Tx >>
AGI Tx >> 200 result=0 endpos=7680
AGI Rx << SAY DIGITS 670507 "0123456789"
-- <Local/3455 at internal-e501,1> Playing 'digits/6' (language 'en')
-- <Local/3455 at internal-e501,1> Playing 'digits/7' (language 'en')
-- <Local/3455 at internal-e501,1> Playing 'digits/0' (language 'en')
-- <Local/3455 at internal-e501,1> Playing 'digits/5' (language 'en')
Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 002 Type: IAX Subclass: PING
Timestamp: 04963ms SCall: 13070 DCall: 00003 [192.168.2.58:4569]
Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 005 Type: IAX Subclass: PONG
Timestamp: 04963ms SCall: 00003 DCall: 13070 [192.168.2.58:4569]
RR_JITTER : 0
RR_LOSS : 0
RR_PKTS : 1
RR_DELAY : 40
RR_DROPPED : 0
RR_OUTOFORDER : 0
algot*CLI>
Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 003 Type: IAX Subclass: ACK
Timestamp: 04963ms SCall: 13070 DCall: 00003 [192.168.2.58:4569]
-- <Local/3455 at internal-e501,1> Playing 'digits/0' (language 'en')
-- <Local/3455 at internal-e501,1> Playing 'digits/7' (language 'en')
AGI Tx >> 200 result=0
AGI Rx << STREAM FILE press-1 "0123456789"
-- Playing 'press-1' (escape_digits=0123456789) (sample_offset 0)
AGI Tx >> 200 result=0 endpos=7360
AGI Rx << STREAM FILE or "0123456789"
-- Playing 'or' (escape_digits=0123456789) (sample_offset 0)
AGI Tx >> 200 result=0 endpos=4480
AGI Rx << GET DATA press-2 15000 1
-- <Local/3455 at internal-e501,1> Playing 'press-2' (language 'en')
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass:
REGREQ
Timestamp: 00002ms SCall: 14665 DCall: 00000 [192.168.2.56:4569]
USERNAME : 3454
REFRESH : 60
DEVICE TYPE : iaxy2
SERVICE IDENT : 0003640008dd
PROVISIONG VER : 326528057
algot*CLI>
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass:
REGACK
Timestamp: 00010ms SCall: 00004 DCall: 14665 [192.168.2.56:4569]
USERNAME : 3454
DATE TIME : 2007-09-11 15:39:24
REFRESH : 60
APPARENT ADDRES : IPV4 192.168.2.56:4569
MESSAGE COUNT : 768
CALLING NUMBER : 3454
CALLING NAME : Robin
Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK
Timestamp: 00010ms SCall: 14665 DCall: 00004 [192.168.2.56:4569]
Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 005 Type: IAX Subclass: LAGRQ
Timestamp: 09956ms SCall: 00003 DCall: 13070 [192.168.2.58:4569]
Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 004 Type: IAX Subclass: LAGRP
Timestamp: 09956ms SCall: 13070 DCall: 00003 [192.168.2.58:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 006 Type: IAX Subclass: ACK
Timestamp: 09956ms SCall: 00003 DCall: 13070 [192.168.2.58:4569]
Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 004 Type: DTMF_E Subclass: 1
Timestamp: 10379ms SCall: 13070 DCall: 00003 [192.168.2.58:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 007 Type: IAX Subclass: ACK
Timestamp: 10379ms SCall: 00003 DCall: 13070 [192.168.2.58:4569]
Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 004 Type: DTMF_E Subclass: 1
Timestamp: 11599ms SCall: 13070 DCall: 00003 [192.168.2.58:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 008 Type: IAX Subclass: ACK
Timestamp: 11599ms SCall: 00003 DCall: 13070 [192.168.2.58:4569]
Rx-Frame Retry[ No] -- OSeqno: 008 ISeqno: 004 Type: DTMF_E Subclass: 1
Timestamp: 14338ms SCall: 13070 DCall: 00003 [192.168.2.58:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 009 Type: IAX Subclass: ACK
Timestamp: 14338ms SCall: 00003 DCall: 13070 [192.168.2.58:4569]
Rx-Frame Retry[ No] -- OSeqno: 009 ISeqno: 004 Type: DTMF_E Subclass: 2
.................................................
Tx-Frame Retry[000] -- OSeqno: 006 ISeqno: 013 Type: IAX Subclass: PING
Timestamp: 20957ms SCall: 00003 DCall: 13070 [192.168.2.58:4569]
Rx-Frame Retry[ No] -- OSeqno: 013 ISeqno: 007 Type: IAX Subclass: PONG
Timestamp: 20957ms SCall: 13070 DCall: 00003 [192.168.2.58:4569]
Tx-Frame Retry[-01] -- OSeqno: 007 ISeqno: 014 Type: IAX Subclass: ACK
Timestamp: 20957ms SCall: 00003 DCall: 13070 [192.168.2.58:4569]
AGI Tx >> 200 result= (timeout)
-- AGI Script test.agi completed, returning 0
-- Hungup 'IAX2/3455-3'
== Spawn extension (macro-answer-arndt, s, 1) exited non-zero on
'Local/3455 at internal-e501,2' in macro 'answer-arndt'
== Spawn extension (macro-answer-arndt, s, 1) exited non-zero on
'Local/3455 at internal-e501,2'
Tx-Frame Retry[000] -- OSeqno: 007 ISeqno: 014 Type: IAX Subclass:
HANGUP
Timestamp: 24430ms SCall: 00003 DCall: 13070 [192.168.2.58:4569]
CAUSE CODE : 16
Rx-Frame Retry[ No] -- OSeqno: 014 ISeqno: 008 Type: IAX Subclass: ACK
Timestamp: 24430ms SCall: 13070 DCall: 00003 [192.168.2.58:4569]
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass:
REGREQ
Timestamp: 00002ms SCall: 10071 DCall: 00000 [192.168.2.58:4569]
USERNAME : 3455
REFRESH : 60
DEVICE TYPE : iaxy2
SERVICE IDENT : 000364002cc8
PROVISIONG VER : 1153878929
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass:
REGACK
Timestamp: 00008ms SCall: 00001 DCall: 10071 [192.168.2.58:4569]
USERNAME : 3455
DATE TIME : 2007-09-11 15:39:42
REFRESH : 60
APPARENT ADDRES : IPV4 192.168.2.58:4569
MESSAGE COUNT : 1280
CALLING NUMBER : 3455
CALLING NAME : Ronja
Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK
Timestamp: 00008ms SCall: 10071 DCall: 00001 [192.168.2.58:4569]
algot*CLI> iax2 set debug off
IAX2 Debugging Disabled
algot*CLI>
=============== end iax_fail.trc =======================
More information about the asterisk-users
mailing list