thr3ads.net - asterisk users - [asterisk-users] AGI script fails on IAX channels (from call file). [Sep 2007]

If this information is useful, please help other people find it:
Share via:

Jonas Arndt

2007-Sep-14 21:00 UTC

[asterisk-users] AGI script fails on IAX channels (from call file).

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 onReveals 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 =======================

Richard Lyman

2007-Sep-14 22:28 UTC

head link

[asterisk-users] AGI script fails on IAX channels (from call file).

Jonas Arndt wrote:> 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
>
>   *snipped

when i was doing some testing i had to use READ, and because i did then 
i had to use GET VARIABLE to retrieve the inputted dtmf.

http://dynx.net/ASTERISK/gnudialer/agiIVR.agi

search for

sub question_1

to see how i did it.

i hope this helps.

Tony Mountifield

2007-Sep-15 09:40 UTC

head link

[asterisk-users] AGI script fails on IAX channels (from call file).

In article <46EAF68B.6070505 at comcast.net>,
Jonas Arndt <jonas_arndt at comcast.net> wrote:> 
> 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 =======================Instead of calling the application directly from the call file, make a
special extension for it, and call that extension instead:

[foo]
exten => _X.,1,Answer(0.5)
exten => _X.,2,AGI(test.agi|${EXTEN})

And then have the call file like this:

Channel: Local/3455 at internal
Maxretries: 3
Retrytime: 60
Waittime: 60
CallerId: "Test" <*66>
Context: foo
Extension: 670507
Priority: 1

The Answer line may or may not be necessary, but if you find it is, that
would explain why calling the AGI directly didn't work. In that case,
perhaps you could put the Answer within the AGI.

Cheers
Tony

-- 
Tony Mountifield
Work: tony at softins.co.uk - http://www.softins.co.uk
Play: tony at mountifield.org - http://tony.mountifield.org

Seemingly Similar Threads

Search for more maybe matching threads

asterisk users - Sep 2007 - AGI script fails on IAX channels (from call file).

[asterisk-users] AGI script fails on IAX channels (from call file).

[asterisk-users] AGI script fails on IAX channels (from call file).

[asterisk-users] AGI script fails on IAX channels (from call file).

Seemingly Similar Threads