Proxmox VE 9.2 – sporadic iSCSI NOP timeouts / DID_TRANSPORT_DISRUPTED with Dell PowerVault ME5 and Intel E810

[huganega]

Hi,

I am experiencing sporadic iSCSI connection interruptions on a Proxmox VE 9.2 host connected directly to a Dell PowerVault ME5224.
The issue manifests as ISCSI_ERR_NOP_TIMEDOUT, followed by DID_TRANSPORT_DISRUPTED. The affected iSCSI session usually recovers automatically after a few seconds.
The problem is intermittent. The system can run normally for a considerable amount of time before another interruption occurs.

Environment

• Proxmox VE 9.2
• currently running kernel: 7.0.14-11-pve
• 7.0.14-12-pve already installed, but not yet tested
• Dell PowerVault ME5224, dual controller
• ME5 firmware: ME5.2.0.1.1
• 25 GbE iSCSI
• direct attached iSCSI connections, no Ethernet switch between host and storage
• Intel E810-XXV 25 GbE adapters (ice driver)
• MTU 9000
• two independent iSCSI sessions / paths
• device-mapper multipath with ALUA
• LVM on top of the multipath device

The LUN WWID is:
3600c0ff0005d88902d02456a01000000

Current multipath state:
3600c0ff0005d88902d02456a01000000 dm-0 DellEMC,ME5
size=23T features='0' hwhandler='1 alua' wp=rw
|-+- policy='service-time 0' prio=50 status=active
| `- 3:0:0:0 sdh 8:112 active ready running
`-+- policy='service-time 0' prio=10 status=enabled
`- 2:0:0:0 sdg 8:96 active ready running

Multipath configuration

I have reverted the ME5 device configuration to the settings recommended in Dell's Linux documentation:

defaults {
polling_interval 5
checker_timeout 15
find_multipaths no
user_friendly_names no
enable_foreign nvme
}

devices {
device {
vendor "DellEMC"
product "ME5"
path_grouping_policy "group_by_prio"
path_checker "tur"
hardware_handler "1 alua"
prio "alua"
failback immediate
rr_weight "uniform"
path_selector "service-time 0"
}
}

Local SAS disks are explicitly blacklisted. Only the ME5 LUN appears in multipath -ll.

iSCSI settings

node.session.timeo.replacement_timeout = 5
node.conn[0].timeo.noop_out_interval = 2
node.conn[0].timeo.noop_out_timeout = 10
node.session.cmds_max = 1024
node.session.queue_depth = 128
node.session.iscsi.InitialR2T = Yes
node.session.iscsi.ImmediateData = No

Both SCSI paths currently have:
queue_depth = 128

and the multipath device:
nr_requests = 256
max_sectors_kb = 4096

Example of an actual failure
Aug 19 15:44:08 pve1 kernel: connection6:0: ping timeout of 10 secs expired, recv timeout 2, last rx 4940010531, last ping 4940010361, now 4940022785
Aug 19 15:44:08 pve1 kernel: connection6:0: detected conn error (1022)
Aug 19 15:44:09 pve1 iscsid[3208]: Kernel reported iSCSI connection 6:0 error (1022 - ISCSI_ERR_NOP_TIMEDOUT: A NOP has timed out) state (3)
Aug 19 15:44:12 pve1 iscsid[3208]: connection6:0 is operational after recovery (1 attempts)
Aug 19 15:44:26 pve1 kernel: connection6:0: ping timeout of 10 secs expired, recv timeout 2, last rx 4940028114, last ping 4940027920, now 4940040193
Aug 19 15:44:26 pve1 kernel: connection6:0: detected conn error (1022)
Aug 19 15:44:26 pve1 kernel: sd 3:0:0:0: [sdh] tag#182 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=14s
Aug 19 15:44:26 pve1 kernel: sd 3:0:0:0: [sdh] tag#164 FAILED Result: hostbyte=DID_TRANSPORT_DISRUPTED driverbyte=DRIVER_OK cmd_age=14s
Aug 19 15:44:26 pve1 kernel: sd 3:0:0:0: [sdh] tag#182 CDB: Test Unit Ready 00 00 00 00 00 00
Aug 19 15:44:26 pve1 kernel: sd 3:0:0:0: [sdh] tag#164 CDB: Test Unit Ready 00 00 00 00 00 00
Aug 19 15:44:26 pve1 iscsid[3208]: Kernel reported iSCSI connection 6:0 error (1022 - ISCSI_ERR_NOP_TIMEDOUT: A NOP has timed out) state (3)
Aug 19 15:44:29 pve1 iscsid[3208]: connection6:0 is operational after recovery (1 attempts)
Aug 19 15:44:31 pve1 kernel: sd 3:0:0:0: alua: supports implicit TPGS
Aug 19 15:44:31 pve1 kernel: sd 3:0:0:0: alua: device naa.600c0ff0005d88902d02456a01000000 port group 0 rel port 1


During this event pvestatd was also delayed:


Aug 19 15:44:31 pve1 pvestatd[3611]: status update time (27.868 seconds)


NIC / physical link

I checked the Intel E810 interface counters after the event. There are no CRC errors, packet drops or TX timeouts:
rx_dropped: 0
tx_errors: 0
tx_timeout.nic: 0
rx_dropped.nic: 0
rx_crc_errors.nic: 0


The kernel log around the failure does not contain an ice reset, link-down/link-up event or other obvious NIC error.
The affected Ethernet interface remained UP,LOWER_UP.
The second iSCSI path remains available, and multipath normally handles the failed path until the session recovers.

What has already been checked

• both iSCSI paths are present and ALUA works
• local disks are excluded from multipath
• no switch is involved in the iSCSI network
• no CRC errors or packet drops are reported by the E810
• no ice driver reset or link flap is logged at the time of the NOP timeout
• the iSCSI session automatically recovers after a few seconds
• the issue has occurred more than once and is not related to a single reboot/configuration event

I am currently trying to determine whether this is related to the Linux ice driver / E810, open-iscsi, SCSI/multipath, or the ME5 target side.
Has anyone seen similar sporadic ISCSI_ERR_NOP_TIMEDOUT / DID_TRANSPORT_DISRUPTED events with Proxmox VE 9 / kernel 7.0 and Intel E810 adapters?

Are there any known issues or recommended diagnostics for this combination?

I can provide complete iscsiadm -m session -P 3, multipathd show config, ethtool -S, kernel logs and packet captures if required.

 

[bbgeek17]

Hi @huganega ,
Are you sure that you looked at the correct network interface? The one used by iSCSI?
If you've confirmed that there are no network layer errors, then issue is likely in the higher layer of the stack. A rolling network trace would definitively tell you whether the reply is delayed by 10s or the request is never sent. The former means the issue is on the ME side (perhaps some sort of raid/group check), or PVE side (backup, CPU contention, etc).

Is this always on the same path/chain?

---

Blockbridge : Ultra low latency all-NVME shared storage for Proxmox - https://www.blockbridge.com/proxmox

 

[huganega]

Hi,

yes, I have now verified the path mapping again, and the sporadic NOP timeouts always affect the same iSCSI/SCSI path.
The connection number changed over time because the iSCSI sessions were recreated (connection2:0, later connection4:0, currently connection6:0), but the affected SCSI path has consistently been:

PVE nic6 / 10.10.1.2
->
ME5 10.10.1.1:3260
->
SCSI host 3
->
sdh

sdh is normally the ALUA preferred path (prio 50).


The second path:

PVE nic8 / 10.10.2.2
->
ME5 10.10.2.1:3260
->
SCSI host 2
->
sdg

remains available and is the non-preferred ALUA path (prio 10).

Examples from the kernel log:
Aug 12: connection2:0 ... DID_TRANSPORT_DISRUPTED ... sd 3:0:0:0 [sdh]
Aug 13: connection4:0 ... DID_TRANSPORT_DISRUPTED ... sd 3:0:0:0 [sdh]
Aug 14: connection6:0 ... DID_TRANSPORT_DISRUPTED ... sd 3:0:0:0 [sdh]
Aug 16: connection6:0 ... NOP timeouts
Aug 19: connection6:0 ... DID_TRANSPORT_DISRUPTED ... sd 3:0:0:0 [sdh]


I also checked the correct physical interface (nic6, Intel E810). Around the NOP event there are no ice driver resets, no link down/up events, no CRC errors, no RX drops and no TX timeouts.

Current mapping:
10.10.2.1 -> SID 5 -> host 2 -> sdg
10.10.1.1 -> SID 6 -> host 3 -> sdh

Current multipath state:
3600c0ff0005d88902d02456a01000000 dm-0 DellEMC,ME5
size=23T features='0' hwhandler='1 alua' wp=rw
|-+- policy='service-time 0' prio=50 status=active
| `- 3:0:0:0 sdh 8:112 active ready running
`-+- policy='service-time 0' prio=10 status=enabled
`- 2:0:0:0 sdg 8:96 active ready running

There was a separate failure at Aug 19 16:19 which I have identified and fixed: a PCI passthrough configuration had “All Functions” enabled and temporarily passed the second E810 port (12:00.1 / nic6) to a VM as well. I am excluding that incident from the NOP investigation.

I agree that a rolling packet capture is the logical next step. I will capture TCP/iSCSI traffic on nic6 so that, on the next occurrence, we can determine whether:

1. the NOP-Out is transmitted and the target does not reply in time,
2. the NOP-Out itself is delayed/not transmitted by the host, or
3. the reply is visible on the wire but not processed by the host in time.

Given that all unexplained events so far affect the same path, I am also investigating the physical/ME5 side of that specific path.

 

[Tmanok]

Hey Everyone,

I also checked the correct physical interface (nic6, Intel E810). Around the NOP event there are no ice driver resets, no link down/up events, no CRC errors, no RX drops and no TX timeouts.

I think there's something pretty overlooked here: Dell's ME5 documentation explicitly says that for iSCSI usage you must have symmetric flow control enabled on the interfaces. If the E810 and ME5 aren't agreeing properly on pause behavior, bursts can overrun buffers on the active path without producing:

rx_crc_errors
rx_dropped.nic
tx_errors

(on the host at least)
A target-side buffer drop obviously doesn't have to increment the host's NIC error counters. You should gather
host-port statistics from the ME5. Dell officially supports direct-connected 25 GbE iSCSI, so the topology itself isn't the problem in my opinion.

Not to let your NIC completely off the hook or anything, I just see this as less likely. If nic6 is receiving huge quantities of PAUSE frames around the incidents, that becomes interesting. Intel's own E810 documentation makes clear that the adapter has a fairly complex multi-queue/interrupt architecture, and Intel specifically recommends examining per-queue drop statistics, IRQ affinity, ring sizes, etc. when troubleshooting receive-side stalls. You should of course also gather host-port statistics from your Intel E810:

ethtool -i nic6
ethtool -i nic8
ethtool -l nic6
ethtool -g nic6
ethtool -c nic6
cat /proc/interrupts | grep -i nic6
cat /proc/net/softnet_stat

If you bring those back to the forum, we might be able to help look for firmware versions reporting issues, too. But you can always try looking through other forums or the changelogs. Here's a list of reference docs I referred to:

• https://www.dell.com/support/manual...954326-1279-4214-8440-c68f0ef2d07f&lang=en-us
• https://www.dell.com/support/manual...9e84a0-66b9-4df8-bd6b-13461a338c9b&lang=en-us
• https://www.dell.com/support/manual...69ed4a-ea80-48b8-bc30-801754ce8df3&lang=en-us
• https://www.dell.com/support/manual...c1d164-1043-4ae2-b12c-54cc8bae014f&lang=en-us
• https://github.com/intel/ethernet-linux-ice/blob/main/README (This is for Intel 800 series NICs)

Thanks, hope you find something more obvious in those port statistics!


Tmanok

 

[huganega]

Hi,

thanks for the pointers. I checked the E810 configuration and statistics.

Both iSCSI interfaces are using the ice driver with firmware 4.91 0x800214ab 1.3909.0.
Both currently use 16 combined queues, RX ring size 2048 / TX 256, and adaptive RX/TX coalescing is enabled.

Flow control also looks correct on both interfaces and, importantly, it is actually negotiated in both directions:

nic6:
RX: on
TX: on
RX negotiated: on
TX negotiated: on

nic8:
RX: on
TX: on
RX negotiated: on
TX negotiated: on

On the active path (nic6) I currently see 5,648 received XOFF and 5,648 XON frames, while there are no RX drops, CRC errors or TX timeouts:

rx_dropped: 0
tx_errors.nic: 0
tx_timeout.nic: 0
link_xon_rx.nic: 5648
link_xoff_rx.nic: 5648
rx_dropped.nic: 0
rx_crc_errors.nic: 0
mac_local_faults.nic: 0
mac_remote_faults.nic: 2

nic8 is the passive ALUA path and carries almost no I/O, so the very low pause-frame counters there seem expected.

I have also set up rolling tcpdump captures on both iSCSI interfaces. Unfortunately the NOP/ping timeout is quite sporadic, so there hasn't been another occurrence since setting this up.
For now I will leave the NIC/ring/coalescing settings unchanged and wait for the next timeout. Once it happens, I should have packet captures from both paths covering the event, together with the kernel timestamp and NIC statistics. That should allow us to determine whether the NOP-Out actually leaves the host and whether the response from the ME5 is delayed/missing.

I'll post the results as soon as I catch the next occurrence.

Thanks again for the help.

 

[huganega]

Quick update:

Unfortunately, another NOP timeout occurred last night at 03:01:30:

Aug 21 03:01:30 pve1 kernel: connection2:0: ping timeout of 10 secs expired, recv timeout 2
Aug 21 03:01:30 pve1 kernel: connection2:0: detected conn error (1022)
Aug 21 03:01:30 pve1 iscsid: Kernel reported iSCSI connection 2:0 error (1022 - ISCSI_ERR_NOP_TIMEDOUT)
Aug 21 03:01:33 pve1 iscsid: connection2:0 is operational after recovery (1 attempts)

After the reboot, SID 2 maps to:

10.10.1.2 -> 10.10.1.1

so this is again the A0/nic6 path, which is also the active ALUA path (prio 50).

The E810 statistics still don't show any obvious host-side network errors:

rx_dropped: 0
tx_errors.nic: 0
tx_timeout.nic: 0
rx_dropped.nic: 0
rx_crc_errors.nic: 0
mac_local_faults.nic: 0
mac_remote_faults.nic: 2

link_xon_rx.nic: 25127
link_xoff_rx.nic: 25127
link_xon_tx.nic: 6
link_xoff_tx.nic: 6

So flow control is clearly active on the busy path, and I still don't see packet drops, CRC errors or TX timeouts on the host NIC.

I did have rolling tcpdump captures running on both iSCSI interfaces. However, I underestimated the amount of traffic on the active 25 GbE path. By the time I noticed the event in the morning, the nic6 capture containing 03:01:30 had already been overwritten. The passive nic8 capture still contains the period, but unfortunately that is not the path on which the timeout occurred.

I have now changed the capture setup. A systemd watcher monitors the kernel log for detected conn error (1022). When another event occurs, it immediately stops both rolling captures, preserves the current PCAP rings together with iSCSI/multipath/E810 diagnostics, and then restarts the captures.

So the next occurrence should finally give us the packet trace around the actual failure and allow us to determine whether the NOP-Out leaves the PVE host and whether/when the ME5 replies.

One interesting observation so far is that all NOP timeout events I have checked have occurred on the same active A0/nic6 path. I will update the thread again as soon as the next event is captured.

 

[Tmanok]

Hi Huganega,

Ok, a few things from your output might be worth examining, but I have to ask a question I normally ignore because I'm vendor agnostic 99% of the time. Are you using a Dell recommended DAC? 25GbE has caused me trouble in the past with some products because it has additional features such as FEC. Moreover, SFP type connectors are very picky about their firmwares.

Back to your outputs and messages, there's a pretty important concept to understand here about PCAP saying that it sent NOP-Out, which is that when your ME5 is pausing transmission due to performance pressures, it may not see that NOP at all. It may genuinely be ignoring packets until it is ready again. So all that PCAP proves is that Linux sent the NOP, not that the ME5 received it.

I bring this up because your OS is clearly receiving pause requests from the ME5 (ON and OFF):

link_xon_rx.nic: 25127
link_xoff_rx.nic: 25127
link_xon_tx.nic: 6
link_xoff_tx.nic: 6

What might peg this on the ME5 for sure would be to figure out whether XOFF frames suddenly arrive in a concentrated burst immediately before the 10-second iSCSI blackout.

Something else worth considering Intel released E810 NVM 5.01 on July 10, 2026. Your firmware is fairly up to date, but it's a new NIC series and might benefit from newer firmware. Sucks that I can only find Windows utilities for it, though...
https://www.intel.com/content/www/u...net-network-adapters-e810-series-windows.html SHA256: 69DF8E77E6CDED18E38921C1626B4120A60CDAFCC69FDBAB7E90FBD8E9182C8F

tmanok@MBP14-M5 Downloads % shasum -a 256 E810_NVMUpdatePackage_v5_01_Windows.zip
69df8e77e6cded18e38921c1626b4120a60cdafcc69fdbab7e90fbd8e9182c8f  E810_NVMUpdatePackage_v5_01_Windows.zip

You can find it here since the forum does not permit large files: https://archive.org/download/e-810-...ndows/E810_NVMUpdatePackage_v5_01_Windows.zip
I linked a copy to the forum because in 6-24 months when someone tries to find this version and only finds broken links, they may thank me.

Thanks,



Tmanok

 

[huganega]

Hi Tmanok,

Thanks for pointing me towards the newer E810 NVM firmware.
I checked the adapters more closely and there is one important detail: these are HPE OEM Intel E810-XXVDA2 adapters, not Intel retail adapters.

Both adapters were running:
firmware-version: 4.91 0x800214ab 1.3909.0

HPE currently provides and recommends NVM 5.00 for these adapters. Intel already has 5.01 available for the E810 series, but since HPE has only released/validated 5.00 for the HPE OEM adapters, I decided to stay with the OEM-supported firmware rather than flashing Intel's generic 5.01 package.

I have now updated both adapters successfully to:
driver: ice
version: 7.0.14-12-pve
firmware-version: 5.00 0x80021bd4 1.4002.0

Both 25 GbE iSCSI links came back correctly after the update. Flow control is still negotiated in both directions on both interfaces:

Pause parameters for nic6:
Autonegotiate: on
RX: on
TX: on
RX negotiated: on
TX negotiated: on

Pause parameters for nic8:
Autonegotiate: on
RX: on
TX: on
RX negotiated: on
TX negotiated: on

Multipath/ALUA also looks normal, with the A0/nic6 path active at priority 50 and the B0/nic8 path available at priority 10.
After the reboot the active nic6 path is already receiving PAUSE frames again:

link_xon_rx.nic: 704
link_xoff_rx.nic: 704
rx_dropped.nic: 0
rx_crc_errors.nic: 0
tx_timeout.nic: 0

So the ME5 is clearly making use of Ethernet flow control, but there are still no obvious host-side drops or CRC errors.

One caveat: according to HPE's published fixes for NVM 5.00, the documented fix is related to LLDP receive reporting. There is no documented iSCSI, flow-control or link-stall fix that would directly explain my issue. Therefore I won't assume that the firmware update fixes the NOP timeouts.

The automated rolling PCAP/event capture is still running. I'll leave the configuration unchanged now and wait for another NOP timeout. If it happens again, we should finally have the packet trace and diagnostics from the actual event.

 

[huganega]

Hi Tmanok,
thanks again for the suggestions. I have some new data now, so I am replacing my previous update with a more complete one.

First, regarding the NIC firmware:
The adapters are HPE OEM Intel E810-XXVDA2 cards. I updated both NICs from:

firmware-version: 4.91 0x800214ab 1.3909.0

to the latest firmware currently released by HPE:

firmware-version: 5.00 0x80021bd4 1.4002.0

I deliberately did not install Intel's generic NVM 5.01 package because these are HPE OEM adapters and HPE currently only provides/recommends NVM 5.00 for them.

Both links are still running at 25 Gbit/s and flow control is negotiated RX/TX on both interfaces.

Unfortunately, the firmware update did not resolve the problem. I captured another event today:

08:43:07 connection2:0 ping timeout of 10 secs expired
08:43:07 detected conn error (1022)
08:43:07 sdk: DID_TRANSPORT_DISRUPTED
08:43:10 connection2:0 operational after recovery

08:43:24 connection2:0 ping timeout of 10 secs expired
08:43:24 detected conn error (1022)
08:43:24 sdk: DID_TRANSPORT_DISRUPTED
08:43:27 connection2:0 operational after recovery

This is again the active path via controller A0 / nic6.
The rolling PCAP capture worked as intended. For the first event tcpdump reported:

nic6: 26,519,499 packets captured
26,519,499 packets received by filter
0 packets dropped by kernel

nic8: 7,150 packets captured
7,150 packets received by filter
0 packets dropped by kernel

I also implemented a one-second logger for the E810 counters specifically to test your XOFF-burst theory.
This produced an interesting result: there was no XOFF/XON burst immediately before this NOP timeout.

From 08:42:30 through 08:43:07 the counters remained completely unchanged:

link_xon_rx.nic = 219631
link_xoff_rx.nic = 219631

There were also no RX drops or CRC errors.

Looking more closely at the PCAP showed another interesting pattern. Immediately before the blackout there is very heavy iSCSI traffic. The Linux TCP receive window becomes very small, and then there is approximately a 12-second period without useful iSCSI traffic before communication resumes.

So at least for this event I cannot see evidence that a concentrated burst of Ethernet PAUSE/XOFF frames immediately before the timeout caused the blackout.

I have now noticed another possible correlation which may be more interesting: the NOP events seem to coincide with backup activity.

For today's event:

08:43:07 first NOP timeout
08:43:10 recovered
08:43:24 second NOP timeout
08:43:27 recovered
08:43:53 Finished Backup of VM 304
08:43:54 Starting Backup of VM 305

VM 304 has five virtual disks on the ME5-backed stor1-vm storage. At the end of the Proxmox vzdump log, five fleecing images are removed before the backup is reported as finished:

removing (old) fleecing image 'local-vm:vm-304-fleece-0'
removing (old) fleecing image 'local-vm:vm-304-fleece-1'
removing (old) fleecing image 'local-vm:vm-304-fleece-2'
removing (old) fleecing image 'local-vm:vm-304-fleece-3'
removing (old) fleecing image 'local-vm:vm-304-fleece-4'
Finished Backup of VM 304

I do not want to conclude yet that removal of the fleecing images / backup cleanup is the cause. The individual cleanup lines in the vzdump task log do not contain timestamps, and an earlier NOP event also occurred while another backup was still in progress rather than right at its end.

However, the apparent correlation with backup/storage activity is interesting enough that I have extended the monitoring again.

In addition to the one-second NIC monitoring I am now recording the dm-0 block statistics for the ME5 LUN every second:

reads / sectors read / read time
writes / sectors written / write time
I/Os currently in progress
I/O time
weighted I/O time
discards
flush requests / flush time

The same logger also records:

XON/XOFF RX/TX
RX drops
CRC errors
MAC remote faults
RX/TX packets and bytes
RX allocation failures
TX busy/restart counters
softnet dropped/time_squeeze
NIC IRQ activity

The event-triggered script preserves the PCAPs, diagnostics and the one-second counter history when the kernel reports ISCSI_ERR_NOP_TIMEDOUT.

So the next occurrence should tell us whether there is a sudden block-I/O/flush spike or queue buildup immediately before the NOP timeout, whether the block-I/O counters stop progressing during the blackout, or whether the issue is still somewhere below that layer.

For now, the two useful findings from today's event seem to be:

1. Updating the HPE E810 firmware from NVM 4.91 to HPE NVM 5.00 did not eliminate the NOP timeout.
2. There was no concentrated XOFF/Pause burst immediately before this particular NOP timeout.

I'll leave the extended monitoring running and post the next captured event.

Thanks

 

[Tmanok]

Hmm well there goes my PAUSE frames storm hypothesis. There was no corresponding jump in link_xoff_rx.nic, no CRC errors, no drops, no E810 reset and no physical link loss. So I was wrong... But that narrowing TCP window is TCP-layer backpressure, which is rather similar to Ethernet flow-control backpressure so at least we were on a parallel thought process.

Looking at your log there, 08:43:07 ping timeout of 10 secs expired seems to indicate the problem started closer to 08:42:57 or earlier, which is consistent with your PCAP showing approximately twelve seconds of useless traffic immediately before the timeout. Look for any misbehaviour around 08:42:50 to 08:43:10.

I don't think your fleece concern is relevant to this exact issue, by the way. Fleecing places QEMU copy-before-write filters in front of the source disks. Old data required by the backup is copied into the fleece storage as guest writes occur, and the backup reads the logical snapshot through that mechanism. Your fleece images are on local-vm, so the eventual image removal is primarily local-storage cleanup. Proxmox's backup architecture is quite incredible, I really enjoyed learning it when I got my Proxmox VE Advanced certificate a few years ago.

Can you tell me what QEMU is doing immediately before it reaches cleanup:

• finishing the backup block jobs;
• draining outstanding work;
• processing the last portion of each source disk;
• removing the copy-before-write/snapshot-access nodes;
• potentially causing a change in I/O concurrency/pattern.

There have been QEMU block level management bugs in the past: https://lists.proxmox.com/pipermail/pve-devel/2024-June/064281.html and maybe even most relevant of all, there's an active thread about PBS slowing down https://forum.proxmox.com/threads/s...r-updated-to-pve-9-1-1-and-pbs-4-0-20.176444/ Fabian (staff) was asking a funny question:

“are the connections stalling with tiny receive windows”

Here's what I think we shold try to answer next, then maybe a staff member can come by and give us a hand if it really is PVE related.

• How small does the advertised Linux receive window actually become?
  • 64 KiB?
  • a few KiB?
  • zero?
• Does Wireshark report:
  • TCP ZeroWindow
  • TCP Window Full
  • TCP ZeroWindowProbe
  • TCP ZeroWindowProbeAck
  • retransmissions?
• Who sends the final useful payload before the blackout?
• Does Linux continue emitting TCP ACKs while iSCSI stops progressing?
• Can we see the actual NOP-Out around ~08:42:57?
• Does the ME5 TCP stack ACK that NOP-Out?
• Is there a NOP-In response visible later in the TCP stream once the receive window opens?

If you can figure those out, I think we'll be onto something. Sorry for leading us astray with the 810 NIC issues and the ME5, but I'm only 80% convinced they still aren't to blame which is why I'd still like to know more about how the ME5 is responding and the NOP-In NOP-Out information.
Cheers,


Tmanok

 

[huganega]

Thanks, this was very useful.

I have now captured another NOP timeout with both the rolling PCAP and an extended 1-second host-side logger, and some of your questions can now be answered more precisely.

The advertised Linux TCP receive window becomes extremely small. On the affected iSCSI connection, tshark shows:
46399
45282
44165
43048
...
10274
9525
8408
7291
6174
5057
3940
2823
1148
31

The connection uses a receive window scale of 4, so the final advertised receive window is:
31 × 16 = 496 bytes
This matches the host-side ss logging exactly:
rcv_wnd = 496
So the window does not initially reach zero, but it becomes effectively unusable.

Wireshark/tshark does not report:
TCP ZeroWindow
TCP Window Full
TCP ZeroWindowProbe
TCP ZeroWindowProbeAck
This makes sense because the advertised receive window never actually reaches zero.

Immediately before the blackout, the ME5 is the sender of the final useful payload. It is sending large TCP segments of approximately 8936 bytes to the Linux initiator.

During that burst, Linux continues ACKing the incoming payload while reducing its advertised receive window packet by packet until only 31 raw / 496 scaled bytes remain.

Example:
ME5 -> PVE: 8936-byte payload
PVE -> ME5: ACK Win=23678
PVE -> ME5: ACK Win=22561
...
PVE -> ME5: ACK Win=1148
PVE -> ME5: ACK Win=31
After that, there is approximately 12 seconds with no useful progress.
The ME5 then still sends a TCP keepalive shortly after the window collapse, but there is no useful response from the Linux side. Roughly 12 seconds later, Linux terminates the TCP session after the iSCSI NOP timeout.

The same pattern occurred repeatedly during the same incident:
07:27:31
07:27:49
07:28:06
07:28:24
07:28:41
with recovery between the timeouts.

At the same time, I still see no evidence of a classic NIC or Ethernet issue:
NIC RX drops = 0
CRC errors = 0
softnet drops = 0
TCP backlog drops = 0
TCP receive queue drops = 0
IP input discards = 0
no E810 reset
no physical link flap
no corresponding XOFF jump
I have also applied Dell's recommended Linux TCP buffer settings:
net.core.rmem_max = 134217728
net.core.wmem_max = 134217728
net.core.netdev_max_backlog = 300000
net.ipv4.tcp_rmem = 4096 87380 134217728
net.ipv4.tcp_wmem = 4096 65536 134217728
net.ipv4.tcp_moderate_rcvbuf = 1
The host was not rebooted afterwards, so these settings were active during the latest NOP timeout. They did not prevent the issue.

I have now extended the logger further to record socket memory every second:
skmem_r
skmem_rb
skmem_t
skmem_tb
skmem_f
skmem_w
skmem_o
skmem_bl
skmem_d
Current normal baseline:
Recv-Q = 0
rcv_wnd = 742384
rcv_space = 333680
skmem_r = 0
skmem_rb = 1048576
skmem_bl = 0
skmem_d = 29
So the next occurrence should tell us whether the receive window collapses because the socket buffer/backlog is actually filling up, or whether the window remains nearly closed even though the receive socket is already empty.

Dell support is also involved now. Starting tonight, I will collect ME5 controller, disk, pool, host-port and volume statistics every 60 seconds between 02:00 and 08:59, so I should be able to correlate the next host-side stall with the SAN-side performance state.

One thing I still cannot answer cleanly yet is the exact iSCSI NOP-Out/NOP-In exchange. Because the capture is started mid-session and uses snaplen 256, tshark does not reliably dissect the traffic as iSCSI. TCP-level analysis is good, but iSCSI PDU decoding is incomplete.

At this point the most interesting observation to me is:

The ME5 is still sending data, Linux ACKs it, but Linux rapidly closes the receive window to only 496 bytes and then no useful progress occurs for about 12 seconds until open-iscsi times out the session.

If anyone has seen this exact receive-window behavior with open-iscsi, QEMU block jobs or the Linux TCP receive path, I would be very interested.

 

[huganega]

Thanks for the links. I have looked into both of them in more detail now.

The fleecing patch is interesting because it demonstrates that a QEMU block-drain condition can indeed leave guest I/O stuck if the drained section is not terminated correctly. However, I don't think that specific old fleecing bug is what I am seeing here, especially since I have also observed the iSCSI NOP issue outside backup/fleecing activity.

The second thread turned out to be much more interesting, particularly the reference to connections stalling with tiny receive windows.

Since my previous post I captured another occurrence with additional SCSI, TCP and ME5-side statistics. There is now a very clear correlation between the receive-window collapse and saturation of the active SCSI path.

Immediately before the incident:

normal:
sdk outstanding = ~0
TCP rcv_wnd = 742384

At the start of the stall:
sdk outstanding = 128/128
TCP rcv_wnd = 496 bytes

The active sdk path then remains at exactly 128 outstanding requests with no completions for roughly 12-14 seconds, while outstanding I/O on the multipath device accumulates up to about 256.

When the NOP timeout occurs, sdk_ioerr_cnt increases by exactly 128 and the 128 outstanding requests are cleared during iSCSI recovery.

After reconnect, the active path rapidly reaches 128/128 again, the TCP receive window becomes tiny again, and the next NOP timeout follows.

The ME5 statistics collected during the same incident show the same thing from the target side. The active host port reports queue-depth 128 during the bad interval, together with a very large increase in response times and a collapse in IOPS.

So the sequence currently looks approximately like this:

normal I/O
→ active SCSI path reaches 128/128 outstanding
→ Linux advertised TCP receive window collapses from ~742 KB to a few hundred / few thousand bytes
→ no SCSI completions / no useful TCP progress
→ dm-multipath outstanding I/O accumulates
→ NOP timeout
→ iSCSI recovery clears the 128 outstanding requests
→ reconnect
→ same cycle can repeat

One additional observation is important: during the stall, Recv-Q and socket receive memory do not appear to fill up.

I logged:

Recv-Q = 0
skmem_r = 0
skmem_rb = 1048576

and I also see no TCP memory pressure, TCP receive queue drops, backlog drops, softnet drops, NIC drops or CRC errors.

So at least from the data I have so far, this does not look like a simple case of the userspace-visible socket receive queue filling up.

I also checked:

net.ipv4.tcp_shrink_window = 0

which makes the voluntary tcp_shrink_window behaviour an unlikely explanation for the extreme window reduction.

I am now tracing the kernel TCP receive path as well. In particular I have enabled the filtered tcp_rcvbuf_grow tracepoint for the iSCSI connection, which exposes:

rcvbuf
space
rcv_ssthresh
window_clamp
rcv_wnd
inq
ooo_space

as well as tcp_retransmit_skb.

Interestingly, during normal iSCSI operation tcp_rcvbuf_grow does not fire at all, so the next real stall should be quite informative if the receive-buffer/window growth path becomes involved.

At this point I am not sure about the direction of causality yet:

1. the SCSI/iSCSI path stops making progress and TCP closes the receive window as backpressure,

or

1. something in the TCP receive/window handling causes the iSCSI data path to stop making progress and eventually saturates the SCSI queue.

But the tiny receive window mentioned in the linked thread is definitely present here, and it occurs at exactly the same time that the active iSCSI/SCSI path stops completing requests.

 

[Tmanok]

Hi Huganega,

Ok, that 128/128 result is probably the most interesting thing you've found yet. The fact that the active SCSI path reaches exactly 128 outstanding requests, stops completing them for 12-14 seconds, and then sdk_ioerr_cnt increases by exactly 128 when iSCSI recovery occurs is almost too tidy to ignore.

I'm also much less convinced now that the tiny TCP window is being caused by the receive socket simply filling. If at the same time you're seeing:

Recv-Q = 0
skmem_r = 0
skmem_rb = 1048576
rcv_wnd = 496

then Linux is advertising virtually no receive space despite there apparently being nothing queued in the socket. There's a good chance this is the strange tiny-window behaviour Fabian was chasing in the other thread than to ordinary TCP backpressure. I wouldn't change any more TCP sysctls for the moment. I think just two more tests will tell us more.

First, as a diagnostic only, I'd try reducing the active SCSI path queue depth from 128 to 64 and repeat the workload:

echo 64 > /sys/block/sdh/device/queue_depth

Maybe even 32 afterward if necessary. I'm not suggesting 64 is the correct production setting. I just want to know whether the failure disappears, becomes less frequent, or simply occurs when the new queue depth becomes saturated. If the whole sequence changes from:

128/128 -> tiny TCP window -> stall -> NOP timeout

to:

64/64 -> tiny TCP window -> stall -> NOP timeout

that should give us our last clue here.

Second, I believe the optimized ALUA workload should be moved onto B0/nic8 for a test if that's ok with you. So far virtually every unexplained failure has involved A0/nic6. If you make B0/nic8 the preferred/active path and the same 128-outstanding/tiny-window behaviour follows the workload over there, I'd become much more suspicious of the Linux iSCSI/SCSI/TCP path generally. If B0 happily handles the same backup/storage workload while A0/nic6 was repeatedly stalling, then I think Dell has something quite concrete to investigate on controller A / that host port / that path.

The ME5 statistics are also useful here. The target seeing queue depth 128 at the same time as response latency explodes and IOPS collapse means the SAN side is seeing the stall too. That doesn't prove the ME5 caused it, but at least we're no longer dealing with something visible only inside Linux. Personally I think the order of causality is now the main unanswered question:

SCSI path stops completing -> 128 outstanding requests accumulate -> TCP receive window collapses -> NOP timeout

versus:

TCP receive/window handling goes wrong -> iSCSI Data-In stops progressing -> SCSI commands reach 128/128 -> NOP timeout

Your tcp_rcvbuf_grow tracing may help answer that, but I think the queue-depth and ALUA-path tests might get us there faster. The exact 128 outstanding -> 128 ioerr relationship is the diagnostic pathway I'd follow now.

Cheers,


Tmanok

 

[huganega]

Hi Tmanok,

thanks, those are good suggestions. There are two details from our earlier troubleshooting that I should add:

We have already tested the other ALUA path. We took the active A0/nic6 path offline, forcing the workload over B0/nic8. The same NOP timeout problem occurred there as well, with essentially the same behaviour. So the issue does not appear to be specific to controller A / A0 / nic6.

We have also effectively tested a substantially lower queue depth already. node.session.queue_depth was originally at the default value of 32. The problem existed with queue depth 32 as well. We later increased it to 128 during troubleshooting, but this did not improve the situation – the NOP timeouts continued.

Unfortunately, when we were still running with QD32, we did not yet have the detailed per-second SCSI instrumentation that we have now, so I cannot show whether those older events followed the exact 32/32 -> tiny receive window -> NOP -> +32 ioerr pattern. With QD128 we can demonstrate the 128/128 -> stall -> recovery -> +128 ioerr sequence very clearly.

Because of that, I don't think changing 128 to 64 or switching the active ALUA path again would currently add much information. Both variables have already been changed independently without eliminating the problem.

Instead, I've now added higher-resolution instrumentation to catch the transition itself. We are monitoring the active SCSI and dm outstanding I/O at 10 ms resolution and have added the kernel tcp_probe tracepoint, which exposes rcv_wnd, snd_wnd, snd_cwnd, srtt, sequence numbers and the socket cookie.

The goal for the next occurrence is to determine the ordering within the interval that our previous 1-second sampling could not resolve:

SCSI queue starts filling -> receive window collapses
or
receive window collapses -> SCSI queue starts filling.

That should hopefully tell us which side of the SCSI/iSCSI/TCP chain stalls first.

 

[huganega]

Another update, as I have now been able to correlate the TCP behaviour with the SCSI path at much higher resolution.

The latest captured incident makes the sequence around the stall considerably clearer.

Immediately before the stall, the ME5 is still sending a large burst of data towards the PVE host, mostly as ~8936-byte TCP payloads. Linux continues ACKing this data, but within a very short period the advertised receive window collapses packet by packet:

46399
45282
44533
43416
...
4499
3382
2265
1148
31

With the negotiated window scaling this corresponds to an effective receive window of only 496 bytes.

There are still no TCP retransmissions, lost segments or ZeroWindow events in the capture, and the NIC continues to show no RX drops, CRC errors, softnet drops, link flap or E810 reset.

At exactly the same time, the active SCSI path reaches its queue limit:

queue_depth = 128
sdk_device_busy = 128
sdk_io_in_progress = 127

The more interesting observation is that SCSI completions then stop completely.

For example, during the captured interval:

07:32:14
sdk_iodone_cnt = 779682533
sdk_iorequest_cnt = 779682661

07:32:15
sdk_iodone_cnt = 779682533
sdk_iorequest_cnt = 779682661

...

07:32:25
sdk_iodone_cnt = 779682533
sdk_iorequest_cnt = 779682661
So for approximately 11 seconds there is no progress on the active SCSI path while ~127 requests remain outstanding.

What I find particularly interesting is the socket state during this condition:

Recv-Q = 0
rcv_wnd = 496
rcv_space = 503808

skmem_r = 0
skmem_rb = 1048576
skmem_bl = 0
Therefore the advertised receive window remains effectively closed even though the userspace-visible receive queue is empty and the socket receive-memory counters do not indicate that the 1 MB receive buffer is full.

The packet capture also shows that immediately before the collapse Linux is actively ACKing the incoming ME5 data while reducing its receive window. The final sequence is essentially:

ME5 -> PVE: data
PVE -> ME5: ACK, decreasing receive window
...
PVE -> ME5: ACK Win=1148
PVE -> ME5: ACK Win=31
The ME5 still sends an ACK shortly afterwards, but useful I/O progress has effectively stopped.

This strengthens the correlation between the SCSI queue stall and the TCP receive-window collapse, but I still cannot determine the direction of causality:

SCSI/iSCSI processing stalls
↓
128 outstanding commands
↓
TCP receive processing applies backpressure
↓
rcv_wnd collapses
↓
NOP timeout
or:

TCP receive/window processing stalls
↓
iSCSI Data-In cannot progress
↓
SCSI completions stop
↓
queue reaches 128/128
↓
NOP timeout
I have therefore extended the kernel tracing again.

For the affected iSCSI TCP connection I am now tracing:

• tcp_probe
• tcp_rcv_space_adjust
• tcp_rcvbuf_grow

together with the existing high-resolution SCSI/sysfs logger.

I also collected a normal-operation baseline. Interestingly, tcp_rcv_space_adjust is very active during healthy iSCSI traffic (about 11,835 events over 30 seconds in one sample), while tcp_rcvbuf_grow did not fire at all.

During normal operation the receive window can also temporarily become small and recover very quickly; for example one trigger showed:

rcv_wnd = 13840
and roughly 52 ms later:

rcv_wnd = 742384
So a small receive window by itself is clearly not the failure condition.

The failure fingerprint currently appears to be the combination of:

SCSI path ~128/128 outstanding
+
SCSI completions stop for ~10-12 seconds
+
TCP advertised receive window collapses to ~496 bytes
+
no NIC/TCP packet-loss indicators
+
NOP timeout / iSCSI recovery
I will leave the tracing running unchanged until the next real NOP timeout. That should allow comparison of tcp_rcv_space_adjust activity immediately before and during the actual SCSI completion stall.

At this point I would be particularly interested in whether anyone familiar with the Linux iSCSI/TCP receive path can explain how rcv_wnd can remain at only ~496 bytes while Recv-Q=0, skmem_r=0 and rcv_space is still ~503 KB, or whether this behaviour is expected when the upper iSCSI/SCSI layer stops consuming/progressing I/O.

 

[huganega]

Update: issue reproduced again, twice in the same packet capture

I captured another series of four ISCSI_ERR_NOP_TIMEDOUT events on Sep 7. Two of them are fully covered by the packet capture, and both reproduce essentially the same packet-level sequence seen on Sep 6.

For the first captured failure:
11:40:31.388915 PVE -> ME5 ACK, receive window reduced to a very small value
11:40:31.403772 ME5 -> PVE TCP Keep-Alive
...
11:40:43.529527 PVE -> ME5 FIN,ACK
There are no packets from the PVE host on this connection for approximately 12.1 seconds between the last ACK and connection teardown.
The second failure is nearly identical:
11:40:48.930237 PVE -> ME5 ACK, calculated advertised window = 496 bytes
11:40:48.944238 ME5 -> PVE TCP Keep-Alive
...
11:41:00.936418 PVE -> ME5 FIN,ACK
Again there are approximately 12 seconds without any packet from the initiator.
An important additional observation is that the target sends a TCP Keep-Alive during the stalled period, but the PVE host does not ACK it.
I also do not see an iSCSI NOP-Out transmitted by the initiator during the critical interval.

Therefore the later
ISCSI_ERR_NOP_TIMEDOUT: A NOP has timed out
appears to be a consequence of an already stalled connection rather than evidence that the target simply ignored a NOP-Out.
At the same time the SCSI tracing shows the affected path at/near queue depth 128, SCSI completions stopping, and very high I/O PSI.

During this Sep 7 series there were four NOP timeouts:
11:40:43
11:41:00
11:41:18
11:41:36
The sdk ioerr counter increased by exactly 512 over the series (4 × 128), consistent with the outstanding queue being failed during each connection recovery.
Current observed sequence:
heavy iSCSI Data-In
↓
initiator advertised receive window becomes very small
↓
SCSI queue reaches ~128 / completions stall
↓
target sends TCP keep-alive
↓
initiator does not ACK the TCP keep-alive
no TCP window update
no iSCSI NOP-Out visible on wire
↓
~12 seconds with no initiator traffic
↓
ISCSI_ERR_NOP_TIMEDOUT
↓
initiator tears down/recreates connection

There are still no NIC drops or TCP retransmission/packet-loss indications in the capture.
This is now reproducible across multiple independent occurrences and seems to point more toward a Linux initiator TCP/iSCSI/SCSI interaction than a simple physical network loss.

Any suggestions for additional kernel tracepoints or specific open-iscsi/TCP state that would help identify why the initiator stops transmitting on this socket would be very welcome.