nas_event_daemon

{toc:maxLevel=2}

h1. Для чего нужен nas_event_daemon

Демон отправки событий *nas_event_daemon* забирает из стека(таблица базы "events_stack") команды для отправки и вызывает функции [session|CarbonBilling:Интеграция оборудования интернет] скрипта, передавая в него параметры абонента и NAS

h1. Описание работы

nas_event_daemon работает следующим образом:

# В настройке [оборудования|Справочник NAS] можно указать количество потоков, это по сути сколько [учетных записей|CarbonBilling:Учетная запись. Создание и изменение.] будет обрабатываться одновременно
# Форк берет первые 1000 событий по учетной записи, при этом в первую очередь обрабатывается user_info
# Если скрипт отправки события возвращает код ошибки 143 или 254 значит событие откладывается на 0.017 умноженное на номер попытки, всего может быть 10 попыток, то есть обязательно обратите внимание на дату события и счетчик попыток
# После форка всех потоков демон просто ждет: usleep 50000 (время указано в микросекундах, что равно 0.05 секунды)
# И снова форкает пока не закончатся события в стеке

Можно настроить количество потоков чтобы ускорить процесс но надо помнить несколько вещей:

* Если на каждую учетку очень много событий и отклик у оборудования долгий, то вы запуститите излишнее количество демонов. Это может наоборот замедлить отправку команд.
* Если на учетную запись пиходится по 1 событию и учётных записей много, то увеличение потоков поможет слабо.

Если увеличили потоки обязательно проверьте, что они успевают обрабатывать:
{code}
ps aux | grep nas
{code}

Не должно расти со временем.

{note}
* При управлении оборудованием по CoA средствами radiclient не должно возникать проблем с параллельной отправкой команд
* При управлении оборудованием по ssh или telnet могут возникать проблемы: ssh может работать недостаточно быстро, telnet часто имеет ограничение на одновременное количество сессий
{note}

h2. Еще немного технических деталей

Все службы биллинга (radius, rtsh, и тд) формирующие события на отправку добавляют их сначала в таблицу базы данных EVENTS_STACK_COMPACT, указывая при этом основные данные - что сделать (cmd), с какой учтеной записью (user_id), абонентом (abonent_id), на какой NAS отправить команду (nas_ip), при необходимости по какой услуге (usluga_id) и если это события RADIUS - то ID сессии (acct_session_id).

[Ядро биллинга|CarbonBilling:Worker (ядро биллинга)] обрабатывает компактный стек, собирая большой набор переменых для передачи скрипту управления и перемещает их в основной стек (EVENTS_STACK).

h3. Конструктор отчетов

Используемые таблицы: EVENTS_STACK_COMPACT, EVENTS_STACK.

h3. API

Переходим на вкладку "ОБОРУДОВАНИЕ", выбираем нужный NAS.
Дополнительно > "Количество потоков для отправки команд на оборудование".
Указываем необходимое количество форков, нажимаем сохранить. (На текущий момент количество форков ограничено, максимум 100.)
Будут автоматически запускаться новые форки nas_event_daemon. Количество процессов не должно превышать "количество форков" + 1 процесс "родитель".

При уменьшении количества форков значение не будет изменяться моментально т.к. процессы должны завершить свою работу.

Контролируем обработку команд с помощью ps aux. Например для микротика:

{code}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{code}

Процессы не должны обрабатываться не более 50 секунд. Если Вы наблюдаете эту ситуацию, изменение количества форков не окажет положительного влияния. Необходимо решать проблему с обработкой команд со стороны оборудования.

h1. Отладка

h2. Проверьте, запущен ли демон

Выполните команду "ps aux | grep nas_event_daemon" в терминале, вывод должен быть приблизительно следующим:
{code}# 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
{code}
Первая строка "*/bin/bash /usr/local/sbin/nas_event_daemon*" говорит о том, что демон запущен.


h2. Проверьте стек событий на отправку

Узнать количество команд в стеке с группировкой по типу команды можно, выполнив скрипт *event_count.sh*:
{code}chroot /app/asr_billing/ event_count.sh{code}
Вывод будет приблизительно следующий:
{code}# 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{code}
Скрипт смотрит два стека:
# *compact stack*
# *main stack*

После сгруппированного списка по каждому стеку можно увидеть суммарное количество команд.

Структура таблиц:
# *compact stack* (таблица базы данных EVENTS_STACK_COMPACT) - изначально команды для отправки на оборудование добавляются в compact stack, его наполняют различные подсистемы (radiusd, sync_nasd) базовыми данными по событию, которое нужно отправить на оборудование и обработчик абонентов переносит их в main stack, дополняя нужными данными:
#* *ABONENT_ID* - ID абонента
#* *USER_ID* - ID учетной записи
#* *CMD* - [Команда для выполнения|http://docs.carbonsoft.ru/pages/viewpage.action?pageId=51708843|] (как в примере выше, названия команд в основном и компактном стеке одинаковы)
#* *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) - этот стек формируется [ядром биллинга|Worker (ядро биллинга)] из compact stack, к нему добавляются расширенные данные для передачи в скрипт управления оборудованием, после чего они обрабатываются демоном nas_event_daemon и удаляются из стека
#* *ABONENT_ID* - ID абонента
#* *USER_ID* - ID учетной записи
#* *EVENT_TYPE* - [Команда для выполнения|Состояния пользователей, услуг и команды управления интернет] (то же что CMD в compact stack)
#* *NAS_TYPE* - ID [типа NAS или OSS схемы|CarbonBilling:Интеграция оборудования интернет]
#* *EVENT_DATE* - дата добавления события в main stack
#* *PARAMS* - набор переменных, передаваемый в скрипт событий
#* *OWNER_SCRIPT* - подсистема [воркера|Worker (ядро биллинга)] добавившая событие в стек
#* *OWNER_FUNCTION* - функция этой под системы в которой вызвано добавление события в стек
#* *NAS_ID* - ID NAS/BRAS
#* *TRY_COUNT* - количество выполненных попыток отправки команд

h3. Поиск причины переполнения стека

В зависимости от ситуации и схемы интеграции с NAS, нормальным можно считать следующее количество событий:
* Штатная работа - до 200 событий суммарно в events_stack и events_stack_compact
* Массовая авторизация на NAS (например, после перезагрузки) - до 5 событий на абонента, суммарно в events_stack и events_stack_compact.
Например, на NAS 1000 абонентов. Сразу после перезагрузки NAS может скопиться до 5000 событий из-за большого количества авторизаций в короткий срок.

Если при выполнении проверки в стеке событий *compact stack* наблюдается большое количество команд, и их число остаётся прежним или растет с каждой последующей проверкой, как указано в примере:
{code}
# 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
{code}

Необходимо сделать следующее:
* Проверить, что сервер выполнял перезагрузку несколько минут назад, так как после перезагрузки может наблюдаться массовая авторизация абонентов;
{code}
uptime
{code}
* Проверить [быстродействие биллинга|Биллинг медленно работает#Как понять почему биллинг работает медленно?];
* Убедиться, что в последнее время не вносили изменения в настройки NAS и в некоторых случаях проверить, что опция "Не посылать user_disconnect при получении Radius Stop" включена, для предотвращения зацикливания обработки radius-пакетов биллингом, получаемых от NAS.

При скоплении событий в стеке *main stack*, они должны отправляться на оборудование со скоростью около 1000 за 5 минут.
Если медленней, то:
* Выясните с каким НАС проявляется проблема, для этого выполните [отчёт|Конструктор отчетов]:
{code}
select
n.name,
count(1)
from events_stack es left join nas n on es.nas_id=n.id
group by 1
{code}
* Попробуйте увеличить [количество потоков отправки команд|nas_event_daemon#Настройка]
* Посмотрите [лог отправки событий|nas_event_daemon#Проверьте логи], возможно NAS слишком долго выполняет полученные команды. Отправьте команду вручную и проверьте скорость ответа программой *time*.
На примере Mikrotik:
{code}
# 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
{code}
Время +real+ не должно превышать 300 милисекунд.
* Возможно БД билинга находится на медленном носителе или прочие аппаратные проблемы мешают работе биллинга. Проведите диагностику по статье "[CarbonBilling:Проблемы с оборудованием]"

h2. Проверьте логи
h3. Лог демона
Он расположен по пути */app/asr_billing/var/log/nas_event_daemon.log*
Каждые 60 секунд демон проверяет состояние настройки NAS-серверов в биллинге и синхронизирует их: запускает потоки на новые NAS, актуализирует данные по ранее созданным, останавливает потоки отправки на удаленные NAS.
При запуске итерации в лог записывается строка с параметрами каждого NAS-сервера на который будут отправляться команды. Пример записи о NAS-сервере интегрированном по стандартной схеме Mikrotik-Simple:
{code}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>{code}
* *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-схемы|CarbonBilling:Интеграция оборудования интернет]
* *script_name=<null>* - путь до скрипта, если [стандартные OSS-схемы не используются|CarbonBilling:Интеграция оборудования интернет]

Если в логе нет записи о начале работы с Вашим NAS, возможно:
* Выбрана OSS схема, но не [инициализирована|CarbonBilling:Этап 2. Генерация конфигурации и upload на оборудование]
* Настройка не была завершена - не выбрана OSS схема или не указан скрипт управления если используется старая схема интеграции
* Нет файлов схемы или скрипта управления по указанному пути - такое может произойти при [переносе|CarbonBilling:Перенос на другой сервер или переустановка] на новый сервер

h3. Лог NAS
Логи по каждому NAS в отдельности сохраняются в папке */app/asr_billing/var/log/nas_event_daemon/*, например:
{code}/app/asr_billing/var/log/nas_event_daemon/Test_NAS_10.20.11.15.log{code}
Имя файла состоит из [наименования и IP-адреса NAS-сервера|CarbonBilling:Этап 1. Мастер Стандартной схемы NAS]
В логе записываются команды вызываемые из скрипта управления.
{info}Их можно скопировать прямо из лога и выполнить в командной строке внутри контейнера биллинга, например:
{code}chroot /app/asr_billing
time send_mikrotik_cmd -s 10.90.185.2 admin servicemode /queue simple remove comment=crb_10.88.0.15{code}
Это может сильно помочь в диагностике.{info}
Так же в логе отражен ответ NAS-сервера. При возникновении каких-либо ошибок можно попробовать понять по документации NAS в чем именно была проблема.

h3. Лог учетной записи
Логи учетных записей дублируют данные из лога NAS-сервера, в них пишутся только логи конкретной [учетной записи|CarbonBilling:Учетная запись. Создание и изменение.].
Они располагаются в папке */app/asr_billing/var/log/abonents/*. Рассмотрим на примере:
{code}/app/asr_billing/var/log/abonents/1375/event_1424.log{code}
* */app/asr_billing/var/log/abonents/* - папка с логами отправленных команд по абонентами и учетным записям
* *1375* - ID абонента
* event_*1424*.log - название файла, где 1424 - ID учетной записи.

По этим логам можно попробовать диагностировать проблему на конкретном абоненте, что может существенно снизить время поиска решения.

h1. Кейcы решения проблем или различных задач

h2. Как массово отправить команды по абонентам
Вам потребуется создать скрипт:
* Получите данные абонентов и учетных записей по заданным параметрам [SQL-запросом командой sqlexec|CarbonBilling:Конструктор отчетов] и передайте полученные данные (ID абонентов, учетных записей, IP-адреса и тд) в команду которой управляется оборудование (SSH, RADIUS CoA и тд)
* Так же получить данные с sqlexec и передайте их по API создавая объекты в моделе EventsStackCompact, например так: \\ \\
{code}
#!/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
{code}

h2. NAS не инициализирован или не выбрана схема, но назначены абоненты

h3. Как диагностировали:

# Проверили по каким NAS скопились команды
{code:title=Команда}sqlexec "select count(*), nas_id from events_stack group by nas_id order by 1"{code}
{code:title=Вывод} COUNT NAS_ID
============ ============
5 -170000
1513 1127 {code}
# Выяснили что в очереди скопились команды по NAS ID 1127
# Посмотрели в настройки
{code:title=Команда}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"{code}
{code:title=Вывод}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>{code}
# Оказалось, что не выбран ни тип NAS, ни OSS схема.

Команды не знали куда отправляться, так как nas_event_daemon необходим путь до скрипта управления - он понимает его из настроек NAS в биллинге.

h3. Решение

# В настройках установили OSS схему "*Пользовательская*"
# Перезапустили nas_event_daemon чтобы он подхватил настройки
{code:title=Команда}chroot /app/asr_billing/ service nas_event_daemon restart{code}

h2. NAS инициализирован, но команды копятся в стеке и не передаются на NAS.

h3. Проведение диагностики:

# Проверили по каким NAS скопились команды
{code:title=Команда}sqlexec "select count(*), nas_id from events_stack group by nas_id order by 1"{code}
{code:title=Вывод} COUNT NAS_ID
============ ============
240 1115
273 1114 {code}
# Проверим, для примера, какая команда висит неотправленной для NAS 1114
{code:title=Команда}sqlexec "set list; select first 1 abonent_id, event_type, nas_id from events_stack where NAS_ID=1114"{code}
{code:title=Вывод}
ABONENT_ID 13550
EVENT_TYPE usluga_deactivated
NAS_ID 1114 {code}

h3. Решение
# Необходимо убедиться, что данный абонент не находится в корзине, если удален, в таком случае, в настройках учетной записи удалите NAS и сохраните изменения.
# Если абонент не удален, необходимо проверить доступность этого NAS и его настройки.

h2. Ошибка назначения политики средствами аккаунтинга

h3. Диагностика

# Посмотрели лог учётной записи и обнаружили ошибку:
{code}
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"'
{code}
# Из лога отправки команд нас интересует строка:
{code}
rad_recv: CoA-NAK packet from host 198.51.100.1 port 3799, id=28, length=101
{code}
# Ответ *CoA-NAK* с Reply-Message "Push invoke failed" означает, что брас не обновил состояние сесии, то есть не удалось назначить политику *FWPOL_BLOCKED_TRUSTED* для сессии *192.0.2.1*.

h3. Решение

Для решения проблемы нужно сравнить настойки оборудования и НАС с настройками [стандартных схем|Стандартные схемы]. Возможно на оборудовании была изменена конфигурация сервисов и политик, либо они не были натсроены вовсе.

h2. На NAS некорректно присваиваются абонентам политики Service

h3. Диагностика

При смене статуса "Разблокирован"/"Заблокирован" в логе nas_event_daemon.log фиксируется ошибка:
{code}
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
{code}

h3. Решение

Необходимо проверить, корректно ли указаны пароли на NAS и в биллинге, в настройках этого NAS, в файле main.ini. (/var/oss/core/_NAS_/main.ini)