Large uploads stuck in "processing" forever on slow-fsync storage (ZFS without SLOG) embedded NATS drops the finalize event #3027

Summary:

Uploading a large file finishes transferring and then the file stays in "processing" forever and never becomes accessible. The desktop client just hangs on it. The bytes are written to disk correctly; only the postprocessing finalize never completes.

We traced it to the embedded NATS JetStream store. During finalization of a large file the fsync load saturates the storage's synchronous-write path, the postprocessing and search consumers miss their NATS deadlines, the finalize event is dropped, and the upload session is left at processing=true with no automatic recovery.

We found several related reports (#648, #529, #1853, owncloud/ocis#10259) but none of them pinned down the root cause or gave a fix for the slow-fsync-storage case, so we are opening a new one with measurements.

Environment

• OpenCloud 7.1.0 (rolling), reva v2.46.2
• Single binary, rootful podman + podman-compose, Fedora 44 VM (QEMU/KVM guest), 4 vCPU, 4.8 GiB RAM
• Default posix/decomposed storage, async uploads on (default), no antivirus or extra postprocessing steps configured
• Storage: guest XFS on a virtual disk, backed on the host by ZFS (raidz2 of 4 consumer SATA SSDs, no SLOG / no separate ZIL device)

This is a normal self-hosting setup. The same disks ran Nextcloud before without this problem.

Steps to reproduce

1. Upload a file of roughly 3 GB or larger with the desktop client (we used a 3.4 GB ISO).
2. All bytes transfer and land on disk (offset == size in the upload session).
3. The session goes to processing=true and never leaves it. The file is invisible and cannot be accessed or deleted. The client hangs.

Log during finalization, repeating every 5 seconds:

service:"postprocessing" error:"context deadline exceeded" message:"failed to get consumer"
service:"search" error:"context deadline exceeded" message:"failed to get consumer"

Earlier, while the upload was still running:

service:"nats" Internal subscription on "$JS.API.CONSUMER.INFO.main-queue.postprocessing-pull" took too long: 2m53s

Diagnosis (measured)

While the upload finalizes the box is fully IO-bound, not CPU- or memory-bound:

io_pressure (some, avg10) ~99.7 %
cpu_pressure (some, avg10) ~0.2 %
MemAvailable ~3.4 GiB, swap 0

The blocked kernel threads are all XFS journal threads (xlog_cil_order_write, xlog_state_get_iclog_space, xfs flush). The opencloud process shows ~0 KB/s during the stall, so it is the writeback/fsync layer, not the app moving bulk data.

Storage characterization from inside the guest:

async write (dd oflag=direct, 1M blocks): 376 MB/s
sync write (dd oflag=dsync, 4k blocks): 0.89 MB/s
fsync latency (4k write + fsync, idle): ~4 ms median (~250 fsync/s)

A pure bulk write of several GB caused only ~21 % io_pressure and zero NATS stalls. A bulk write running at the same time as fsync probes barely changed fsync latency. So this is not bandwidth, not RAM, not CPU, and not bulk-vs-sync contention. It is the number of fsyncs the finalization issues against storage where each fsync is expensive. ZFS commits synchronous writes through the ZIL, and on consumer SSDs without a SLOG that is a cache-flush round trip per fsync.

The embedded NATS JetStream store lives on this same disk and fsyncs per message. During finalization the combined metadata and event fsync load saturates the sync path, JetStream cannot service its consumers in time, the consumers hit their context deadline, and the finalize event is lost. The upload then sits in processing forever and nothing recovers it.

Manual recovery works, since the blob is intact:

opencloud postprocessing resume -u -r

Workaround we applied

We moved the JetStream store onto tmpfs so its fsyncs become memory operations:

yaml
services:
opencloud:
environment:
NATS_NATS_STORE_DIR: /run/opencloud-nats
tmpfs:
- /run/opencloud-nats:rw,size=1g,mode=1777

Same 3.4 GB upload after the change:

io_pressure during finalization ~1 % (was 99.7 %)
consumer-deadline errors 0 (was a steady stream)
upload completes ~30 s (was: never)

This one change took io_pressure from 99.7 % to ~1 %, which means the JetStream fsyncs were the dominant IO source during finalization, not the decomposedfs xattr writes.

We also checked what an ephemeral store costs. With an empty store at start the id-cache (KV_ids-storage-users) rebuilds on demand from the filesystem (PROPFIND of the root and of deep nodes both return 207 from a cold start), and app tokens are kept on disk in storage-system metadata, not in NATS, so they survive a restart. The only thing lost on restart is KV_activitylog.

Suggested permanent fix

Two parts. The second one is the important one.

1. Make the embedded JetStream store durability/location a proper option for the single-node case, or default the embedded server to a memory/ephemeral store. The streams are a cache plus a transient bus that rebuild from the filesystem, so persisting them with per-message fsync on the same disk as the bulk data is what creates the failure. NATS_NATS_STORE_DIR already lets an admin point the store at tmpfs, but this is not documented as a mitigation and is not obvious.

2. Do not let a slow or stalled event bus turn into permanent data-unavailability. If the postprocessing consumer cannot be reached in time it should keep retrying and reconnecting instead of dropping the finalize, and uploads left in processing should be auto-resumed (on a timer and/or on restart) rather than waiting forever. Right now "storage was slow for a couple of minutes" becomes "this upload is broken until an admin runs a CLI command." Reducing fsync amplification during finalization (batching metadata commits) would also help.

At a minimum, documenting the fsync sensitivity and the NATS_NATS_STORE_DIR=tmpfs mitigation for single-node / consumer-hardware setups would save people a long debugging session.

Related issues

#648, #529, #1853, owncloud/ocis#10259. They describe the same "stuck in processing / NATS dies under upload" symptom across versions 2.0 through 3.7, but we could not find a definitive root cause or a fix for the slow-fsync-storage case in any of them, which is why we are filing this one with the measurements above.