RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 2168477 - DHCP transaction started on ovs internal interface before set-cloned MAC address
Summary: DHCP transaction started on ovs internal interface before set-cloned MAC address
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 9
Classification: Red Hat
Component: NetworkManager
Version: 9.0
Hardware: x86_64
OS: Linux
high
high
Target Milestone: rc
: 9.2
Assignee: Beniamino Galvani
QA Contact: Matej Berezny
URL:
Whiteboard:
: 2165874 (view as bug list)
Depends On:
Blocks: 2165874
TreeView+ depends on / blocked
 
Reported: 2023-02-09 06:37 UTC by Gris Ge
Modified: 2023-05-09 10:24 UTC (History)
10 users (show)

Fixed In Version: NetworkManager-1.42.2-1.el9
Doc Type: No Doc Update
Doc Text:
If this bug requires documentation, please select an appropriate Doc Type value.
Clone Of:
Environment:
Last Closed: 2023-05-09 08:17:59 UTC
Type: Bug
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)
NetworkManager trace log (1.07 MB, text/plain)
2023-02-09 13:05 UTC, Gris Ge 		no flags Details
View All


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker NMT-273 0 None None None 2023-02-09 06:39:13 UTC
Red Hat Issue Tracker RHELPLAN-148107 0 None None None 2023-02-09 06:39:16 UTC
Red Hat Product Errata RHBA-2023:2485 0 None None None 2023-05-09 08:18:33 UTC
freedesktop.org Gitlab NetworkManager NetworkManager merge_requests 1532 0 None merged device: update address in nm_device_update_from_platform_link() 2023-02-20 16:40:31 UTC

Description Gris Ge 2023-02-09 06:37:34 UTC 
Description of problem:

In OpenShift kubernetes-nmstate, we set cloned mac address to OVS internal interface and reboot. After bootup, we might different DHCP address:


Feb 01 07:09:38 localhost.localdomain NetworkManager[1673]: <info>  [1675235378.6696] dhcp4 (ovs0): state changed new lease, address=192.168.66.51


Feb 01 07:08:26 localhost.localdomain NetworkManager[1673]: <info>  [1675235306.6211] dhcp4 (ovs0): state changed new lease, address=192.168.66.102


Version-Release number of selected component (if applicable):
NetworkManager-1.40.10-1.el8 (also tried NetworkManager latest git build, got the same)

How reproducible:
5%

Steps to Reproduce:
1. Request openshift team to run kubernetes-nmstate CI
2.
3.

Actual results:

Since the `ovs0` interface is cloning the MAC address of `eth0`, after reboot, the `ovs0` hold __different__ IP address of `eth0` was.

Expected results:

Since the `ovs0` interface is cloning the MAC address of `eth0`, after reboot, the `ovs0` hold __identical__ IP address of `eth0` was.

Additional info:

The full log could be found at
https://storage.googleapis.com/kubevirt-prow/pr-logs/pull/nmstate_kubernetes-nmstate/1059/pull-kubernetes-nmstate-e2e-handler-k8s/1620675826716512256/artifacts/NodeNetworkConfigurationPolicy_default_ovs-bridged_network_when_there_is_a_default_interface_with_dynamic_address_and_ovs_bridge_on_top_of_the_default_interface/NetworkManager.log

Highlights: 

Correct one:

Feb 01 07:07:52 localhost.localdomain NetworkManager[1673]: <info>  [1675235272.1622] device (ovs0): set-hw-addr: set-cloned MAC address to 52:55:00:D1:55:02 (52:55:00:D1:55:02)
Feb 01 07:07:52 localhost.localdomain NetworkManager[1673]: <info>  [1675235272.1626] device (ovs0): carrier: link connected
Feb 01 07:07:52 localhost.localdomain NetworkManager[1673]: <info>  [1675235272.1628] device (eth0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Feb 01 07:07:52 localhost.localdomain NetworkManager[1673]: <info>  [1675235272.1637] device (eth0): Activation: connection 'eth0' enslaved, continuing activation
Feb 01 07:07:52 localhost.localdomain NetworkManager[1673]: <info>  [1675235272.1640] device (eth0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Feb 01 07:07:52 localhost.localdomain NetworkManager[1673]: <info>  [1675235272.1649] dhcp4 (ovs0): activation: beginning transaction (no timeout)
Feb 01 07:07:52 localhost.localdomain NetworkManager[1673]: <info>  [1675235272.1661] device (eth0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Feb 01 07:07:52 localhost.localdomain NetworkManager[1673]: <info>  [1675235272.1663] device (eth0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Feb 01 07:07:52 localhost.localdomain NetworkManager[1673]: <info>  [1675235272.1668] device (eth0): Activation: successful, device activated.
Feb 01 07:08:26 localhost.localdomain NetworkManager[1673]: <info>  [1675235306.6211] dhcp4 (ovs0): state changed new lease, address=192.168.66.102

Wrong one:


Feb 01 07:09:01 node02 NetworkManager[1673]: <info>  [1675235341.2998] dhcp4 (ovs0): activation: beginning transaction (no timeout)
Feb 01 07:09:01 node02 NetworkManager[1673]: <info>  [1675235341.3010] device (ovs0): set-hw-addr: set-cloned MAC address to 52:55:00:D1:55:02 (52:55:00:D1:55:02)
Feb 01 07:09:02 localhost.localdomain NetworkManager[1673]: <info>  [1675235342.3294] audit: op="checkpoint-adjust-rollback-timeout" arg="/org/freedesktop/NetworkManager/Checkpoint/1" pid=3992 uid=0 result="success"
Feb 01 07:09:38 localhost.localdomain NetworkManager[1673]: <info>  [1675235378.6696] dhcp4 (ovs0): state changed new lease, address=192.168.66.51

Above logs indicate NetworkManager is starting DHCP before `set-hw-addr`
Comment 1 Beniamino Galvani 2023-02-09 08:46:16 UTC 
Hi Gris, I don't understand why that happens. Can you please provide a trace log that shows the problem?
Comment 2 Gris Ge 2023-02-09 13:05:02 UTC 
Created attachment 1943092 [details]
NetworkManager trace log

Trace log for NetworkManager-1.43.1-31701.copr.04fb042965.el8.x86_64
Comment 3 Gris Ge 2023-02-09 13:05:37 UTC 
For above log, the expected IP address is 192.168.66.102. The problematic one is 192.168.66.117
Comment 4 Beniamino Galvani 2023-02-10 16:48:01 UTC 
Thanks, there is a race condition when reactivating a ovs connection with a cloned MAC. It depends on how fast ovs-vswitchd is to update the MAC address, and I couldn't reproduce it with normal ovs. To force a delay, I recompiled ovs with the following patch, and then the problem becomes 100% visible.

--- a/lib/netdev-linux.c
+++ b/lib/netdev-linux.c
@@ -1827,6 +1827,8 @@ netdev_linux_set_etheraddr(struct netdev *netdev_, const struct eth_addr mac)
     if (is_tap_netdev(netdev_)) {
         update_flags(netdev, NETDEV_UP, 0, &old_flags);
     }
+
+    usleep(200000);
     error = set_etheraddr(netdev_get_name(netdev_), mac);
Comment 7 Gris Ge 2023-02-21 05:19:44 UTC 
*** Bug 2165874 has been marked as a duplicate of this bug. ***
Comment 11 errata-xmlrpc 2023-05-09 08:17:59 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (NetworkManager bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2023:2485
Note You need to log in before you can comment on or make changes to this bug.