Is the only way to debug SpiceDB to take CPU profiles? There's nothing similar to an

EXPLAIN ANALYZE

which could show us what SpiceDB is doing with a permissionCheck request?

SpiceDB has no equivalent of EXPLAIN ANALYZE. It does support OpenTelemetry traces per request, which will give you the entire flow through the program handling the request. We run an instance of Jaeger and push into that.

I'm not sure if there's a "zero setup" tool to collect OTEL traces on the fly, though.

I've tried to run Jaeger indeed, but I struggle to make sense of the traces, all I could see was a bunch of

dispatch

calls and couldn't understand what they related to (it's been a few days, I don't remember exactly)

Another (simpler) option is that you can use https://github.com/authzed/zed to make a request with

--debug

and it'll return the dispatch count and cached count. You can see how complex the query is and if it is being cached at all that way. Fundamentally, complex queries are broken down into subproblems and dispatched to nodes that are assigned to store them in their cache. The more complex the query, the more subproblems there are.

The zed usage might be a quick answer to "this request isn't being cached", which could lead to a bug report. We're actually beginning on some work to basically allow all APIs to share the same subproblem cache -- right now it's the case that "checks have their own cache", etc...

I'll take a look at

--debug

thanks! Going back to the original question: is it unreasonable to expect SpiceDB to give a <10ms P50, and <50ms P99 for ~7M relations? I'm sure that's not enough information to give a good answer, but is there any way I can have a rough idea of what I should be expecting from SpiceDB in terms of performances?

That's really hard to say without spending time understanding your schema, distribution of the relationships in that the schema, and what datastore you're using and how it's configured. Are those purely check latencies? If so, yes they are unreasonably high. If that's a combination of all API request types, then the distribution of those could be effecting the numbers (Expand, Lookup are quite expensive operations). If everything is "reasonable" from the perspective of your usage, then it's likely to simply be a lack of optimization in SpiceDB, which we'd need to the traces/profiles to identify in order to identify and create a GitHub issue for.

These are 95% checks, yes. We have a few lookups which might affect the P99, and no expand. > If so, yes they are unreasonably high Thank you, thank's helpful 😄 at least I know there's something to be done I'll dig a bit into traces/profiles then!

You could try the same requests with less relationships in the datastore. If the performance changes between having 100k rows vs 7M, then it's possible the datastore implementation you're using just needs optimization (e.g. a missing index).

I'm having this query which is consuming crazy amounts of CPU on my staging environment (using Postgres, the green bars are CPU and the left part of the graph is "normal" load):

SELECT MIN(id), MAX(id) FROM relation_tuple_transaction WHERE timestamp >= $1

I only have read traffic, no write. When it starts going into this pattern, all checks take multiple minutes (and might be timeout-ing). That looks like a bug in spicedb?

This is the

EXPLAIN ANALYZE

for it:

Result  (cost=1.07..1.08 rows=1 width=16) (actual time=28103.240..28103.242 rows=1 loops=1)
  InitPlan 1 (returns $0)
    ->  Limit  (cost=0.43..0.54 rows=1 width=8) (actual time=28103.219..28103.220 rows=1 loops=1)
          ->  Index Scan using pk_rttx on relation_tuple_transaction  (cost=0.43..193195.54 rows=1823603 width=8) (actual time=28103.218..28103.218 rows=1 loops=1)
                Index Cond: (id IS NOT NULL)
                Filter: ("timestamp" >= '2022-03-15 00:00:00'::timestamp without time zone)
                Rows Removed by Filter: 548517
  InitPlan 2 (returns $1)
    ->  Limit  (cost=0.43..0.54 rows=1 width=8) (actual time=0.016..0.016 rows=1 loops=1)
          ->  Index Scan Backward using pk_rttx on relation_tuple_transaction relation_tuple_transaction_1  (cost=0.43..193195.54 rows=1823603 width=8) (actual time=0.015..0.015 rows=1 loops=1)
                Index Cond: (id IS NOT NULL)
                Filter: ("timestamp" >= '2022-03-15 00:00:00'::timestamp without time zone)
Planning time: 0.375 ms
Execution time: 28103.275 ms

what value do you have set for the

datastore-revision-fuzzing-duration

flag?

or are you not setting it at all? (default is 5s)

I didn't set it

what version of spicedb are you using? there should be an index on the timestamp field

ix_relation_tuple_transaction_by_timestamp

but from the explain output it doesn't look like that's being used

(it was added in https://github.com/authzed/spicedb/pull/211)

I'm using

1.4.0

. The index does exist, but indeed isn't used: PG has to choose whether to use the index on

id

(to speed up one of

MIN

or

MAX

), or the index on

timestamp

to speed up the filtering. Adding this index seems to solve it, at least in the query plan:

CREATE INDEX CONCURRENTLY rttx_timestamp_id ON relation_tuple_transaction(id, "timestamp");

i don't think the index on

id

helps with

MIN(id)

or

MAX(id)

with a where clause

not sure what the thought process is there....

seems like it's setting you up for table scan always

can you try removing that index and running

ANALYZE

on the db?

maybe it assumes the timestamp index will be useless

> can you try removing that index and running ANALYZE on the db? on it > maybe it assumes the timestamp index will be useless It might not be wrong, a lot of my data has been created in a short amount of time (~3 days), but I don't really know the context of this query

Same thing without the index, after an ANALYZE

timestamps should always be very useful, the query in question is trying to find the range of timestamps that are ok to use as the execution timestamp when you don't specify a strict-er consistency level, and using the timestamp index should eliminate all but the last

5s

of data

OK... I've been hit by a late breaking requirement that permissions have to be a function of the subject and azp claims in the JWT token. For example, normally if the subject is an investor, they don't have read access to deals they aren't invested in. But if the authorized party is a specific type of widget developed by us and administered by a client organization that owns that deal, the user does have read access. Any tips on modeling that without rewriting my model from scratch? I'm mostly thinking that that azp goes into userset namespace and the client has to make 2 spicedb calls; if either call returns

PERMISSIONSHIP_HAS_PERMISSION

the API proceeds.

Question: when does the gRPC API return

PERMISSIONSHIP_UNSPECIFIED

?

never; we just use it as a zero-value

I was hoping to use it as a "soft no" in a multi-subject environment