BiTel

radius 12-10/09:06:02  INFO [rdsLstnr-p-8-t-2] RadiusListenerWorker - REQUEST:
Packet type: Access-Request
Identifier: 191
Authenticator: {08 31 E4 7B 09 49 75 86 BE 35 75 E5 30 AC 68 E0}
Attributes:
  User-Name=d4:ca:6d:53:35:d0
  NAS-Port-Id=2/2 vlan-id 100:11 clips 183472
  NAS-Identifier=SE100-test-CLIPS
  User-Password=Redback
  NAS-IP-Address=10.0.0.11
  UNKNOWN[2352-202]={3D 3D 07 01 D4 CA 6D 53 35 D0}
  UNKNOWN[2352-202]={0C 0C 0B 6F 66 66 69 63 65 2D 77 69 66 69}
  Agent-Circuit-Id={00 04 00 0B 00 1A}
  OS-Version=12.1.1.5
  Mac-Addr=d4:ca:6d:53:35:d0
  NAS-Real-Port=570834955
  UNKNOWN[3561--1]={02 0A 00 06 AC F1 DF A7 BF 40}
  UNKNOWN[3561--1]={01 08 00 04 00 0B 00 1A}

radius 12-10/09:06:02 DEBUG [rdsLstnr-p-8-t-2] AbstractRadiusProtocolHandler - State is enable (from attributes)
radius 12-10/09:06:02  INFO [rdsLstnr-p-8-t-2] InetRadiusProcessor - REQUEST_AFTER_PREPROCESS:
Packet type: Access-Request
Identifier: 191
Authenticator: {08 31 E4 7B 09 49 75 86 BE 35 75 E5 30 AC 68 E0}
Attributes:
  User-Name=d4:ca:6d:53:35:d0
  NAS-Port-Id=2/2 vlan-id 100:11 clips 183472
  NAS-Identifier=SE100-test-CLIPS
  User-Password=Redback
  NAS-IP-Address=10.0.0.11
  NAS-Port=570834955
  Service-Type=5
  NAS-Port-Type=5
  Platform-Type=4
  Medium-Type=11
  Agent-Remote-Id={00 06 AC F1 DF A7 BF 40}
  UNKNOWN[2352-202]={3D 3D 07 01 D4 CA 6D 53 35 D0}
  UNKNOWN[2352-202]={0C 0C 0B 6F 66 66 69 63 65 2D 77 69 66 69}
  Agent-Circuit-Id={00 04 00 0B 00 1A}
  OS-Version=12.1.1.5
  Mac-Addr=d4:ca:6d:53:35:d0
  NAS-Real-Port=570834955
  UNKNOWN[3561--1]={02 0A 00 06 AC F1 DF A7 BF 40}
  UNKNOWN[3561--1]={01 08 00 04 00 0B 00 1A}
Common options: {agentRemoteId={acf1dfa7bf40}, agentCircuitId={000b001a}, deviceState=1}
radius 12-10/09:06:02 DEBUG [rdsLstnr-p-8-t-2] RadiusProcessor - Create new radius session.
radius 12-10/09:06:02 DEBUG [rdsLstnr-p-8-t-2] InetNas - agentRemoteId=java.nio.DirectByteBufferR[pos=0 lim=6 cap=6]
radius 12-10/09:06:02  INFO [rdsLstnr-p-8-t-2] InetNas - Found agentDevice:4
radius 12-10/09:06:02 DEBUG [rdsLstnr-p-8-t-2] InetNas - findServ agentDeviceRuntime=ru.bitel.bgbilling.modules.inet.runtime.device.InetDeviceRuntime@2904b5ae
radius 12-10/09:06:02  INFO [rdsLstnr-p-8-t-2] InetNas - Search serv on deviceId=4; interfaceId=26
radius 12-10/09:06:02 DEBUG [rdsLstnr-p-8-t-2] InetRadiusProcessor - Password verification disabled.
radius 12-10/09:06:02  INFO [rdsLstnr-p-8-t-2] InetRadiusProcessor - [username=d4:ca:6d:53:35:d0] Authenticated as inetServId:6
radius 12-10/09:06:02 DEBUG [rdsLstnr-p-8-t-2] InetRadiusProcessor - Identifier from request: null
radius 12-10/09:06:02 DEBUG [rdsLstnr-p-8-t-2] InetRadiusProcessor - MAC-address from request:
radius 12-10/09:06:02 DEBUG [rdsLstnr-p-8-t-2] InetAccountingPeriodList - Create:
                AccountingPeriod: 2: 02.12.2013 00:00:00.0 - 31.12.2013 23:59:59.999
radius 12-10/09:06:02  INFO [rdsLstnr-p-8-t-2] InetApplication - inetServ[id=6] balance ok: 0.00 [0]
radius 12-10/09:06:02  INFO [rdsLstnr-p-8-t-2] InetApplication - TariffOptionMap: {}
radius 12-10/09:06:02  INFO [rdsLstnr-p-8-t-2] InetApplication - OptionSet: [1]
radius 12-10/09:06:02  INFO [rdsLstnr-p-8-t-2] InetRadiusProcessor - Not found free IP-address in serv
radius 12-10/09:06:02  INFO [rdsLstnr-p-8-t-2] InetRadiusProcessor - Set ip from pool
radius 12-10/09:06:02  INFO [rdsLstnr-p-8-t-2] InetRadiusProcessor - Return code=0
radius 12-10/09:06:02  INFO [rdsLstnr-p-8-t-2] InetRadiusProcessor - RESPONSE_BEFORE_POSTPROCESS:
Packet type: Access-Accept
Identifier: 191
Authenticator: {}
Attributes:
  Acct-Interim-Interval=900
  Framed-IP-Address=1.1.1.18
  DHCP-Max-Leases=1
  Service-Name:1=RSE-SVC-EXT
  Service-Options:1=1
  Service-Parameter:1=Rate=10000 Burst=1250000
  IP-Interface-Name=CLIENTS

Process time auth: 16

dhcp 12-10/09:06:02 DEBUG [ip-dyn-reserve-p-14-t-1] IpResourceReserveManager - Deleted 2 old IPs
radius 12-10/09:06:02 DEBUG [rdsLstnr-p-8-t-2] ProcessorRequest - Sending to /10.0.0.11:1812
radius 12-10/09:06:02  INFO [rdsLstnr-p-8-t-2] InetRadiusListenerWorker - RESPONSE:
Packet type: Access-Accept
Identifier: 191
Authenticator: {CE 10 F5 25 ED 40 4C A3 2A BB 7D 7D 23 66 AD C5}
Attributes:
  Acct-Interim-Interval=900
  DHCP-Max-Leases=1
  Service-Name:1=RSE-SVC-EXT
  Service-Options:1=1
  Service-Parameter:1=Rate=10000 Burst=1250000
  IP-Interface-Name=CLIENTS

Process time auth: 23

connection 12-10/09:06:02  INFO [sa-p-12-t-3] ServiceActivatorSet - Connecting to device
connection 12-10/09:06:02 DEBUG [sa-p-12-t-3] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 1; deviceId: 3; connectionId: 43742; timestamp: 1386644762876
connection 12-10/09:06:02  INFO [sa-p-12-t-3] ServiceActivatorDeviceWorker - Do task deviceId: 3; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 1; deviceId: 3; connectionId: 43742; timestamp: 1386644762876
connection 12-10/09:06:02  INFO [sa-p-12-t-3] InetApplication - TariffOptionMap: {}
connection 12-10/09:06:02  INFO [sa-p-12-t-3] InetApplication - OptionSet: [1]
connection 12-10/09:06:02  INFO [sa-p-12-t-3] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-10/09:06:02  INFO [sa-p-12-t-3] ServiceActivatorDeviceWorker - Processing deviceId:3; command ServiceActivatorEvent type=4; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-10/09:06:02  INFO [sa-p-12-t-3] ServiceActivatorSet - Invoking onAccountingStart
connection 12-10/09:06:02  INFO [sa-p-12-t-3] ServiceActivatorDeviceWorker - Process event type[4] result=true
connection 12-10/09:06:02 DEBUG [sa-p-12-t-3] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 1; deviceId: 3; connectionId: 43743; timestamp: 1386644762930
connection 12-10/09:06:02  INFO [sa-p-12-t-3] ServiceActivatorDeviceWorker - Do task deviceId: 3; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 1; deviceId: 3; connectionId: 43743; timestamp: 1386644762930
connection 12-10/09:06:02  INFO [sa-p-12-t-3] InetApplication - TariffOptionMap: {}
connection 12-10/09:06:02  INFO [sa-p-12-t-3] InetApplication - OptionSet: [1]
connection 12-10/09:06:02  INFO [sa-p-12-t-3] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-10/09:06:02  INFO [sa-p-12-t-3] ServiceActivatorDeviceWorker - Processing deviceId:3; command ServiceActivatorEvent type=4; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-10/09:06:02  INFO [sa-p-12-t-3] ServiceActivatorSet - Invoking onAccountingStart
connection 12-10/09:06:02  INFO [sa-p-12-t-3] ServiceActivatorDeviceWorker - Process event type[4] result=true
dhcp 12-10/09:06:02  INFO [dhcpLstnr-p-10-t-7] InetAbstractDhcpProcessor - REQUEST:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Discover{1}
htype: 1, hlen: 6, hops: 1
xid: 1667481522, secs: 2, flags: -32768
Client IP: 0.0.0.0
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 1.1.1.1
Client MAC: {D4CA6D5335D0}
  Parameter request list{55}={1, 121, 3, 33, 6, 42}
  Host name{12}={office-wifi}
  {61}={01D4CA6D5335D0}
  Agent information{82}=
    sub{1}={0004000B001A}
    sub{2}={0006ACF1DFA7BF40}

dhcp 12-10/09:06:02 DEBUG [dhcpLstnr-p-10-t-7] InetAbstractDhcpProcessor - OP_BOOT_REQUEST
dhcp 12-10/09:06:02 DEBUG [dhcpLstnr-p-10-t-7] InetAbstractDhcpProcessor - Found device by giaddr id=3
dhcp 12-10/09:06:02  INFO [dhcpLstnr-p-10-t-7] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Discover{1}
htype: 1, hlen: 6, hops: 1
xid: 1667481522, secs: 2, flags: -32768
Client IP: 0.0.0.0
  Host name{12}={office-wifi}
  {61}={01D4CA6D5335D0}
  Agent information{82}=
    sub{1}={0004000B001A}
    sub{2}={0006ACF1DFA7BF40}

dhcp 12-10/09:06:02 DEBUG [dhcpLstnr-p-10-t-7] InetAbstractDhcpProcessor - Found subDevice by identifier id=4
dhcp 12-10/09:06:02 DEBUG [dhcpLstnr-p-10-t-7] InetDhcpProcessor - DHCP_DISCOVER
dhcp 12-10/09:06:02 DEBUG [dhcpLstnr-p-10-t-7] InetDhcpProcessor - request.giaddr= 1.1.1.1, clientAddress=/10.0.0.11:67
dhcp 12-10/09:06:02  INFO [dhcpLstnr-p-10-t-7] InetDhcpDevice - Search serv on deviceId: 4; 1; interfaceId: 26
dhcp 12-10/09:06:02  INFO [dhcpLstnr-p-10-t-7] InetDhcpProcessor - InetServ found: ContractId: 1; status: 0; servId: 6

        Options [1:04.12.2013-01.01.1970; ] TariffModuleTreeSet [4:27.11.2013-…; ]
        Device state: 1; optionSet:1
dhcp 12-10/09:06:03 DEBUG [dhcpLstnr-p-10-t-7] InetAccountingPeriodList - Create:
                AccountingPeriod: 2: 02.12.2013 00:00:00.0 - 31.12.2013 23:59:59.999
dhcp 12-10/09:06:03  INFO [dhcpLstnr-p-10-t-7] InetApplication - inetServ[id=6] balance ok: 0.00 [0]
dhcp 12-10/09:06:03  INFO [dhcpLstnr-p-10-t-7] InetApplication - TariffOptionMap: {}
dhcp 12-10/09:06:03  INFO [dhcpLstnr-p-10-t-7] InetApplication - OptionSet: [1]
dhcp 12-10/09:06:03  INFO [dhcpLstnr-p-10-t-7] InetDhcpProcessor - IP not found in service. Searching in device...
dhcp 12-10/09:06:03  INFO [dhcpLstnr-p-10-t-7] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP Offer{2}
htype: 1, hlen: 6, hops: 1
xid: 1667481522, secs: 0, flags: -32768
Client IP: 0.0.0.0
Your IP: 1.1.1.19
Server IP: 0.0.0.0
Relay IP: 1.1.1.1
Client MAC: {D4CA6D5335D0}
  Agent information{82}=
    sub{1}={0004000B001A}
    sub{2}={0006ACF1DFA7BF40}
  Router{3}=1.1.1.1
  Subnet mask{1}=255.255.255.0
  DNS{6}={50F420B4}
  IP Address Lease Time{51}=900
  Server Identifier{54}={00000000}

dhcp 12-10/09:06:03 DEBUG [dhcpLstnr-p-10-t-7] ProcessorRequest - Sending to /10.0.0.11:67
dhcp 12-10/09:06:03 DEBUG [ip-dyn-reserve-p-14-t-1] IpResourceReserveManager - Deleted 0 old IPs
dhcp 12-10/09:06:03  INFO [dhcpLstnr-p-10-t-9] InetAbstractDhcpProcessor - REQUEST:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1667481522, secs: 2, flags: -32768
Client IP: 0.0.0.0
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 1.1.1.1
Client MAC: {D4CA6D5335D0}
  Server Identifier{54}={C0A83211}
  Requested IP Address{50}=1.1.1.19
  Parameter request list{55}={1, 121, 3, 33, 6, 42}
  Host name{12}={office-wifi}
  {61}={01D4CA6D5335D0}
  Agent information{82}=
    sub{1}={0004000B001A}
    sub{2}={0006ACF1DFA7BF40}

dhcp 12-10/09:06:03 DEBUG [dhcpLstnr-p-10-t-9] InetAbstractDhcpProcessor - OP_BOOT_REQUEST
dhcp 12-10/09:06:03 DEBUG [dhcpLstnr-p-10-t-9] InetAbstractDhcpProcessor - Found device by giaddr id=3
dhcp 12-10/09:06:03  INFO [dhcpLstnr-p-10-t-9] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1667481522, secs: 2, flags: -32768
Client IP: 0.0.0.0
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 1.1.1.1
Client MAC: {D4CA6D5335D0}
  Server Identifier{54}={C0A83211}
  Requested IP Address{50}=1.1.1.19
  Parameter request list{55}={1, 121, 3, 33, 6, 42}
  Host name{12}={office-wifi}
  {61}={01D4CA6D5335D0}
  Agent information{82}=
    sub{1}={0004000B001A}
    sub{2}={0006ACF1DFA7BF40}

dhcp 12-10/09:06:03 DEBUG [dhcpLstnr-p-10-t-9] InetAbstractDhcpProcessor - Found subDevice by identifier id=4
dhcp 12-10/09:06:03 DEBUG [dhcpLstnr-p-10-t-9] InetDhcpProcessor - DHCP_REQUEST
dhcp 12-10/09:06:03 DEBUG [dhcpLstnr-p-10-t-9] InetDhcpProcessor - request.giaddr= 1.1.1.1, clientAddress=/10.0.0.11:67
dhcp 12-10/09:06:03  INFO [dhcpLstnr-p-10-t-9] InetDhcpDevice - Search serv on deviceId: 4; 1; interfaceId: 26
dhcp 12-10/09:06:03  INFO [dhcpLstnr-p-10-t-9] InetDhcpProcessor - InetServ found: ContractId: 1; status: 0; servId: 6

        Options [1:04.12.2013-01.01.1970; ] TariffModuleTreeSet [4:27.11.2013-…; ]
        Device state: 1; optionSet:1
dhcp 12-10/09:06:03  INFO [dhcpLstnr-p-10-t-9] InetDhcpProcessor - Starting connection: InetConnection [id=0-0, iface=4:26, sessId=6363bfb2, start=10.12.2013 09:06:03, uname=null, addr=1.1.1.19]
mq 12-10/09:06:03 DEBUG [dhcpLstnr-p-10-t-9] EventProcessor - Request, timeout 4000 : Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingManageEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: -1; type: 1; deviceId: 4; connectionId: 0; timestamp: 1386644763135
dhcp 12-10/09:06:03  INFO [dhcpLstnr-p-10-t-9] InetConnectionManager - Add connection: InetConnection [id=43744-0, iface=4:26, sessId=6363bfb2, start=10.12.2013 09:06:03, uname=null, addr=1.1.1.19]
dhcp 12-10/09:06:03  INFO [dhcpLstnr-p-10-t-9] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP ACK{5}
htype: 1, hlen: 6, hops: 1
xid: 1667481522, secs: 0, flags: -32768
Client IP: 0.0.0.0
Your IP: 1.1.1.19
Server IP: 0.0.0.0
Relay IP: 1.1.1.1
Client MAC: {D4CA6D5335D0}
  Agent information{82}=
    sub{1}={0004000B001A}
    sub{2}={0006ACF1DFA7BF40}
  Router{3}=1.1.1.1
  Subnet mask{1}=255.255.255.0
  DNS{6}={50F420B4}
  IP Address Lease Time{51}=900
  Server Identifier{54}={00000000}

dhcp 12-10/09:06:03 DEBUG [dhcpLstnr-p-10-t-9] ProcessorRequest - Sending to /10.0.0.11:67
connection 12-10/09:06:03  INFO [sa-p-12-t-1] ServiceActivatorSet - Connecting to device
connection 12-10/09:06:03 DEBUG [sa-p-12-t-1] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 1; deviceId: 4; connectionId: 43744; timestamp: 1386644763148
connection 12-10/09:06:03  INFO [sa-p-12-t-1] ServiceActivatorDeviceWorker - Do task deviceId: 4; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 1; deviceId: 4; connectionId: 43744; timestamp: 1386644763148
connection 12-10/09:06:03  INFO [sa-p-12-t-1] InetApplication - TariffOptionMap: {}
connection 12-10/09:06:03  INFO [sa-p-12-t-1] InetApplication - OptionSet: [1]
connection 12-10/09:06:03  INFO [sa-p-12-t-1] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-10/09:06:03  INFO [sa-p-12-t-1] ServiceActivatorDeviceWorker - Processing deviceId:4; command ServiceActivatorEvent type=4; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-10/09:06:03  INFO [sa-p-12-t-1] ServiceActivatorSet - Invoking onAccountingStart
connection 12-10/09:06:03  INFO [sa-p-12-t-1] ServiceActivatorDeviceWorker - Process event type[4] result=true
mq 12-10/09:06:03 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 1; deviceId: 3; connectionId: 43742; timestamp: 1386644762876
mq 12-10/09:06:03  INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=43742-0, iface=3:570834955, sessId=0101FFFF7800CCB0-52A6851A, start=10.12.2013 09:06:02, uname=d4:ca:6d:53:35:d0, addr=[IpAddress:null]]
mq 12-10/09:06:03 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 1; deviceId: 3; connectionId: 43743; timestamp: 1386644762930
mq 12-10/09:06:03  INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=43743-43742, iface=3:570834955, sessId=0101FFFF7800CCB0-52A6851A-RSE-SVC-EXT-F63D4A98, start=10.12.2013 09:06:02, uname=RSE-SVC-EXT, addr=[IpAddress:null]]
mq 12-10/09:06:03 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 3; deviceId: 3; connectionId: 43742; timestamp: 1386644763022
mq 12-10/09:06:03  INFO [event-proc-p-2-t-1] InetConnectionManager - Update connection: InetConnection [id=43742-0, iface=3:570834955, sessId=0101FFFF7800CCB0-52A6851A, start=10.12.2013 09:06:02, uname=d4:ca:6d:53:35:d0, addr=[IpAddress:null]]
mq 12-10/09:06:03 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 1; deviceId: 4; connectionId: 43744; timestamp: 1386644763148
mq 12-10/09:06:03  INFO [event-proc-p-2-t-1] InetConnectionManager - Already added: InetConnection [id=43744-0, iface=4:26, sessId=6363bfb2, start=10.12.2013 09:06:03, uname=null, addr=1.1.1.19]
mq 12-10/09:06:04 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.oss.systems.inventory.resource.common.event.IpResourceSubscribedEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: -1; timestamp: 1386644763148
connection 12-10/09:06:07  INFO [sa-p-12-t-3] ServiceActivatorSet - Disconnecting from device
connection 12-10/09:06:08  INFO [sa-p-12-t-1] ServiceActivatorSet - Disconnecting from device

radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] RadiusListenerWorker - REQUEST:
Packet type: Access-Request
Identifier: 6
Authenticator: {C1 BE 98 F0 D7 5E EB 3F DF 35 89 D8 92 0E C9 1F}
Attributes:
  User-Name=d4:ca:6d:53:35:d0
  NAS-Port-Id=2/2 vlan-id 100:11 clips 131079
  NAS-Identifier=SE100-test-CLIPS
  User-Password=Redback
  NAS-IP-Address=10.0.0.11
  NAS-Port=570834955
  Service-Type=5
  NAS-Port-Type=5
  Platform-Type=4
  Medium-Type=11
  Agent-Remote-Id={00 06 AC F1 DF A7 BF 40}
  UNKNOWN[2352-202]={3D 3D 07 01 D4 CA 6D 53 35 D0}
  UNKNOWN[2352-202]={0C 0C 0B 6F 66 66 69 63 65 2D 77 69 66 69}
  Agent-Circuit-Id={00 04 00 0B 00 1A}
  OS-Version=12.1.1.5
  Mac-Addr=d4:ca:6d:53:35:d0
  NAS-Real-Port=570834955
  UNKNOWN[3561--1]={02 0A 00 06 AC F1 DF A7 BF 40}
  UNKNOWN[3561--1]={01 08 00 04 00 0B 00 1A}

radius 12-18/12:22:43 DEBUG [rdsLstnr-p-8-t-5] AbstractRadiusProtocolHandler - State is enable (from attributes)
radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] InetRadiusProcessor - REQUEST_AFTER_PREPROCESS:
Packet type: Access-Request
Identifier: 6
Authenticator: {C1 BE 98 F0 D7 5E EB 3F DF 35 89 D8 92 0E C9 1F}
Attributes:
  User-Name=d4:ca:6d:53:35:d0
  NAS-Port-Id=2/2 vlan-id 100:11 clips 131079
  NAS-Identifier=SE100-Lenina93-CLIPS
  Agent-Circuit-Id={00 04 00 0B 00 1A}
  OS-Version=12.1.1.5
  Mac-Addr=d4:ca:6d:53:35:d0
  NAS-Real-Port=570834955
  UNKNOWN[3561--1]={02 0A 00 06 AC F1 DF A7 BF 40}
  UNKNOWN[3561--1]={01 08 00 04 00 0B 00 1A}
Common options: {agentRemoteId={acf1dfa7bf40}, agentCircuitId={000b001a}, deviceState=1}
radius 12-18/12:22:43 DEBUG [rdsLstnr-p-8-t-5] RadiusProcessor - Create new radius session.
radius 12-18/12:22:43 DEBUG [rdsLstnr-p-8-t-5] InetNas - agentRemoteId=java.nio.DirectByteBufferR[pos=0 lim=6 cap=6]
radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] InetNas - Found agentDevice:4
radius 12-18/12:22:43 DEBUG [rdsLstnr-p-8-t-5] InetNas - findServ agentDeviceRuntime=ru.bitel.bgbilling.modules.inet.runtime.device.InetDeviceRuntime@1520a48c
radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] InetNas - Search serv on deviceId=4; interfaceId=26
radius 12-18/12:22:43 DEBUG [rdsLstnr-p-8-t-5] InetRadiusProcessor - Password verification disabled.
radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] InetRadiusProcessor - [username=d4:ca:6d:53:35:d0] Authenticated as inetServId:6
radius 12-18/12:22:43 DEBUG [rdsLstnr-p-8-t-5] InetRadiusProcessor - Identifier from request: null
radius 12-18/12:22:43 DEBUG [rdsLstnr-p-8-t-5] InetRadiusProcessor - MAC-address from request:
radius 12-18/12:22:43 DEBUG [rdsLstnr-p-8-t-5] InetAccountingPeriodList - Create:
                AccountingPeriod: 2: 02.12.2013 00:00:00.0 - 31.12.2013 23:59:59.999
radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] InetApplication - inetServ[id=6] balance ok: 0.00 [0]
radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] InetApplication - TariffOptionMap: {}
radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] InetApplication - OptionSet: [1]
radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] InetRadiusProcessor - Not found free IP-address in serv
radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] InetRadiusProcessor - Set ip from pool
radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] InetRadiusProcessor - Return code=0
radius 12-18/12:22:43 DEBUG [ip-dyn-reserve-p-14-t-1] IpResourceReserveManager - Deleted 2 old IPs
radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] InetDhcpHelperProcessor - Put auth accept 3:4:26
radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] InetRadiusProcessor - RESPONSE_BEFORE_POSTPROCESS:
Packet type: Access-Accept
Identifier: 6
Authenticator: {}
Attributes:
  Acct-Interim-Interval=900
  Framed-IP-Address=2.2.2.12
  DHCP-Max-Leases=1
  Service-Name:1=RSE-SVC-EXT
  Service-Options:1=1
  Service-Parameter:1=Rate=10000 Burst=1250000
  IP-Interface-Name=CLIENTS

Process time auth: 14

radius 12-18/12:22:43 DEBUG [rdsLstnr-p-8-t-5] ProcessorRequest - Sending to /10.0.0.11:1812
radius 12-18/12:22:43  INFO [rdsLstnr-p-8-t-5] InetRadiusListenerWorker - RESPONSE:
Packet type: Access-Accept
Identifier: 6
Authenticator: {EC 4F AD 8E BD 70 1F A4 0C 22 82 24 1C AD 89 CB}
Attributes:
  Acct-Interim-Interval=900
  DHCP-Max-Leases=1
  Service-Name:1=RSE-SVC-EXT
  Service-Options:1=1
  Service-Parameter:1=Rate=10000 Burst=1250000
  IP-Interface-Name=CLIENTS

Process time auth: 21

connection 12-18/12:22:43  INFO [sa-p-12-t-1] ServiceActivatorSet - Connecting to device
connection 12-18/12:22:43 DEBUG [sa-p-12-t-1] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 1; deviceId: 3; connectionId: 43755; timestamp: 1387347763568
connection 12-18/12:22:43  INFO [sa-p-12-t-1] ServiceActivatorDeviceWorker - Do task deviceId: 3; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 1; deviceId: 3; connectionId: 43755; timestamp: 1387347763568
connection 12-18/12:22:43  INFO [sa-p-12-t-1] InetApplication - TariffOptionMap: {}
connection 12-18/12:22:43  INFO [sa-p-12-t-1] InetApplication - OptionSet: [1]
connection 12-18/12:22:43  INFO [sa-p-12-t-1] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-18/12:22:43  INFO [sa-p-12-t-1] ServiceActivatorDeviceWorker - Processing deviceId:3; command ServiceActivatorEvent type=4; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-18/12:22:43  INFO [sa-p-12-t-1] ServiceActivatorSet - Invoking onAccountingStart
connection 12-18/12:22:43  INFO [sa-p-12-t-1] ServiceActivatorDeviceWorker - Process event type[4] result=true
connection 12-18/12:22:43 DEBUG [sa-p-12-t-1] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 1; deviceId: 3; connectionId: 43756; timestamp: 1387347763600
connection 12-18/12:22:43  INFO [sa-p-12-t-1] ServiceActivatorDeviceWorker - Do task deviceId: 3; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 1; deviceId: 3; connectionId: 43756; timestamp: 1387347763600
connection 12-18/12:22:43  INFO [sa-p-12-t-1] InetApplication - TariffOptionMap: {}
connection 12-18/12:22:43  INFO [sa-p-12-t-1] InetApplication - OptionSet: [1]
connection 12-18/12:22:43  INFO [sa-p-12-t-1] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-18/12:22:43  INFO [sa-p-12-t-1] ServiceActivatorDeviceWorker - Processing deviceId:3; command ServiceActivatorEvent type=4; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-18/12:22:43  INFO [sa-p-12-t-1] ServiceActivatorSet - Invoking onAccountingStart
connection 12-18/12:22:43  INFO [sa-p-12-t-1] ServiceActivatorDeviceWorker - Process event type[4] result=true
dhcp 12-18/12:22:43  INFO [dhcpLstnr-p-10-t-9] InetAbstractDhcpProcessor - REQUEST:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Discover{1}
htype: 1, hlen: 6, hops: 1
xid: 197160492, secs: 2, flags: -32768
Client IP: 0.0.0.0
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 2.2.2.1
Client MAC: {D4CA6D5335D0}
  Parameter request list{55}={1, 121, 3, 33, 6, 42}
  Host name{12}={client}
  {61}={01D4CA6D5335D0}
  Agent information{82}=
    sub{1}={0004000B001A}
    sub{2}={0006ACF1DFA7BF40}

dhcp 12-18/12:22:43 DEBUG [dhcpLstnr-p-10-t-9] InetAbstractDhcpProcessor - OP_BOOT_REQUEST
dhcp 12-18/12:22:43 DEBUG [dhcpLstnr-p-10-t-9] InetAbstractDhcpProcessor - Found device by giaddr id=3
dhcp 12-18/12:22:43  INFO [dhcpLstnr-p-10-t-9] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Discover{1}
htype: 1, hlen: 6, hops: 1
xid: 197160492, secs: 2, flags: -32768
Client IP: 0.0.0.0
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 2.2.2.1
Client MAC: {D4CA6D5335D0}
  Parameter request list{55}={1, 121, 3, 33, 6, 42}
  Host name{12}={client}
  {61}={01D4CA6D5335D0}
  Agent information{82}=
    sub{1}={0004000B001A}
    sub{2}={0006ACF1DFA7BF40}

dhcp 12-18/12:22:43 DEBUG [dhcpLstnr-p-10-t-9] InetAbstractDhcpProcessor - Found subDevice by identifier id=4
dhcp 12-18/12:22:43 DEBUG [dhcpLstnr-p-10-t-9] InetDhcpHelperProcessor - request.giaddr = 2.2.2.1
dhcp 12-18/12:22:43 DEBUG [dhcpLstnr-p-10-t-9] InetAbstractDhcpProcessor - DHCP_DISCOVER
dhcp 12-18/12:22:43  INFO [dhcpLstnr-p-10-t-9] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP Offer{2}
htype: 1, hlen: 6, hops: 1
xid: 197160492, secs: 0, flags: -32768
Client IP: 0.0.0.0
Your IP: 2.2.2.12
Server IP: 0.0.0.0
Relay IP: 2.2.2.1
Client MAC: {D4CA6D5335D0}
  Agent information{82}=
    sub{1}={0004000B001A}
    sub{2}={0006ACF1DFA7BF40}
  Router{3}=2.2.2.1
  Subnet mask{1}=255.255.255.0
  DNS{6}={50F420B4}
  IP Address Lease Time{51}=900
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 197160492, secs: 2, flags: -32768
Client IP: 0.0.0.0
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 2.2.2.1
Client MAC: {D4CA6D5335D0}
  Server Identifier{54}={C0A83211}
  Requested IP Address{50}=2.2.2.12
  Parameter request list{55}={1, 121, 3, 33, 6, 42}
  Host name{12}={client}
  {61}={01D4CA6D5335D0}
  Agent information{82}=
    sub{1}={0004000B001A}
    sub{2}={0006ACF1DFA7BF40}

dhcp 12-18/12:22:43 DEBUG [dhcpLstnr-p-10-t-10] InetAbstractDhcpProcessor - Found subDevice by identifier id=4
dhcp 12-18/12:22:43 DEBUG [dhcpLstnr-p-10-t-10] InetDhcpHelperProcessor - request.giaddr = 2.2.2.1
dhcp 12-18/12:22:43 DEBUG [dhcpLstnr-p-10-t-10] InetAbstractDhcpProcessor - DHCP_REQUEST
dhcp 12-18/12:22:43  INFO [dhcpLstnr-p-10-t-10] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP ACK{5}
htype: 1, hlen: 6, hops: 1
xid: 197160492, secs: 0, flags: -32768
Client IP: 0.0.0.0
Your IP: 2.2.2.12
Server IP: 0.0.0.0
Relay IP: 2.2.2.1
Client MAC: {D4CA6D5335D0}
  Agent information{82}=
    sub{1}={0004000B001A}
    sub{2}={0006ACF1DFA7BF40}
  Router{3}=2.2.2.1
  Subnet mask{1}=255.255.255.0
  DNS{6}={50F420B4}
  IP Address Lease Time{51}=900
  Server Identifier{54}={00000000}

dhcp 12-18/12:22:43 DEBUG [dhcpLstnr-p-10-t-10] ProcessorRequest - Sending to /10.0.0.11:67
mq 12-18/12:22:44 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 3; deviceId: 3; connectionId: 43755; timestamp: 1387347763715
mq 12-18/12:22:44  INFO [event-proc-p-2-t-1] InetConnectionManager - Update connection: InetConnection [id=43755-0, iface=3:570834955, sessId=0101FFFF78000007-52B13F2E, start=18.12.2013 12:22:43, uname=d4:ca:6d:53:35:d0, addr=[IpAddress:null]]
mq 12-18/12:22:44  INFO [event-proc-p-2-t-1] InetDhcpHelperProcessor - IP is null 3:0:26
connection 12-18/12:22:48  INFO [sa-p-12-t-1] ServiceActivatorSet - Disconnecting from device
connection 12-18/12:22:50  INFO [sa-p-12-t-2] ServiceActivatorSet - Connecting to device
connection 12-18/12:22:50 DEBUG [sa-p-12-t-2] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateModifyEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; deviceId: 3; inetServId: 6; connectionId: 43755; state: 0; accessCode: 63; timestamp: 1387347770242
connection 12-18/12:22:50  INFO [sa-p-12-t-2] ServiceActivatorDeviceWorker - Do task deviceId: 3; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateModifyEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; deviceId: 3; inetServId: 6; connectionId: 43755; state: 0; accessCode: 63; timestamp: 1387347770242
connection 12-18/12:22:50  INFO [sa-p-12-t-2] InetApplication - TariffOptionMap: {}
connection 12-18/12:22:50  INFO [sa-p-12-t-2] InetApplication - OptionSet: [1]
connection 12-18/12:22:50  INFO [sa-p-12-t-2] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=2; inetServId: 6; call: true; oldState: 1; newState: 0; oldOptionSet: 1; newOptionSet: 1
connection 12-18/12:22:50  INFO [sa-p-12-t-2] ServiceActivatorDeviceWorker - Processing deviceId:3; command ServiceActivatorEvent type=2; inetServId: 6; call: true; oldState: 1; newState: 0; oldOptionSet: 1; newOptionSet: 1
connection 12-18/12:22:50  INFO [sa-p-12-t-2] ServiceActivatorSet - Invoking connectionModify
connection 12-18/12:22:50  INFO [sa-p-12-t-2] SmartEdgeServiceActivator - Connection modify!
connection 12-18/12:22:50  INFO [sa-p-12-t-2] SmartEdgeServiceActivator - oldState: 1; newState: 0; oldOptionSet: [1]; newOptionSet: [1]
connection 12-18/12:22:50  INFO [sa-p-12-t-2] SmartEdgeServiceActivator - Connection close!
connection 12-18/12:22:50  INFO [sa-p-12-t-2] InetDhcpHelperProcessor - Remove connection remove 3:0:26
connection 12-18/12:22:50  INFO [sa-p-12-t-2] SmartEdgeServiceActivator - Send CoA lock:
Packet type: CoA-Request
Identifier: 3
Authenticator: {31 7A E1 9F C1 0F B6 20 66 6B 44 B4 A3 0B D8 A6}
Attributes:
  Acct-Interim-Interval=900
  Acct-Session-Id=0101FFFF78000007-52B13F2E
  Forward-Policy=in:NOAUTH-IPOE
  HTTP-Redirect-Profile-Name=NOAUTH

connection 12-18/12:22:50  INFO [sa-p-12-t-2] RadiusClient - Sending to /10.0.0.11:3799
Packet type: CoA-Request
Identifier: 3
Authenticator: {31 7A E1 9F C1 0F B6 20 66 6B 44 B4 A3 0B D8 A6}
Attributes:
  Acct-Interim-Interval=900
  Acct-Session-Id=0101FFFF78000007-52B13F2E
  Forward-Policy=in:NOAUTH-IPOE
  HTTP-Redirect-Profile-Name=NOAUTH

connection 12-18/12:22:50  INFO [sa-p-12-t-2] ServiceActivatorDeviceWorker - Process event type[2] result=true
connection 12-18/12:22:50  INFO [rds-clnt-/10.0.0.11-3799] RadiusClient - Recieved from /10.0.0.11:3799
Packet type: CoA-NAK
Identifier: 3
Authenticator: {96 FB A3 49 41 AC DC EB 59 E7 F7 65 03 2A AF D9}
Attributes:
  Error-Cause=555
  Event-Timestamp=1387347765

connection 12-18/12:22:51 DEBUG [sa-p-12-t-2] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 2; deviceId: 3; connectionId: 43756; timestamp: 1387347771479
connection 12-18/12:22:51  INFO [sa-p-12-t-2] ServiceActivatorDeviceWorker - Do task deviceId: 3; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 2; deviceId: 3; connectionId: 43756; timestamp: 1387347771479
connection 12-18/12:22:51  INFO [sa-p-12-t-2] InetApplication - TariffOptionMap: {}
connection 12-18/12:22:51  INFO [sa-p-12-t-2] InetApplication - OptionSet: [1]
connection 12-18/12:22:51  INFO [sa-p-12-t-2] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=5; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-18/12:22:51  INFO [sa-p-12-t-2] ServiceActivatorDeviceWorker - Processing deviceId:3; command ServiceActivatorEvent type=5; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-18/12:22:51  INFO [sa-p-12-t-2] ServiceActivatorSet - Invoking onAccountingStop
connection 12-18/12:22:51  INFO [sa-p-12-t-2] ServiceActivatorDeviceWorker - Process event type[5] result=true
connection 12-18/12:22:51 DEBUG [sa-p-12-t-2] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 2; deviceId: 3; connectionId: 43755; timestamp: 1387347771508
connection 12-18/12:22:51  INFO [sa-p-12-t-2] ServiceActivatorDeviceWorker - Do task deviceId: 3; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 2; deviceId: 3; connectionId: 43755; timestamp: 1387347771508
connection 12-18/12:22:51  INFO [sa-p-12-t-2] InetApplication - TariffOptionMap: {}
connection 12-18/12:22:51  INFO [sa-p-12-t-2] InetApplication - OptionSet: [1]
connection 12-18/12:22:51  INFO [sa-p-12-t-2] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=5; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-18/12:22:51  INFO [sa-p-12-t-2] ServiceActivatorDeviceWorker - Processing deviceId:3; command ServiceActivatorEvent type=5; inetServId: 6; call: true; oldState: 1; newState: 1; oldOptionSet: 1; newOptionSet: 1
connection 12-18/12:22:51  INFO [sa-p-12-t-2] ServiceActivatorSet - Invoking onAccountingStop
connection 12-18/12:22:51  INFO [sa-p-12-t-2] ServiceActivatorDeviceWorker - Process event type[5] result=true
mq 12-18/12:22:51 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 2; deviceId: 3; connectionId: 43756; timestamp: 1387347771479
mq 12-18/12:22:51  INFO [event-proc-p-2-t-1] InetConnectionManager - Remove connection: InetConnection [id=43756-43755, iface=3:570834955, sessId=0101FFFF78000007-52B13F2E-RSE-SVC-EXT-72F726EB, start=18.12.2013 12:22:43, uname=RSE-SVC-EXT, addr=[IpAddress:null]]
mq 12-18/12:22:51 DEBUG [event-proc-p-2-t-1] InetAbstractDhcpProcessor - Skip service connection
mq 12-18/12:22:51  INFO [event-proc-p-2-t-1] InetDhcpHelperProcessor - Remove connection remove 3:0:26
mq 12-18/12:22:51 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 2; deviceId: 3; connectionId: 43755; timestamp: 1387347771508
mq 12-18/12:22:51  INFO [event-proc-p-2-t-1] InetConnectionManager - Remove connection: InetConnection [id=43755-0, iface=3:570834955, sessId=0101FFFF78000007-52B13F2E, start=18.12.2013 12:22:43, uname=d4:ca:6d:53:35:d0, addr=[IpAddress:null]]
mq 12-18/12:22:51  INFO [event-proc-p-2-t-1] InetDhcpHelperProcessor - Remove connection remove 3:0:26

mq 12-18/12:22:44 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] moduleId: 1; pluginId: no; cid: 1; scid: -1; userId: 0; type: 3; deviceId: 3; connectionId: 43755; timestamp: 1387347763715
mq 12-18/12:22:44  INFO [event-proc-p-2-t-1] InetConnectionManager - Update connection: InetConnection [id=43755-0, iface=3:570834955, sessId=0101FFFF78000007-52B13F2E, start=18.12.2013 12:22:43, uname=d4:ca:6d:53:35:d0, addr=[IpAddress:null]]
mq 12-18/12:22:44  INFO [event-proc-p-2-t-1] InetDhcpHelperProcessor - IP is null 3:0:26

   @Override
   public void postprocessAccessRequest( final RadiusPacket request, final RadiusPacket response, final ConnectionSet connectionSet )
       throws Exception
   {
      super.postprocessAccessRequest( request, response, connectionSet );

      response.removeAttributes( -1, RadiusDictionary.Framed_IP_Address );
   }

const.access.attributes=IP-Interface-Name=CLIENTS;DHCP-Max-Leases=1;Acct-Interim-Interval=900
redirect.attributes=HTTP-Redirect-Profile-Name=NOAUTH;Forward-Policy=in:NOAUTH-IPOE;Acct-Interim-Interval=900;
option.1.attributes=Service-Name:1=RSE-SVC-EXT;Service-Options:1=1;Service-Parameter:1=Rate=10000 Burst=1250000

radius.realm.default.attributes={@const.access.attributes}radius.realm.default.ipCategories=1
radius.disable.accessCodes=1,2,3,4,10,11,12
radius.disable.attributes=IP-Interface-Name=REJECT;DHCP-Max-Leases=1;{@redirect.attributes}
radius.disable.ipCategories=3
radius.disable.pattern.attributes=HTTP-Redirect-Profile-Name=NOAUTH
radius.inetOption.1.attributes={@option.1.attributes}

dhcp.option.serverIdentifier=0.0.0.0
dhcp.option.leaseTime=900
dhcp.ipCategories=1
dhcp.disable.ipCategories=3

sa.radius.option.attributesPrefix=option.
sa.radius.connection.attributes=Acct-Session-Id
sa.radius.disable.attributes={@redirect.attributes}
sa.radius.service.closeAttributes=Deactivate-Service-Name:1=RSE-SVC-EXT

radius.connection.checkDuplicate=2
radius.password.verification=0

radius.agent.option.removeHeader=2
radius.agent.option.remoteId.position=0
radius.agent.option.remoteId.length=6

dhcp.connection.closeOnNew=1
dhcp.option82.removeHeader=2
dhcp.option82.agentRemoteId.code=2
dhcp.option82.agentRemoteId.type=0
dhcp.option82.agentRemoteId.position=0
dhcp.option82.agentRemoteId.length=6

dhcp.option82.interfaceId.code=1
#dhcp.option82.interfaceId.type=0
dhcp.option82.interfaceId.position=3
dhcp.option82.interfaceId.length=1

dhcp.option82.vlanId.code=1
dhcp.option82.vlanId.position=2
dhcp.option82.vlanId.length=2

dhcp.deviceSearchMode=0

dhcp.servSearchMode=1
radius.servSearchMode=1

dhcp.key.pattern=$deviceId:$remoteId:$circuitId
radius.key.pattern=$deviceId:$remoteId:$circuitId