Bug 1763062

https://gitlab.freedesktop.org/NetworkManager/NetworkManager/merge_requests/318

Fixed:

https://gitlab.freedesktop.org/NetworkManager/NetworkManager/commit/01920d3d523795c6f2917007bbf471ac28603371

to get proper DHCP reply I need sometimes to wait more than 60 seconds. Is that something we would like to solve here or should I file yet another bug?

so far test looks like this:
    @rhbz1763062
    @ver+=1.22
    @con_general_remove @teardown_testveth @dhcpd
    @device_reapply_routes
    Scenario: NM - device - reapply just routes
    * Prepare simulated test "testG" device
    * Execute "ip netns exec testG_ns kill -SIGSTOP $(cat /tmp/testG_ns.pid)"
    * Add a new connection of type "ethernet" and options "ifname testG con-name con_general"
    * Modify connection "con_general" changing options "ipv4.routes '192.168.5.0/24 192.168.99.111 1' ipv4.route-metric 21 ipv6.method static ipv6.addresses 2000::2/126 ipv6.routes '1010::1/128 2000::1 1'"
    * "Error.*" is not visible with command "nmcli device reapply testG" in "1" seconds
    * Execute "ip netns exec testG_ns kill -SIGCONT $(cat /tmp/testG_ns.pid)"
    When "connected" is visible with command "nmcli -g GENERAL.STATE dev show testG" in "25" seconds
    Then "1010::1 via 2000::1 dev testG\s+proto static\s+metric 1" is visible with command "ip -6 route" in "5" seconds
    And "2000::/126 dev testG\s+proto kernel\s+metric 1" is visible with command "ip -6 route"
    And "192.168.5.0/24 via 192.168.99.111 dev testG\s+proto static\s+metric" is visible with command "ip route"
    And "routers = 192.168.99.1" is visible with command "nmcli con show con_general" in "70" seconds
^^ here we have the long waiting period
    And "default via 192.168.99.1 dev testG\s+proto dhcp\s+metric 21" is visible with command "ip r"

test passes like this.

The long timeout doesn't seem related to this bz. From the log the you provided:

 <info>  [1581414454.0367] audit: op="device-reapply" interface="testG" ifindex=93 args="ipv6.method,ipv6.routes,ipv6.addresses,ipv4.route-metric,ipv4.routes" pid=26382 uid=0 result="success"
 <info>  [1581414455.5971] device (testG): Activation: successful, device activated.
 <debug> [1581414455.6737] dhcp4 (testG): sent DISCOVER to 255.255.255.255
 <debug> [1581414459.9469] dhcp4 (testG): sent DISCOVER to 255.255.255.255
 <debug> [1581414468.7730] dhcp4 (testG): sent DISCOVER to 255.255.255.255
 ...
 <info>  [1581414481.5651] audit: op="connection-delete" uuid="06a90131-43ad-4529-913b-fefd0ca85ae1" name="con_general" pid=26537 uid=0 result="success"

So for some reason the server is not replying, or takes long time to respond. Maybe there are issues in the setup. I tried in a F30 VM and it succeeds immediately:

Scenario: NM - device - reapply just routes
    * Prepare simulated test "testG" device ... passed in 3.150s
    * Execute "ip netns exec testG_ns kill -SIGSTOP $(cat /tmp/testG_ns.pid)" ... passed in 0.306s
    * Add a new connection of type "ethernet" and options "ifname testG con-name con_general" ... passed in 0.157s
    * Modify connection "con_general" changing options "ipv4.routes '192.168.5.0/24 192.168.99.111 1' ipv4.route-metric 21 ipv6.method static ipv6.addresses 2000::2/126 ipv6.routes '1010::1/128 2000::1 1'" ... passed in 0.048s
    * "Error.*" is not visible with command "nmcli device reapply testG" in "1" seconds ... passed in 0.166s
    * Execute "ip netns exec testG_ns kill -SIGCONT $(cat /tmp/testG_ns.pid)" ... passed in 0.305s
    When "connected" is visible with command "nmcli -g GENERAL.STATE dev show testG" in "25" seconds ... passed in 2.372s
    Then "1010::1 via 2000::1 dev testG\s+proto static\s+metric 1" is visible with command "ip -6 route" in "5" seconds ... passed in 0.119s
    And "2000::/126 dev testG\s+proto kernel\s+metric 1" is visible with command "ip -6 route" ... passed in 0.118s
    And "192.168.5.0/24 via 192.168.99.111 dev testG\s+proto static\s+metric" is visible with command "ip route" ... passed in 0.123s
    And "routers = 192.168.99.1" is visible with command "nmcli con show con_general" in "70" seconds ... passed in 0.152s
    And "default via 192.168.99.1 dev testG\s+proto dhcp\s+metric 21" is visible with command "ip r" ... passed in 0.119s

Do you have a machine where the problem can be reproduced?

device_reapply_routes test altered to do reapply when the DHCP request is not yet done. This showed the bug and also shows the bug fix now.

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, 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-2020:1847