forum.bitel.ru http://forum.bitel.ru/ |
|
Обработка пакета авторизации (РЕШЕНО) http://forum.bitel.ru/viewtopic.php?f=19&t=9587 |
Страница 1 из 1 |
Автор: | Угрюмов Роман [ 18 авг 2014, 17:17 ] |
Заголовок сообщения: | Обработка пакета авторизации (РЕШЕНО) |
Господа! У нас используется схема авторизации с Opt82 с авторизацией по Id устройства:порт Для этого написан специальный скрипт, алгоритм работы которого кратко выглядит так: Код: public class SmartEdgeClipsProtocolHandler extends ru.bitel.bgbilling.modules.inet.dyn.device.redback.SmartEdgeClipsProtocolHandler implements RadiusProtocolHandler, DhcpProtocolHandler { protected void setAgentOptions( RadiusPacket request ) { 1) Вычислить из пакета Id устройства 2) Если устройства с таким Id нет, то создать его. 3) Вычислить из пакета порт 4) Если такого порта(интерфейса) на устройстве нет, то создать интерфейс 5) Найти договор с сервисом, у которого данный Id устройства:порт 6) Если такого договора нет, то создать договор и установить на нем сервис с Id устройства:порт } @Override public void preprocessDhcpRequest( DhcpPacket request, DhcpPacket response ) throws Exception { } } Все работает устройства порты и договора создаются автоматически при подключении каждого нового клиента Но! Иногда биллинг вызывает функцию setAgentOptions( RadiusPacket request ) без всякого пакета авторизации! Из логов я сегодня увидел, что произошло что-то Код: mq 08-18/14:09:31 INFO [event-proc-p-2-t-1] ContractRuntimeMap - Taked event: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusModifiedEvent] moduleId: 0; pluginId: no; cid: 90911; scid: -1; userId: 0; timestamp: 1408356571255 mq 08-18/14:09:31 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Caught event: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusModifiedEvent] moduleId: 0; pluginId: no; cid: 90911; scid: -1; userId: 0; timestamp: 1408356571255 mq 08-18/14:09:31 INFO [event-proc-p-2-t-1] ContractRuntimeMap - Taked event: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusModifiedEvent] moduleId: 0; pluginId: no; cid: 90911; scid: -1; userId: 0; timestamp: 1408356571255 connection 08-18/14:09:31 INFO [sa-p-14-t-15] ServiceActivatorSet - Connecting to device mq 08-18/14:09:31 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Caught event: Event[ru.bitel.bgbilling.modules.inet.api.server.event.InetServModifiedEvent] moduleId: 1; pluginId: no; cid: 90911; scid: -1; userId: -1; timestamp: 1408356571317 mq 08-18/14:09:31 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Adding new InetServRuntime: 204 connection 08-18/14:09:31 INFO [sa-p-14-t-15] ServiceActivatorDeviceWorker - Do task deviceId: 85; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaServModifyEvent] moduleId: 1; pluginId: no; cid: 90911; scid: -1; userId: -1; oldInetServ: null; newInetServ: 4:13090004; newInetServState: 1; newInetServOptionList: ; timestamp: 1408356571319 mq 08-18/14:09:31 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Loading inetServ from database. mq 08-18/14:09:31 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Adding InetServRuntime: 204 mq 08-18/14:09:31 INFO [event-proc-p-2-t-1] InetServRuntimeMap - ContractId: 90911; status: 0; servId: 204 4:13090004 Options [] TariffModuleTreeSet [10:18.08.2014-…; ] Device state: -1; optionSet: connection 08-18/14:09:31 INFO [sa-p-14-t-15] InetServRuntimeMap - Reload InetServRuntime: 204 connection 08-18/14:09:31 INFO [sa-p-14-t-15] InetServRuntimeMap - Removing InetServRuntime: 204 connection 08-18/14:09:31 INFO [sa-p-14-t-15] InetServRuntimeMap - Adding InetServRuntime: 204 connection 08-18/14:09:31 INFO [sa-p-14-t-15] InetServRuntimeMap - ContractId: 90911; status: 0; servId: 204 4:13090004 Options [] TariffModuleTreeSet [10:18.08.2014-…; ] Device state: -1; optionSet: connection 08-18/14:09:31 WARN [sa-p-14-t-15] InetApplication - Accounting period not found for inetServ:204 connection 08-18/14:09:31 INFO [sa-p-14-t-15] InetApplication - OptionSet: [] connection 08-18/14:09:31 INFO [sa-p-14-t-15] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=1; inetServId: 204; call: true; oldState: -1; newState: 1; oldOptionSet: ; newOptionSet: connection 08-18/14:09:31 INFO [sa-p-14-t-15] ServiceActivatorDeviceWorker - Processing deviceId:85; command ServiceActivatorEvent type=1; inetServId: 204; call: true; oldState: -1; newState: 1; oldOptionSet: ; newOptionSet: connection 08-18/14:09:31 INFO [sa-p-14-t-15] ServiceActivatorSet - Invoking serviceCreate connection 08-18/14:09:31 INFO [sa-p-14-t-15] ServiceActivatorDeviceWorker - Process event type[1] result=true connection 08-18/14:09:31 INFO [sa-p-14-t-15] ServiceActivatorDeviceWorker - Changing InetServ:204 state and/or options mq 08-18/14:09:31 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Caught event: Event[ru.bitel.bgbilling.modules.inet.access.event.InetServDeviceStateAndOptionsModifiedEvent] moduleId: 1; pluginId: no; cid: global; scid: -1; userId: -1; deviceId: 85; inetServId: 204; state: 1; optionSet: ; timestamp: 1408356571585 В результате чего у меня в 14:09:31 создалось устройство c id=13090004, порт = 4 и договор cid=90911 !!!! В устройстве GPON 13090004 в этот момент ни в один порт не было воткнуто ни одного кабеля!!! Последний раз в 4-порту был WiFi роутер где то в обед два дня назад (подправил 19:34 а то не понятно)! В логах BGInetAccess radius.log нет никаких сообщений о создании устройства, порта и договора в 14:09:31! Что происходит? Как добиться что бы не было "самопроизвольного запуска" setAgentOptions( RadiusPacket request ) ??? |
Автор: | stark [ 18 авг 2014, 17:31 ] |
Заголовок сообщения: | Re: Обработка пакета авторизации от ОТСУТСТВУЮЩЕГО устройств |
Если это наш SmartEdgeClipsProtocolHandler, то этом метод может вызываться если пришел radius access или accounting. Посмотрите логи radius не было ли запроса на авторизацию. Зачем столько восклицательных знаков? |
Автор: | Угрюмов Роман [ 18 авг 2014, 17:40 ] |
Заголовок сообщения: | Re: Обработка пакета авторизации от ОТСУТСТВУЮЩЕГО устройств |
stark писал(а): Если это наш SmartEdgeClipsProtocolHandler, то этом метод может вызываться если пришел radius access или accounting. Посмотрите логи radius не было ли запроса на авторизацию. Да это ваш SmartEdgeClipsProtocolHandler, в котором я переписал функции под свои задачи В radius.log Access - сервера пакетов на авторизацию нет: Код: 08-18/14:08:30 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Checking data log files to close [hours=1]... 08-18/14:16:30 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Checking data log files to close [hours=1]... 08-18/14:16:30 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/usr/local/BGInetAccess/data/radius/source_2/2014/2014-08/2014-08-18/log_2014-08-18-14.000.bgdl] В radius.log Accounting сервера тоже нет пакетов в 14:09:31 |
Автор: | Amir [ 18 авг 2014, 20:04 ] |
Заголовок сообщения: | Re: Обработка пакета авторизации от ОТСУТСТВУЮЩЕГО устройств |
Добавьте в ваш setAgentOption дополнительное логирование, чтобы потом grep'om можно было найти, когда и кем вызывался. Вроде бы еще предобработка preprocessAccountingRequest вызывается при переобработке RADIUS-логов. |
Автор: | Угрюмов Роман [ 18 авг 2014, 20:49 ] |
Заголовок сообщения: | Re: Обработка пакета авторизации от ОТСУТСТВУЮЩЕГО устройств |
Метод setAgentOptions у меня залогирован по самое небалуйся. Завтра в личку кину его текст. Когда метод вызывается по приходу пакета авторизации, то в логе Access сервера я вижу все свои отладочные сообщения, которые пишу в лог. В том то и весь прикол, что этот метод вызывается (скорее всего ИМХО) еще где-то, при этом записи в лог нет. Парадокс! Договор, устройство, порт создается корректно! Я вам и лог вышлю за 14:09:31. |
Автор: | Угрюмов Роман [ 19 авг 2014, 12:22 ] |
Заголовок сообщения: | Re: Обработка пакета авторизации от ОТСУТСТВУЮЩЕГО устройств |
У меня еще смутные подозрения. А может быть так, что Java-машина после редактирования и перекомпиляции кода в BGBilling и перезагрузки BGAccess берет код из кэша? То есть то что было до внесения изменений и компиляции? |
Автор: | Amir [ 19 авг 2014, 13:14 ] |
Заголовок сообщения: | Re: Обработка пакета авторизации от ОТСУТСТВУЮЩЕГО устройств |
Да, но не совсем так - ProtocolHandler и ServiceActivator используются старые пока не нажмете перечитать конфигурацию на серверах или не перезапустите Access/Accounting. |
Автор: | Угрюмов Роман [ 19 авг 2014, 14:33 ] |
Заголовок сообщения: | Re: Обработка пакета авторизации от ОТСУТСТВУЮЩЕГО устройств |
Amir! Биллинг вызывает дважды обработчик Код: protected void setAgentOptions( RadiusPacket request ) при приходе пакета авторизации!!!как я это вычислил. Я навтыкал в обработчик массу logger.info( "текст сообщения" ); и смотрю что происходит. В 11:33:53 пришел пакет авторизации, скрипт начал его обрабатывать. Алгоритм проверил, что есть устройство, но на данном устройстве нет порта, на котором клиент собирается авторизоваться. Алгоритм создает порт и устанавливает: Код: request.setOption( InetRadiusProcessor.AGENT_REMOTE_ID, deviceIdString); //Поиск агента по серийному номеру request.setOption( InetRadiusProcessor.INTERFACE_ID, devicePort ); //Поиск по порту Где Код: deviceIdString = "AUTOCREATE"; //Авторизуемся на специальном договоре с сервисом в статусе Отключено, что бы получить Reject и devicePort = 1; // заставить устройство еще раз выслать пакет авторизации В этот момент ветка алгоритма, где создается договор не отрабатывает. Через 2-3 секунды должен прийти снова запрос на авторизацию. Тогда устройство и порт будут уже существовать. Алгоритм создает договор и авторизует на нем клиента. Внимание!!! В 11:33:53 в логах MQ я вижу: Код: 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetDeviceRuntimeMap - (Re)loading InetDeviceRuntimeMap 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetDeviceRuntime - Reload protocolHandler class for device: RootType: Root 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetDeviceRuntime - Reload SA classes for device: RootType: Root 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetDeviceRuntime - Reload protocolHandler class for device: Redback: RedBack [172.16.98.7] 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetDeviceRuntime - Reload SA classes for device: Redback: RedBack [172.16.98.7] 08-19/11:33:53 WARN [event-proc-p-2-t-1] RadiusDictionary - Radius attribute Deactivate-Service-Name:1 not found in dictionary! .... 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetDeviceRuntime - Reload protocolHandler class for device: QTech GPON: 13090004 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetDeviceRuntime - Reload SA classes for device: QTech GPON: 13090004 08-19/11:33:53 WARN [event-proc-p-2-t-1] RadiusDictionary - Radius attribute Deactivate-Service-Name:1 not found in dictionary! .... 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetDeviceRuntimeMap - Load inetDeviceRuntimeMap complete. Loaded 27 inetDevices. 08-19/11:33:53 INFO [AccessReload-1] Access - childrenDeviceIds=[68, 1, 32, 2, 33, 38, 67, 76, 12, 75, 85, 17, 16, 84, 19, 18, 86, 20, 23, 22, 25, 24, 27, 29, 28, 31, 30] 08-19/11:33:53 INFO [AccessReload-1] InetConnectionManager - Loading connections from database. 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetDhcpDeviceMap - Load DHCP relay list, types: [2]. 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetDhcpDeviceMap - Loaded device: 2 08-19/11:33:53 INFO [pool-5-thread-1] InetDhcpDeviceMap - Bind device: 2; 172.16.98.7 08-19/11:33:53 INFO [event-proc-p-2-t-1] ContractRuntimeMap - Taked event: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusModifiedEvent] moduleId: 0; pluginId: no; cid: 90923; scid: -1; userId: 0; timestamp: 1408433633752 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Caught event: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusModifiedEvent] moduleId: 0; pluginId: no; cid: 90923; scid: -1; userId: 0; timestamp: 1408433633752 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Caught event: Event[ru.bitel.bgbilling.modules.inet.api.server.event.InetServModifiedEvent] moduleId: 1; pluginId: no; cid: 90923; scid: -1; userId: -1; timestamp: 1408433633804 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Adding new InetServRuntime: 216 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Loading inetServ from database. 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Adding InetServRuntime: 216 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetServRuntimeMap - ContractId: 90923; status: 0; servId: 216 1:13090004 Options [] TariffModuleTreeSet [10:19.08.2014-…; ] Device state: -1; optionSet: 08-19/11:33:54 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Caught event: Event[ru.bitel.bgbilling.modules.inet.access.event.InetServDeviceStateAndOptionsModifiedEvent] moduleId: 1; pluginId: no; cid: global; scid: -1; userId: -1; deviceId: 85; inetServId: 216; state: 1; optionSet: ; timestamp: 1408433634128 08-19/11:33:55 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Caught event: Event[ru.bitel.bgbilling.modules.inet.api.server.event.InetAccountingPeriodModifiedEvent] moduleId: 1; pluginId: no; cid: 90923; scid: -1; userId: 0; timestamp: 1408433635405 08-19/11:33:57 INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=45643-0, iface=2:50528256, sessId=0202FFFF78001818-53F2FD45, start=19.08.2014 11:33:57, uname=0006001fce109dc5:000e0064000701515445431309000401, addr=185.23.81.2] То есть в 11:33:53 совершенно логично вызвался обработчик для обработки пакета авторизации, в котором я создал порт. И каким то чудом, сразу же еще раз повторно вызвался обработчик setAgentOptions! Поскольку устройство и порт уже есть, то стала отрабатываться ветка создания договора на устройстве 13090004!!! Вот строчка 08-19/11:33:53 INFO [event-proc-p-2-t-1] InetServRuntimeMap - ContractId: 90923; status: 0; servId: 216 1:13090004 cid=90923 это как раз этот договор, servId=216 это сервис на этом договоре! Причем в логах Access radius.log нет никаких сообщений от этого повторного запуска!!! На первый запуск при приходе пакета есть записи лога, а при повторном нет. Но запуск есть!!! Договор создается! Это я к тому написал, что регулярно у меня появляются "фантомные договора" которые создаются в функции setAgentOptions, которая вызывается биллингов БЕЗ ПРИХОДА ПАКЕТА АВТОРИЗАЦИИ!!! я завтра уезжаю в отпуск на неделю. Буду на работе 28 августа. Готов заплатить из личных средств за разрешение данной проблемы (но что бы директор не знал ![]() |
Автор: | stark [ 19 авг 2014, 14:48 ] |
Заголовок сообщения: | Re: Обработка пакета авторизации от ОТСУТСТВУЮЩЕГО устройств |
там же эту функция вызывается не только на пакет авторизации, но и start-пакет например. Может быть в этом причина ? |
Автор: | Угрюмов Роман [ 19 авг 2014, 14:59 ] |
Заголовок сообщения: | Re: Обработка пакета авторизации от ОТСУТСТВУЮЩЕГО устройств |
stark писал(а): там же эту функция вызывается не только на пакет авторизации, но и start-пакет например. Может быть в этом причина ? Нашел!!! В 11:33:53 Пришел еще Accounting-пакет Код: radius 08-19/11:33:53 INFO [rdsLstnr-p-8-t-7] RadiusListenerWorker - REQUEST: Packet type: Accounting-Request Identifier: 91 Authenticator: {D7 2E 48 A7 7F D3 6F 68 F0 C8 44 AE FB 12 C0 A3} .... radius 08-19/11:33:53 INFO [rdsLstnr-p-8-t-7] SmartEdgeClipsProtocolHandler - AutoCreate routine started!!! radius 08-19/11:33:53 INFO [rdsLstnr-p-8-t-7] SmartEdgeClipsProtocolHandler - Set comment: АвтоСоздан 19.08.2014 11:33:53 radius 08-19/11:33:53 INFO [rdsLstnr-p-8-t-7] CommonKernelEventProcessor - Process event cid:0; event:Event[ru.bitel.bgbilling.kernel.event.events.system.ContractCreateEvent] moduleId: 0; pluginId: no; cid: 0; scid: -1; userId: 0; timestamp: 1408433633746 radius 08-19/11:33:53 INFO [rdsLstnr-p-8-t-7] CommonKernelEventProcessor - Process event cid:90923; event:Event[ru.bitel.bgbilling.kernel.event.events.system.ContractCreateEvent] moduleId: 0; pluginId: no; cid: 90923; scid: -1; userId: 0; timestamp: 1408433633784 radius 08-19/11:33:53 INFO [rdsLstnr-p-8-t-7] SmartEdgeClipsProtocolHandler - inetServUpdate! deviceId:85 cid: 90923 script 08-19/11:33:53 INFO [rdsLstnr-p-8-t-7] ScriptEventListener - Caught event: ru.bitel.bgbilling.modules.inet.api.server.event.InetServChangingEvent script 08-19/11:33:53 INFO [rdsLstnr-p-8-t-7] ScriptEventListener - Process time => 7 script 08-19/11:33:53 INFO [rdsLstnr-p-8-t-7] ScriptEventListener - ClipsLoginGenerator Start! deviceId = 85 inetServ.getTypeId() = 1 Setting userName:1:13090004 ... Вот тут я и создал договор! Теперь все начинает проясняться!!! Как отличить в обработчике, на какой пакет он был вызван? То есть как отличить пакет авторизации от Accounting -пакета? Это оно getCode() Получение типа пакета (например, ACCESS_REQUEST ACCOUNTING_REQUEST). ? |
Автор: | stark [ 19 авг 2014, 15:14 ] |
Заголовок сообщения: | Re: Обработка пакета авторизации от ОТСУТСТВУЮЩЕГО устройств |
Угрюмов Роман писал(а): Вот тут я и создал договор! Теперь все начинает проясняться!!! Как отличить в обработчике, на какой пакет он был вызван? То есть как отличить пакет авторизации от Accounting -пакета? Это оно getCode() Получение типа пакета (например, ACCESS_REQUEST ACCOUNTING_REQUEST). ? Да. Код: if ( packet.getCode() == RadiusPacket.ACCESS_REQUEST ) )
{ .. } |
Автор: | Угрюмов Роман [ 19 авг 2014, 15:58 ] |
Заголовок сообщения: | Re: Обработка пакета авторизации от ОТСУТСТВУЮЩЕГО устройств |
Это была эпопея... Нет слов выразить благодарность за помощь в отлавливании глюка. Мой скрипт реагировал на Accounting пакеты. Теперь все вроде должно работать. (тьфу тьфу тьфу) |
Страница 1 из 1 | Часовой пояс: UTC + 5 часов [ Летнее время ] |
Powered by phpBB® Forum Software © phpBB Group http://www.phpbb.com/ |