BiTel

Добрый день!

Есть BRAS Ericsson SE100. На нем висят две сессии. С одной из них все нормально, вторая рвется каждые, примерно, 14 минут по причине DHCP lease expired. Посмотрел обмен, получил что первоначальный запрос нормально обрабатывается, два последующих тоже, а вот потом сервер в ответе не отдает router, subnet mask и dns.

01-09/14:46:52 INFO [dhcpLstnr-p-11-t-4] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Discover{1}
htype: 1, hlen: 6, hops: 1
xid: 1433753520, secs: 0, flags: 0
Client IP: 0.0.0.0
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Requested IP{50}=10.1.11.71
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
Common options: {interfaceId=0/0/0, agentRemoteId=BLG-TVR-MA5683T-1, agentCircuitId=0/0/0}
01-09/14:46:52 INFO [dhcpLstnr-p-11-t-4] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP Offer{2}
htype: 1, hlen: 6, hops: 1
xid: 1433753520, secs: 0, flags: 0
Client IP: 0.0.0.0
Your IP: 10.1.2.33
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
IP Address Lease Time{51}=300
Server Identifier{54}={00000000}
Router{3}=10.1.0.1
Subnet mask{1}=255.255.0.0
DNS{6}={B9FDB505B9FDB605}

01-09/14:46:52 INFO [dhcpLstnr-p-11-t-2] InetAbstractDhcpProcessor - REQUEST:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753520, secs: 0, flags: 0
Client IP: 0.0.0.0
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Requested IP{50}=10.1.2.33
Server Identifier{54}={AC1F110A}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}

01-09/14:46:52 INFO [dhcpLstnr-p-11-t-2] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753520, secs: 0, flags: 0
Client IP: 0.0.0.0
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Requested IP{50}=10.1.2.33
Server Identifier{54}={AC1F110A}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
Common options: {interfaceId=0/0/0, agentRemoteId=BLG-TVR-MA5683T-1, agentCircuitId=0/0/0}
01-09/14:46:52 INFO [dhcpLstnr-p-11-t-2] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP ACK{5}
htype: 1, hlen: 6, hops: 1
xid: 1433753520, secs: 0, flags: 0
Client IP: 0.0.0.0
Your IP: 10.1.2.33
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
IP Address Lease Time{51}=300
Server Identifier{54}={00000000}
Router{3}=10.1.0.1
Subnet mask{1}=255.255.0.0
DNS{6}={B9FDB505B9FDB605}

01-09/14:51:14 INFO [dhcpLstnr-p-11-t-7] InetAbstractDhcpProcessor - REQUEST:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753504, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}

01-09/14:51:14 INFO [dhcpLstnr-p-11-t-7] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753504, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
Common options: {interfaceId=0/0/0, agentRemoteId=BLG-TVR-MA5683T-1, agentCircuitId=0/0/0}
01-09/14:51:14 INFO [dhcpLstnr-p-11-t-7] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP ACK{5}
htype: 1, hlen: 6, hops: 1
xid: 1433753504, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 10.1.2.33
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
IP Address Lease Time{51}=300
Server Identifier{54}={00000000}
Router{3}=10.1.0.1
Subnet mask{1}=255.255.0.0
DNS{6}={B9FDB505B9FDB605}

01-09/14:55:37 INFO [dhcpLstnr-p-11-t-5] InetAbstractDhcpProcessor - REQUEST:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753516, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}

01-09/14:55:37 INFO [dhcpLstnr-p-11-t-5] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753516, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
Common options: {interfaceId=0/0/0, agentRemoteId=BLG-TVR-MA5683T-1, agentCircuitId=0/0/0}
01-09/14:55:37 INFO [dhcpLstnr-p-11-t-5] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP ACK{5}
htype: 1, hlen: 6, hops: 1
xid: 1433753516, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 10.1.2.33
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
IP Address Lease Time{51}=300
Server Identifier{54}={00000000}
Router{3}=10.1.0.1
Subnet mask{1}=255.255.0.0
DNS{6}={B9FDB505B9FDB605}

01-09/14:59:59 INFO [dhcpLstnr-p-11-t-2] InetAbstractDhcpProcessor - REQUEST:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753512, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}

01-09/14:59:59 INFO [dhcpLstnr-p-11-t-2] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753512, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
Common options: {interfaceId=0/0/0, agentRemoteId=BLG-TVR-MA5683T-1, agentCircuitId=0/0/0}
01-09/14:59:59 INFO [dhcpLstnr-p-11-t-2] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP ACK{5}
htype: 1, hlen: 6, hops: 1
xid: 1433753512, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 10.1.2.33
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
IP Address Lease Time{51}=300
Server Identifier{54}={00000000}

Соответственно, BRAS отбивает этот пакет из-за отсутствия опции router.
Как с этим бороться?

Как адрес выдается - динамически или прописан в сервисе статически?

Динамически

Какое значение ipResourceId в inet_connection_<mid> у этой сессии?

5

Правильный

Вышел из положения указанием необходимых опций в конфиге:
dhcp.net.option.10.1.0.0:255.255.0.0.0.subnetmask=255.255.0.0
dhcp.net.option.10.1.0.0:255.255.0.0.gate=10.1.0.1

Но что-то здесь не так...

Нужен лог из all.log, когда происходит выдача правильного и выдача неправильного ACK.

radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] RadiusListenerWorker - REQUEST:
Packet type: Access-Request
Identifier: 81
Authenticator: {C1 A8 70 83 15 6E 76 46 C6 41 55 4E AC 34 3B CD}
Attributes:
NAS-Identifier=BLG-TVR-SE100-1
User-Name=00:46:4b:0a:bf:86
User-Password=Redback
NAS-IP-Address=172.31.255.21
NAS-Port=-1761606320
Service-Type=5
NAS-Port-Id=lg id 825 vlan-id 200 clips 132432
NAS-Port-Type=5
OS-Version=12.1.1.12p1
Agent-Remote-Id={42 4C 47 2D 54 56 52 2D 4D 41 35 36 38 33 54 2D 31}
Mac-Addr=00-46-4b-0a-bf-86
Agent-Circuit-Id={30 2F 30 2F 30}
Platform-Type=4
Medium-Type=11
UNKNOWN[2352-202]={3D 3D 07 01 00 46 4B 0A BF 86}
NAS-Real-Port=587202760
UNKNOWN[3561--1]={02 13 42 4C 47 2D 54 56 52 2D 4D 41 35 36 38 33 54 2D 31}
UNKNOWN[3561--1]={01 07 30 2F 30 2F 30}

radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] InetRadiusProcessor - REQUEST_AFTER_PREPROCESS:
Packet type: Access-Request
Identifier: 81
Authenticator: {C1 A8 70 83 15 6E 76 46 C6 41 55 4E AC 34 3B CD}
Attributes:
NAS-Identifier=BLG-TVR-SE100-1
User-Name=424c472d5456522d4d4135363833542d31:302f302f30
User-Password=Redback
NAS-IP-Address=172.31.255.21
NAS-Port=-1761606320
Service-Type=5
NAS-Port-Id=lg id 825 vlan-id 200 clips 132432
NAS-Port-Type=5
Calling-Station-Id=00464b0abf86
OS-Version=12.1.1.12p1
Agent-Remote-Id={42 4C 47 2D 54 56 52 2D 4D 41 35 36 38 33 54 2D 31}
Mac-Addr=00-46-4b-0a-bf-86
Agent-Circuit-Id={30 2F 30 2F 30}
Platform-Type=4
Medium-Type=11
UNKNOWN[2352-202]={3D 3D 07 01 00 46 4B 0A BF 86}
NAS-Real-Port=587202760
UNKNOWN[3561--1]={02 13 42 4C 47 2D 54 56 52 2D 4D 41 35 36 38 33 54 2D 31}
UNKNOWN[3561--1]={01 07 30 2F 30 2F 30}
Common options: {macAddress=00-46-4b-0a-bf-86, interfaceId=0/0/0, agentRemoteId=BLG-TVR-MA5683T-1, agentCircuitId=0/0/0}
radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] InetNas - Search by mac on device and descendants=00464b0abf86
radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] InetRadiusProcessor - [username=424c472d5456522d4d4135363833542d31:302f302f30] Authenticated as inetServId:383
radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] InetNas - Found agentDevice by identifier: 14
radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] InetApplication - contract tariffOptions: {}
radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] InetApplication - inetServ[id=383] balance ok: 0.00 [0]
radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] InetApplication - OptionSet: [3]
radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] InetRadiusProcessor - Not found free static IP in serv
radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] InetRadiusProcessor - Set ip from pool
radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] InetRadiusProcessor - Return code=0
radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] InetDhcpHelperProcessor - Put auth accept 13:00464B0ABF86 10.1.2.33
radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] InetRadiusProcessor - RESPONSE_BEFORE_POSTPROCESS:
Packet type: Access-Accept
Identifier: 81
Authenticator: {}
Attributes:
Acct-Interim-Interval=600
Framed-IP-Address=10.1.2.33
Service-Parameter:1=Burst=51200 Rate=51200 ExBurst=51200
Service-Name:1=SERVICE_INET
Service-Options:1=0

Process time auth: 246

radius 01-09/14:46:51 INFO [rdsLstnr-p-9-t-4] InetRadiusListenerWorker - RESPONSE (246ms):
Packet type: Access-Accept
Identifier: 81
Authenticator: {94 F8 24 D0 72 04 2E 0F 5D 58 E5 A0 F0 56 E5 50}
Attributes:
Acct-Interim-Interval=600
Service-Parameter:1=Burst=51200 Rate=51200 ExBurst=51200
Service-Name:1=SERVICE_INET
Service-Options:1=0

Process time auth: 246

connection 01-09/14:46:52 INFO [sa-p-14-t-93] ServiceActivatorDeviceWorker - Do task deviceId: 13; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccountingEvent] moduleId: 1; pluginId: no; c
id: 311; scid: -1; userId: 0; type: 1; deviceId: 13; connectionId: 430901; timestamp: 1547034412307
connection 01-09/14:46:52 INFO [sa-p-14-t-93] InetApplication - contract tariffOptions: {}
connection 01-09/14:46:52 INFO [sa-p-14-t-93] InetApplication - OptionSet: [3]
connection 01-09/14:46:52 INFO [sa-p-14-t-93] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=4; inetServId: 383; call: true; oldState: 1; newState: 1; oldOptionSet: 3; new
OptionSet: 3
connection 01-09/14:46:52 INFO [sa-p-14-t-93] ServiceActivatorDeviceWorker - Processing deviceId:13; command ServiceActivatorEvent type=4; inetServId: 383; call: true; oldState: 1; newState: 1; oldOptionS
et: 3; newOptionSet: 3
connection 01-09/14:46:52 INFO [sa-p-14-t-93] ServiceActivatorSet - Invoking onAccountingStart
connection 01-09/14:46:52 INFO [sa-p-14-t-93] ServiceActivatorDeviceWorker - Process event type[4] result=true
mq 01-09/14:46:52 INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=430901-0, iface=13:-1761606320, sessId=FF16033978000550-5C35DF2B, start=09.01.2019 14:46:52, uname=42
4c472d5456522d4d4135363833542d31:302f302f30, addr=[IpAddress:null]]
mq 01-09/14:46:52 INFO [event-proc-p-2-t-1] InetDhcpHelperProcessor - IP is null 13:00464B0ABF86
dhcp 01-09/14:46:52 INFO [dhcpLstnr-p-11-t-4] InetAbstractDhcpProcessor - REQUEST:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Discover{1}
htype: 1, hlen: 6, hops: 1
xid: 1433753520, secs: 0, flags: 0
Client IP: 0.0.0.0
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Requested IP{50}=10.1.11.71
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}

dhcp 01-09/14:46:52 INFO [dhcpLstnr-p-11-t-4] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Discover{1}
htype: 1, hlen: 6, hops: 1
xid: 1433753520, secs: 0, flags: 0
Client IP: 0.0.0.0
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Requested IP{50}=10.1.11.71
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
Common options: {interfaceId=0/0/0, agentRemoteId=BLG-TVR-MA5683T-1, agentCircuitId=0/0/0}
dhcp 01-09/14:46:52 INFO [dhcpLstnr-p-11-t-4] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP Offer{2}
htype: 1, hlen: 6, hops: 1
xid: 1433753520, secs: 0, flags: 0
Client IP: 0.0.0.0
Your IP: 10.1.2.33
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
IP Address Lease Time{51}=300
Server Identifier{54}={00000000}
Router{3}=10.1.0.1
Subnet mask{1}=255.255.0.0
DNS{6}={B9FDB505B9FDB605}

dhcp 01-09/14:46:52 INFO [dhcpLstnr-p-11-t-2] InetAbstractDhcpProcessor - REQUEST:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753520, secs: 0, flags: 0
Client IP: 0.0.0.0
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Requested IP{50}=10.1.2.33
Server Identifier{54}={AC1F110A}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}

dhcp 01-09/14:46:52 INFO [dhcpLstnr-p-11-t-2] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753520, secs: 0, flags: 0
Client IP: 0.0.0.0
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Requested IP{50}=10.1.2.33
Server Identifier{54}={AC1F110A}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
Common options: {interfaceId=0/0/0, agentRemoteId=BLG-TVR-MA5683T-1, agentCircuitId=0/0/0}
dhcp 01-09/14:46:52 INFO [dhcpLstnr-p-11-t-2] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP ACK{5}
htype: 1, hlen: 6, hops: 1
xid: 1433753520, secs: 0, flags: 0
Client IP: 0.0.0.0
Your IP: 10.1.2.33
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
IP Address Lease Time{51}=300
Server Identifier{54}={00000000}
Router{3}=10.1.0.1
Subnet mask{1}=255.255.0.0
DNS{6}={B9FDB505B9FDB605}

dhcp 01-09/14:51:14 INFO [dhcpLstnr-p-11-t-7] InetAbstractDhcpProcessor - REQUEST:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753504, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}

dhcp 01-09/14:51:14 INFO [dhcpLstnr-p-11-t-7] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753504, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
Common options: {interfaceId=0/0/0, agentRemoteId=BLG-TVR-MA5683T-1, agentCircuitId=0/0/0}
dhcp 01-09/14:51:14 INFO [dhcpLstnr-p-11-t-7] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP ACK{5}
htype: 1, hlen: 6, hops: 1
xid: 1433753504, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 10.1.2.33
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
IP Address Lease Time{51}=300
Server Identifier{54}={00000000}
Router{3}=10.1.0.1
Subnet mask{1}=255.255.0.0
DNS{6}={B9FDB505B9FDB605}

dhcp 01-09/14:55:37 INFO [dhcpLstnr-p-11-t-5] InetAbstractDhcpProcessor - REQUEST:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753516, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}

dhcp 01-09/14:55:37 INFO [dhcpLstnr-p-11-t-5] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753516, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
Common options: {interfaceId=0/0/0, agentRemoteId=BLG-TVR-MA5683T-1, agentCircuitId=0/0/0}
dhcp 01-09/14:55:37 INFO [dhcpLstnr-p-11-t-5] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP ACK{5}
htype: 1, hlen: 6, hops: 1
xid: 1433753516, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 10.1.2.33
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
IP Address Lease Time{51}=300
Server Identifier{54}={00000000}
Router{3}=10.1.0.1
Subnet mask{1}=255.255.0.0
DNS{6}={B9FDB505B9FDB605}

dhcp 01-09/14:59:59 INFO [dhcpLstnr-p-11-t-2] InetAbstractDhcpProcessor - REQUEST_AFTER_PREPROCESS:
Message type: BOOT_REQUEST
Dhcp message type: DHCP Request{3}
htype: 1, hlen: 6, hops: 1
xid: 1433753512, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 0.0.0.0
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Client-ident.{61}={0100464B0ABF86}
Param request list{55}={1, 3, 6, 12, 15, 28, 40, 41, 42, 43, 100, 120, 121}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
Common options: {interfaceId=0/0/0, agentRemoteId=BLG-TVR-MA5683T-1, agentCircuitId=0/0/0}
dhcp 01-09/14:59:59 INFO [dhcpLstnr-p-11-t-2] InetAbstractDhcpProcessor - RESPONSE:
Message type: BOOT_RESPONSE
Dhcp message type: DHCP ACK{5}
htype: 1, hlen: 6, hops: 1
xid: 1433753512, secs: 0, flags: 0
Client IP: 10.1.2.33
Your IP: 10.1.2.33
Server IP: 0.0.0.0
Relay IP: 172.31.255.21
Client MAC: {00464B0ABF86}
Agent information{82}=
sub{1}={302F302F30}
sub{2}={424C472D5456522D4D4135363833542D31}
IP Address Lease Time{51}=300
Server Identifier{54}={00000000}

И еще одна странность с этим же пулом- ip сессии заносится в базу не сразу, а через 10 минут, по приходу первого Accounting-Request.
При этом с другим брасом и, соответственно, с другим пулом все хорошо.

Сессия всегда начинается только при получении первого Accounting-Request по сессии.
Т.к. выдача Access-Accept/Reject еще не означает что сессия будет или не будет.

Возможно проблема с DHCP связана с тем, что большая пауза после Accept и перед Accounting-Request, но пока не понял как.
Приведенный лог - это вырезка? Можете более полный отправить в личку или нам email?

Отправил на billing@bitel.ru

Чем дело кончилось? Очень интересно, поскольку тоже иногда ловим такую проблему, как лечить не понятно.

Пока молчанием)