Hi folks 👋,
# spicedb
w
Hi folks 👋, Got a bit of a exploratory question in case there's anything obvious as I go down some rabbit holes. Occasional/unusual spikes in latency and am having a bit of trouble in diagnosing the issue. Whether it be infra, poor usage, or something else. Figured maybe check in here if anything stands out to the experts.
Running spicedb on top of PSQL w/ some read replicas and for the most part things are amazing - service handles many requests and w/ low latency. However every once in a while there seems to be periodic spikes where latency spikes >= 5s (our max timeout configured). When we had no timeouts we saw in some instances where requests would go > 9 minutes. The latency/spikes always appeared to originate from the same pod, and go routines would appear to build up on that pod. I think there are some previous threads around deadlocks wrt inflight schema that have similar symptoms but not sure if related at all. Reducing the timeout has seemingly helped mitigate the impact of it, but has made getting a pprof more difficult while its happening, and we still do see the occasional 5 second spikes. During these spikes, there doesnt appear to be any saturation on the psql pool. Minimum or no latency in acquiring the locks. In fact things (logs, cpu, etc) seem to fall off a cliff generally. I do see instances of this occuring when we are running large reconciliation workflows. In some cases we use spicedb as a cache to have rels available in our larger permission graph, and our synchronization involves generating expected relationships from external source and bringing spicedb up to par with those (deleting, touching rels based on set differentiation). Sometimes this can involve touching a lot of relationships, and some of the larger more legacy workflows can involve reading a lot of relations (long lived relation stream). It's unclear to me if the two are related. My impression was that large read rels should have minimal impact when compared to say LR, given it's one query and not an unbounded fan out. But wondering if theres any obvious concerns there or if specific metrics/symptoms to look for? Not super familiar w the read in transaction and if that could come into play here.
j
this implies something is getting wedged in the pod
> During these spikes, there doesnt appear to be any saturation on the psql pool. Minimum or no latency in acquiring the locks. In fact things (logs, cpu, etc) seem to fall off a cliff generally.
dumping the gorountines would be most useful
w
Gotcha, figured pprof probably was needed. Just to sanity check - no obvious concern with long-lived read rel streams? Thank you
j
not that we know of offhand
its certainly possible, as it would hold a DB connection
but I doubt that would hold much more than that
w
Ok great sounds good, wasn't sure if there was anything to be weary of wrt read transaction open for a long time impacting some sort of revision cleanup/count. Agreed the one query probably not a factor here. Thanks again, will spend my time trying to repro and grabbing a pprof
j
let us know
also, make sure you're on latest SpiceDB
we did roll out a preventative change in case certain queries could deadlock
w
Hello folks, Ran into this issue again and was able to get a dump of the go routines throughout the duration of the issue. Here's what appears to be happening: A handful of BulkCheck & LR requests come in (normal traffic, typically handles very quickly and well below our bursty traffic periods). The OptimizedRevision cache expired, one goroutine became the singleflight leader to refresh it. This called the pgxpool.Acquire to get a conn, which triggered the Ping health check. This health check blocked indefinitely blocking other requests, long after client side timeouts etc. Any other dispatches on that spicedb replica hanged behind this leader. The trace shows this was after the acquire, on the receiveMessage - Not Pool exhaustion, which seems supported by metrics. Not super familiar on the connection front but appears the conn was an idle connection in a TCP half-open state. The kernel reported the tcp socket as alive but postgres not responding.
Other replicas were handling some requests fine. I don't see any error logs wrt general database health. This is on latest spicedb btw
j
can you send a stack trace?
20 Views