Сейчас обнаружил, что при попытке авторизации при отключенном сервисе, биллинг повторно пытается отключить уже отключенные сервисы на циске. Поясню более подробно по шагам.
1. Активных сессий нет, сервис в биллинге отключен (вручную, например).
2. Пытаемся авторизоваться и видим в логах:
Код:
...
radius 08-13/17:56:59 INFO [rdsLstnr-p-8-t-8] InetNas - Search by username=VK-001/12
radius 08-13/17:56:59 INFO [rdsLstnr-p-8-t-8] InetRadiusProcessor - [username=VK-001/12] Authenticated as inetServId:1
radius 08-13/17:56:59 INFO [rdsLstnr-p-8-t-8] InetApplication - inetServ[id=1] deviceState not active (accessCode=44).
radius 08-13/17:56:59 INFO [rdsLstnr-p-8-t-8] InetRadiusProcessor - Return code=0
radius 08-13/17:56:59 INFO [rdsLstnr-p-8-t-8] InetRadiusProcessor - RESPONSE_BEFORE_POSTPROCESS:
Packet type: Access-Accept
Identifier: 118
Authenticator: {}
Attributes:
Reply-Message=44
cisco-SSG-Account-Info=APORTAL
cisco-SSG-Account-Info=AREDIRECT
...
Видно, что сервис выключен (deviceState not active), но, согласно настройкам, выдаётся Access-Accept с фейковыми сервисами.
3. Дальше циска запрашивает описание сервисов у радиуса и благополучно их получает. Смысла сюда выкладывать нет.
4. Теперь начинается аккаунтинг всех сессий, а сами сессии записываются в базу. Для примера в логах я оставил начало аккаунтинга только одной сессии.
Код:
connection 08-13/17:56:59 INFO [sa-p-10-t-2] ServiceActivatorSet - Connecting to device
connection 08-13/17:56:59 INFO [sa-p-10-t-2] ServiceActivatorDeviceWorker - Do task deviceId: 2; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 8; pluginId: no; cid: 4; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 120; timestamp: 1344866219558
connection 08-13/17:56:59 INFO [sa-p-10-t-2] InetApplication - TariffOptionMap: {}
connection 08-13/17:56:59 INFO [sa-p-10-t-2] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 1; call: true; oldState: 0; newState: 0; oldOptionSet: 4,9; newOptionSet: 4,9
connection 08-13/17:56:59 INFO [sa-p-10-t-2] ServiceActivatorDeviceWorker - Processing deviceId:2; command ServiceActivatorEvent type=4; inetServId: 1; call: true; oldState: 0; newState: 0; oldOptionSet: 4,9; newOptionSet: 4,9
connection 08-13/17:56:59 INFO [sa-p-10-t-2] ServiceActivatorSet - Invoking onAccountingStart
connection 08-13/17:56:59 INFO [sa-p-10-t-2] ServiceActivatorDeviceWorker - Process event type[4] result=true
mq 08-13/17:56:59 INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=118-0, iface=2:44962, sessId=5D5885820000AFA2, start=13.08.2012 17:56:59, uname=VK-001/12, addr=[IpAddress:null]]
mq 08-13/17:56:59 INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=119-118, iface=2:44962, sessId=5D5885820000AFA3, start=13.08.2012 17:56:59, uname=REDIRECT, addr=[IpAddress:null]]
mq 08-13/17:56:59 INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=120-118, iface=2:44962, sessId=5D5885820000AFA4, start=13.08.2012 17:56:59, uname=PORTAL, addr=[IpAddress:null]]
connection 08-13/17:57:04 INFO [sa-p-10-t-2] ServiceActivatorSet - Disconnecting from device
Видно, что сессии нормально создались и пошёл аккаунтинг. Также видно, что сервис по-прежнему отключен (oldState: 0; newState: 0;).
5. Теперь начинается интересное.
Код:
connection 08-13/17:57:11 INFO [sa-p-10-t-2] ServiceActivatorSet - Connecting to device
connection 08-13/17:57:11 INFO [sa-p-10-t-2] ServiceActivatorDeviceWorker - Do task deviceId: 2; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateModifyEvent] moduleId: 8; pluginId: no; cid: 4; scid: -1; userId: 0; deviceId: 2; inetServId: 1; connectionId: 118; state: 0; accessCode: 44; timestamp: 1344866231859
connection 08-13/17:57:11 INFO [sa-p-10-t-2] InetApplication - TariffOptionMap: {}
connection 08-13/17:57:11 INFO [sa-p-10-t-2] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=2; inetServId: 1; call: true; oldState: 1; newState: 0; oldOptionSet: 4,9; newOptionSet: 4,9
connection 08-13/17:57:11 INFO [sa-p-10-t-2] ServiceActivatorDeviceWorker - Processing deviceId:2; command ServiceActivatorEvent type=2; inetServId: 1; call: true; oldState: 1; newState: 0; oldOptionSet: 4,9; newOptionSet: 4,9
connection 08-13/17:57:11 INFO [sa-p-10-t-2] ServiceActivatorSet - Invoking connectionModify
connection 08-13/17:57:11 INFO [sa-p-10-t-2] ISGServiceActivator - Connection modify: oldState: 1; newState: 0; oldOptionSet: [4, 9]; newOptionSet: [4, 9]
connection 08-13/17:57:11 INFO [sa-p-10-t-2] ISGServiceActivator - Connection close!
connection 08-13/17:57:11 INFO [sa-p-10-t-2] ISGPPPoEServiceActivator - Send deactivate service CoA:
Биллинг таинственным для меня образом начинает считать, что сервис выключился только что (oldState: 1; newState: 0;), и пытается отключить якобы активные сервисы договора и включить disabled-сервисы из параметра sa.radius.service.disable.
6. Дальше всё банально: посылаются CoA пакеты на отключение сервисов INTERNET_3mbps и LOCAL, которые и так отсутствуют на циске, на подключение сервисов PORTAL и REDIRECT, которые и так уже есть на циске.
7. Дальше всё работает как и должно.
Из вышесказанного следует вопрос: почему статус сервиса (oldState) изменился с 0 на 1?