kubernetes-nmstate icon indicating copy to clipboard operation
kubernetes-nmstate copied to clipboard

NNCP apply takes *very long* time to apply; nmstatectl does not

Open k8scoder192 opened this issue 1 year ago • 2 comments

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:

  • NodeNetworkState on affected nodes (use kubectl 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

k8scoder192 avatar May 28 '24 16:05 k8scoder192