Skip to content

Commit a1a9509

Browse files
authored
feat: add metric counting % of HAS_PERMISSION results (#3240)
1 parent 398abc0 commit a1a9509

12 files changed

Lines changed: 471 additions & 40 deletions

File tree

CHANGELOG.md

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,9 @@ All notable changes to this project will be documented in this file.
44
The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/).
55

66
## [Unreleased]
7+
### Added
8+
- New metric `check_permissionship_total` for CheckPermission and CheckBulkPermissions that counts the number of requests that returned HAS_PERMISSION. Also, `write_relationships_updates` also includes BulkImport calls (https://github.com/authzed/spicedb/pull/3240)
9+
710
### Changed
811
- Schema: reads inside write transactions now use a cheap hash-only lookup (`schema_revision`) to check the cache before loading the full schema blob, reducing DB round-trips on cache hits (https://github.com/authzed/spicedb/pull/3160)
912
- Updated the Prometheus buckets for `grpc_server_handling_seconds` and `spicedb_datastore_query_latency` to be able to correlate them (https://github.com/authzed/spicedb/pull/3188)

development/grafana/dashboards/dashboard.json

Lines changed: 118 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -513,7 +513,7 @@
513513
},
514514
"editorMode": "code",
515515
"expr": "histogram_quantile(0.99, sum(rate(spicedb_perf_insights_api_shape_latency_seconds{job=\"spicedb\",instance=~\"$instance\",resource_type!=\"\"}[$__rate_interval])) by (api_kind, resource_type, resource_relation, subject_type, subject_relation))",
516-
"legendFormat": "{{api_kind}} {{resource_type}}:{{resource_relation}} {{subject_type}}#{{subject_relation}}",
516+
"legendFormat": "{{api_kind}} {{resource_type}}:{{resource_relation}} \u2192 {{subject_type}}#{{subject_relation}}",
517517
"range": true,
518518
"refId": "A"
519519
}
@@ -526,7 +526,7 @@
526526
"type": "prometheus",
527527
"uid": "prometheus"
528528
},
529-
"description": "Average logical checks per second across all APIs. Counts each item within a CheckBulk and each result returned from LookupResources/LookupSubjects separately. This measures workload intensity independently of gRPC RPS a single LookupResources call can account for hundreds of logical checks.",
529+
"description": "Average logical checks per second across all APIs. Counts each item within a CheckBulk and each result returned from LookupResources/LookupSubjects separately. This measures workload intensity independently of gRPC RPS \u2014 a single LookupResources call can account for hundreds of logical checks.",
530530
"fieldConfig": {
531531
"defaults": {
532532
"color": {
@@ -700,6 +700,101 @@
700700
"title": "Avg Consistency Mode Distribution",
701701
"type": "timeseries"
702702
},
703+
{
704+
"datasource": {
705+
"type": "prometheus",
706+
"uid": "prometheus"
707+
},
708+
"description": "Percentage of check results (CheckPermission and CheckBulkPermissions, each bulk item counted individually) that return HAS_PERMISSION, aggregated across all instances. CONDITIONAL_PERMISSION and NO_PERMISSION results count toward the denominator. Only successful checks are counted; errored checks are excluded.",
709+
"fieldConfig": {
710+
"defaults": {
711+
"color": {
712+
"mode": "palette-classic"
713+
},
714+
"custom": {
715+
"axisCenteredZero": false,
716+
"axisColorMode": "text",
717+
"axisLabel": "",
718+
"axisPlacement": "auto",
719+
"barAlignment": 0,
720+
"drawStyle": "line",
721+
"fillOpacity": 10,
722+
"gradientMode": "none",
723+
"hideFrom": {
724+
"legend": false,
725+
"tooltip": false,
726+
"viz": false
727+
},
728+
"lineInterpolation": "linear",
729+
"lineWidth": 1,
730+
"pointSize": 5,
731+
"scaleDistribution": {
732+
"type": "linear"
733+
},
734+
"showPoints": "auto",
735+
"spanNulls": false,
736+
"stacking": {
737+
"group": "A",
738+
"mode": "none"
739+
},
740+
"thresholdsStyle": {
741+
"mode": "off"
742+
}
743+
},
744+
"mappings": [],
745+
"max": 100,
746+
"min": 0,
747+
"thresholds": {
748+
"mode": "absolute",
749+
"steps": [
750+
{
751+
"color": "green",
752+
"value": null
753+
}
754+
]
755+
},
756+
"unit": "percent"
757+
},
758+
"overrides": []
759+
},
760+
"gridPos": {
761+
"h": 8,
762+
"w": 24,
763+
"x": 0,
764+
"y": 39
765+
},
766+
"id": 81,
767+
"options": {
768+
"legend": {
769+
"calcs": [
770+
"mean",
771+
"lastNotNull"
772+
],
773+
"displayMode": "table",
774+
"placement": "bottom",
775+
"showLegend": true
776+
},
777+
"tooltip": {
778+
"mode": "multi",
779+
"sort": "desc"
780+
}
781+
},
782+
"targets": [
783+
{
784+
"datasource": {
785+
"type": "prometheus",
786+
"uid": "prometheus"
787+
},
788+
"editorMode": "code",
789+
"expr": "100 *\nsum by(method) (rate(spicedb_v1_check_permissionship_total{job=\"spicedb\",permissionship=\"HAS_PERMISSION\"}[$__rate_interval]))\n/\n(sum by(method) (rate(spicedb_v1_check_permissionship_total{job=\"spicedb\"}[$__rate_interval])) > 0)",
790+
"legendFormat": "HAS_PERMISSION % ({{method}})",
791+
"range": true,
792+
"refId": "A"
793+
}
794+
],
795+
"title": "Check HAS_PERMISSION Ratio",
796+
"type": "timeseries"
797+
},
703798
{
704799
"datasource": {
705800
"type": "prometheus",
@@ -762,7 +857,7 @@
762857
"h": 8,
763858
"w": 24,
764859
"x": 0,
765-
"y": 39
860+
"y": 47
766861
},
767862
"id": 45,
768863
"options": {
@@ -855,7 +950,7 @@
855950
"h": 8,
856951
"w": 24,
857952
"x": 0,
858-
"y": 47
953+
"y": 55
859954
},
860955
"id": 46,
861956
"options": {
@@ -892,7 +987,7 @@
892987
"h": 1,
893988
"w": 24,
894989
"x": 0,
895-
"y": 55
990+
"y": 63
896991
},
897992
"id": 70,
898993
"panels": [
@@ -901,7 +996,7 @@
901996
"type": "prometheus",
902997
"uid": "prometheus"
903998
},
904-
"description": "Cache hit ratio for each dispatch operation type, split by dispatcher layer. High ratios (>80%) for check operations are expected under steady workloads. Low ratios indicate cache churn, highly diverse queries, or an undersized cache. Per-instance variance is expected and normal: the dispatch cache is local in-process (not shared across instances), and every cache key is scoped to a specific revision so any write that advances the revision causes all instances to miss on subsequent requests until they re-warm at the new revision. Instances that recently restarted or received the first requests after a revision bump will show lower ratios than instances with a warm cache at a stable revision.",
999+
"description": "Cache hit ratio for each dispatch operation type, split by dispatcher layer. High ratios (>80%) for check operations are expected under steady workloads. Low ratios indicate cache churn, highly diverse queries, or an undersized cache. Per-instance variance is expected and normal: the dispatch cache is local in-process (not shared across instances), and every cache key is scoped to a specific revision \u2014 so any write that advances the revision causes all instances to miss on subsequent requests until they re-warm at the new revision. Instances that recently restarted or received the first requests after a revision bump will show lower ratios than instances with a warm cache at a stable revision.",
9051000
"fieldConfig": {
9061001
"defaults": {
9071002
"color": {
@@ -1050,7 +1145,7 @@
10501145
"type": "prometheus",
10511146
"uid": "prometheus"
10521147
},
1053-
"description": "p99 of the number of chunks dispatched per Check request. Each chunk holds up to dispatch-chunk-size subjects (default: 100) and is processed in parallel. A value of N means the check fanned out to N×chunk-size subjects of the same type. Consistently high values indicate broad permission checks with large subject fan-out.",
1148+
"description": "p99 of the number of chunks dispatched per Check request. Each chunk holds up to dispatch-chunk-size subjects (default: 100) and is processed in parallel. A value of N means the check fanned out to N\u00d7chunk-size subjects of the same type. Consistently high values indicate broad permission checks with large subject fan-out.",
10541149
"fieldConfig": {
10551150
"defaults": {
10561151
"color": {
@@ -1155,7 +1250,7 @@
11551250
"h": 1,
11561251
"w": 24,
11571252
"x": 0,
1158-
"y": 56
1253+
"y": 64
11591254
},
11601255
"id": 42,
11611256
"panels": [
@@ -1164,7 +1259,7 @@
11641259
"type": "prometheus",
11651260
"uid": "prometheus"
11661261
},
1167-
"description": "Hit ratio per cache, from spicedb_cache_hits_total and spicedb_cache_misses_total. Three caches emit metrics:\n\n namespace (32MiB): caches parsed namespace and caveat definitions. Should be near 100% schemas change infrequently. A sustained drop means schema writes are frequent or the cache is undersized.\n\n dispatch (default: 30% of free memory): caches sub-problem results for dispatches this node sends out (outbound). Revision-scoped every write that advances the revision invalidates prior entries.\n\n cluster_dispatch (default: 70% of free memory): caches sub-problem results for dispatches this node receives from other nodes (inbound). Also revision-scoped. Larger by default because in a multi-node cluster this node handles a proportionally larger share of inbound sub-problems.",
1262+
"description": "Hit ratio per cache, from spicedb_cache_hits_total and spicedb_cache_misses_total. Three caches emit metrics:\n\n\u2022 namespace (32MiB): caches parsed namespace and caveat definitions. Should be near 100% \u2014 schemas change infrequently. A sustained drop means schema writes are frequent or the cache is undersized.\n\n\u2022 dispatch (default: 30% of free memory): caches sub-problem results for dispatches this node sends out (outbound). Revision-scoped \u2014 every write that advances the revision invalidates prior entries.\n\n\u2022 cluster_dispatch (default: 70% of free memory): caches sub-problem results for dispatches this node receives from other nodes (inbound). Also revision-scoped. Larger by default because in a multi-node cluster this node handles a proportionally larger share of inbound sub-problems.",
11681263
"fieldConfig": {
11691264
"defaults": {
11701265
"color": {
@@ -1295,7 +1390,7 @@
12951390
"h": 1,
12961391
"w": 24,
12971392
"x": 0,
1298-
"y": 57
1393+
"y": 65
12991394
},
13001395
"id": 30,
13011396
"panels": [
@@ -1583,7 +1678,7 @@
15831678
"type": "prometheus",
15841679
"uid": "prometheus"
15851680
},
1586-
"description": "p99 of the number of relationship updates per WriteRelationships call, split by update kind (CREATE, TOUCH, DELETE). Large batches (>1000) can cause write amplification and lock contention in the datastore.",
1681+
"description": "p99 of the number of relationship updates per write call, split by update kind (CREATE, TOUCH, DELETE). Includes WriteRelationships calls and bulk imports (ImportBulkRelationships and the deprecated BulkImportRelationships), whose imported relationships are counted as CREATE. Large batches (>1000) can cause write amplification and lock contention in the datastore. Uses the metric's native histogram representation, which has no bucket cap, so large bulk imports report accurate percentiles.",
15871682
"fieldConfig": {
15881683
"defaults": {
15891684
"color": {
@@ -1658,13 +1753,13 @@
16581753
"uid": "prometheus"
16591754
},
16601755
"editorMode": "code",
1661-
"expr": "histogram_quantile(0.99, rate(spicedb_v1_write_relationships_updates_bucket{job=\"spicedb\",instance=~\"$instance\"}[$__rate_interval]))",
1756+
"expr": "histogram_quantile(0.99, rate(spicedb_v1_write_relationships_updates{job=\"spicedb\",instance=~\"$instance\"}[$__rate_interval]))",
16621757
"legendFormat": "{{kind}} ({{instance}})",
16631758
"range": true,
16641759
"refId": "A"
16651760
}
16661761
],
1667-
"title": "p99 WriteRelationships Batch Size - $instance",
1762+
"title": "p99 Write Batch Size (WriteRelationships + bulk imports) - $instance",
16681763
"type": "timeseries"
16691764
}
16701765
],
@@ -1677,7 +1772,7 @@
16771772
"h": 1,
16781773
"w": 24,
16791774
"x": 0,
1680-
"y": 58
1775+
"y": 66
16811776
},
16821777
"id": 65,
16831778
"panels": [
@@ -1828,7 +1923,7 @@
18281923
},
18291924
"editorMode": "code",
18301925
"expr": "crdb_connections_per_node{job=\"spicedb\",instance=~\"$instance\"}",
1831-
"legendFormat": "{{pool}} node {{node_id}} ({{instance}})",
1926+
"legendFormat": "{{pool}} \u2192 node {{node_id}} ({{instance}})",
18321927
"range": true,
18331928
"refId": "A"
18341929
}
@@ -2067,7 +2162,7 @@
20672162
"h": 1,
20682163
"w": 24,
20692164
"x": 0,
2070-
"y": 59
2165+
"y": 67
20712166
},
20722167
"id": 48,
20732168
"panels": [
@@ -2983,7 +3078,7 @@
29833078
"h": 1,
29843079
"w": 24,
29853080
"x": 0,
2986-
"y": 60
3081+
"y": 68
29873082
},
29883083
"id": 51,
29893084
"panels": [
@@ -3256,7 +3351,7 @@
32563351
"h": 1,
32573352
"w": 24,
32583353
"x": 0,
3259-
"y": 61
3354+
"y": 69
32603355
},
32613356
"id": 54,
32623357
"panels": [
@@ -3265,7 +3360,7 @@
32653360
"type": "prometheus",
32663361
"uid": "prometheus"
32673362
},
3268-
"description": "Ratios (0–1) reflecting Spanner session pool health. max_allowed_sessions_ratio approaching 1 means the pool is near its configured limit. max_in_use_sessions_ratio shows peak concurrent session usage. num_sessions_in_pool_ratio and open_session_count_ratio show current utilization.",
3363+
"description": "Ratios (0\u20131) reflecting Spanner session pool health. max_allowed_sessions_ratio approaching 1 means the pool is near its configured limit. max_in_use_sessions_ratio shows peak concurrent session usage. num_sessions_in_pool_ratio and open_session_count_ratio show current utilization.",
32693364
"fieldConfig": {
32703365
"defaults": {
32713366
"color": {
@@ -3389,7 +3484,7 @@
33893484
"type": "prometheus",
33903485
"uid": "prometheus"
33913486
},
3392-
"description": "Rate of Spanner sessions acquired and released from the pool, plus the rate of GFE (Google Front End) responses missing the server-timing header a non-zero gfe_header_missing_count may indicate requests bypassing the GFE or connectivity issues.",
3487+
"description": "Rate of Spanner sessions acquired and released from the pool, plus the rate of GFE (Google Front End) responses missing the server-timing header \u2014 a non-zero gfe_header_missing_count may indicate requests bypassing the GFE or connectivity issues.",
33933488
"fieldConfig": {
33943489
"defaults": {
33953490
"color": {
@@ -3507,7 +3602,7 @@
35073602
"h": 1,
35083603
"w": 24,
35093604
"x": 0,
3510-
"y": 62
3605+
"y": 70
35113606
},
35123607
"id": 74,
35133608
"panels": [
@@ -3836,7 +3931,7 @@
38363931
"h": 1,
38373932
"w": 24,
38383933
"x": 0,
3839-
"y": 63
3934+
"y": 71
38403935
},
38413936
"id": 4,
38423937
"panels": [
@@ -4744,4 +4839,4 @@
47444839
"uid": "qvsJJ_6Hk",
47454840
"version": 57,
47464841
"weekStart": ""
4747-
}
4842+
}

internal/services/v1/bulkcheck.go

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -45,7 +45,7 @@ type bulkChecker struct {
4545

4646
const maxBulkCheckCount = 10000
4747

48-
func (bc *bulkChecker) checkBulkPermissions(ctx context.Context, req *v1.CheckBulkPermissionsRequest) (*v1.CheckBulkPermissionsResponse, error) {
48+
func (bc *bulkChecker) checkBulkPermissions(ctx context.Context, req *v1.CheckBulkPermissionsRequest, metrics *Metrics) (*v1.CheckBulkPermissionsResponse, error) {
4949
telemetry.LogicalChecks.Add(float64(len(req.Items)))
5050

5151
atRevision, schemaHash, checkedAt, err := consistency.RevisionFromContext(ctx)
@@ -239,7 +239,7 @@ func (bc *bulkChecker) checkBulkPermissions(ctx context.Context, req *v1.CheckBu
239239

240240
if err := addPair(&v1.CheckBulkPermissionsPair{
241241
Request: reqItem,
242-
Response: pairItemFromCheckResult(results[resourceID], debugTrace),
242+
Response: pairItemFromCheckResult(results[resourceID], debugTrace, metrics),
243243
}); err != nil {
244244
return err
245245
}

internal/services/v1/bulkcheck_test.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -122,7 +122,7 @@ func runBulkCheck(t *testing.T, d dispatch.Dispatcher, withTracing bool) *v1.Che
122122
dispatchChunkSize: 100,
123123
}
124124

125-
resp, err := bc.checkBulkPermissions(ctx, req)
125+
resp, err := bc.checkBulkPermissions(ctx, req, NewMetrics(nil))
126126
require.NoError(err)
127127
return resp
128128
}

internal/services/v1/experimental.go

Lines changed: 10 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -95,6 +95,11 @@ func NewExperimentalServer(dispatch dispatch.Dispatcher, permServerConfig Permis
9595
chunkSize = 100
9696
}
9797

98+
metrics := permServerConfig.Metrics
99+
if metrics == nil {
100+
metrics = NewMetrics(nil)
101+
}
102+
98103
return &experimentalServer{
99104
WithServiceSpecificInterceptors: shared.WithServiceSpecificInterceptors{
100105
Unary: middleware.ChainUnaryServer(
@@ -113,6 +118,7 @@ func NewExperimentalServer(dispatch dispatch.Dispatcher, permServerConfig Permis
113118
},
114119
maxBatchSize: uint64(config.MaxExportBatchSize),
115120
caveatTypeSet: caveattypes.TypeSetOrDefault(permServerConfig.CaveatTypeSet),
121+
metrics: metrics,
116122
bulkChecker: &bulkChecker{
117123
maxAPIDepth: permServerConfig.MaximumAPIDepth,
118124
maxCaveatContextSize: permServerConfig.MaxCaveatContextSize,
@@ -132,6 +138,7 @@ type experimentalServer struct {
132138

133139
bulkChecker *bulkChecker
134140
caveatTypeSet *caveattypes.TypeSet
141+
metrics *Metrics
135142
}
136143

137144
type bulkLoadAdapter struct {
@@ -309,6 +316,8 @@ func (es *experimentalServer) BulkImportRelationships(stream v1.ExperimentalServ
309316
DispatchCount: 1,
310317
})
311318

319+
es.metrics.RecordBulkImportedRelationships(numWritten)
320+
312321
return stream.SendAndClose(&v1.BulkImportRelationshipsResponse{
313322
NumLoaded: numWritten,
314323
})
@@ -507,7 +516,7 @@ func (es *experimentalServer) BulkCheckPermission(ctx context.Context, req *v1.B
507516
perfinsights.SetInContext(ctx, perfinsights.NoLabels)
508517

509518
convertedReq := toCheckBulkPermissionsRequest(req)
510-
res, err := es.bulkChecker.checkBulkPermissions(ctx, convertedReq)
519+
res, err := es.bulkChecker.checkBulkPermissions(ctx, convertedReq, es.metrics)
511520
if err != nil {
512521
return nil, shared.RewriteErrorWithoutConfig(ctx, err)
513522
}

0 commit comments

Comments
 (0)