kubernetes-nmstate
kubernetes-nmstate copied to clipboard
NNCP apply takes *very long* time to apply; nmstatectl does not
What happened: Apply of a nncp takes over 60 seconds. If I exec into the node's nmstate-handler pod and use nmstatectl to create an interface (vlan or bridge) it takes seconds.
What you expected to happen: Apply of nncp to apply quickly
How to reproduce it (as minimally and precisely as possible): Apply a yaml such as this
apiVersion: nmstate.io/v1
kind: NodeNetworkConfigurationPolicy
metadata:
name: svc-uc-v108-dal4-qz4-sr7-rk047-s04
spec:
desiredState:
interfaces:
- ipv4:
dhcp: false
enabled: false
mac-address: 02:10:2c:2c:7e:52
name: svc-uc-v108
state: up
type: vlan
vlan:
base-iface: bond1
id: 108
nodeSelector:
kubernetes.io/hostname: dal4-qz4-sr7-rk047-s04
Anything else we need to know?: nmstate version --> kubernetes-nmstate-handler:v0.80.0
Environment:
NodeNetworkStateon affected nodes (usekubectl get nodenetworkstate <node_name> -o yaml):
apiVersion: nmstate.io/v1beta1
kind: NodeNetworkState
metadata:
creationTimestamp: "2023-10-20T21:26:46Z"
generation: 1
name: dal4-qz4-sr7-rk048-s47
ownerReferences:
- apiVersion: v1
kind: Node
name: dal4-qz4-sr7-rk048-s47
uid: 0e2aece7-b94c-4d1e-94d8-cfa8d55c08a3
resourceVersion: "428891868"
uid: cdd70d0c-0b6d-482c-a8e0-25c017e4e0c7
status:
currentState:
dns-resolver:
config:
search: null
server: null
running:
search: []
server: []
interfaces:
- accept-all-mac-addresses: false
ethtool:
feature:
esp-hw-offload: false
esp-tx-csum-hw-offload: false
highdma: true
rx-gro: true
rx-gro-list: false
rx-lro: false
rx-udp-gro-forwarding: false
rx-vlan-filter: true
rx-vlan-hw-parse: true
tx-checksum-ip-generic: true
tx-esp-segmentation: false
tx-generic-segmentation: true
tx-gre-csum-segmentation: true
tx-gre-segmentation: true
tx-gso-list: false
tx-ipxip4-segmentation: true
tx-ipxip6-segmentation: true
tx-nocache-copy: false
tx-scatter-gather-fraglist: false
tx-sctp-segmentation: false
tx-tcp-ecn-segmentation: true
tx-tcp-mangleid-segmentation: true
tx-tcp-segmentation: true
tx-tcp6-segmentation: true
tx-udp-segmentation: true
tx-udp_tnl-csum-segmentation: true
tx-udp_tnl-segmentation: true
ipv4:
address:
- ip: 198.19.0.17
prefix-length: 22
enabled: true
ipv6:
address:
- ip: fe80::849c:86ff:feed:378b
prefix-length: 64
enabled: true
link-aggregation:
mode: 802.3ad
options:
ad_actor_sys_prio: 65535
ad_actor_system: "00:00:00:00:00:00"
ad_select: stable
ad_user_port_key: 0
all_slaves_active: dropped
arp_all_targets: any
arp_interval: 0
arp_validate: none
downdelay: 0
lacp_rate: fast
lp_interval: 1
miimon: 1000
min_links: 0
primary_reselect: always
updelay: 0
use_carrier: true
xmit_hash_policy: layer3+4
port:
- enp175s0f0np0
- enp175s0f1np1
mac-address: 86:9C:86:ED:37:8B
max-mtu: 65535
min-mtu: 68
mptcp:
address-flags: []
mtu: 1500
name: bond1
state: ignore
type: bond
- accept-all-mac-addresses: false
ethtool:
feature:
rx-checksum: true
rx-gro: true
rx-gro-list: false
rx-udp-gro-forwarding: false
tx-checksum-ip-generic: true
tx-generic-segmentation: true
tx-gso-list: true
tx-nocache-copy: false
tx-scatter-gather-fraglist: true
tx-sctp-segmentation: true
tx-tcp-ecn-segmentation: true
tx-tcp-mangleid-segmentation: true
tx-tcp-segmentation: true
tx-tcp6-segmentation: true
tx-udp-segmentation: true
ipv4:
enabled: false
ipv6:
address:
- ip: fe80::2c9c:bff:fe94:9164
prefix-length: 64
enabled: true
mac-address: 2E:9C:0B:94:91:64
max-mtu: 65535
min-mtu: 68
mtu: 1500
name: cilium_vxlan
state: ignore
type: vxlan
vxlan:
destination-port: 8472
id: 0
learning: false
- accept-all-mac-addresses: false
bridge:
options:
group-addr: 01:80:C2:00:00:00
group-forward-mask: 0
group-fwd-mask: 0
hash-max: 4096
mac-ageing-time: 300
multicast-last-member-count: 2
multicast-last-member-interval: 100
multicast-membership-interval: 26000
multicast-querier: false
multicast-querier-interval: 25500
multicast-query-interval: 12500
multicast-query-response-interval: 1000
multicast-query-use-ifaddr: false
multicast-router: auto
multicast-snooping: true
multicast-startup-query-count: 2
multicast-startup-query-interval: 3124
stp:
enabled: false
forward-delay: 15
hello-time: 2
max-age: 20
priority: 32768
vlan-default-pvid: 1
vlan-protocol: 802.1q
port: []
ethtool:
feature:
highdma: true
rx-gro: true
rx-gro-list: false
rx-udp-gro-forwarding: false
tx-checksum-ip-generic: true
tx-esp-segmentation: true
tx-fcoe-segmentation: true
tx-generic-segmentation: true
tx-gre-csum-segmentation: true
tx-gre-segmentation: true
tx-gso-list: true
tx-gso-partial: true
tx-gso-robust: true
tx-ipxip4-segmentation: true
tx-ipxip6-segmentation: true
tx-nocache-copy: false
tx-scatter-gather-fraglist: true
tx-sctp-segmentation: true
tx-tcp-ecn-segmentation: true
tx-tcp-mangleid-segmentation: true
tx-tcp-segmentation: true
tx-tcp6-segmentation: true
tx-tunnel-remcsum-segmentation: true
tx-udp-segmentation: true
tx-udp_tnl-csum-segmentation: true
tx-udp_tnl-segmentation: true
tx-vlan-hw-insert: true
tx-vlan-stag-hw-insert: true
ipv4:
address:
- ip: 172.17.0.1
prefix-length: 16
enabled: true
ipv6:
enabled: false
mac-address: 02:42:F3:B6:47:0A
max-mtu: 65535
min-mtu: 68
mptcp:
address-flags: []
mtu: 1500
name: docker0
state: ignore
type: linux-bridge
- accept-all-mac-addresses: false
ethernet:
auto-negotiation: true
duplex: full
speed: 10000
sr-iov:
total-vfs: 0
vfs: []
ethtool:
coalesce:
rx-usecs: 1
tx-usecs: 0
feature:
esp-hw-offload: true
esp-tx-csum-hw-offload: true
hw-tc-offload: false
l2-fwd-offload: false
rx-all: false
rx-checksum: true
rx-gro: true
rx-gro-list: false
rx-hashing: true
rx-lro: false
rx-ntuple-filter: false
rx-udp-gro-forwarding: false
rx-vlan-filter: true
rx-vlan-hw-parse: true
tx-checksum-ip-generic: true
tx-checksum-sctp: true
tx-esp-segmentation: true
tx-generic-segmentation: true
tx-gre-csum-segmentation: true
tx-gre-segmentation: true
tx-gso-partial: true
tx-ipxip4-segmentation: true
tx-ipxip6-segmentation: true
tx-nocache-copy: false
tx-tcp-mangleid-segmentation: false
tx-tcp-segmentation: true
tx-tcp6-segmentation: true
tx-udp-segmentation: true
tx-udp_tnl-csum-segmentation: true
tx-udp_tnl-segmentation: true
tx-vlan-hw-insert: true
pause:
autoneg: true
rx: true
tx: true
ring:
rx: 512
rx-max: 4096
tx: 512
tx-max: 4096
ipv4:
address:
- ip: 198.18.0.17
prefix-length: 25
enabled: true
ipv6:
address:
- ip: fe80::3eec:efff:fe60:532e
prefix-length: 64
enabled: true
mac-address: 3C:EC:EF:60:53:2E
max-mtu: 9710
min-mtu: 68
mptcp:
address-flags: []
mtu: 1500
name: eno1
state: ignore
type: ethernet
- accept-all-mac-addresses: false
ethernet:
auto-negotiation: true
sr-iov:
total-vfs: 0
vfs: []
ethtool:
coalesce:
rx-usecs: 1
tx-usecs: 0
feature:
esp-hw-offload: true
esp-tx-csum-hw-offload: true
hw-tc-offload: false
l2-fwd-offload: false
rx-all: false
rx-checksum: true
rx-gro: true
rx-gro-list: false
rx-hashing: true
rx-lro: false
rx-ntuple-filter: false
rx-udp-gro-forwarding: false
rx-vlan-filter: true
rx-vlan-hw-parse: true
tx-checksum-ip-generic: true
tx-checksum-sctp: true
tx-esp-segmentation: true
tx-generic-segmentation: true
tx-gre-csum-segmentation: true
tx-gre-segmentation: true
tx-gso-partial: true
tx-ipxip4-segmentation: true
tx-ipxip6-segmentation: true
tx-nocache-copy: false
tx-tcp-mangleid-segmentation: false
tx-tcp-segmentation: true
tx-tcp6-segmentation: true
tx-udp-segmentation: true
tx-udp_tnl-csum-segmentation: true
tx-udp_tnl-segmentation: true
tx-vlan-hw-insert: true
pause:
autoneg: true
rx: true
tx: true
ring:
rx: 512
rx-max: 4096
tx: 512
tx-max: 4096
ipv4:
enabled: false
ipv6:
enabled: false
mac-address: 3C:EC:EF:60:53:2F
max-mtu: 9710
min-mtu: 68
mtu: 1500
name: eno2
state: ignore
type: ethernet
- accept-all-mac-addresses: false
controller: bond1
ethernet:
auto-negotiation: true
duplex: full
speed: 100000
sr-iov:
total-vfs: 0
vfs: []
ethtool:
coalesce:
adaptive-rx: true
adaptive-tx: true
rx-frames: 128
rx-usecs: 8
tx-frames: 128
tx-usecs: 8
feature:
hw-tc-offload: true
rx-all: false
rx-checksum: true
rx-fcs: false
rx-gro: true
rx-gro-list: false
rx-hashing: true
rx-lro: false
rx-ntuple-filter: false
rx-udp-gro-forwarding: false
rx-udp_tunnel-port-offload: true
rx-vlan-filter: true
rx-vlan-hw-parse: true
tx-checksum-ip-generic: true
tx-generic-segmentation: true
tx-gre-csum-segmentation: true
tx-gre-segmentation: true
tx-gso-partial: true
tx-ipxip4-segmentation: true
tx-ipxip6-segmentation: true
tx-nocache-copy: false
tx-tcp-mangleid-segmentation: false
tx-tcp-segmentation: true
tx-tcp6-segmentation: true
tx-udp-segmentation: true
tx-udp_tnl-csum-segmentation: true
tx-udp_tnl-segmentation: true
tx-vlan-hw-insert: true
tx-vlan-stag-hw-insert: true
pause:
autoneg: false
rx: true
tx: true
ring:
rx: 1024
rx-max: 8192
tx: 1024
tx-max: 8192
ipv4:
enabled: false
ipv6:
enabled: false
mac-address: 86:9C:86:ED:37:8B
max-mtu: 9978
min-mtu: 68
mtu: 1500
name: enp175s0f0np0
state: ignore
type: ethernet
- accept-all-mac-addresses: false
controller: bond1
ethernet:
auto-negotiation: true
duplex: full
speed: 100000
sr-iov:
total-vfs: 0
vfs: []
ethtool:
coalesce:
adaptive-rx: true
adaptive-tx: true
rx-frames: 128
rx-usecs: 8
tx-frames: 128
tx-usecs: 8
feature:
hw-tc-offload: true
rx-all: false
rx-checksum: true
rx-fcs: false
rx-gro: true
rx-gro-list: false
rx-hashing: true
rx-lro: false
rx-ntuple-filter: false
rx-udp-gro-forwarding: false
rx-udp_tunnel-port-offload: true
rx-vlan-filter: true
rx-vlan-hw-parse: true
tx-checksum-ip-generic: true
tx-generic-segmentation: true
tx-gre-csum-segmentation: true
tx-gre-segmentation: true
tx-gso-partial: true
tx-ipxip4-segmentation: true
tx-ipxip6-segmentation: true
tx-nocache-copy: false
tx-tcp-mangleid-segmentation: false
tx-tcp-segmentation: true
tx-tcp6-segmentation: true
tx-udp-segmentation: true
tx-udp_tnl-csum-segmentation: true
tx-udp_tnl-segmentation: true
tx-vlan-hw-insert: true
tx-vlan-stag-hw-insert: true
pause:
autoneg: false
rx: true
tx: true
ring:
rx: 1024
rx-max: 8192
tx: 1024
tx-max: 8192
ipv4:
enabled: false
ipv6:
enabled: false
mac-address: 86:9C:86:ED:37:8B
max-mtu: 9978
min-mtu: 68
mtu: 1500
name: enp175s0f1np1
state: ignore
type: ethernet
- accept-all-mac-addresses: false
ethtool:
feature:
rx-gro: true
rx-gro-list: false
rx-udp-gro-forwarding: false
tx-generic-segmentation: true
tx-gso-list: true
tx-sctp-segmentation: true
tx-tcp-ecn-segmentation: true
tx-tcp-mangleid-segmentation: true
tx-tcp-segmentation: true
tx-tcp6-segmentation: true
tx-udp-segmentation: true
ipv4:
address:
- ip: 127.0.0.1
prefix-length: 8
enabled: true
ipv6:
address:
- ip: ::1
prefix-length: 128
enabled: true
mac-address: "00:00:00:00:00:00"
mtu: 65536
name: lo
state: ignore
type: loopback
routes:
config:
- destination: 10.203.92.0/23
next-hop-address: 198.19.0.30
next-hop-interface: bond1
table-id: 254
- destination: 0.0.0.0/0
next-hop-address: 198.18.0.1
next-hop-interface: eno1
table-id: 254
running:
- destination: 10.203.92.0/23
next-hop-address: 198.19.0.30
next-hop-interface: bond1
table-id: 254
- destination: 0.0.0.0/0
next-hop-address: 198.18.0.1
next-hop-interface: eno1
table-id: 254
handlerNmstateVersion: nmstatectl 2.2.13
hostNetworkManagerVersion: 1.36.6
lastSuccessfulUpdateTime: "2024-05-02T16:12:49Z"
- Problematic
NodeNetworkConfigurationPolicy: Any but see above yaml, here is the actual output from the nncp
apiVersion: nmstate.io/v1
kind: NodeNetworkConfigurationPolicy
metadata:
annotations:
nmstate.io/webhook-mutating-timestamp: "1716582405477407436"
creationTimestamp: "2024-05-24T20:26:45Z"
generation: 1
name: svc-uc-v108-dal4-qz4-sr7-rk047-s04
resourceVersion: "525584546"
uid: dae7d032-d339-4bbd-b7d9-ac1d6d42e2a6
spec:
desiredState:
interfaces:
- ipv4:
dhcp: false
enabled: false
mac-address: 02:10:2c:2c:7e:52
name: svc-uc-v108
state: up
type: vlan
vlan:
base-iface: bond1
id: 108
nodeSelector:
kubernetes.io/hostname: dal4-qz4-sr7-rk047-s04
status:
conditions:
- lastHeartbeatTime: "2024-05-28T16:03:32Z"
lastTransitionTime: "2024-05-28T16:03:32Z"
message: 1/1 nodes successfully configured
reason: SuccessfullyConfigured
status: "True"
type: Available
- lastHeartbeatTime: "2024-05-28T16:03:32Z"
lastTransitionTime: "2024-05-28T16:03:32Z"
reason: SuccessfullyConfigured
status: "False"
type: Degraded
- lastHeartbeatTime: "2024-05-28T16:03:32Z"
lastTransitionTime: "2024-05-28T16:03:32Z"
reason: ConfigurationProgressing
status: "False"
type: Progressing
lastUnavailableNodeCountUpdate: "2024-05-28T16:03:32Z"
- kubernetes-nmstate image (use
kubectl get pods --all-namespaces -l app=kubernetes-nmstate -o jsonpath='{.items[0].spec.containers[0].image}'):
kubernetes-nmstate-handler:v0.80.0
- NetworkManager version (use
nmcli --version)
nmcli tool, version 1.36.6
- Kubernetes version (use
kubectl version):
Client Version: version.Info{Major:"1", Minor:"23", GitVersion:"v1.23.10", GitCommit:"7e54d50d3012cf3389e43b096ba35300f36e0817", GitTreeState:"clean", BuildDate:"2022-08-17T18:32:54Z", GoVersion:"go1.17.13", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"23", GitVersion:"v1.23.10", GitCommit:"7e54d50d3012cf3389e43b096ba35300f36e0817", GitTreeState:"clean", BuildDate:"2022-08-17T18:26:59Z", GoVersion:"go1.17.13", Compiler:"gc", Platform:"linux/amd64"}
- OS (e.g. from /etc/os-release):
PRETTY_NAME="Ubuntu 22.04.1 LTS"
NAME="Ubuntu"
VERSION_ID="22.04"
VERSION="22.04.1 LTS (Jammy Jellyfish)"
VERSION_CODENAME=jammy
ID=ubuntu
ID_LIKE=debian
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
UBUNTU_CODENAME=jammy
Kernel
5.15.0-1020
- Others: nmstate pod log:
kubectl logs nmstate-handler-9zkz6 -n nmstate
{"level":"info","ts":"2024-05-28T15:48:59.214Z","logger":"enactmentstatus","msg":"status: {DesiredState:interfaces:\n- bridge:\n options:\n stp:\n enabled: false\n port:\n - name: usb-int-v53\n vlan:\n mode: trunk\n trunk-tags:\n - id-range:\n max: 4094\n min: 2\n ipv4:\n dhcp: false\n enabled: false\n mac-address: 02:20:34:a8:07:57\n name: usb-int-br53\n state: up\n type: linux-bridge\n DesiredStateMetaInfo:{Version: TimeStamp:0001-01-01 00:00:00 +0000 UTC} CapturedStates:map[] PolicyGeneration:1 Conditions:[{Type:Progressing Status:True Reason:ConfigurationProgressing Message:Applying desired state LastHeartbeatTime:2024-05-28 15:48:59.21462073 +0000 UTC m=+3231.903715825 LastTransitionTime:2024-05-28 15:48:59.21462073 +0000 UTC m=+3231.903715825} {Type:Failing Status:Unknown Reason:ConfigurationProgressing Message: LastHeartbeatTime:2024-05-28 15:48:59.214621417 +0000 UTC m=+3231.903716506 LastTransitionTime:2024-05-28 15:48:59.214621417 +0000 UTC m=+3231.903716506} {Type:Available Status:Unknown Reason:ConfigurationProgressing Message: LastHeartbeatTime:2024-05-28 15:48:59.214623185 +0000 UTC m=+3231.903718275 LastTransitionTime:2024-05-28 15:48:59.214623185 +0000 UTC m=+3231.903718275} {Type:Pending Status:False Reason:ConfigurationProgressing Message: LastHeartbeatTime:2024-05-28 15:48:59.214623966 +0000 UTC m=+3231.903719056 LastTransitionTime:2024-05-28 15:48:59.214623966 +0000 UTC m=+3231.903719056} {Type:Aborted Status:False Reason:ConfigurationProgressing Message: LastHeartbeatTime:2024-05-28 15:48:59.214624079 +0000 UTC m=+3231.903719168 LastTransitionTime:2024-05-28 15:48:59.214624079 +0000 UTC m=+3231.903719168}]}","enactment":"dal4-qz4-sr7-rk047-s04.usb-int-br53-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:48:59.222Z","logger":"enactmentstatus","msg":"enactment updated at the node: true","enactment":"dal4-qz4-sr7-rk047-s04.usb-int-br53-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:48:59.306Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 0, unknown: 1}, progressing: {true: 1, false: 0, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 0, false: 0, unknown: 1}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"usb-int-br53-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:48:59.306Z","logger":"policyconditions","msg":"SetPolicyProgressing"}
{"level":"info","ts":"2024-05-28T15:49:03.879Z","logger":"probe","msg":"Running 'ping' probe"}
{"level":"info","ts":"2024-05-28T15:49:04.581Z","logger":"probe","msg":"Running 'dns' probe"}
{"level":"info","ts":"2024-05-28T15:49:05.185Z","logger":"probe","msg":"Running 'api-server' probe"}
I0528 15:49:06.236434 1 request.go:601] Waited for 1.046322626s due to client-side throttling, not priority and fairness, request: GET:https://172.16.0.1:443/apis/objectbucket.io/v1alpha1?timeout=32s
{"level":"info","ts":"2024-05-28T15:49:07.048Z","logger":"probe","msg":"Running 'node-readiness' probe"}
{"level":"info","ts":"2024-05-28T15:49:07.063Z","logger":"controllers.NodeNetworkConfigurationPolicy","msg":"nmstate","nodenetworkconfigurationpolicy":"/usb-int-br53-dal4-qz4-sr7-rk047-s04","output":"setOutput: dns-resolver: {}\nroute-rules: {}\nroutes: {}\ninterfaces:\n- name: usb-int-br53\n type: linux-bridge\n state: up\n mac-address: 02:20:34:a8:07:57\n ipv4:\n enabled: false\n dhcp: false\n bridge:\n options:\n stp:\n enabled: false\n port:\n - name: usb-int-v53\n vlan:\n mode: trunk\n trunk-tags:\n - id-range:\n min: 2\n max: 4094\novs-db: {}\novn: {}\n\n \n"}
{"level":"info","ts":"2024-05-28T15:49:07.063Z","logger":"enactmentconditions","msg":"NotifySuccess","enactment":"dal4-qz4-sr7-rk047-s04.usb-int-br53-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:07.067Z","logger":"enactmentstatus","msg":"status: {DesiredState:interfaces:\n- bridge:\n options:\n stp:\n enabled: false\n port:\n - name: usb-int-v53\n vlan:\n mode: trunk\n trunk-tags:\n - id-range:\n max: 4094\n min: 2\n ipv4:\n dhcp: false\n enabled: false\n mac-address: 02:20:34:a8:07:57\n name: usb-int-br53\n state: up\n type: linux-bridge\n DesiredStateMetaInfo:{Version: TimeStamp:0001-01-01 00:00:00 +0000 UTC} CapturedStates:map[] PolicyGeneration:1 Conditions:[{Type:Progressing Status:False Reason:SuccessfullyConfigured Message: LastHeartbeatTime:2024-05-28 15:49:07.067145399 +0000 UTC m=+3239.756240528 LastTransitionTime:2024-05-28 15:49:07.067145399 +0000 UTC m=+3239.756240528} {Type:Failing Status:False Reason:SuccessfullyConfigured Message: LastHeartbeatTime:2024-05-28 15:49:07.067145008 +0000 UTC m=+3239.756240137 LastTransitionTime:2024-05-28 15:49:07.067145008 +0000 UTC m=+3239.756240137} {Type:Available Status:True Reason:SuccessfullyConfigured Message:successfully reconciled LastHeartbeatTime:2024-05-28 15:49:07.067144298 +0000 UTC m=+3239.756239442 LastTransitionTime:2024-05-28 15:49:07.067144298 +0000 UTC m=+3239.756239442} {Type:Pending Status:False Reason:SuccessfullyConfigured Message: LastHeartbeatTime:2024-05-28 15:49:07.06714591 +0000 UTC m=+3239.756241040 LastTransitionTime:2024-05-28 15:48:59 +0000 UTC} {Type:Aborted Status:False Reason:SuccessfullyConfigured Message: LastHeartbeatTime:2024-05-28 15:49:07.067146601 +0000 UTC m=+3239.756241728 LastTransitionTime:2024-05-28 15:48:59 +0000 UTC}]}","enactment":"dal4-qz4-sr7-rk047-s04.usb-int-br53-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:07.082Z","logger":"enactmentstatus","msg":"enactment updated at the node: true","enactment":"dal4-qz4-sr7-rk047-s04.usb-int-br53-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:07.082Z","logger":"controllers.NodeNetworkConfigurationPolicy.forceNNSRefresh","msg":"forcing NodeNetworkState refresh after NNCP applied","node":"dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:07.319Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 1, unknown: 0}, progressing: {true: 0, false: 1, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 1, false: 0, unknown: 0}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"usb-int-br53-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:07.320Z","logger":"policyconditions","msg":"SetPolicySuccess"}
{"level":"info","ts":"2024-05-28T15:49:07.335Z","logger":"controllers.NodeNetworkConfigurationPolicy","msg":"Policy node selectors does not match node, removing previous enactment if any","nodenetworkconfigurationpolicy":"/cos-dp-br53-dal4-qz4-sr7-rk047-s06"}
{"level":"info","ts":"2024-05-28T15:49:07.421Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 1, unknown: 0}, progressing: {true: 0, false: 1, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 1, false: 0, unknown: 0}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"cos-dp-br53-dal4-qz4-sr7-rk047-s06"}
{"level":"info","ts":"2024-05-28T15:49:07.421Z","logger":"policyconditions","msg":"SetPolicySuccess"}
{"level":"info","ts":"2024-05-28T15:49:07.435Z","logger":"controllers.NodeNetworkConfigurationPolicy","msg":"Policy node selectors does not match node, removing previous enactment if any","nodenetworkconfigurationpolicy":"/svc-uc-v108-dal4-qz4-sr7-rk046-s06"}
{"level":"info","ts":"2024-05-28T15:49:07.518Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 1, unknown: 0}, progressing: {true: 0, false: 1, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 1, false: 0, unknown: 0}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"svc-uc-v108-dal4-qz4-sr7-rk046-s06"}
{"level":"info","ts":"2024-05-28T15:49:07.518Z","logger":"policyconditions","msg":"SetPolicySuccess"}
{"level":"info","ts":"2024-05-28T15:49:07.533Z","logger":"controllers.NodeNetworkConfigurationPolicy","msg":"Policy node selectors does not match node, removing previous enactment if any","nodenetworkconfigurationpolicy":"/default-br90-dal4-qz4-sr7-rk049-s06"}
{"level":"info","ts":"2024-05-28T15:49:07.620Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 1, unknown: 0}, progressing: {true: 0, false: 1, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 1, false: 0, unknown: 0}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"default-br90-dal4-qz4-sr7-rk049-s06"}
{"level":"info","ts":"2024-05-28T15:49:07.620Z","logger":"policyconditions","msg":"SetPolicySuccess"}
{"level":"info","ts":"2024-05-28T15:49:07.635Z","logger":"controllers.NodeNetworkConfigurationPolicy","msg":"Policy node selectors does not match node, removing previous enactment if any","nodenetworkconfigurationpolicy":"/svc-uc-v39-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:07.721Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 1, unknown: 0}, progressing: {true: 0, false: 1, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 1, false: 0, unknown: 0}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"svc-uc-v39-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:07.721Z","logger":"policyconditions","msg":"SetPolicySuccess"}
{"level":"info","ts":"2024-05-28T15:49:07.738Z","logger":"controllers.NodeNetworkConfigurationPolicy","msg":"Policy node selectors does not match node, removing previous enactment if any","nodenetworkconfigurationpolicy":"/usb-int-br106-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:07.819Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 1, unknown: 0}, progressing: {true: 0, false: 1, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 1, false: 0, unknown: 0}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"usb-int-br106-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:07.819Z","logger":"policyconditions","msg":"SetPolicySuccess"}
{"level":"info","ts":"2024-05-28T15:49:07.835Z","logger":"controllers.NodeNetworkConfigurationPolicy","msg":"Policy node selectors does not match node, removing previous enactment if any","nodenetworkconfigurationpolicy":"/svc-uc-br37-dal4-qz4-sr7-rk047-s06"}
{"level":"info","ts":"2024-05-28T15:49:07.920Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 1, unknown: 0}, progressing: {true: 0, false: 1, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 1, false: 0, unknown: 0}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"svc-uc-br37-dal4-qz4-sr7-rk047-s06"}
{"level":"info","ts":"2024-05-28T15:49:07.920Z","logger":"policyconditions","msg":"SetPolicySuccess"}
{"level":"info","ts":"2024-05-28T15:49:07.935Z","logger":"controllers.NodeNetworkConfigurationPolicy","msg":"Policy node selectors does not match node, removing previous enactment if any","nodenetworkconfigurationpolicy":"/svc-uc-v37-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:08.050Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 1, unknown: 0}, progressing: {true: 0, false: 1, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 1, false: 0, unknown: 0}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"svc-uc-v37-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:08.050Z","logger":"policyconditions","msg":"SetPolicySuccess"}
{"level":"info","ts":"2024-05-28T15:49:08.069Z","logger":"controllers.NodeNetworkConfigurationPolicy","msg":"Policy node selectors does not match node, removing previous enactment if any","nodenetworkconfigurationpolicy":"/svc-vsi-br107-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:08.157Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 1, unknown: 0}, progressing: {true: 0, false: 1, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 1, false: 0, unknown: 0}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"svc-vsi-br107-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:08.157Z","logger":"policyconditions","msg":"SetPolicySuccess"}
{"level":"info","ts":"2024-05-28T15:49:08.173Z","logger":"controllers.NodeNetworkConfigurationPolicy","msg":"Policy node selectors does not match node, removing previous enactment if any","nodenetworkconfigurationpolicy":"/svc-uc-v108-dal4-qz4-sr7-rk049-s06"}
{"level":"info","ts":"2024-05-28T15:49:08.263Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 1, unknown: 0}, progressing: {true: 0, false: 1, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 1, false: 0, unknown: 0}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"svc-uc-v108-dal4-qz4-sr7-rk049-s06"}
{"level":"info","ts":"2024-05-28T15:49:08.263Z","logger":"policyconditions","msg":"SetPolicySuccess"}
{"level":"info","ts":"2024-05-28T15:49:08.279Z","logger":"controllers.NodeNetworkConfigurationPolicy","msg":"Policy node selectors does not match node, removing previous enactment if any","nodenetworkconfigurationpolicy":"/default-br90-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:08.366Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 1, unknown: 0}, progressing: {true: 0, false: 1, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 1, false: 0, unknown: 0}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"default-br90-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:08.366Z","logger":"policyconditions","msg":"SetPolicySuccess"}
{"level":"info","ts":"2024-05-28T15:49:08.382Z","logger":"controllers.NodeNetworkConfigurationPolicy","msg":"Policy node selectors does not match node, removing previous enactment if any","nodenetworkconfigurationpolicy":"/svc-uc-br43-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:08.466Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 1, unknown: 0}, progressing: {true: 0, false: 1, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 1, false: 0, unknown: 0}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"svc-uc-br43-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:08.466Z","logger":"policyconditions","msg":"SetPolicySuccess"}
{"level":"info","ts":"2024-05-28T15:49:08.482Z","logger":"controllers.NodeNetworkConfigurationPolicy","msg":"Policy node selectors does not match node, removing previous enactment if any","nodenetworkconfigurationpolicy":"/svc-vsi-v107-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:08.567Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 1, unknown: 0}, progressing: {true: 0, false: 1, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 1, false: 0, unknown: 0}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"svc-vsi-v107-dal4-qz4-sr7-rk048-s06"}
{"level":"info","ts":"2024-05-28T15:49:08.567Z","logger":"policyconditions","msg":"SetPolicySuccess"}
{"level":"info","ts":"2024-05-28T15:49:08.587Z","logger":"enactmentconditions","msg":"Reset","enactment":"dal4-qz4-sr7-rk047-s04.svc-uc-v108-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:08.590Z","logger":"enactmentstatus","msg":"status: {DesiredState:interfaces:\n- ipv4:\n dhcp: false\n enabled: false\n mac-address: 02:10:2c:2c:7e:52\n name: svc-uc-v108\n state: up\n type: vlan\n vlan:\n base-iface: bond1\n id: 108\n DesiredStateMetaInfo:{Version: TimeStamp:0001-01-01 00:00:00 +0000 UTC} CapturedStates:map[] PolicyGeneration:1 Conditions:[]}","enactment":"dal4-qz4-sr7-rk047-s04.svc-uc-v108-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:08.598Z","logger":"enactmentstatus","msg":"enactment updated at the node: true","enactment":"dal4-qz4-sr7-rk047-s04.svc-uc-v108-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:09.358Z","logger":"enactmentstatus","msg":"status: {DesiredState:interfaces:\n- ipv4:\n dhcp: false\n enabled: false\n mac-address: 02:10:2c:2c:7e:52\n name: svc-uc-v108\n state: up\n type: vlan\n vlan:\n base-iface: bond1\n id: 108\n DesiredStateMetaInfo:{Version: TimeStamp:0001-01-01 00:00:00 +0000 UTC} CapturedStates:map[] PolicyGeneration:1 Conditions:[]}","enactment":"dal4-qz4-sr7-rk047-s04.svc-uc-v108-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:09.367Z","logger":"enactmentstatus","msg":"enactment updated at the node: true","enactment":"dal4-qz4-sr7-rk047-s04.svc-uc-v108-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:09.474Z","logger":"enactmentconditions","msg":"NotifyProgressing","enactment":"dal4-qz4-sr7-rk047-s04.svc-uc-v108-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:09.477Z","logger":"enactmentstatus","msg":"status: {DesiredState:interfaces:\n- ipv4:\n dhcp: false\n enabled: false\n mac-address: 02:10:2c:2c:7e:52\n name: svc-uc-v108\n state: up\n type: vlan\n vlan:\n base-iface: bond1\n id: 108\n DesiredStateMetaInfo:{Version: TimeStamp:0001-01-01 00:00:00 +0000 UTC} CapturedStates:map[] PolicyGeneration:1 Conditions:[{Type:Progressing Status:True Reason:ConfigurationProgressing Message:Applying desired state LastHeartbeatTime:2024-05-28 15:49:09.477075435 +0000 UTC m=+3242.166170578 LastTransitionTime:2024-05-28 15:49:09.477075435 +0000 UTC m=+3242.166170578} {Type:Failing Status:Unknown Reason:ConfigurationProgressing Message: LastHeartbeatTime:2024-05-28 15:49:09.477076702 +0000 UTC m=+3242.166171846 LastTransitionTime:2024-05-28 15:49:09.477076702 +0000 UTC m=+3242.166171846} {Type:Available Status:Unknown Reason:ConfigurationProgressing Message: LastHeartbeatTime:2024-05-28 15:49:09.477077817 +0000 UTC m=+3242.166172945 LastTransitionTime:2024-05-28 15:49:09.477077817 +0000 UTC m=+3242.166172945} {Type:Pending Status:False Reason:ConfigurationProgressing Message: LastHeartbeatTime:2024-05-28 15:49:09.477079183 +0000 UTC m=+3242.166174311 LastTransitionTime:2024-05-28 15:49:09.477079183 +0000 UTC m=+3242.166174311} {Type:Aborted Status:False Reason:ConfigurationProgressing Message: LastHeartbeatTime:2024-05-28 15:49:09.477079649 +0000 UTC m=+3242.166174778 LastTransitionTime:2024-05-28 15:49:09.477079649 +0000 UTC m=+3242.166174778}]}","enactment":"dal4-qz4-sr7-rk047-s04.svc-uc-v108-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:09.485Z","logger":"enactmentstatus","msg":"enactment updated at the node: true","enactment":"dal4-qz4-sr7-rk047-s04.svc-uc-v108-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:09.565Z","logger":"policyconditions","msg":"numberOfNmstateMatchingNodes: 1, enactments count: {failed: {true: 0, false: 0, unknown: 1}, progressing: {true: 1, false: 0, unknown: 0}, pending: {true: 0, false: 1, unknown: 0}, available: {true: 0, false: 0, unknown: 1}, aborted: {true: 0, false: 1, unknown: 0}}","policy":"svc-uc-v108-dal4-qz4-sr7-rk047-s04"}
{"level":"info","ts":"2024-05-28T15:49:09.565Z","logger":"policyconditions","msg":"SetPolicyProgressing"}
I killed the pod and a new one properly started up. Tried the apply for another vlan interface and it still took > 60s to apply
I attached the full logs of nmstate-handler-9zkz6 logs--svc-uc-v108-apply.txt