search

hpe-storage / csi-driver

A Container Storage Interface (CSI) driver from HPE
https://scod.hpedev.io
Apache License 2.0
58 stars 53 forks source link

UUID conflict on BL460 system #270

Closed m4r1k closed 3 years ago

m4r1k commented 3 years ago

Hello there,

While doing the integration of the CSI with C7000 and BL460 systems, the CSI literally generates the same UUID for all the blades. See the following logs

time="2021-05-12T12:42:43Z" level=trace msg=">>>>> LoadNodeInfo called with node &{ nlhen06st1rm039 0a58a9fe-0001-6e6c-6865-6e3036737431 [0xc0005bc3f0] [0xc00015c340 0xc00015c550 0xc00015c750 0xc00015c900] [0xc00000c780 0xc00000c790]  }" file="flavor.go:173"
time="2021-05-12T12:42:43Z" level=trace msg=">>>>> getNodeInfoByUUID with uuid 0a58a9fe-0001-6e6c-6865-6e3036737431" file="flavor.go:552"
time="2021-05-12T12:42:43Z" level=trace msg="<<<<< getNodeInfoByUUID" file="flavor.go:562"
time="2021-05-12T12:42:43Z" level=info msg="Node info nlhen06st1rm040 already known to cluster\n" file="flavor.go:199"
time="2021-05-12T12:42:43Z" level=info msg="updating Node nlhen06st1rm040 with iqns [iqn.1994-05.com.redhat:24534a2be9e4] wwpns [10000a5fd750001c 10000a5fd750001e] networks [10.128.0.2/23 169.254.0.1/20 10.59.65.234/26 10.59.65.204/32]" file="flavor.go:231"
time="2021-05-12T12:42:40Z" level=trace msg=">>>>> LoadNodeInfo called with node &{ nlhen06st1rm040 0a58a9fe-0001-6e6c-6865-6e3036737431 [0xc0003c8140] [0xc00083e600 0xc00083e7b0 0xc00083e970 0xc00083eb20] [0xc0001e5b60 0xc0001e5b70]  }" file="flavor.go:173"
time="2021-05-12T12:42:40Z" level=trace msg=">>>>> getNodeInfoByUUID with uuid 0a58a9fe-0001-6e6c-6865-6e3036737431" file="flavor.go:552"
time="2021-05-12T12:42:40Z" level=trace msg=">>>>> getNodeInfoByName with name nlhen06st1rm040" file="flavor.go:569"
time="2021-05-12T12:42:40Z" level=info msg="Adding node with name nlhen06st1rm040" file="flavor.go:254"
time="2021-05-12T12:42:40Z" level=info msg="Successfully added node info for node <RAW SNIPPED> [iqn.1994-05.com.redhat:ccd53eae81e] [10.130.0.2/23 169.254.0.1/20 10.59.65.235/26 10.59.65.205/32] [10000a5fd7500020 10000a5fd7500022]  }}" file="flavor.go:262"
time="2021-05-12T12:42:54Z" level=trace msg=">>>>> LoadNodeInfo called with node &{ nlhen06st1rm047 0a58a9fe-0001-6e6c-6865-6e3036737431 [0xc0006c8310] [0xc000518640 0xc0005187f0 0xc0005189b0] [0xc0005c3620 0xc0005c3630]  }" file="flavor.go:173"
time="2021-05-12T12:42:54Z" level=trace msg=">>>>> getNodeInfoByUUID with uuid 0a58a9fe-0001-6e6c-6865-6e3036737431" file="flavor.go:552"
time="2021-05-12T12:42:54Z" level=trace msg="<<<<< getNodeInfoByUUID" file="flavor.go:562"
time="2021-05-12T12:42:54Z" level=info msg="Node info nlhen06st1rm040 already known to cluster\n" file="flavor.go:199"
time="2021-05-12T12:42:54Z" level=info msg="updating Node nlhen06st1rm040 with iqns [iqn.1994-05.com.redhat:60bf19f2dd9] wwpns [10000a5fd7500024 10000a5fd7500026] networks [10.129.0.2/23 169.254.0.1/20 10.59.65.236/26]" file="flavor.go:231"

Because of this UUID conflict, then the CRD hpenodeinfo is populated as follows

$ oc get hpenodeinfo
NAME              AGE
nlhen06st1rm039   69s
$ oc get hpenodeinfo nlhen06st1rm039 -o yaml
apiVersion: storage.hpe.com/v1
kind: HPENodeInfo
metadata:
  creationTimestamp: "2021-05-12T12:43:19Z"
  generation: 3
  managedFields:
  - apiVersion: storage.hpe.com/v1
    fieldsType: FieldsV1
    fieldsV1:
      f:spec:
        .: {}
        f:iqns: {}
        f:networks: {}
        f:uuid: {}
        f:wwpns: {}
    manager: csi-driver
    operation: Update
    time: "2021-05-12T12:43:19Z"
  name: nlhen06st1rm039
  resourceVersion: "1835075"
  selfLink: /apis/storage.hpe.com/v1/hpenodeinfos/nlhen06st1rm039
  uid: 5b312dbd-2932-4e6c-aaf8-01a338924eaf
spec:
  iqns:
  - iqn.1994-05.com.redhat:60bf19f2dd9
  networks:
  - 10.129.0.2/23
  - 169.254.0.1/20
  - 10.59.65.236/26
  uuid: 0a58a9fe-0001-6e6c-6865-6e3036737431
  wwpns:
  - 10000a5fd7500024
  - 10000a5fd7500026

Testing in a different environment with rackmounts (albeit not from HPE), the issue is not present.

Platform details

A couple of questions:

Thanks!

datamattsson commented 3 years ago

@raunakkumar @rgcostea could you help @m4r1k ?

raunakkumar commented 3 years ago

Hi @m4r1k The unique UUID is generated with a combination of hostname and mac address of the host. https://github.com/hpe-storage/common-host-libs/blob/master/chapi/chapidriver_linux.go#L76-L82 The UUID would be same if the hostname and the mac addresses are same. Could you get us output of hostname and ip addr of any two conflicting blades. Also, does the hosts have persistent /etc/ root partition? We persist the node uuid information in a file at /etc/hpe-storage/node.gob

m4r1k commented 3 years ago

Hey everybody,

Hostnames are different (see below output), and the same goes for the IP Address with an exception. These blades all have an Ethernet USB device connected with the same IP Address.

Pay attention to the enp1s0f4u4

Host VH039

[root@nlhen06st1rm039 ~]# hostname
nlhen06st1rm039
[root@nlhen06st1rm039 ~]# hostname -f
nlhen06st1rm039.openshift-pilot.sandbox.nfv.local
[root@nlhen06st1rm039 ~]# ip a
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host
       valid_lft forever preferred_lft forever
2: ens2f0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group default qlen 1000
    link/ether 48:df:37:de:b5:30 brd ff:ff:ff:ff:ff:ff
3: ens2f1: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc mq state DOWN group default qlen 1000
    link/ether 48:df:37:de:b5:31 brd ff:ff:ff:ff:ff:ff
4: eno1: <BROADCAST,MULTICAST,SLAVE,UP,LOWER_UP> mtu 1500 qdisc mq master bond0 state UP group default qlen 1000
    link/ether 92:c2:bf:50:00:26 brd ff:ff:ff:ff:ff:ff
5: eno2: <BROADCAST,MULTICAST,SLAVE,UP,LOWER_UP> mtu 1500 qdisc mq master bond0 state UP group default qlen 1000
    link/ether 92:c2:bf:50:00:26 brd ff:ff:ff:ff:ff:ff
6: enp1s0f4u4: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UNKNOWN group default qlen 1000
    link/ether 5a:00:ee:a5:2b:a2 brd ff:ff:ff:ff:ff:ff
    inet 16.1.15.2/30 brd 16.1.15.3 scope global dynamic noprefixroute enp1s0f4u4
       valid_lft 8639710sec preferred_lft 8639710sec
    inet6 fe80::b838:75f:b4d2:abc4/64 scope link noprefixroute
       valid_lft forever preferred_lft forever
7: ovs-system: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 06:cf:0c:d7:8e:e0 brd ff:ff:ff:ff:ff:ff
8: ovn-k8s-mp0: <BROADCAST,MULTICAST> mtu 1400 qdisc noop state DOWN group default qlen 1000
    link/ether 52:79:ff:09:09:78 brd ff:ff:ff:ff:ff:ff
9: genev_sys_6081: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 65000 qdisc noqueue master ovs-system state UNKNOWN group default qlen 1000
    link/ether 96:75:a5:89:b1:4b brd ff:ff:ff:ff:ff:ff
    inet6 fe80::9475:a5ff:fe89:b14b/64 scope link
       valid_lft forever preferred_lft forever
10: br-int: <BROADCAST,MULTICAST> mtu 1400 qdisc noop state DOWN group default qlen 1000
    link/ether 26:c1:64:34:c6:b7 brd ff:ff:ff:ff:ff:ff
11: ovn-k8s-gw0: <BROADCAST,MULTICAST> mtu 1400 qdisc noop state DOWN group default qlen 1000
    link/ether 0a:58:a9:fe:00:01 brd ff:ff:ff:ff:ff:ff
12: br-local: <BROADCAST,MULTICAST> mtu 1400 qdisc noop state DOWN group default qlen 1000
    link/ether b2:6f:42:7b:d8:4f brd ff:ff:ff:ff:ff:ff
13: bond0: <BROADCAST,MULTICAST,MASTER,UP,LOWER_UP> mtu 1500 qdisc noqueue master ovs-system state UP group default qlen 1000
    link/ether 92:c2:bf:50:00:26 brd ff:ff:ff:ff:ff:ff
14: br-ex: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default qlen 1000
    link/ether 92:c2:bf:50:00:26 brd ff:ff:ff:ff:ff:ff
    inet 10.59.65.234/26 brd 10.59.65.255 scope global dynamic noprefixroute br-ex
       valid_lft 3310sec preferred_lft 3310sec
    inet6 fe80::1804:91c1:6d76:6c8e/64 scope link noprefixroute
       valid_lft forever preferred_lft forever

Host VH040

[root@nlhen06st1rm040 ~]# hostname
nlhen06st1rm040
[root@nlhen06st1rm040 ~]# hostname -f
nlhen06st1rm040.openshift-pilot.sandbox.nfv.local
[root@nlhen06st1rm040 ~]# ip a
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host
       valid_lft forever preferred_lft forever
2: ens2f0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group default qlen 1000
    link/ether 48:df:37:de:b7:f8 brd ff:ff:ff:ff:ff:ff
3: ens2f1: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc mq state DOWN group default qlen 1000
    link/ether 48:df:37:de:b7:f9 brd ff:ff:ff:ff:ff:ff
4: eno1: <BROADCAST,MULTICAST,SLAVE,UP,LOWER_UP> mtu 1500 qdisc mq master bond0 state UP group default qlen 1000
    link/ether 92:c2:bf:50:00:2a brd ff:ff:ff:ff:ff:ff
5: eno2: <BROADCAST,MULTICAST,SLAVE,UP,LOWER_UP> mtu 1500 qdisc mq master bond0 state UP group default qlen 1000
    link/ether 92:c2:bf:50:00:2a brd ff:ff:ff:ff:ff:ff
6: enp1s0f4u4: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UNKNOWN group default qlen 1000
    link/ether 6a:62:2a:89:69:61 brd ff:ff:ff:ff:ff:ff
    inet 16.1.15.2/30 brd 16.1.15.3 scope global dynamic noprefixroute enp1s0f4u4
       valid_lft 8639740sec preferred_lft 8639740sec
    inet6 fe80::67f2:b41d:8cec:8e64/64 scope link noprefixroute
       valid_lft forever preferred_lft forever
7: ovs-system: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 36:6e:42:69:8e:5c brd ff:ff:ff:ff:ff:ff
8: genev_sys_6081: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 65000 qdisc noqueue master ovs-system state UNKNOWN group default qlen 1000
    link/ether 7a:d7:03:5e:49:e0 brd ff:ff:ff:ff:ff:ff
    inet6 fe80::78d7:3ff:fe5e:49e0/64 scope link
       valid_lft forever preferred_lft forever
9: ovn-k8s-mp0: <BROADCAST,MULTICAST> mtu 1400 qdisc noop state DOWN group default qlen 1000
    link/ether 9e:cc:f1:7a:a9:58 brd ff:ff:ff:ff:ff:ff
10: br-int: <BROADCAST,MULTICAST> mtu 1400 qdisc noop state DOWN group default qlen 1000
    link/ether 2a:5d:cd:45:de:29 brd ff:ff:ff:ff:ff:ff
11: ovn-k8s-gw0: <BROADCAST,MULTICAST> mtu 1400 qdisc noop state DOWN group default qlen 1000
    link/ether 0a:58:a9:fe:00:01 brd ff:ff:ff:ff:ff:ff
12: br-local: <BROADCAST,MULTICAST> mtu 1400 qdisc noop state DOWN group default qlen 1000
    link/ether 2a:0a:11:28:4f:44 brd ff:ff:ff:ff:ff:ff
13: bond0: <BROADCAST,MULTICAST,MASTER,UP,LOWER_UP> mtu 1500 qdisc noqueue master ovs-system state UP group default qlen 1000
    link/ether 92:c2:bf:50:00:2a brd ff:ff:ff:ff:ff:ff
14: br-ex: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default qlen 1000
    link/ether 92:c2:bf:50:00:2a brd ff:ff:ff:ff:ff:ff
    inet 10.59.65.235/26 brd 10.59.65.255 scope global dynamic noprefixroute br-ex
       valid_lft 3340sec preferred_lft 3340sec
    inet6 fe80::1240:64af:5702:8a82/64 scope link noprefixroute
       valid_lft forever preferred_lft forever

On the details of enp1s0f4u4

[root@nlhen06st1rm040 ~]# ethtool enp1s0f4u4
Settings for enp1s0f4u4:
        Current message level: 0x00000007 (7)
                               drv probe link
        Link detected: yes
[root@nlhen06st1rm040 ~]# ethtool -i enp1s0f4u4
driver: cdc_eem
version: 22-Aug-2005
firmware-version: CDC EEM Device
expansion-rom-version:
bus-info: usb-0000:01:00.4-4
supports-statistics: no
supports-test: no
supports-eeprom-access: no
supports-register-dump: no
supports-priv-flags: no
[root@nlhen06st1rm040 ~]# modinfo cdc_eem
filename:       /lib/modules/4.18.0-240.22.1.el8_3.x86_64/kernel/drivers/net/usb/cdc_eem.ko.xz
license:        GPL
description:    USB CDC EEM
author:         Omar Laazimani <omar.oberthur@gmail.com>
rhelversion:    8.3
srcversion:     7B36069B1D7AB812D12E939
alias:          usb:v*p*d*dc*dsc*dp*ic02isc0Cip07in*
depends:        usbnet
intree:         Y
name:           cdc_eem
vermagic:       4.18.0-240.22.1.el8_3.x86_64 SMP mod_unload modversions
sig_id:         PKCS#7
signer:         Red Hat Enterprise Linux kernel signing key
<SNIP>
[root@nlhen06st1rm040 ~]# dmesg | grep -i "cdc_eem"
[   22.999518] cdc_eem 1-4:1.0 usb0: register 'cdc_eem' at usb-0000:01:00.4-4, CDC EEM Device, 72:b4:f6:1a:70:04
[   22.999546] usbcore: registered new interface driver cdc_eem
[   23.572948] cdc_eem 1-4:1.0 enp1s0f4u4: renamed from usb0
root@nlhen06st1rm040:/# lsusb
Bus 001 Device 002: ID 03f0:2927 HPE Virtual NIC
Bus 001 Device 001: ID 1d6b:0002
Bus 003 Device 001: ID 1d6b:0003
Bus 002 Device 002: ID 0424:2660
Bus 002 Device 001: ID 1d6b:0002
root@nlhen06st1rm040:/# lsusb -vv -s 001:002

Bus 001 Device 002: ID 03f0:2927 HPE Virtual NIC
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass            2
  bDeviceSubClass        12
  bDeviceProtocol         7
  bMaxPacketSize0        64
  idVendor           0x03f0
  idProduct          0x2927
  bcdDevice            0.01
  iManufacturer           1 HPE
  iProduct                2 Virtual NIC
  iSerial                 0
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x0020
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0
    bmAttributes         0xe0
      Self Powered
      Remote Wakeup
    MaxPower                0mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           2
      bInterfaceClass         2
      bInterfaceSubClass     12
      bInterfaceProtocol      7
      iInterface             16 (error)
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0200  1x 512 bytes
        bInterval               0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x02  EP 2 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0200  1x 512 bytes
        bInterval               0
can't get device qualifier: Resource temporarily unavailable
can't get debug descriptor: Resource temporarily unavailable
Device Status:     0x0001
  Self Powered

So I removed this device (being a USB rmmod cdc_eem works), delete the file /etc/hpe-storage/node.gob but the UUID was generated in the same way

time="2021-05-14T07:11:12Z" level=trace msg=">>>>> NodeGetInfo" file="node_server.go:1861"
time="2021-05-14T07:11:12Z" level=trace msg=">>>>> GetNetworkInterfaces called" file="network.go:125"
time="2021-05-14T07:11:12Z" level=trace msg=">>>>> getNetworkInterfaces called" file="network.go:137"
time="2021-05-14T07:11:12Z" level=trace msg="<<<<< getNetworkInterfaces" file="network.go:176"
time="2021-05-14T07:11:12Z" level=trace msg="<<<<< GetNetworkInterfaces" file="network.go:132"
time="2021-05-14T07:11:12Z" level=info msg="Writing uuid to file:/etc/hpe-storage/node.gob uuid:0a58a9fe-0001-6e6c-6865-6e3036737431" file="chapidriver_linux.go:49"
time="2021-05-14T07:11:12Z" level=trace msg=">>>>> FileSaveGob called with /etc/hpe-storage/node.gob" file="file.go:258"
time="2021-05-14T07:11:12Z" level=trace msg="<<<<< FileSaveGob" file="file.go:273"
time="2021-05-14T07:11:12Z" level=trace msg=">>>>> FileLoadGob called with /etc/hpe-storage/node.gob" file="file.go:278"
time="2021-05-14T07:11:12Z" level=trace msg="<<<<< FileLoadGob" file="file.go:287"
time="2021-05-14T07:11:12Z" level=trace msg=">>>>> GetHostNameAndDomain" file="network.go:40"

At this point looks safe to assume that this USB device is not the root problem.

Could you comment on the rest of the network layout? This is a fairly standard setup: two ethernet devices in a bond which is then connected to the br-ex of OVS.

Thanks!

m4r1k commented 3 years ago

Previous output of the network stack is when the system is just started without any pod running. See below for when the OCP cluster fully up and running

Host VH039

1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host
       valid_lft forever preferred_lft forever
2: ens2f0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group default qlen 1000
    link/ether 48:df:37:de:b5:30 brd ff:ff:ff:ff:ff:ff
3: ens2f1: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc mq state DOWN group default qlen 1000
    link/ether 48:df:37:de:b5:31 brd ff:ff:ff:ff:ff:ff
4: eno1: <BROADCAST,MULTICAST,SLAVE,UP,LOWER_UP> mtu 1500 qdisc mq master bond0 state UP group default qlen 1000
    link/ether 92:c2:bf:50:00:26 brd ff:ff:ff:ff:ff:ff
5: eno2: <BROADCAST,MULTICAST,SLAVE,UP,LOWER_UP> mtu 1500 qdisc mq master bond0 state UP group default qlen 1000
    link/ether 92:c2:bf:50:00:26 brd ff:ff:ff:ff:ff:ff
6: enp1s0f4u4: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UNKNOWN group default qlen 1000
    link/ether 5a:00:ee:a5:2b:a2 brd ff:ff:ff:ff:ff:ff
    inet 16.1.15.2/30 brd 16.1.15.3 scope global dynamic noprefixroute enp1s0f4u4
       valid_lft 8635909sec preferred_lft 8635909sec
    inet6 fe80::b838:75f:b4d2:abc4/64 scope link noprefixroute
       valid_lft forever preferred_lft forever
7: ovs-system: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 06:cf:0c:d7:8e:e0 brd ff:ff:ff:ff:ff:ff
8: ovn-k8s-mp0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue state UNKNOWN group default qlen 1000
    link/ether 52:79:ff:09:09:78 brd ff:ff:ff:ff:ff:ff
    inet 10.128.0.2/23 brd 10.128.1.255 scope global ovn-k8s-mp0
       valid_lft forever preferred_lft forever
    inet6 fe80::5079:ffff:fe09:978/64 scope link
       valid_lft forever preferred_lft forever
9: genev_sys_6081: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 65000 qdisc noqueue master ovs-system state UNKNOWN group default qlen 1000
    link/ether 96:75:a5:89:b1:4b brd ff:ff:ff:ff:ff:ff
    inet6 fe80::9475:a5ff:fe89:b14b/64 scope link
       valid_lft forever preferred_lft forever
10: br-int: <BROADCAST,MULTICAST> mtu 1400 qdisc noop state DOWN group default qlen 1000
    link/ether 26:c1:64:34:c6:b7 brd ff:ff:ff:ff:ff:ff
11: ovn-k8s-gw0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue state UNKNOWN group default qlen 1000
    link/ether 0a:58:a9:fe:00:01 brd ff:ff:ff:ff:ff:ff
    inet 169.254.0.1/20 brd 169.254.15.255 scope global ovn-k8s-gw0
       valid_lft forever preferred_lft forever
    inet6 fe80::858:a9ff:fefe:1/64 scope link
       valid_lft forever preferred_lft forever
12: br-local: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue state UNKNOWN group default qlen 1000
    link/ether b2:6f:42:7b:d8:4f brd ff:ff:ff:ff:ff:ff
    inet6 fe80::b06f:42ff:fe7b:d84f/64 scope link
       valid_lft forever preferred_lft forever
13: bond0: <BROADCAST,MULTICAST,MASTER,UP,LOWER_UP> mtu 1500 qdisc noqueue master ovs-system state UP group default qlen 1000
    link/ether 92:c2:bf:50:00:26 brd ff:ff:ff:ff:ff:ff
14: br-ex: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default qlen 1000
    link/ether 92:c2:bf:50:00:26 brd ff:ff:ff:ff:ff:ff
    inet 10.59.65.234/26 brd 10.59.65.255 scope global dynamic noprefixroute br-ex
       valid_lft 2936sec preferred_lft 2936sec
    inet 10.59.65.204/32 scope global br-ex
       valid_lft forever preferred_lft forever
    inet 10.59.65.205/32 scope global br-ex
       valid_lft forever preferred_lft forever
    inet6 fe80::1804:91c1:6d76:6c8e/64 scope link noprefixroute
       valid_lft forever preferred_lft forever
15: 2f6270a301aa70f@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether d6:53:b6:49:ab:84 brd ff:ff:ff:ff:ff:ff link-netns 29a47804-06de-4a21-8ef0-702617e09da1
    inet6 fe80::d453:b6ff:fe49:ab84/64 scope link
       valid_lft forever preferred_lft forever
16: 54972081e41d9a3@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether f2:73:8d:4b:5b:8d brd ff:ff:ff:ff:ff:ff link-netns 7938e521-5a50-4331-8958-c178e0ff38fd
    inet6 fe80::f073:8dff:fe4b:5b8d/64 scope link
       valid_lft forever preferred_lft forever
17: 29796972c285331@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 72:d6:5c:55:37:5c brd ff:ff:ff:ff:ff:ff link-netns 4e796a0f-dc5f-426c-ad41-dbb113ded74d
    inet6 fe80::70d6:5cff:fe55:375c/64 scope link
       valid_lft forever preferred_lft forever
18: 4d5689027be38cb@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 5e:94:8a:05:55:dc brd ff:ff:ff:ff:ff:ff link-netns e7420aff-4c49-4b1a-b7c6-0904ce81b18c
    inet6 fe80::5c94:8aff:fe05:55dc/64 scope link
       valid_lft forever preferred_lft forever
19: 01fc1a1b63cbe69@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 7e:dc:3e:6d:80:20 brd ff:ff:ff:ff:ff:ff link-netns 6bf1fa53-f465-4468-8615-a250e4c69b9a
    inet6 fe80::7cdc:3eff:fe6d:8020/64 scope link
       valid_lft forever preferred_lft forever
20: 9c31cefaf557fc8@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 42:bf:1d:8f:10:14 brd ff:ff:ff:ff:ff:ff link-netns 754eba16-1a26-4bde-8743-0533fbceb6dc
    inet6 fe80::40bf:1dff:fe8f:1014/64 scope link
       valid_lft forever preferred_lft forever
21: 7824cf73dd6f42f@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 7a:a6:56:45:3b:88 brd ff:ff:ff:ff:ff:ff link-netns e8a99b2a-5d38-4602-99a5-3d8e3c5498e6
    inet6 fe80::78a6:56ff:fe45:3b88/64 scope link
       valid_lft forever preferred_lft forever
22: 8acd87393aaa6c9@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 4e:c4:f9:55:d7:e3 brd ff:ff:ff:ff:ff:ff link-netns 51249606-fa5e-4c4a-8470-7582886d88c1
    inet6 fe80::4cc4:f9ff:fe55:d7e3/64 scope link
       valid_lft forever preferred_lft forever
23: 02d5ae6d7804b42@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 72:95:4b:9c:a1:6e brd ff:ff:ff:ff:ff:ff link-netns cb13e0ee-3f6e-422b-a6c5-dea498966497
    inet6 fe80::7095:4bff:fe9c:a16e/64 scope link
       valid_lft forever preferred_lft forever
24: a35391089334c23@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether a2:57:ae:5b:28:d2 brd ff:ff:ff:ff:ff:ff link-netns 4f0be18d-2d5e-4779-88b7-99a00b8df050
    inet6 fe80::a057:aeff:fe5b:28d2/64 scope link
       valid_lft forever preferred_lft forever
25: f9865658b6f2eb3@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 06:36:35:ec:aa:2e brd ff:ff:ff:ff:ff:ff link-netns 9d514f5e-a280-468f-aff6-13ce0f763518
    inet6 fe80::436:35ff:feec:aa2e/64 scope link
       valid_lft forever preferred_lft forever
26: 7bb4d9e4a2da2d9@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 6e:71:38:96:99:51 brd ff:ff:ff:ff:ff:ff link-netns 9777482c-f1bb-4d51-9376-40007ab165b3
    inet6 fe80::6c71:38ff:fe96:9951/64 scope link
       valid_lft forever preferred_lft forever
27: 98eaba59be76c1f@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether fa:d0:67:e1:97:b6 brd ff:ff:ff:ff:ff:ff link-netns 0c42a920-fe6d-4704-8312-6b039befca12
    inet6 fe80::f8d0:67ff:fee1:97b6/64 scope link
       valid_lft forever preferred_lft forever
28: af40d7094d787ee@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 0e:c0:91:5c:e4:1a brd ff:ff:ff:ff:ff:ff link-netns 9565bfcf-860a-4d8b-b71e-489baa7ea2a8
    inet6 fe80::cc0:91ff:fe5c:e41a/64 scope link
       valid_lft forever preferred_lft forever
29: 5c348bde2112334@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 3e:cf:4e:32:3b:bb brd ff:ff:ff:ff:ff:ff link-netns b893a84e-c0ab-4f74-830a-5063b46aa757
    inet6 fe80::3ccf:4eff:fe32:3bbb/64 scope link
       valid_lft forever preferred_lft forever
30: 5d993af6f389255@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether f2:f7:53:33:15:48 brd ff:ff:ff:ff:ff:ff link-netns 66f098f3-9c91-451d-b1e0-ce1f362004b0
    inet6 fe80::f0f7:53ff:fe33:1548/64 scope link
       valid_lft forever preferred_lft forever
31: 6041c6089b2ac6b@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether f6:19:b1:1c:89:26 brd ff:ff:ff:ff:ff:ff link-netns e7f0985c-ea6e-474b-998e-8559b3889b38
    inet6 fe80::f419:b1ff:fe1c:8926/64 scope link
       valid_lft forever preferred_lft forever
32: 744c7cf5b77f7a3@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 3a:9c:77:e9:da:c1 brd ff:ff:ff:ff:ff:ff link-netns 6ec4fc5b-6fc4-4571-8960-8509abc37f4f
    inet6 fe80::389c:77ff:fee9:dac1/64 scope link
       valid_lft forever preferred_lft forever
33: 352cd24b0040f01@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 12:c8:5a:d3:dd:56 brd ff:ff:ff:ff:ff:ff link-netns c48f6337-1e34-4393-a771-9c3c575fd8da
    inet6 fe80::10c8:5aff:fed3:dd56/64 scope link
       valid_lft forever preferred_lft forever
34: 190e1d2315eed18@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether c6:8d:77:d1:2c:d3 brd ff:ff:ff:ff:ff:ff link-netns dc8a10ff-7763-464b-9d20-fe4bae0288ec
    inet6 fe80::c48d:77ff:fed1:2cd3/64 scope link
       valid_lft forever preferred_lft forever
35: af367b4a83ef5f7@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 82:cf:cc:68:70:f9 brd ff:ff:ff:ff:ff:ff link-netns ad6251f0-0ebb-4ce5-90a4-693274e1445a
    inet6 fe80::80cf:ccff:fe68:70f9/64 scope link
       valid_lft forever preferred_lft forever
36: 6ebbb8e38ff6ad4@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 32:93:f0:18:01:23 brd ff:ff:ff:ff:ff:ff link-netns 42fa72ac-8837-4cc5-8379-1e5391d42970
    inet6 fe80::3093:f0ff:fe18:123/64 scope link
       valid_lft forever preferred_lft forever
37: 593253077aa6dbb@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 62:28:28:d3:55:45 brd ff:ff:ff:ff:ff:ff link-netns 452d5c78-e550-478e-a158-172eefaa8434
    inet6 fe80::6028:28ff:fed3:5545/64 scope link
       valid_lft forever preferred_lft forever
38: 60c28718173977b@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether fa:cf:30:59:28:24 brd ff:ff:ff:ff:ff:ff link-netns 101606b8-bc37-42a4-b546-60262d6a320d
    inet6 fe80::f8cf:30ff:fe59:2824/64 scope link
       valid_lft forever preferred_lft forever
39: 845b8f4e707f055@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether c6:a0:5d:6e:e4:ce brd ff:ff:ff:ff:ff:ff link-netns cf9a8c2a-14ef-45ac-8395-00e95ef7a6b3
    inet6 fe80::c4a0:5dff:fe6e:e4ce/64 scope link
       valid_lft forever preferred_lft forever

Host VH040

1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host
       valid_lft forever preferred_lft forever
2: ens2f0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group default qlen 1000
    link/ether 48:df:37:de:b7:f8 brd ff:ff:ff:ff:ff:ff
3: ens2f1: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc mq state DOWN group default qlen 1000
    link/ether 48:df:37:de:b7:f9 brd ff:ff:ff:ff:ff:ff
4: eno1: <BROADCAST,MULTICAST,SLAVE,UP,LOWER_UP> mtu 1500 qdisc mq master bond0 state UP group default qlen 1000
    link/ether 92:c2:bf:50:00:2a brd ff:ff:ff:ff:ff:ff
5: eno2: <BROADCAST,MULTICAST,SLAVE,UP,LOWER_UP> mtu 1500 qdisc mq master bond0 state UP group default qlen 1000
    link/ether 92:c2:bf:50:00:2a brd ff:ff:ff:ff:ff:ff
7: ovs-system: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 36:6e:42:69:8e:5c brd ff:ff:ff:ff:ff:ff
8: genev_sys_6081: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 65000 qdisc noqueue master ovs-system state UNKNOWN group default qlen 1000
    link/ether 7a:d7:03:5e:49:e0 brd ff:ff:ff:ff:ff:ff
    inet6 fe80::78d7:3ff:fe5e:49e0/64 scope link
       valid_lft forever preferred_lft forever
9: ovn-k8s-mp0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue state UNKNOWN group default qlen 1000
    link/ether 9e:cc:f1:7a:a9:58 brd ff:ff:ff:ff:ff:ff
    inet 10.130.0.2/23 brd 10.130.1.255 scope global ovn-k8s-mp0
       valid_lft forever preferred_lft forever
    inet6 fe80::9ccc:f1ff:fe7a:a958/64 scope link
       valid_lft forever preferred_lft forever
10: br-int: <BROADCAST,MULTICAST> mtu 1400 qdisc noop state DOWN group default qlen 1000
    link/ether 2a:5d:cd:45:de:29 brd ff:ff:ff:ff:ff:ff
11: ovn-k8s-gw0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue state UNKNOWN group default qlen 1000
    link/ether 0a:58:a9:fe:00:01 brd ff:ff:ff:ff:ff:ff
    inet 169.254.0.1/20 brd 169.254.15.255 scope global ovn-k8s-gw0
       valid_lft forever preferred_lft forever
    inet6 fe80::858:a9ff:fefe:1/64 scope link
       valid_lft forever preferred_lft forever
12: br-local: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue state UNKNOWN group default qlen 1000
    link/ether 2a:0a:11:28:4f:44 brd ff:ff:ff:ff:ff:ff
    inet6 fe80::280a:11ff:fe28:4f44/64 scope link
       valid_lft forever preferred_lft forever
13: bond0: <BROADCAST,MULTICAST,MASTER,UP,LOWER_UP> mtu 1500 qdisc noqueue master ovs-system state UP group default qlen 1000
    link/ether 92:c2:bf:50:00:2a brd ff:ff:ff:ff:ff:ff
14: br-ex: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default qlen 1000
    link/ether 92:c2:bf:50:00:2a brd ff:ff:ff:ff:ff:ff
    inet 10.59.65.235/26 brd 10.59.65.255 scope global dynamic noprefixroute br-ex
       valid_lft 2950sec preferred_lft 2950sec
    inet6 fe80::1240:64af:5702:8a82/64 scope link noprefixroute
       valid_lft forever preferred_lft forever
15: a1ab33356ef273d@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 42:5d:bc:5e:1f:ea brd ff:ff:ff:ff:ff:ff link-netns 3ddc6f56-b02f-493c-acee-bf15bd051280
    inet6 fe80::405d:bcff:fe5e:1fea/64 scope link
       valid_lft forever preferred_lft forever
16: c67fb9319c44a34@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 2e:77:c0:10:f6:a4 brd ff:ff:ff:ff:ff:ff link-netns aff6d319-85c3-48e0-b3bb-584ab6f90d49
    inet6 fe80::2c77:c0ff:fe10:f6a4/64 scope link
       valid_lft forever preferred_lft forever
17: 5c8cdd16c0fe25e@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 9e:bf:07:35:c6:e6 brd ff:ff:ff:ff:ff:ff link-netns 9d1f88be-c8ff-4e08-a554-8db1e3e9a145
    inet6 fe80::9cbf:7ff:fe35:c6e6/64 scope link
       valid_lft forever preferred_lft forever
18: 350356ec5ee89e8@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 72:af:d9:d0:72:71 brd ff:ff:ff:ff:ff:ff link-netns 2b69e649-5e3e-45f1-a9f9-d73a15519afb
    inet6 fe80::70af:d9ff:fed0:7271/64 scope link
       valid_lft forever preferred_lft forever
19: c4cdcffe0a349bb@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 9e:8d:e4:51:da:c2 brd ff:ff:ff:ff:ff:ff link-netns 28e80dfe-0b84-42f1-a7f5-3d61bd6a97b6
    inet6 fe80::9c8d:e4ff:fe51:dac2/64 scope link
       valid_lft forever preferred_lft forever
20: f7811c1e03e6acd@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 5a:26:c9:2d:c6:1e brd ff:ff:ff:ff:ff:ff link-netns f5f770ad-d18e-47bd-85df-c503cd09cadb
    inet6 fe80::5826:c9ff:fe2d:c61e/64 scope link
       valid_lft forever preferred_lft forever
21: 91d2ce7b566af53@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 0e:97:05:24:29:5f brd ff:ff:ff:ff:ff:ff link-netns 99b99668-9bfa-4d19-b5f3-c303fa167f61
    inet6 fe80::c97:5ff:fe24:295f/64 scope link
       valid_lft forever preferred_lft forever
22: 16d1355b8d495e5@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 26:6f:8f:9a:11:4b brd ff:ff:ff:ff:ff:ff link-netns c911a0c5-1858-44ed-bdee-45153ef17067
    inet6 fe80::246f:8fff:fe9a:114b/64 scope link
       valid_lft forever preferred_lft forever
23: fb65d8fa3fac01a@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 92:f5:fd:1c:08:ab brd ff:ff:ff:ff:ff:ff link-netns 1dd32164-dd87-4315-a223-2fdb38ce79fe
    inet6 fe80::90f5:fdff:fe1c:8ab/64 scope link
       valid_lft forever preferred_lft forever
24: 6fb12a7a768ccef@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 0a:a8:45:e4:46:f4 brd ff:ff:ff:ff:ff:ff link-netns aabc8927-fcd3-4ed5-8177-ef70f86222ed
    inet6 fe80::8a8:45ff:fee4:46f4/64 scope link
       valid_lft forever preferred_lft forever
25: 771f9aad1588e1c@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether f2:00:0d:34:a9:8a brd ff:ff:ff:ff:ff:ff link-netns e5a29750-0de5-44c4-836f-e4b237000724
    inet6 fe80::f000:dff:fe34:a98a/64 scope link
       valid_lft forever preferred_lft forever
26: 7501df8cd39952c@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 06:05:8d:76:d7:94 brd ff:ff:ff:ff:ff:ff link-netns ab795ed4-83a7-4e9d-8116-048f6173c663
    inet6 fe80::405:8dff:fe76:d794/64 scope link
       valid_lft forever preferred_lft forever
27: a3013ddd9a33c9e@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 8a:b4:f1:4d:7f:fa brd ff:ff:ff:ff:ff:ff link-netns d603fdac-1b67-4f9a-a5fb-b685fa5e59ba
    inet6 fe80::88b4:f1ff:fe4d:7ffa/64 scope link
       valid_lft forever preferred_lft forever
28: a17613e60ecc962@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 2a:6c:1d:3f:df:3f brd ff:ff:ff:ff:ff:ff link-netns 1cc841ce-5c21-4314-8277-c6ceae0884c5
    inet6 fe80::286c:1dff:fe3f:df3f/64 scope link
       valid_lft forever preferred_lft forever
29: 365e02fb5847d7d@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 9e:85:cf:33:68:fe brd ff:ff:ff:ff:ff:ff link-netns 5fac014a-6907-4a2c-ad45-6464727a175b
    inet6 fe80::9c85:cfff:fe33:68fe/64 scope link
       valid_lft forever preferred_lft forever
30: f6c1bc8dc4761da@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 4a:b5:7a:c8:41:ab brd ff:ff:ff:ff:ff:ff link-netns ba98a59d-2c04-4af5-a365-e1c5fed7690c
    inet6 fe80::48b5:7aff:fec8:41ab/64 scope link
       valid_lft forever preferred_lft forever
31: bddf6c0d266cc81@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 1e:b1:82:b4:24:cd brd ff:ff:ff:ff:ff:ff link-netns 3133dd34-c527-43fb-aa80-cdcbb1922f93
    inet6 fe80::1cb1:82ff:feb4:24cd/64 scope link
       valid_lft forever preferred_lft forever
32: c778c65df756f3b@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 32:54:39:75:cb:50 brd ff:ff:ff:ff:ff:ff link-netns 82124060-955c-4a26-b885-a88c7d7d3b58
    inet6 fe80::3054:39ff:fe75:cb50/64 scope link
       valid_lft forever preferred_lft forever
33: 1913b72faaf80e0@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 8a:dc:a7:a5:57:a7 brd ff:ff:ff:ff:ff:ff link-netns 70d0a37b-d7af-45d5-acba-748c35028661
    inet6 fe80::88dc:a7ff:fea5:57a7/64 scope link
       valid_lft forever preferred_lft forever
34: 68e6f47eacecadb@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 5a:31:82:22:03:a9 brd ff:ff:ff:ff:ff:ff link-netns cd651186-3c04-4475-ac37-a7a86ed8d04d
    inet6 fe80::5831:82ff:fe22:3a9/64 scope link
       valid_lft forever preferred_lft forever
35: b039bcd08ee770c@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 0a:23:ee:1c:99:02 brd ff:ff:ff:ff:ff:ff link-netns a5bb8f0d-d987-44dc-8485-e355e1963518
    inet6 fe80::823:eeff:fe1c:9902/64 scope link
       valid_lft forever preferred_lft forever
36: 4237c6ef6a8f70c@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether c2:33:d0:a8:12:dd brd ff:ff:ff:ff:ff:ff link-netns 3f054c71-2985-4dc5-9431-ceed1041f4f9
    inet6 fe80::c033:d0ff:fea8:12dd/64 scope link
       valid_lft forever preferred_lft forever
37: d6c4ea6bc19ec18@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether f2:af:20:c2:39:0c brd ff:ff:ff:ff:ff:ff link-netns fa19c0cc-87a3-4c11-ada6-361ff730ead2
    inet6 fe80::f0af:20ff:fec2:390c/64 scope link
       valid_lft forever preferred_lft forever
38: 5d3c83b972b94b8@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 0e:ba:63:26:15:67 brd ff:ff:ff:ff:ff:ff link-netns 054ef41b-3323-486c-9cc6-4bd50b1dc2d9
    inet6 fe80::cba:63ff:fe26:1567/64 scope link
       valid_lft forever preferred_lft forever
39: 63bae0a93c23357@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether be:32:aa:14:dd:4a brd ff:ff:ff:ff:ff:ff link-netns 5c5a57d0-1d6c-4257-89e9-dcc805443593
    inet6 fe80::bc32:aaff:fe14:dd4a/64 scope link
       valid_lft forever preferred_lft forever
40: dcff8cd038a794f@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 46:97:4c:06:26:ff brd ff:ff:ff:ff:ff:ff link-netns 8b77e7de-03d3-4be2-a46d-55f56f285e18
    inet6 fe80::4497:4cff:fe06:26ff/64 scope link
       valid_lft forever preferred_lft forever
41: 0e8c2f2b6e4f361@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 3e:32:d4:9c:e5:dc brd ff:ff:ff:ff:ff:ff link-netns b301635c-6df5-4d2a-841a-258436729afb
    inet6 fe80::3c32:d4ff:fe9c:e5dc/64 scope link
       valid_lft forever preferred_lft forever
42: 3571e02594719e7@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 36:d1:c9:f9:84:1a brd ff:ff:ff:ff:ff:ff link-netns 17c83009-7c99-4173-acee-4da8272a5b7b
    inet6 fe80::34d1:c9ff:fef9:841a/64 scope link
       valid_lft forever preferred_lft forever
43: d100e4d80732cde@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether a2:34:7b:fa:e8:bb brd ff:ff:ff:ff:ff:ff link-netns c85621cf-dd33-4efb-aebf-8a90b231e0b0
    inet6 fe80::a034:7bff:fefa:e8bb/64 scope link
       valid_lft forever preferred_lft forever
44: 150594ed68de30f@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether aa:e4:95:a7:c0:b9 brd ff:ff:ff:ff:ff:ff link-netns 6ea67090-a717-4981-9d28-ce774bdb4c91
    inet6 fe80::a8e4:95ff:fea7:c0b9/64 scope link
       valid_lft forever preferred_lft forever
45: 1af8fcb55dea90a@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether ce:bb:c7:58:f4:ed brd ff:ff:ff:ff:ff:ff link-netns 87b4428c-c1e9-488e-85a7-d19c91015121
    inet6 fe80::ccbb:c7ff:fe58:f4ed/64 scope link
       valid_lft forever preferred_lft forever
46: 2a3650663d03157@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether b6:00:3d:8c:70:a6 brd ff:ff:ff:ff:ff:ff link-netns 42a91a17-b4dc-426b-9752-06adbade0aaa
    inet6 fe80::b400:3dff:fe8c:70a6/64 scope link
       valid_lft forever preferred_lft forever
47: 9ec2613db2726e9@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether fe:c8:02:c3:b7:92 brd ff:ff:ff:ff:ff:ff link-netns 2f36beb4-e6f6-418a-a13f-755c0366ac91
    inet6 fe80::fcc8:2ff:fec3:b792/64 scope link
       valid_lft forever preferred_lft forever
48: a740b5ac9817b34@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether a2:e6:ff:e4:77:6b brd ff:ff:ff:ff:ff:ff link-netns f5b2935a-47ca-4cc9-a2d2-a785ceff95c3
    inet6 fe80::a0e6:ffff:fee4:776b/64 scope link
       valid_lft forever preferred_lft forever
49: 85a84445c8d173a@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether b2:42:2f:98:61:29 brd ff:ff:ff:ff:ff:ff link-netns 27958c32-6bbf-4cfa-8899-07256cf4a52e
    inet6 fe80::b042:2fff:fe98:6129/64 scope link
       valid_lft forever preferred_lft forever
50: 6798fbcb57751de@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 26:d7:6c:ec:66:4d brd ff:ff:ff:ff:ff:ff link-netns d93047b5-8926-44f3-9474-9cc1dbee2cbe
    inet6 fe80::24d7:6cff:feec:664d/64 scope link
       valid_lft forever preferred_lft forever
51: a6f8d776e73bff3@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 4e:4c:d0:68:ba:7a brd ff:ff:ff:ff:ff:ff link-netns c309792d-985f-4d66-bc21-040945df475f
    inet6 fe80::4c4c:d0ff:fe68:ba7a/64 scope link
       valid_lft forever preferred_lft forever
52: d14a61867ecf262@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 92:db:25:ce:9d:b6 brd ff:ff:ff:ff:ff:ff link-netns a99f4e8b-8caf-4900-ad6b-3cf5e8421db0
    inet6 fe80::90db:25ff:fece:9db6/64 scope link
       valid_lft forever preferred_lft forever
53: 88c23e9a788e2c8@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 02:a1:bc:e0:fa:ee brd ff:ff:ff:ff:ff:ff link-netns 1aec894d-4fba-4d54-a2ef-e0609e1b82dc
    inet6 fe80::a1:bcff:fee0:faee/64 scope link
       valid_lft forever preferred_lft forever
54: aa3cb2617f828be@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 7a:31:44:4e:3a:61 brd ff:ff:ff:ff:ff:ff link-netns 55399a4f-a6cf-41bc-aaf4-f1c5f8cf1854
    inet6 fe80::7831:44ff:fe4e:3a61/64 scope link
       valid_lft forever preferred_lft forever
55: 1dea763b4c96bfa@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether aa:ab:a6:a7:17:47 brd ff:ff:ff:ff:ff:ff link-netns ab854887-5db1-4063-b140-486925082069
    inet6 fe80::a8ab:a6ff:fea7:1747/64 scope link
       valid_lft forever preferred_lft forever
56: 2eb1adcbe352cc8@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether aa:a8:6d:cc:3b:a6 brd ff:ff:ff:ff:ff:ff link-netns 08a6b066-07ca-41fa-b548-7cf8548c885a
    inet6 fe80::a8a8:6dff:fecc:3ba6/64 scope link
       valid_lft forever preferred_lft forever
57: 7579cb15025b0f6@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 36:66:36:94:4e:6d brd ff:ff:ff:ff:ff:ff link-netns 0652ed8d-fce9-4dd4-bf20-d76e10509748
    inet6 fe80::3466:36ff:fe94:4e6d/64 scope link
       valid_lft forever preferred_lft forever
58: 9c0fe0b75e9e1bf@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether aa:43:66:16:39:96 brd ff:ff:ff:ff:ff:ff link-netns 2009d12a-c5c5-4f7f-8219-39d2ce0301cf
    inet6 fe80::a843:66ff:fe16:3996/64 scope link
       valid_lft forever preferred_lft forever
59: 3c00dbf7f247bf6@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether fa:dd:d8:97:04:ae brd ff:ff:ff:ff:ff:ff link-netns aac42230-7d91-4fdf-914e-11b348f2ee92
    inet6 fe80::f8dd:d8ff:fe97:4ae/64 scope link
       valid_lft forever preferred_lft forever
60: caa5c23673d8959@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1400 qdisc noqueue master ovs-system state UP group default
    link/ether 22:78:7f:04:c0:40 brd ff:ff:ff:ff:ff:ff link-netns b91d2c84-c40c-4192-908a-d8aa62394f04
    inet6 fe80::2078:7fff:fe04:c040/64 scope link
       valid_lft forever preferred_lft forever
61: enp1s0f4u4: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UNKNOWN group default qlen 1000
    link/ether 6a:62:2a:89:69:61 brd ff:ff:ff:ff:ff:ff
    inet 16.1.15.2/30 brd 16.1.15.3 scope global dynamic noprefixroute enp1s0f4u4
       valid_lft 8635940sec preferred_lft 8635940sec
    inet6 fe80::67f2:b41d:8cec:8e64/64 scope link noprefixroute
       valid_lft forever preferred_lft forever

HTH to further nail down the UUID conflict. Thanks!

raunakkumar commented 3 years ago

Thanks for the details. It is still baffling to see 2 nodes with 2 different hostnames and mac address would yield same uuid. Could you please share the log snippet from both nodes just after writing uuid to file. It begins with Host name reported as and ends with "Adding node with name with the networks in between.

m4r1k commented 3 years ago

Apologies for the late answer. Here we go with the full logs of hpe-csi-node

vh039

+ for arg in '"$@"'
+ '[' --endpoint=unix:///csi/csi.sock = --node-service ']'
+ for arg in '"$@"'
+ '[' --node-service = --node-service ']'
+ nodeservice=true
+ for arg in '"$@"'
+ '[' --flavor=kubernetes = --node-service ']'
+ '[' true = true ']'
+ '[' '' = true ']'
+ cp -f /opt/hpe-storage/lib/hpe-storage-node.service /etc/systemd/system/hpe-storage-node.service
+ cp -f /opt/hpe-storage/lib/hpe-storage-node.sh /etc/hpe-storage/hpe-storage-node.sh
+ chmod +x /etc/hpe-storage/hpe-storage-node.sh
+ echo 'running node conformance checks...'
running node conformance checks...
+ systemctl daemon-reload
+ systemctl restart hpe-storage-node
+ echo 'copying hpe log collector diag script'
+ cp -f /opt/hpe-storage/bin/hpe-logcollector.sh /usr/local/bin/hpe-logcollector.sh
copying hpe log collector diag script
+ chmod +x /usr/local/bin/hpe-logcollector.sh
+ '[' '!' -f /host/etc/multipath.conf ']'
+ ln -s /host/etc/multipath.conf /etc/multipath.conf
+ ln -s /host/etc/multipath /etc/multipath
+ ln -s /host/etc/iscsi /etc/iscsi
+ '[' -f /host/etc/redhat-release ']'
+ rm /etc/redhat-release
+ ln -s /host/etc/redhat-release /etc/redhat-release
+ '[' -f /host/etc/os-release ']'
+ rm /etc/os-release
+ ln -s /host/etc/os-release /etc/os-release
starting csi plugin...
+ echo 'starting csi plugin...'
+ exec /bin/csi-driver --endpoint=unix:///csi/csi.sock --node-service --flavor=kubernetes
time="2021-05-18T08:22:43Z" level=info msg="Initialized logging." alsoLogToStderr=true logFileLocation=/var/log/hpe-csi-node.log logLevel=trace
time="2021-05-18T08:22:43Z" level=info msg="**********************************************" file="csi-driver.go:54"
time="2021-05-18T08:22:43Z" level=info msg="*************** HPE CSI DRIVER ***************" file="csi-driver.go:55"
time="2021-05-18T08:22:43Z" level=info msg="**********************************************" file="csi-driver.go:56"
time="2021-05-18T08:22:43Z" level=info msg=">>>>> CMDLINE Exec, args: []" file="csi-driver.go:58"
time="2021-05-18T08:22:43Z" level=trace msg=">>>>> csiCliHandler" file="csi-driver.go:83"
time="2021-05-18T08:22:43Z" level=trace msg=">>>>> FileExists for path /csi" file="file.go:62"
time="2021-05-18T08:22:43Z" level=trace msg="<<<<< FileExists" file="file.go:72"
time="2021-05-18T08:22:43Z" level=trace msg=">>>>> ConfigureIscsi" file="iscsi.go:394"
time="2021-05-18T08:22:43Z" level=trace msg="ExecCommandOutputWithTimeout called with lsb_release[-a] 60" file="cmd.go:35"
time="2021-05-18T08:22:43Z" level=trace msg="lsb_release is not available on the system" file="os.go:144"
time="2021-05-18T08:22:43Z" level=trace msg=">>>>> FileReadFirstLine" file="file.go:35"
time="2021-05-18T08:22:43Z" level=trace msg="Red Hat Enterprise Linux CoreOS release 4.7" file="file.go:55"
time="2021-05-18T08:22:43Z" level=trace msg="<<<<< FileReadFirstLine" file="file.go:56"
time="2021-05-18T08:22:43Z" level=trace msg="matched os info map:map[distro:Red major:4 minor:7]" file="os.go:245"
time="2021-05-18T08:22:43Z" level=trace msg="ExecCommandOutputWithTimeout called with uname[-r] 60" file="cmd.go:35"
time="2021-05-18T08:22:43Z" level=trace msg="process with pid: 36 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:43Z" level=trace msg="4.18.0-240.22.1.el8_3.x86_64\n" file="cmd.go:66"
time="2021-05-18T08:22:43Z" level=info msg="got OS details as [redhat 4 7 4.18.0-240.22.1.el8_3.x86_64]\n" file="os.go:94"
time="2021-05-18T08:22:43Z" level=trace msg=">>>>> EnableService called with iscsi" file="os.go:465"
time="2021-05-18T08:22:43Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[--version] 60" file="cmd.go:35"
time="2021-05-18T08:22:43Z" level=trace msg="process with pid: 40 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:43Z" level=trace msg="systemd 219\n+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN\n" file="cmd.go:66"
time="2021-05-18T08:22:43Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[daemon-reload] 60" file="cmd.go:35"
time="2021-05-18T08:22:43Z" level=trace msg="process with pid: 41 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:43Z" level=trace file="cmd.go:66"
time="2021-05-18T08:22:43Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[enable iscsid.service] 60" file="cmd.go:35"
time="2021-05-18T08:22:44Z" level=trace msg="process with pid: 42 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:44Z" level=trace file="cmd.go:66"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< EnableService" file="os.go:477"
time="2021-05-18T08:22:44Z" level=trace msg="SetIscsiRecommendations called" file="iscsi.go:348"
time="2021-05-18T08:22:44Z" level=trace msg="GetIscsiRecommendations called" file="iscsi.go:173"
time="2021-05-18T08:22:44Z" level=trace msg="Reading template config file: /opt/hpe-storage/nimbletune/config.json" file="config.go:191"
time="2021-05-18T08:22:44Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:44Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:44Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:44Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:44Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:44Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:44Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> GetIfaces" file="iscsi.go:500"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> GetIscsiIfacesPath" file="iscsi.go:481"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileExists for path /var/lib/iscsi/ifaces" file="file.go:62"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileExists" file="file.go:68"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileExists for path /etc/iscsi/ifaces" file="file.go:62"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileExists" file="file.go:68"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< GetIscsiIfacesPath" file="iscsi.go:488"
time="2021-05-18T08:22:44Z" level=trace msg="no iscsi ifaces found" file="iscsi.go:513"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< GetIfaces" file="iscsi.go:514"
time="2021-05-18T08:22:44Z" level=info msg="No further iSCSI recommendations are found for this host" file="iscsi.go:387"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> ServiceCommand called with type iscsi op start" file="os.go:569"
time="2021-05-18T08:22:44Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[--version] 60" file="cmd.go:35"
time="2021-05-18T08:22:44Z" level=trace msg="process with pid: 43 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:44Z" level=trace msg="systemd 219\n+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN\n" file="cmd.go:66"
time="2021-05-18T08:22:44Z" level=trace msg="running command  systemctl  args:  [start iscsid]" file="os.go:601"
time="2021-05-18T08:22:44Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[start iscsid] 60" file="cmd.go:35"
time="2021-05-18T08:22:44Z" level=trace msg="process with pid: 44 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:44Z" level=trace file="cmd.go:66"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< ServiceCommand" file="os.go:608"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< ConfigureIscsi" file="iscsi.go:421"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> ConfigureMultipath" file="multipath.go:346"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> SetMultipathRecommendations" file="multipath.go:295"
time="2021-05-18T08:22:44Z" level=trace msg="GetMultipathRecommendations called" file="multipath.go:178"
time="2021-05-18T08:22:44Z" level=trace msg="ExecCommandOutputWithTimeout called with dmidecode[--type system] 60" file="cmd.go:35"
time="2021-05-18T08:22:44Z" level=error msg="process with pid : 45 finished with error = exit status 127" file="cmd.go:60"
time="2021-05-18T08:22:44Z" level=trace msg="/usr/bin/env: 'dmidecode': No such file or directory\n" file="cmd.go:66"
time="2021-05-18T08:22:44Z" level=error msg="unable to get system information using dmidecode command dmidecode failed with rc=127 err=/usr/bin/env: 'dmidecode': No such file or directory\n" file="system.go:31"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileGetStringsWithPattern called with path: /sys/firmware/dmi/tables/DMI Pattern: vmware.*|qemu|hyper.*" file="file.go:112"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileGetStringsWithPattern" file="file.go:150"
time="2021-05-18T08:22:44Z" level=trace msg="DMI-SYSFS: System is running as a virtual machine" file="system.go:115"
time="2021-05-18T08:22:44Z" level=trace msg="getMultipathDeviceScopeRecommendations called" file="multipath.go:102"
time="2021-05-18T08:22:44Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey product value \"Server\" recommended \"Server\"" file="multipath.go:72"
time="2021-05-18T08:22:44Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey prio value alua recommended alua" file="multipath.go:72"
time="2021-05-18T08:22:44Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey hardware_handler value \"1 alua\" recommended \"1 alua\"" file="multipath.go:72"
time="2021-05-18T08:22:44Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey no_path_retry value 30 recommended 30" file="multipath.go:72"
time="2021-05-18T08:22:44Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey vendor value \"Nimble\" recommended \"Nimble\"" file="multipath.go:72"
time="2021-05-18T08:22:44Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey path_grouping_policy value group_by_prio recommended group_by_prio" file="multipath.go:72"
time="2021-05-18T08:22:44Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey dev_loss_tmo value infinity recommended infinity" file="multipath.go:72"
time="2021-05-18T08:22:44Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey failback value immediate recommended immediate" file="multipath.go:72"
time="2021-05-18T08:22:44Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey fast_io_fail_tmo value 5 recommended 5" file="multipath.go:72"
time="2021-05-18T08:22:44Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey path_selector value \"service-time 0\" recommended \"service-time 0\"" file="multipath.go:72"
time="2021-05-18T08:22:44Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey path_checker value tur recommended tur" file="multipath.go:72"
time="2021-05-18T08:22:44Z" level=trace msg="ParseConfig called" file="configresource.go:264"
time="2021-05-18T08:22:44Z" level=trace msg="adding section defaults" file="configresource.go:289"
time="2021-05-18T08:22:44Z" level=trace msg="addSection called with defaults" file="configresource.go:180"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param user_friendly_names value yes" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param find_multipaths value no" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param enable_foreign value \"^$\"" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="adding section blacklist_exceptions" file="configresource.go:289"
time="2021-05-18T08:22:44Z" level=trace msg="addSection called with blacklist_exceptions" file="configresource.go:180"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param property value \"(SCSI_IDENT_|ID_WWN)\"" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="adding section blacklist" file="configresource.go:289"
time="2021-05-18T08:22:44Z" level=trace msg="addSection called with blacklist" file="configresource.go:180"
time="2021-05-18T08:22:44Z" level=trace msg="adding section devices" file="configresource.go:289"
time="2021-05-18T08:22:44Z" level=trace msg="addSection called with devices" file="configresource.go:180"
time="2021-05-18T08:22:44Z" level=trace msg="adding section device" file="configresource.go:289"
time="2021-05-18T08:22:44Z" level=trace msg="addSection called with device" file="configresource.go:180"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param failback value immediate" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param path_grouping_policy value group_by_prio" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param fast_io_fail_tmo value 5" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param dev_loss_tmo value infinity" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param hardware_handler value \"1 alua\"" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param product value \"Server\"" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param path_selector value \"service-time 0\"" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param prio value alua" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param path_checker value tur" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param vendor value \"Nimble\"" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:44Z" level=trace msg="parseOption param no_path_retry value 30" file="configresource.go:216"
time="2021-05-18T08:22:44Z" level=trace msg="GetNimbleSection called" file="configresource.go:354"
time="2021-05-18T08:22:44Z" level=trace msg="GetSection called with defaults" file="configresource.go:379"
time="2021-05-18T08:22:44Z" level=trace msg="SaveConfig called" file="configresource.go:318"
time="2021-05-18T08:22:44Z" level=trace msg="PrintConf called" file="configresource.go:153"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> ServiceCommand called with type multipath op start" file="os.go:569"
time="2021-05-18T08:22:44Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[--version] 60" file="cmd.go:35"
time="2021-05-18T08:22:44Z" level=trace msg="process with pid: 47 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:44Z" level=trace msg="systemd 219\n+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN\n" file="cmd.go:66"
time="2021-05-18T08:22:44Z" level=trace msg="running command  systemctl  args:  [start multipathd]" file="os.go:601"
time="2021-05-18T08:22:44Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[start multipathd] 60" file="cmd.go:35"
time="2021-05-18T08:22:44Z" level=trace msg="process with pid: 48 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:44Z" level=trace file="cmd.go:66"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< ServiceCommand" file="os.go:608"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> MultipathdReconfigure" file="multipath.go:57"
time="2021-05-18T08:22:44Z" level=trace msg="ExecCommandOutputWithTimeout called with multipathd[reconfigure] 60" file="cmd.go:35"
time="2021-05-18T08:22:44Z" level=trace msg="process with pid: 49 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:44Z" level=trace msg="ok\n" file="cmd.go:66"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<<< MultipathdReconfigure" file="multipath.go:70"
time="2021-05-18T08:22:44Z" level=info msg="Successfully configured multipath.conf settings" file="multipath.go:338"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< SetMultipathRecommendations" file="multipath.go:339"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< ConfigureMultipath" file="multipath.go:354"
time="2021-05-18T08:22:44Z" level=trace msg="About to start the CSI driver 'csi.hpe.com'" file="csi-driver.go:138"
time="2021-05-18T08:22:44Z" level=info msg="Enabling controller service capability: CREATE_DELETE_VOLUME" file="driver.go:229"
time="2021-05-18T08:22:44Z" level=info msg="Enabling controller service capability: PUBLISH_UNPUBLISH_VOLUME" file="driver.go:229"
time="2021-05-18T08:22:44Z" level=info msg="Enabling controller service capability: LIST_VOLUMES" file="driver.go:229"
time="2021-05-18T08:22:44Z" level=info msg="Enabling controller service capability: CREATE_DELETE_SNAPSHOT" file="driver.go:229"
time="2021-05-18T08:22:44Z" level=info msg="Enabling controller service capability: LIST_SNAPSHOTS" file="driver.go:229"
time="2021-05-18T08:22:44Z" level=info msg="Enabling controller service capability: CLONE_VOLUME" file="driver.go:229"
time="2021-05-18T08:22:44Z" level=info msg="Enabling controller service capability: PUBLISH_READONLY" file="driver.go:229"
time="2021-05-18T08:22:44Z" level=info msg="Enabling controller service capability: EXPAND_VOLUME" file="driver.go:229"
time="2021-05-18T08:22:44Z" level=info msg="Enabling node service capability: STAGE_UNSTAGE_VOLUME" file="driver.go:242"
time="2021-05-18T08:22:44Z" level=info msg="Enabling node service capability: EXPAND_VOLUME" file="driver.go:242"
time="2021-05-18T08:22:44Z" level=info msg="Enabling node service capability: GET_VOLUME_STATS" file="driver.go:242"
time="2021-05-18T08:22:44Z" level=info msg="Enabling volume expansion type: ONLINE" file="driver.go:255"
time="2021-05-18T08:22:44Z" level=info msg="Enabling volume access mode: SINGLE_NODE_WRITER" file="driver.go:267"
time="2021-05-18T08:22:44Z" level=info msg="Enabling volume access mode: SINGLE_NODE_READER_ONLY" file="driver.go:267"
time="2021-05-18T08:22:44Z" level=info msg="Enabling volume access mode: MULTI_NODE_READER_ONLY" file="driver.go:267"
time="2021-05-18T08:22:44Z" level=info msg="Enabling volume access mode: MULTI_NODE_SINGLE_WRITER" file="driver.go:267"
time="2021-05-18T08:22:44Z" level=info msg="Enabling volume access mode: MULTI_NODE_MULTI_WRITER" file="driver.go:267"
time="2021-05-18T08:22:44Z" level=info msg="DB service disabled!!!" file="driver.go:126"
time="2021-05-18T08:22:44Z" level=info msg="[1] reply  : [/bin/csi-driver --endpoint=unix:///csi/csi.sock --node-service --flavor=kubernetes]" file="csi-driver.go:155"
time="2021-05-18T08:22:44Z" level=trace msg="Using defaultInlineVolumeScrubberInterval 3600" file="driver.go:185"
time="2021-05-18T08:22:44Z" level=trace msg="Using defaultPodsDirPath /var/lib/kubelet/pods" file="driver.go:191"
time="2021-05-18T08:22:44Z" level=info msg="Scheduled ephemeral inline volumes scrubber task to run every 3600 seconds, PodsDirPath: [/var/lib/kubelet/pods]" file="driver.go:193"
time="2021-05-18T08:22:44Z" level=info msg=">>>>> Scrubber task invoked at 2021-05-18 08:22:44.327628948 +0000 UTC m=+1.142774230" file="driver.go:713"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> ScrubEphemeralPods" file="driver.go:724"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileExists for path /var/lib/kubelet/pods" file="file.go:62"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileExists" file="file.go:72"
time="2021-05-18T08:22:44Z" level=info msg="Listening for connections on address: &net.UnixAddr{Name:\"//csi/csi.sock\", Net:\"unix\"}" file="server.go:86"
time="2021-05-18T08:22:44Z" level=info msg="No ephemeral inline volumes found" file="driver.go:782"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< ScrubEphemeralPods" file="driver.go:783"
time="2021-05-18T08:22:44Z" level=info msg="<<<<< Scrubber task completed at 2021-05-18 08:22:44.348086101 +0000 UTC m=+1.163231366" file="driver.go:718"
time="2021-05-18T08:22:44Z" level=info msg="GRPC call: /csi.v1.Identity/GetPluginInfo" file="utils.go:69"
time="2021-05-18T08:22:44Z" level=info msg="GRPC request: {}" file="utils.go:70"
time="2021-05-18T08:22:44Z" level=info msg=">>>>> GetPluginInfo" file="identity_server.go:16"
time="2021-05-18T08:22:44Z" level=info msg="<<<<< GetPluginInfo" file="identity_server.go:19"
time="2021-05-18T08:22:44Z" level=info msg="GRPC response: {\"name\":\"csi.hpe.com\",\"vendor_version\":\"0.1\"}" file="utils.go:75"
time="2021-05-18T08:22:44Z" level=info msg="GRPC call: /csi.v1.Node/NodeGetInfo" file="utils.go:69"
time="2021-05-18T08:22:44Z" level=info msg="GRPC request: {}" file="utils.go:70"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> NodeGetInfo" file="node_server.go:1861"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> GetNetworkInterfaces called" file="network.go:125"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> getNetworkInterfaces called" file="network.go:137"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< getNetworkInterfaces" file="network.go:176"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< GetNetworkInterfaces" file="network.go:132"
time="2021-05-18T08:22:44Z" level=info msg="Writing uuid to file:/etc/hpe-storage/node.gob uuid:0a58a9fe-0001-6e6c-6865-6e3036737431" file="chapidriver_linux.go:49"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileSaveGob called with /etc/hpe-storage/node.gob" file="file.go:258"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileSaveGob" file="file.go:273"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileLoadGob called with /etc/hpe-storage/node.gob" file="file.go:278"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileLoadGob" file="file.go:287"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> GetHostNameAndDomain" file="network.go:40"
time="2021-05-18T08:22:44Z" level=trace msg="ExecCommandOutputWithTimeout called with dnsdomainname[] 60" file="cmd.go:35"
time="2021-05-18T08:22:44Z" level=trace msg="process with pid: 58 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:44Z" level=trace msg="openshift-pilot.sandbox.nfv.local\n" file="cmd.go:66"
time="2021-05-18T08:22:44Z" level=trace msg="hostname=nlhen06st1rm039 domain=openshift-pilot.sandbox.nfv.local" file="network.go:51"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< GetHostNameAndDomain" file="network.go:52"
time="2021-05-18T08:22:44Z" level=info msg="Host name reported as nlhen06st1rm039" file="node_server.go:1938"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> GetInitiators" file="initiator.go:21"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> getIscsiInitiator" file="initiator.go:51"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileExists for path /etc/iscsi/initiatorname.iscsi" file="file.go:62"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileExists" file="file.go:72"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileGetStringsWithPattern called with path: /etc/iscsi/initiatorname.iscsi Pattern: ^InitiatorName=(?P<iscsiinit>.*)$" file="file.go:112"
time="2021-05-18T08:22:44Z" level=trace msg="matching line :InitiatorName=iqn.1994-05.com.redhat:24534a2be9e4" file="file.go:140"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileGetStringsWithPattern" file="file.go:150"
time="2021-05-18T08:22:44Z" level=debug msg="got iscsi initiator name as iqn.1994-05.com.redhat:24534a2be9e4" file="initiator.go:68"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> GetChapInfo" file="iscsi.go:658"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileGetStringsWithPattern called with path: /etc/iscsi/iscsid.conf Pattern: ^\\s*node.session.auth.authmethod\\s*=\\s*(?P<password>.*)\\s*$" file="file.go:112"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileGetStringsWithPattern" file="file.go:150"
time="2021-05-18T08:22:44Z" level=trace msg="chap auth not set" file="iscsi.go:667"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< GetChapInfo" file="iscsi.go:668"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< getIscsiInitiators" file="initiator.go:75"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> getFcInitiators" file="initiator.go:80"
time="2021-05-18T08:22:44Z" level=trace msg="GetAllFcHostPortWWN called" file="fc.go:80"
time="2021-05-18T08:22:44Z" level=trace msg="GetAllFcHostPorts called" file="fc.go:44"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileExists for path /sys/class/fc_host" file="file.go:62"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileExists" file="file.go:72"
time="2021-05-18T08:22:44Z" level=trace msg="ExecCommandOutputWithTimeout called with ls[-1 /sys/class/fc_host] 60" file="cmd.go:35"
time="2021-05-18T08:22:44Z" level=trace msg="process with pid: 66 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:44Z" level=trace msg="host0\nhost1\n" file="cmd.go:66"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileReadFirstLine" file="file.go:35"
time="2021-05-18T08:22:44Z" level=trace msg=0x10000a5fd750001c file="file.go:55"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileReadFirstLine" file="file.go:56"
time="2021-05-18T08:22:44Z" level=trace msg="got port WWN 0x10000a5fd750001c for host 0" file="fc.go:30"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileReadFirstLine" file="file.go:35"
time="2021-05-18T08:22:44Z" level=trace msg=0x10000a5fd750001d file="file.go:55"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileReadFirstLine" file="file.go:56"
time="2021-05-18T08:22:44Z" level=trace msg="got node WWN 0x10000a5fd750001d for host 0" file="fc.go:37"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileReadFirstLine" file="file.go:35"
time="2021-05-18T08:22:44Z" level=trace msg=0x10000a5fd750001e file="file.go:55"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileReadFirstLine" file="file.go:56"
time="2021-05-18T08:22:44Z" level=trace msg="got port WWN 0x10000a5fd750001e for host 1" file="fc.go:30"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> FileReadFirstLine" file="file.go:35"
time="2021-05-18T08:22:44Z" level=trace msg=0x10000a5fd750001f file="file.go:55"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< FileReadFirstLine" file="file.go:56"
time="2021-05-18T08:22:44Z" level=trace msg="got node WWN 0x10000a5fd750001f for host 1" file="fc.go:37"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< getFcInitiators" file="initiator.go:95"
time="2021-05-18T08:22:44Z" level=debug msg="initiators [0xc0007f56e0 0xc0007f4210]" file="initiator.go:46"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< GetInitiators" file="initiator.go:47"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> GetNetworkInterfaces called" file="network.go:125"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> getNetworkInterfaces called" file="network.go:137"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< getNetworkInterfaces" file="network.go:176"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< GetNetworkInterfaces" file="network.go:132"
time="2021-05-18T08:22:44Z" level=info msg="Processing network named enp1s0f4u4 with IpV4 CIDR 16.1.15.2/30" file="node_server.go:1978"
time="2021-05-18T08:22:44Z" level=info msg="Processing network named ovn-k8s-mp0 with IpV4 CIDR 10.128.0.2/23" file="node_server.go:1978"
time="2021-05-18T08:22:44Z" level=info msg="Processing network named ovn-k8s-gw0 with IpV4 CIDR 169.254.0.1/20" file="node_server.go:1978"
time="2021-05-18T08:22:44Z" level=info msg="Processing network named br-ex with IpV4 CIDR 10.59.65.234/26" file="node_server.go:1978"
time="2021-05-18T08:22:44Z" level=info msg="Processing network named br-ex with IpV4 CIDR 10.59.65.205/32" file="node_server.go:1978"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> LoadNodeInfo called with node &{ nlhen06st1rm039 0a58a9fe-0001-6e6c-6865-6e3036737431 [0xc0006e1550] [0xc0002e3ce0 0xc0002e3e90 0xc0007e0090 0xc0007e1010 0xc0007e1320] [0xc000438b60 0xc000438b70]  }" file="flavor.go:173"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> getNodeInfoByUUID with uuid 0a58a9fe-0001-6e6c-6865-6e3036737431" file="flavor.go:552"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< getNodeInfoByUUID" file="flavor.go:562"
time="2021-05-18T08:22:44Z" level=info msg="Node info nlhen06st1rm040 already known to cluster\n" file="flavor.go:199"
time="2021-05-18T08:22:44Z" level=info msg="updating Node nlhen06st1rm040 with iqns [iqn.1994-05.com.redhat:24534a2be9e4] wwpns [10000a5fd750001c 10000a5fd750001e] networks [16.1.15.2/30 10.128.0.2/23 169.254.0.1/20 10.59.65.234/26 10.59.65.205/32]" file="flavor.go:231"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< LoadNodeInfo" file="flavor.go:265"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> InitializeWatcher" file="watcher.go:33"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< InitializeWatcher" file="watcher.go:67"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> AddWatchList" file="watcher.go:72"
time="2021-05-18T08:22:44Z" level=trace msg="Successfully added [/etc/sysconfig/network-scripts/] file to watch list" file="watcher.go:84"
time="2021-05-18T08:22:44Z" level=trace msg="Successfully added [/etc/sysconfig/network/] file to watch list" file="watcher.go:84"
time="2021-05-18T08:22:44Z" level=trace msg="Successfully added [/etc/iscsi/initiatorname.iscsi] file to watch list" file="watcher.go:84"
time="2021-05-18T08:22:44Z" level=warning msg="Failed to add [/etc/networks] file to watch list, err no such file or directory :" file="watcher.go:82"
time="2021-05-18T08:22:44Z" level=trace msg="Successfully added [/etc/iscsi/iscsid.conf] file to watch list" file="watcher.go:84"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< AddWatchList" file="watcher.go:87"
time="2021-05-18T08:22:44Z" level=trace msg="<<<<< NodeGetInfo" file="node_server.go:1903"
time="2021-05-18T08:22:44Z" level=trace msg=">>>>> StartWatcher" file="watcher.go:92"
time="2021-05-18T08:22:44Z" level=trace msg="Watcher [1 PID] is successfully started" file="watcher.go:95"
time="2021-05-18T08:22:44Z" level=info msg="GRPC response: {\"max_volumes_per_node\":100,\"node_id\":\"0a58a9fe-0001-6e6c-6865-6e3036737431\"}" file="utils.go:75"

vh040

+ for arg in '"$@"'
+ '[' --endpoint=unix:///csi/csi.sock = --node-service ']'
+ for arg in '"$@"'
+ '[' --node-service = --node-service ']'
+ nodeservice=true
+ for arg in '"$@"'
+ '[' --flavor=kubernetes = --node-service ']'
+ '[' true = true ']'
+ '[' '' = true ']'
+ cp -f /opt/hpe-storage/lib/hpe-storage-node.service /etc/systemd/system/hpe-storage-node.service
+ cp -f /opt/hpe-storage/lib/hpe-storage-node.sh /etc/hpe-storage/hpe-storage-node.sh
+ chmod +x /etc/hpe-storage/hpe-storage-node.sh
+ echo 'running node conformance checks...'
running node conformance checks...
+ systemctl daemon-reload
+ systemctl restart hpe-storage-node
+ echo 'copying hpe log collector diag script'
copying hpe log collector diag script
+ cp -f /opt/hpe-storage/bin/hpe-logcollector.sh /usr/local/bin/hpe-logcollector.sh
+ chmod +x /usr/local/bin/hpe-logcollector.sh
+ '[' '!' -f /host/etc/multipath.conf ']'
+ ln -s /host/etc/multipath.conf /etc/multipath.conf
+ ln -s /host/etc/multipath /etc/multipath
+ ln -s /host/etc/iscsi /etc/iscsi
+ '[' -f /host/etc/redhat-release ']'
+ rm /etc/redhat-release
+ ln -s /host/etc/redhat-release /etc/redhat-release
+ '[' -f /host/etc/os-release ']'
+ rm /etc/os-release
+ ln -s /host/etc/os-release /etc/os-release
starting csi plugin...
+ echo 'starting csi plugin...'
+ exec /bin/csi-driver --endpoint=unix:///csi/csi.sock --node-service --flavor=kubernetes
time="2021-05-18T08:22:39Z" level=info msg="Initialized logging." alsoLogToStderr=true logFileLocation=/var/log/hpe-csi-node.log logLevel=trace
time="2021-05-18T08:22:39Z" level=info msg="**********************************************" file="csi-driver.go:54"
time="2021-05-18T08:22:39Z" level=info msg="*************** HPE CSI DRIVER ***************" file="csi-driver.go:55"
time="2021-05-18T08:22:39Z" level=info msg="**********************************************" file="csi-driver.go:56"
time="2021-05-18T08:22:39Z" level=info msg=">>>>> CMDLINE Exec, args: []" file="csi-driver.go:58"
time="2021-05-18T08:22:39Z" level=trace msg=">>>>> csiCliHandler" file="csi-driver.go:83"
time="2021-05-18T08:22:39Z" level=trace msg=">>>>> FileExists for path /csi" file="file.go:62"
time="2021-05-18T08:22:39Z" level=trace msg="<<<<< FileExists" file="file.go:72"
time="2021-05-18T08:22:39Z" level=trace msg=">>>>> ConfigureIscsi" file="iscsi.go:394"
time="2021-05-18T08:22:39Z" level=trace msg="ExecCommandOutputWithTimeout called with lsb_release[-a] 60" file="cmd.go:35"
time="2021-05-18T08:22:39Z" level=trace msg="lsb_release is not available on the system" file="os.go:144"
time="2021-05-18T08:22:39Z" level=trace msg=">>>>> FileReadFirstLine" file="file.go:35"
time="2021-05-18T08:22:39Z" level=trace msg="Red Hat Enterprise Linux CoreOS release 4.7" file="file.go:55"
time="2021-05-18T08:22:39Z" level=trace msg="<<<<< FileReadFirstLine" file="file.go:56"
time="2021-05-18T08:22:39Z" level=trace msg="matched os info map:map[distro:Red major:4 minor:7]" file="os.go:245"
time="2021-05-18T08:22:39Z" level=trace msg="ExecCommandOutputWithTimeout called with uname[-r] 60" file="cmd.go:35"
time="2021-05-18T08:22:39Z" level=trace msg="process with pid: 36 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:39Z" level=trace msg="4.18.0-240.22.1.el8_3.x86_64\n" file="cmd.go:66"
time="2021-05-18T08:22:39Z" level=info msg="got OS details as [redhat 4 7 4.18.0-240.22.1.el8_3.x86_64]\n" file="os.go:94"
time="2021-05-18T08:22:39Z" level=trace msg=">>>>> EnableService called with iscsi" file="os.go:465"
time="2021-05-18T08:22:39Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[--version] 60" file="cmd.go:35"
time="2021-05-18T08:22:39Z" level=trace msg="process with pid: 37 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:39Z" level=trace msg="systemd 219\n+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN\n" file="cmd.go:66"
time="2021-05-18T08:22:39Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[daemon-reload] 60" file="cmd.go:35"
time="2021-05-18T08:22:40Z" level=trace msg="process with pid: 38 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:40Z" level=trace file="cmd.go:66"
time="2021-05-18T08:22:40Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[enable iscsid.service] 60" file="cmd.go:35"
time="2021-05-18T08:22:41Z" level=trace msg="process with pid: 39 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:41Z" level=trace file="cmd.go:66"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< EnableService" file="os.go:477"
time="2021-05-18T08:22:41Z" level=trace msg="SetIscsiRecommendations called" file="iscsi.go:348"
time="2021-05-18T08:22:41Z" level=trace msg="GetIscsiRecommendations called" file="iscsi.go:173"
time="2021-05-18T08:22:41Z" level=trace msg="Reading template config file: /opt/hpe-storage/nimbletune/config.json" file="config.go:191"
time="2021-05-18T08:22:41Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:41Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:41Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:41Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:41Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:41Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:41Z" level=trace msg="getIscsiParamRecommendation called" file="iscsi.go:54"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> GetIfaces" file="iscsi.go:500"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> GetIscsiIfacesPath" file="iscsi.go:481"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileExists for path /var/lib/iscsi/ifaces" file="file.go:62"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileExists" file="file.go:68"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileExists for path /etc/iscsi/ifaces" file="file.go:62"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileExists" file="file.go:68"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< GetIscsiIfacesPath" file="iscsi.go:488"
time="2021-05-18T08:22:41Z" level=trace msg="no iscsi ifaces found" file="iscsi.go:513"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< GetIfaces" file="iscsi.go:514"
time="2021-05-18T08:22:41Z" level=info msg="No further iSCSI recommendations are found for this host" file="iscsi.go:387"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> ServiceCommand called with type iscsi op start" file="os.go:569"
time="2021-05-18T08:22:41Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[--version] 60" file="cmd.go:35"
time="2021-05-18T08:22:41Z" level=trace msg="process with pid: 40 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:41Z" level=trace msg="systemd 219\n+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN\n" file="cmd.go:66"
time="2021-05-18T08:22:41Z" level=trace msg="running command  systemctl  args:  [start iscsid]" file="os.go:601"
time="2021-05-18T08:22:41Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[start iscsid] 60" file="cmd.go:35"
time="2021-05-18T08:22:41Z" level=trace msg="process with pid: 41 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:41Z" level=trace file="cmd.go:66"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< ServiceCommand" file="os.go:608"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< ConfigureIscsi" file="iscsi.go:421"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> ConfigureMultipath" file="multipath.go:346"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> SetMultipathRecommendations" file="multipath.go:295"
time="2021-05-18T08:22:41Z" level=trace msg="GetMultipathRecommendations called" file="multipath.go:178"
time="2021-05-18T08:22:41Z" level=trace msg="ExecCommandOutputWithTimeout called with dmidecode[--type system] 60" file="cmd.go:35"
time="2021-05-18T08:22:41Z" level=error msg="process with pid : 42 finished with error = exit status 127" file="cmd.go:60"
time="2021-05-18T08:22:41Z" level=trace msg="/usr/bin/env: 'dmidecode': No such file or directory\n" file="cmd.go:66"
time="2021-05-18T08:22:41Z" level=error msg="unable to get system information using dmidecode command dmidecode failed with rc=127 err=/usr/bin/env: 'dmidecode': No such file or directory\n" file="system.go:31"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileGetStringsWithPattern called with path: /sys/firmware/dmi/tables/DMI Pattern: vmware.*|qemu|hyper.*" file="file.go:112"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileGetStringsWithPattern" file="file.go:150"
time="2021-05-18T08:22:41Z" level=trace msg="DMI-SYSFS: System is running as a virtual machine" file="system.go:115"
time="2021-05-18T08:22:41Z" level=trace msg="getMultipathDeviceScopeRecommendations called" file="multipath.go:102"
time="2021-05-18T08:22:41Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey no_path_retry value 30 recommended 30" file="multipath.go:72"
time="2021-05-18T08:22:41Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey vendor value \"Nimble\" recommended \"Nimble\"" file="multipath.go:72"
time="2021-05-18T08:22:41Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey path_grouping_policy value group_by_prio recommended group_by_prio" file="multipath.go:72"
time="2021-05-18T08:22:41Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey path_checker value tur recommended tur" file="multipath.go:72"
time="2021-05-18T08:22:41Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey failback value immediate recommended immediate" file="multipath.go:72"
time="2021-05-18T08:22:41Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey prio value alua recommended alua" file="multipath.go:72"
time="2021-05-18T08:22:41Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey hardware_handler value \"1 alua\" recommended \"1 alua\"" file="multipath.go:72"
time="2021-05-18T08:22:41Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey fast_io_fail_tmo value 5 recommended 5" file="multipath.go:72"
time="2021-05-18T08:22:41Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey path_selector value \"service-time 0\" recommended \"service-time 0\"" file="multipath.go:72"
time="2021-05-18T08:22:41Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey dev_loss_tmo value infinity recommended infinity" file="multipath.go:72"
time="2021-05-18T08:22:41Z" level=trace msg="getMultipathDeviceParamRecommendation called with paramKey product value \"Server\" recommended \"Server\"" file="multipath.go:72"
time="2021-05-18T08:22:41Z" level=trace msg="ParseConfig called" file="configresource.go:264"
time="2021-05-18T08:22:41Z" level=trace msg="adding section defaults" file="configresource.go:289"
time="2021-05-18T08:22:41Z" level=trace msg="addSection called with defaults" file="configresource.go:180"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param user_friendly_names value yes" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param find_multipaths value no" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param enable_foreign value \"^$\"" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="adding section blacklist_exceptions" file="configresource.go:289"
time="2021-05-18T08:22:41Z" level=trace msg="addSection called with blacklist_exceptions" file="configresource.go:180"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param property value \"(SCSI_IDENT_|ID_WWN)\"" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="adding section blacklist" file="configresource.go:289"
time="2021-05-18T08:22:41Z" level=trace msg="addSection called with blacklist" file="configresource.go:180"
time="2021-05-18T08:22:41Z" level=trace msg="adding section devices" file="configresource.go:289"
time="2021-05-18T08:22:41Z" level=trace msg="addSection called with devices" file="configresource.go:180"
time="2021-05-18T08:22:41Z" level=trace msg="adding section device" file="configresource.go:289"
time="2021-05-18T08:22:41Z" level=trace msg="addSection called with device" file="configresource.go:180"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param path_selector value \"service-time 0\"" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param path_grouping_policy value group_by_prio" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param path_checker value tur" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param vendor value \"Nimble\"" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param failback value immediate" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param hardware_handler value \"1 alua\"" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param no_path_retry value 30" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param prio value alua" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param dev_loss_tmo value infinity" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param product value \"Server\"" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption called" file="configresource.go:210"
time="2021-05-18T08:22:41Z" level=trace msg="parseOption param fast_io_fail_tmo value 5" file="configresource.go:216"
time="2021-05-18T08:22:41Z" level=trace msg="GetNimbleSection called" file="configresource.go:354"
time="2021-05-18T08:22:41Z" level=trace msg="GetSection called with defaults" file="configresource.go:379"
time="2021-05-18T08:22:41Z" level=trace msg="SaveConfig called" file="configresource.go:318"
time="2021-05-18T08:22:41Z" level=trace msg="PrintConf called" file="configresource.go:153"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> ServiceCommand called with type multipath op start" file="os.go:569"
time="2021-05-18T08:22:41Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[--version] 60" file="cmd.go:35"
time="2021-05-18T08:22:41Z" level=trace msg="process with pid: 48 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:41Z" level=trace msg="systemd 219\n+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN\n" file="cmd.go:66"
time="2021-05-18T08:22:41Z" level=trace msg="running command  systemctl  args:  [start multipathd]" file="os.go:601"
time="2021-05-18T08:22:41Z" level=trace msg="ExecCommandOutputWithTimeout called with systemctl[start multipathd] 60" file="cmd.go:35"
time="2021-05-18T08:22:41Z" level=trace msg="process with pid: 49 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:41Z" level=trace file="cmd.go:66"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< ServiceCommand" file="os.go:608"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> MultipathdReconfigure" file="multipath.go:57"
time="2021-05-18T08:22:41Z" level=trace msg="ExecCommandOutputWithTimeout called with multipathd[reconfigure] 60" file="cmd.go:35"
time="2021-05-18T08:22:41Z" level=trace msg="process with pid: 50 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:41Z" level=trace msg="ok\n" file="cmd.go:66"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<<< MultipathdReconfigure" file="multipath.go:70"
time="2021-05-18T08:22:41Z" level=info msg="Successfully configured multipath.conf settings" file="multipath.go:338"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< SetMultipathRecommendations" file="multipath.go:339"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< ConfigureMultipath" file="multipath.go:354"
time="2021-05-18T08:22:41Z" level=trace msg="About to start the CSI driver 'csi.hpe.com'" file="csi-driver.go:138"
time="2021-05-18T08:22:41Z" level=info msg="Enabling controller service capability: CREATE_DELETE_VOLUME" file="driver.go:229"
time="2021-05-18T08:22:41Z" level=info msg="Enabling controller service capability: PUBLISH_UNPUBLISH_VOLUME" file="driver.go:229"
time="2021-05-18T08:22:41Z" level=info msg="Enabling controller service capability: LIST_VOLUMES" file="driver.go:229"
time="2021-05-18T08:22:41Z" level=info msg="Enabling controller service capability: CREATE_DELETE_SNAPSHOT" file="driver.go:229"
time="2021-05-18T08:22:41Z" level=info msg="Enabling controller service capability: LIST_SNAPSHOTS" file="driver.go:229"
time="2021-05-18T08:22:41Z" level=info msg="Enabling controller service capability: CLONE_VOLUME" file="driver.go:229"
time="2021-05-18T08:22:41Z" level=info msg="Enabling controller service capability: PUBLISH_READONLY" file="driver.go:229"
time="2021-05-18T08:22:41Z" level=info msg="Enabling controller service capability: EXPAND_VOLUME" file="driver.go:229"
time="2021-05-18T08:22:41Z" level=info msg="Enabling node service capability: STAGE_UNSTAGE_VOLUME" file="driver.go:242"
time="2021-05-18T08:22:41Z" level=info msg="Enabling node service capability: EXPAND_VOLUME" file="driver.go:242"
time="2021-05-18T08:22:41Z" level=info msg="Enabling node service capability: GET_VOLUME_STATS" file="driver.go:242"
time="2021-05-18T08:22:41Z" level=info msg="Enabling volume expansion type: ONLINE" file="driver.go:255"
time="2021-05-18T08:22:41Z" level=info msg="Enabling volume access mode: SINGLE_NODE_WRITER" file="driver.go:267"
time="2021-05-18T08:22:41Z" level=info msg="Enabling volume access mode: SINGLE_NODE_READER_ONLY" file="driver.go:267"
time="2021-05-18T08:22:41Z" level=info msg="Enabling volume access mode: MULTI_NODE_READER_ONLY" file="driver.go:267"
time="2021-05-18T08:22:41Z" level=info msg="Enabling volume access mode: MULTI_NODE_SINGLE_WRITER" file="driver.go:267"
time="2021-05-18T08:22:41Z" level=info msg="Enabling volume access mode: MULTI_NODE_MULTI_WRITER" file="driver.go:267"
time="2021-05-18T08:22:41Z" level=info msg="DB service disabled!!!" file="driver.go:126"
time="2021-05-18T08:22:41Z" level=info msg="[1] reply  : [/bin/csi-driver --endpoint=unix:///csi/csi.sock --node-service --flavor=kubernetes]" file="csi-driver.go:155"
time="2021-05-18T08:22:41Z" level=trace msg="Using defaultInlineVolumeScrubberInterval 3600" file="driver.go:185"
time="2021-05-18T08:22:41Z" level=trace msg="Using defaultPodsDirPath /var/lib/kubelet/pods" file="driver.go:191"
time="2021-05-18T08:22:41Z" level=info msg="Scheduled ephemeral inline volumes scrubber task to run every 3600 seconds, PodsDirPath: [/var/lib/kubelet/pods]" file="driver.go:193"
time="2021-05-18T08:22:41Z" level=info msg=">>>>> Scrubber task invoked at 2021-05-18 08:22:41.105238365 +0000 UTC m=+1.474644162" file="driver.go:713"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> ScrubEphemeralPods" file="driver.go:724"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileExists for path /var/lib/kubelet/pods" file="file.go:62"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileExists" file="file.go:72"
time="2021-05-18T08:22:41Z" level=info msg="Listening for connections on address: &net.UnixAddr{Name:\"//csi/csi.sock\", Net:\"unix\"}" file="server.go:86"
time="2021-05-18T08:22:41Z" level=info msg="No ephemeral inline volumes found" file="driver.go:782"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< ScrubEphemeralPods" file="driver.go:783"
time="2021-05-18T08:22:41Z" level=info msg="<<<<< Scrubber task completed at 2021-05-18 08:22:41.134247611 +0000 UTC m=+1.503653384" file="driver.go:718"
time="2021-05-18T08:22:41Z" level=info msg="GRPC call: /csi.v1.Identity/GetPluginInfo" file="utils.go:69"
time="2021-05-18T08:22:41Z" level=info msg="GRPC request: {}" file="utils.go:70"
time="2021-05-18T08:22:41Z" level=info msg=">>>>> GetPluginInfo" file="identity_server.go:16"
time="2021-05-18T08:22:41Z" level=info msg="<<<<< GetPluginInfo" file="identity_server.go:19"
time="2021-05-18T08:22:41Z" level=info msg="GRPC response: {\"name\":\"csi.hpe.com\",\"vendor_version\":\"0.1\"}" file="utils.go:75"
time="2021-05-18T08:22:41Z" level=info msg="GRPC call: /csi.v1.Node/NodeGetInfo" file="utils.go:69"
time="2021-05-18T08:22:41Z" level=info msg="GRPC request: {}" file="utils.go:70"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> NodeGetInfo" file="node_server.go:1861"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> GetNetworkInterfaces called" file="network.go:125"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> getNetworkInterfaces called" file="network.go:137"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< getNetworkInterfaces" file="network.go:176"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< GetNetworkInterfaces" file="network.go:132"
time="2021-05-18T08:22:41Z" level=info msg="Writing uuid to file:/etc/hpe-storage/node.gob uuid:0a58a9fe-0001-6e6c-6865-6e3036737431" file="chapidriver_linux.go:49"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileSaveGob called with /etc/hpe-storage/node.gob" file="file.go:258"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileSaveGob" file="file.go:273"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileLoadGob called with /etc/hpe-storage/node.gob" file="file.go:278"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileLoadGob" file="file.go:287"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> GetHostNameAndDomain" file="network.go:40"
time="2021-05-18T08:22:41Z" level=trace msg="ExecCommandOutputWithTimeout called with dnsdomainname[] 60" file="cmd.go:35"
time="2021-05-18T08:22:41Z" level=trace msg="process with pid: 60 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:41Z" level=trace msg="openshift-pilot.sandbox.nfv.local\n" file="cmd.go:66"
time="2021-05-18T08:22:41Z" level=trace msg="hostname=nlhen06st1rm040 domain=openshift-pilot.sandbox.nfv.local" file="network.go:51"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< GetHostNameAndDomain" file="network.go:52"
time="2021-05-18T08:22:41Z" level=info msg="Host name reported as nlhen06st1rm040" file="node_server.go:1938"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> GetInitiators" file="initiator.go:21"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> getIscsiInitiator" file="initiator.go:51"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileExists for path /etc/iscsi/initiatorname.iscsi" file="file.go:62"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileExists" file="file.go:72"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileGetStringsWithPattern called with path: /etc/iscsi/initiatorname.iscsi Pattern: ^InitiatorName=(?P<iscsiinit>.*)$" file="file.go:112"
time="2021-05-18T08:22:41Z" level=trace msg="matching line :InitiatorName=iqn.1994-05.com.redhat:ccd53eae81e" file="file.go:140"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileGetStringsWithPattern" file="file.go:150"
time="2021-05-18T08:22:41Z" level=debug msg="got iscsi initiator name as iqn.1994-05.com.redhat:ccd53eae81e" file="initiator.go:68"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> GetChapInfo" file="iscsi.go:658"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileGetStringsWithPattern called with path: /etc/iscsi/iscsid.conf Pattern: ^\\s*node.session.auth.authmethod\\s*=\\s*(?P<password>.*)\\s*$" file="file.go:112"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileGetStringsWithPattern" file="file.go:150"
time="2021-05-18T08:22:41Z" level=trace msg="chap auth not set" file="iscsi.go:667"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< GetChapInfo" file="iscsi.go:668"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< getIscsiInitiators" file="initiator.go:75"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> getFcInitiators" file="initiator.go:80"
time="2021-05-18T08:22:41Z" level=trace msg="GetAllFcHostPortWWN called" file="fc.go:80"
time="2021-05-18T08:22:41Z" level=trace msg="GetAllFcHostPorts called" file="fc.go:44"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileExists for path /sys/class/fc_host" file="file.go:62"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileExists" file="file.go:72"
time="2021-05-18T08:22:41Z" level=trace msg="ExecCommandOutputWithTimeout called with ls[-1 /sys/class/fc_host] 60" file="cmd.go:35"
time="2021-05-18T08:22:41Z" level=trace msg="process with pid: 62 finished successfully" file="cmd.go:62"
time="2021-05-18T08:22:41Z" level=trace msg="host0\nhost1\n" file="cmd.go:66"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileReadFirstLine" file="file.go:35"
time="2021-05-18T08:22:41Z" level=trace msg=0x10000a5fd7500020 file="file.go:55"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileReadFirstLine" file="file.go:56"
time="2021-05-18T08:22:41Z" level=trace msg="got port WWN 0x10000a5fd7500020 for host 0" file="fc.go:30"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileReadFirstLine" file="file.go:35"
time="2021-05-18T08:22:41Z" level=trace msg=0x10000a5fd7500021 file="file.go:55"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileReadFirstLine" file="file.go:56"
time="2021-05-18T08:22:41Z" level=trace msg="got node WWN 0x10000a5fd7500021 for host 0" file="fc.go:37"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileReadFirstLine" file="file.go:35"
time="2021-05-18T08:22:41Z" level=trace msg=0x10000a5fd7500022 file="file.go:55"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileReadFirstLine" file="file.go:56"
time="2021-05-18T08:22:41Z" level=trace msg="got port WWN 0x10000a5fd7500022 for host 1" file="fc.go:30"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> FileReadFirstLine" file="file.go:35"
time="2021-05-18T08:22:41Z" level=trace msg=0x10000a5fd7500023 file="file.go:55"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< FileReadFirstLine" file="file.go:56"
time="2021-05-18T08:22:41Z" level=trace msg="got node WWN 0x10000a5fd7500023 for host 1" file="fc.go:37"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< getFcInitiators" file="initiator.go:95"
time="2021-05-18T08:22:41Z" level=debug msg="initiators [0xc000513b00 0xc00071d680]" file="initiator.go:46"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< GetInitiators" file="initiator.go:47"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> GetNetworkInterfaces called" file="network.go:125"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> getNetworkInterfaces called" file="network.go:137"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< getNetworkInterfaces" file="network.go:176"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< GetNetworkInterfaces" file="network.go:132"
time="2021-05-18T08:22:41Z" level=info msg="Processing network named ovn-k8s-mp0 with IpV4 CIDR 10.130.0.2/23" file="node_server.go:1978"
time="2021-05-18T08:22:41Z" level=info msg="Processing network named ovn-k8s-gw0 with IpV4 CIDR 169.254.0.1/20" file="node_server.go:1978"
time="2021-05-18T08:22:41Z" level=info msg="Processing network named br-ex with IpV4 CIDR 10.59.65.235/26" file="node_server.go:1978"
time="2021-05-18T08:22:41Z" level=info msg="Processing network named enp1s0f4u4 with IpV4 CIDR 16.1.15.2/30" file="node_server.go:1978"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> LoadNodeInfo called with node &{ nlhen06st1rm040 0a58a9fe-0001-6e6c-6865-6e3036737431 [0xc00032de30] [0xc0000388d0 0xc000038a80 0xc000038c40 0xc000038df0] [0xc00000d4a0 0xc00000d4b0]  }" file="flavor.go:173"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> getNodeInfoByUUID with uuid 0a58a9fe-0001-6e6c-6865-6e3036737431" file="flavor.go:552"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< getNodeInfoByUUID" file="flavor.go:565"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> getNodeInfoByName with name nlhen06st1rm040" file="flavor.go:569"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< getNodeInfoByName" file="flavor.go:583"
time="2021-05-18T08:22:41Z" level=info msg="Adding node with name nlhen06st1rm040" file="flavor.go:254"
time="2021-05-18T08:22:41Z" level=info msg="Successfully added node info for node &{{ } {nlhen06st1rm040   /apis/storage.hpe.com/v1/hpenodeinfos/nlhen06st1rm040 2160da53-9806-417a-bbe1-80dc1235d7a7 4041989 1 2021-05-18 08:22:41 +0000 UTC <nil> <nil> map[] map[] [] []  [{csi-driver Update storage.hpe.com/v1 2021-05-18 08:22:41 +0000 UTC FieldsV1 &FieldsV1{Raw:*[123 34 102 58 115 112 101 99 34 58 123 34 46 34 58 123 125 44 34 102 58 105 113 110 115 34 58 123 125 44 34 102 58 110 101 116 119 111 114 107 115 34 58 123 125 44 34 102 58 117 117 105 100 34 58 123 125 44 34 102 58 119 119 112 110 115 34 58 123 125 125 125],}}]} {0a58a9fe-0001-6e6c-6865-6e3036737431 [iqn.1994-05.com.redhat:ccd53eae81e] [10.130.0.2/23 169.254.0.1/20 10.59.65.235/26 16.1.15.2/30] [10000a5fd7500020 10000a5fd7500022]  }}" file="flavor.go:262"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< LoadNodeInfo" file="flavor.go:265"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> InitializeWatcher" file="watcher.go:33"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< InitializeWatcher" file="watcher.go:67"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> AddWatchList" file="watcher.go:72"
time="2021-05-18T08:22:41Z" level=trace msg="Successfully added [/etc/sysconfig/network-scripts/] file to watch list" file="watcher.go:84"
time="2021-05-18T08:22:41Z" level=trace msg="Successfully added [/etc/sysconfig/network/] file to watch list" file="watcher.go:84"
time="2021-05-18T08:22:41Z" level=trace msg="Successfully added [/etc/iscsi/initiatorname.iscsi] file to watch list" file="watcher.go:84"
time="2021-05-18T08:22:41Z" level=warning msg="Failed to add [/etc/networks] file to watch list, err no such file or directory :" file="watcher.go:82"
time="2021-05-18T08:22:41Z" level=trace msg="Successfully added [/etc/iscsi/iscsid.conf] file to watch list" file="watcher.go:84"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< AddWatchList" file="watcher.go:87"
time="2021-05-18T08:22:41Z" level=trace msg="<<<<< NodeGetInfo" file="node_server.go:1903"
time="2021-05-18T08:22:41Z" level=info msg="GRPC response: {\"max_volumes_per_node\":100,\"node_id\":\"0a58a9fe-0001-6e6c-6865-6e3036737431\"}" file="utils.go:75"
time="2021-05-18T08:22:41Z" level=trace msg=">>>>> StartWatcher" file="watcher.go:92"
time="2021-05-18T08:22:41Z" level=trace msg="Watcher [1 PID] is successfully started" file="watcher.go:95"
raunakkumar commented 3 years ago

Thanks @m4r1k for the logs. We were able to reproduce the issue internally with the above data. Since we pick the first sorted mac address, we pick up the mac address which is common to both the host.

11: ovn-k8s-gw0: <BROADCAST,MULTICAST> mtu 1400 qdisc noop state DOWN group default qlen 1000
    link/ether 0a:58:a9:fe:00:01 brd ff:ff:ff:ff:ff:ff

Our current mechanism doesn't guarantee uniqueness across 32 characters. We will address this in the next release by using md5 hash instead. Below is one such example with current and the updated approach. 

lhen06st1rm039 current uuid 0a58a9fe00016e6c68656e3036737431726d303339
lhen06st1rm040 current uuid 0a58a9fe00016e6c68656e3036737431726d303430
lhen06st1rm039 md5     uuid 0a58a9fe0001bab220af5595641cfeee948c92971816
lhen06st1rm040 md5     uuid 0a58a9fe0001bab220af5595641cfeee948c92971816
m4r1k commented 3 years ago

Hey @raunakkumar thanks for finding the root issue and already proposing a PR

Is there any test build I could run in my platform to verify that indeed the new approach works as expected?

Thanks!

m4r1k commented 3 years ago

Hey guys,

Following @datamattsson suggestion (email exchanged) he proposed to short/change the hostnames. We did that and the current problem has been solved.

$ oc get hpenodeinfos
 NAME              AGE
 vh039nlhen06st1   5m37s
 vh040nlhen06st1   5m38s
 vh047nlhen06st1   5m36s

$ oc describe hpenodeinfos|grep -E "(Name|Uuid):"
Name:     vh039nlhen06st1
 Uuid: 0a58a9fe-0001-7668-3033-396e6c68656e
Name:     vh040nlhen06st1
 Uuid: 0a58a9fe-0001-7668-3034-306e6c68656e
Name:     vh047nlhen06st1
 Uuid: 0a58a9fe-0001-7668-3034-376e6c68656e

Definitely, the PR hash-based is the ultimate solution, but here we also have a potential workaround

datamattsson commented 3 years ago

272 merges the changes in the dependent library that generates the UUID, this will be a non-issue beyond version 1.4.x

The workaround, if duplicates MAC addresses are being picked up, is to use hostname uniqueness in the first 10 characters of the hostname.