Вот логи того момента когда биллинг сначала пускает ISG сессию, а затем ее срубает:
Код:
Packet type: Access-Accept
Identifier: 134
Authenticator: {3C 5C 30 2F D9 E0 37 75 78 C1 52 66 3A E3 0F 15}
Attributes:
Acct-Interim-Interval=120
Framed-IP-Address=109.XXX.56.1
Idle-Timeout=900
cisco-avpair=subscriber:accounting-list=ipoe-isg-aaa
cisco-SSG-Account-Info=AISG-8MBPS
cisco-SSG-Account-Info=AISG-LOCAL-RES
cisco-SSG-Account-Info=AISG-8MBPS-BONUS
cisco-SSG-Account-Info=AISG-SPEEDTEST
Process time auth: 71
mq 10-08/19:40:46 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29134; timestamp: 1412779246679
mq 10-08/19:40:46 INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=29134-0, iface=2:81854040, sessId=0/0/2/1001_04E0FE58, start=08.10.2014 19:40:46, uname=109.XXX.56.1, addr=109.XXX.56.1]
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorSet - Connecting to device
connection 10-08/19:40:46 DEBUG [sa-p-12-t-96] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29134; timestamp: 1412779246679
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Do task deviceId: 2; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29134; timestamp: 1412779246679
connection 10-08/19:40:46 INFO [sa-p-12-t-96] InetApplication - TariffOptionMap: {}
connection 10-08/19:40:46 INFO [sa-p-12-t-96] InetApplication - OptionSet: [3, 4, 7, 8]
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 72; call: true; oldState: 1; newState: 1; oldOptionSet: 3,4,7,8; newOptionSet: 3,4,7,8
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Processing deviceId:2; command ServiceActivatorEvent type=4; inetServId: 72; call: true; oldState: 1; newState: 1; oldOptionSet: 3,4,7,8; newOptionSet: 3,4,7,8
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorSet - Invoking onAccountingStart
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Process event type[4] result=true
connection 10-08/19:40:46 DEBUG [sa-p-12-t-96] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29135; timestamp: 1412779246734
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Do task deviceId: 2; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29135; timestamp: 1412779246734
connection 10-08/19:40:46 INFO [sa-p-12-t-96] InetApplication - TariffOptionMap: {}
connection 10-08/19:40:46 INFO [sa-p-12-t-96] InetApplication - OptionSet: [3, 4, 7, 8]
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 72; call: true; oldState: 0; newState: 0; oldOptionSet: 3,4,7,8; newOptionSet: 3,4,7,8
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Processing deviceId:2; command ServiceActivatorEvent type=4; inetServId: 72; call: true; oldState: 0; newState: 0; oldOptionSet: 3,4,7,8; newOptionSet: 3,4,7,8
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorSet - Invoking onAccountingStart
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Process event type[4] result=true
connection 10-08/19:40:46 DEBUG [sa-p-12-t-96] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29136; timestamp: 1412779246778
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Do task deviceId: 2; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29136; timestamp: 1412779246778
connection 10-08/19:40:46 INFO [sa-p-12-t-96] InetApplication - TariffOptionMap: {}
connection 10-08/19:40:46 INFO [sa-p-12-t-96] InetApplication - OptionSet: [3, 4, 7, 8]
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 72; call: true; oldState: 0; newState: 0; oldOptionSet: 3,4,7,8; newOptionSet: 3,4,7,8
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Processing deviceId:2; command ServiceActivatorEvent type=4; inetServId: 72; call: true; oldState: 0; newState: 0; oldOptionSet: 3,4,7,8; newOptionSet: 3,4,7,8
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorSet - Invoking onAccountingStart
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Process event type[4] result=true
connection 10-08/19:40:46 DEBUG [sa-p-12-t-96] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29137; timestamp: 1412779246786
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Do task deviceId: 2; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29137; timestamp: 1412779246786
connection 10-08/19:40:46 INFO [sa-p-12-t-96] InetApplication - TariffOptionMap: {}
connection 10-08/19:40:46 INFO [sa-p-12-t-96] InetApplication - OptionSet: [3, 4, 7, 8]
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 72; call: true; oldState: 0; newState: 0; oldOptionSet: 3,4,7,8; newOptionSet: 3,4,7,8
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Processing deviceId:2; command ServiceActivatorEvent type=4; inetServId: 72; call: true; oldState: 0; newState: 0; oldOptionSet: 3,4,7,8; newOptionSet: 3,4,7,8
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorSet - Invoking onAccountingStart
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Process event type[4] result=true
connection 10-08/19:40:46 DEBUG [sa-p-12-t-96] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29138; timestamp: 1412779246823
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Do task deviceId: 2; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29138; timestamp: 1412779246823
connection 10-08/19:40:46 INFO [sa-p-12-t-96] InetApplication - TariffOptionMap: {}
connection 10-08/19:40:46 INFO [sa-p-12-t-96] InetApplication - OptionSet: [3, 4, 7, 8]
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 72; call: true; oldState: 0; newState: 0; oldOptionSet: 3,4,7,8; newOptionSet: 3,4,7,8
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Processing deviceId:2; command ServiceActivatorEvent type=4; inetServId: 72; call: true; oldState: 0; newState: 0; oldOptionSet: 3,4,7,8; newOptionSet: 3,4,7,8
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorSet - Invoking onAccountingStart
connection 10-08/19:40:46 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Process event type[4] result=true
mq 10-08/19:40:46 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29135; timestamp: 1412779246734
mq 10-08/19:40:46 INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=29135-29134, iface=2:81854040, sessId=0/0/2/1001_04E0FE59, start=08.10.2014 19:40:46, uname=ISG-SPEEDTEST, addr=[IpAddress:null]]
mq 10-08/19:40:46 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29136; timestamp: 1412779246778
mq 10-08/19:40:46 INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=29136-29134, iface=2:81854040, sessId=0/0/2/1001_04E0FE5A, start=08.10.2014 19:40:46, uname=ISG-8MBPS-BONUS, addr=[IpAddress:null]]
mq 10-08/19:40:46 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29137; timestamp: 1412779246786
mq 10-08/19:40:46 INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=29137-29134, iface=2:81854040, sessId=0/0/2/1001_04E0FE5B, start=08.10.2014 19:40:46, uname=ISG-LOCAL-RES, addr=[IpAddress:null]]
mq 10-08/19:40:46 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; type: 1; deviceId: 2; connectionId: 29138; timestamp: 1412779246823
mq 10-08/19:40:46 INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=29138-29134, iface=2:81854040, sessId=0/0/2/1001_04E0FE5C, start=08.10.2014 19:40:46, uname=ISG-8MBPS, addr=[IpAddress:null]]
mq 10-08/19:40:47 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 2; pluginId: no; cid: 71; scid: -1; userId: 0; type: 3; deviceId: 2; connectionId: 27823; timestamp: 1412779247664
mq 10-08/19:40:47 INFO [event-proc-p-2-t-1] InetConnectionManager - Update connection: InetConnection [id=27823-27821, iface=2:81426674, sessId=0/0/2/1001_04DA78F4, start=08.10.2014 14:12:35, uname=ISG-8MBPS-BONUS, addr=[IpAddress:null]]
connection 10-08/19:40:48 DEBUG [sa-p-12-t-96] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateModifyEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; deviceId: 2; inetServId: 72; connectionId: 29134; state: 0; accessCode: 10; timestamp: 1412779248016
connection 10-08/19:40:48 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Do task deviceId: 2; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateModifyEvent] moduleId: 2; pluginId: no; cid: 73; scid: -1; userId: 0; deviceId: 2; inetServId: 72; connectionId: 29134; state: 0; accessCode: 10; timestamp: 1412779248016
connection 10-08/19:40:48 INFO [sa-p-12-t-96] InetApplication - TariffOptionMap: {}
connection 10-08/19:40:48 INFO [sa-p-12-t-96] InetApplication - OptionSet: [3, 4, 7, 8]
connection 10-08/19:40:48 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=2; inetServId: 72; call: true; oldState: 1; newState: 0; oldOptionSet: 3,4,7,8; newOptionSet: 3,4,7,8
connection 10-08/19:40:48 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Processing deviceId:2; command ServiceActivatorEvent type=2; inetServId: 72; call: true; oldState: 1; newState: 0; oldOptionSet: 3,4,7,8; newOptionSet: 3,4,7,8
connection 10-08/19:40:48 INFO [sa-p-12-t-96] ServiceActivatorSet - Invoking connectionModify
connection 10-08/19:40:48 DEBUG [sa-p-12-t-96] ISGIPServiceActivator - connectionModify
connection 10-08/19:40:48 INFO [sa-p-12-t-96] ISGServiceActivator - Connection modify: oldState: 1; newState: 0; oldOptionSet: [3, 4, 7, 8]; newOptionSet: [3, 4, 7, 8]
connection 10-08/19:40:48 DEBUG [sa-p-12-t-96] ISGIPServiceActivator - connectionClose
connection 10-08/19:40:48 INFO [sa-p-12-t-96] ISGServiceActivator - Connection close
connection 10-08/19:40:48 INFO [sa-p-12-t-96] ISGServiceActivator - Connection close mode 3
connection 10-08/19:40:48 INFO [sa-p-12-t-96] ISGServiceActivator - Connection close (logoff)
connection 10-08/19:40:48 INFO [sa-p-12-t-96] ISGServiceActivator - Send logoff CoA:
Packet type: CoA-Request
Identifier: 145
Authenticator: {D1 55 1E 5D 45 48 BC AC BC 57 2A D8 AC 27 FD D3}
Attributes:
User-Name=109.XXX.56.1
Framed-IP-Address=109.XXX.56.1
Acct-Session-Id=0/0/2/1001_04E0FE58
cisco-avpair=subscriber:command=account-logoff
connection 10-08/19:40:48 INFO [sa-p-12-t-96] RadiusClient - Sending to /10.100.198.31:1700
Packet type: CoA-Request
Identifier: 145
Authenticator: {D1 55 1E 5D 45 48 BC AC BC 57 2A D8 AC 27 FD D3}
Attributes:
User-Name=109.XXX.56.1
Framed-IP-Address=109.XXX.56.1
Acct-Session-Id=0/0/2/1001_04E0FE58
cisco-avpair=subscriber:command=account-logoff
connection 10-08/19:40:48 INFO [sa-p-12-t-96] ServiceActivatorDeviceWorker - Process event type[2] result=true
connection 10-08/19:40:48 INFO [rds-clnt-/10.100.198.31-1700] RadiusClient - Recieved from /10.100.198.31:1700
Packet type: CoA-ACK
Identifier: 145
Authenticator: {67 4A FF 51 CC A8 18 FE 5C 7A 14 7D 0F 24 07 F6}
Attributes:
cisco-SSG-Command-Code=\0x2109.XXX.56.1
cisco-SSG-Account-Info=S109.XXX.56.1