Tuesday, September 17, 2013

DHCPNAK messages in log file

When I was checking log files I spotted the following log entries that were strange:
Sep  7 11:32:20 srv dhcpd: DHCPREQUEST for 1.1.1.151 from 00:40:5a:18:83:56 via eth0
Sep  7 11:32:20 srv dhcpd: DHCPACK on 1.1.1.151 to 0:4:5:1:8:5 via eth0
Sep  7 11:32:20 srv dhcpd: DHCPREQUEST for 1.1.1.151 from 0:4:5:1:8:5 via 1.1.1.10
Sep  7 11:32:20 srv dhcpd: DHCPACK on 1.1.1.151 to 0:4:5:1:8:5 via 1.1.1.10
Sep  7 11:32:20 srv dhcpd: DHCPREQUEST for 1.1.1.151 from 0:4:5:1:8:5 via 1.1.0.10: wrong network.
Sep  7 11:32:20 srv dhcpd: DHCPNAK on 1.1.1.151 to 0:4:5:1:8:5 via 1.1.0.10
The problem is that DHCP request is received three times, on two of which the answer is positive (DHCPACK) while one received negative response (DHCPNAK) and dhcpd logged the error message 'wrong network'.

The important thing is the network configuration in this specific scenario, which looks something like follows:
  +----+            +-----+              +----+
  |    |------------|     |--------------|    |
  +----+            +-----+              +----+
  Client      Firewall/DHCP relay      DHCP server
1.1.1.151    1.1.1.10     1.1.0.10       1.1.0.4
Looking into log entries, not much can be inferred. The only thing that can be seen is that third DHCPREQUEST came from 1.1.0.10 which isn't on the same network with a client requesting IP address. Sniffing the network gave a bit more information on what's happening. Analyzing the network trace the following were conclusions:

  1. There are three DHCPREQUEST messages with the same transaction ID, the same destination (1.1.0.4, i.e. DHCP server) and also client IP address field within DHCP request is set to 1.1.1.151.
  2. The first DHCPREQUEST comes directly from the client. It has source IP 1.1.1.151, and there is no relay field (i.e. the value is 0.0.0.0). Also, client MAC address field within DHCP request has MAC address of a given client. 
  3. The second DHCP request comes from DHCP relay on the firewall. It has source set to 1.1.0.10, and relay field is properly set to 1.1.1.10, i.e. the IP address from the client's network,.
  4. The third DHCP request also comes from DHCP relay on the firewall, but this time relay field is set to 1.1.0.10. This contradicts client's IP address and DHCP server rejects this request.
So, the conclusion is that client sends request to 1.1.0.4. This request is forwarded by the firewall to the server, but also intercepted by DHCP relay on the firewall that creates two proxy requests and sends them to DHCP server too, one of which is rejected.

The interesting thing, not visible in logs, is that DHCP relay upon receiving NAK from the DCHP server, generates new NAK that is broadcasted on the network where DHCP server lives. 

So, the conclusion is that firewall is wrongly configured. It should not forward DHCP requests if there is a relay agent running. Furthermore, those NAKs aren't seen by the client, only by DHCP relay that reflects them back to DHCP servers.

2 comments:

Silvester Norman said...
This comment has been removed by the author.
Silvester Norman said...

When a DHCP server detects that the client requests an IP address that does not fit for the current subnet, the DHCP server must send a DHCPNAK to the client (according to RFC1541).

Thanks
Silvester Norman

Change MAC Address

About Me

scientist, consultant, security specialist, networking guy, system administrator, philosopher ;)