Bug 2179314
| Summary: | verification state fails with "current '[]'" | ||
|---|---|---|---|
| Product: | Red Hat Enterprise Linux 9 | Reporter: | Quique Llorente <ellorent> |
| Component: | nmstate | Assignee: | Gris Ge <fge> |
| Status: | CLOSED DUPLICATE | QA Contact: | Mingyu Shi <mshi> |
| Severity: | urgent | Docs Contact: | |
| Priority: | unspecified | ||
| Version: | 9.2 | CC: | ferferna, jiji, jishi, network-qe, till |
| Target Milestone: | rc | Flags: | pm-rhel:
mirror+
|
| 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: | 2023-03-22 07:34: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: | |||
This might be duplicate report of https://bugzilla.redhat.com/show_bug.cgi?id=2177592 Please use `dnf copr enable packit/nmstate-nmstate-2280 ` to check whether it fix your problem. Thanks! (In reply to Gris Ge from comment #1) > This might be duplicate report of > https://bugzilla.redhat.com/show_bug.cgi?id=2177592 > > Please use `dnf copr enable packit/nmstate-nmstate-2280 ` to check whether > it fix your problem. > > Thanks! With the copr we don't suffer from massive failures anymore, there is one error but it's not related I think. Confirmed that it really fix the issue, QE this. *** This bug has been marked as a duplicate of bug 2177592 *** |
Description of problem: At kubernetes-nmstate CI we suffer from massive failures from nmstate verifycation state since the state is empty. Also checking NM logs looks like state get removed before verify kicks in. Version-Release number of selected component (if applicable): nmstate-2.2.7 How reproducible: Not always Steps to Reproduce: 1. Apply a state and repeat until it fails 2. 3. Actual results: Verification failure: br6.interface.bridge.port desire '[{\"name\"..., current: '[]' Expected results: State is as expected on verification and nmstate do not fail Additional info: Checking CI runs and NM versions: NM 1.41.90 + nmstate 2.2.5 -> Success NM 1.42.0 + nmstate-2.2.7 -> ? NM 1.42.2 + nmstate-2.2.7 -> Fail NM 1.43.3 + nmstate-2.2.7 -> Fail NM 1.43.3 + nmstate-2.2.6 -> Fail NM 1.43.3 + nmstate-2.2.5 -> Success nmstate logs: https://storage.googleapis.com/kubevirt-prow/pr-logs/pull/nmstate_kubernetes-nmstate/1059/pull-kubernetes-nmstate-e2e-handler-k8s/1636319764265570304/artifacts/NNCP_with_maxUnavailable_when_applying_a_policy_to_matching_nodes/pods.log [2023-03-16T11:14:30Z INFO nmstate::nispor::base_iface] Got unsupported interface type Other(\"IpTun\"): tunl0, ignoring [2023-03-16T11:14:30Z INFO nmstate::nispor::show] Got unsupported interface tunl0 type Other(\"IpTun\") [2023-03-16T11:14:30Z INFO nmstate::nm::show] Got unsupported interface type ip-tunnel: tunl0, ignoring [2023-03-16T11:14:30Z INFO nmstate::query_apply::net_state] Created checkpoint /org/freedesktop/NetworkManager/Checkpoint/18 [2023-03-16T11:14:30Z INFO nmstate::ifaces::inter_ifaces] Ignoring interface cali9fa290ddf78 type ethernet [2023-03-16T11:14:30Z INFO nmstate::iface] Include interface eth2 to edit as its controller required so [2023-03-16T11:14:30Z INFO nmstate::iface] Include interface eth1 to edit as its controller required so [2023-03-16T11:14:30Z INFO nmstate::nm::query_apply::profile] Creating connection UUID Some(\"e1ed7c0f-0f4d-4219-afba-c07fc02cdd80\"), ID Some(\"br6\"), type Some(\"bridge\") name Some(\"br6\") [2023-03-16T11:14:30Z INFO nmstate::nm::query_apply::profile] Modifying connection UUID Some(\"6ca9014e-f39d-4935-b8b5-b5e9b3a086cc\"), ID Some(\"eth1\"), type Some(\"802-3-ethernet\") name Some(\"eth1\") [2023-03-16T11:14:30Z INFO nmstate::nm::query_apply::profile] Modifying connection UUID Some(\"6ff34640-86d9-49af-a1f8-c6961fa2a55f\"), ID Some(\"eth2\"), type Some(\"802-3-ethernet\") name Some(\"eth2\") [2023-03-16T11:14:30Z INFO nmstate::nm::query_apply::profile] Activating connection e1ed7c0f-0f4d-4219-afba-c07fc02cdd80: br6/bridge [2023-03-16T11:14:30Z INFO nmstate::nm::query_apply::profile] Activating connection 6ca9014e-f39d-4935-b8b5-b5e9b3a086cc: eth1/802-3-ethernet [2023-03-16T11:14:30Z INFO nmstate::nm::query_apply::profile] Activating connection 6ff34640-86d9-49af-a1f8-c6961fa2a55f: eth2/802-3-ethernet [2023-03-16T11:14:30Z INFO nmstate::nm::query_apply::profile] Deactivating connection 6ca9014e-f39d-4935-b8b5-b5e9b3a086cc: eth1/802-3-ethernet [2023-03-16T11:14:31Z INFO nmstate::nm::query_apply::profile] Deactivating connection 6ff34640-86d9-49af-a1f8-c6961fa2a55f: eth2/802-3-ethernet [2023-03-16T11:14:31Z INFO nmstate::nispor::base_iface] Got unsupported interface type Other(\"IpTun\"): tunl0, ignoring [2023-03-16T11:14:31Z INFO nmstate::nispor::show] Got unsupported interface tunl0 type Other(\"IpTun\") [2023-03-16T11:14:31Z INFO nmstate::nm::show] Got unsupported interface type ip-tunnel: tunl0, ignoring [2023-03-16T11:14:31Z INFO nmstate::query_apply::net_state] Retrying on: VerificationError: Verification failure: br6.interface.bridge.port desire networkmanager logs before retry/verify: https://storage.googleapis.com/kubevirt-prow/pr-logs/pull/nmstate_kubernetes-nmstate/1059/pull-kubernetes-nmstate-e2e-handler-k8s/1636319764265570304/artifacts/NNCP_with_maxUnavailable_when_applying_a_policy_to_matching_nodes/NetworkManager.log [Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2340] manager: (br6): new Bridge device (/org/freedesktop/NetworkManager/Devices/8) Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2342] audit: op="connection-add" uuid="e1ed7c0f-0f4d-4219-afba-c07fc02cdd80" name="br6" pid=10515 uid=0 result="success" Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2365] audit: op="connection-update" uuid="6ca9014e-f39d-4935-b8b5-b5e9b3a086cc" name="eth1" args="bridge-port.vlans,ipv4.dns,ipv4.routing-rules,ipv4.routes,ipv4.dns-search,ipv4.addresses,ipv4.method,ipv6.dns,ipv6.addr-gen-mode,ipv6.routing-rules,ipv6.routes,ipv6.dns-search,ipv6.addresses,ipv6.method,connection.master,connection.timestamp,connection.slave-type" pid=10515 uid=0 result="success" Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2381] audit: op="connection-update" uuid="6ff34640-86d9-49af-a1f8-c6961fa2a55f" name="eth2" args="bridge-port.vlans,ipv4.dns,ipv4.routing-rules,ipv4.routes,ipv4.dns-search,ipv4.addresses,ipv4.method,ipv6.dns,ipv6.addr-gen-mode,ipv6.routing-rules,ipv6.routes,ipv6.dns-search,ipv6.addresses,ipv6.method,connection.master,connection.slave-type" pid=10515 uid=0 result="success" Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2423] device (br6): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2435] device (br6): state change: unavailable -> disconnected (reason 'user-requested', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2441] device (br6): Activation: starting connection 'br6' (e1ed7c0f-0f4d-4219-afba-c07fc02cdd80) Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2441] audit: op="connection-activate" uuid="e1ed7c0f-0f4d-4219-afba-c07fc02cdd80" name="br6" pid=10515 uid=0 result="success" Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2444] device (eth1): Activation: starting connection 'eth1' (6ca9014e-f39d-4935-b8b5-b5e9b3a086cc) Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2446] device (eth2): Activation: starting connection 'eth2' (6ff34640-86d9-49af-a1f8-c6961fa2a55f) Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2446] device (br6): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2454] device (br6): state change: prepare -> config (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2458] device (eth1): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2463] device (eth1): state change: prepare -> config (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2467] device (eth2): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2470] device (eth2): state change: prepare -> config (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2474] device (br6): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.2478] device (eth1): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.4068] device (br6): attached bridge port eth1 Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.4068] device (eth1): Activation: connection 'eth1' enslaved, continuing activation Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.4074] device (eth2): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.5665] device (br6): attached bridge port eth2 Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.5665] device (eth2): Activation: connection 'eth2' enslaved, continuing activation Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.5670] device (br6): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.5674] device (eth1): state change: ip-config -> deactivating (reason 'new-activation', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.7222] device (br6): detached bridge port eth1 Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.7223] device (eth1): released from master device br6 Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.7229] device (eth1): disconnecting for new activation request. Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.7229] audit: op="connection-activate" uuid="6ca9014e-f39d-4935-b8b5-b5e9b3a086cc" name="eth1" pid=10515 uid=0 result="success" Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.7235] device (eth2): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.7238] device (br6): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.7241] device (br6): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.7245] device (br6): Activation: successful, device activated. Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.7250] device (eth2): state change: ip-check -> deactivating (reason 'new-activation', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.8935] device (br6): detached bridge port eth2 Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.8936] device (eth2): released from master device br6 Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.8955] device (eth2): disconnecting for new activation request. Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.8956] audit: op="connection-activate" uuid="6ff34640-86d9-49af-a1f8-c6961fa2a55f" name="eth2" pid=10515 uid=0 result="success" Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.8957] device (eth1): state change: deactivating -> disconnected (reason 'new-activation', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.8963] device (eth1): Activation: starting connection 'eth1' (6ca9014e-f39d-4935-b8b5-b5e9b3a086cc) Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.8965] device (eth2): state change: deactivating -> disconnected (reason 'new-activation', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.8974] device (eth2): Activation: starting connection 'eth2' (6ff34640-86d9-49af-a1f8-c6961fa2a55f) Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.8990] device (eth1): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.8992] device (eth1): state change: prepare -> config (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.8994] device (eth2): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.8996] device (eth2): state change: prepare -> config (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:30 node02 NetworkManager[5268]: <info> [1678965270.8999] device (eth1): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.0842] device (br6): attached bridge port eth1 Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.0844] device (eth1): Activation: connection 'eth1' enslaved, continuing activation Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.0848] device (eth2): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.2498] device (br6): attached bridge port eth2 Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.2498] device (eth2): Activation: connection 'eth2' enslaved, continuing activation Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.2506] device (eth1): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.2511] device (eth2): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.2519] device (eth1): state change: ip-check -> deactivating (reason 'user-requested', sys-iface-state: 'managed') Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.4074] device (br6): detached bridge port eth1 Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.4074] device (eth1): released from master device br6 Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.4079] audit: op="connection-deactivate" uuid="6ca9014e-f39d-4935-b8b5-b5e9b3a086cc" name="eth1" pid=10515 uid=0 result="success" Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.4080] device (eth2): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.4081] device (eth2): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed') Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.4085] device (eth2): Activation: successful, device activated. Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.4108] device (eth1): state change: deactivating -> disconnected (reason 'user-requested', sys-iface-state: 'managed') Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.4121] device (eth2): state change: activated -> deactivating (reason 'user-requested', sys-iface-state: 'managed') Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.5719] device (br6): detached bridge port eth2 Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.5720] device (eth2): released from master device br6 Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.5725] audit: op="connection-deactivate" uuid="6ff34640-86d9-49af-a1f8-c6961fa2a55f" name="eth2" pid=10515 uid=0 result="success" Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.5732] device (eth2): state change: deactivating -> disconnected (reason 'user-requested', sys-iface-state: 'managed') Mar 16 11:14:31 node02 NetworkManager[5268]: <info> [1678965271.5759] audit: op="checkpoint-adjust-rollback-timeout" arg="/org/freedesktop/NetworkManager/Checkpoint/18" pid=10515 uid=0 result="success" Mar 16 11:14:32 node02 NetworkManager[5268]: <info> [1678965272.6244] audit: op="checkpoint-adjust-rollback-timeout" arg="/org/freedesktop/NetworkManager/Checkpoint/18" pid=10515 uid=0 result="success" Mar 16 11:14:33 node02 NetworkManager[5268]: <info> [1678965273.6628] audit: op="checkpoint-adjust-rollback-timeout" arg="/org/freedesktop/NetworkManager/Checkpoint/18" pid=10515 uid=0 result="success" Mar 16 11:14:34 node02 NetworkManager[5268]: <info> [1678965274.6899] audit: op="checkpoint-adjust-rollback-timeout" arg="/org/freedesktop/NetworkManager/Checkpoint/18" pid=10515 uid=0 result="success" Mar 16 11:14:35 node02 NetworkManager[5268]: <info> [1678965275.7178] audit: op="checkpoint-adjust-rollback-timeout" arg="/org/freedesktop/NetworkManager/Checkpoint/18" pid=10515 uid=0 result="success" Mar 16 11:14:36 node02 NetworkManager[5268]: <info> [1678965276.7453] audit: op="checkpoint-adjust-rollback-timeout" arg="/org/freedesktop/NetworkManager/Checkpoint/18" pid=10515 uid=0 result="success"