Intermittent multi-second ZFS I/O latency on 4x Crucial BX500 RAIDZ1 – SMART clean, latency changes between drives

[cupidonihack]

Hi,

I am trying to diagnose severe intermittent I/O latency on a single-node
Proxmox VE server.

I have already spent quite a lot of time isolating the issue, but the results
are becoming confusing. I would appreciate some experienced ZFS/PVE advice
before replacing hardware randomly.

SYSTEM
------

- Proxmox VE 9.2
- Kernel: 7.0.14-15-pve
- Single node, no cluster
- Gigabyte GA-Z270XP-SLI motherboard
- Intel Z270 AHCI SATA controller
- 4 x Crucial BX500 1 TB SATA SSD
- Firmware M6CR061
- ZFS RAIDZ1 pool named "storage"
- Docker runs inside an LXC container
- Nextcloud + MariaDB run as Docker containers

SSD serial numbers:

D45E = 2418E8ABD45E
D472 = 2418E8ABD472
E315 = 2418E8ABE315
DE32 = 2418E8ABDE32

The ZFS pool remains ONLINE:

READ = 0
WRITE = 0
CKSUM = 0

Last scrub repaired 0B and reported 0 errors.


APPLICATION SYMPTOM
-------------------

During a large Nextcloud desktop synchronization (~90,000 files), the client
regularly reports that connection to the server is taking too long.

Nginx then reports FastCGI timeouts waiting for PHP-FPM.

I enabled the PHP-FPM slowlog.

The slow requests consistently end up waiting inside SQL execution, for example:

PDO Statement::execute()
-> Doctrine DBAL
-> Nextcloud DB Connection
-> QueryBuilder::executeStatement()
-> Files/Cache/Cache.php
-> Scanner.php
-> finalizeUpload()
-> WebDAV PUT/MOVE

For example, after a reboot I still captured:

MOVE /remote.php
executing too slow: 10.75 seconds

with the process stuck at PDO/Doctrine executeStatement() while inserting into
the Nextcloud file cache.

PHP-FPM also eventually reaches pm.max_children=10, but increasing PHP workers
does not look like the correct solution because the workers are waiting rather
than doing CPU-intensive work.


MARIADB OBSERVATIONS
--------------------

MariaDB configuration includes:

innodb_doublewrite = ON
innodb_flush_log_at_trx_commit = 1
innodb_flush_method = O_DIRECT
log_bin = ON
sync_binlog = 0

During the issue, SHOW ENGINE INNODB STATUS showed transactions such as:

ACTIVE (PREPARED) 5 sec preparing
ACTIVE (PREPARED) 6 sec preparing
ACTIVE (PREPARED) 7 sec preparing

including INSERTs into oc_filecache.

I also observed:

state: flushing log

There were no InnoDB lock waits.

This made me suspect storage/fsync latency rather than SQL lock contention.


ZFS / STORAGE
-------------

Nextcloud data and MariaDB data are currently stored in the same LXC ZFS
dataset:

storage/subvol-100-disk-0

Relevant properties:

recordsize=128K
sync=standard
logbias=latency
compression=off
atime=on
xattr=sa

There is no SLOG.

I intentionally did NOT change sync=disabled or weaken MariaDB durability,
because I want to identify the actual problem first.


SMART / SATA
------------

SMART looks clean on the SSDs I checked:

SMART overall-health: PASSED
Reallocated NAND blocks = 0
Pending sectors = 0
Uncorrectable = 0
Program failures = 0
Erase failures = 0
UDMA CRC errors = 0
SATA interface downshift = 0

Temperatures are around 34-35 C.

SATA PHY statistics show:

ICRC errors = 0
R_ERR = 0

Only a very small number of historical COMRESET events are present.

dmesg contains no:

hard resetting link
failed command
I/O error
exception

The drives negotiate SATA 6.0 Gb/s and NCQ depth 32.

The Linux Crucial BX500 "nolpm" quirk is applied and the controller reports
max_power.


ZPOOL IOSTAT RESULTS
--------------------

I ran:

zpool iostat -v -l 1 30

under the same heavy Nextcloud synchronization workload.

The interesting part is that the problem appears intermittently on individual
leaf devices.


TEST 1 - D472 ON ata3
---------------------

Mapping at this point:

D45E -> ata1
D472 -> ata3
E315 -> ata6
DE32 -> ata5

One representative sample:

total_wait disk_wait asyncq_wait

D45E (2418E8ABD45E) 339us 339us 20us
D472 (2418E8ABD472) 11s 230ms 12s
E315 (2418E8ABE315) 972us 666us 417us
DE32 (2418E8ABDE32) 330us 330us 35us

A second consecutive sample showed essentially the same thing:

D45E (2418E8ABD45E) 596us 414us 250us
D472 (2418E8ABD472) 11s 224ms 12s
E315 (2418E8ABE315) 259us 231us 39us
DE32 (2418E8ABDE32) 819us 507us 428us

So D472 could have ~11 seconds total_wait / ~12 seconds asyncq_wait while the
actual disk_wait was only around 230 ms.

The other three members were sub-millisecond.


CONTROLLED TEST: MOVE D472 FROM ata3 TO ata2
--------------------------------------------

I shut down the server and changed ONLY the motherboard-side SATA port.

Same SSD.
Same SATA cable.
Same SATA power connector.

D472 was moved:

ata3 -> ata2

After reboot:

D45E -> ata1
D472 -> ata2
E315 -> ata6
DE32 -> ata5

The pool remained ONLINE with zero errors.

Immediately after this change, D472 initially became extremely fast.

For example, in one sample:

D45E = 319us
D472 = 57us
E315 = 311us
DE32 = 307us

So the multi-second latency did not immediately follow D472 to ata2.


BUT THEN E315 BECAME THE SLOW DEVICE
-----------------------------------

During another sample with D472 still on ata2:

D45E = 263us
D472 = 70us
E315 = 720ms
DE32 = 307us

Another sample showed E315 at approximately 1 second while D472 remained
around 98us.

This initially made me suspect ata6 or E315.


CONTROLLED TEST: MOVE E315 FROM ata6 TO ata4
--------------------------------------------

Again I shut down and changed ONLY the motherboard-side SATA connection.

Same E315 SSD.
Same cable.
Same power connection.

E315:

ata6 -> ata4

Current mapping is therefore:

D45E -> ata1
D472 -> ata2
E315 -> ata4
DE32 -> ata5

ata3 and ata6 are currently unused.


TEST 3 - CURRENT CONFIGURATION
------------------------------

After moving E315 to ata4, E315 now generally behaves normally.

However, D472, which has NOT moved and is still on ata2, started showing very
large latency again.

Representative sample:

total_wait disk_wait asyncq_wait

D45E (2418E8ABD45E) 939us 720us 344us
D472 (2418E8ABD472) 1s 806ms 805ms (read)
6s write ~1s 4s
E315 (2418E8ABE315) 1ms 756us 750us
DE32 (2418E8ABDE32) 828us 674us 432us

Other samples from the same run show D472 write total_wait repeatedly between
approximately 1 and 6 seconds while D45E, E315 and DE32 generally remain around
hundreds of microseconds to ~1 ms.


WHY I AM CONFUSED
-----------------

Initially:

E315 on ata3 appeared slow.

After recabling:

D472 on ata3 became extremely slow (up to ~11-12 seconds).

Moving D472 from ata3 to ata2 initially made D472 fast.

Then E315 on ata6 showed intermittent ~300-1000 ms latency.

Moving E315 from ata6 to ata4 made E315 fast.

But now D472, still on ata2, again exhibits 1-6 second latency.

Therefore I no longer think this can be explained simply by one bad SATA port.

At the same time:

- SMART remains clean
- UDMA CRC errors remain zero
- dmesg shows no SATA resets or I/O errors
- ZFS reports no READ/WRITE/CKSUM errors
- the problem is highly intermittent


QUESTIONS
---------

1. Can Crucial BX500 consumer SSDs show this kind of multi-second latency under
ZFS RAIDZ1 due to internal FTL garbage collection, SLC cache exhaustion,
NAND housekeeping, or firmware behaviour?

2. How should I interpret a leaf device showing e.g.:

total_wait = 11 s
disk_wait = 230 ms
asyncq_wait = 12 s

Is most of this latency ZFS queueing behind a temporarily slow device rather
than 11 seconds of actual SATA command execution?

3. Can such a temporary stall on one RAIDZ1 member realistically cause
synchronous MariaDB commits/fsyncs to take 5-10+ seconds?

4. Why would the identity of the visibly slow drive change between tests?
Could this simply be different BX500 drives independently entering internal
garbage collection?

5. Could SATA power delivery cause this kind of latency without generating CRC
errors, link resets or SMART errors?

6. Is there a safe/non-destructive test that can be run against each member of
an active RAIDZ1 pool to distinguish:

- SSD firmware / FTL latency
- SATA controller issue
- SATA cable issue
- power delivery issue
- ZFS queueing effect?

7. Which additional Linux/ZFS statistics would be useful to capture exactly
while one of these stalls occurs?

I would particularly like to avoid randomly replacing hardware or hiding the
problem using sync=disabled / reduced MariaDB durability.

I am looking for a systematic next diagnostic step.

Thanks.

 

[leesteken]

BX500 has QLC and it need to flush it's SLC cache to it. And it cannot cache sync writes. Also, RAIDz1 has low IOPS compared to a ZFS mirror and is not good for VM/CTs. QLC and RAIDz1 and BX500 have been discussed on this forum so many times that I don't feel like doing the search for you, but I sincerely hope that those two term can help you in your search. Anyone who would have searched for this would not have bought those drives and not use RAIDz1 for VM/CTs. It's really that bad and it's no fun convincing people that they wasted money and time.

Answer to question 1: yes, definitely. Answer to question 3: yes, because of the answer to question 1. Question 4: because each drive has to do housekeeping (at potentially different times) in order to get performance back up (to the default, which is not the greatest any way). Question 5: probably not and unrelated. Question 6: probably yes, but I feel like I already know the problems is the BX500.

EDIT: I'm sorry that this first interaction with this forum/Proxmox/ZFS is bad and unfortunate news to you. Volunteers here do actively investigate issues and usually are more friendly.

 

[cupidonihack]

Thank you very much for your answer.
You have honestly saved me a huge amount of time. I was starting to go in circles with SATA ports, cables and individual drives, while the real issue was much more fundamental.


I really appreciate you pointing me in the right direction, especially regarding the BX500/QLC behaviour and RAIDZ1 for this type of workload.


In the future, I will definitely spend more time searching through the forum and existing discussions instead of relying too much on my own intuition when diagnosing this kind of issue.


Thanks again for taking the time to answer.

 

[Impact]

I also have some tips on how to investigate IO stuff in detail.

compression=off
atime=on

I'd recommend you try if compression=lz4 and atime=off (or relatime=on) helps. This is not supposed to fix anything, just take some load off of the disk(s).

GA-Z270XP

Make sure to apply the E1000E offload fix if this uses a E1000E based NIC.

As for the BX500, I made bad experiences with it too many years ago. It caused freezes/hangs on my Windows 10 machine and I promptly sold it.
It hasn't gotten better. Here's a very recent/relevant (~24h) discussion about it. There are QLC drives that perform a lot better. There's just something very wrong with this model it seems like. Always has been.
Also note that CTs don't have the ZVOL "overhead" VMs have so if it performs bad for CTs, VMs will be even more painful.