Monday 22 August 2016

DHCP Relay IP Address Renewal Packets Dropped by Juniper Switch

If a client assigns an IP Address via a DHCP Relay all initial DISCOVERY, OFFER, REQUEST and ACK udp packets are broadcast between the Client and the DHCP Relay, and unicast between the DHCP Relay and the DHCP Server. But half the lease time the client asks to extend the Lease time to the DHCP Server. This renewal REQUEST is unicast from the Client to the DHCP Server. The DHCP Relay is not involved.

If DHCP Relay option is configured for any instance on a Juniper SW/RTR, The DHCP Snooping is automatically enabled. Any Juniper Switch on the path from the client to the DHCP Server with DHCP Snooping activated, would drop these unicast udp DHCP renewal packets that pass through if forwarding options are not configured properly.


To figure out this issue we have collected the logs for a dhcp packet on Juniper during the issue.

> show configuration system processes dhcp-service
traceoptions {
    file dhcp_logfile size 10m files 5;
    level all;
    flag all;
}

You can find the logs at the end of this post.

The unicast packets from the Client to the DHCP Server were definitely entering the Switch, were being processed by the DHCP Snooping mechanism (Can be seen in the logs), but no packets were coming out from the switch.

The unicast packets were being dropped by DHCP Snooping on the Juniper Switch..

SOLUTION:

To let packets not to be dropped we enabled forwarding of snooped packets on all interfaces.

> show configuration routing-instances <instance> forwarding-options
dhcp-relay {
    forward-snooped-clients all-interfaces;
    overrides {
        allow-snooped-clients;
    }
}

Related Links:
http://www.juniper.net/techpubs/en_US/junos15.1/topics/concept/dhcp-extended-snooped-packets.html
http://www.juniper.net/documentation/en_US/junos15.1/topics/task/configuration/dhcp-subscriber-access-dhcp-relay-snooped-clients-forwarding.html


DHCP-Service Logs on the Juniper Switch

Aug 18 09:35:24.404067 [INFO]  jdhcpd_io_l2ng_pfe_reader: jdhcpd_pfe_pkt_hdr_t: len 141850860 L3ifindex = 328, L2ifindex = 586, dpi_rtbl=561
Aug 18 09:35:24.404106 [INFO] [irb.1] jdhcpd_io_get_ifs: The L3 interface is 586 and L2 interface is 561, using the L3 interface
Aug 18 09:35:24.404123 [DEBUG] rc_entry_sus_find_ipaddr: rc_entry_sus_find_ipaddr: TYPE 0 for IP ADDR 100.100.100.1 in routing context LR default/RI <inst>
Aug 18 09:35:24.404143 [INFO] [default:<inst>][RLY][INET][irb.1] jdhcpd_io_pfe_packet: SNOOP : recv sa 10.30.17.72 da 100.100.100.1, src_port 68, dst_port 67 if name irb.1 len 300
Aug 18 09:35:24.404158 [ERROR] jdhcpd_security_packet_handle: Interface >ae48.0< packet_flags:204
Aug 18 09:35:24.404169 security-packet-handle sus_l2:ae48.0
Aug 18 09:35:24.404180 [INFO]  jdhcpd_security_packet_handle: security-packet-handle sus_l3:irb.1
Aug 18 09:35:24.404191 [INFO]  jdhcpd_security_packet_handle: security-packet-handle input bd srv
Aug 18 09:35:24.404200 security-packet-handle default/default-switch/srv dhcp-security not configured
Aug 18 09:35:24.404262 [INFO] [default:<inst>][RLY][INET][irb.1] --[ DHCP/BOOTP   from == 10.30.17.72, port == 68 ]--
Aug 18 09:35:24.404284 [INFO] [default:<inst>][RLY][INET][irb.1] --[ DHCP/BOOTP   size == 300, op == 1 ]--
Aug 18 09:35:24.404298 [INFO] [default:<inst>][RLY][INET][irb.1] --[ DHCP/BOOTP  flags == 0 ]--
Aug 18 09:35:24.404311 [INFO] [default:<inst>][RLY][INET][irb.1] --[ DHCP/BOOTP  htype == 1, hlen == 6 ]--
Aug 18 09:35:24.404323 [INFO] [default:<inst>][RLY][INET][irb.1] --[ DHCP/BOOTP   hops == 0, xid == de401a3c ]--
Aug 18 09:35:24.404336 [INFO] [default:<inst>][RLY][INET][irb.1] --[ DHCP/BOOTP   secs == 0, flags == 0000 ]--
Aug 18 09:35:24.404350 [INFO] [default:<inst>][RLY][INET][irb.1] --[ DHCP/BOOTP ciaddr == 10.30.17.72 ]--
Aug 18 09:35:24.404364 [INFO] [default:<inst>][RLY][INET][irb.1] --[ DHCP/BOOTP yiaddr == 0.0.0.0 ]--
Aug 18 09:35:24.404378 [INFO] [default:<inst>][RLY][INET][irb.1] --[ DHCP/BOOTP siaddr == 0.0.0.0 ]--
Aug 18 09:35:24.404391 [INFO] [default:<inst>][RLY][INET][irb.1] --[ DHCP/BOOTP giaddr == 0.0.0.0 ]--
Aug 18 09:35:24.404411 [INFO] [default:<inst>][RLY][INET][irb.1] --[ DHCP/BOOTP chaddr == 00 cd fe e1 92 28 00 00 00 00 00 00 00 00 00 00 ]--
Aug 18 09:35:24.404424 [INFO] [default:<inst>][RLY][INET][irb.1] --[ DHCP/BOOTP  sname ==  ]--
Aug 18 09:35:24.404436 [INFO] [default:<inst>][RLY][INET][irb.1] --[ DHCP/BOOTP   file ==  ]--
Aug 18 09:35:24.404450 [INFO] [default:<inst>][RLY][INET][irb.1] --[ OPTION code  53, len   1, data DHCP-REQUEST ]--
Aug 18 09:35:24.404467 [INFO] [default:<inst>][RLY][INET][irb.1] --[ OPTION code  55, len   7, data 01 79 03 06 0f 77 fc ]--
Aug 18 09:35:24.404481 [INFO] [default:<inst>][RLY][INET][irb.1] --[ OPTION code  57, len   2, data 05 dc ]--
Aug 18 09:35:24.404498 [INFO] [default:<inst>][RLY][INET][irb.1] --[ OPTION code  61, len   7, data 01 00 cd fe e1 92 28 ]--
Aug 18 09:35:24.404512 [INFO] [default:<inst>][RLY][INET][irb.1] --[ OPTION code  51, len   4, data 00 76 a7 00 ]--
Aug 18 09:35:24.404531 [INFO] [default:<inst>][RLY][INET][irb.1] --[ OPTION code  12, len  14, data 52 61 63 68 65 6c 73 2d 69 50 68 6f 6e 65 ]--
Aug 18 09:35:24.404545 [INFO] [default:<inst>][RLY][INET][irb.1] --[ OPTION code 255, len   0 ]--
Aug 18 09:35:24.404560 [NOTE] [default:<inst>][RLY][INET][irb.1] jdhcpd_packet_handle: BOOTPREQUEST arrived on unconfigured interface irb.1, flags 3

Juniper Troubleshooting Commands

TROUBLESHOOTING set cli timestamp (logs timestamp on cli for all commands you run. Very useful) show system uptime show chass...