Push server becomes permanently unresponsive after hours-to-days: DashMap guard held across .await in get_storage_mapping

[dispather]

Summary

The push server stops serving all HTTP (both the main port and --metrics-port) after anywhere from ~15 hours to ~10 days of uptime. The process stays alive: CPU 0%, RSS flat (~6 MB), no OOM, no panic, no log output. Only a restart recovers it.

I believe the cause is in src/storage_mapping.rs: a DashMap shard read guard is held across an .await of a database round-trip, which lets any task that needs the write lock on that shard block a Tokio worker thread. Once enough workers are blocked, nothing reaches the park point, the I/O driver is never polled, the in-flight DB response is never delivered, and the guard is never released — a self-sustaining deadlock.

This is present in 1.3.3, 1.3.4, 1.3.5 and current master, and absent in 1.3.2.

Environment

• notify_push 1.3.5 (also observed on 1.3.3 and 1.3.4)
• Nextcloud 34.0.2, PHP 8.5.9, official nextcloud Docker image
• MariaDB 10.6, Redis 8.x, all in Docker on Linux x86_64
• ~20 logical CPUs → 21 Tokio threads
• Single active user, 2–4 concurrent websocket connections (small instance)

Symptoms

• GET /test/cookie times out. GET /metrics on the separate metrics port times out at the same moment.
• Process alive, RestartCount=0, OOMKilled=false, CPU 0.00%, memory flat.
• No log line is emitted from the moment of the freeze onward — the log simply stops.
• The Redis subscriber connection stays established on the Redis side (CLIENT LIST still shows it, sub=11, obl=0 oll=0 omem=0), with age equal to the container uptime — it never disconnected or reconnected. So this is not a dropped-Redis-link problem.
• CLOSE_WAIT sockets accumulate after the freeze (peers hang up, the process never calls close()).

The decisive observation: no thread is polling the reactor

Over 8 captures taken automatically at freeze time (5 valid; 3 turned out to be snapshots of an already-restarted container), thread wchan state was:

state	valid freeze captures (n=5)	freshly-restarted healthy captures (n=3)
do_epoll_wait	0 threads	exactly 1 thread
futex_wait	all threads (21/21, 21/21, 24/24, 21/21, 21/21)	all remaining threads

A healthy idle multi-thread runtime keeps exactly one worker blocked in epoll_wait holding the I/O driver. During the freeze that thread does not exist — nothing will ever deliver an I/O readiness event again.

For comparison, here is a healthy process sampled via /proc/<pid>/task/*/syscall (202 = futex, 281 = epoll_wait):

1065996  tokio-rt-worker   202 0x7f..53af38 ...
1065997  tokio-rt-worker   202 0x7f..535788 ...
...
1066013  tokio-rt-worker   281 0x3 0x7f..541230 ...    <-- the single epoll_wait
...
# all 20 futex waiters are on distinct addresses (per-worker park futexes)

Onset is instantaneous, not gradual

A 30-minute-interval trend log (2471 samples) shows file descriptors, connection counts and event counts completely flat right up to the last healthy sample. In the tightest case the server passed both the health endpoint and the metrics endpoint at 07:00:00 and was fully unresponsive at 07:01:07 — 67 seconds. There is no resource-exhaustion ramp.

Suspected cause

src/storage_mapping.rs (v1.3.5, and identical on master):

async fn get_storage_mapping(&self, storage: u32)
    -> Result<Ref<'_, u32, CachedAccess>, DatabaseError>
{
    if let Some(cached) = self.cache.get(&storage) {   // (1) shard READ guard
        if cached.is_valid() {
            return Ok(cached);
        }

        cached.prepare_update(true);
        let users = self
            .load_storage_mapping(storage)
            .await                                     // (2) awaited while (1) is still held
            .inspect_err(|_| cached.prepare_update(false))?;

        drop(cached);                                  // (3) released only after the await
        let cached = CachedAccess::new(users);
        self.cache.insert(storage, cached);            // (4) shard WRITE lock
        return Ok(self.cache.get(&storage).unwrap());
    }

    let users = self.load_storage_mapping(storage).await?;
    self.cache.insert(storage, CachedAccess::new(users));   // (4') shard WRITE lock
    Ok(self.cache.get(&storage).unwrap())
}

dashmap::mapref::one::Ref is an RwLock read guard on the shard. Holding it across (2) means:

1. Task A holds the shard read lock for the whole DB round-trip.
2. Task B reaching (4)/(4') on the same shard waits for the write lock. dashmap 6.x uses its own RawRwLock built on lock_api + parking_lot_core, so this is a blocking, thread-parking wait, not an async one — it takes the entire Tokio worker thread out of service.
3. With enough such blocked workers, no worker reaches its park point, so the I/O driver is never polled.
4. A's DB response is therefore never delivered; A never completes; the guard is never dropped. Steps 2–4 become permanent.

Possible amplifier (not yet confirmed — see caveat below). load_storage_mapping calls fetch_all(&self.connection), which includes waiting for a pool connection. With sqlx 0.9.0 (the version in Cargo.toml), PoolOptions::new() gives max_connections: 10, acquire_timeout: 30s, fair: true; notify_push calls AnyPool::connect_with(options) and never overrides PoolOptions, so those defaults apply. Meanwhile src/lib.rs:

while let Some(event) = event_stream.next().await {
    match event {
        Ok(event) => { ...; tokio::spawn(handle(event)); }   // unbounded spawn per event

spawns an unbounded task per Redis event, and handle_event → get_users_for_storage_path → get_storage_mapping. During a burst (e.g. a desktop client syncing many files) the pool could saturate, holding the guard in (1)–(2) for seconds rather than milliseconds — long enough for many tasks to pile up on the shard write lock.

Caveat, stated because it cuts against me: sqlx 0.9 logs a WARN once an acquire exceeds acquire_slow_threshold (2 s), and sqlx log records do reach this service's log output (one of my captures contains INFO [sqlx_core::pool::inner] ... ping on idle connection returned error). I have not observed any slow-acquire or pool timed out warning before a freeze. My log capture so far is only docker logs --tail 20, so this is weak evidence rather than a refutation — I've widened the capture and will report back. If the pool never saturates, the deadlock in (1)–(4) still stands but requires a much narrower race window than I describe here.

When it was introduced

v1.3.2 did not hold the guard across the await — Option::filter consumed and dropped the Ref before the else branch:

// v1.3.2
if let Some(cached) = self.cache.get(&storage).filter(|cached| cached.is_valid()) {
    Ok(cached)
} else {
    let users = self.load_storage_mapping(storage).await?;   // no guard held here
    self.cache.insert(storage, CachedAccess::new(users));
    Ok(self.cache.get(&storage).unwrap())
}

v1.3.3 restructured this to add the updating flag (release note: "fix: avoid too many concurrent db queries when cache becomes invalid"), binding the guard to a named variable that outlives the .await. v1.3.4, v1.3.5 and master are unchanged from v1.3.3 in this function.

Suggested fix

Drop the guard before awaiting:

async fn get_storage_mapping(&self, storage: u32)
    -> Result<Ref<'_, u32, CachedAccess>, DatabaseError>
{
    if let Some(cached) = self.cache.get(&storage) {
        if cached.is_valid() {
            return Ok(cached);
        }
        cached.prepare_update(true);
    }   // guard dropped here

    match self.load_storage_mapping(storage).await {
        Ok(users) => {
            self.cache.insert(storage, CachedAccess::new(users));
            Ok(self.cache.get(&storage).unwrap())
        }
        Err(e) => {
            if let Some(cached) = self.cache.get(&storage) {
                cached.prepare_update(false);
            }
            Err(e)
        }
    }
}

Two smaller points in the same area:

• prepare_update is an unconditional store, not a compare_exchange, so several tasks can still each decide to refresh and each issue a query — the stampede it was meant to prevent is only partly prevented.
• Bounding the per-event tokio::spawn (e.g. a semaphore sized near the DB pool) would keep a burst from saturating the pool in the first place.

This is implemented and submitted as a pull request (linked below) — the shape above is the idea; the PR has the actual diff, and cargo check --all-targets, cargo clippy --all-targets, cargo test --lib and cargo build all pass on rustc 1.94.0.

Since both shapes compile, I also checked separately that the change does what I claim. Reducing each shape to a DashMap plus a suspended future:

before   same-shard insert blocked for 301.2ms   (guard held across the await)
after    same-shard insert took       13.6µs     (guard released before the await)

and, with the runtime's workers occupied by same-shard writers, the original shape is not merely slow but self-sustaining — the task that would wake the guard holder never gets scheduled:

before   1 worker  + 4  concurrent same-shard writers -> no progress within 3s
before   2 workers + 8  concurrent same-shard writers -> no progress within 3s
before   4 workers + 16 concurrent same-shard writers -> no progress within 3s
after    4 workers + 16 concurrent same-shard writers -> completes normally

So the number of blocked tasks needed is worker_threads, not something exotic.

What I have not proven

wchan/futex tells me the threads are blocked in a futex, not which lock. Unwinding the release binary from outside the container did not produce usable frames (static-PIE, no frame pointers; eu-stack and gdb --sysroot both stop at the syscall stub). I have instrumented the next occurrence to dump /proc/<pid>/task/*/syscall and cluster the futex addresses: if several threads share one address it is lock contention; if all addresses are distinct while epoll_wait is still absent, the cause is elsewhere and this analysis is wrong. I will follow up with that data.

Happy to run any specific diagnostic you'd like on the next occurrence — it reproduces on its own every few days.

[sushifrick]

I would like to acknowledge this problem. In our main instance with ~3000 concurrent users, the process (running 1.3.5) became unresponsive nearly daily. I implemented a nightly restart of the service, that helped a bit. But Today the process became unresponsive again, only a couple of hours after the nightly restart.

The analysis of the problem in detail by @dispather is great, although it goes way over my head. I hope the devs can make more sense of it and look into the proposed fix soon.

[dispather]

@sushifrick Thank you — that's a valuable data point, and your instance may be able to settle the open question far faster than mine can.

Why the scale difference matters. My instance hangs every 4–16 days; yours does it nearly daily at ~3000 concurrent users. That direction is what the hypothesis predicts: the deadlock needs two tasks touching the same DashMap shard concurrently — one get_storage_mapping holding its read guard across the DB .await, one insert taking the write side. More concurrent users → more shard collisions → shorter time-to-hang. Consistent, not proof.

What would actually settle it. Before my last hang I pre-registered a discriminator: in every valid hang capture I have, zero threads sit in do_epoll_wait, while a healthy process has exactly one — i.e. nobody is driving the tokio reactor. If you can grab this while the process is hung, before restarting it:

# while hung, BEFORE the restart
for t in /proc/<PID>/task/*; do printf '%s ' "$(basename "$t")"; cat "$t/wchan"; echo; done

and then run it once more after the restart, while it is healthy.

Please paste the raw output rather than a count — and please include both samples. There is a trap here that cost me a couple of hours today.

/proc/<pid>/task/*/wchan only resolves symbol names for a reader holding PTRACE_MODE_READ on the target. Without that privilege every line reads 0 — which is indistinguishable from "no thread is in epoll". In other words, an under-privileged read looks exactly like a confirmation of my hypothesis while being a permissions artifact. So:

• run it as root, or as the same uid the push process runs under (under Docker, docker exec into the container works if the exec uid matches the process uid — check with id);
• the healthy-state sample is your control. If it shows exactly one do_epoll_wait, your reads are privileged enough and the hung sample can be trusted. If both samples are all-0, discard them.

My own dataset only survived scrutiny because it happened to contain that control. 5 genuine hang captures show futex_wait on every thread and no epoll thread; 3 further captures that my watchdog took a few seconds after an automatic restart show futex_wait×21 + do_epoll_wait×1. Same script, same privileges, different result — so the zero is a real state, not an artifact.

One caution when reading it: a large number of threads in futex_wait is not by itself a signal. A healthy process here shows 20 of them. The distinguishing fact is only the missing epoll thread.

If you can additionally capture cat /proc/<PID>/task/*/syscall (this one does need root) at hang time, the futex uaddr values would separate the two remaining possibilities:

• many threads blocked on the same uaddr → lock contention, supports this hypothesis;
• all uaddrs distinct with no epoll thread → the reactor was lost some other way, refutes it.

No pressure at all if that is too invasive on a production box — the report on its own is already useful.

For what it's worth, the patch in #740 is independent of which hypothesis wins: holding a DashMap guard across an .await is a defect on its own terms (I measured a same-shard insert blocked for 301 ms against 13.6 µs after the change, and with as many concurrent writers as worker threads the original never recovered). If it turns out my hang has a different cause, that would mean the patch is incomplete, not wrong.