Для чего нужен nas_event_daemon
Демон отправки событий nas_event_daemon забирает из стека(таблица базы "events_stack") команды для отправки и вызывает функции session скрипта, передавая в него параметры абонента и NAS
Описание работы
nas_event_daemon работает следующим образом:
- В настройке оборудования можно указать количество потоков, это по сути сколько учетных записей будет обрабатываться одновременно
- Форк берет первые 1000 событий по учетной записи, при этом в первую очередь обрабатывается user_info
- Если скрипт отправки события возвращает код ошибки 143 или 254 значит событие откладывается на 0.017 умноженное на номер попытки, всего может быть 10 попыток, т.е. обязательно обратите внимание на дату события и счетчик попыток
- После форка всех потоков демон просто ждет: usleep 50000 (время указано в микросекундах, что равно 0.05 секунды)
- И снова форкает пока не закончатся события в стеке
Можно настроить количество потоков чтобы ускорить процесс но надо помнить несколько вещей:
- Если на каждую учетку очень много событий и отклик у оборудования долгий то вы просто наспамите демонов, которые скорее всего еще и транзакций навешают друг на друга т.к. один не успеет завершиться за 50000 милисекунд
- Если на учетку по 1 событию и учеток очень много, то увеличение потоков не очень поможет.
Если увеличили потоки обязательно проверьте что они успевают обрабатывать:
ps aux |grep nas
Не должно со временем расти.
|
Еще немного технических деталей
Все службы биллинга (radius, rtsh, и тд) формирующие события на отправку добавляют их сначала в таблицу базы данных EVENTS_STACK_COMPACT, указывая при этом основные данные - что сделать (cmd), с какой учтеной записью (user_id), абонентом (abonent_id), на какой NAS отправить команду (nas_ip), при необходимости по какой услуге (usluga_id) и если это события RADIUS - то ID сессии (acct_session_id).
Ядро биллинга обрабатывает компактный стек, собирая большой набор переменых для передачи скрипту управления и перемещает их в основной стек (EVENTS_STACK).
Конструктор отчетов
Используемые таблицы: EVENTS_STACK_COMPACT, EVENTS_STACK.
Вряд ли Вам потребуется их использовать в конструкторе отчетов, стеки динамические, но это может быть полезно при отладке из командной строки.
API
Используемые модели: EventsStackCompact, EventsStack.
Настройка
Переходим на вкладку "ОБОРУДОВАНИЕ", выбираем нужный NAS.
Дополнительно > "Количество потоков для отправки команд на оборудование".
Указываем необходимое количество форков, нажимаем сохранить. (На текущий момент количество форков ограничено, максимум 100.)
Будут автоматически запускаться новые форки nas_event_daemon. Количество процессов не должно превышать "количество форков" + 1 процесс "родитель".
При уменьшении количества форков значение не будет изменяться моментально т.к. процессы должны завершить свою работу.
Контролируем обработку команд с помощью ps aux. Например для микротика:
ps aux |grep send_mikrotik_cmd root 27122 2.0 0.0 748333 8230 ? SN 15:47 0:00 /usr/bin/python2.7 /usr/local/bin/send_mikrotik_cmd -s 10.0.0.1 carbon carbon /ip firewall address-list remove numbers=192.168.1.10_crb_blocked
Процессы не должны обрабатываться не более 50 секунд. Если Вы наблюдаете эту ситуацию, изменение количества форков не окажет положительного влияния. Необходимо решать проблему с обработкой команд со стороны оборудования.
Отладка
Проверьте, запущен ли демон
Выполните команду "ps aux | grep nas_event_daemon" в терминале, вывод должен быть приблизительно следующим:
# ps aux | grep nas_event_daemon root 13560 0.0 0.0 106184 1608 ? Ss 10:40 0:00 /bin/bash /usr/local/sbin/nas_event_daemon root 14291 0.0 0.0 103320 920 pts/0 S+ 10:40 0:00 grep nas_event_daemon
Первая строка "/bin/bash /usr/local/sbin/nas_event_daemon" говорит о том, что демон запущен.
Проверьте стек событий на отправку
Узнать количество команд в стеке с группировкой по типу команды можно, выполнив скрипт event_count.sh:
chroot /app/asr_billing/ event_count.sh
Вывод будет приблизительно следующий:
# compact stack TOTAL COUNT 0 # main stack COUNT EVENT_TYPE 52 b_negbal 4 b_sys 44 u_b_negbal 207 user_accept 75 user_add 16 user_del 50 user_drop 73 user_edit 1 user_rate_set_cancel 168 user_redirect 89 user_redirect_cancel 122 usluga_activated 28 usluga_add 3 usluga_deactivated 4 usluga_del 1 usluga_disabled 28 usluga_recalc TOTAL COUNT 965
Скрипт смотрит два стека:
- compact stack
- main stack
После сгруппированного списка по каждому стеку можно увидеть суммарное количество команд.
Структура таблиц:
- compact stack (таблица базы данных EVENTS_STACK_COMPACT) - изначально команды для отправки на оборудование добавляются в compact stack, его наполняют различные подсистемы (radiusd, sync_nasd) базовыми данными по событию, которое нужно отправить на оборудование и обработчик абонентов переносит их в main stack, дополняя нужными данными:
- ABONENT_ID - ID абонента
- USER_ID - ID учетной записи
- CMD - Команда для выполнения (как в примере выше, названия команд в основном и компактном стеке одинаковы)
- USER_IP - IP абонента
- NAS_IP - IP NAS/BRAS
- USLUGA_ID - ID услуги (указывается при изменении статусов услуг абонента в событиях usluga_add, usluga_activated и т.д.)
- ACCT_SESSION_ID - Acct-Session-ID (уникальный ID сессии, используется при авторизации по RADIUS)
- main stack (таблица базы данных EVENTS_STACK) - этот стек формируется из compact stack, к нему добавляются расширенные данные для передачи в скрипт управления оборудованием, после чего они обрабатываются демоном nas_event_daemon и удаляются из стека
- ABONENT_ID - ID абонента
- USER_ID - ID учетной записи
- EVENT_TYPE - Команда для выполнения (то же что CMD в compact stack)
- NAS_TYPE - ID типа NAS или OSS схемы
- EVENT_DATE - дата добавления события в main stack
- PARAMS - набор переменных, передаваемый в скрипт событий
- OWNER_SCRIPT - подсистема воркера добавившая событие в стек
- OWNER_FUNCTION - функция этой под системы в которой вызвано добавление события в стек
- NAS_ID - ID NAS/BRAS
- TRY_COUNT - количество выполненных попыток отправки команд
Поиск причины переполнения стека
В зависимости от ситуации и схемы интеграции с NAS, нормальным можно считать следующее количество событий:
- Штатная работа - до 200 событий суммарно в events_stack и events_stack_compact
- Массовая авторизация на NAS (например, после перезагрузки) - до 5 на абонента в суммарно в events_stack и events_stack_compact.
Например, на NAS 1000 абонентов. Сразу после перезагрузки NAS может скопиться до 5000 событий из-за большого количества авторизаций в короткий срок.
Если при выполнении проверки в стеке событий compact stack наблюдается большое количество команд и их число не уменьшается (растет) с каждой последующей проверкой, как указано в примере:
# compact stack COUNT CMD 7774 rad_acc_start 6762 rad_acc_stop 10827 rad_simul 1736 try_double_login 4 user_accept 97 user_add 50 user_del 249 user_rate_set 148 user_redirect_cancel TOTAL COUNT 27647
необходимо сделать следующее:
- Проверить текущую нагрузку на биллинге командой top;
- Проверить, что сервер выполнял перезагрузку несколько минут назад, так как после перезагрузки может наблюдаться массовая авторизация абонентов;
- Проверить сервер на соответствие системным требованиям;
- Убедиться, что в последнее время не вносили изменения в настройки NAS и в некоторых случаях проверить, что опция "Не посылать user_disconnect при получении Radius Stop" включена, для предотвращения зацикливания обработки radius-пакетов биллингом, получаемых от NAS.
При скоплении событий в стеке main stack, они должны отправляться на оборудование со скоростью около 1000 за 5 минут.
Если медленней, то:
- Попробуйте увеличить количество форков (описано выше в статье)
- Посмотрите лог отправки событий, возможно NAS слишком долго выполняет полученные команды. Отправьте команду вручную и проверьте скорость ответа программой time.
На примере Mikrotik:# time send_mikrotik_cmd -s 10.90.185.2 admin servicemode /queue simple remove comment=crb_10.88.0.15 ERROR: UnknownParameter message: 'unknown parameter', command: '/queue/simple/remove =comment=crb_10.88.0.15' exit code: 249 real 0m0.096s user 0m0.031s sys 0m0.008s
Время real не должно превышать 300 милисекунд.
- Возможно БД билинга находится на медленном носителе или прочие аппаратные проблемы мешают работе биллинга. Проведите диагностику по статье "Проблемы с оборудованием"
Проверьте логи
Лог демона
Он расположен по пути /app/asr_billing/var/log/nas_event_daemon.log
Каждые 60 секунд демон проверяет состояние настройки NAS-серверов в биллинге и синхронизирует их: запускает потоки на новые NAS, актуализирует данные по ранее созданным, останавливает потоки отправки на удаленные NAS.
При запуске итерации в лог записывается строка с параметрами каждого NAS-сервера на который будут отправляться команды. Пример записи о NAS-сервере интегрированном по стандартной схеме Mikrotik-Simple:
2019-08-27 10:57:41 vm185-120 nas_event_daemon[32736]: Start work with nas nasid=1116 nas_ip=10.90.185.2 oss_pathname=/var/oss/core/Mikrotik-Simple script_name=<null>
- 2019-08-27 10:57:41 - дата и время записи
- vm185-120 - hostname опреационной системы
- nas_event_daemon[32736]: Start work with nas - запись о начале работы с NAS, 32736 - PID процесса демона
- nasid=1116 - ID NAS в базе биллинга
- nas_ip=10.90.185.2 - IP-адрес NAS
- oss_pathname=/var/oss/core/Mikrotik-Simple - путь директории OSS-схемы
- script_name=<null> - путь до скрипта, если стандартные OSS-схемы не используются
Если в логе нет записи о начале работы с Вашим NAS, возможно:
- Выбрана OSS схема, но не инициализирована
- Настройка не была завершена - не выбрана OSS схема или не указан скрипт управления если используется старая схема интеграции
- Нет файлов схемы или скрипта управления по указанному пути - такое может произойти при переносе на новый сервер
Лог NAS
Логи по каждому NAS в отдельности сохраняются в папке /app/asr_billing/var/log/nas_event_daemon/, например:
/app/asr_billing/var/log/nas_event_daemon/Test_NAS_10.20.11.15.log
Имя файла состоит из наименования и IP-адреса NAS-сервера
В логе записываются команды вызываемые из скрипта управления.
Их можно скопировать прямо из лога и выполнить в командной строке внутри контейнера биллинга, например:
chroot /app/asr_billing time send_mikrotik_cmd -s 10.90.185.2 admin servicemode /queue simple remove comment=crb_10.88.0.15 Это может сильно помочь в диагностике. |
Так же в логе отражен ответ NAS-сервера. При возникновении каких-либо ошибок можно попробовать понять по документации NAS в чем именно была проблема.
Лог учетной записи
Логи учетных записей дублируют данные из лога NAS-сервера, в них пишутся только логи конкретной учетной записи.
Они располагаются в папке /app/asr_billing/var/log/abonents/. Рассмотрим на примере:
/app/asr_billing/var/log/abonents/1375/event_1424.log
- /app/asr_billing/var/log/abonents/ - папка с логами отправленных команд по абонентами и учетным записям
- 1375 - ID абонента
- event_1424.log - название файла, где 1424 - ID учетной записи.
По этим логам можно попробовать диагностировать проблему на конкретном абоненте, что может существенно снизить время поиска решения.
Кейcы решения проблем или различных задач
Как массово отправить команды по абонентам
Вам потребуется создать скрипт:
- Получите данные абонентов и учетных записей по заданным параметрам SQL-запросом командой sqlexec и передайте полученные данные (ID абонентов, учетных записей, IP-адреса и тд) в команду которой управляется оборудование (SSH, RADIUS CoA и тд)
- Так же получить данные с sqlexec и передайте их по API создавая объекты в моделе EventsStackCompact, например так:
#!/bin/bash sqlexec "set list; select id from users u where nas_id=1112" | awk '$2{print $2}' | while read user_id; do curl -XPOST 'http://169.254.80.82:8082/rest_api/v2/EventsStackCompact/' -d 'method1=objects.create&arg1={"user_id": '$user_id',"cmd":"user_redirect_cancel"}' done exit 0
NAS не инициализирован или не выбрана схема, но назначены абоненты
Как диагностировали:
- Проверили по каким NAS скопились команды
Команда
sqlexec "select count(*), nas_id from events_stack group by nas_id order by 1"
ВыводCOUNT NAS_ID ============ ============ 5 -170000 1513 1127
- Выяснили что в очереди скопились команды по NAS ID 1127
- Посмотрели в настройки
Команда
sqlexec -l "select n.name,uf_ip2string(n.ip),n.OSS_PATHNAME,'',nt.name,'',ns.name,n.nas_scheme_ver from nas n left join nas_scheme ns on n.nas_scheme_id=ns.id left join nas_type nt on n.nas_type=nt.id where n.id=1127"
ВыводNAME MY_NAS UF_IP2STRING 10.0.0.1 OSS_PATHNAME /var/oss/core/MY_NAS CONSTANT NAME <null> CONSTANT NAME <null> NAS_SCHEME_VER <null>
- Оказалось, что не выбран ни тип NAS, ни OSS схема.
Команды не знали куда отправляться, так как nas_event_daemon необходим путь до скрипта управления - он понимает его из настроек NAS в биллинге.
Решение
- В настройках установили OSS схему "Пользовательская"
- Перезапустили nas_event_daemon чтобы он подхватил настройки
Команда
chroot /app/asr_billing/ service nas_event_daemon restart
NAS инициализирован, но команды копятся в стеке и не передаются на NAS.
Проведение диагностики:
- Проверили по каким NAS скопились команды
Команда
sqlexec "select count(*), nas_id from events_stack group by nas_id order by 1"
ВыводCOUNT NAS_ID ============ ============ 240 1115 273 1114
- Проверим, для примера, какая команда висит неотправленной для NAS 1114
Команда
sqlexec "set list; select first 1 abonent_id, event_type, nas_id from events_stack where NAS_ID=1114"
ВыводABONENT_ID 13550 EVENT_TYPE usluga_deactivated NAS_ID 1114
Решение
- Необходимо убедиться, что данный абонент не находится в корзине, если удален, в таком случае, в настройках учетной записи удалите NAS и сохраните изменения.
- Если абонент не удален, необходимо проверить доступность этого NAS и его настройки.
Ошибка назначения политики средствами аккаунтинга
Диагностика
- Посмотрели лог учётной записи и обнаружили ошибку:
2020-05-28 10:06:22 localhost.localdomain session[6084] 367336 1449: user_accept ... 2020-05-28 10:06:22 localhost.localdomain session[6084] 367336 1449: echo 'Cisco-Account-Info="S192.0.2.1.:vrf-id=global", cisco-avpair+="subscriber:service-name=FWPOL_BLOCKED_TRUSTED", cisco-avpair+="subscriber:command=deactivate-service"' 2020-05-28 10:06:22 localhost.localdomain session[6084] 367336 1449: __radclient coa 2020-05-28 10:06:22 localhost.localdomain session[6084] 367336 1449: radclient -c 1 -r 2 -t 1 -x 198.51.100.1:3799 coa servicemode 2020-05-28 10:06:22 localhost.localdomain session[6084] 367336 1449: res='Sending CoA-Request of id 28 to 198.51.100.1 port 3799 Cisco-Account-Info = "S192.0.2.1:vrf-id=global" Cisco-AVPair += "subscriber:service-name=FWPOL_BLOCKED_TRUSTED" Cisco-AVPair += "subscriber:command=deactivate-service" rad_recv: CoA-NAK packet from host 198.51.100.1 port 3799, id=28, length=101 Reply-Message = "Push invoke failed" Error-Cause = Unsupported-Service Cisco-Command-Code = "\02057;;FWPOL_BLOCKED_TRUSTED" Cisco-Account-Info = "S192.0.2.1"'
- Из лога отправки команд нас интересует строка:
rad_recv: CoA-NAK packet from host 198.51.100.1 port 3799, id=28, length=101
- Ответ CoA-NAK с Reply-Message "Push invoke failed" означает, что брас не обновил состояние сесии, то есть не удалось назначить политику FWPOL_BLOCKED_TRUSTED для сессии 192.0.2.1.
Решение
Для решения проблемы нужно сравнить настойки оборудования и НАС с настройками стандартных схем. Возможно на оборудовании была изменена конфигурация сервисов и политик, либо они не были натсроены вовсе.
На NAS некорректно присваиваются абонентам политики Service
Диагностика
При смене статуса "Разблокирован"/"Заблокирован" в логе nas_event_daemon.log фиксируется ошибка:
rad_verify: Received CoA-ACK packet from home server 10.10.1.248 port 3799 with invalid signature! (Shared secret is incorrect.)
radclient: no response from server for ID 234 socket 3
Решение
Необходимо проверить, корректно ли указаны пароли на NAS и в биллинге, в настройках этого NAS, в файле main.ini. (/var/oss/core/NAS/main.ini)