В последнее время начала проявляться проблема с отключением активных сессий абонентов при закрытии договора по балансу.
Например, 14 апреля абонент поднял сессию и благополучно работал. 22 апреля у абонента закончились средства. В час ночи договор был заблокирован задачей по недостаточному балансу. После этого сервис перешёл в состояние "Отключен". Всё бы хорошо, но вот уже 2 часа дня, а сессия абонента всё висит в состоянии "Подключено" и статусе "Активна" и не думает переключаться в состояние "Отключено".
У нас настроен Cisco ISG с посервисным аккаунтингом, при отключении сервиса у сессии обычно отключаются сервисы INTERNET и LOCAL и включается REDIRECT, после чего сессия переходит в состояние "Отключено". Но в данном случае этого не происходит.
Начали разбираться и выяснили, что при закрытии договора вызывается connectionModify, который отправляет на Cisco следующие CoA-запросы:
Код:
connection 04-22/01:12:37 INFO [sa-p-11-t-38] ISGServiceActivator - Send deactivate service CoA:
Packet type: CoA-Request
Identifier: 241
Authenticator: {42 89 0E 27 D6 56 D7 28 1B 00 BD B7 02 0F 9E BA}
Attributes:
User-Name=XXX
Acct-Session-Id=0/1/0/2281.1263_03764390
cisco-avpair=subscriber:service-name=LOCAL_SIMPLE
cisco-avpair=subscriber:command=deactivate-service
connection 04-22/01:12:37 INFO [sa-p-11-t-38] ISGServiceActivator - Send deactivate service CoA:
Packet type: CoA-Request
Identifier: 242
Authenticator: {F0 BB 8F 2C DF E7 9A 2D A2 9D E7 62 80 A9 EF 6A}
Attributes:
User-Name=XXX
Acct-Session-Id=0/1/0/2281.1263_03764390
cisco-avpair=subscriber:service-name=INTERNET_30mbps
cisco-avpair=subscriber:command=deactivate-service
connection 04-22/01:12:37 INFO [sa-p-11-t-38] ISGServiceActivator - Send activate service CoA:
Packet type: CoA-Request
Identifier: 243
Authenticator: {E6 22 40 49 35 C4 D5 EC 73 DB 9C A0 25 99 3C 07}
Attributes:
User-Name=XXX
Acct-Session-Id=0/1/0/2281.1263_03764390
cisco-avpair=subscriber:service-name=REDIRECT_SIMPLE
cisco-avpair=subscriber:command=activate-service
Но ответа на эти запросы никакого нет, лишь через некоторое время появляется следующее:
Код:
connection 04-22/01:12:42 INFO [sa-p-11-t-38] EventWorker - Timeout waiting futures
connection 04-22/01:12:42 ERROR [sa-p-11-t-38] AcknowledgeConsumer - java.util.concurrent.TimeoutException
ru.bitel.bgbilling.common.BGException: java.util.concurrent.TimeoutException
at ru.bitel.bgbilling.kernel.event.AsyncEventWorker.notify(AsyncEventWorker.java:181)
at ru.bitel.bgbilling.kernel.event.AcknowledgeConsumer.onMessage0(AcknowledgeConsumer.java:75)
at ru.bitel.bgbilling.kernel.event.EventWorker.internalDoTask(EventWorker.java:177)
at ru.bitel.bgbilling.kernel.event.AsyncEventWorker.doTasks(AsyncEventWorker.java:75)
at ru.bitel.bgbilling.modules.inet.access.sa.ServiceActivatorDeviceWorker.runWorker(ServiceActivatorDeviceWorker.java:179)
at ru.bitel.bgbilling.kernel.event.EventWorker.internalRunWorker(EventWorker.java:113)
at ru.bitel.bgbilling.modules.inet.access.sa.ServiceActivatorDeviceWorker.runImpl(ServiceActivatorDeviceWorker.java:117)
at ru.bitel.common.worker.WorkerTask.run(WorkerTask.java:86)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:40)
Caused by: java.util.concurrent.TimeoutException
... 18 more
Правда я на 100% не уверен, что это таймаут именно по нужным запросам.
В дебаге на Cisco видно, что запросы приходят, но из подозрительного там только:
Код:
COA: Message Authenticator missing or failed decode
В итоге запросы ушли, на Cisco пришли, но сервисы на Cisco при этом остались и никакого ответа на запросы нет. Очень странная ситуация, особенно если учесть, что большая часть запросов обрабатывается нормально.
Для решения пробовали добавить в запрос Message-Authenticator следующим образом:
Код:
sa.radius.coa.attributes=Message-Authenticator=0x00
Аутентификатор в запрос добавился, но имел неправильную длину и вообще, после такого его добавления радиус пакет очень печально выглядел. Другого способа добавить аутентификатор я не нашёл, да и не уверен, что в нём проблема.
Дальше пробовал отключить сессию, отправляя событие:
Код:
ep.publish(new InetSaStateModifyEvent(moduleId, contractId, userId, deviceId, servId, connectionId, (short) 0, 44));
но ситуация повторилась и сессия не отключилась. В итоге, сессию можно отключить лишь разорвав её.
Проблема вроде как и не связана с биллингом напрямую, но спросить больше негде. Есть ли у кого идеи, с чем всё это может быть связано и куда копать?