[BUG]: NVMe LED state stuck in FAILURE during hot-plug due to Multipath/Virtual syspath mismatch

[czsczsczs2]

Description

Hi, I have encountered an issue where the LED state becomes abnormal during NVMe hot-plugging.

During NVMe hot-plug operations on systems with Native Multipathing(nvme_core.multipath=Y), enabled, ledmon fails to track the device state changes correctly. Specifically, when a drive is removed and re-inserted, the LED state becomes stuck in FAILURE. This happens because ledmon stores the physical PCI sysfs path, but udev reports events using the virtual subsystem path(e.g., /sys/devices/virtual/nvme-subsystem/...). Due to this path mismatch, ledmon cannot find the matching block device in its internal list, preventing the state from resetting to NORMAL.

Steps to reproduce bug

1. Use an NVMe SSD that supports Multi-controller Capabilities (CMIC).

2. Ensure the kernel is running with nvme_core.multipath=Y (default in many modern distributions).

3. Start ledmon in debug mode to monitor state transitions.

4. Perform a hot-remove of the NVMe drive.

5. Re-insert (hot-plug) the same NVMe drive.

6. Check the LED state using ledctl --list-slots --controller-type VMD

Expected behavior

When the drive is removed, the LED state should update accordingly (e.g., to an empty or neutral state). Upon re-insertion, the state should return to NORMAL.

Actual behavior

The LED state transitions to FAILURE after removal and remains in FAILURE even after the drive is plugged back in. The logs show No matching block device found because of the discrepancy between the stored physical path and the udev virtual path.

Environment

OS: Linux 6.8.0-83-generic
Disks: NVMe SSD with Multi-controller support (CMIC enabled)
Kernel Parameters: nvme_core.multipath=Y

Ledmon version

Intel(R) Enclosure LED Monitor Service 1.1.0

Ledmon logs

Initial State (Drive Attached)

ledmon[4902]: NEW /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme1/nvme1c1n1: state 'ONESHOT_NORMAL'.
ledmon[4902]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme1/nvme1c1n1: from 'ONESHOT_NORMAL' to 'UNKNOWN'


root@SKY-9236-efi-N1:~/ledmon/src/ledctl# ./ledctl --list-slots --controller-type VMD
slot: 19              led state: NORMAL          device: /dev/nvme1n1

Drive Removal (Path Mismatch Occurs)

ledmon[4902]: === UDEV Event: action=remove, syspath=/sys/devices/virtual/nvme-subsystem/nvme-subsys1/nvme1n1 ===
ledmon[4902]: Searching for matching block device in list...
ledmon[4902]:   Comparing: stored sysfs_path=/sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme1/nvme1c1n1 with udev syspath=/sys/devices/virtual/nvme-subsystem/nvme-subsys1/nvme1n1
ledmon[4902]: No matching block device found for syspath: /sys/devices/virtual/nvme-subsystem/nvme-subsys1/nvme1n1
ledmon[4902]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme1/nvme1c1n1: from 'UNKNOWN' to 'FAILURE'.


root@SKY-9236-efi-N1:~/ledmon/src/ledctl# ./ledctl --list-slots --controller-type VMD
slot: 19              led state: FAILURE         device: /dev/nvme1n1

Drive Re-insertion (State Remains FAILURE)

ledmon[4902]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme1/nvme1c1n1: from 'FAILURE' to 'UNKNOWN'
ledmon[4902]: === UDEV Event: action=add, syspath=/sys/devices/virtual/nvme-subsystem/nvme-subsys1/nvme1n1 ===
ledmon[4902]: Searching for matching block device in list...
ledmon[4902]:   Comparing: stored sysfs_path=/sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme1/nvme1c1n1 with udev syspath=/sys/devices/virtual/nvme-subsystem/nvme-subsys1/nvme1n1
ledmon[4902]: No matching block device found for syspath: /sys/devices/virtual/nvme-subsystem/nvme-subsys1/nvme1n1
ledmon[4902]: === UDEV Event: action=change, syspath=/sys/devices/virtual/nvme-subsystem/nvme-subsys1/nvme1n1 ===


root@SKY-9236-efi-N1:~/ledmon/src/ledctl# ./ledctl --list-slots --controller-type VMD
slot: 19              led state: FAILURE         device: /dev/nvme1n1

Ledctl logs

No response

Ledmon supported controllers

VMD (Intel Volume Management Device)

Additional information

No response

[mtkaczyk]

When the drive is removed, the LED state should update accordingly (e.g., to an empty or neutral state). Upon re-insertion, the state should return to NORMAL.

About behavior when removed:
This is not perfect as on the software level we are unable to differentiate user intended drive remove from remove caused by hardware.
Some users would like to clear the led, some other don't. If we would like to support this- it must be configurable.
It is more like feature request to me. @tasleson what do you think?

About reinsertion:
In the past ledmon was unable to "read" the current led state. Now this functionality is supported so we may consider adding option to read the led after reinsertion and update the state to the expected.

A set of possible options is increasing, but it has to since people are using this soft! Thanks for the request.
@czsczsczs2 would you like to try implementing this?

[tasleson]

@mtkaczyk

@tasleson what do you think?

I think we have some bugs based on the logs, and we need to consider the correction of those bugs on desired behavior.

This is not perfect as on the software level we are unable to differentiate user intended drive remove from remove caused by hardware.

This is indeed true. However, should the role the drive plays be a consideration too? If the drive isn't participating in a RAID, is it OK that we update the hardware status that the drive is back?

To save some time I, let Claude chew on what is going on, I got this, which after reviewing seems legit.

1. Drive removed — ledmon's timestamp mismatch logic in _send_msg() (line 729-735) detects the device is missing, sets ibpi = FAILED_DRIVE, and writes ATTENTION_FAILURE (0xD) to the slot's attention register via vmdssd_write().

2. Drive re-inserted — ledmon's sysfs scan rediscovers the device. _add_block() finds it in ledmon_block_list and hits line 661: temp->ibpi != LED_IBPI_PATTERN_FAILED_DRIVE — this is false (it is FAILED_DRIVE), so the normal state update is skipped. It falls through to the condition at lines 673-677, which only allows transition if the incoming state is HOTSPARE or NONE — but the freshly scanned device comes in as UNKNOWN (set at block.c:314). So the state stays FAILED_DRIVE, and _send_msg() sees ibpi == ibpi_prev == FAILED_DRIVE and writes nothing new.

3. ledctl reads hardware — vmdssd_get_attention() reads the attention register, which still contains 0xD (FAILURE) from step 1 Nobody ever wrote it back to 0xF (NORMAL). So ledctl faithfully reports FAILURE.

The root problem (expected behavior) for the stuck state: FAILED_DRIVE is intentionally sticky in _add_block() — it's designed to persist across scans so a failed RAID member doesn't flicker back to normal. But this same stickiness prevents recovery after a hot-swap.

[mtkaczyk]

The root problem (expected behavior) for the stuck state: FAILED_DRIVE is intentionally sticky in _add_block() — it's designed to persist across scans so a failed RAID member doesn't flicker back to normal. But this same stickiness prevents recovery after a hot-swap.

It appears to be true. I was in impression that we are loosing info about removed drive but I was probably wrong.

Fix you are proposed in #275 seems to be good but it require some testing as we are modifying _compare which of course is not used only with NVMe.

@bkucman could you validate this on your side?
@czsczsczs2 could you verify issue is fixed with #275?

Thanks @tasleson, it seems to be good idea to invite Cloude.

[czsczsczs2]

Hi, thanks to @tasleson @mtkaczyk for the effort!

Sorry for the delay due to some personal issues.

This PR works on my side. I can see that the ADDED state is triggered, and ledctl behaves as expected on the multipath drive.

However, it seems that the REMOVED state does not appear in the logs.

Sorry if I may not fully understand some parts of the earlier discussion, as I am still learning the related background.
However, based on my current understanding and testing, the behavior is as described above.

Here are the debug logs collected while verifying this issue:

Initial state

ledmon[39029]: NEW /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme2/nvme2c2n1: state 'ONESHOT_NORMAL'.
ledmon[39029]: NEW /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:02.0/10003:0a:00.0/nvme/nvme3/nvme3n1: state 'ONESHOT_NORMAL'.
ledmon[39029]: NEW /sys/devices/pci0000:af/0000:af:00.5/pci10002:00/10002:00:06.0/10002:0a:00.0/nvme/nvme1/nvme1n1: state 'ONESHOT_NORMAL'.
ledmon[39029]: NEW /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:06.0/10003:0c:00.0/nvme/nvme5/nvme5c5n1: state 'ONESHOT_NORMAL'.
ledmon[39029]: NEW /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:04.0/10003:0b:00.0/nvme/nvme4/nvme4c4n1: state 'ONESHOT_NORMAL'.
ledmon[39029]: 10003:0d:00 before: 0xf
ledmon[39029]: 10003:0d:00 after: 0xf
ledmon[39029]: 10003:0a:00 before: 0xf
ledmon[39029]: 10003:0a:00 after: 0xf
ledmon[39029]: 10002:0a:00 before: 0xf
ledmon[39029]: 10002:0a:00 after: 0xf
ledmon[39029]: 10003:0c:00 before: 0xf
ledmon[39029]: 10003:0c:00 after: 0xf
ledmon[39029]: 10003:0b:00 before: 0xf
ledmon[39029]: 10003:0b:00 after: 0xf
ledmon[39029]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme2/nvme2c2n1: from 'ONESHOT_NORMAL' to 'UNKNOWN'
ledmon[39029]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:02.0/10003:0a:00.0/nvme/nvme3/nvme3n1: from 'ONESHOT_NORMAL' to 'UNKNOWN'
ledmon[39029]: CHANGE /sys/devices/pci0000:af/0000:af:00.5/pci10002:00/10002:00:06.0/10002:0a:00.0/nvme/nvme1/nvme1n1: from 'ONESHOT_NORMAL' to 'UNKNOWN'
ledmon[39029]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:06.0/10003:0c:00.0/nvme/nvme5/nvme5c5n1: from 'ONESHOT_NORMAL' to 'UNKNOWN'
ledmon[39029]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:04.0/10003:0b:00.0/nvme/nvme4/nvme4c4n1: from 'ONESHOT_NORMAL' to 'UNKNOWN'

Drive Removal(Using nvme2c2n1 to verify)

ledmon[39029]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme2/nvme2c2n1: from 'UNKNOWN' to 'FAILURE'.
ledmon[39029]: 10003:0d:00 before: 0xf
ledmon[39029]: 10003:0d:00 after: 0xd

Drive Re-insertion(Using nvme2c2n1 to verify)

ledmon[39029]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme2/nvme2c2n1: from 'FAILURE' to 'ADDED'
ledmon[39029]: Inappropiate IBPI LED status to set: ADDED on /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme2/nvme2c2n1
ledmon[39029]: Unable to set ADDED IBPI state on /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme2/nvme2c2n1. Status: 10
ledmon[39029]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme2/nvme2c2n1: from 'ADDED' to 'ONESHOT_NORMAL'
ledmon[39029]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme2/nvme2c2n1: from 'ONESHOT_NORMAL' to 'UNKNOWN'

[mtkaczyk]

ledmon[39029]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:08.0/10003:0d:00.0/nvme/nvme2/nvme2c2n1: from 'UNKNOWN' to 'FAILURE'.

However, it seems that the REMOVED state does not appear in the logs.

Looking into code, looks like we are avoinng printing REMOVED, we are translating it to failure:

// static void _send_msg(struct block_device *block)
    if (block->timestamp != timestamp ||
	    block->ibpi == LED_IBPI_PATTERN_REMOVED) {
		if (block->ibpi != LED_IBPI_PATTERN_FAILED_DRIVE) {
			log_info("CHANGE %s: from '%s' to '%s'.", block->sysfs_path,
				 ibpi2str(block->ibpi), ibpi2str(LED_IBPI_PATTERN_FAILED_DRIVE));

			block->ibpi = LED_IBPI_PATTERN_FAILED_DRIVE;

and this pattern is printed as failure:

	{LED_IBPI_PATTERN_FAILED_DRIVE,	"FAILURE",	"failure"},

Thanks for verifying!

[czsczsczs2]

Hi @mtkaczyk @tasleson ,

I found another issue that seems related.

I used two multipath drives to create a RAID array and used this PR to verify the rebuild LED state.

After hot-plugging the removed drive back, the LED should change from FAILURE to REBUILD, but the LED shows NORMAL, which does not match the actual RAID rebuilding state.

If I verify the same scenario with the original source code, the state changes to FAILURE, which is expected based on the udev report.

Below are some logs for troubleshooting.

Removed drive

ledmon[3279]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:06.0/10003:0c:00.0/nvme/nvme2/nvme2c2n1: from 'UNKNOWN' to 'FAILURE'. 

#mdadm --detail /dev/md126 
/dev/md126:
         Container : /dev/md/imsm0, member 0
        Raid Level : raid1
        Array Size : 10485760 (10.00 GiB 10.74 GB)
     Used Dev Size : 10485760 (10.00 GiB 10.74 GB)
      Raid Devices : 2
     Total Devices : 1

             State : active, degraded
    Active Devices : 1
   Working Devices : 1
    Failed Devices : 0

Consistency Policy : resync


              UUID : 9dac33a1:ad42571d:c9841eb1:9340b47c
    Number   Major   Minor   RaidDevice State
       1     259        5        0      active sync   /dev/nvme1n1
       -       0        0        1      removed

# ledctl --list-slots --controller-type VMD
ledctl: (raid_device_init) path: md127, level=0, state=2, degraded=-1, disks=0, type=2
ledctl: (raid_device_init) path: md126, level=2, state=7, degraded=1, disks=2, type=1
slot: 11              led state: NORMAL          device: (empty)
slot: 14              led state: NORMAL          device: (empty)
slot: 15              led state: NORMAL          device: (empty)
slot: 16              led state: NORMAL          device: (empty)
slot: 17              led state: NORMAL          device: /dev/nvme1n1
slot: 18              led state: FAILURE         device: (empty)
slot: 19              led state: NORMAL          device: (empty)

Drive Re-insertion

ledmon[3279]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:06.0/10003:0c:00.0/nvme/nvme2/nvme2c2n1: from 'FAILURE' to 'ADDED' 
ledmon[3279]: Inappropiate IBPI LED status to set: ADDED on /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:06.0/10003:0c:00.0/nvme/nvme2/nvme2c2n1 
ledmon[3279]: Unable to set ADDED IBPI state on /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:06.0/10003:0c:00.0/nvme/nvme2/nvme2c2n1. Status: 10 
ledmon[3279]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:06.0/10003:0c:00.0/nvme/nvme2/nvme2c2n1: from 'ADDED' to 'ONESHOT_NORMAL' 
ledmon[3279]: CHANGE /sys/devices/pci0000:d5/0000:d5:00.5/pci10003:00/10003:00:06.0/10003:0c:00.0/nvme/nvme2/nvme2c2n1: from 'ONESHOT_NORMAL' to 'UNKNOWN'


# mdadm --detail /dev/md126
/dev/md126:
         Container : /dev/md/imsm0, member 0
        Raid Level : raid1
        Array Size : 10485760 (10.00 GiB 10.74 GB)
     Used Dev Size : 10485760 (10.00 GiB 10.74 GB)
      Raid Devices : 2
     Total Devices : 2

             State : active, degraded, recovering
    Active Devices : 1
   Working Devices : 2
    Failed Devices : 0

Consistency Policy : resync

    Rebuild Status : 9% complete


              UUID : 9dac33a1:ad42571d:c9841eb1:9340b47c
    Number   Major   Minor   RaidDevice State
       1     259        5        0      active sync   /dev/nvme1n1
       2     259        7        1      spare rebuilding   /dev/nvme2n1

# ledctl --list-slots --controller-type VMD
ledctl: (raid_device_init) path: md127, level=0, state=2, degraded=-1, disks=0, type=2
ledctl: (raid_device_init) path: md126, level=2, state=7, degraded=1, disks=2, type=1
slot: 11              led state: NORMAL          device: (empty)
slot: 14              led state: NORMAL          device: (empty)
slot: 15              led state: NORMAL          device: (empty)
slot: 16              led state: NORMAL          device: (empty)
slot: 17              led state: NORMAL          device: /dev/nvme1n1
slot: 18              led state: NORMAL          device: /dev/nvme2n1
slot: 19              led state: NORMAL          device: (empty)
# mdadm --detail /dev/md126
/dev/md126:
         Container : /dev/md/imsm0, member 0
        Raid Level : raid1
        Array Size : 10485760 (10.00 GiB 10.74 GB)
     Used Dev Size : 10485760 (10.00 GiB 10.74 GB)
      Raid Devices : 2
     Total Devices : 2

             State : active, degraded, recovering
    Active Devices : 1
   Working Devices : 2
    Failed Devices : 0

Consistency Policy : resync

    Rebuild Status : 36% complete

              UUID : 9dac33a1:ad42571d:c9841eb1:9340b47c
    Number   Major   Minor   RaidDevice State
       1     259        5        0      active sync   /dev/nvme1n1
       2     259        7        1      spare rebuilding   /dev/nvme2n1

As shown above, nvme2n1 should be in the REBUILD state according to mdadm, but ledctl reports it as NORMAL.

I am not sure what the root cause is.

If you would like me to add more debug information to the code, I would be happy to help.

It may need some time to collect more detailed debug logs.

Thanks for the help!

[mtkaczyk]

@bkucman could you help?