forum.bitel.ru :: Просмотр темы - Изменение ISG сервисов без разрыва сессии

mq 05-26/15:14:17 DEBUG [event-proc-p-2-t-1] Consumer - Caught from BGBillingServer Event[ru.bitel.bgbilling.kernel.event.events.system.SystemLimitChangedEvent] moduleId: 0; pluginId: no; cid: 35; scid: -1; userId: 0; timestamp: 1401099257543
connection 05-26/15:14:17 INFO [sa-p-11-t-11] ServiceActivatorSet - Connecting to device
connection 05-26/15:14:17 DEBUG [sa-p-11-t-11] AcknowledgeConsumer - Caught BGBillingServer:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateModifyEvent] moduleId: 2; pluginId: no; cid: 35; scid: -1; userId: 0; deviceId: 16; inetServId: 33; connectionId: 0; state: 0; accessCode: 12; timestamp: 1401099257551
connection 05-26/15:14:17 INFO [sa-p-11-t-11] ServiceActivatorDeviceWorker - Do task deviceId: 16; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateModifyEvent] moduleId: 2; pluginId: no; cid: 35; scid: -1; userId: 0; deviceId: 16; inetServId: 33; connectionId: 0; state: 0; accessCode: 12; timestamp: 1401099257551
connection 05-26/15:14:17 INFO [sa-p-11-t-11] InetApplication - TariffOptionMap: {}
connection 05-26/15:14:17 INFO [sa-p-11-t-11] InetApplication - OptionSet: [3, 4]
connection 05-26/15:14:17 INFO [sa-p-11-t-11] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=2; inetServId: 33; call: true; oldState: 1; newState: 0; oldOptionSet: 3,4; newOptionSet: 3,4
connection 05-26/15:14:17 INFO [sa-p-11-t-11] ServiceActivatorDeviceWorker - Processing deviceId:16; command ServiceActivatorEvent type=2; inetServId: 33; call: true; oldState: 1; newState: 0; oldOptionSet: 3,4; newOptionSet: 3,4
connection 05-26/15:14:17 INFO [sa-p-11-t-11] ServiceActivatorSet - Invoking serviceModify
connection 05-26/15:14:17 INFO [sa-p-11-t-11] ServiceActivatorDeviceWorker - Process event type[2] result=true
connection 05-26/15:14:17 INFO [sa-p-11-t-11] ServiceActivatorDeviceWorker - Changing InetServ:33 state and/or options
mq 05-26/15:14:17 DEBUG [sa-p-11-t-11] EventProcessor - Publish: Event[ru.bitel.bgbilling.modules.inet.access.event.InetServDeviceStateAndOptionsModifiedEvent] moduleId: 2; pluginId: no; cid: global; scid: -1; userId: -1; deviceId: 16; inetServId: 33; state: 0; optionSet: ; timestamp: 1401099257580
mq 05-26/15:14:17 DEBUG [event-proc-p-2-t-1] Consumer - Caught from BGInetAccess Event[ru.bitel.bgbilling.modules.inet.access.event.InetServDeviceStateAndOptionsModifiedEvent] moduleId: 2; pluginId: no; cid: global; scid: -1; userId: -1; deviceId: 16; inetServId: 33; state: 0; optionSet: ; timestamp: 1401099257580
mq 05-26/15:14:17 INFO [event-proc-p-2-t-1] InetServRuntimeMap - Taked event: Event[ru.bitel.bgbilling.modules.inet.access.event.InetServDeviceStateAndOptionsModifiedEvent] moduleId: 2; pluginId: no; cid: global; scid: -1; userId: -1; deviceId: 16; inetServId: 33; state: 0; optionSet: ; timestamp: 1401099257580
connection 05-26/15:14:19 INFO [sa-p-11-t-6] ServiceActivatorSet - Connecting to device
connection 05-26/15:14:19 DEBUG [sa-p-11-t-6] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateModifyEvent] moduleId: 2; pluginId: no; cid: 35; scid: -1; userId: 0; deviceId: 2; inetServId: 33; connectionId: 14207; state: 0; accessCode: 10; timestamp: 1401099259099
connection 05-26/15:14:19 INFO [sa-p-11-t-6] ServiceActivatorDeviceWorker - Do task deviceId: 2; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateModifyEvent] moduleId: 2; pluginId: no; cid: 35; scid: -1; userId: 0; deviceId: 2; inetServId: 33; connectionId: 14207; state: 0; accessCode: 10; timestamp: 1401099259099
connection 05-26/15:14:19 INFO [sa-p-11-t-6] InetApplication - TariffOptionMap: {}
connection 05-26/15:14:19 INFO [sa-p-11-t-6] InetApplication - OptionSet: [3, 4]
connection 05-26/15:14:19 INFO [sa-p-11-t-6] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=2; inetServId: 33; call: true; oldState: 1; newState: 0; oldOptionSet: 3,4; newOptionSet: 3,4
connection 05-26/15:14:19 INFO [sa-p-11-t-6] ServiceActivatorDeviceWorker - Processing deviceId:2; command ServiceActivatorEvent type=2; inetServId: 33; call: true; oldState: 1; newState: 0; oldOptionSet: 3,4; newOptionSet: 3,4
connection 05-26/15:14:19 INFO [sa-p-11-t-6] ServiceActivatorSet - Invoking connectionModify
connection 05-26/15:14:19 DEBUG [sa-p-11-t-6] ISGIPServiceActivator - connectionModify
connection 05-26/15:14:19 INFO [sa-p-11-t-6] ISGServiceActivator - Connection modify: oldState: 1; newState: 0; oldOptionSet: [3, 4]; newOptionSet: [3, 4]
connection 05-26/15:14:19 INFO [sa-p-11-t-6] ISGServiceActivator - Send deactivate service CoA:
Packet type: CoA-Request
Identifier: 22
Authenticator: {41 9D BB 71 96 1D 3E 57 BD DD F5 15 87 C4 A4 F5}
Attributes:
User-Name=109.XXX.49.104
Framed-IP-Address=109.XXX.49.104
Acct-Session-Id=0/0/2/1001_2325EA11
cisco-avpair=subscriber:service-name=ISG-10MBPS
cisco-avpair=subscriber:command=deactivate-service

connection 05-26/15:14:19 INFO [sa-p-11-t-6] RadiusClient - Sending to /10.100.198.31:1700
Packet type: CoA-Request
Identifier: 22
Authenticator: {41 9D BB 71 96 1D 3E 57 BD DD F5 15 87 C4 A4 F5}
Attributes:
User-Name=109.XXX.49.104
Framed-IP-Address=109.XXX.49.104
Acct-Session-Id=0/0/2/1001_2325EA11
cisco-avpair=subscriber:service-name=ISG-10MBPS
cisco-avpair=subscriber:command=deactivate-service

connection 05-26/15:14:19 INFO [sa-p-11-t-6] ISGServiceActivator - Send deactivate service CoA:
Packet type: CoA-Request
Identifier: 23
Authenticator: {40 CD 14 41 34 BB 86 A5 6B A0 1A 79 9F D3 AC 91}
Attributes:
User-Name=109.XXX.49.104
Framed-IP-Address=109.XXX.49.104
Acct-Session-Id=0/0/2/1001_2325EA11
cisco-avpair=subscriber:service-name=ISG-LOCAL
cisco-avpair=subscriber:command=deactivate-service

connection 05-26/15:14:19 INFO [sa-p-11-t-6] RadiusClient - Sending to /10.100.198.31:1700
Packet type: CoA-Request
Identifier: 23
Authenticator: {40 CD 14 41 34 BB 86 A5 6B A0 1A 79 9F D3 AC 91}
Attributes:
User-Name=109.XXX.49.104
Framed-IP-Address=109.XXX.49.104
Acct-Session-Id=0/0/2/1001_2325EA11
cisco-avpair=subscriber:service-name=ISG-LOCAL
cisco-avpair=subscriber:command=deactivate-service

connection 05-26/15:14:19 INFO [sa-p-11-t-6] ISGServiceActivator - Send activate service CoA:
Packet type: CoA-Request
Identifier: 24
Authenticator: {96 2C 50 E7 E4 84 99 F1 E8 CD 4E 2E DF 69 DA 88}
Attributes:
User-Name=109.XXX.49.104
Framed-IP-Address=109.XXX.49.104
Acct-Session-Id=0/0/2/1001_2325EA11
cisco-avpair=subscriber:service-name=L4REDIRECT
cisco-avpair=subscriber:command=activate-service

connection 05-26/15:14:19 INFO [sa-p-11-t-6] RadiusClient - Sending to /10.100.198.31:1700
Packet type: CoA-Request
Identifier: 24
Authenticator: {96 2C 50 E7 E4 84 99 F1 E8 CD 4E 2E DF 69 DA 88}
Attributes:
User-Name=109.XXX.49.104
Framed-IP-Address=109.XXX.49.104
Acct-Session-Id=0/0/2/1001_2325EA11
cisco-avpair=subscriber:service-name=L4REDIRECT
cisco-avpair=subscriber:command=activate-service

connection 05-26/15:14:19 DEBUG [sa-p-11-t-11] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateModifyEvent] moduleId: 2; pluginId: no; cid: 35; scid: -1; userId: 0; deviceId: 16; inetServId: 33; connectionId: 14202; state: 0; accessCode: 10; timestamp: 1401099259109
connection 05-26/15:14:19 INFO [sa-p-11-t-11] ServiceActivatorDeviceWorker - Do task deviceId: 16; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateModifyEvent] moduleId: 2; pluginId: no; cid: 35; scid: -1; userId: 0; deviceId: 16; inetServId: 33; connectionId: 14202; state: 0; accessCode: 10; timestamp: 1401099259109
connection 05-26/15:14:19 INFO [sa-p-11-t-6] ISGServiceActivator - Send activate service CoA:
Packet type: CoA-Request
Identifier: 25
Authenticator: {1A C8 28 E5 CB CF 53 78 8C 90 3C D0 5E 62 9C B3}
Attributes:
User-Name=109.XXX.49.104
Framed-IP-Address=109.XXX.49.104
Acct-Session-Id=0/0/2/1001_2325EA11
cisco-avpair=subscriber:service-name=OPENGARDEN
cisco-avpair=subscriber:command=activate-service

connection 05-26/15:14:19 INFO [sa-p-11-t-6] RadiusClient - Sending to /10.100.198.31:1700
Packet type: CoA-Request
Identifier: 25
Authenticator: {1A C8 28 E5 CB CF 53 78 8C 90 3C D0 5E 62 9C B3}
Attributes:
User-Name=109.XXX.49.104
Framed-IP-Address=109.XXX.49.104
Acct-Session-Id=0/0/2/1001_2325EA11
cisco-avpair=subscriber:service-name=OPENGARDEN
cisco-avpair=subscriber:command=activate-service

connection 05-26/15:14:19 INFO [sa-p-11-t-11] InetApplication - TariffOptionMap: {}
connection 05-26/15:14:19 INFO [sa-p-11-t-11] InetApplication - OptionSet: [3, 4]
connection 05-26/15:14:19 INFO [sa-p-11-t-11] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=2; inetServId: 33; call: true; oldState: 1; newState: 0; oldOptionSet: 3,4; newOptionSet: 3,4
connection 05-26/15:14:19 INFO [sa-p-11-t-11] ServiceActivatorDeviceWorker - Processing deviceId:16; command ServiceActivatorEvent type=2; inetServId: 33; call: true; oldState: 1; newState: 0; oldOptionSet: 3,4; newOptionSet: 3,4
connection 05-26/15:14:19 INFO [sa-p-11-t-11] ServiceActivatorSet - Invoking connectionModify
connection 05-26/15:14:19 DEBUG [sa-p-11-t-11] ISGIPServiceActivator - connectionModify
connection 05-26/15:14:19 DEBUG [sa-p-11-t-11] ISGIPServiceActivator - Skip InetConnection [id=14202-0, iface=16:0, sessId=aa45454f, start=26.05.2014 15:07:41, uname=null, addr=109.XXX.49.104] 2
connection 05-26/15:14:19 INFO [sa-p-11-t-11] ServiceActivatorDeviceWorker - Process event type[2] result=true
connection 05-26/15:14:19 INFO [sa-p-11-t-11] ServiceActivatorDeviceWorker - Changing InetConnection:14202 state and/or options
connection 05-26/15:14:19 INFO [sa-p-11-t-6] ServiceActivatorDeviceWorker - Process event type[2] result=true
mq 05-26/15:14:19 DEBUG [sa-p-11-t-11] EventProcessor - Publish: Event[ru.bitel.bgbilling.modules.inet.access.event.InetConnectionDeviceStateAndOptionsModifiedEvent] moduleId: 2; pluginId: no; cid: global; scid: -1; userId: -1; deviceId: 16; connectionId: 14202; optionSet: ; timestamp: 1401099259113
mq 05-26/15:14:19 DEBUG [event-proc-p-2-t-1] Consumer - Caught from BGInetAccess Event[ru.bitel.bgbilling.modules.inet.access.event.InetConnectionDeviceStateAndOptionsModifiedEvent] moduleId: 2; pluginId: no; cid: global; scid: -1; userId: -1; deviceId: 16; connectionId: 14202; optionSet: ; timestamp: 1401099259113
radius 05-26/15:14:20 INFO [hrlydtlggr-p-6-t-1] HourlyDataLoggerTracker - Checking data log files to close [hours=2]...
radius 05-26/15:14:20 DEBUG [hrlydtlggr-p-6-t-1] HourlyDataLogEntry - Last modified: 1401098853000 : -1
dhcp 05-26/15:14:21 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Checking data log files to close [hours=2]...
dhcp 05-26/15:14:21 DEBUG [hrlydtlggr-p-8-t-1] HourlyDataLogEntry - Last modified: 1401098360000 : 1401098360000
dhcp 05-26/15:14:21 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/usr/local/BGInetAccess/data/dhcp/source_12/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl]
dhcp 05-26/15:14:21 DEBUG [hrlydtlggr-p-8-t-1] HourlyDataLogEntry - Last modified: 1401098326000 : 1401098326000
dhcp 05-26/15:14:21 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/usr/local/BGInetAccess/data/dhcp/source_9/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl]
dhcp 05-26/15:14:21 DEBUG [hrlydtlggr-p-8-t-1] HourlyDataLogEntry - Last modified: 1401098392000 : 1401098392000
dhcp 05-26/15:14:21 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/usr/local/BGInetAccess/data/dhcp/source_16/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl]
dhcp 05-26/15:14:21 DEBUG [hrlydtlggr-p-8-t-1] HourlyDataLogEntry - Last modified: 1401098360000 : 1401098360000
dhcp 05-26/15:14:21 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/usr/local/BGInetAccess/data/dhcp/source_10/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl]
dhcp 05-26/15:14:21 DEBUG [hrlydtlggr-p-8-t-1] HourlyDataLogEntry - Last modified: 1401098367000 : 1401098367000
dhcp 05-26/15:14:21 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/usr/local/BGInetAccess/data/dhcp/source_11/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl]
dhcp 05-26/15:14:21 DEBUG [hrlydtlggr-p-8-t-1] HourlyDataLogEntry - Last modified: 1401098326000 : 1401098326000
dhcp 05-26/15:14:21 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/usr/local/BGInetAccess/data/dhcp/source_4/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl]
dhcp 05-26/15:14:21 DEBUG [hrlydtlggr-p-8-t-1] HourlyDataLogEntry - Last modified: 1401098510000 : 1401098510000
dhcp 05-26/15:14:21 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/usr/local/BGInetAccess/data/dhcp/source_12/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl]
dhcp 05-26/15:14:21 DEBUG [hrlydtlggr-p-8-t-1] HourlyDataLogEntry - Last modified: 1401098476000 : 1401098476000
dhcp 05-26/15:14:21 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/usr/local/BGInetAccess/data/dhcp/source_9/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl]
dhcp 05-26/15:14:21 DEBUG [hrlydtlggr-p-8-t-1] HourlyDataLogEntry - Last modified: 1401098518000 : 1401098518000
dhcp 05-26/15:14:21 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/usr/local/BGInetAccess/data/dhcp/source_16/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl]
dhcp 05-26/15:14:21 DEBUG [hrlydtlggr-p-8-t-1] HourlyDataLogEntry - Last modified: 1401098444000 : 1401098444000
dhcp 05-26/15:14:21 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/usr/local/BGInetAccess/data/dhcp/source_10/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl]
dhcp 05-26/15:14:21 DEBUG [hrlydtlggr-p-8-t-1] HourlyDataLogEntry - Last modified: 1401098517000 : 1401098517000
dhcp 05-26/15:14:21 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/usr/local/BGInetAccess/data/dhcp/source_11/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl]
dhcp 05-26/15:14:21 DEBUG [hrlydtlggr-p-8-t-1] HourlyDataLogEntry - Last modified: 1401098476000 : 1401098476000
dhcp 05-26/15:14:21 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/usr/local/BGInetAccess/data/dhcp/source_4/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl]
dhcp 05-26/15:14:23 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Close dataLog file [/usr/local/BGInetAccess/data/dhcp/source_12/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl]
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 2
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Close ZLIBWritableChannel...
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 776
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] DataLog - DataLog file [data/dhcp/source_12/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl] was closed
dhcp 05-26/15:14:23 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Close dataLog file [/usr/local/BGInetAccess/data/dhcp/source_9/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl]
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 2
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Close ZLIBWritableChannel...
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 942
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] DataLog - DataLog file [data/dhcp/source_9/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl] was closed
dhcp 05-26/15:14:23 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Close dataLog file [/usr/local/BGInetAccess/data/dhcp/source_16/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl]
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 2
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Close ZLIBWritableChannel...
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 754
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] DataLog - DataLog file [data/dhcp/source_16/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl] was closed
dhcp 05-26/15:14:23 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Close dataLog file [/usr/local/BGInetAccess/data/dhcp/source_10/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl]
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 2
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Close ZLIBWritableChannel...
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 819
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] DataLog - DataLog file [data/dhcp/source_10/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl] was closed
dhcp 05-26/15:14:23 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Close dataLog file [/usr/local/BGInetAccess/data/dhcp/source_11/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl]
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 2
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Close ZLIBWritableChannel...
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 775
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] DataLog - DataLog file [data/dhcp/source_11/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl] was closed
dhcp 05-26/15:14:23 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Close dataLog file [/usr/local/BGInetAccess/data/dhcp/source_4/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl]
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 2
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Close ZLIBWritableChannel...
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 878
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] DataLog - DataLog file [data/dhcp/source_4/2014/2014-05/2014-05-26/log_2014-05-26-14.004.bgdl] was closed
dhcp 05-26/15:14:23 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Close dataLog file [/usr/local/BGInetAccess/data/dhcp/source_12/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl]
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 2
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Close ZLIBWritableChannel...
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 817
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] DataLog - DataLog file [data/dhcp/source_12/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl] was closed
dhcp 05-26/15:14:23 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Close dataLog file [/usr/local/BGInetAccess/data/dhcp/source_9/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl]
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 2
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Close ZLIBWritableChannel...
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 1107
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] DataLog - DataLog file [data/dhcp/source_9/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl] was closed
dhcp 05-26/15:14:23 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Close dataLog file [/usr/local/BGInetAccess/data/dhcp/source_16/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl]
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 2
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Close ZLIBWritableChannel...
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 863
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] DataLog - DataLog file [data/dhcp/source_16/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl] was closed
dhcp 05-26/15:14:23 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Close dataLog file [/usr/local/BGInetAccess/data/dhcp/source_10/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl]
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 2
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Close ZLIBWritableChannel...
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 1056
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] DataLog - DataLog file [data/dhcp/source_10/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl] was closed
dhcp 05-26/15:14:23 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Close dataLog file [/usr/local/BGInetAccess/data/dhcp/source_11/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl]
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 2
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Close ZLIBWritableChannel...
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 815
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] DataLog - DataLog file [data/dhcp/source_11/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl] was closed
dhcp 05-26/15:14:23 INFO [hrlydtlggr-p-8-t-1] HourlyDataLoggerTracker - Close dataLog file [/usr/local/BGInetAccess/data/dhcp/source_4/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl]
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 2
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Close ZLIBWritableChannel...
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] ZLIBWritableChannel - Deflating... 131088 1041
dhcp 05-26/15:14:23 DEBUG [hrlydtlggr-p-8-t-1] DataLog - DataLog file [data/dhcp/source_4/2014/2014-05/2014-05-26/log_2014-05-26-15.000.bgdl] was closed
connection 05-26/15:14:24 DEBUG [sa-p-11-t-6] EventWorker - Waiting 5000 millis for last future results will done...
connection 05-26/15:14:24 INFO [sa-p-11-t-11] ServiceActivatorSet - Disconnecting from device
connection 05-26/15:14:29 INFO [sa-p-11-t-6] EventWorker - Timeout waiting futures
connection 05-26/15:14:29 ERROR [sa-p-11-t-6] EventWorker - java.util.concurrent.TimeoutException
ru.bitel.bgbilling.common.BGException: java.util.concurrent.TimeoutException
at ru.bitel.bgbilling.kernel.event.AsyncEventWorker.doTasks(AsyncEventWorker.java:92)
at ru.bitel.bgbilling.modules.inet.access.sa.ServiceActivatorDeviceWorker.runWorker(ServiceActivatorDeviceWorker.java:179)
at ru.bitel.bgbilling.kernel.event.EventWorker.internalRunWorker(EventWorker.java:115)
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:439)
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:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)
at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:40)
Caused by: java.util.concurrent.TimeoutException
... 15 more
connection 05-26/15:14:29 INFO [sa-p-11-t-6] ServiceActivatorSet - Disconnecting from device
connection 05-26/15:14:29 INFO [sa-p-11-t-6] ServiceActivatorDeviceWorker - Execution error - waiting 60000ms for next try.
dhcp 05-26/15:14:31 INFO [dhcpLstnr-p-9-t-6] InetAbstractDhcpProcessor - REQUEST:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: -1438300849, secs: 0, flags: 0
Client IP: 109.XXX.49.104
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 109.XXX.49.254
Client MAC: {001560BBCB17}
Host name{12}={hp-notebook}
Parameter request list{55}={1, 28, 2, 3, 15, 6, 12, 44, 47}
Agent information{82}=
sub{1}={000404B10000}
sub{2}={0006000B46CA4F00}

dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] InetAbstractDhcpProcessor - OP_BOOT_REQUEST
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] InetAbstractDhcpProcessor - Found device by giaddr id=13
dhcp 05-26/15:14:31 INFO [dhcpLstnr-p-9-t-6] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: -1438300849, secs: 0, flags: 0
Client IP: 109.XXX.49.104
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 109.XXX.49.254
Client MAC: {001560BBCB17}
Host name{12}={hp-notebook}
Parameter request list{55}={1, 28, 2, 3, 15, 6, 12, 44, 47}
Agent information{82}=
sub{1}={000404B10000}
sub{2}={0006000B46CA4F00}
Common options: {agentRemoteId=[B@214fdcf3}
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] InetAbstractDhcpProcessor - Found subDevice by identifier id=16
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] InetDhcpProcessor - DHCP_REQUEST
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] InetDhcpProcessor - request.giaddr= 109.XXX.49.254, clientAddress=/109.XXX.49.254:67
dhcp 05-26/15:14:31 INFO [dhcpLstnr-p-9-t-6] InetDhcpDevice - Search serv on deviceId: 16; 1; interfaceId: 0
dhcp 05-26/15:14:31 INFO [dhcpLstnr-p-9-t-6] InetDhcpProcessor - InetServ found: ContractId: 35; servId: 33
L2 cisco catalyst mixed network): 000b46ca4f00 [10.112.1.2]: (0
Options [] TariffModuleTreeSet [9:21.05.2014-?; ]
Device state: 0; optionSet:3,4
dhcp 05-26/15:14:31 INFO [dhcpLstnr-p-9-t-6] InetApplication - inetServ[id=33] deviceState not active (accessCode=0).
dhcp 05-26/15:14:31 INFO [dhcpLstnr-p-9-t-6] InetDhcpProcessor - Updating of existing connection: InetConnection [id=14202-0, iface=16:0, sessId=aa45454f, start=26.05.2014 15:07:41, uname=null, addr=109.XXX.49.104]
mq 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] EventProcessor - Publish: Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingManageEvent] moduleId: 2; pluginId: no; cid: 35; scid: -1; userId: -1; type: 3; deviceId: 16; connectionId: 14202; timestamp: 1401099271045
dhcp 05-26/15:14:31 INFO [dhcpLstnr-p-9-t-6] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP ACK{5}
htype: 1, hlen: 6, hops: 1
xid: -1438300849, secs: 0, flags: 0
Client IP: 109.XXX.49.104
Your IP: 109.XXX.49.104
Server IP: 0.0.0.0
Relay IP: 109.XXX.49.254
Client MAC: {001560BBCB17}
Agent information{82}=
sub{1}={000404B10000}
sub{2}={0006000B46CA4F00}
Router{3}=109.XXX.49.254
Subnet mask{1}=255.255.255.0
DNS{6}={6D7F0135}
IP Address Lease Time{51}=300
Server Identifier{54}={00000000}

dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] ProcessorRequest - Sending to /109.XXX.49.254:67
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] HourlyDataLogger - Create log file...
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] HourlyLogFileUtils - Next log file: /usr/local/BGInetAccess/data/dhcp/source_16/2014/2014-05/2014-05-26/log_2014-05-26-15.001.bgdl
dhcp 05-26/15:14:31 INFO [dhcpLstnr-p-9-t-6] HourlyDataLogEntry - Create dataLog file: /usr/local/BGInetAccess/data/dhcp/source_16/2014/2014-05/2014-05-26/log_2014-05-26-15.001.bgdl
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] BGDataLog - DataLog file [data/dhcp/source_16/2014/2014-05/2014-05-26/log_2014-05-26-15.001.bgdl] was opened
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] DataLog - Writing TLV finished(3)=[0]
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] DataLog - Writing TLV buffer(4)=[type=chunked, size=131072]
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] DataLog - Writing TLV compression(5)=[type=zlib, level=1, strategy=1]
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] DataLog - Writing TLV distributed(6)=[1]
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] DataLog - Writing TLV streaming(7)=[1]
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] BGDataLog - Header length=51
dhcp 05-26/15:14:31 DEBUG [dhcpLstnr-p-9-t-6] ZLIBWritableChannel - ZLIBWritableChannel bufferLength=131088
mq 05-26/15:14:31 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 2; pluginId: no; cid: 35; scid: -1; userId: 0; type: 3; deviceId: 16; connectionId: 14202; timestamp: 1401099271055
access 05-26/15:14:36 DEBUG [access-p-5-t-1] SessionCountManager - Run SessionCountManager...
access 05-26/15:15:08 DEBUG [access-p-5-t-1] SessionCountManager - Run SessionCountManager...
radius 05-26/15:15:18 DEBUG [setup-sched-p-1-t-1] RadiusProcessor - After clean old rad sessions: 0
mq 05-26/15:15:23 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 2; pluginId: no; cid: 35; scid: -1; userId: 0; type: 3; deviceId: 2; connectionId: 14207; timestamp: 1401099323805

Автор:	survivor [ 23 май 2014, 16:36 ]
Заголовок сообщения:	Изменение ISG сервисов без разрыва сессии
Доброго дня, На данный момент работает такая конфигурация: абоненты (влан на юзера) через свичи доступа (с opt82) попадают на L3 аггрегатор (заведен в биллинге как родительское устройство для свичей доступа) потом траффик попадает на БРАС (родитель для L3 аггрегатора) где уже стартует ISG. В биллинге (в мониторе) для онлайн абонента висит две сессии: одна для L3 аггрегатора (результат dhcp запроса) и вторая для БРАСа (результат радиус запроса от ISG). Есть один ньюанс - когда абонент имеет проблемы с балансом - биллинг принудительно закрывает одну его сессию в биллинге (от браса) и сбрасывает ISG на брасе. Потому что: Код: sa.radius.connection.withoutBreak=0 При этом в мониторе dhcp сессия от L3 аггрегатора остается в состоянии "подключено". Как только брас присылает новый радиус запрос на авторизацию - биллинг ему отвечает Access-Reject. на этот случай на циске заготовлена конфигурация - создать ISG сессию длительностью 1 мин., навесить локальные сервисы OPENGARDEN и L4REDIRECT. Через некоторое время висящая в биллинге dhcp сессия (для L3 аггрегатора) переходит в состояние "отключено". Однако это не мешает ей продолжать выдавать клиенту IP адрес в случае необходимости. Потому что: Код: dhcp.disable.mode=1 Хочу попробовать сделать все без пересоздания ISG сессии на брасе - т.е. с автоматическим снятием текущих сервисов, установкой L4REDIRECT и OPENGARDEN при возникновении проблем с балансом и наоборот - при их решении. Делаю: Код: sa.radius.connection.withoutBreak=1 radius.serviceName.disable=L4REDIRECT,OPENGARDEN sa.radius.service.disable=L4REDIRECT,OPENGARDEN Тут есть две проблемы: 1) Как только баланс чрезмерно понижается - биллинг исправно снимает текущие сервисы и навешивает новые (L4REDIRECT и OPENGARDEN). Но! Через некоторое время dhcp сессия переходит в состояние отключено, что убивает связанную с ней БРАС сессию (которую хотелось сохранить). Можно с этим что-то сделать в принципе? 2) При следующем радиус запросе от браса биллинг по прежнему отвечает Access-Reject. А по идее должен пустить и отдать сервисы L4REDIRECT и OPENGARDEN. Тут похоже я что-то забыл сконфигурить? Сервер: вер. 6.0 сборка 1723 от 10.04.2014 12:49:07 os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.6.0_41 inet вер. 6.0 сборка 1369 от 07.04.2014 19:04:33

Автор:	Amir [ 23 май 2014, 17:25 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Цитата: Через некоторое время dhcp сессия переходит в состояние отключено, что убивает связанную с ней БРАС сессию (которую хотелось сохранить) А что в это время в логах? Посылается account-logoff? Вроде бы должен только при стопе DHCP-сессии. Цитата: При следующем радиус запросе от браса биллинг по прежнему отвечает Access-Reject Указаны параметры Код: radius.disable.accessCodes= radius.disable.attributes= ?

Автор:	survivor [ 23 май 2014, 17:59 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Код: radius.disable.accessCodes= radius.disable.attributes= поправил спасибо теперь - пускает. Насчет первого вопроса: да account-logoff отправляет. Вот логи: Код: mq 05-23/16:44:04 INFO [event-proc-p-2-t-1] InetConnectionManager - Update connection: InetConnection [id=13916-13915, iface=2:584503288, sessId=0/0/2/1001_22D6D004, start=23.05.2014 12:24:24, uname=ISG-10MBPS, addr=[IpAddress:null]] dhcp 05-23/16:44:06 INFO [dhcpLstnr-p-9-t-6] InetAbstractDhcpProcessor - REQUEST: Message type: BOOT_REQUEST Dhcp message type: DHCP Request{3} htype: 1, hlen: 6, hops: 1 xid: -1537920000, secs: 0, flags: 0 Client IP: 109.XXX.49.122 Your IP: 0.0.0.0 Server IP: 0.0.0.0 Relay IP: 109.XXX.49.254 Client MAC: {001560BBCB17} Host name{12}={hp-notebook} Parameter request list{55}={1, 28, 2, 3, 15, 6, 12, 44, 47} Agent information{82}= sub{1}={000404B10000} sub{2}={0006000B46CA4F00} dhcp 05-23/16:44:06 DEBUG [dhcpLstnr-p-9-t-6] InetAbstractDhcpProcessor - OP_BOOT_REQUEST dhcp 05-23/16:44:06 DEBUG [dhcpLstnr-p-9-t-6] InetAbstractDhcpProcessor - Found device by giaddr id=13 dhcp 05-23/16:44:06 INFO [dhcpLstnr-p-9-t-6] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS: Message type: BOOT_REQUEST Dhcp message type: DHCP Request{3} htype: 1, hlen: 6, hops: 1 xid: -1537920000, secs: 0, flags: 0 Client IP: 109.XXX.49.122 Your IP: 0.0.0.0 Server IP: 0.0.0.0 Relay IP: 109.XXX.49.254 Client MAC: {001560BBCB17} Host name{12}={hp-notebook} Parameter request list{55}={1, 28, 2, 3, 15, 6, 12, 44, 47} Agent information{82}= sub{1}={000404B10000} sub{2}={0006000B46CA4F00} Common options: {agentRemoteId=[B@1a684bf2} dhcp 05-23/16:44:06 DEBUG [dhcpLstnr-p-9-t-6] InetAbstractDhcpProcessor - Found subDevice by identifier id=16 dhcp 05-23/16:44:06 DEBUG [dhcpLstnr-p-9-t-6] InetDhcpProcessor - DHCP_REQUEST dhcp 05-23/16:44:06 DEBUG [dhcpLstnr-p-9-t-6] InetDhcpProcessor - request.giaddr= 109.XXX.49.254, clientAddress=/109.XXX.49.254:67 dhcp 05-23/16:44:06 INFO [dhcpLstnr-p-9-t-6] InetDhcpDevice - Search serv on deviceId: 16; 1; interfaceId: 0 dhcp 05-23/16:44:06 INFO [dhcpLstnr-p-9-t-6] InetDhcpProcessor - InetServ found: ContractId: 35; servId: 33 L2 cisco catalyst mixed network): 000b46ca4f00 [10.112.1.2]: (0 Options [] TariffModuleTreeSet [5:21.05.2014-?; ] Device state: 0; optionSet:3,4 dhcp 05-23/16:44:06 INFO [dhcpLstnr-p-9-t-6] InetApplication - inetServ[id=33] deviceState not active (accessCode=0). dhcp 05-23/16:44:06 INFO [dhcpLstnr-p-9-t-6] InetDhcpProcessor - Stopping session with deviceState= 1 and accessCode=10 mq 05-23/16:44:06 DEBUG [dhcpLstnr-p-9-t-6] EventProcessor - Request, timeout 5000 : Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingManageEvent] moduleId: 2; pluginId: no; cid: 35; scid: -1; userId: -1; type: 2; deviceId: 16; connectionId: 13947; timestamp: 1400845446795 connection 05-23/16:44:06 INFO [sa-p-11-t-12] ServiceActivatorSet - Connecting to device connection 05-23/16:44:06 DEBUG [sa-p-11-t-12] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 2; pluginId: no; cid: 35; scid: -1; userId: 0; type: 2; deviceId: 16; connectionId: 13947; timestamp: 1400845446805 connection 05-23/16:44:06 INFO [sa-p-11-t-12] ServiceActivatorDeviceWorker - Do task deviceId: 16; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 2; pluginId: no; cid: 35; scid: -1; userId: 0; type: 2; deviceId: 16; connectionId: 13947; timestamp: 1400845446805 connection 05-23/16:44:06 INFO [sa-p-11-t-12] InetApplication - TariffOptionMap: {} connection 05-23/16:44:06 INFO [sa-p-11-t-12] InetApplication - OptionSet: [3, 4] connection 05-23/16:44:06 INFO [sa-p-11-t-12] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=5; inetServId: 33; call: true; oldState: 0; newState: 0; oldOptionSet: 3,4; newOptionSet: 3,4 connection 05-23/16:44:06 INFO [sa-p-11-t-12] ServiceActivatorDeviceWorker - Processing deviceId:16; command ServiceActivatorEvent type=5; inetServId: 33; call: true; oldState: 0; newState: 0; oldOptionSet: 3,4; newOptionSet: 3,4 connection 05-23/16:44:06 INFO [sa-p-11-t-12] ServiceActivatorSet - Invoking onAccountingStop connection 05-23/16:44:06 INFO [sa-p-11-t-12] ISGIPServiceActivator - onAccountingStop connection 05-23/16:44:06 INFO [sa-p-11-t-12] ISGServiceActivator - Connection close mode 3 connection 05-23/16:44:06 INFO [sa-p-11-t-12] ISGServiceActivator - Connection close (logoff) connection 05-23/16:44:06 INFO [sa-p-11-t-12] ISGServiceActivator - Send logoff CoA: Packet type: CoA-Request Identifier: 1 Authenticator: {0B 87 78 F0 13 96 87 60 27 6B EC B9 A9 B7 1F 65} Attributes: User-Name=109.XXX.49.122 Framed-IP-Address=109.XXX.49.122 Acct-Session-Id=0/0/2/1001_22DB8C77 cisco-avpair=subscriber:command=account-logoff connection 05-23/16:44:06 INFO [sa-p-11-t-12] RadiusClient - Sending to /10.XXX.198.31:1700 Packet type: CoA-Request Identifier: 1 Authenticator: {0B 87 78 F0 13 96 87 60 27 6B EC B9 A9 B7 1F 65} Attributes: User-Name=109.XXX.49.122 Framed-IP-Address=109.XXX.49.122 Acct-Session-Id=0/0/2/1001_22DB8C77 cisco-avpair=subscriber:command=account-logoff connection 05-23/16:44:06 INFO [sa-p-11-t-12] DatagramChannelListener - ru.bitel.bgbilling.kernel.network.radius.RadiusClient$RadiusDatagramChannelListener socket init ok. connection 05-23/16:44:06 INFO [sa-p-11-t-12] ServiceActivatorDeviceWorker - Process event type[5] result=true dhcp 05-23/16:44:06 INFO [dhcpLstnr-p-9-t-6] InetConnectionManager - Remove connection: InetConnection [id=13947-0, iface=16:0, sessId=a4553400, start=23.05.2014 16:37:46, uname=null, addr=109.XXX.49.122] dhcp 05-23/16:44:06 INFO [dhcpLstnr-p-9-t-6] InetConnectionKeyMap - Remove connection remove 109.XXX.49.122 dhcp 05-23/16:44:06 INFO [dhcpLstnr-p-9-t-6] InetAbstractDhcpProcessor - RESPONSE: Message type: BOOT_RESPONSE Dhcp message type: DHCP NAK{6} htype: 1, hlen: 6, hops: 1 xid: -1537920000, secs: 0, flags: 0 Client IP: 109.XXX.49.122 Your IP: 0.0.0.0 Server IP: 0.0.0.0 Relay IP: 109.XXX.49.254 Client MAC: {001560BBCB17} Agent information{82}= sub{1}={000404B10000} sub{2}={0006000B46CA4F00} dhcp 05-23/16:44:06 DEBUG [dhcpLstnr-p-9-t-6] ProcessorRequest - Sending to /109.XXX.49.254:67

Автор:	Amir [ 23 май 2014, 18:11 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Т.е. получается нужно, чтобы, если баланс стал меньше лимита или наоборот или сменился статус договора, DHCP продолжал выдавать так, будто ничего этого не было?

Автор:	survivor [ 23 май 2014, 18:20 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Ага В принципе так почти и есть - dhcp выдает адреса нормально, просто от убивает сессию от ISG... после того как она восстанавливается - опять все ok. Без разрыва не получается

forum.bitel.ru http://forum.bitel.ru/

Изменение ISG сервисов без разрыва сессии http://forum.bitel.ru/viewtopic.php?f=44&t=9279	Страница 1 из 2

Автор:	Amir [ 23 май 2014, 18:23 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
В большинстве случаев должно помочь, если добавить e.setConnectionStateModified( true ); в connectionModify: Код: @Override public Object connectionModify( ServiceActivatorEvent e ) throws Exception { logger.debug( "connectionModify" ); if( e.getConnection().getDeviceId() != this.deviceId ) { logger.debug( "Skip " + e.getConnection() + " " + this.deviceId ); e.setConnectionStateModified( true ); return null; } return super.connectionModify( e ); } Т.е. Access здесь сам укажет, что состояние уже изменил. Но, теоретически, ServiceActivator может не успеть обработать до того как придет новый DHCP-пакет - чтобы все равно не отключало, нужно будет кроме этого немного доработать модуль.

Автор:	survivor [ 26 май 2014, 13:14 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Amir, могу я спросить о соответствующей доработке? Запрос делать в техподдержке?

Автор:	survivor [ 26 май 2014, 13:54 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Что интересно - процесс возвращения в нормальное состояние (при пополнении баланса) тоже двухступенчатый: сначала dhcp сессия остается в состоянии отключено, а isg сессия переходит в состояние подключено. Интернет у абонента начинает работать. Через какой-то промежуток времени (несколько минут) dhcp сессия убивает связанную isg сессию и переходит в состояние подключено. Потом стартует новая isg сессия и интернет опять возвращается.

Автор:	Amir [ 26 май 2014, 14:16 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Потому что сейчас при получении DHCP-запроса он начинает проверять что текущее состояние сессии совпадает с необходимым, если нет - просто выдает NAK. А ISG меняет сразу через CoA. Сегодня выложим. Не пробовали еще предобработку менять? При стабильной работе должно в 99% вроде бы работать как вам надо.

Автор:	Amir [ 26 май 2014, 14:22 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
После обновления нужно будет указать dhcp.disable.mode=2

Автор:	survivor [ 26 май 2014, 14:33 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Amir писал(а): Потому что сейчас при получении DHCP-запроса он начинает проверять что текущее состояние сессии совпадает с необходимым, если нет - просто выдает NAK. А ISG меняет сразу через CoA. Сегодня выложим. Не пробовали еще предобработку менять? При стабильной работе должно в 99% вроде бы работать как вам надо. О это клево! Насчет предобработки - правильно ли я понял, что нужно поменять "обработчик активации сервисов" для типа устройств = BRAS ISG? Создать новый класс - у в него ваш код? Или для типа устройств = L3 свитч (DHCP)?

Автор:	Amir [ 26 май 2014, 14:44 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Вроде бы у вас для типа устройства BRAS ISG уже должен быть указан обработчик активации сервисов - вот его надо поменять. Сейчас там должно быть что-то вроде Код: @Override public Object connectionModify( ServiceActivatorEvent e ) throws Exception { logger.debug( "connectionModify" ); if( e.getConnection().getDeviceId() != this.deviceId ) { logger.debug( "Skip " + e.getConnection() + " " + this.deviceId ); return null; } return super.connectionModify( e ); } А нужно добавить туда e.setConnectionStateModified( true );

Автор:	survivor [ 26 май 2014, 15:21 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Понял, попробовал. Процесс отключения стал более простым: 1) DHCP сессия - начало: 14:03:06 - подключено ISG сессия - начало: 14:03:08 - подключено сессия на циске - uptime:38s 2) DHCP сессия - начало: 14:03:06 - отключено ISG сессия - начало: 14:04:04 - отключено сессия на циске - uptime:1m26s 3) DHCP сессия - начало: 14:04:05 - отключено ISG сессия - начало: 14:04:04 - отключено сессия на циске - uptime:2m13s но вот процесс включения баланса подвис: 4) DHCP сессия - начало: 14:12:15 - подключено ISG сессия - начало: 14:04:04 - отключено сессия на циске - uptime:12m28s и дальше не двигается. Параллельно вопрос - почему у сессий в биллинге (особенно у ISG) меняется начало (выделил темно красным), хотя видно что isg сессия на циске не пересоздается?

Автор:	Amir [ 26 май 2014, 15:53 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
А какой у вас был connectionModify и какой стал?

Автор:	survivor [ 26 май 2014, 17:19 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Ситуация легко воспроизводится. Сейчас опять: dhcp сессия - подключено, isg сессия - отключено. В логах: Код: connection 05-26/16:14:22 INFO [sa-p-11-t-5] ISGServiceActivator - Send activate service CoA: Packet type: CoA-Request Identifier: 45 Authenticator: {51 1D D4 4A 97 37 62 27 92 6A D2 51 43 AF F6 1B} Attributes: User-Name=109.XXX.49.206 Framed-IP-Address=109.XXX.49.206 Acct-Session-Id=0/0/2/1001_2326A1F8 cisco-avpair=subscriber:service-name=ISG-10MBPS cisco-avpair=subscriber:command=activate-service connection 05-26/16:14:22 INFO [sa-p-11-t-5] RadiusClient - Sending to /10.100.198.31:1700 Packet type: CoA-Request Identifier: 45 Authenticator: {51 1D D4 4A 97 37 62 27 92 6A D2 51 43 AF F6 1B} Attributes: User-Name=109.XXX.49.206 Framed-IP-Address=109.XXX.49.206 Acct-Session-Id=0/0/2/1001_2326A1F8 cisco-avpair=subscriber:service-name=ISG-10MBPS cisco-avpair=subscriber:command=activate-service connection 05-26/16:14:22 INFO [sa-p-11-t-5] ISGServiceActivator - Send activate service CoA: Packet type: CoA-Request Identifier: 46 Authenticator: {84 80 12 1E F7 1C A4 1A 64 0B 9A E7 52 BF 96 46} Attributes: User-Name=109.XXX.49.206 Framed-IP-Address=109.XXX.49.206 Acct-Session-Id=0/0/2/1001_2326A1F8 cisco-avpair=subscriber:service-name=ISG-LOCAL cisco-avpair=subscriber:command=activate-service connection 05-26/16:14:22 INFO [sa-p-11-t-5] RadiusClient - Sending to /10.100.198.31:1700 Packet type: CoA-Request Identifier: 46 Authenticator: {84 80 12 1E F7 1C A4 1A 64 0B 9A E7 52 BF 96 46} Attributes: User-Name=109.XXX.49.206 Framed-IP-Address=109.XXX.49.206 Acct-Session-Id=0/0/2/1001_2326A1F8 cisco-avpair=subscriber:service-name=ISG-LOCAL cisco-avpair=subscriber:command=activate-service На циске сессия живая: Код: Type: IP, UID: 1816, State: authen, Identity: 109.XXX.49.206 IPv4 Address: 109.XXX.49.206 Session Up-time: 00:23:53, Last Changed: 00:03:03 Switch-ID: 8337682 Policy information: Authentication status: authen Active services associated with session: name "OPENGARDEN" name "L4REDIRECT" Rules, actions and conditions executed: subscriber rule-map IPoE-ISG condition always event session-start 10 authorize aaa list ipoe-isg-aaa identifier source-ip-address subscriber rule-map default-internal-rule condition always event service-start 1 service-policy type service identifier service-name subscriber rule-map default-internal-rule condition always event service-start 1 service-policy type service identifier service-name subscriber rule-map IPoE-ISG condition always event service-stop 1 service-policy type service unapply identifier service-name 10 log-session-state subscriber rule-map IPoE-ISG condition always event service-stop 1 service-policy type service unapply identifier service-name 10 log-session-state subscriber rule-map default-internal-rule condition always event service-start 1 service-policy type service identifier service-name subscriber rule-map default-internal-rule condition always event service-start 1 service-policy type service identifier service-name Classifiers: Class-id Dir Packets Bytes Pri. Definition 0 In 238 30363 0 Match Any 1 Out 302 217183 0 Match Any 61470 In 10 1894 20 Match ACL traffic-for-redirect 61472 In 0 0 40 Match ACL limited-upstream-domonet 61473 Out 8 801 40 Match ACL limited-downstream-domonet 4294967294 In 0 0 - Drop 4294967295 Out 82 4048 - Drop Features: Idle Timeout: Class-id Dir Timeout value Idle-Time Source 0 In 900 00:02:36 Peruser Accounting: Class-id Dir Packets Bytes Source 0 In 278 35247 Peruser 1 Out 254 219620 Peruser 61472 In 0 0 OPENGARDEN 61473 Out 8 801 OPENGARDEN L4 Redirect: Class-id Rule cfg Definition Source 61470 #1 SVC to group NO-MONEY L4REDIRECT Policing: Class-id Dir Avg. Rate Normal Burst Excess Burst Source 61472 In 1024000 192000 384000 OPENGARDEN 61473 Out 1024000 192000 384000 OPENGARDEN Configuration Sources: Type Active Time AAA Service ID Name SVC 00:03:03 - L4REDIRECT SVC 00:03:03 2298484156 OPENGARDEN USR 00:23:53 - Peruser INT 00:23:53 - GigabitEthernet0/0/2.1001 IP адрес такой же.

Страница 1 из 2	Часовой пояс: UTC + 5 часов [ Летнее время ]
Powered by phpBB® Forum Software © phpBB Group http://www.phpbb.com/

Автор:	Amir [ 26 май 2014, 15:55 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Цитата: Параллельно вопрос - почему у сессий в биллинге (особенно у ISG) меняется начало (выделил темно красным), хотя видно что isg сессия на циске не пересоздается? У вас, видимо, указан session.split.onDeviceState=1, т.е. при смене состояния в биллинге сессия разделяется (логически в БД). Можно указать 0, если тарификация идет по RADIUS-атрибутам, а не по Netflow.

Автор:	survivor [ 26 май 2014, 15:57 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
был: Код: @Override public Object connectionModify( ServiceActivatorEvent e ) throws Exception { logger.debug( "connectionModify" ); if( e.getConnection().getDeviceId() != this.deviceId ) { logger.debug( "Skip " + e.getConnection() + " " + this.deviceId ); return null; } return super.connectionModify( e ); } стал: Код: public Object connectionModify( ServiceActivatorEvent e ) throws Exception { logger.debug( "connectionModify" ); if( e.getConnection().getDeviceId() != this.deviceId ) { logger.debug( "Skip " + e.getConnection() + " " + this.deviceId ); e.setConnectionStateModified( true ); // modification by Amir return null; } return super.connectionModify( e ); }

Автор:	survivor [ 26 май 2014, 15:58 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Цитата: У вас, видимо, указан session.split.onDeviceState=1, т.е. при смене состояния в биллинге сессия разделяется (логически в БД). Можно указать 0, если тарификация идет по RADIUS-атрибутам, а не по Netflow. ясно, поправил. Спасибо!

Автор:	Amir [ 26 май 2014, 16:01 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
А all.log из Access и Accounting не остался где есть эта сессия с 1 по 4?

Автор:	survivor [ 26 май 2014, 16:05 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
сейчас повторю, соберу логи

Автор:	survivor [ 26 май 2014, 16:28 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Ага, это все из-за session.split.onDeviceState. Вернул его в значение 1 и смог повторить ситуация: отключение проходит нормально, включение виснет. (При session.split.onDeviceState=0 все наоборот, не знаю как это связано...)

Автор:	Amir [ 26 май 2014, 16:34 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
В первом логе на CoA почему-то ISG не ответил. Может быть в CoA пакете неправильный IP, Acct-Session-Id или эти сервисы уже были отключены?

Автор:	Amir [ 26 май 2014, 16:37 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Странно, в обоих случаях не отвечал на CoA. В первом случае на отключение, а во втором, наоборот, на включение.

Автор:	survivor [ 26 май 2014, 17:22 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Amir писал(а): В первом логе на CoA почему-то ISG не ответил. Может быть в CoA пакете неправильный IP, Acct-Session-Id или эти сервисы уже были отключены? IP правильный, сервисы OPENGARDEN и L4REDIRECT еще не отключены, а вот как на циске посмотреть Acct-Session-Id пока не знаю

Автор:	survivor [ 26 май 2014, 17:30 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Amir, возможно какая-то проблема с циской. Потому что подвисшее соединение не мог ни сбить radclient'ом через CoA ни посмотреть его account-status-query. После того как сделал вручную clear на циске, для новой сессии account-status-query заработал...

Автор:	Amir [ 26 май 2014, 18:06 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
По логам тоже как-будто биллинг правильно все хочет сделать.

Автор:	survivor [ 26 май 2014, 18:26 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Да, думается дело в прошивке... Буду искать/пробовать иосы... Я правильно понимаю, что если я оставлю: sa.radius.connection.withoutBreak=0 и: radius.disable.accessCodes=1,2,3,4,10,11,12,46 radius.disable.attributes=Acct-Interim-Interval=120;Idle-Timeout=900;cisco-avpair=subscriber:accounting-list=ipoe-isg-aaa;cisco-SSG-Account-Info=AL4REDIRECT;cisco-SSG-Account-Info=AOPENGARDEN radius.serviceName.disable=L4REDIRECT,OPENGARDEN sa.radius.service.disable=L4REDIRECT,OPENGARDEN то все будет работать точно так же, только isg сессия будет каждый раз пересоздаваться? Похоже что сессия подвисает именно когда я меняю на ней сервисы - воспроизводится простым radclient'ом...

Автор:	Amir [ 26 май 2014, 18:44 ]
Заголовок сообщения:	Re: Изменение ISG сервисов без разрыва сессии
Вроде бы да. Будет слать account-logoff.