[oi-dev] hotplug errors with scsi-vhci after update

[Udo Grabowski (IMK)]

Hi, upgraded to the latest Hipster from Sep-13 to today, and got a massive
amount of error messages from hotplug, for each of the 70 (SAS-expander
connected) disks I got the block of messages below (in total 2325 lines!).
But the pools are available and healthy.

The disks are configured in /kernel/drv/scsi_vhci.conf:
scsi-vhci-failover-override=
"HGST HUSMH8010BSS200", "f_sym",
"HGST HUS726040AL5210", "f_sym";
device-type-scsi-options-list=
"HGST HUSMH8010BSS200", "symmetric-option",
"HGST HUS726040AL5210", "symmetric-option";
and are 70 two-port disks, crosswise visible to a second host in the
same machine, 35 disks per host configured into a pool per host,
usually the unused disks are unconfigured on the resp.second host (but
see problem below). The messages are for all disks, regradless if they
belong to the host or not, and have not been thrown before the upgrade
(even though the next problem already was visible).

For quite a while now, I noticed another, unrelated error: I cannot
unconfigure any disk with 'cfgadm -c unconfigure', it's immediatly
reconfigured (regardless of hotplugd running or not). This is awkward
especially when a disk is behaving bad.

Any ideas what's wrong here ?
....
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.794 [E]
hotplug.c:66: devpath /scsi_vhci/***@g5000cca2441ed3f4 already present in
store, ignore event
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.795 [E]
hotplug.c:66: devpath /scsi_vhci/***@g5000cca2441ed3f4:wd already present in
store, ignore event
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.795 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.795 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:a/s0
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.796 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:b/s1
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.796 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:c/s2
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.796 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:d/s3
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.796 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:e/s4
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.797 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:f/s5
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.797 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:g/s6
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.797 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:i/s8
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.798 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:j/s9
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.798 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:k/s10
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.798 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:l/s11
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.799 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:m/s12
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.799 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:n/s13
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.799 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:o/s14
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.800 [E]
hotplug.c:81: Parent is NULL devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:p/s15
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.800 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:1
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.800 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:2
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.800 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:3
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.801 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:4
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.801 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:5
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.801 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:6
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.802 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:7
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.802 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:8
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.802 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:9
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.803 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:10
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.803 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:11
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.803 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:12
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.804 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:13
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.804 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:14
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.804 [E]
hotplug.c:81: Parent is NULL
devfs_path=/scsi_vhci/***@g5000cca2441ed3f4:wd/d0:15
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180
...

[Udo Grabowski (IMK)]

Post by Udo Grabowski (IMK)
Hi, upgraded to the latest Hipster from Sep-13 to today, and got a massive
amount of error messages from hotplug, for each of the 70 (SAS-expander
connected) disks I got the block of messages below (in total 2325 lines!).
But the pools are available and healthy.
scsi-vhci-failover-override=
"HGST HUSMH8010BSS200", "f_sym",
"HGST HUS726040AL5210", "f_sym";
device-type-scsi-options-list=
"HGST HUSMH8010BSS200", "symmetric-option",
"HGST HUS726040AL5210", "symmetric-option";
and are 70 two-port disks, crosswise visible to a second host in the
same machine, 35 disks per host configured into a pool per host,
usually the unused disks are unconfigured on the resp.second host (but
see problem below). The messages are for all disks, regradless if they
belong to the host or not, and have not been thrown before the upgrade
(even though the next problem already was visible).
For quite a while now, I noticed another, unrelated error: I cannot
unconfigure any disk with 'cfgadm -c unconfigure', it's immediatly
reconfigured (regardless of hotplugd running or not). This is awkward
especially when a disk is behaving bad.
Any ideas what's wrong here ?
....
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.794 [E]
store, ignore event
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.795 [E]
store, ignore event
Nov 8 16:43:12 imksunth7 hald[268]: [ID 702911 daemon.error] 16:43:12.795 [E]
parent_udi=/org/freedesktop/Hal/devices/scsi_vhci_0/disk180_0/sd180

//openindiana.org/mailman/listinfo/oi-dev
Found the culprit, enabled --verbose and --use-syslog in HAL service
script a while ago for a test, and didn't revert it. Probably the
cause for the excessive messages.

Post by Udo Grabowski (IMK)
For quite a while now, I noticed another, unrelated error: I cannot
unconfigure any disk with 'cfgadm -c unconfigure', it's immediatly
reconfigured (regardless of hotplugd running or not). This is awkward
especially when a disk is behaving bad.

Neverthelesss, this problem is still present, and I don't find a
reasonable cause for it. It started when upgrading from an older
Hipster from 2016 to the 2018.4 snapshot, so a wider range of commits
to illumos are to be suspected here.