Repository navigation
Replies: 3 comments
|
Follow-up: I think I've found at least one concrete bug here, and it's reproducible from the code. Unbounded wait in
|
|
Second follow-up: I benchmarked the underlying work to rule out hardware, and the gap is stark. The actual work is fastAll measured inside the running Image path, via the bundled Video path, via the bundled Storage and host: The gapEach unit of real work costs roughly 0.3 to 1.3 seconds. The queue completes roughly one job per minute. That is a 50-100x discrepancy that does not live in the disk, the CPU, the network share, or the iGPU — all of them are idle and fast. For completeness on the queue composition, since large videos were my first suspicion and they are not the problem:
Also worth noting
Happy to run anything else that would help, including a CPU profile or heap snapshot of the microservices process. |
|
Resolved on my end, and it was a configuration hazard rather than an Immich bug. Posting the root cause in case it helps others. Root cause: library watching on a network shareI have an external library of 89,735 assets whose import path is a CIFS/SMB mount, with File watching cannot use native change notifications on a network mount, so it degrades to polling the tree. Against ~90k files over SMB, that produced a metadata storm: Measured SMB operation latency on that mount is 186 ms serially (though ~20 parallel reads complete in 159 ms wall, so it parallelises fine — latency, not bandwidth, is the problem). Node does filesystem work on a small libuv thread pool. The watcher kept those threads permanently blocked: I found 5 threads in uninterruptible Result of disabling
|
| Metric | Before | After |
|---|---|---|
| Thumbnails/min | 0.25 | 50 |
| SMB ops/sec | ~1,700 | 43 |
thumbnailGeneration active |
1 | 3 (the configured concurrency) |
| Backlog | 3,053 | draining |
A 200x improvement, and the configured concurrency of 3 immediately started being honoured — it never was while the pool was starved.
Why it was hard to see
Everything I benchmarked in isolation was fast, which sent me down several wrong paths:
sharp1080px preview: 273 ms;ffmpegsingle-frame extract on queued videos: 643-1301 ms- Local disk: 198 MB/s sequential, 6 ms per fsync'd small file
- Reading one queued source file: 11 ms
- Postgres: 19 connections, idle
- Host
/proc/pressure/{cpu,io,memory}: all ~0 — this is the trap. PSI tracks block-device I/O and does not account for network-filesystem waits, so a machine whose thread pool is entirely blocked on SMB still reports zero I/O pressure and looks idle.
The single-operation benchmarks were fast precisely because they bypassed the saturated thread pool.
This also retroactively explains the UND_ERR_CONNECT_TIMEOUT errors I mentioned in the original post, against both the ML container and Postgres, on network paths that tested clean on demand. A starved thread pool starves everything, not just image processing.
Suggestions
- A warning in the admin UI when
library.watch.enabledis on and an import path is a network mount would have saved a lot of time here. The docs mention watching may not work on network shares, but the failure mode is not "watching doesn't work" — it is "the entire job system silently grinds to a halt", which is much harder to attribute. - The unbounded
waitForQueueCompletionI reported in the comment above is still a genuine bug worth fixing independently. It was not the cause of the throughput problem, but it does permanently blockfacialRecognitionon any instance with a persistent thumbnail backlog, and it busy-waits while holding a worker slot.
Thanks, and apologies for the noise on the throughput half of this.
Uh oh!
There was an error while loading. Please reload this page.
Summary
On 3.2.0, all job queues crawl at roughly 0.3 jobs/min.
thumbnailGenerationhas ~3,000 jobs in:wait,activeis pinned at exactly 1 indefinitely, and the workers are connected but idle. Nothing is resource constrained. Adocker restart immich_serverbriefly produces real concurrency (4 jobs at once, queues visibly draining), which decays back to 1 within about 10-15 minutes and then effectively stops.This looks similar to #24972, but that turned out to be a Docker network name collision where the workers and the jobs were on two different Redis instances. That is not the case here (ruled out below).
Environment
postgres:14-vectorchord0.4.3-pgvectors0.2.0release-openvinoimageSymptoms
Measured over 18 minutes with no config writes and no new uploads:
thumbnailGeneration:waitthumbnailGeneration:activeThe oldest queued job is ~44 hours old. The backlog does drain, roughly 100x slower than it should.
Redis evidence
Sampled three times, 30 seconds apart, all identical:
age> 300s — no churn, so workers are not being recreated in a loopBZPOPMIN— workers are parked waiting for workllen immich_bull:thumbnailGeneration:wait= ~3,005zcard immich_bull:thumbnailGeneration:marker= 1immich_bull:dGh1bWJuYWlsR2VuZXJhdGlvbg==:w:microservicesThe single active job is genuine, not an orphan:
ttl immich_bull:thumbnailGeneration:<id>:lockreturns ~21s and is being renewed, andprocessedOnadvances as jobs rotate.At
IMMICH_LOG_LEVEL=verbose,[Microservices:JobRepository] Waiting for thumbnailGeneration queue to stop...logs once per second, continuously, starting 3 seconds after boot, with no config change having been made. Worth noting for anyone else debugging this: that line is verbose-level, so at default logging it is invisible and its absence means nothing.Ruled out
REDIS_HOSTNAMEresolves to the same instance that holds the:waitlist the workers are attached to.stats in 58 ms and reads in 11 ms./proc/pressure/{cpu,io,memory}all ~0 on the Proxmox host, 55-76% idle, no D-state processes.fetchloop run insideimmich_serverwith Node's own runtime: 15/15 success at 5-12 ms, DNS returns a single A record. Despite that, real jobs still intermittently throwUND_ERR_CONNECT_TIMEOUTagainst both the ML container and Postgres, which is what makes me suspect the microservices event loop is being blocked rather than any network fault.Tried, no effect
job.thumbnailGeneration.concurrencyfrom 1 to 3 viaPUT /api/system-config. It does apply after a container restart (verbose logs show three thumbnails generated within the same second), butactivesettles back to 1 permanently and the rate is unchanged. Only one worker connection ever registers for the queue.clear-failed. Those failures were allwrite CONNECT_TIMEOUT immich_postgres:5432from an unrelated database outage, so they were wreckage rather than cause.softtohardwithactimeo=30. No change. The host kernel log contains zero SMB messages either way.Question
Is there a known condition where the microservices worker registers a single connection for a queue and never scales to the configured concurrency, while the
Waiting for ... queue to stoppoll never completes? I am happy to run further diagnostics or provide a heap/CPU profile from the microservices process.All reactions