From f6e610ff49bbd7bcf6144c4c753a96832814c2cf Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ste=CC=81phane=20Duchesneau?= Date: Mon, 1 Jun 2026 10:09:29 -0400 Subject: [PATCH] add two metric points for squashing --- docs/release-notes/change-log.md | 4 ++++ orchestrator/stage/metrics.go | 25 ++++++++++++++++++------- orchestrator/stage/squash.go | 4 ++++ 3 files changed, 26 insertions(+), 7 deletions(-) diff --git a/docs/release-notes/change-log.md b/docs/release-notes/change-log.md index 7546dcdf9..4547940db 100644 --- a/docs/release-notes/change-log.md +++ b/docs/release-notes/change-log.md @@ -16,6 +16,10 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), - Server: per-block execution timeouts (`--substreams-block-execution-timeout`) are no longer silently swallowed when a WASM host-function panic (e.g. wasmtime) coincides with the deadline. Previously, `recoverExecutionPanic` would return `nil` instead of `CodeDeadlineExceeded`, causing the offending block to be skipped and the stream to complete successfully. - CI: Docker image login, build and push are now skipped for fork PRs; image is still built (without push) to validate the Dockerfile. +### Added + +- added more metrics to identify time spent squashing + ## v1.18.5 ### Server diff --git a/orchestrator/stage/metrics.go b/orchestrator/stage/metrics.go index 0de8924f1..8a36f233a 100644 --- a/orchestrator/stage/metrics.go +++ b/orchestrator/stage/metrics.go @@ -9,13 +9,17 @@ import ( ) type mergeMetrics struct { - start time.Time - loadStart time.Time - loadEnd time.Time - mergeStart time.Time - mergeEnd time.Time - saveStart time.Time - saveEnd time.Time + start time.Time + getStoreStart time.Time + getStoreEnd time.Time + loadStart time.Time + loadEnd time.Time + mergeStart time.Time + mergeEnd time.Time + saveStart time.Time + saveEnd time.Time + writeStart time.Time + writeEnd time.Time blockRange *block.Range stage int @@ -27,6 +31,9 @@ func (m mergeMetrics) logFields() []zap.Field { f := []zap.Field{ zap.String("total_time", time.Since(m.start).String()), } + if !m.getStoreStart.IsZero() { + f = append(f, zap.String("get_store_time", m.getStoreEnd.Sub(m.getStoreStart).String())) + } if !m.loadStart.IsZero() { f = append(f, zap.String("load_time", m.loadEnd.Sub(m.loadStart).String())) } @@ -39,6 +46,10 @@ func (m mergeMetrics) logFields() []zap.Field { f = append(f, zap.String("save_time", m.saveEnd.Sub(m.saveStart).String())) } + if !m.writeEnd.IsZero() { + f = append(f, zap.String("write_time", m.writeEnd.Sub(m.writeStart).String())) + } + if m.blockRange != nil { f = append(f, zap.Uint64("start_block", m.blockRange.StartBlock), zap.Uint64("end_block", m.blockRange.ExclusiveEndBlock)) } diff --git a/orchestrator/stage/squash.go b/orchestrator/stage/squash.go index d220dae7e..c10498081 100644 --- a/orchestrator/stage/squash.go +++ b/orchestrator/stage/squash.go @@ -111,10 +111,12 @@ func (s *Stages) singleSquash(stage *Stage, modState *StoreModuleState, mergeUni // Retrieve store to merge, from cache or load from storage. Allows skipping of segments // for handling partials interspearsed with full KVs. + meter.getStoreStart = time.Now() fullKV, err := modState.getStore(s.ctx, rng.StartBlock) // loads+caches or uses cached store if err != nil { return fmt.Errorf("getting store: %w", err) } + meter.getStoreEnd = time.Now() // Load meter.loadStart = time.Now() @@ -157,7 +159,9 @@ func (s *Stages) singleSquash(stage *Stage, modState *StoreModuleState, mergeUni return fmt.Errorf("save full store: %w", err) } meter.saveEnd = time.Now() + meter.writeStart = time.Now() err = writer.Write(ctx) + meter.writeEnd = time.Now() if err == nil { go partialKV.DeleteStore(context.Background(), partialFile) }