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

Проблема сессий с различными процессорами DHCP. [РЕШЕНО]
http://forum.bitel.ru/viewtopic.php?f=44&t=8758		 Страница 1 из 1
Автор:  Магнитка.RU [ 09 дек 2013, 11:35 ]
Заголовок сообщения:  Проблема сессий с различными процессорами DHCP. [РЕШЕНО]
Здраствуйте настроили биллинг по схеме IPOE аналогично статье http://wiki.bitel.ru/index.php/RedBack_CLIPS
за исключением старой схемы поиска устройства по логину, используем новую radius.servSearchMode=1 поиск по
RemoteId,СircuitID. DHCP сервер используем встроенный в биллинг а SE100 настроен как DHCP-релей.
Клеинт аутентифицируется и адрес выдается, но есть проблема с сессиями.

1) При использовании InetDhcpProcessor класс во внутреннем DHCP сервере, во время подключения одного клиента
создается две сессии одна от устройства SE100 когда происходит радиус авторизация а вторая от коммутатора
уровня доступа когда встроенный DHCP сервер выдает адрес.
Вложение:
InetDhcpProcessor.jpg
InetDhcpProcessor.jpg [ 56.76 КБ | Просмотров: 6879 ]


2) При использовании InetDhcpHelperProcessor класса во внутреннем DHCP сервер, во время подключения одного клиента
создается одна сессия как и хотелось бы, т.е идет привязка к аутентифицированной сессии радиуса, но при этом в нее
не помещается выданный айпи адрес клиенту. Привязка осуществляется по параметрам dhcp.key.pattern=$deviceId:$remoteId:$circuitId
radius.key.pattern=$deviceId:$remoteId:$circuitId

Вложение:
InetDhcpHelperProcessor.jpg
InetDhcpHelperProcessor.jpg [ 52.71 КБ | Просмотров: 6879 ]


Хотелось бы видеть одну нормальную сессию от радиуса с выданным пользователю айпи адресом от устройства (SE100)
т.к на нем можно выполнять CoA/PoD запросы на отключение, что не возможно с DHCP сессией
т.к она не имеет идентификатора радиус сессии Acct-Session-Id, а имеет xid dhcp пакета в идентификаторе сессии.
Подскажите как правильно такое реализовать ?

Версия Bgbilling 6.0 сборка 1268 от 26.11.2013.
Автор:  Amir [ 09 дек 2013, 16:44 ]
Заголовок сообщения:  Re: Проблема сессий с различными процессорами DHCP
Нужны логи Access авторизации и когда следом DHCP приходит (для InetDhcpHelperProcessor).
Автор:  Магнитка.RU [ 10 дек 2013, 09:20 ]
Заголовок сообщения:  Re: Проблема сессий с различными процессорами DHCP
Лог:
Код:
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
Автор:  Магнитка.RU [ 12 дек 2013, 10:03 ]
Заголовок сообщения:  Re: Проблема сессий с различными процессорами DHCP
так что там ? по логу ? нужно решение
Автор:  Amir [ 13 дек 2013, 18:56 ]
Заголовок сообщения:  Re: Проблема сессий с различными процессорами DHCP
По логу у вас сейчас InetDhcpProcessor установлен, а для схемы CLIPS+DHCP82 нужен InetDhcpHelperProcessor. Нужны логи с ним.
Автор:  Магнитка.RU [ 18 дек 2013, 15:30 ]
Заголовок сообщения:  Re: Проблема сессий с различными процессорами DHCP
Вот лог с InetDhcpHelperProcessor, скажите а InetDhcpProcessor не предназначен для данной схемы ?

Код:
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
Автор:  Магнитка.RU [ 24 дек 2013, 17:05 ]
Заголовок сообщения:  Re: Проблема сессий с различными процессорами DHCP
Подскажите почему InetDhcpHelperProcessor не вставляет выданный айпи в сессию биллинга, а если вставляет то почему не показывает ? и еще почему при событии аккаунтинга сессия находиться
с ключом 3:0:26 тогда как на accept-request она put 3:4:26 , т.е почемуто remoteAgentId = 0 всместо 4 ?
Код:
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
Автор:  Amir [ 25 дек 2013, 15:59 ]
Заголовок сообщения:  Re: Проблема сессий с различными процессорами DHCP
В SmartEdgeClipsProtocolHandler адрес удаляется из Access-Accept. Не знаю зачем, нас вроде бы просили так сделать, когда впервые реализовывали поддержку.
Код:
   @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 );
   }
Попробуйте закомментировать строку response.removeAttributes( -1, RadiusDictionary.Framed_IP_Address );, сохранить и "перекомпилировать все", затем "перечитать конфигурацию на серверах".
Автор:  Amir [ 25 дек 2013, 16:12 ]
Заголовок сообщения:  Re: Проблема сессий с различными процессорами DHCP
Цитата:
InetDhcpHelperProcessor - IP is null 3:0:26
Попробуйте указать dhcp.deviceSearchMode=0.
Автор:  Магнитка.RU [ 25 дек 2013, 17:43 ]
Заголовок сообщения:  Re: Проблема сессий с различными процессорами DHCP
Цитата:
Попробуйте закомментировать строку response.removeAttributes( -1, RadiusDictionary.Framed_IP_Address );, сохранить и "перекомпилировать все", затем "перечитать конфигурацию на серверах".

Это описано в этой статье http://wiki.bitel.ru/index.php/RedBack_CLIPS нужно удалять этот атрибут (Framed_IP_Address) для того чтобы редбэк вернул адрес по dhcp.

Цитата:
Попробуйте указать dhcp.deviceSearchMode=0.

Этот режим поиска и стоит, пробывал все остальные 1, 2.

Вот часть конфигурации.
Код:
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
Автор:  Amir [ 25 дек 2013, 17:55 ]
Заголовок сообщения:  Re: Проблема сессий с различными процессорами DHCP
А в предыдущем большом логе же нормально как-будто выдал Access-Accept, а затем DHCP-ACK.
Цитата:
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 DEBUG [dhcpLstnr-p-10-t-7] InetAbstractDhcpProcessor - Found subDevice by identifier id=4
Автор:  Amir [ 25 дек 2013, 17:59 ]
Заголовок сообщения:  Re: Проблема сессий с различными процессорами DHCP
По поводу IP-адреса не понял тогда вопроса - думал спрашиваете почему нет в ответе.
А в сессии нет адреса, потому что в старт-пакете и в апдейт-пакетах нет адреса.
Но это можно исправить, если указать
connection.start.fromAccept=1
Чтобы при Access-Accept биллинг заносил запись в БД, в том числе, с выданным адресом.
Автор:  Магнитка.RU [ 26 дек 2013, 09:13 ]
Заголовок сообщения:  Re: Проблема сессий с различными процессорами DHCP
Спасибо большое это (connection.start.fromAccept=1) именно то что нужно, это решило проблему в сессии биллинга появился айпи адрес выданный по dhcp и ключ 3:0:26 исправился на нужный 3:4:26 как и должно было быть.
Страница 1 из 1 Часовой пояс: UTC + 5 часов [ Летнее время ]
Powered by phpBB® Forum Software © phpBB Group
http://www.phpbb.com/