Note: This is a public test instance of Red Hat Bugzilla. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback at bugzilla.redhat.com.

Bug 1479593

Summary: dhclient does not consider time changes
Product: [Fedora] Fedora Reporter: Kyle Marek <psppsn96>
Component: dhcpAssignee: Pavel Zhukov <pzhukov>
Status: CLOSED DUPLICATE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 26CC: jpopelka, pemensik, pzhukov, thozza
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-08-09 05:37:13 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Kyle Marek 2017-08-08 23:09:47 UTC 
Description of problem:
dhclient lets leases expire if time dramatically changes backwards from when lease time was recorded.

Version-Release number of selected component (if applicable):
dhcp-client-4.3.5-7.fc26.x86_64

How reproducible:
100%

Steps to Reproduce:
1. Install Fedora 26 in a QEMU VM
2. Configure time zone as America/New_York
3. Configure time source as LOCAL time
4. Reboot

Actual results:
1. VM boots with time that is 4 or 5 hours ahead depending on daylight saving time.
2. dhclient obtains a lease
3. dhclient records renew time as 5 minutes ahead of current time (at least in my 10-minute lease environment)
4. NTP corrects time
5. 10 minutes later: Kernel removes IP address from interface due to dhclient-configured valid_lft counter reaching 0.
6. 4 or 5 hours later: dhclient finally renews lease

Expected results:
dhclient corrects recorded leases upon time shift, and continues to renew leases on expected schedule.

Additional info:
This issue is not specific to Fedora 26. I have also experienced this in Fedora 24 and 25.

This issue may be specific-ish to running Fedora in VMs that do not match expected time settings. Physical machines may only be subject to the issue once as NTP's correction of the time will be retained by CMOS/time circuit, whereas restarting QEMU will reset time presented to VM as whatever is specified (or UTC if unspecified).

Will likely affect anything else that never keep the time such as dead laptops (was observed during testing) or Raspberry Pi boards.

Anaconda usually configures time source to whatever looked more-correct during installation [1]. I was subject to this issue a lot before identifying the source as I left UTC unspecified in my very frequently used kickstart file.

journal to support:
Aug 08 13:00:50 localhost.localdomain NetworkManager[603]: <info>  [1502211650.1064] device (ens3): state change: config -> ip-config (reason 'none', internal state 'managed')
Aug 08 13:00:50 localhost.localdomain NetworkManager[603]: <info>  [1502211650.1080] dhcp4 (ens3): activation: beginning transaction (timeout in 45 seconds)
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.5081] dhcp4 (ens3): dhclient started with pid 761
Aug 08 13:00:54 localhost.localdomain dhclient[761]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 3 (xid=0xa00fa608)
Aug 08 13:00:54 localhost.localdomain dhclient[761]: DHCPREQUEST on ens3 to 255.255.255.255 port 67 (xid=0xa00fa608)
Aug 08 13:00:54 localhost.localdomain dhclient[761]: DHCPOFFER from 10.42.0.1
Aug 08 13:00:54 localhost.localdomain dhclient[761]: DHCPACK from 10.42.0.1 (xid=0xa00fa608)
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6179] dhcp4 (ens3):   address 10.42.0.225
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6179] dhcp4 (ens3):   plen 24 (255.255.255.0)
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6179] dhcp4 (ens3):   gateway 10.42.0.1
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6180] dhcp4 (ens3):   lease time 505
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6180] dhcp4 (ens3):   nameserver '10.42.0.29'
Aug 08 13:00:54 localhost.localdomain nm-dispatcher[616]: req:2 'pre-up' [ens3]: new request (1 scripts)
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6180] dhcp4 (ens3):   domain name 'internal.gigabyteproductions.net'
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6180] dhcp4 (ens3): state changed unknown -> bound
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6202] device (ens3): state change: ip-config -> ip-check (reason 'none', internal state 'managed')
Aug 08 13:00:54 localhost.localdomain dhclient[761]: bound to 10.42.0.225 -- renewal in 45 seconds.
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6765] device (ens3): state change: ip-check -> secondaries (reason 'none', internal state 'managed')
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6770] device (ens3): state change: secondaries -> activated (reason 'none', internal state 'managed')
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6772] manager: NetworkManager state is now CONNECTED_LOCAL
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6823] manager: NetworkManager state is now CONNECTED_SITE
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6829] policy: set 'ens3' (ens3) as default for IPv4 routing and DNS
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6930] device (ens3): Activation: successful, device activated.
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6944] manager: startup complete
Aug 08 13:00:54 localhost.localdomain NetworkManager[603]: <info>  [1502211654.6954] manager: NetworkManager state is now CONNECTED_GLOBAL
Aug 08 13:00:54 localhost.localdomain nm-dispatcher[616]: req:3 'up' [ens3]: new request (4 scripts)
Aug 08 13:00:54 localhost.localdomain nm-dispatcher[616]: req:3 'up' [ens3]: start running ordered scripts...
Aug 08 13:00:54 localhost.localdomain nm-dispatcher[616]: req:4 'connectivity-change': new request (4 scripts)
Aug 08 13:00:55 localhost.localdomain nm-dispatcher[616]: req:4 'connectivity-change': start running ordered scripts...
Aug 08 13:00:56 localhost.localdomain NetworkManager[603]: <info>  [1502211656.8716] policy: set 'ens3' (ens3) as default for IPv6 routing and DNS
Aug 08 13:01:00 localhost.localdomain chronyd[584]: Selected source 216.218.254.202
Aug 08 13:01:00 localhost.localdomain chronyd[584]: System clock wrong by -14399.260823 seconds, adjustment started
Aug 08 09:01:01 localhost.localdomain chronyd[584]: System clock was stepped by -14399.260823 seconds

[omitted non-jumped progression of time from 09:01:01 to 13:01:39]
(no occurrence of the word "lease" in this omission)

Aug 08 13:01:39 localhost.localdomain dhclient[761]: DHCPREQUEST on ens3 to 10.42.0.1 port 67 (xid=0xa00fa608)
Aug 08 13:01:39 localhost.localdomain dhclient[761]: DHCPACK from 10.42.0.1 (xid=0xa00fa608)
Aug 08 13:01:39 localhost.localdomain NetworkManager[603]: <info>  [1502211699.5943] dhcp4 (ens3):   address 10.42.0.225
Aug 08 13:01:39 localhost.localdomain NetworkManager[603]: <info>  [1502211699.5954] dhcp4 (ens3):   plen 24 (255.255.255.0)
Aug 08 13:01:39 localhost.localdomain NetworkManager[603]: <info>  [1502211699.5954] dhcp4 (ens3):   gateway 10.42.0.1
Aug 08 13:01:39 localhost.localdomain NetworkManager[603]: <info>  [1502211699.5954] dhcp4 (ens3):   lease time 600
Aug 08 13:01:39 localhost.localdomain NetworkManager[603]: <info>  [1502211699.5954] dhcp4 (ens3):   nameserver '10.42.0.29'
Aug 08 13:01:39 localhost.localdomain NetworkManager[603]: <info>  [1502211699.5955] dhcp4 (ens3):   domain name 'internal.gigabyteproductions.net'
Aug 08 13:01:39 localhost.localdomain dbus-daemon[582]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.4' (uid=0 pid=603 comm="/usr/sbin/NetworkManager --no-daemon " label="s
Aug 08 13:01:39 localhost.localdomain NetworkManager[603]: <info>  [1502211699.5955] dhcp4 (ens3): state changed bound -> bound
Aug 08 13:01:39 localhost.localdomain NetworkManager[603]: <info>  [1502211699.5970] policy: set 'ens3' (ens3) as default for IPv4 routing and DNS
Aug 08 13:01:39 localhost.localdomain systemd[1]: Starting Network Manager Script Dispatcher Service...
Aug 08 13:01:39 localhost.localdomain dhclient[761]: bound to 10.42.0.225 -- renewal in 45 seconds.


[1] https://lists.fedorahosted.org/archives/list/anaconda-patches@lists.fedorahosted.org/thread/AIEJ5XXDGE3ICDMVQX5NLGUA52VBO3KU/
Comment 1 Pavel Zhukov 2017-08-09 05:37:13 UTC 
Thank you for reporting this.
This is known issue. DHCP code uses gettimeofday and because of that it not stable in case of system time changing. It can cause IP changing or no IP at all because of lifetime.
https://bugzilla.redhat.com/show_bug.cgi?id=916116#c8

and 
https://bugzilla.redhat.com/show_bug.cgi?id=1093803 for RHEL

*** This bug has been marked as a duplicate of bug 916116 ***