BiTel

Странное поведение активатора. Скорость на тарифах реализована через опции модуля inet. При создании нового договора, выборе тарифа и добавлении сервиса, сервис создается без учёта опции на тарифе и через активатор передается дефолтное значение в 100мбит. В логах видно, что опция не проставляется.

07-10/10:05:24 INFO [sa-p-12-t-15] ServiceActivatorDeviceWorker - Do task deviceId: 62; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaServModifyEvent] moduleId: 1; pluginId: no; cid: 25; scid: -1; userId: -1; oldInetServ: null; newInetServ: 10.0.0.23; newInetServState: 1; newInetServOptionList: ; timestamp: 1436511924448
07-10/10:05:24 WARN [sa-p-12-t-15] InetApplication - Accounting period not found for inetServ:57
07-10/10:05:24 INFO [sa-p-12-t-15] InetApplication - OptionSet: []
07-10/10:05:24 INFO [sa-p-12-t-15] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=1; inetServId: 57; call: false; oldState: -1; newState: 1; oldOptionSet: ; newOptionSet:
07-10/10:05:24 INFO [sa-p-12-t-15] ServiceActivatorDeviceWorker - Processing deviceId:62; command ServiceActivatorEvent type=1; inetServId: 57; call: false; oldState: -1; newState: 1; oldOptionSet: ; newOptionSet:

При этом, если выключить и включить сервис, то опция выставлется нормально:

Выключение:
Id: 1; pluginId: no; cid: 25; scid: -1; userId: 0; type: 1; deviceId: 62; connectionId: 2941; timestamp: 1436512004978
07-10/10:06:45 INFO [sa-p-12-t-84] InetApplication - TariffOptionMap: {}
07-10/10:06:45 INFO [sa-p-12-t-84] InetApplication - OptionSet: [2]
07-10/10:06:45 INFO [sa-p-12-t-84] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 57; call: false; oldState: 1; newState: 1; oldOptionSet: 2; newOptionSet: 2
07-10/10:06:45 INFO [sa-p-12-t-84] ServiceActivatorDeviceWorker - Processing deviceId:62; command ServiceActivatorEvent type=4; inetServId: 57; call: false; oldState: 1; newState: 1; oldOptionSet: 2; newOptionSet: 2
Включение:
07-10/10:07:04 INFO [sa-p-12-t-44] ServiceActivatorDeviceWorker - Do task deviceId: 62; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaOptionsModifyEvent] moduleId: 1; pluginId: no; cid: 25; scid: -1; userId: 0; deviceId: 62; inetServId: 57; connectionId: 0; options: 2; timestamp: 1436512024089
07-10/10:07:04 INFO [sa-p-12-t-44] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=2; inetServId: 57; call: false; oldState: 1; newState: 1; oldOptionSet: ; newOptionSet: 2
07-10/10:07:04 INFO [sa-p-12-t-44] ServiceActivatorDeviceWorker - Processing deviceId:62; command ServiceActivatorEvent type=2; inetServId: 57; call: false; oldState: 1; newState: 1; oldOptionSet: ; newOptionSet: 2
07-10/10:07:04 INFO [sa-p-12-t-44] ServiceActivatorSet - Invoking serviceModify


Далее с договором можно делать всё что угодно. Добавлять и удалять тарифы. Сносить и добавлять сервисы. Опция всегда нормально передаётся, т.е. проблема присутсвтует только на договорах, на которых никогда ни 1 сервис не добавлялся. С чем это может быть связано?

_________________
Сервер: вер. 7.0.1409 / 03.09.2018 20:20:58
os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_45

Как создается договор/сервис - через клиент биллинг или скриптом?

И договор и сервис создаются через клиент.

_________________
Сервер: вер. 7.0.1409 / 03.09.2018 20:20:58
os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_45

А что выше этой строчки - можно посмотреть?

Да не особо. Заново повторил действия.

07-10/13:31:54 INFO [sa-p-12-t-68] ServiceActivatorSet - Connecting to device
07-10/13:31:54 INFO [sa-p-12-t-68] ServiceActivatorSet - Skip device:10 with disabled ServiceActivator
07-10/13:31:54 INFO [sa-p-12-t-68] ServiceActivatorDeviceWorker - Do task deviceId: 62; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaServModifyEvent] moduleId: 1; pluginId: no; cid: 24; scid: -1; userId: -1; oldInetServ: null; newInetServ: 10.0.0.30; newInetServState: 1; newInetServOptionList: ; timestamp: 1436524313771
07-10/13:31:54 WARN [sa-p-12-t-68] InetApplication - Accounting period not found for inetServ:54
07-10/13:31:54 INFO [sa-p-12-t-68] InetApplication - OptionSet: []
07-10/13:31:54 INFO [sa-p-12-t-68] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=1; inetServId: 54; call: false; oldState: -1; newState: 1; oldOptionSet: ; newOptionSet:
07-10/13:31:54 INFO [sa-p-12-t-68] ServiceActivatorDeviceWorker - Processing deviceId:62; command ServiceActivatorEvent type=1; inetServId: 54; call: false; oldState: -1; newState: 1; oldOptionSet: ; newOptionSet:
07-10/13:31:54 INFO [sa-p-12-t-68] ServiceActivatorSet - Invoking serviceCreate
07-10/13:31:54 INFO [sa-p-12-t-68] TelnetServiceActivator - Connected
07-10/13:31:54 INFO [sa-p-12-t-68] TelnetServiceActivator - Password:
07-10/13:31:54 INFO [sa-p-12-t-68] TelnetServiceActivator - Login entered
07-10/13:31:54 INFO [sa-p-12-t-68] TelnetServiceActivator -



А вот дальше, после того как он выполнил все действия, ещё в лог добавляется

07-10/13:32:16 INFO [sa-p-12-t-68] ServiceActivatorDeviceWorker - Process event type[1] result=true
07-10/13:32:16 INFO [sa-p-12-t-68] ServiceActivatorDeviceWorker - Changing InetServ:54 state and/or options
07-10/13:32:16 INFO [sa-p-12-t-68] ServiceActivatorDeviceWorker - Do task deviceId: 62; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 24; scid: -1; userId: 0; type: 1; deviceId: 62; connectionId: 2947; timestamp: 1436524331332
07-10/13:32:16 INFO [sa-p-12-t-68] InetApplication - TariffOptionMap: {}
07-10/13:32:16 INFO [sa-p-12-t-68] InetApplication - OptionSet: [2]
07-10/13:32:16 INFO [sa-p-12-t-68] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 54; call: false; oldState: 1; newState: 1; oldOptionSet: 2; newOptionSet: 2
07-10/13:32:16 INFO [sa-p-12-t-68] ServiceActivatorDeviceWorker - Processing deviceId:62; command ServiceActivatorEvent type=4; inetServId: 54; call: false; oldState: 1; newState: 1; oldOptionSet: 2; newOptionSet: 2
07-10/13:32:16 INFO [sa-p-12-t-68] ServiceActivatorSet - Invoking onAccountingStart
07-10/13:32:16 INFO [sa-p-12-t-68] ServiceActivatorDeviceWorker - Process event type[4] result=true
07-10/13:32:21 INFO [sa-p-12-t-68] ServiceActivatorSet - Disconnecting from device
07-10/13:32:21 INFO [sa-p-12-t-68] TelnetServiceActivator - executeAsync: quit
07-10/13:32:21 INFO [sa-p-12-t-68] TelnetServiceActivator - executeAsync: logout
07-10/13:32:21 INFO [sa-p-12-t-68] TelnetServiceActivator - executeAsync: logout
07-10/13:32:22 INFO [sa-p-12-t-17] ServiceActivatorSet - Connecting to device
07-10/13:32:22 INFO [sa-p-12-t-17] ServiceActivatorSet - Skip device:10 with disabled ServiceActivator
07-10/13:32:22 INFO [sa-p-12-t-17] ServiceActivatorDeviceWorker - Do task deviceId: 62; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaOptionsModifyEvent] moduleId: 1; pluginId: no; cid: 24; scid: -1; userId: 0; deviceId: 62; inetServId: 54; connectionId: 0; options: 2; timestamp: 1436524342551
07-10/13:32:22 INFO [sa-p-12-t-17] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=2; inetServId: 54; call: false; oldState: 1; newState: 1; oldOptionSet: ; newOptionSet: 2
07-10/13:32:22 INFO [sa-p-12-t-17] ServiceActivatorDeviceWorker - Processing deviceId:62; command ServiceActivatorEvent type=2; inetServId: 54; call: false; oldState: 1; newState: 1; oldOptionSet: ; newOptionSet: 2
07-10/13:32:22 INFO [sa-p-12-t-17] ServiceActivatorSet - Invoking serviceModify
07-10/13:32:22 INFO [sa-p-12-t-17] ServiceActivatorDeviceWorker - Process event type[2] result=true
07-10/13:32:22 INFO [sa-p-12-t-17] ServiceActivatorDeviceWorker - Changing InetServ:54 state and/or options
07-10/13:32:27 INFO [sa-p-12-t-17] ServiceActivatorSet - Disconnecting from device

При этом ничего

_________________
Сервер: вер. 7.0.1409 / 03.09.2018 20:20:58
os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_45

До
07-10/13:31:54 INFO [sa-p-12-t-68] ServiceActivatorSet - Connecting to device
тоже должно быть что-то в этом потоке ([sa-p-12-t-68]) - сначала он событие получает, его обрабатывает, только потом подключается к устройству.

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

07-10/13:29:42 INFO [main] DefaultServerSetup - Binding javax.jms.ConnectionFactory[org.apache.activemq.ActiveMQConnectionFactory@57ad2aa7] to java:comp/env/mq/connectionFactory
07-10/13:29:42 INFO [main] DefaultServerSetup - Init DB connection pools
07-10/13:29:42 INFO [main] DefaultServerSetup - Binding JDBC pool "master" to java:comp/env/jdbc/master
07-10/13:29:43 INFO [main] AnnotatedMBean - Register MBean ru.bitel.bgbilling.server.util:type=DatabaseConnectionPool,name=master
07-10/13:29:43 INFO [main] DefaultServerSetup - Init trash pools...
07-10/13:29:53 INFO [sa-p-12-t-37] ServiceActivatorSet - Connecting to device
07-10/13:29:53 INFO [sa-p-12-t-37] ServiceActivatorSet - Skip device:10 with disabled ServiceActivator
07-10/13:29:53 INFO [sa-p-12-t-37] ServiceActivatorDeviceWorker - Do task deviceId: 62; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaServModifyEvent] moduleId: 1; pluginId: no; cid: 26; scid: -1; userId: -1; oldInetServ: 10.0.0.26; newInetServ: null; newInetServState: -1; newInetServOptionList: ; timestamp: 1436524070136
07-10/13:29:53 INFO [sa-p-12-t-37] InetServRuntimeMap - Loading inetServ from database.
07-10/13:29:53 WARN [sa-p-12-t-37] ContractRuntimeMap - Contract id=26 not found
07-10/13:29:53 ERROR [sa-p-12-t-37] InetServRuntimeMap - Contract not found with id=26 but inetServ exist
07-10/13:29:53 ERROR [sa-p-12-t-37] ServiceActivatorDeviceWorker - Device:62 - null
java.lang.NullPointerException
at ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaServModifyEvent.toSaEvent(InetSaServModifyEvent.java:248)
at ru.bitel.bgbilling.modules.inet.access.sa.ServiceActivatorDeviceWorker.doTask(ServiceActivatorDeviceWorker.java:355)
at ru.bitel.bgbilling.kernel.event.AsyncEventWorker.internalDoTaskImpl(AsyncEventWorker.java:211)
at ru.bitel.bgbilling.kernel.event.AsyncEventWorker.notify(AsyncEventWorker.java:201)
at ru.bitel.bgbilling.kernel.event.AcknowledgeConsumer.onMessage0(AcknowledgeConsumer.java:83)
at ru.bitel.bgbilling.kernel.event.AsyncEventWorker.internalDoTask(AsyncEventWorker.java:176)
at ru.bitel.bgbilling.kernel.event.AsyncEventWorker.doTasks(AsyncEventWorker.java:109)
at ru.bitel.bgbilling.modules.inet.access.sa.ServiceActivatorDeviceWorker.runWorker(ServiceActivatorDeviceWorker.java:245)
at ru.bitel.bgbilling.kernel.event.EventWorker.internalRunWorker(EventWorker.java:139)
at ru.bitel.bgbilling.modules.inet.access.sa.ServiceActivatorDeviceWorker.runImpl(ServiceActivatorDeviceWorker.java:151)
at ru.bitel.common.worker.WorkerTask.run(WorkerTask.java:86)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:46)
07-10/13:29:58 INFO [sa-p-12-t-37] ServiceActivatorSet - Disconnecting from device
root@billing:/usr/local/BGInetAccess/log# tail -f connection.log
at ru.bitel.common.worker.WorkerTask.run(WorkerTask.java:86)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:46)
07-10/13:29:58 INFO [sa-p-12-t-37] ServiceActivatorSet - Disconnecting from device
07-10/13:31:54 INFO [sa-p-12-t-68] ServiceActivatorSet - Connecting to device
07-10/13:31:54 INFO [sa-p-12-t-68] ServiceActivatorSet - Skip device:10 with disabled ServiceActivator
07-10/13:31:54 INFO [sa-p-12-t-68] ServiceActivatorDeviceWorker - Do task deviceId: 62; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaServModifyEvent] moduleId: 1; pluginId: no; cid: 24; scid: -1; userId: -1; oldInetServ: null; newInetServ: 10.0.0.30; newInetServState: 1; newInetServOptionList: ; timestamp: 1436524313771
07-10/13:31:54 WARN [sa-p-12-t-68] InetApplication - Accounting period not found for inetServ:54

_________________
Сервер: вер. 7.0.1409 / 03.09.2018 20:20:58
os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_45

Наверное это не all.log. Если так - посмотрите что в нем, там больше должно быть.

ох. Я по connection.log просто проверял что он делает на железках... Вот all.log Пришлось заново создавать договор, т.к. лог уже стёрся


mq 07-10/15:45:28 INFO [event-proc-p-2-t-1] ContractRuntimeMap - Taked event: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusModifiedEvent] moduleId: 0; pluginId: no; cid: 25; scid: -1; userId: 0; timestamp: 1436532328014
mq 07-10/15:45:28 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Caught event: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusModifiedEvent] moduleId: 0; pluginId: no; cid: 25; scid: -1; userId: 0; timestamp: 1436532328014
mq 07-10/15:45:39 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Caught event: Event[ru.bitel.bgbilling.kernel.tariff.server.event.ContractTariffChangedEvent] moduleId: 0; pluginId: no; cid: 25; scid: -1; userId: 0; timestamp: 1436532339419
radius 07-10/15:45:48 INFO [hrlydtlggr-p-6-t-1] HourlyDataLoggerTracker - Checking data log files to close [hours=0]...
dhcp 07-10/15:45:48 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Checking data log files to close [hours=0]...
mq 07-10/15:46:18 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: 25; scid: -1; userId: 1; timestamp: 1436532378039
mq 07-10/15:46:18 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Adding new InetServRuntime: 55
mq 07-10/15:46:18 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Loading inetServ from database.
mq 07-10/15:46:18 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Adding InetServRuntime: 55
mq 07-10/15:46:18 INFO [event-proc-p-2-t-1] InetServRuntimeMap - ContractId: 25; status: 0; servId: 55
10.0.0.15
Options [] TariffModuleTreeSet [2:10.07.2015-?; ]
Device state: -1; optionSet:
connection 07-10/15:46:18 INFO [sa-p-12-t-91] ServiceActivatorSet - Connecting to device
connection 07-10/15:46:18 INFO [sa-p-12-t-91] ServiceActivatorSet - Skip device:10 with disabled ServiceActivator
connection 07-10/15:46:18 INFO [sa-p-12-t-91] ServiceActivatorDeviceWorker - Do task deviceId: 62; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaServModifyEvent] moduleId: 1; pluginId: no; cid: 25; scid: -1; userId: -1; oldInetServ: null; newInetServ: 10.0.0.15; newInetServState: 1; newInetServOptionList: ; timestamp: 1436532378050
connection 07-10/15:46:18 WARN [sa-p-12-t-91] InetApplication - Accounting period not found for inetServ:55
connection 07-10/15:46:18 INFO [sa-p-12-t-91] InetApplication - OptionSet: []
connection 07-10/15:46:18 INFO [sa-p-12-t-91] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=1; inetServId: 55; call: false; oldState: -1; newState: 1; oldOptionSet: ; newOptionSet:
connection 07-10/15:46:18 INFO [sa-p-12-t-91] ServiceActivatorDeviceWorker - Processing deviceId:62; command ServiceActivatorEvent type=1; inetServId: 55; call: false; oldState: -1; newState: 1; oldOptionSet: ; newOptionSet:
connection 07-10/15:46:18 INFO [sa-p-12-t-91] ServiceActivatorSet - Invoking serviceCreate

_________________
Сервер: вер. 7.0.1409 / 03.09.2018 20:20:58
os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_45

up

_________________
Сервер: вер. 7.0.1409 / 03.09.2018 20:20:58
os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_45

На одном из сервисов простая отладка не работает и приходится переводить договор в статус "отключен", а потом снова в "активен".

_________________
Сервер: вер. 7.0.1409 / 03.09.2018 20:20:58
os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_45

Там похоже еще учетного периода нет, потому без опций. Надо нам подумать, как это лучше исправить.

Возможно в Вашем случае подойдет добавление обработчика сервисов без сессий с активацией учетного периода
http://docs.bitel.ru/pages/viewpage.act ... Id=1606476 (в самом низу)
Т.е. создастся без опций, но должен достаточно быстро переключиться на правильную скорость.

Спасибо. Думаю, подождём исправления.

_________________
Сервер: вер. 7.0.1409 / 03.09.2018 20:20:58
os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_45

А у вас учетные периоды не используются?

А они автоматически создаются, после создания сервиса

_________________
Сервер: вер. 7.0.1409 / 03.09.2018 20:20:58
os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_45

_________________
Сервер: вер. 7.0.1409 / 03.09.2018 20:20:58
os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_45