Tag Archives: asterisk

Finding the 100% CPU culprit in multi-threaded applications

Wow, after many years with Linux I just stubled upon some ultra useful functionality and now I feel kind of stupid because I didn’t know about it all that time, lol. :)

I have a multi-threaded application – namely Asterisk, a software PBX – that was always at 250% CPU for many months without a visible reason. Googling for Asterisk + high CPU brought me to this site: https://moythreads.com/wordpress/2009/05/06/why-does-asterisk-consume-100-cpu

Basically everything is already explained there but I’ll give another example. Here sample output from top:

PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
16780 asterisk -11   0 4681m 115m  10m S 207.5  3.0 649:34.98 asterisk

So, Asterisk going berserk at 207% CPU. Let’s install pstack:

yum install gdb

Let’s look at all the threads of Asterisk, PID 16780, using the magic parameters -LlFm to ps which will show all threads of that process:

ps -LlFm 16780

The output will be something like the following. Look for the C column which means CPU usage:

F S UID        PID  PPID   LWP  C NLWP PRI  NI ADDR SZ WCHAN    RSS PSR STIME TTY        TIME CMD
[...]
1 S asterisk     -     - 32498  0    -  49   - -     - futex_     -   7 04:15 -        00:00:00 -
1 S asterisk     -     - 32499  0    -  49   - -     - poll_s     -   1 04:15 -        00:00:00 -
1 S asterisk     -     -   418  0    -  49   - -     - inotif     -   4 04:33 -        00:00:00 -
1 R asterisk     -     -  3967 99    -  49   - -     - -          -   0 05:59 -        12:14:44 -
1 R asterisk     -     -  4367 99    -  49   - -     - -          -   1 06:05 -        12:08:27 -
1 S asterisk     -     - 22668  0    -  49   - -     - poll_s     -   4 16:40 -        00:00:19 -
1 S asterisk     -     - 23627  0    -  49   - -     - poll_s     -   7 17:20 -        00:00:12 -
1 S asterisk     -     - 23641  0    -  49   - -     - poll_s     -   2 17:20 -        00:00:11 -
[...]

Notice those two entries with 99 CPU: LWP 3967 and 4367! Let’s look at these little f*ckers in more detail:

pstack 16780 > /tmp/asterisk.stack.txt

Let’s look into /tmp/asterisk.stack.txt and search for our two LWPs 3967 and 4367…

Thread 35 (Thread 0x7ff211a9b700 (LWP 3967)):
#0  0x00007ff248cb96ec in recv () from /lib64/libc.so.6
#1  0x00007ff23c07b8b1 in ooSocketRecv () from /usr/lib64/asterisk/modules/chan_ooh323.so
#2  0x00007ff23c06461f in ooH2250Receive () from /usr/lib64/asterisk/modules/chan_ooh323.so
#3  0x00007ff23c064fba in ooProcessCallFDSETsAndTimers () from /usr/lib64/asterisk/modules/chan_ooh323.so
#4  0x00007ff23c06518e in ooMonitorCallChannels () from /usr/lib64/asterisk/modules/chan_ooh323.so
#5  0x00007ff23c14ed95 in ooh323c_call_thread () from /usr/lib64/asterisk/modules/chan_ooh323.so
#6  0x000000000057a1a8 in dummy_start ()
#7  0x00007ff2476eaaa1 in start_thread () from /lib64/libpthread.so.0
#8  0x00007ff248cb893d in clone () from /lib64/libc.so.6
Thread 34 (Thread 0x7ff21195e700 (LWP 4367)):
#0  0x00007ff248cb96ec in recv () from /lib64/libc.so.6
#1  0x00007ff23c07b8b1 in ooSocketRecv () from /usr/lib64/asterisk/modules/chan_ooh323.so
#2  0x00007ff23c06461f in ooH2250Receive () from /usr/lib64/asterisk/modules/chan_ooh323.so
#3  0x00007ff23c064fba in ooProcessCallFDSETsAndTimers () from /usr/lib64/asterisk/modules/chan_ooh323.so
#4  0x00007ff23c06518e in ooMonitorCallChannels () from /usr/lib64/asterisk/modules/chan_ooh323.so
#5  0x00007ff23c14ed95 in ooh323c_call_thread () from /usr/lib64/asterisk/modules/chan_ooh323.so
#6  0x000000000057a1a8 in dummy_start ()
#7  0x00007ff2476eaaa1 in start_thread () from /lib64/libpthread.so.0
#8  0x00007ff248cb893d in clone () from /lib64/libc.so.6

Aha! Something about ooh323 which is a module responsible for H.323 which we really don’t need in 2019. Let’s deactivate the culprit and put this into /etc/asterisk/modules.conf:

noload => chan_ooh323.so

Restart asterisk and voila:

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
25893 asterisk -11   0 4601m  64m  10m S 14.3  1.7   3:16.92 asterisk

14% CPU is about what Asterisk really consumes given the load. Problem solved. pstack and ps to the rescue!

Receiving faxes with Asterisk, iaxmodem and HylaFax with dynamic eMail recipients

This is still the best how-to for sending and receiving faxes with Asterisk 1.4 without T.38: http://das-asterisk-buch.de/1.6/faxserver-mit-iaxmodem-und-hylafax.html – in German only, but you can probably still figure it out. I use this setup only to receive faxes and have them mailed as PDFs to the recipient. The speciality here is that the eMail address of the recipient is defined based on the called number, dynamically.

This is extensions.conf:

[fax-incoming]
exten => +496980001234,1,Dial(IAX2/iaxmodem/+496980001234)
exten => +442055446677,1,Dial(IAX2/iaxmodem/+442055446677)
exten => _0000.,1,Dial(IAX2/iaxmodem/${EXTEN})

This simply sends all incoming calls starting with 0000 to iaxmodem/called-number and faxes for the two DIDs +4969… and +4420… also to iaxmodem, passing the called number statically. The magic happens in /var/spool/hylafax/etc/FaxDispatch:

LANG=de_DE
DEST_EMAIL=$(/bin/grep $CALLID4 /etc/hylafax/emails.txt | awk ‘{print $2}’)
FEILTUEP=$(/bin/grep $CALLID4 /etc/hylafax/emails.txt | awk ‘{print $3}’)
if [ “$DEST_EMAIL” == “” ];
then

GNFAX=$(echo $CALLID4 | cut -b 1-4)
if [ “$GNFAX” = “0000” ];
then
SENDTO=$(echo $CALLID4 | sed ‘s/^0000//g’ | sed ‘s/1111/@/g’)
FILETYPE=pdf
else
SENDTO=fax-incoming@company.com
FILETYPE=pdf
fi

else
SENDTO=$DEST_EMAIL
FILETYPE=$FEILTUEP
fi

And this is /etc/hylafax/emails.txt:

+496980001234 hans@company.com pdf
+442055446677 jeff@company.com pdf

What happens is: call (fax) is coming in to +496980001234 – send it to iaxmodem/+496980001234 – pass it to HylaFax – HylaFax “FaxDispatch” script looks up in /etc/hylafax/emails.txt whether we know the called number +496980001234. If so, we also know the eMail address – hans@company.com – and the format – pdf – and HylaFax sends the received fax out to that eMail address in that format. Format can be pdf or tif. But now, if someone faxes to 0000john1111anothercompany.net then Asterisk will pass “0000john1111anothercompany.net” to iaxmodem and therefore to HylaFax “FaxDispatch”, which will do the following: if the called number was not found in /etc/hylafax/emails.txt and the called number starts with 0000, strip off 0000 and replace 1111 with the @ sign. Which translates into an useable eMail address: john@anothercompany.net. This is where the fax will be sent. If the called number does not start with 0000 and it was not found in emails.txt either, then send it to a fallback address: fax-incoming@company.com. To sum up:

1. Manage static users in /etc/hylafax/emails.txt: DID, eMail address, format of attachment
2. The eMail address of the fax recipient will be resolved dynamically for all calls that start with 0000
3. If no match in emails.txt and the called number doesn’t start with 0000, send the fax to a fallback eMail address.