[asterisk-dev] AMI Disconnect/Sudden "Asterisk Call Manager/1.3" received

Tue May 6 17:05:09 CDT 2014

Hi Tony,

See my answers inline.

On 05/06/2014 12:11 PM, Tony Mountifield wrote:
> In article <5368ED8B.4080103 at szeto.ca>,
> Daniel McFarlane <daniel at szeto.ca> wrote:
>> Hi All,
>>
>> I've been working with Asterisk for 2.5 years now but I am new to the
>> mailing list.  Hoping to get some answers here..
>>
>> I've written a piece of software to control Asterisk via AMI.  I'm able
>> to login, making outbound calls, receive/record calls, handle digits,
>> put people into conferences, etc.  Everything seems to work well, at a
>> low to medium call volume.
> It would be worthwhile mentioning which version of Asterisk you are using.
As I added in my last email: I'm running Asterisk 11.2.1
>
>> I've been stress testing the system and found what seems to be a memory
>> issue within Asterisk.  However, after over a day of searching I can't
>> even find any bug reports or anything to bring me closer to a
>> solution..but still hoping to find a solution or that someone can help
>> me find one..
>>
>> I connect to the AMI successfully.  In my test I am making an outbound
>> call through a sip "device" I configured within sip.conf. This sip
>> "device" basically connects back into the same Asterisk I am using to
>> generate the calls.
>>
>> If I generate outbound calls (i.e.: Via Action: Originate) using a low
>> call volume everything seems to be fine.  e.g.: I can generate 10 calls
>> and they all go through and complete successfully (with a total of 20
>> calls bring processed by the same Asterisk, due to both outbound and
>> inbound calls).
>>
>> The problem arises If I bombard (i.e.: Write all the Originate requests
>> within about 7 seconds) the AMI to generate 97 outbound calls (for a
>> total of 194 channels).  The first Originate commands seem to get
>> processed,  but then all of a sudden (after Asterisk seems to have
>> started processing a good amount of my Originate requests already)
>> Asterisk seems to reset the AMI interface! Without even having a dropped
>> connection I receive a new "Asterisk Call Manager/1.3" string and then
>> previous commands that I issued start coming back with Response: Error
>> and Message: Permission denied.
>>
>> I've enabled debugging and here's the security log output when I connect:
>>
>> [Apr  1 12:43:25] SECURITY[9877] res_security_log.c:
>> SecurityEvent="SuccessfulAuth",EventTV="1396370605-551714",Severity="Informational",Service="AMI",EventVersion="1",AccountID="username",SessionID="0x7f0c540d96b8",LocalAddress="IPV4/TCP/0.0.0.0/5038",RemoteAddress="IPV4/TCP/192.168.1.62/52139",UsingPassword="0",SessionTV="1396370605-551710"
>>
>> (This is the time when I am issuing commands, it is accepting and
>> processing them)
>>
>> Then all of a sudden (when I receive a new "Asterisk Call Manager/1.3"
>> string and commands are rejected with "Permission denied") here is what
>> the log shows:
>>
>> [Apr  1 12:44:36] SECURITY[9877] res_security_log.c:
>> SecurityEvent="RequestNotAllowed",EventTV="1396370676-876795",Severity="Error",Service="AMI",EventVersion="1",AccountID="",SessionID="0x7f0c54072968",LocalAddress="IPV4/TCP/0.0.0.0/5038",RemoteAddress="IPV4/TCP/192.168.1.62/52144",RequestType="Action:
>> Originate",SessionTV="0-0"
>>
>> (Note: How the AccountID is now empty)
>>
>> At this same time the CLI shows:
>>
>>     == Manager '*****' logged off from 192.168.1.**
> Why ***-out the username and part of the IP address when you've included
> them both in the log messages above?
Guess that was a slip.  I did actually change my username to "username", 
but missed the IP address. No big deal anyways, as it's local  :)
>
>> ..yet it wasn't my application that disconnected and/or issued an
>> Action: logoff to Asterisk (my application doesn't even detect a
>> connection drop, so it seems like Asterisk just logs the manager user out!).
>>
>> Why did Asterisk all of a sudden reset itself and/or lose reference to
>> the user I am authenticating with?
> Just to be certain what is happening on the connection, set up a tcpdump
> on the Asterisk box to capture the traffic into a file, then look at it
> in wireshark. I find it easiest to create a suitable script:
>
> root# cat capture-ami.sh
> #!/bin/sh
>
> DATE=`date '+%Y%m%d-%H%M%S'`
> FILE=ami-`hostname -s`-$DATE.pkt
>
> cd /var/tmp
>
> tcpdump -C 8 -i any -n -p -s 0 -w $FILE tcp port 5038 </dev/null >/dev/null 2>&1 &
> root# ./capture-ami.sh
>
> Then when you have reproduced the problem, kill the tcpdump and copy the file
> to a machine that has wireshark. You can then see exactly what is happening
> at the time of the problem - whether it is initiated by your client program
> doing something strange or by Asterisk.
>
> Cheers
> Tony
>

Thank you for the in-dept usage information for TCP dump and your 
suggested script, btw.

I have investigated with Wireshark, reproduced the problem and confirmed 
that Asterisk is resetting the connection.  I see a [RST, ACK] being 
issued from the Asterisk AMI port to my software.  My software then 
re-initializes the connection with a [SYN].

I'm new to the mailing list so how do we proceed to find a working 
solution from here?

Thank You,

Daniel