AMI Potential Memory Leak
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:
ConnectedLineNum:
ConnectedLineName:
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%DD%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%FFgtjch%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%DD%E1%E0%E1%E3%E3%DF%DF%DF%DE%E0%E5%E9%F6%7CmcTKMJIOTYboon%7Ctt%FA%F7%F3%E9%DE%E1%DC%D9%DB%DE%E1%DE%E6%E7%DF%E1%DF%DD%DC%DE%E1%E1%EE%FAx%5DRMLHJOPWblo%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%F9%EF%E9%E2%DF%DA%DA%DA%D9%D9%DB%DC%DC%DF%E3%E4%EB%F4%FFmdYRPLKNOTZdl%7D%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%DF%DE%E2%E6%E7%F1%F8%7Boid_%5C%5BZY%5BZ%5B%5E%60flu%FF%F4%EC%E8%E3%E1%E1%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%F5%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
5 thoughts on - AMI Potential Memory Leak
That seems kind of yucky. How reproducible is it?
—
Matthew Fredrickson Digium, Inc. | Engineering Manager
445 Jan Davis Drive NW – Huntsville, AL 35806 – USA
—
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:
ConnectedLineNum:
ConnectedLineName:
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:
ConnectedLineNum:
ConnectedLineName:
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:
ConnectedLineNum:
ConnectedLineName:
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:
ConnectedLineNum:
ConnectedLineName:
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:
ConnectedLineNum:
ConnectedLineName:
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. That seems kind of yucky. How reproducible is it?
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
That seems kind of yucky. How reproducible is it?
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:
ConnectedLineNum:
ConnectedLineName:
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—
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—