01-26/12:13:49  INFO [main] DefaultServerSetup - Binding javax.jms.ConnectionFactory[org.apache.activemq.ActiveMQConnectionFactory@546c585a] to java:comp/env/mq/connectionFactory
 01-26/12:13:49  INFO [main] DefaultServerSetup - Init DB connection pools
 01-26/12:13:49  INFO [main] DefaultServerSetup - Binding JDBC pool "master" to java:comp/env/jdbc/master
 01-26/12:13:50  INFO [main] DefaultServerSetup - Init trash pools..
mq 01-26/12:13:50  INFO [EventProcessor-init] EventProcessor - Init EventProcessor MQ connection factory...
access 01-26/12:13:52  INFO [main] InetApplication - rootDeviceId=1
access 01-26/12:13:52  INFO [main] InetDeviceRuntimeMap - (Re)loading InetDeviceRuntimeMap
access 01-26/12:13:52  INFO [main] InetDeviceMap - (Re)loading InetDeviceMap
access 01-26/12:13:52  INFO [main] InetDeviceRuntime - Reload protocolHandler class for device: Process group
access 01-26/12:13:52  INFO [main] InetDeviceRuntime - Reload SA classes for device: Process group
access 01-26/12:13:52  INFO [main] InetDeviceRuntime - Reload protocolHandler class for device: Redback: Redback-IPOE [10.1.1.1]
access 01-26/12:13:52  INFO [main] InetDeviceRuntime - Reload SA classes for device: Redback: Redback-IPOE [10.1.1.1]
access 01-26/12:13:52  INFO [main] SmartEdgeServiceActivator - Init script for device: 2
access 01-26/12:13:53  INFO [main] SmartEdgeServiceActivator - Options map size: 3
access 01-26/12:13:53  INFO [main] InetDeviceRuntime - Reload protocolHandler class for device: Des 3028: Des 3028 [10.147.0.101]
access 01-26/12:13:53  INFO [main] InetDeviceRuntime - Reload SA classes for device: Des 3028: Des 3028 [10.147.0.101]
access 01-26/12:13:53  INFO [main] DES320028ServiceActivator - INIT
access 01-26/12:13:53  INFO [main] SmartEdgeServiceActivator - Init script for device: 2
access 01-26/12:13:53  INFO [main] SmartEdgeServiceActivator - Options map size: 3
access 01-26/12:13:53  INFO [main] InetOptionRuntimeMap - Loading inetOptionRuntimeMap for moduleId:2
script 01-26/12:13:54  INFO [main] ScriptEventListener - Starting DynamicScriptEventListener...
script 01-26/12:13:54  INFO [main] ScriptEventListener - Starting ScriptEventListener...
script 01-26/12:13:54  INFO [main] ScriptEventListener - Relinking script functions.
access 01-26/12:13:54  INFO [main] Access - childrenDeviceIds=[1, 2, 3]
access 01-26/12:13:54  INFO [main] InetConnectionManager - Loading connections from database.
access 01-26/12:13:54  INFO [main] Setup - Load config for mid=2
access 01-26/12:13:54  INFO [main] InetServRuntimeMap - Loading inetServs from database.
access 01-26/12:13:54  INFO [main] InetServRuntimeMap - Adding InetServRuntime: 1
access 01-26/12:13:54  INFO [main] InetServRuntimeMap - ContractId: 2; servId: 1
   2
   Options [] TariffModuleTreeSet [2:28.12.2011-…; ]
   Device state: 1; optionSet:1
access 01-26/12:13:54  INFO [main] InetServRuntimeMap - Adding InetServRuntime: 2
access 01-26/12:13:54  INFO [main] InetServRuntimeMap - ContractId: 3; servId: 2
   3
   Options [] TariffModuleTreeSet [2:12.01.2012-…; ]
   Device state: 1; optionSet:
access 01-26/12:13:54  INFO [main] InetServRuntimeMap - Adding InetServRuntime: 3
access 01-26/12:13:54  INFO [main] InetServRuntimeMap - ContractId: 4; servId: 3
   4
   Options [] TariffModuleTreeSet [1:19.01.2012-…; ]
   Device state: 1; optionSet:
access 01-26/12:13:54  INFO [main] InetServRuntimeMap - Loaded 3 inetServs.
radius 01-26/12:13:55  INFO [main] radius - Eap not enabled (keystore file not loaded).
radius-processor 01-26/12:13:55  INFO [main] InetRadiusProcessor - Reloading nas list
radius-processor 01-26/12:13:55  INFO [main] InetNasList - Loading NAS list...
radius-processor 01-26/12:13:55  INFO [main] NasList - LOADED NAS: Nas id: Redback-IPOE; ip: 10.1.1.1
CONFIG:
accounting.worker.1.tariffication.1.batchSize=100
accounting.worker.1.tariffication.1.delay=1
accounting.worker.1.tariffication.1.minDeltaAmount=1
accounting.worker.1.thread.count=1
accounting.worker.1.tracking.1.batchSize=100
accounting.worker.1.tracking.1.delay=10
accounting.worker.2.flushing.1.batchSize=500
accounting.worker.2.flushing.1.delay=20
accounting.worker.2.flushing.1.minDeltaAccount=0
accounting.worker.2.thread.count=1
accounting.worker.3.finishing.1.batchSize=500
accounting.worker.3.finishing.1.delay=10
accounting.worker.3.thread.count=1
connection.close.timeout=900
connection.suspend.timeout=900
const.access.attributes=Acct-Interim-Interval=900
dhcp.relay.deviceTypeIds=1
nas.radius.deviceTypeIds=2
nas.radius.disable.attributes=IP-Interface-Name=2core;HTTP-Redirect-Profile-Name=noauth;Forward-Policy=in:HTTP-REDIRECT;Acct-Interim-Interval=900
nas.radius.disable.ipCategories=2
nas.radius.disable.pattern.attributes=HTTP-Redirect-Profile-Name=noauth
nas.radius.inetOption.1.attributes=Acct-Interim-Interval=900;Sub-Profile-Name=bronze
nas.radius.inetOption.2.attributes=Acct-Interim-Interval=900;Sub-Profile-Name=gold
nas.radius.inetOption.3.attributes=Acct-Interim-Interval=900;Sub-Profile-Name=platinum
option.1.attributes=Sub-Profile-Name=bronze
option.2.attributes=Sub-Profile-Name=gold
option.3.attributes=Sub-Profile-Name=platinum
radius.deviceTypeIds=2
radius.disable.attributes=IP-Interface-Name=2core;HTTP-Redirect-Profile-Name=noauth;Forward-Policy=in:HTTP-REDIRECT;Acct-Interim-Interval=900
radius.disable.ipCategories=2
radius.disable.pattern.attributes=HTTP-Redirect-Profile-Name=noauth
radius.inetOption.1.attributes=Acct-Interim-Interval=900;Sub-Profile-Name=bronze
radius.inetOption.2.attributes=Acct-Interim-Interval=900;Sub-Profile-Name=gold
radius.inetOption.3.attributes=Acct-Interim-Interval=900;Sub-Profile-Name=platinum
redirect.attributes=HTTP-Redirect-Profile-Name=noauth;Forward-Policy=in:HTTP-REDIRECT;Acct-Interim-Interval=900
sa.batch.pause=0
sa.batch.size=20
sa.batch.wait=5
sa.batch.waitNext=5
sa.error.pause=60
sa.radius.connection.attributes=Acct-Session-Id
sa.radius.disable.attributes=HTTP-Redirect-Profile-Name=noauth;Forward-Policy=in:HTTP-REDIRECT;Acct-Interim-Interval=900
sa.radius.option.attributesPrefix=option.

access 01-26/12:13:55  INFO [main] Application - Starting ru.bitel.bgbilling.modules.inet.radius.InetRadiusListener@221a5770
access 01-26/12:13:55  INFO [main] DatagramChannelListener - Open socket [0.0.0.0/0.0.0.0:1812]
access 01-26/12:13:55  INFO [main] DatagramChannelListener - ru.bitel.bgbilling.modules.inet.radius.InetRadiusListener socket init ok.
radius 01-26/12:15:34  INFO [rdsLstnr-p-10-t-1] RadiusListenerWorker - REQUEST:
Packet type: Access-Request
Identifier: 89
Authenticator: {26 BD 49 B5 DD 3C 84 F1 AA 0B 73 E7 75 C2 0E 26}
Attributes:
  User-Name=2
  NAS-Port-Id=2/1 vlan-id 813 clips 2
  NAS-Identifier=Redback-IPOE
  User-Password=Redback
  NAS-IP-Address=10.1.1.1
  NAS-Port=553648941
  Service-Type=5
  NAS-Port-Type=5
  Platform-Type=4
  Medium-Type=11
  OS-Version=6.4.1.3
  NAS-Real-Port=553648941

radius 01-26/12:15:34  INFO [rdsLstnr-p-10-t-1] InetRadiusProcessor - REQUEST_AFTER_PREPROCESS:
Packet type: Access-Request
Identifier: 89
Authenticator: {26 BD 49 B5 DD 3C 84 F1 AA 0B 73 E7 75 C2 0E 26}
Attributes:
  User-Name=2
  NAS-Port-Id=2/1 vlan-id 813 clips 2
  NAS-Identifier=Redback-IPOE
  User-Password=Redback
  NAS-IP-Address=10.1.1.1
  NAS-Port=553648941
  Service-Type=5
  NAS-Port-Type=5
  Platform-Type=4
  Medium-Type=11
  OS-Version=6.4.1.3
  NAS-Real-Port=553648941

radius 01-26/12:15:34  INFO [rdsLstnr-p-10-t-1] InetRadiusProcessor - [username=2] Authenticated as inetServId:1
radius 01-26/12:15:34  INFO [rdsLstnr-p-10-t-1] Access - inetServ[id=1] balance ok: 0.00 [0]
radius 01-26/12:15:34  INFO [rdsLstnr-p-10-t-1] HourlyDataLogEntry - Create dataLog file: /usr/local/BGInetAccess/data/radius/source_2/2012/2012-01/2012-01-26/log_2012-01-26-12.001.bgdl
radius 01-26/12:15:34  INFO [rdsLstnr-p-10-t-1] InetRadiusListenerWorker - RESPONSE:
Packet type: Access-Reject
Identifier: 89
Authenticator: {F2 3D 5B A8 19 DF 1B B0 D6 F4 89 A0 91 5E 80 3D}
Attributes:

Process time auth: 186

radius 01-26/12:15:34 ERROR [rdsLstnr-p-10-t-1] RadiusListenerWorker -
java.lang.NullPointerException
   at ru.bitel.bgbilling.modules.inet.runtime.InetApplication.tarifficate(InetApplication.java:207)
   at ru.bitel.bgbilling.modules.inet.runtime.InetApplication.checkTariffAndGetOptions(InetApplication.java:285)
   at ru.bitel.bgbilling.modules.inet.access.Access.authorization(Access.java:291)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.authorization(InetRadiusProcessor.java:429)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.authenticationImpl(InetRadiusProcessor.java:406)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.authentication(InetRadiusProcessor.java:315)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.authentication(InetRadiusProcessor.java:1)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusSession.authentication(RadiusSession.java:114)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusSession.accessRequest(RadiusSession.java:92)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accessRequestImpl(RadiusProcessor.java:360)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.accessRequestImpl(InetRadiusProcessor.java:276)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.accessRequestImpl(InetRadiusProcessor.java:1)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accessRequest(RadiusProcessor.java:347)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusListenerWorker.accessRequest(InetRadiusListenerWorker.java:55)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusListenerWorker.accessRequest(InetRadiusListenerWorker.java:1)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.processPacket(RadiusListenerWorker.java:163)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.runImpl(RadiusListenerWorker.java:87)
   at ru.bitel.common.worker.WorkerTask.run(WorkerTask.java:86)
   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)
radius 01-26/12:15:45  INFO [rdsLstnr-p-10-t-3] RadiusListenerWorker - REQUEST:
Packet type: Access-Request
Identifier: 89
Authenticator: {26 BD 49 B5 DD 3C 84 F1 AA 0B 73 E7 75 C2 0E 26}
Attributes:
  User-Name=2
  NAS-Port-Id=2/1 vlan-id 813 clips 2
  NAS-Identifier=Redback-IPOE
  User-Password=Redback
  NAS-IP-Address=10.1.1.1
  NAS-Port=553648941
  Service-Type=5
  NAS-Port-Type=5
  Platform-Type=4
  Medium-Type=11
  OS-Version=6.4.1.3
  NAS-Real-Port=553648941

radius 01-26/12:15:45  INFO [rdsLstnr-p-10-t-2] RadiusListenerWorker - REQUEST:
Packet type: Access-Request
Identifier: 90
Authenticator: {09 89 32 FA 84 17 69 E4 2D A6 CB 1B E3 0B 80 62}
Attributes:
  User-Name=3
  NAS-Port-Id=2/1 vlan-id 813 clips 3
  NAS-Identifier=Redback-IPOE
  User-Password=Redback
  NAS-IP-Address=10.1.1.1
  NAS-Port=553648941
  Service-Type=5
  NAS-Port-Type=5
  Platform-Type=4
  Medium-Type=11
  OS-Version=6.4.1.3
  NAS-Real-Port=553648941

radius 01-26/12:15:45  INFO [rdsLstnr-p-10-t-2] InetRadiusProcessor - REQUEST_AFTER_PREPROCESS:
Packet type: Access-Request
Identifier: 90
Authenticator: {09 89 32 FA 84 17 69 E4 2D A6 CB 1B E3 0B 80 62}
Attributes:
  User-Name=3
  NAS-Port-Id=2/1 vlan-id 813 clips 3
  NAS-Identifier=Redback-IPOE
  User-Password=Redback
  NAS-IP-Address=10.1.1.1
  NAS-Port=553648941
  Service-Type=5
  NAS-Port-Type=5
  Platform-Type=4
  Medium-Type=11
  OS-Version=6.4.1.3
  NAS-Real-Port=553648941

radius 01-26/12:15:45  INFO [rdsLstnr-p-10-t-3] InetRadiusProcessor - REQUEST_AFTER_PREPROCESS:
Packet type: Access-Request
Identifier: 89
Authenticator: {26 BD 49 B5 DD 3C 84 F1 AA 0B 73 E7 75 C2 0E 26}
Attributes:
  User-Name=2
  NAS-Port-Id=2/1 vlan-id 813 clips 2
  NAS-Identifier=Redback-IPOE
  User-Password=Redback
  NAS-IP-Address=10.1.1.1
  NAS-Port=553648941
  Service-Type=5
  NAS-Port-Type=5
  Platform-Type=4
  Medium-Type=11
  OS-Version=6.4.1.3
  NAS-Real-Port=553648941

radius 01-26/12:15:45  INFO [rdsLstnr-p-10-t-2] InetRadiusProcessor - [username=3] Authenticated as inetServId:2
radius 01-26/12:15:45  INFO [rdsLstnr-p-10-t-3] InetRadiusProcessor - [username=2] Authenticated as inetServId:1
radius 01-26/12:15:45  INFO [rdsLstnr-p-10-t-3] Access - inetServ[id=1] balance ok: 0.00 [0]
radius 01-26/12:15:45  INFO [rdsLstnr-p-10-t-3] InetRadiusListenerWorker - RESPONSE:
Packet type: Access-Reject
Identifier: 89
Authenticator: {F2 3D 5B A8 19 DF 1B B0 D6 F4 89 A0 91 5E 80 3D}
Attributes:

Process time auth: 17

radius 01-26/12:15:45 ERROR [rdsLstnr-p-10-t-3] RadiusListenerWorker -
java.lang.NullPointerException
   at ru.bitel.bgbilling.modules.inet.runtime.InetApplication.tarifficate(InetApplication.java:207)
   at ru.bitel.bgbilling.modules.inet.runtime.InetApplication.checkTariffAndGetOptions(InetApplication.java:285)
   at ru.bitel.bgbilling.modules.inet.access.Access.authorization(Access.java:291)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.authorization(InetRadiusProcessor.java:429)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.authenticationImpl(InetRadiusProcessor.java:406)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.authentication(InetRadiusProcessor.java:315)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.authentication(InetRadiusProcessor.java:1)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusSession.authentication(RadiusSession.java:114)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusSession.accessRequest(RadiusSession.java:92)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accessRequestImpl(RadiusProcessor.java:360)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.accessRequestImpl(InetRadiusProcessor.java:276)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.accessRequestImpl(InetRadiusProcessor.java:1)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accessRequest(RadiusProcessor.java:347)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusListenerWorker.accessRequest(InetRadiusListenerWorker.java:55)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusListenerWorker.accessRequest(InetRadiusListenerWorker.java:1)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.processPacket(RadiusListenerWorker.java:163)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.runImpl(RadiusListenerWorker.java:87)
   at ru.bitel.common.worker.WorkerTask.run(WorkerTask.java:86)
   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)
radius 01-26/12:15:45  INFO [rdsLstnr-p-10-t-2] Access - inetServ[id=2] balance ok: 0.00 [0]
radius 01-26/12:15:45  INFO [rdsLstnr-p-10-t-2] InetRadiusListenerWorker - RESPONSE:
Packet type: Access-Reject
Identifier: 90
Authenticator: {86 6F 54 B4 43 1B 4D 52 89 37 F5 97 42 B8 FB 1F}
Attributes:

Process time auth: 31

radius 01-26/12:15:45 ERROR [rdsLstnr-p-10-t-2] RadiusListenerWorker -
java.lang.NullPointerException
   at ru.bitel.bgbilling.modules.inet.runtime.InetApplication.tarifficate(InetApplication.java:207)
   at ru.bitel.bgbilling.modules.inet.runtime.InetApplication.checkTariffAndGetOptions(InetApplication.java:285)
   at ru.bitel.bgbilling.modules.inet.access.Access.authorization(Access.java:291)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.authorization(InetRadiusProcessor.java:429)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.authenticationImpl(InetRadiusProcessor.java:406)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.authentication(InetRadiusProcessor.java:315)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.authentication(InetRadiusProcessor.java:1)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusSession.authentication(RadiusSession.java:114)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusSession.accessRequest(RadiusSession.java:92)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accessRequestImpl(RadiusProcessor.java:360)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.accessRequestImpl(InetRadiusProcessor.java:276)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.accessRequestImpl(InetRadiusProcessor.java:1)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accessRequest(RadiusProcessor.java:347)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusListenerWorker.accessRequest(InetRadiusListenerWorker.java:55)
   at ru.bitel.bgbilling.modules.inet.radius.InetRadiusListenerWorker.accessRequest(InetRadiusListenerWorker.java:1)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.processPacket(RadiusListenerWorker.java:163)
   at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.runImpl(RadiusListenerWorker.java:87)
   at ru.bitel.common.worker.WorkerTask.run(WorkerTask.java:86)
   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)