mirror of
https://github.com/andwati/zitadel.git
synced 2026-10-18 05:52:51 +00:00
4bc484dac9
# Which Problems Are Solved - A projection that subscribes to several event types gets slower the further it falls behind. - The handler reads its events with one query: `aggregate_type = ANY(...) AND event_type = ANY(...)`, ordered by position and limited to the bulk limit. - The `es_projection` index returns each (aggregate type, event type) range in position order, but Postgres cannot merge those ranges. - So each batch reads every matching event after the projection's position, sorts them all, and keeps only the bulk limit. - A projection that is N events behind therefore reads about N rows per batch. Catching up costs about N² in total, and once events arrive faster than such batches can process them, the projection does not recover. - Every query that triggers the projection waits for that catch-up. Examples are `GetSession` and the notification handlers. # How the Problems Are Solved - **New opt-in, `SearchQueryBuilder.ScanEventTypesSeparately()`.** It applies to event queries for a single instance, ascending and limited, whose sub-queries filter only by aggregate and event types. - For such a query, the SQL layer reads each distinct (aggregate type, event type) combination in its own `ORDER BY … LIMIT` subquery, using `UNNEST … CROSS JOIN LATERAL`. - It then merges the results with the same sort key and limit. - Each subquery is one `es_projection` range read in position order, so it stops at the limit. A batch reads at most `limit × combinations` rows, however far behind the projection is. - Every other query renders exactly as before. - **The projection handler** now passes its real combinations, one sub-query per aggregate type instead of the cross product of all types, and sets the opt-in. - **Results are identical to the single query.** - The sort key (`position, in_tx_order, instance_id, aggregate_type, aggregate_id, sequence`) is a total order, and the global top n is contained in the union of each combination's top n. - The cursor from #12703 and the open-transaction cap apply inside every subquery. - A test against a real Postgres compares both shapes from every cursor and every position, for several limits. The test events include positions shared by several transactions, whose `in_tx_order` restarts. # Additional Changes This is a separate commit and can be split into its own PR: - `cmd/defaults.yaml` sets `BulkLimit: 1000` for the `sessions` projection. - `projection_state_latency` gets histogram buckets up to one week. Until now, every projection more than 30 minutes behind was reported in the same top bucket. # Additional Context These numbers come from a local, CPU-pinned sandbox, for comparing builds only. - **Database:** Postgres 17 in a VM with 8 vCPUs and 16 GiB. The `Eventstore.Autovacuum` and `Projections` settings mirror a production-like setup. - **Starting state:** `sessions8` 4.8M events behind, restored byte-identically for every run. Batch query for `sessions8`, `EXPLAIN ANALYZE`, median of 5 runs, parallel workers at the default: | | before | after | | --- | ---: | ---: | | at the backlog, limit 1000 | 832 ms | 4.0 ms | | at the backlog, limit 200 | 832 ms | 1.0 ms | | at the head (idle poll) | 0.14 ms | 0.19 ms | | generic plan (`plan_cache_mode=force_generic_plan`), at the backlog | 1,042 ms | 4.0 ms | Draining `sessions8` from that backlog for 600 s, 3 runs per build (median, with the range in brackets): | | before | after | | --- | ---: | ---: | | events/s | 975 (932-1,032) | 7,811 (7,523-7,955) | | mean batch time, including writes | 1.03 s | 0.13 s | | still behind after 600 s | 4.2M | 17k-277k | A new index `(instance_id, position, in_tx_order, aggregate_type, event_type)` with the old query was evaluated as an alternative and rejected. Under a generic plan, Postgres chose it for projections whose events are rare and walked the whole event stream: 430 ms instead of 0.15 ms. This is the behaviour that led to dropping `es_instance_position` in #10626. - Follow-up for #12703 🤖 Generated with [Claude Code](https://claude.com/claude-code) --------- Co-authored-by: Claude Opus 5 <[email protected]> Co-authored-by: Copilot Autofix powered by AI <[email protected]>
77 lines
3.0 KiB
Go
77 lines
3.0 KiB
Go
package handler
|
|
|
|
import (
|
|
"context"
|
|
|
|
"go.opentelemetry.io/otel/attribute"
|
|
|
|
"github.com/zitadel/zitadel/backend/v3/instrumentation/logging"
|
|
"github.com/zitadel/zitadel/backend/v3/instrumentation/metrics"
|
|
)
|
|
|
|
const (
|
|
ProjectionLabel = "projection"
|
|
SuccessLabel = "success"
|
|
|
|
ProjectionEventsProcessed = "projection_events_processed"
|
|
ProjectionHandleTimerMetric = "projection_handle_timer"
|
|
ProjectionStateLatencyMetric = "projection_state_latency"
|
|
)
|
|
|
|
type ProjectionMetrics struct {
|
|
provider metrics.Metrics
|
|
}
|
|
|
|
func NewProjectionMetrics(ctx context.Context) *ProjectionMetrics {
|
|
return newProjectionMetrics(ctx, metrics.GlobalMeter())
|
|
}
|
|
|
|
func newProjectionMetrics(ctx context.Context, m metrics.Metrics) *ProjectionMetrics {
|
|
projectionMetrics := &ProjectionMetrics{provider: m}
|
|
|
|
err := projectionMetrics.provider.RegisterCounter(
|
|
ProjectionEventsProcessed,
|
|
"Number of events reduced to process projection updates",
|
|
)
|
|
logging.OnError(ctx, err).Error("failed to register projection events processed counter")
|
|
err = projectionMetrics.provider.RegisterHistogram(
|
|
ProjectionHandleTimerMetric,
|
|
"Time taken to process a projection update",
|
|
"s",
|
|
[]float64{0.005, 0.01, 0.05, 0.1, 1, 5, 10, 30, 60, 120},
|
|
)
|
|
logging.OnError(ctx, err).Error("failed to register projection handle timer metric")
|
|
err = projectionMetrics.provider.RegisterHistogram(
|
|
ProjectionStateLatencyMetric,
|
|
"When finishing processing a batch of events, this track the age of the last events seen from current time",
|
|
"s",
|
|
// the upper bounds up to a week make a projection that falls hours or days behind visible,
|
|
// instead of reporting every latency above 30 minutes as the 1800s bucket
|
|
[]float64{0.1, 0.5, 1, 5, 10, 30, 60, 300, 600, 1800, 3600, 21600, 86400, 604800},
|
|
)
|
|
logging.OnError(ctx, err).Error("failed to register projection state latency metric")
|
|
return projectionMetrics
|
|
}
|
|
|
|
func (m *ProjectionMetrics) ProjectionUpdateTiming(ctx context.Context, projection string, duration float64) {
|
|
err := m.provider.AddHistogramMeasurement(ctx, ProjectionHandleTimerMetric, duration, map[string]attribute.Value{
|
|
ProjectionLabel: attribute.StringValue(projection),
|
|
})
|
|
logging.OnError(ctx, err).Error("failed to add projection trigger timing")
|
|
}
|
|
|
|
func (m *ProjectionMetrics) ProjectionEventsProcessed(ctx context.Context, projection string, count int64, success bool) {
|
|
err := m.provider.AddCount(ctx, ProjectionEventsProcessed, count, map[string]attribute.Value{
|
|
ProjectionLabel: attribute.StringValue(projection),
|
|
SuccessLabel: attribute.BoolValue(success),
|
|
})
|
|
logging.OnError(ctx, err).Error("failed to add projection events processed metric")
|
|
}
|
|
|
|
func (m *ProjectionMetrics) ProjectionStateLatency(ctx context.Context, projection string, latency float64) {
|
|
err := m.provider.AddHistogramMeasurement(ctx, ProjectionStateLatencyMetric, latency, map[string]attribute.Value{
|
|
ProjectionLabel: attribute.StringValue(projection),
|
|
})
|
|
logging.OnError(ctx, err).Error("failed to add projection state latency metric")
|
|
}
|