[asterisk-users] AMI potential memory leak

Dan Cropp dan at amtelco.com
Thu Mar 22 11:04:12 CDT 2018 

I just noticed a new Asterisk 13.20.0.  Some of the change log information seems to match what we are seeing.

I will upgrade to asterisk 13.20.0 and run tests.


-----Original Message-----
From: asterisk-users-bounces at lists.digium.com [mailto:asterisk-users-bounces at lists.digium.com] On Behalf Of Dan Cropp
Sent: Thursday, March 22, 2018 10:48 AM
To: Asterisk Users Mailing List - Non-Commercial Discussion
Subject: Re: [asterisk-users] AMI potential memory leak

We just received a separate call with a Result that seems random...  This is on a separate box running Asterisk 14.7.5 for this example.  However, I am comfortable that we will eventually see this on a 13.18.5 asterisk if we increase the number of simultaneous calls.

I would say the random Result header containing information similar to this (random, but at least typical ASCII characters) is a more common pattern that we are seeing.

[03/22 15:33:52.217] DEBUG[529] manager.c: Examining AMI event:
Event: AsyncAGIExec
Privilege: agi,all
Channel: PJSIP/192.168.40.105-00008a2a
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1234
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 10
Context: ABC
Exten: 3002
Priority: 7
Uniqueid: 1521732812.35370
Linkedid: 1521732812.35370
Result: E%2CSuccessfully%20Played%0A
CommandId: C318070


-----Original Message-----
From: asterisk-users-bounces at lists.digium.com [mailto:asterisk-users-bounces at lists.digium.com] On Behalf Of Dan Cropp
Sent: Thursday, March 22, 2018 9:37 AM
To: Asterisk Users Mailing List - Non-Commercial Discussion
Subject: Re: [asterisk-users] AMI potential memory leak

Not sure if this may provide any guidance...

Call comes in and the extension is configured to send it to AsyncAGI We use AMI to detect when we have control of the call.
We perform some actions (Answer)
Maybe play a few prompts.

At some point, we need to play and collect some digits.
For this portion, we set a variable on the channel.
We end the AsyncAGI with an asyncagi break

Action: AGI
ActionID: C7138
Channel: _____
CommandID: C7138
Command: asyncagi break

The extensions for this call looks at the channel variable and sees it is set.
It then sends the call to ExternalIVR
On an ExternalIVR socket we determine the channel so we know which channel this ExternalIVR socket represents.
We then perform the play and monitor for digits.
In the tests, no digits are received.
ExternalIVR will end.

Extensions is configured to send the call back to AsyncAGI.
We receive the call and do actions based on what was received.

In the test case I am looking at this morning, there is no dtmf.
It repeats the digit collection (ExternalIVR) process 3 times.
After 3 times of no digits, it plays a good bye prompt.

The data I just sent was what happened after the BYE attempt (no AsyncAGIExec event with a result).
I just saw another case where the BYE completed, so we sent an Action: Hangup packet

Asterisk debug log shows it receive the Hangup and started the Soft-Hanging up.  However, there is nothing more for this channel in the Asterisk debug log.

[03/22 08:41:03.354] DEBUG[1228] manager.c: Running action 'Hangup'
[03/22 08:41:03.354] DEBUG[1228] channel.c: Soft-Hanging (0x20) up channel 'SIP/192.168.40.105-00000314'

These are two scenarios we are able to replicate within a couple hours regularly.

Dan

-----Original Message-----
From: asterisk-users-bounces at lists.digium.com [mailto:asterisk-users-bounces at lists.digium.com] On Behalf Of Dan Cropp
Sent: Thursday, March 22, 2018 9:20 AM
To: Asterisk Users Mailing List - Non-Commercial Discussion
Subject: Re: [asterisk-users] AMI potential memory leak

HI Matt,

I am trying to replicate this particular problem.  We are seeing more frequently where the Event: AsyncAGIExec is never being sent.  
The two scenarios I have seen in tests yesterday and today...

We sendl an AMI action.  For example, play a short file or hangup.
AMI Events will indicate it did the work, but we never receive the Event: AsyncAGIExec with a result at all.
Asterisk debug log (logging set to 999) is never showing the Event: AsyncAGIExec being sent.
It seems to do everything right up to that.

Directly from Asterisk logging...
Here is a play example from this morning...

[03/22 08:13:32.219] DEBUG[1228] manager.c: Examining AMI event:
Event: Newexten
Privilege: call,all
Channel: SIP/192.168.40.105-000000c5
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1234
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 11
Context: ABC
Exten: 3002
Priority: 8
Uniqueid: 1521724388.197
Linkedid: 1521724388.197
Extension: 3002
Application: AGI
AppData: agi:async

[03/22 08:13:32.220] DEBUG[1228] manager.c: Examining AMI event:
Event: AsyncAGIStart
Privilege: agi,all
Channel: SIP/192.168.40.105-000000c5
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1234
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 11
Context: ABC
Exten: 3002
Priority: 8
Uniqueid: 1521724388.197
Linkedid: 1521724388.197
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.40.105-000000c5%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201521724388.197%0Aagi_version%3A%2013.18.5%0Aagi_callerid%3A%201234%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%203002%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20IS%0Aagi_extension%3A%203002%0Aagi_priority%3A%208%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%2011%0Aagi_threadid%3A%20140085827688192%0A%0A

[03/22 08:13:32.320] DEBUG[1228] manager.c: Examining AMI event:
Event: AGIExecStart
Privilege: agi,all
Channel: SIP/192.168.40.105-000000c5
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1234
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 11
Context: ABC
Exten: 3002
Priority: 8
Uniqueid: 1521724388.197
Linkedid: 1521724388.197
CommandId: 401382226
Command: EXEC Playback iss/eng/THANK-U&iss/eng/BYE

[03/22 08:13:33.643] DEBUG[1228] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/192.168.40.105-000000c5
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1234
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 11
Context: ABC
Exten: 3002
Priority: 8
Uniqueid: 1521724388.197
Linkedid: 1521724388.197
Variable: PLAYBACKSTATUS
Value: SUCCESS

[03/22 08:13:33.643] DEBUG[1228] manager.c: Examining AMI event:
Event: AGIExecEnd
Privilege: agi,all
Channel: SIP/192.168.40.105-000000c5
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1234
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 11
Context: ABC
Exten: 3002
Priority: 8
Uniqueid: 1521724388.197
Linkedid: 1521724388.197
CommandId: 401382226
Command: EXEC Playback iss/eng/THANK-U&iss/eng/BYE
Result: Success
ResultCode: 200

After this, there are no more AMI events for this channel.
On other channels, we receive the Event: AsyncAGIExec with the Result.

It's as if there is some condition where the AMI Result is getting corrupted.  In most cases, it's working.  However, we are seeing intermittent cases where this occurs.

Any suggestions for what I should try?

Dan


-----Original Message-----
From: asterisk-users-bounces at lists.digium.com [mailto:asterisk-users-bounces at lists.digium.com] On Behalf Of Matt Fredrickson
Sent: Wednesday, March 21, 2018 4:16 PM
To: Asterisk Users Mailing List - Non-Commercial Discussion
Subject: Re: [asterisk-users] AMI potential memory leak

On Wed, Mar 21, 2018 at 4:03 PM, Dan Cropp <dan at amtelco.com> wrote:
> We are communicating with Asterisk via AMI.  Running Asterisk version
> 13.18.5 on an Ubuntu box.
>
>
>
> If you look at the event response, the Result field is filled with 
> random characters.  I’m not sure what to do because that is a 
> completely random result.  It makes no sense.
>
>
>
>
>
> We send the following command to asterisk via AMI
>
> Action: AGI
>
> ActionID: C44415
>
> Channel: SIP/192.168.40.105-00001338
>
> CommandID: C44415
>
> Command: asyncagi break
>
>
>
> Asterisk processes it and the Asterisk log shows it sends the 
> following for the AsyncAGIEXEC event…
>
> This is coming directly from the Asterisk log so it’s clearly Asterisk 
> filling the Result with what appears to be random characters.
>
>
>
> [03/21 15:44:27.793] DEBUG[1213] manager.c: Examining AMI event:
>
> Event: AsyncAGIExec
>
> Privilege: agi,all
>
> Channel: SIP/192.168.40.105-00001338
>
> ChannelState: 6
>
> ChannelStateDesc: Up
>
> CallerIDNum: 1234
>
> CallerIDName: <unknown>
>
> ConnectedLineNum: <unknown>
>
> ConnectedLineName: <unknown>
>
> Language: en
>
> AccountCode: 11
>
> Context: ABC
>
> Exten: 3002
>
> Priority: 8
>
> Uniqueid: 1521665055.4920
>
> Linkedid: 1521665055.4920
>
> Result:
> %F7%EF%F0%F4z%7C%EE%EF%F6%FCkWDDLO%5Cm%EF%7B__%60h%FE%E0%D4%D5%D9%DA%D
> D%E2%E8%E1%DC%DE%E0%F3%EC%EF%7C%ED%ED%EC%FAx~oov%F9%F2%F6%EB%ED%FA%FD%
> F9%FEvjXGFMKWg%FF%7Cdidew%E8%D9%D9%D8%D6%DA%DF%E3%E3%E2%E5%E9%EA%E1%E6
> %EF%E9%F8%F8%F6%FD%F8%7C~%7D%FC%F9%F7%ED%F4%F6%F9oh%60JFMKP%5Do%FFgtjc
> h%7B%E3%DF%DB%D6%D8%DB%E6%EC%E7%E6%E5%DF%DD%E0%EA%F6%ED%EC%F7%E8%E4%EB
> %F2%F8%F9%7Cu%FC%F8%FAwhXIIIHQ%5Dksw%7Fgfl%7F%EA%E2%DA%D8%DC%DE%DE%E2%
> E4%DF%E0%E3%E9%E4%E8%EC%E6%E3%E1%E4%E0%E3%EE%F4%FAxy%FCj%5BLIJFLU%5Bdm
> %FFljws%FD%ED%E2%DC%DD%DA%D9%DC%DE%DD%E1%E7%E9%E8%E6%EC%E5%E1%E5%E0%DF
> %E2%E9%ED%F1xyo%5EOKMHJSU%5Bfvml%7F%7B%7B%F0%EB%EA%E2%DD%DD%DB%DB%DC%D
> D%E1%E0%E1%E3%E3%DF%DF%DF%DE%E0%E5%E9%F6%7CmcTKMJIOTYboon%7Ctt%FA%F7%F
> 3%E9%DE%E1%DC%D9%DB%DE%E1%DE%E6%E7%DF%E1%DF%DD%DC%DE%E1%E1%EE%FAx%5DRM
> LHJOPWblo%7C%FA%7B~%F9%FC%F7%E9%E1%E1%DC%D9%DC%DC%DB%DF%E3%E0%DF%E0%DE
> %DC%DF%E1%E1%EE%F9r%5DQMKHKOQXdmt%F8%F6%FC%FB%FFy%F5%EA%E5%DF%DA%D9%DA
> %D8%DB%DE%DD%DE%DF%DF%DF%E3%EA%EB%ECrkbSPOLLOST_jk%F9%F3%FB%F9%FF%FE%F
> 9%EF%E9%E2%DF%DA%DA%DA%D9%D9%DB%DC%DC%DF%E3%E4%EB%F4%FFmdYRPLKNOTZdl%7
> D%EE%F6%EE%EB%EF%EE%EA%E3%E7%DE%DB%DD%D8%D9%D9%D9%D9%DC%DF%E1%EE%FAxf_
> XROMMNQUYbgx%FE%FB%EC%EE%ED%E4%E4%E0%DD%DD%DB%DA%D9%DA%D9%D9%DD%DD%E2%
> EC%F9tg%5EZSPONORUZ%5Efmw%FC%F3%ED%E7%E2%E1%DC%DB%DB%D8%D9%D9%D8%DA%DB
> %DD%E2%E9%F6uh%60%5BVSQOOQSX%5B_jq%F9%ED%E8%E1%DF%DC%DA%DA%DA%DA%D9%DB
> %DC%DC%E3%E6%EE%FEtha%5EYWVTTUWY%5Eckx%FA%EC%E7%E2%DF%DD%DC%DD%DC%DC%D
> F%DE%E2%E6%E7%F1%F8%7Boid_%5C%5BZY%5BZ%5B%5E%60flu%FF%F4%EC%E8%E3%E1%E
> 1%DF%DF%E1%E0%E4%E7%E9%EE%F5%FByqmhfca%60%5E__%60bfhlqz%FE%F7%EF%EE%EB
> %E8%EA%E9%E9%EB%EA%ED%EF%F3%F7%FC%7Cysookkkiijiklmqry%7B%7F%FD%F9%F7%F
> 5%F4%F5%F5%F6%F7%F8%F8%FA%FD%FF%7Dxxtrsooonoposttw%7By%7C%7D~%7F%FE%FF
> %FE%FD%7F%FE%7F%FE%7F%FF%7F%FE%7F%7D~%7B%7Bzvwwvvwvuwvxwyxxyy%7B%7C%7C
> %7D%7D%7F%7F%7F%FD%7F%FF~%7D%7D%7B%7Bzywyvwvvvwxxy%7By~%7C%7D%7F%7D~~%
> 7C~%FF%7D%7C%FF~%7F%7F~~%7Dz%7C%7Czxywwxxwxxwy%7Bx%7Bz%7C%7D%7C%FF~%7F
> %7F~%FF~%7F%7D~%7C%7D%7D~%7D%7D%7C%7B%7B%7B%7Bxzyzyzzz%7Cz%7D~%7C%7C~%
> 7C~%7F~~%FF%7D%7F%7F%7D%7F~%7C%7C%7B%7By%7Byy%7Bzzzz%7B%7B%7B~%7D%7D~~
> %7F%7F%FE%7F%FF
>
> CommandId: C44415

That seems kind of yucky.  How reproducible is it?


--
Matthew Fredrickson
Digium, Inc. | Engineering Manager
445 Jan Davis Drive NW - Huntsville, AL 35806 - USA

--
_____________________________________________________________________
-- Bandwidth and Colocation Provided by http://www.api-digital.com --

Check out the new Asterisk community forum at: https://community.asterisk.org/

New to Asterisk? Start here:
      https://wiki.asterisk.org/wiki/display/AST/Getting+Started

asterisk-users mailing list
To UNSUBSCRIBE or update options visit:
   http://lists.digium.com/mailman/listinfo/asterisk-users
--
_____________________________________________________________________
-- Bandwidth and Colocation Provided by http://www.api-digital.com --

Check out the new Asterisk community forum at: https://community.asterisk.org/

New to Asterisk? Start here:
      https://wiki.asterisk.org/wiki/display/AST/Getting+Started

asterisk-users mailing list
To UNSUBSCRIBE or update options visit:
   http://lists.digium.com/mailman/listinfo/asterisk-users
--
_____________________________________________________________________
-- Bandwidth and Colocation Provided by http://www.api-digital.com --

Check out the new Asterisk community forum at: https://community.asterisk.org/

New to Asterisk? Start here:
      https://wiki.asterisk.org/wiki/display/AST/Getting+Started

asterisk-users mailing list
To UNSUBSCRIBE or update options visit:
   http://lists.digium.com/mailman/listinfo/asterisk-users
--
_____________________________________________________________________
-- Bandwidth and Colocation Provided by http://www.api-digital.com --

Check out the new Asterisk community forum at: https://community.asterisk.org/

New to Asterisk? Start here:
      https://wiki.asterisk.org/wiki/display/AST/Getting+Started

asterisk-users mailing list
To UNSUBSCRIBE or update options visit:
   http://lists.digium.com/mailman/listinfo/asterisk-users

More information about the asterisk-users mailing list