[asterisk-users] ERROR during high volume MoH dialplan

[Richard Mudgett]

On Mon, Aug 28, 2017 at 1:04 PM, Joseph Smith <warlock1999 at hotmail.com>
wrote:

> Hello,
>
> I've recently setup a small load test against an instance of Asterisks.
> I've tested on asterisk 13.5 and 14.6 with the same results.
>
I think you mean 13.15.0 as the excessive ref count trap is not in 13.5.0.

> I am using PJSIP.  My dial plan is,
>
> [test]
>
> exten => 1001,1,Answer
>
> exten => 1001,n,MusicOnHold(15)
>
> exten => 1001,n,Hangup
>
>
> I am using SIPP to test.  I can share XML if desired but it simply waits
> on the line while music plays for 8 seconds.  I used sippycup to generate
> it with the following steps in the yaml file.
>
>
> steps:
>
>   - invite
>
>   - wait_for_answer
>
>   - ack_answer
>
>   - sleep 8
>
>   - send_bye
>
>
> At around 500 calls per second I begin to see the following ERRORs,
>
>
> [Aug 28 17:46:14] ERROR[26150][C-00005594]: frame.c:343 ast_frdup:
> Excessive refcount 100000 reached on ao2 object 0x26bffc0
>
> [Aug 28 17:46:14] ERROR[26150][C-00005594]: frame.c:343 ast_frdup: FRACK!,
> Failed assertion Excessive refcount 100000 reached on ao2 object 0x26bffc0
> (0)
>
> Got 19 backtrace records
>
> #0: [0x45d229] /usr/sbin/asterisk(__ao2_ref+0x1a9) [0x45d229]
>
> #1: [0x526ce6] /usr/sbin/asterisk(ast_frdup+0x116) [0x526ce6]
>
> #2: [0x5fa616] /usr/sbin/asterisk(ast_translate+0x306) [0x5fa616]
>
> #3: [0x4bf16b] /usr/sbin/asterisk(ast_write+0x104b) [0x4bf16b]
>
> #4: [0x7efeb578230b] /usr/lib/asterisk/modules/res_musiconhold.so(+0x430b)
> [0x7efeb578230b]
>
> #5: [0x4b5b52] /usr/sbin/asterisk() [0x4b5b52]
>
> #6: [0x4c259c] /usr/sbin/asterisk() [0x4c259c]
>
> #7: [0x4c4a45] /usr/sbin/asterisk() [0x4c4a45]
>
> #8: [0x7efeb578478d] /usr/lib/asterisk/modules/res_musiconhold.so(+0x678d)
> [0x7efeb578478d]
>
> #9: [0x58ec79] /usr/sbin/asterisk(pbx_exec+0xb9) [0x58ec79]
>
> #10: [0x582e84] /usr/sbin/asterisk() [0x582e84]
>
> #11: [0x584e7c] /usr/sbin/asterisk() [0x584e7c]
>
> #12: [0x5863fb] /usr/sbin/asterisk() [0x5863fb]
>
> #13: [0x60002a] /usr/sbin/asterisk() [0x60002a]
>
>
This inline backtrace would be more useful if you had BETTER_BACKTRACES
enabled.


>
> I've also seen similar behavior when using playback instead of
> MusicOnHold.  CPU usage gets around 50%.  Can anyone enlighten me on the
> meaning and cause of the error?  Is there some steps (config etc) that can
> be taken to alleviate the issue?
>

This particular FRACK is meant to help find ao2 object reference leaks.  It
acts as an early warning for excessive references to any particular ao2
object used in the code.  The FRACK itself is benign.  Based upon the
inline backtrace the ao2 object is likely to be a codec format.

* What codecs are you using in this setup?

* With 500 calls/sec and the calls lasting 8 seconds that comes to 4000
active channels.  Hitting the FRACK would result in an average of 25
references to the format per channel.  This is a simplistic calculation as
there are going to be some references that have nothing to do with a call.
The number of base references would depend upon which codec is involved.

* There is no user configurable option to change the excessive ref count
trigger value.  However, you could change the EXCESSIVE_REF_COUNT define
value in the main/astobj2.c file and recompile.

Richard
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.digium.com/pipermail/asterisk-users/attachments/20170828/1304a594/attachment.html>