Asterisk 100% загрузка CPU

Начал один из подопечных asterisk`ов 100% загрузку ядра процессора иногда устраивать, причем даже в не нагруженное время бывало, как сейчас.

Ниже поиск и решение проблемы.

Для начала посмотрим какой из потоков asterisk`а грузит CPU:

ps -LlFm -p `pidof asterisk`

Вывод будет следующий:

[root@sip ~]# ps -LlFm -p `pidof asterisk`
F S UID        PID  PPID   LWP  C NLWP PRI  NI ADDR SZ WCHAN    RSS PSR STIME TTY          TIME CMD
4 - asterisk 15841 15838     - 12   49   -   - - 334124 -     192540  - Jan24 ?        05:49:28 /usr/sbin/asterisk -f -U asterisk -G asterisk -vvvg -c
4 S asterisk     -     - 15841  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:00:04 -
1 S asterisk     -     - 15842  0    -  80   0 -     - futex_     -   0 Jan24 -        00:01:26 -
1 S asterisk     -     - 15843  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15844  0    -  80   0 -     - futex_     -   0 Jan24 -        00:01:22 -
1 S asterisk     -     - 15845  0    -  80   0 -     - hrtime     -   0 Jan24 -        00:01:40 -
1 S asterisk     -     - 15846  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15847  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15848  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:16 -
1 S asterisk     -     - 15849  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15850  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:12 -
1 S asterisk     -     - 15851  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15852  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15853  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15856  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:02 -
1 S asterisk     -     - 15857  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15858  0    -  80   0 -     - hrtime     -   0 Jan24 -        00:03:11 -
1 S asterisk     -     - 15859  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15860  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:20:23 -
1 S asterisk     -     - 15861  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:00:02 -
1 S asterisk     -     - 15862  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:05 -
1 S asterisk     -     - 15863  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:10 -
1 S asterisk     -     - 15864  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:35 -
1 S asterisk     -     - 15865  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:35 -
1 S asterisk     -     - 15866  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:36 -
1 S asterisk     -     - 15867  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:35 -
1 S asterisk     -     - 15868  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:35 -
1 S asterisk     -     - 15869  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:40 -
1 S asterisk     -     - 15870  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:35 -
1 S asterisk     -     - 15871  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:35 -
1 S asterisk     -     - 15872  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:35 -
1 S asterisk     -     - 15873  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:35 -
1 S asterisk     -     - 15874  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:07:21 -
1 S asterisk     -     - 15875  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:00:01 -
1 S asterisk     -     - 15876  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:02:56 -
1 S asterisk     -     - 15877  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:00:03 -
1 S asterisk     -     - 15878  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15881  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:00:01 -
1 S asterisk     -     - 15882  0    -  80   0 -     - hrtime     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15883  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15884  0    -  80   0 -     - hrtime     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15885  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15886  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:33 -
1 S asterisk     -     - 15887  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15888  0    -  80   0 -     - poll_s     -   0 Jan24 -        00:00:00 -
1 S asterisk     -     - 15939  0    -  80   0 -     - futex_     -   0 Jan24 -        00:00:02 -
1 S asterisk     -     - 13823  0    -  80   0 -     - inotif     -   0 Jan25 -        00:00:00 -
1 R asterisk     -     - 14526 47    -  80   0 -     - -          -   0 21:30 -        00:34:59 -
1 R asterisk     -     - 14696 36    -  80   0 -     - -          -   0 21:44 -        00:21:35 -
1 R asterisk     -     - 14890 32    -  80   0 -     - -          -   0 21:59 -        00:14:27 -

Смотрим на столбец «C», который показывает сколько CPU забирает соответствующий поток и их LWP(Light weight Processes). Нашлось три подозреваемых, их LWP: 14526, 14696 и 14890. Более того, время старта потока 14526 равняется времени начала загрузки CPU Asterisk`ом.

Теперь запоминаем LWP подозреваемых и идем собирать дамп стека Asterisk`а в файл.

stack `pidof asterisk` > /tmp/asterisk.dump

Ниже приведена только та часть файла, которая относится к искомым LWP:

Thread 4 (Thread 0x7f59a06f2700 (LWP 14526)):
#0  0x00007f59eb16685c in recv () from /lib64/libc.so.6
#1  0x00007f59b2e8d8b1 in ooSocketRecv () from /usr/lib64/asterisk/modules/chan_ooh323.so
#2  0x00007f59b2e7661f in ooH2250Receive () from /usr/lib64/asterisk/modules/chan_ooh323.so
#3  0x00007f59b2e76fba in ooProcessCallFDSETsAndTimers () from /usr/lib64/asterisk/modules/chan_ooh323.so
#4  0x00007f59b2e7718e in ooMonitorCallChannels () from /usr/lib64/asterisk/modules/chan_ooh323.so
#5  0x00007f59b2f60d95 in ooh323c_call_thread () from /usr/lib64/asterisk/modules/chan_ooh323.so
#6  0x000000000057a1a8 in dummy_start ()
#7  0x00007f59e9b96aa1 in start_thread () from /lib64/libpthread.so.0
#8  0x00007f59eb165aad in clone () from /lib64/libc.so.6
Thread 3 (Thread 0x7f59a0486700 (LWP 14696)):
#0  0x00007f59eb16685c in recv () from /lib64/libc.so.6
#1  0x00007f59b2e8d8b1 in ooSocketRecv () from /usr/lib64/asterisk/modules/chan_ooh323.so
#2  0x00007f59b2e7661f in ooH2250Receive () from /usr/lib64/asterisk/modules/chan_ooh323.so
#3  0x00007f59b2e76fba in ooProcessCallFDSETsAndTimers () from /usr/lib64/asterisk/modules/chan_ooh323.so
#4  0x00007f59b2e7718e in ooMonitorCallChannels () from /usr/lib64/asterisk/modules/chan_ooh323.so
#5  0x00007f59b2f60d95 in ooh323c_call_thread () from /usr/lib64/asterisk/modules/chan_ooh323.so
#6  0x000000000057a1a8 in dummy_start ()
#7  0x00007f59e9b96aa1 in start_thread () from /lib64/libpthread.so.0
#8  0x00007f59eb165aad in clone () from /lib64/libc.so.6
Thread 2 (Thread 0x7f59a03c5700 (LWP 14890)):
#0  0x00007f59eb16685c in recv () from /lib64/libc.so.6
#1  0x00007f59b2e8d8b1 in ooSocketRecv () from /usr/lib64/asterisk/modules/chan_ooh323.so
#2  0x00007f59b2e7661f in ooH2250Receive () from /usr/lib64/asterisk/modules/chan_ooh323.so
#3  0x00007f59b2e76fba in ooProcessCallFDSETsAndTimers () from /usr/lib64/asterisk/modules/chan_ooh323.so
#4  0x00007f59b2e7718e in ooMonitorCallChannels () from /usr/lib64/asterisk/modules/chan_ooh323.so
#5  0x00007f59b2f60d95 in ooh323c_call_thread () from /usr/lib64/asterisk/modules/chan_ooh323.so
#6  0x000000000057a1a8 in dummy_start ()
#7  0x00007f59e9b96aa1 in start_thread () from /lib64/libpthread.so.0
#8  0x00007f59eb165aad in clone () from /lib64/libc.so.6

Как видим, грузит его модуль chan_ooh323.so, который ранее использовался, но сейчас болтается в памяти и начал доставлять неудобвства. Видимо злодеи басурманские нашли какой-то баг в нем, от чего он СЗГ грузит. Другой паразитной активности не замечено. Благополучно отключаем его автозагрузку в файле /etc/asterisk/modules.conf

[modules]
autoload=yes
...
noload => chan_ooh323.so
...

После чего перезагружаем asterisk

service asterisk restart

и смотрим, что такого модуля у нас больше нет:

sip*CLI> module show like chan_ooh323.so
Module                         Description                              Use Count 
0 modules loaded

Всё. Спасибо за внимание. Надеюсь, кому-то поможет.

p.s. asterisk 11, centos 6 x86_64




.gitignore для django virtualenv

Содержание файла .gitignore для django проекта в virtualenv.

# Byte-compiled / optimized / DLL files
__pycache__/
*.py[cod]

# C extensions
*.so

# Distribution / packaging
bin/
build/
develop-eggs/
dist/
eggs/
lib/
lib64/
parts/
sdist/
var/
*.egg-info/
.installed.cfg
*.egg

# Installer logs
pip-log.txt
pip-delete-this-directory.txt

# Unit test / coverage reports
.tox/
.coverage
.cache
nosetests.xml
coverage.xml

# Translations
*.mo

# Mr Developer
.mr.developer.cfg
.project
.pydevproject

# Rope
.ropeproject

# Django stuff:
*.log
*.pot

# Sphinx documentation
docs/_build/

# idea/pycharm
.idea/