0
Отвечен

После обновления RADIUS зависает

core 4 года назад обновлен mikbill (CEO) 3 года назад 39

После обновления на последнюю версию RADIUS постоянно зависает.


В логе следующее:


Mon May 16 20:37:29 2016 : Info: WARNING: Child is hung for request 620719 in component <core> module .

Mon May 16 20:37:29 2016 : Info: WARNING: Child is hung for request 620884 in component <core> module .
Mon May 16 20:37:29 2016 : Info: WARNING: Child is hung for request 620982 in component <core> module <queue>.
Mon May 16 20:37:29 2016 : Info: WARNING: Child is hung for request 621046 in component <core> module <queue>.
Mon May 16 20:37:29 2016 : Info: WARNING: Child is hung for request 620720 in component <core> module <queue>.
Mon May 16 20:37:29 2016 : Error: Discarding duplicate request from client dhcp port 68 - ID: 1147837977 due to unfinished request 621371 in component <core> module <queue>.
Mon May 16 20:37:29 2016 : Info: WARNING: Child is hung for request 620721 in component <core> module <done>.
Mon May 16 20:37:29 2016 : Info: WARNING: Child is hung for request 620169 in component <core> module <queue>.
Mon May 16 20:37:29 2016 : Info: WARNING: Child is hung for request 620723 in component <core> module .
Mon May 16 20:37:29 2016 : Info: WARNING: Child is hung for request 620724 in component <core> module <queue>.
Mon May 16 20:37:29 2016 : Info: WARNING: Child is hung for request 621047 in component <core> module <queue>.

Каждую секунду десятки таких сообщений.

Если перезапустить RADIUS все нормализуется. Если не трогать то через 12 часов все запросы висят и любые пакеты обрабатываться перестают. В итоге в биллинге становится онлайн = 0, а новые пользователи подключиться не могут.


Судя по top, сервер в это время простаивает (загрузка по нулям).


Судя по mysql, запросов в это время не выполняется:


mysql> show full processlist;

+--------+---------+-----------+---------+---------+-------+-------+-----------------------+
| Id | User | Host | db | Command | Time | State | Info |
+--------+---------+-----------+---------+---------+-------+-------+-----------------------+
| 330106 | mikbill | localhost | mikbill | Sleep | 19352 | | NULL |
| 336447 | root | localhost | mikbill | Sleep | 12421 | | NULL |
| 337799 | mikbill | localhost | mikbill | Sleep | 11356 | | NULL |
| 337807 | mikbill | localhost | mikbill | Sleep | 11416 | | NULL |
| 342804 | mikbill | localhost | mikbill | Sleep | 3660 | | NULL |
| 344910 | mikbill | localhost | mikbill | Sleep | 0 | | NULL |
| 344934 | root | localhost | NULL | Query | 0 | NULL | show full processlist |
+--------+---------+-----------+---------+---------+-------+-------+-----------------------+



В чем причина такого поведения RADIUS и что нужно сделать чтобы исправить?

Не ошибка

При отсутствии информации для более детального ответа даю общие рекомендации которые помогут, советую не пропускать а делать по порядку все.

Причина в пункте 0 , для себя подтвердите ее.


Как временное решение используйте это

https://wiki.mikbill.ru/billing/radiusd_check

но это лишь снятие "симпотомов"...а не устранение причины.



0 Понаблюдайте что у вас с IOPS на сервере , желательно в cactiпохоже на просадку IOPS у диска , как следствие "залипание" запросов в mysql


1 Это поможет заметно

https://mikbill.userecho.com/topics/89-radius-server-is-not-responding/


2 если размер ibdata1 больше 100МБ - то ниже по ссылке сделать обязательно

2.1 Еще вот это стоит сделать "обязательно" если не делали. (касается ссылки ниже)

https://wiki.mikbill.ru/billing/mysql_myisam_inodb


3 Так же есть смысл проверить ротацию логов внутри микбила , если не включена включить.




Какая именно информация нужна для более детального ответа?

Дело точно не в WA, т.к. сервер работает на SSD-дисках. Вот уровень загрузки в момент когда баг проявляется:


Tasks: 165 total, 1 running, 164 sleeping, 0 stopped, 0 zombie

Cpu(s): 1.8%us, 0.5%sy, 0.0%ni, 97.5%id, 0.3%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 3924208k total, 2947480k used, 976728k free, 164840k buffers
Swap: 2096124k total, 7424k used, 2088700k free, 1197028k cached


Т.е. ее можно сказать нет.


Ротация логов работает.



От ibdata1 планировали избавиться через какое-то время, но база большая, так что сразу сделать это не выйдет.

Если бы дело было в залипающих запросах, то они бы были в processlist, верно? А в данном случае он пуст (иногда можно впоймать 1-2 запроса если очень часто вызывать show full processlist).

да пуст, а при этом все висит..

сделайте по шагам , поможет, какти не нужен уже все понятно.


"От ibdata1 планировали избавиться через какое-то время, но база большая, так что сразу сделать это не выйдет."

в этом и причина как раз.

обычно эта процедура занимает 10-15 минут максимум на большой бд, у вас же SSD



Окей, переведем все в отдельные таблички innodb, и отпишусь.

Мы сделали следующее:

1) Конвертировали всю базу в InnoDB (отдельными таблицами).

2) Изменили настройки MySQL на следующие:

innodb_buffer_pool_size = 4G

table_open_cache = 256
query_cache_size = 256M

query_cache_limit = 256M
join_buffer_size = 16M

max_connections = 64
3) Изменили настройки RADIUS на следующие:

max_request_time = 10

cleanup_delay = 10
max_requests = 5000000

4) Увеличили количество доступной памяти на сервере до 8 Гб.

В итоге проблем с производительностью как небыло так и нет, но после 6-12 часов работы в логах radius:

Wed May 18 16:33:53 2016 : Info: WARNING: Child is hung for request 1688562 in component <core> module <queue>.

Wed May 18 16:33:53 2016 : Info: WARNING: Child is hung for request 1688426 in component <core> module <queue>.
Wed May 18 16:33:53 2016 : Info: WARNING: Child is hung for request 1688227 in component <core> module <queue>.
Wed May 18 16:33:53 2016 : Info: WARNING: Child is hung for request 1688238 in component <core> module <queue>.
Wed May 18 16:33:53 2016 : Info: WARNING: Child is hung for request 1688572 in component <core> module <queue>.
Wed May 18 16:33:53 2016 : Info: WARNING: Child is hung for request 1688243 in component <core> module <queue>.
Wed May 18 16:33:53 2016 : Info: WARNING: Child is hung for request 1688578 in component <core> module <queue>.
Wed May 18 16:33:54 2016 : Info: WARNING: Child is hung for request 1688585 in component <core> module <queue>.
Wed May 18 16:33:54 2016 : Info: WARNING: Child is hung for request 1688255 in component <core> module <queue>.
Wed May 18 16:33:54 2016 : Info: WARNING: Child is hung for request 1688265 in component <core> module <queue>.
Wed May 18 16:33:55 2016 : Info: WARNING: Child is hung for request 1688299 in component <core> module <queue>.
Wed May 18 16:33:55 2016 : Info: WARNING: Child is hung for request 1688301 in component <core> module <queue>.
Wed May 18 16:33:55 2016 : Info: WARNING: Child is hung for request 1688309 in component <core> module <queue>.
Wed May 18 16:33:56 2016 : Info: WARNING: Child is hung for request 1688512 in component <core> module <queue>.
Wed May 18 16:33:56 2016 : Info: WARNING: Child is hung for request 1688513 in component <core> module <queue>.

При этом запросы в MySQL не подвисают.

mysql> show full processlist;

+-------+---------+-----------+---------+---------+-------+-------+-----------------------+
| Id | User | Host | db | Command | Time | State | Info |
+-------+---------+-----------+---------+---------+-------+-------+-----------------------+
| 41422 | mikbill | localhost | mikbill | Sleep | 10897 | | NULL |
| 41425 | mikbill | localhost | mikbill | Sleep | 0 | | NULL |
| 41426 | mikbill | localhost | mikbill | Sleep | 1 | | NULL |
| 41429 | mikbill | localhost | mikbill | Sleep | 0 | | NULL |
| 41430 | mikbill | localhost | mikbill | Sleep | 0 | | NULL |
| 49799 | root | localhost | NULL | Query | 0 | NULL | show full processlist |
+-------+---------+-----------+---------+---------+-------+-------+-----------------------+
6 rows in set (0.00 sec)

top - 19:36:45 up 20:41, 2 users, load average: 0.21, 0.29, 0.28

Tasks: 159 total, 1 running, 158 sleeping, 0 stopped, 0 zombie
Cpu(s): 2.0%us, 0.7%sy, 0.0%ni, 97.0%id, 0.2%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 8061144k total, 3895352k used, 4165792k free, 170036k buffers
Swap: 2096124k total, 0k used, 2096124k free, 867252k cached

В настоящий момент удалось выяснить, что когда RADIUS подвисает таким образом то убить его при помощи kill -15 не получается. А если сделать strace то он зависает на инструкции:


futex(0 , FUTEX_WAIT, 30625, NULL

На всякий случай включил логгирование медленных запросов MySQL (>10 сек), в логе - пусто.

а конфиг radiusd.conf можно ?

а так же версию

http://pastebin.com/VLkPrgLh

radiusd: FreeRADIUS Version 2.2.6, for host x86_64-unknown-linux-gnu, built on Mar 25 2015 at 21:27:01

  1. thread pool {
  2. start_servers = 4
  3. max_servers = 4
  4. min_spare_servers = 4
  5. max_spare_servers = 4
  6. max_requests_per_server = 500000
  7. }

вот и проблема


max_requests_per_server = 300

поставте, это рекомендую авторы freeradius иначе он может "зависнуть" у них так и сказано.



Изменение этого параметра не помогает. При любом значении (300, 2000, 500000) RADIUS начинает зависать через пару часов.

Может сменить версию freeradiusd ?

а насчет любого значения я выше писал что об этом думают сами авторы freeradiusd

Если рекомендаций насчет версии нет, попробуем в течение пары дней поставить последнюю (из той же ветки).

вы бы отписались по результатам

нам ведь интересно

Та же проблема. Решение есть?

по сути советы теже что и выше.

у 99% людей после их выполнения все решается.

новые установки мы по этой методике изначально делаем уже какойто период времени.

Заметил такую особенность, что отвал радиуса наступает во время бекапа, скрипт какого был применён

отсюда https://wiki.mikbill.ru/billing/mysql_backup_scp?s[]=sqldump

Поэтому для баз в InnoDB - рекомендуют делать бекап с ключиком --single-transaction

Ну или настроить репликацию базы данных.

у меня тут схожая проблема

иногда радиус подвисает (в данный момент первожу на innodb)

кроме этого все чаще и чаще (бывает пару раз в сутки) на микроте ip dhcp relay начинает работать в одну сторону, т.е. только принимает запросы, а клиентам ничего не возвращает

при этом у меня два НАСа и помогает ребут этого наса

второй может при этом вполне адекватно работать

может ли это быть связано с глюками радиуса и/или размером БД?

кстати в файлах миграции mikbill-to-InnoDB.sh и mikbill-to-MyISAM.sh перед $PASSWORD нужен пробел (во всяком случае у меня) и неплохо бы добавить вывод названия таблицы которая сейчас конвертируется
, а то запустил и догадывайся когда закончит

кстати радиус качал у вас когда переходил на ваш DHCP (версия 2.2.3 соответственно)

можно ли его спокойно обновлять до 2.2.9 отсюда ftp://ftp.freeradius.org/pub/freeradius/freeradius-server-2.2.9.tar.gz или есть какие-то различия между вашей сборкой и офф

никто не обратил внимания насколько выросла в размере табличка radacct, а то у меня из 7 гиг уже 10 гиг стало и до сих пор растет

хотелось бы знать когда перестанет

из 7 стало 16 гиг может кому пригодится

радиус ставлю 2.2.9, проблем не замечено. Radacct будет только расти. В ней хранится история сессий. Нужно настроить ротацию в админке.

Переход на InnoDB действительно улучшил ситуацию (пока рано судить на сколько)

в статье по переходу указано память 3 ГБ - тут ставьте не более половины от того что есть в системе, т.е. при 4 ставить 2, но никак не 3. ядра цпу считайте реальные, а не виртуальные

Вопрос к разработчикам - может есть смысл указать максимальный размер файла таблицы, чтоб мускул ее нарезал гига по 2. Вроде как ИнноДБ так должен даже лучше работать

можно и 1 GB ставить памяти...mysql по нужде добавляет память сколько ему нужно...


"Вопрос к разработчикам - может есть смысл указать максимальный размер файла таблицы, чтоб мускул ее нарезал гига по 2. Вроде как ИнноДБ так должен даже лучше работать" -можно ссылку на материал по теме.

это чисто логическое умозаключение

инно работает с блокировкой по записям, а не по таблице как MyIsam, вот и прикинул что если порезать файл radacct помельче ему будет проще работать. Это предположение без каких либо потверждений (не нашел)

Есть проблемка возникшая после перехода на ИнноДБ - процесс httpds выжирает одно ядро к херам и мускулу начинает становится туго без ресурсов

в инете нарыл что-то про модуль ldap https://svn.haxx.se/users/archive-2007-04/0779.shtml

но какое отношение он имеет к моей сети если нет никакой авторизации по AD - непонятно

Вот здесь хорошо описан процесс: https://habrahabr.ru/post/66151/

Для innoDB таблиц в конфигурации по умолчанию – разные пространства таблиц в файлах innoDB (не забываем, что innoDB позволяет настраивать индивидуальные хранилища на уровне баз данных или даже конкретных таблиц).


This example shows how to create a table that is partitioned by hash into 6 partitions and which uses the InnoDB storage engine:

CREATE TABLE ti (id INT, amount DECIMAL(7,2), tr_date DATE)

ENGINE=INNODB

PARTITION BY HASH( MONTH(tr_date) )

PARTITIONS 6;

еще один alter table на 6 часов я не переживу

надо сначала вычистить бд, а потом уже браться за подобное

его убивание не приводит к каким либо последствиям, но все равно не сильно ясно откуда он выростает

Если кому интересно, нам не удалось решить эту проблему. После выполнения всех рекомендаций технической поддержки (отдельный ssd для базы, увеличение памяти, конвертация в innodb, обновление системы и radius до последней версии), все так же видим в логах:


Tue Feb 14 18:31:48 2017 : Info: WARNING: Child is hung for request 67640 in component authorize module perl.

Tue Feb 14 18:31:49 2017 : Info: WARNING: Child is hung for request 67640 in component authorize module perl.
Tue Feb 14 18:31:52 2017 : Info: WARNING: Child is hung for request 67640 in component authorize module perl.
Tue Feb 14 18:31:55 2017 : Info: WARNING: Child is hung for request 67640 in component authorize module perl.
Tue Feb 14 18:32:00 2017 : Info: WARNING: Child is hung for request 67640 in component authorize module perl.
Tue Feb 14 18:32:08 2017 : Info: WARNING: Child is hung for request 67640 in component authorize module perl.


И проблема явно не в MySQL, поскольку в это время нет записей о длинных запросах, в show processlist никогда ничего не блокируется, а вся база влезает в innodb buffer pool (т.е. находится в памяти).


Имхо, это баг в биллинге, поскольку такие ошибки появились после очередного обновления, но к сожалению никаких путей устранения этого кроме как добавления задания в крон для перезапуска radius мы не видим.

по новому диску

1 вы тестировали IOPS диска для БД перед запуском в работу ?

2 вы тестировали скорость записи на новый диск ? ( чтобы понять точно ли ег овидит контролер)

3 не включали ли случаем програмный или другой raid для нового диска на БД ?


в my.cnf

4 прописано использование tmp на новом диске ?

5 ну и естественно сам /var/lib/mysql путь заменили на новый диск ?

может пёрл?

в саппорт обратитесь - ребята редко отказывают в интересных проблемах даже если у вас кончилась техподдержка

кстати с начала разбора проблемы ошибки изменились - значит эффект есть

это не perl.

а таймаут по неответу от БД, скорее всего какойто из процедур/запросов.


учитывая что аккаунтинг храниться в ОЗУ типе таблицы memory - как класс горячих данных, то проблема с другим типом данных какой записывается (реже считывается) с диска.

это общее направление а чуть выше я дал 5 пунктов вопросов - если на них ответить то автору темы думаю все станет очевидно.

Сервис поддержки клиентов работает на платформе UserEcho