dhcp leases expire before ROS requests a new lease

[wjimenez5271]

RancherOS Version: (ros os version)
1.0
Where are you running RancherOS? (docker-machine, AWS, GCE, baremetal, etc.)
vmware

Noticing that IP addresses are being given to other hosts even though an ROS host had the initial lease on it. Theory is ROS isn't asking for a new lease before the current one expires

[SvenDowideit]

what is the expiry time set on the DHCP server?

[wjimenez5271]

@SvenDowideit 24 hours

[janeczku]

According to the logs the DHCP expiry time is actually not 24h but varies between 1h or 2h.

Aug 22 16:07:09 rancher dhcpcd[1026]: eth0: soliciting a DHCP lease
Aug 22 16:07:09 rancher dhcpcd[1026]: eth0: offered XX.XX.13.198 from XX.XX.6.162
Aug 22 16:07:09 rancher dhcpcd[1026]: eth0: leased XX.XX.13.198 for 3396 seconds
Aug 22 16:07:09 rancher dhcpcd[1026]: eth0: adding route to XX.XX.13.0/24
Aug 22 16:07:09 rancher dhcpcd[1026]: eth0: adding default route via XX.XX.13.1
Aug 22 16:07:09 rancher dhcpcd[1026]: forked to background, child pid 1112

In 1.0.4 the logs contain entries for the renewals but in v1.0.0 there are no such entries (probably because the dhcpcd daemon is not started with the -d flag in that version).

@wjimenez5271 @SvenDowideit

[janeczku]

We also observed on one host whose eth0 interface ended up being configured with two DHCP IP addresses with only the later being actively renewed and the first one then being assigned to another hosts by DHCP server. Which meant we then had two hosts advertising the same IP address in the network.

2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group default qlen 1000
    link/ether 00:50:56:bc:ad:30 brd ff:ff:ff:ff:ff:ff
    inet XX.XX.13.121/24 brdXX.XX.13.255 scope global eth0
       valid_lft forever preferred_lft forever
    inet XX.XX.13.194/24 brd XX.XX.13.255 scope global secondary eth0
       valid_lft forever preferred_lft forever

[SvenDowideit]

I added /etc//dhcpcd.enter-hook to v1.1.0, and set my dhcp server to expire every hour, and a RENEW even was triggered every 30 mins.

#!/bin/bash

echo "DHCPCD: $interface $reason" &>> /var/log/dhcpcd.debug.log
echo "$(date)" &>> /var/log/dhcpcd.debug.log
set | sed -ne 's/^new_//p' | sort &>> /var/log/dhcpcd.debug.log
echo "--------------------------" &>> /var/log/dhcpcd.debug.log

[niusmallnan]

After enable debug by sudo ros config set rancher.debug true.
We can see dhcp renew logs in /var/log/dhcpcd.debug.log, something like:

Mon Dec 18 02:28:14 UTC 2017
broadcast_address=192.168.99.255
dhcp_lease_time=1200
dhcp_message_type=5
dhcp_server_identifier=192.168.99.6
ip_address=192.168.99.100
network_number=192.168.99.0
subnet_cidr=24
subnet_mask=255.255.255.0

[niusmallnan]

We also observed on one host whose eth0 interface ended up being configured with two DHCP IP addresses with only the later being actively renewed and the first one then being assigned to another hosts by DHCP server. Which meant we then had two hosts advertising the same IP address in the network.

@janeczku Do you have any detailed steps to reproduce it? It is better to file another issue.
This issue, Let's focus on the dhcpcd log output.

[kingsd041]

To enable debug in RancherOS-v1.1.2-rc2, we can see DHCP renew logs. Let's close this issue.