From f537feafa1276f5ea4f080783365a3ea16a20be3 Mon Sep 17 00:00:00 2001 From: Lev Brouk Date: Mon, 22 Jun 2026 12:59:39 -0700 Subject: [PATCH 1/2] WIP --- packages/orchestrator/cmd/copy-build/main.go | 8 +- .../orchestrator/cmd/create-build/main.go | 2 +- .../cmd/inspect-build/validate.go | 4 +- .../pkg/sandbox/block/fetch_session.go | 13 + .../pkg/sandbox/block/metrics/main.go | 37 +-- .../pkg/sandbox/block/streaming_chunk.go | 216 ++++++------- .../pkg/sandbox/block/streaming_chunk_test.go | 26 +- .../orchestrator/pkg/sandbox/build/build.go | 37 ++- .../pkg/sandbox/build/softdelete.go | 2 +- .../pkg/sandbox/build/storage_diff.go | 19 +- .../pkg/sandbox/build/storage_diff_test.go | 66 ++-- .../pkg/sandbox/build_upload_v3.go | 8 +- .../pkg/sandbox/build_upload_v4.go | 17 +- .../sandbox/nbd/testutils/template_rootfs.go | 4 +- .../pkg/sandbox/template/peerclient/blob.go | 8 +- .../sandbox/template/peerclient/blob_test.go | 20 +- .../sandbox/template/peerclient/seekable.go | 45 ++- .../template/peerclient/seekable_test.go | 22 +- .../sandbox/template/peerclient/storage.go | 59 ++-- .../template/peerclient/storage_test.go | 4 +- .../pkg/sandbox/template/storage.go | 18 +- .../pkg/sandbox/template/storage_file.go | 3 +- .../pkg/sandbox/template/storage_template.go | 2 - .../pkg/sandbox/upload_metrics.go | 4 +- .../pkg/template/build/builder.go | 2 +- .../pkg/template/build/commands/copy.go | 2 +- .../pkg/template/build/storage/cache/cache.go | 4 +- .../pkg/template/metadata/prefetch.go | 2 +- .../template/metadata/template_metadata.go | 2 +- .../server/upload_layer_files_template.go | 3 +- .../shared/pkg/storage/compress_decode.go | 52 ++- .../pkg/storage/compress_frame_table.go | 4 + .../pkg/storage/header/serialization.go | 23 +- packages/shared/pkg/storage/io_wrappers.go | 150 +++++---- packages/shared/pkg/storage/metrics.go | 303 ++++++++++++++++++ packages/shared/pkg/storage/metrics_test.go | 52 +++ packages/shared/pkg/storage/mock_seekable.go | 24 +- .../pkg/storage/mock_storageprovider.go | 60 ++-- packages/shared/pkg/storage/paths.go | 42 +++ packages/shared/pkg/storage/paths_test.go | 38 +++ packages/shared/pkg/storage/storage.go | 43 ++- packages/shared/pkg/storage/storage_aws.go | 35 +- packages/shared/pkg/storage/storage_cache.go | 11 +- .../shared/pkg/storage/storage_cache_blob.go | 29 +- .../storage/storage_cache_compressed_test.go | 18 +- .../pkg/storage/storage_cache_metrics.go | 142 -------- .../pkg/storage/storage_cache_seekable.go | 170 +++------- .../storage_cache_seekable_compressed.go | 99 +++--- .../storage/storage_cache_seekable_test.go | 63 ++-- packages/shared/pkg/storage/storage_fs.go | 48 ++- .../shared/pkg/storage/storage_fs_test.go | 10 +- packages/shared/pkg/storage/storage_google.go | 96 ++---- packages/shared/pkg/telemetry/meters.go | 62 +++- .../sandbox_rapid_pause_resume_test.go | 14 +- 54 files changed, 1294 insertions(+), 953 deletions(-) create mode 100644 packages/shared/pkg/storage/metrics.go create mode 100644 packages/shared/pkg/storage/metrics_test.go create mode 100644 packages/shared/pkg/storage/paths_test.go delete mode 100644 packages/shared/pkg/storage/storage_cache_metrics.go diff --git a/packages/orchestrator/cmd/copy-build/main.go b/packages/orchestrator/cmd/copy-build/main.go index 4e07f60d18..438c75cea6 100644 --- a/packages/orchestrator/cmd/copy-build/main.go +++ b/packages/orchestrator/cmd/copy-build/main.go @@ -77,13 +77,13 @@ func NewDestinationFromPath(prefix, file string) (*Destination, error) { }, nil } -func NewHeaderFromObject(ctx context.Context, bucketName string, headerPath string, objectType storage.ObjectType) (*header.Header, error) { +func NewHeaderFromObject(ctx context.Context, bucketName string, headerPath string) (*header.Header, error) { b, err := storage.NewGCP(ctx, bucketName, nil) if err != nil { return nil, fmt.Errorf("failed to create GCS bucket storage provider: %w", err) } - obj, err := b.OpenBlob(ctx, headerPath, objectType) + obj, err := b.OpenBlob(ctx, headerPath) if err != nil { return nil, fmt.Errorf("failed to open object: %w", err) } @@ -228,7 +228,7 @@ func main() { if strings.HasPrefix(*from, "gs://") { bucketName, _ := strings.CutPrefix(*from, "gs://") - h, err := NewHeaderFromObject(ctx, bucketName, buildMemfileHeaderPath, storage.MemfileHeaderObjectType) + h, err := NewHeaderFromObject(ctx, bucketName, buildMemfileHeaderPath) if err != nil { log.Fatalf("failed to create header from object: %s", err) } @@ -254,7 +254,7 @@ func main() { var rootfsHeader *header.Header if strings.HasPrefix(*from, "gs://") { bucketName, _ := strings.CutPrefix(*from, "gs://") - h, err := NewHeaderFromObject(ctx, bucketName, buildRootfsHeaderPath, storage.RootFSHeaderObjectType) + h, err := NewHeaderFromObject(ctx, bucketName, buildRootfsHeaderPath) if err != nil { log.Fatalf("failed to create header from object: %s", err) } diff --git a/packages/orchestrator/cmd/create-build/main.go b/packages/orchestrator/cmd/create-build/main.go index 31b30d6522..c3870b8b5e 100644 --- a/packages/orchestrator/cmd/create-build/main.go +++ b/packages/orchestrator/cmd/create-build/main.go @@ -432,7 +432,7 @@ func printArtifactSizes(ctx context.Context, persistence storage.StorageProvider printLocalFileSizes(basePath, buildID) } else { // For remote storage, get sizes from storage provider - if memfile, err := persistence.OpenSeekable(ctx, paths.Memfile(), storage.MemfileObjectType); err == nil { + if memfile, err := persistence.OpenSeekable(ctx, paths.Memfile()); err == nil { if size, err := memfile.Size(ctx); err == nil { fmt.Printf(" Memfile: %d MB\n", size>>20) } diff --git a/packages/orchestrator/cmd/inspect-build/validate.go b/packages/orchestrator/cmd/inspect-build/validate.go index 9548c04012..0772ac45fb 100644 --- a/packages/orchestrator/cmd/inspect-build/validate.go +++ b/packages/orchestrator/cmd/inspect-build/validate.go @@ -160,7 +160,7 @@ func openChunker(ctx context.Context, storagePath, buildID, artifact string, h * if ft.IsCompressed() { dataPath += ft.CompressionType().Suffix() } - obj, err := provider.OpenSeekable(ctx, dataPath, seekableType(artifact)) + obj, err := provider.OpenSeekable(ctx, dataPath) if err != nil { return nil, nil, 0, nil, fmt.Errorf("open data: %w", err) } @@ -190,7 +190,7 @@ func openChunker(ctx context.Context, storagePath, buildID, artifact string, h * return nil, nil, 0, nil, err } - chunker, err := block.NewChunker(flags, size, int64(h.Metadata.BlockSize), filepath.Join(cacheDir, "cache"), m) + chunker, err := block.NewChunker(flags, size, int64(h.Metadata.BlockSize), filepath.Join(cacheDir, "cache"), m, seekableType(artifact)) if err != nil { os.RemoveAll(cacheDir) diff --git a/packages/orchestrator/pkg/sandbox/block/fetch_session.go b/packages/orchestrator/pkg/sandbox/block/fetch_session.go index 8b013afb01..9f80484261 100644 --- a/packages/orchestrator/pkg/sandbox/block/fetch_session.go +++ b/packages/orchestrator/pkg/sandbox/block/fetch_session.go @@ -7,6 +7,8 @@ import ( "fmt" "sync" "sync/atomic" + + "github.com/e2b-dev/infra/packages/shared/pkg/storage" ) type fetchSession struct { @@ -21,12 +23,23 @@ type fetchSession struct { fetchErr error done bool // true once terminated (success or error) + // source is the backend that served the fetch; set by runFetch. + source atomic.Int32 + // bytesReady is the byte count (from chunkOff) up to which all blocks // are fully written and marked cached. Atomic so registerAndWait can // do a lock-free fast-path check: bytesReady only increases. bytesReady atomic.Int64 } +func (s *fetchSession) setSource(src storage.Source) { + s.source.Store(int32(src)) +} + +func (s *fetchSession) Source() storage.Source { + return storage.Source(s.source.Load()) +} + // contains reports whether the session covers the byte range [off, off+length). func (s *fetchSession) contains(off, length int64) bool { return s.chunkOff <= off && s.chunkOff+s.chunkLen >= off+length diff --git a/packages/orchestrator/pkg/sandbox/block/metrics/main.go b/packages/orchestrator/pkg/sandbox/block/metrics/main.go index f1d67440da..ece0849537 100644 --- a/packages/orchestrator/pkg/sandbox/block/metrics/main.go +++ b/packages/orchestrator/pkg/sandbox/block/metrics/main.go @@ -9,20 +9,15 @@ import ( ) const ( - orchestratorBlockSlices = "orchestrator.blocks.slices" - orchestratorBlockChunksFetch = "orchestrator.blocks.chunks.fetch" orchestratorBlockChunksStore = "orchestrator.blocks.chunks.store" + orchestratorChunkSlice = "orchestrator.chunk.slice" ) type Metrics struct { - // SlicesMetric is used to measure page faulting performance. - SlicesTimerFactory telemetry.TimerFactory - - // WriteChunksMetric is used to measure the time taken to download chunks from remote storage - RemoteReadsTimerFactory telemetry.TimerFactory - // WriteChunksMetric is used to measure performance of writing chunks to disk. WriteChunksTimerFactory telemetry.TimerFactory + + ChunkSliceTimerFactory telemetry.FloatTimerFactory } func NewMetrics(meterProvider metric.MeterProvider) (Metrics, error) { @@ -31,24 +26,6 @@ func NewMetrics(meterProvider metric.MeterProvider) (Metrics, error) { blocksMeter := meterProvider.Meter("github.com/e2b-dev/infra/packages/orchestrator/pkg/sandbox/block/metrics") var err error - if m.SlicesTimerFactory, err = telemetry.NewTimerFactory( - blocksMeter, orchestratorBlockSlices, - "Time taken to retrieve memory slices", - "Total bytes requested", - "Total page faults", - ); err != nil { - return m, fmt.Errorf("error creating slices timer factory: %w", err) - } - - if m.RemoteReadsTimerFactory, err = telemetry.NewTimerFactory( - blocksMeter, orchestratorBlockChunksFetch, - "Time taken to fetch memory chunks from remote store", - "Total bytes fetched from remote store", - "Total remote fetches", - ); err != nil { - return m, fmt.Errorf("error creating reads timer factory: %w", err) - } - if m.WriteChunksTimerFactory, err = telemetry.NewTimerFactory( blocksMeter, orchestratorBlockChunksStore, "Time taken to write memory chunks to disk", @@ -58,5 +35,13 @@ func NewMetrics(meterProvider metric.MeterProvider) (Metrics, error) { return m, fmt.Errorf("failed to get stored chunks metric: %w", err) } + if m.ChunkSliceTimerFactory, err = telemetry.NewFloatTimerFactory( + blocksMeter, orchestratorChunkSlice, + "Time taken by Chunker to serve a Slice() (source=mmap when served from cache)", + "Bytes returned", + ); err != nil { + return m, fmt.Errorf("error creating chunk slice timer factory: %w", err) + } + return m, nil } diff --git a/packages/orchestrator/pkg/sandbox/block/streaming_chunk.go b/packages/orchestrator/pkg/sandbox/block/streaming_chunk.go index 5c05ff7255..1599fedb84 100644 --- a/packages/orchestrator/pkg/sandbox/block/streaming_chunk.go +++ b/packages/orchestrator/pkg/sandbox/block/streaming_chunk.go @@ -11,7 +11,6 @@ import ( "time" "go.opentelemetry.io/otel/attribute" - "go.opentelemetry.io/otel/metric" "github.com/e2b-dev/infra/packages/orchestrator/pkg/sandbox/block/metrics" "github.com/e2b-dev/infra/packages/shared/pkg/featureflags" @@ -30,6 +29,7 @@ type Chunker struct { metrics metrics.Metrics fetchTimeout time.Duration featureFlags *featureflags.Client + objType storage.SeekableObjectType size int64 @@ -42,6 +42,7 @@ func NewChunker( size, blockSize int64, cachePath string, metrics metrics.Metrics, + objType storage.SeekableObjectType, ) (*Chunker, error) { cache, err := NewCache(size, blockSize, cachePath, false) if err != nil { @@ -54,6 +55,7 @@ func NewChunker( metrics: metrics, featureFlags: ff, fetchTimeout: defaultFetchTimeout, + objType: objType, }, nil } @@ -69,54 +71,54 @@ func (c *Chunker) ReadAt(ctx context.Context, b []byte, off int64, upstream stor } func (c *Chunker) Slice(ctx context.Context, off, length int64, upstream storage.RangeOpener, ft *storage.FrameTable) ([]byte, error) { - attrs := chunkerAttrs - if ft.IsCompressed() { - attrs = chunkerAttrsCompressed - } - timer := c.metrics.SlicesTimerFactory.Begin() + ct := ft.CompressionType() + sliceStart := time.Now() - // Fast path: already cached + // Fast path: already cached. b, err := c.cache.Slice(off, length) if err == nil { - timer.RecordRaw(ctx, length, attrs.successFromCache) + c.metrics.ChunkSliceTimerFactory.Record(ctx, time.Since(sliceStart), length, storage.OKAttrs(c.objType, storage.SourceMmap, ct)) return b, nil } if !errors.As(err, &BytesNotAvailableError{}) { - timer.RecordRaw(ctx, length, attrs.failCacheRead) + c.metrics.ChunkSliceTimerFactory.Record(ctx, time.Since(sliceStart), 0, storage.ErrAttrs(c.objType, storage.SourceMmap, ct, err)) return nil, fmt.Errorf("failed read from cache at offset %d: %w", off, err) } // Fetch every chunk the range spans (one fetch session per chunk). + var src storage.Source end := off + length for cur := off; cur < end; { chunkOff, chunkLen, lerr := c.locateChunk(cur, ft) if lerr != nil { - timer.RecordRaw(ctx, length, attrs.failRemoteFetch) + c.metrics.ChunkSliceTimerFactory.Record(ctx, time.Since(sliceStart), 0, storage.ErrAttrs(c.objType, src, ct, lerr)) return nil, fmt.Errorf("failed to locate chunk for offset %d: %w", cur, lerr) } chunkEnd := chunkOff + chunkLen rangeEnd := min(end, chunkEnd) - if err := c.fetch(ctx, cur, rangeEnd-cur, upstream, ft); err != nil { - timer.RecordRaw(ctx, length, attrs.failRemoteFetch) + s, err := c.fetch(ctx, cur, rangeEnd-cur, upstream, ft) + if err != nil { + c.metrics.ChunkSliceTimerFactory.Record(ctx, time.Since(sliceStart), 0, storage.ErrAttrs(c.objType, s, ct, err)) return nil, fmt.Errorf("failed to ensure data at %d-%d: %w", cur, rangeEnd, err) } + src = max(src, s) cur = chunkEnd } // sliceDirect skips isCached — the waiter already confirmed the data is in the mmap. b, cacheErr := c.cache.sliceDirect(off, length) if cacheErr != nil { - timer.RecordRaw(ctx, length, attrs.failLocalReadAgain) + c.metrics.ChunkSliceTimerFactory.Record(ctx, time.Since(sliceStart), 0, storage.ErrAttrs(c.objType, src, ct, cacheErr)) return nil, fmt.Errorf("failed to read from cache after ensuring data at %d-%d: %w", off, off+length, cacheErr) } - timer.RecordRaw(ctx, length, attrs.successFromRemote) + c.metrics.ChunkSliceTimerFactory.Record(ctx, time.Since(sliceStart), length, storage.OKAttrs(c.objType, src, ct)) return b, nil } @@ -156,31 +158,38 @@ func (c *Chunker) getOrCreateSession(ctx context.Context, off, length int64, ups // fetch ensures the chunk for [off, off+length) is fetched and waits // for every block the range spans (a span can cross block boundaries // after dedup; waiting only on the start block leaves the tail unfetched). -func (c *Chunker) fetch(ctx context.Context, off, length int64, upstream storage.RangeOpener, ft *storage.FrameTable) error { +func (c *Chunker) fetch(ctx context.Context, off, length int64, upstream storage.RangeOpener, ft *storage.FrameTable) (storage.Source, error) { chunkOff, chunkLen, err := c.locateChunk(off, ft) if err != nil { - return fmt.Errorf("failed to locate chunk for offset %d: %w", off, err) + return storage.UnknownSource, fmt.Errorf("failed to locate chunk for offset %d: %w", off, err) } session, justGotCached := c.getOrCreateSession(ctx, chunkOff, chunkLen, upstream, ft) if justGotCached { - return nil + return storage.SourceMmap, nil } blockSize := c.cache.BlockSize() startBlock := (off / blockSize) * blockSize endBlock := ((off + length - 1) / blockSize) * blockSize chunkEnd := chunkOff + chunkLen + + // Already streamed past every byte we need: it's in the mmap, source=mmap. + endByte := min(endBlock+blockSize, chunkEnd) - chunkOff + if session.bytesReady.Load() >= endByte { + return storage.SourceMmap, nil + } + for b := startBlock; b <= endBlock; b += blockSize { if b >= chunkEnd { break // tail belongs to the caller's next chunk fetch. } if err := session.registerAndWait(ctx, b); err != nil { - return err + return session.Source(), err } } - return nil + return session.Source(), nil } // runFetch fetches data from storage into the mmap cache. Runs in a background goroutine. @@ -188,6 +197,13 @@ func (c *Chunker) runFetch(ctx context.Context, s *fetchSession, upstream storag ctx, cancel := context.WithTimeout(ctx, c.fetchTimeout) defer cancel() + ctx, span := tracer.Start(ctx, "chunk.fetch") + defer span.End() + span.SetAttributes( + attribute.Int64("off", s.chunkOff), + attribute.Int64("len", s.chunkLen), + ) + defer c.releaseSession(s) // Unconditionally terminate the session on exit so registerAndWait @@ -211,15 +227,17 @@ func (c *Chunker) runFetch(ctx context.Context, s *fetchSession, upstream storag } defer releaseLock() - attrs := chunkerAttrs - if ft.IsCompressed() { - attrs = chunkerAttrsCompressed - } - fetchTimer := c.metrics.RemoteReadsTimerFactory.Begin() + ct := ft.CompressionType() - readBytes, err := c.progressiveRead(ctx, s, mmapSlice, upstream, ft) + fetchStart := time.Now() + + res, err := c.progressiveFetch(ctx, s, mmapSlice, upstream, ft) + var readBytes int64 + if res.stats != nil { + readBytes = res.stats.DeliveredBytes + } if err != nil { - fetchTimer.RecordRaw(ctx, readBytes, attrs.remoteFailure) + storage.RecordReadFetch(ctx, time.Since(fetchStart), readBytes, storage.ErrAttrs(c.objType, res.source, ct, err)) s.fail(err) @@ -231,24 +249,63 @@ func (c *Chunker) runFetch(ctx context.Context, s *fetchSession, upstream storag // closing the TOCTOU window in getOrCreateSession. c.cache.setIsCached(s.chunkOff, s.chunkLen) - fetchTimer.RecordRaw(ctx, readBytes, attrs.remoteSuccess) + fetchDuration := time.Since(fetchStart) + storage.RecordReadFetch(ctx, fetchDuration, readBytes, storage.OKAttrs(c.objType, res.source, ct)) + + // fetch wall / (open + read + decompress); >1 = unaccounted overhead. + if res.stats != nil { + if work := res.openDuration + res.stats.Read + res.stats.Decompress; work > 0 { + ratio := fetchDuration.Seconds() / work.Seconds() + storage.RecordPipelineEfficiency(ctx, ratio, storage.OKAttrs(c.objType, res.source, ct)) + } + } + s.setDone() } -func (c *Chunker) progressiveRead(ctx context.Context, s *fetchSession, mmapSlice []byte, upstream storage.RangeOpener, ft *storage.FrameTable) (totalRead int64, err error) { - reader, err := upstream.OpenRangeReader(ctx, s.chunkOff, s.chunkLen, ft) +// fetchStats is one progressiveFetch outcome: the resolved source, the open/TTFB +// wall, and the read sub-stage stats (nil if the open failed). +type fetchStats struct { + source storage.Source + openDuration time.Duration + stats *storage.ReadStats +} + +func (c *Chunker) progressiveFetch(ctx context.Context, s *fetchSession, mmapSlice []byte, upstream storage.RangeOpener, ft *storage.FrameTable) (res fetchStats, err error) { + openStart := time.Now() + reader, source, err := upstream.OpenRangeReader(ctx, s.chunkOff, s.chunkLen, ft) + res.source = source + res.openDuration = time.Since(openStart) + s.setSource(source) if err != nil { - return 0, fmt.Errorf("failed to open range reader at %d: %w", s.chunkOff, err) + return res, fmt.Errorf("failed to open range reader at %d: %w", s.chunkOff, err) } + defer func() { - if closeErr := reader.Close(context.WithoutCancel(ctx)); closeErr != nil && err == nil { - err = closeErr + var closeErr error + res.stats, closeErr = reader.Close(context.WithoutCancel(ctx)) + + ct := ft.CompressionType() + attrs := storage.OKAttrs(c.objType, source, ct) + switch { + case err != nil: + attrs = storage.ErrAttrs(c.objType, source, ct, err) + case closeErr != nil: + attrs = storage.ErrAttrs(c.objType, source, ct, closeErr) } + + var readDur time.Duration + var readBytes int64 + if res.stats != nil { + readDur, readBytes = res.stats.Read, res.stats.StoredBytes + } + storage.RecordReadRead(ctx, readDur, readBytes, attrs) }() blockSize := c.cache.BlockSize() readBatch := max(blockSize, int64(c.featureFlags.IntFlag(ctx, featureflags.MinChunkerReadSizeKB))*1024) + var totalRead int64 for totalRead < s.chunkLen { // Read in batches of max(blockSize, minReadBatchSize) to align notification // granularity with the read size and minimize lock/notify overhead. @@ -273,11 +330,11 @@ func (c *Chunker) progressiveRead(ctx context.Context, s *fetchSession, mmapSlic break // all bytes received; trailing EOF is expected } - return totalRead, fmt.Errorf("failed reading at offset %d after %d bytes: %w", s.chunkOff, totalRead, readErr) + return res, fmt.Errorf("failed reading at offset %d after %d bytes: %w", s.chunkOff, totalRead, readErr) } } - return totalRead, nil + return res, nil } // releaseSession removes s from the active list (swap-delete). @@ -338,94 +395,3 @@ var ( writeSuccessAttr = telemetry.PrecomputeAttrs(telemetry.Success) writeFailureAttr = telemetry.PrecomputeAttrs(telemetry.Failure) ) - -const ( - compressedAttr = "compressed" - pullType = "pull-type" - pullTypeLocal = "local" - pullTypeRemote = "remote" - - failureReason = "failure-reason" - - failureTypeLocalRead = "local-read" - failureTypeLocalReadAgain = "local-read-again" - failureTypeRemoteRead = "remote-read" - failureTypeCacheFetch = "cache-fetch" -) - -type precomputedAttrs struct { - successFromCache metric.MeasurementOption - successFromRemote metric.MeasurementOption - - failCacheRead metric.MeasurementOption - failRemoteFetch metric.MeasurementOption - failLocalReadAgain metric.MeasurementOption - - // RemoteReads timer (runFetch) - remoteSuccess metric.MeasurementOption - remoteFailure metric.MeasurementOption -} - -var chunkerAttrs = precomputedAttrs{ - successFromCache: telemetry.PrecomputeAttrs( - telemetry.Success, - attribute.String(pullType, pullTypeLocal)), - - successFromRemote: telemetry.PrecomputeAttrs( - telemetry.Success, - attribute.String(pullType, pullTypeRemote)), - - failCacheRead: telemetry.PrecomputeAttrs( - telemetry.Failure, - attribute.String(pullType, pullTypeLocal), - attribute.String(failureReason, failureTypeLocalRead)), - - failRemoteFetch: telemetry.PrecomputeAttrs( - telemetry.Failure, - attribute.String(pullType, pullTypeRemote), - attribute.String(failureReason, failureTypeCacheFetch)), - - failLocalReadAgain: telemetry.PrecomputeAttrs( - telemetry.Failure, - attribute.String(pullType, pullTypeLocal), - attribute.String(failureReason, failureTypeLocalReadAgain)), - - remoteSuccess: telemetry.PrecomputeAttrs( - telemetry.Success), - - remoteFailure: telemetry.PrecomputeAttrs( - telemetry.Failure, - attribute.String(failureReason, failureTypeRemoteRead)), -} - -var chunkerAttrsCompressed = precomputedAttrs{ - successFromCache: telemetry.PrecomputeAttrs( - telemetry.Success, attribute.Bool(compressedAttr, true), - attribute.String(pullType, pullTypeLocal)), - - successFromRemote: telemetry.PrecomputeAttrs( - telemetry.Success, attribute.Bool(compressedAttr, true), - attribute.String(pullType, pullTypeRemote)), - - failCacheRead: telemetry.PrecomputeAttrs( - telemetry.Failure, attribute.Bool(compressedAttr, true), - attribute.String(pullType, pullTypeLocal), - attribute.String(failureReason, failureTypeLocalRead)), - - failRemoteFetch: telemetry.PrecomputeAttrs( - telemetry.Failure, attribute.Bool(compressedAttr, true), - attribute.String(pullType, pullTypeRemote), - attribute.String(failureReason, failureTypeCacheFetch)), - - failLocalReadAgain: telemetry.PrecomputeAttrs( - telemetry.Failure, attribute.Bool(compressedAttr, true), - attribute.String(pullType, pullTypeLocal), - attribute.String(failureReason, failureTypeLocalReadAgain)), - - remoteSuccess: telemetry.PrecomputeAttrs( - telemetry.Success, attribute.Bool(compressedAttr, true)), - - remoteFailure: telemetry.PrecomputeAttrs( - telemetry.Failure, attribute.Bool(compressedAttr, true), - attribute.String(failureReason, failureTypeRemoteRead)), -} diff --git a/packages/orchestrator/pkg/sandbox/block/streaming_chunk_test.go b/packages/orchestrator/pkg/sandbox/block/streaming_chunk_test.go index 8295daaa46..f536286634 100644 --- a/packages/orchestrator/pkg/sandbox/block/streaming_chunk_test.go +++ b/packages/orchestrator/pkg/sandbox/block/streaming_chunk_test.go @@ -68,7 +68,7 @@ type testControl struct { func newTestChunker(t *testing.T, size int64) *Chunker { t.Helper() - c, err := NewChunker(&featureflags.Client{}, size, testBlockSize, t.TempDir()+"/cache", newTestMetrics(t)) + c, err := NewChunker(&featureflags.Client{}, size, testBlockSize, t.TempDir()+"/cache", newTestMetrics(t), storage.MemfileObjectType) require.NoError(t, err) return c @@ -82,7 +82,7 @@ func (s *fakeSeekable) StoreFile(context.Context, string, ...storage.PutOption) panic("not used") } -func (s *fakeSeekable) OpenRangeReader(_ context.Context, offsetU int64, length int64, frameTable *storage.FrameTable) (storage.RangeReader, error) { +func (s *fakeSeekable) OpenRangeReader(_ context.Context, offsetU int64, length int64, frameTable *storage.FrameTable) (storage.RangeReader, storage.Source, error) { s.fetchCount.Add(1) if s.ctrl != nil { @@ -103,14 +103,14 @@ func (s *fakeSeekable) OpenRangeReader(_ context.Context, offsetU int64, length advance: s.ctrl.advance, consumed: s.ctrl.consumed, closed: s.ctrl.closed, - }, nil + }, storage.SourceFS, nil } var fetchOff, fetchLen int64 if frameTable.IsCompressed() { r, err := frameTable.LocateCompressed(offsetU) if err != nil { - return nil, fmt.Errorf("frame lookup: %w", err) + return nil, storage.UnknownSource, fmt.Errorf("frame lookup: %w", err) } fetchOff = r.Offset @@ -127,10 +127,12 @@ func (s *fakeSeekable) OpenRangeReader(_ context.Context, offsetU int64, length r := io.Reader(bytes.NewReader(s.data[fetchOff:end])) if frameTable.IsCompressed() { - return storage.NewDecompressingReader(storage.NewRangeReader(io.NopCloser(r)), frameTable.CompressionType()) + dec, err := storage.NewDecompressReader(storage.NewRangeReader(io.NopCloser(r)), frameTable.CompressionType(), storage.UnknownSource, storage.UnknownSeekableObjectType) + + return dec, storage.SourceFS, err } - return storage.NewRangeReader(io.NopCloser(r)), nil + return storage.NewRangeReader(io.NopCloser(r)), storage.SourceFS, nil } func makeCompressedTestData(tb testing.TB, data []byte) (*storage.FrameTable, *fakeSeekable) { @@ -429,13 +431,13 @@ func (s *panicSeekable) StoreFile(context.Context, string, ...storage.PutOption) panic("not used") } -func (s *panicSeekable) OpenRangeReader(_ context.Context, off int64, length int64, _ *storage.FrameTable) (storage.RangeReader, error) { +func (s *panicSeekable) OpenRangeReader(_ context.Context, off int64, length int64, _ *storage.FrameTable) (storage.RangeReader, storage.Source, error) { end := min(off+length, int64(len(s.data))) return &panicReader{ data: s.data[off:end], panicAfter: int(s.panicAfter - off), - }, nil + }, storage.SourceFS, nil } type panicReader struct { @@ -460,8 +462,8 @@ func (r *panicReader) Read(p []byte) (int, error) { return n, nil } -func (r *panicReader) Close(context.Context) error { - return nil +func (r *panicReader) Close(context.Context) (*storage.ReadStats, error) { + return nil, nil } func TestChunker_PanicRecovery(t *testing.T) { @@ -587,11 +589,11 @@ func (r *controlledReader) Read(p []byte) (int, error) { return n, nil } -func (r *controlledReader) Close(context.Context) error { +func (r *controlledReader) Close(context.Context) (*storage.ReadStats, error) { select { case r.closed <- struct{}{}: default: } - return nil + return nil, nil } diff --git a/packages/orchestrator/pkg/sandbox/build/build.go b/packages/orchestrator/pkg/sandbox/build/build.go index 4f93d57145..6925a74ab8 100644 --- a/packages/orchestrator/pkg/sandbox/build/build.go +++ b/packages/orchestrator/pkg/sandbox/build/build.go @@ -12,6 +12,8 @@ import ( "github.com/google/uuid" "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/metric" "go.uber.org/zap" "golang.org/x/sync/errgroup" @@ -43,6 +45,10 @@ var ( "Bytes loaded during frame-table refreshes", "Frame-table refresh events", )) + + fileReadAtTimer = utils.Must(telemetry.NewFloatTimerFactory(buildMeter, "orchestrator.file.read_at", + "Time to serve a build.File ReadAt across all source builds", + "Bytes read")) ) type File struct { @@ -51,6 +57,8 @@ type File struct { fileType DiffType persistence storage.StorageProvider metrics blockmetrics.Metrics + + okAttrs metric.MeasurementOption } func NewFile( @@ -65,6 +73,10 @@ func NewFile( fileType: fileType, persistence: persistence, metrics: metrics, + okAttrs: metric.WithAttributes( + attribute.String(storage.AttrFileType, string(fileType)), + attribute.String(storage.AttrOutcome, storage.OutcomeOK), + ), } f.header.Store(header) @@ -79,9 +91,28 @@ func (b *File) SwapHeader(h *header.Header) { b.header.Store(h) } -// ReadAt fills p from the mapped build segments, optionally in parallel. +// ReadAt times file.read_at around readAt; Slice composes via readAt directly to +// avoid double counting. +func (b *File) ReadAt(ctx context.Context, p []byte, off int64) (n int, err error) { + start := time.Now() + n, err = b.readAt(ctx, p, off) + // io.EOF is a normal short-read outcome (io.ReaderAt), not an I/O error. + if err != nil && !errors.Is(err, io.EOF) { + fileReadAtTimer.Record(ctx, time.Since(start), int64(n), metric.WithAttributes( + attribute.String(storage.AttrFileType, string(b.fileType)), + attribute.String(storage.AttrOutcome, storage.Outcome(err)), + )) + + return n, err + } + fileReadAtTimer.Record(ctx, time.Since(start), int64(n), b.okAttrs) + + return n, err +} + +// readAt fills p from the mapped build segments, optionally in parallel. // Cache eviction or a peer transition re-resolves and retries. -func (b *File) ReadAt(ctx context.Context, p []byte, off int64) (int, error) { +func (b *File) readAt(ctx context.Context, p []byte, off int64) (int, error) { maxParallel := b.store.flags.IntFlag(ctx, featureflags.MaxParallelBuildReadSegments) for { @@ -259,7 +290,7 @@ func (b *File) Slice(ctx context.Context, off, length int64) ([]byte, error) { } } out := make([]byte, length) - if _, err := b.ReadAt(ctx, out, off); err != nil { + if _, err := b.readAt(ctx, out, off); err != nil { return nil, fmt.Errorf("failed to read at: %w", err) } diff --git a/packages/orchestrator/pkg/sandbox/build/softdelete.go b/packages/orchestrator/pkg/sandbox/build/softdelete.go index 79229e9dbe..b04bc1783b 100644 --- a/packages/orchestrator/pkg/sandbox/build/softdelete.go +++ b/packages/orchestrator/pkg/sandbox/build/softdelete.go @@ -84,7 +84,7 @@ func (b *StorageDiff) softDeleteCheck(ctx context.Context, ff *featureflags.Clie if path == "" { return } - blob, err := b.persistence.OpenBlob(ctx, path, storage.MetadataObjectType) + blob, err := b.persistence.OpenBlob(ctx, path) if err != nil { result := classifyCheckError(err) b.recordCheck(ctx, result, false, false) diff --git a/packages/orchestrator/pkg/sandbox/build/storage_diff.go b/packages/orchestrator/pkg/sandbox/build/storage_diff.go index ffed761994..3f7f9a032f 100644 --- a/packages/orchestrator/pkg/sandbox/build/storage_diff.go +++ b/packages/orchestrator/pkg/sandbox/build/storage_diff.go @@ -101,7 +101,7 @@ func newStorageDiff( ff *featureflags.Client, ) (*StorageDiff, error) { cachePath := GenerateDiffCachePath(basePath, buildID, diffType) - c, err := block.NewChunker(ff, uncompressedSize, blockSize, cachePath, metrics) + c, err := block.NewChunker(ff, uncompressedSize, blockSize, cachePath, metrics, storageObjectType) if err != nil { return nil, fmt.Errorf("create chunker for build %s: %w", buildID, err) } @@ -148,7 +148,7 @@ func (b *File) createDiff(ctx context.Context, buildID uuid.UUID) (Diff, error) // LoadHeader backfill marker for an uncompressed V3-or-older ancestor; // UncompressedFullFrameTable IS that ancestor's full table, latch it // to skip a refresh whose header file may not exist. - upstream, dataPath, err = b.openDataFile(ctx, buildID, objType, bd.FrameData.CompressionType()) + upstream, dataPath, err = b.openDataFile(ctx, buildID, bd.FrameData.CompressionType()) if err != nil { return nil, err } @@ -162,7 +162,7 @@ func (b *File) createDiff(ctx context.Context, buildID uuid.UUID) (Diff, error) // missing entries for storage-loaded headers, so storage paths always // hit one of the hasEntry cases). Probe basic-name to detect peer // routing; on miss/transition refresh from storage. - upstream, dataPath, err = b.openDataFile(ctx, buildID, objType, storage.CompressionNone) + upstream, dataPath, err = b.openDataFile(ctx, buildID, storage.CompressionNone) if err != nil { return nil, err } @@ -198,7 +198,7 @@ func (b *File) createDiff(ctx context.Context, buildID uuid.UUID) (Diff, error) b.SwapHeader(loaded) } } - upstream, size, initialFT, dataPath, err = openFromLoadedHeader(ctx, b.persistence, loaded, b.fileType, objType) + upstream, size, initialFT, dataPath, err = openFromLoadedHeader(ctx, b.persistence, loaded, b.fileType) if err != nil { return nil, err } @@ -238,9 +238,9 @@ func (b *File) createDiff(ctx context.Context, buildID uuid.UUID) (Diff, error) return d, nil } -func (b *File) openDataFile(ctx context.Context, buildID uuid.UUID, objType storage.SeekableObjectType, ct storage.CompressionType) (storage.Seekable, string, error) { +func (b *File) openDataFile(ctx context.Context, buildID uuid.UUID, ct storage.CompressionType) (storage.Seekable, string, error) { path := storage.Paths{BuildID: buildID.String()}.DataFile(string(b.fileType), ct) - upstream, err := b.persistence.OpenSeekable(ctx, path, objType) + upstream, err := b.persistence.OpenSeekable(ctx, path) if err != nil { return nil, "", fmt.Errorf("createDiff: open data file for build %s at %s: %w", buildID, path, err) } @@ -253,13 +253,12 @@ func openFromLoadedHeader( persistence storage.StorageProvider, loaded *header.Header, fileType DiffType, - objType storage.SeekableObjectType, ) (storage.Seekable, int64, *storage.FullFrameTable, string, error) { buildID := loaded.Metadata.BuildId paths := storage.Paths{BuildID: buildID.String()} if loaded.Metadata.Version < header.MetadataVersionV4 { path := paths.DataFile(string(fileType), storage.CompressionNone) - upstream, err := persistence.OpenSeekable(ctx, path, objType) + upstream, err := persistence.OpenSeekable(ctx, path) if err != nil { return nil, 0, nil, "", fmt.Errorf("reopen uncompressed upstream for pre-V4 build %s at %s: %w", buildID, path, err) } @@ -271,7 +270,7 @@ func openFromLoadedHeader( return nil, 0, nil, "", err } path := paths.DataFile(string(fileType), ft.Table().CompressionType()) - upstream, err := persistence.OpenSeekable(ctx, path, objType) + upstream, err := persistence.OpenSeekable(ctx, path) if err != nil { return nil, 0, nil, "", fmt.Errorf("reopen upstream for build %s at %s: %w", buildID, path, err) } @@ -465,7 +464,7 @@ func (b *StorageDiff) reloadSourceLocked(ctx context.Context, cause string) erro if err != nil { return fmt.Errorf("reloadSourceLocked: load header for build %s: %w", b.buildID, err) } - upstream, _, ft, dataPath, err := openFromLoadedHeader(ctx, b.persistence, loaded, b.diffType, b.storageObjectType) + upstream, _, ft, dataPath, err := openFromLoadedHeader(ctx, b.persistence, loaded, b.diffType) if err != nil { return fmt.Errorf("reloadSourceLocked: build %s: %w", b.buildID, err) } diff --git a/packages/orchestrator/pkg/sandbox/build/storage_diff_test.go b/packages/orchestrator/pkg/sandbox/build/storage_diff_test.go index 271b30c520..45e09cf3df 100644 --- a/packages/orchestrator/pkg/sandbox/build/storage_diff_test.go +++ b/packages/orchestrator/pkg/sandbox/build/storage_diff_test.go @@ -64,7 +64,7 @@ func TestStorageDiff_LoadsOwnHeaderWhenParentHasNoEntry(t *testing.T) { // Peer-routing probe: non-PeerRouted result → fall through to refresh. probeSeekable := storage.NewMockSeekable(t) provider.EXPECT(). - OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone), mock.Anything). + OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone)). Return(probeSeekable, nil).Once() // Then load A's own header. @@ -75,7 +75,7 @@ func TestStorageDiff_LoadsOwnHeaderWhenParentHasNoEntry(t *testing.T) { return io.Copy(w, bytes.NewReader(aHeaderBytes)) }).Once() provider.EXPECT(). - OpenBlob(mock.Anything, aPaths.HeaderFile(storage.MemfileName), mock.Anything). + OpenBlob(mock.Anything, aPaths.HeaderFile(storage.MemfileName)). Return(headerBlob, nil).Once() // Then open upstream at the compressed path; the read decompresses cleanly. @@ -84,7 +84,7 @@ func TestStorageDiff_LoadsOwnHeaderWhenParentHasNoEntry(t *testing.T) { OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, mock.Anything). RunAndReturn(decompressingRangeReader(compressed)) provider.EXPECT(). - OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionZstd), mock.Anything). + OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionZstd)). Return(compressedSeekable, nil).Once() require.Equal(t, payload[:readLen], runRead(t, bHeader, provider)) @@ -134,7 +134,7 @@ func TestStorageDiff_SwapsHeaderOnSelfMatch(t *testing.T) { // Peer-routing probe: non-PeerRouted result → fall through to refresh. probeSeekable := storage.NewMockSeekable(t) provider.EXPECT(). - OpenSeekable(mock.Anything, paths.DataFile(storage.MemfileName, storage.CompressionNone), mock.Anything). + OpenSeekable(mock.Anything, paths.DataFile(storage.MemfileName, storage.CompressionNone)). Return(probeSeekable, nil).Once() headerBlob := storage.NewMockBlob(t) @@ -144,7 +144,7 @@ func TestStorageDiff_SwapsHeaderOnSelfMatch(t *testing.T) { return io.Copy(w, bytes.NewReader(fullHeaderBytes)) }).Once() provider.EXPECT(). - OpenBlob(mock.Anything, paths.HeaderFile(storage.MemfileName), mock.Anything). + OpenBlob(mock.Anything, paths.HeaderFile(storage.MemfileName)). Return(headerBlob, nil).Once() compressedSeekable := storage.NewMockSeekable(t) @@ -152,7 +152,7 @@ func TestStorageDiff_SwapsHeaderOnSelfMatch(t *testing.T) { OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, mock.Anything). RunAndReturn(decompressingRangeReader(compressed)) provider.EXPECT(). - OpenSeekable(mock.Anything, paths.DataFile(storage.MemfileName, storage.CompressionZstd), mock.Anything). + OpenSeekable(mock.Anything, paths.DataFile(storage.MemfileName, storage.CompressionZstd)). Return(compressedSeekable, nil).Once() got, f := runReadOnFile(t, staleHeader, provider) @@ -188,13 +188,13 @@ func TestStorageDiff_NoRefreshOnFinalizedHeader(t *testing.T) { uncompressedSeekable := storage.NewMockSeekable(t) uncompressedSeekable.EXPECT(). OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, mock.Anything). - RunAndReturn(func(_ context.Context, off, length int64, _ *storage.FrameTable) (storage.RangeReader, error) { + RunAndReturn(func(_ context.Context, off, length int64, _ *storage.FrameTable) (storage.RangeReader, storage.Source, error) { end := min(off+length, int64(len(payload))) - return storage.NewRangeReader(io.NopCloser(bytes.NewReader(payload[off:end]))), nil + return storage.NewRangeReader(io.NopCloser(bytes.NewReader(payload[off:end]))), storage.SourceFS, nil }) provider.EXPECT(). - OpenSeekable(mock.Anything, uncompressedPath, mock.Anything). + OpenSeekable(mock.Anything, uncompressedPath). Return(uncompressedSeekable, nil) // No expectation on OpenBlob — any header fetch panics the test. @@ -235,13 +235,13 @@ func TestStorageDiff_SkipsHeaderRefreshWhenPeerActive(t *testing.T) { Return(int64(payloadSize), nil).Once() uncompressedSeekable.EXPECT(). OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, mock.Anything). - RunAndReturn(func(_ context.Context, off, length int64, _ *storage.FrameTable) (storage.RangeReader, error) { + RunAndReturn(func(_ context.Context, off, length int64, _ *storage.FrameTable) (storage.RangeReader, storage.Source, error) { end := min(off+length, int64(len(payload))) - return storage.NewRangeReader(io.NopCloser(bytes.NewReader(payload[off:end]))), nil + return storage.NewRangeReader(io.NopCloser(bytes.NewReader(payload[off:end]))), storage.SourceFS, nil }) provider.EXPECT(). - OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone), mock.Anything). + OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone)). Return(peerRoutedSeekable{Seekable: uncompressedSeekable}, nil).Once() got, _ := runReadOnFile(t, bHeader, provider) @@ -279,7 +279,7 @@ func TestStorageDiff_V3AncestorFallsBackToUncompressed(t *testing.T) { // initialSize falls through to refresh. probeSeekable := storage.NewMockSeekable(t) provider.EXPECT(). - OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone), mock.Anything). + OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone)). Return(probeSeekable, nil).Once() // Refresh A's header — V3, so openFromLoadedHeader opens at the basic path. @@ -290,7 +290,7 @@ func TestStorageDiff_V3AncestorFallsBackToUncompressed(t *testing.T) { return io.Copy(w, bytes.NewReader(aHeaderBytes)) }).Once() provider.EXPECT(). - OpenBlob(mock.Anything, aPaths.HeaderFile(storage.MemfileName), mock.Anything). + OpenBlob(mock.Anything, aPaths.HeaderFile(storage.MemfileName)). Return(headerBlob, nil).Once() rawSeekable := storage.NewMockSeekable(t) @@ -299,13 +299,13 @@ func TestStorageDiff_V3AncestorFallsBackToUncompressed(t *testing.T) { Return(int64(payloadSize), nil).Once() rawSeekable.EXPECT(). OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, mock.Anything). - RunAndReturn(func(_ context.Context, off, length int64, _ *storage.FrameTable) (storage.RangeReader, error) { + RunAndReturn(func(_ context.Context, off, length int64, _ *storage.FrameTable) (storage.RangeReader, storage.Source, error) { end := min(off+length, int64(len(payload))) - return storage.NewRangeReader(io.NopCloser(bytes.NewReader(payload[off:end]))), nil + return storage.NewRangeReader(io.NopCloser(bytes.NewReader(payload[off:end]))), storage.SourceFS, nil }) provider.EXPECT(). - OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone), mock.Anything). + OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone)). Return(rawSeekable, nil).Once() require.Equal(t, payload[:readLen], runRead(t, bHeader, provider)) @@ -342,19 +342,19 @@ func TestStorageDiff_ReloadSourceLatchesV3AsUncompressed(t *testing.T) { return io.Copy(w, bytes.NewReader(aHeaderBytes)) }).Once() provider.EXPECT(). - OpenBlob(mock.Anything, aPaths.HeaderFile(storage.MemfileName), mock.Anything). + OpenBlob(mock.Anything, aPaths.HeaderFile(storage.MemfileName)). Return(headerBlob, nil).Once() rawSeekable := storage.NewMockSeekable(t) rawSeekable.EXPECT(). OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, mock.Anything). - RunAndReturn(func(_ context.Context, off, length int64, _ *storage.FrameTable) (storage.RangeReader, error) { + RunAndReturn(func(_ context.Context, off, length int64, _ *storage.FrameTable) (storage.RangeReader, storage.Source, error) { end := min(off+length, int64(len(payload))) - return storage.NewRangeReader(io.NopCloser(bytes.NewReader(payload[off:end]))), nil + return storage.NewRangeReader(io.NopCloser(bytes.NewReader(payload[off:end]))), storage.SourceFS, nil }) provider.EXPECT(). - OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone), mock.Anything). + OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone)). Return(rawSeekable, nil).Once() m, err := blockmetrics.NewMetrics(noop.NewMeterProvider()) @@ -406,18 +406,18 @@ func TestStorageDiff_MissingAncestorHeaderFallsBackToUncompressed(t *testing.T) Return(int64(payloadSize), nil).Once() rawSeekable.EXPECT(). OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, mock.Anything). - RunAndReturn(func(_ context.Context, off, length int64, _ *storage.FrameTable) (storage.RangeReader, error) { + RunAndReturn(func(_ context.Context, off, length int64, _ *storage.FrameTable) (storage.RangeReader, storage.Source, error) { end := min(off+length, int64(len(payload))) - return storage.NewRangeReader(io.NopCloser(bytes.NewReader(payload[off:end]))), nil + return storage.NewRangeReader(io.NopCloser(bytes.NewReader(payload[off:end]))), storage.SourceFS, nil }) provider.EXPECT(). - OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone), mock.Anything). + OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone)). Return(rawSeekable, nil).Once() // Header file is missing — the very-old-template case. provider.EXPECT(). - OpenBlob(mock.Anything, aPaths.HeaderFile(storage.MemfileName), mock.Anything). + OpenBlob(mock.Anything, aPaths.HeaderFile(storage.MemfileName)). Return(nil, storage.ErrObjectNotExist).Once() require.Equal(t, payload[:readLen], runRead(t, bHeader, provider)) @@ -460,13 +460,13 @@ func TestStorageDiff_BackfillMarkerLatchesUncompressedAtConstruction(t *testing. Return(int64(payloadSize), nil).Once() rawSeekable.EXPECT(). OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, mock.Anything). - RunAndReturn(func(_ context.Context, off, length int64, _ *storage.FrameTable) (storage.RangeReader, error) { + RunAndReturn(func(_ context.Context, off, length int64, _ *storage.FrameTable) (storage.RangeReader, storage.Source, error) { end := min(off+length, int64(len(payload))) - return storage.NewRangeReader(io.NopCloser(bytes.NewReader(payload[off:end]))), nil + return storage.NewRangeReader(io.NopCloser(bytes.NewReader(payload[off:end]))), storage.SourceFS, nil }) provider.EXPECT(). - OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone), mock.Anything). + OpenSeekable(mock.Anything, aPaths.DataFile(storage.MemfileName, storage.CompressionNone)). Return(rawSeekable, nil).Once() // No OpenBlob expectation: refresh path must NOT fire. @@ -545,14 +545,16 @@ func buildHeader(t *testing.T, selfID uuid.UUID, size int64, mapsTo uuid.UUID) * // requested U-offset in the caller's frame table, slices the compressed // payload, and streams it through a decompressor. Mirrors what a real // Seekable does over zstd-compressed data. -func decompressingRangeReader(compressed []byte) func(context.Context, int64, int64, *storage.FrameTable) (storage.RangeReader, error) { - return func(_ context.Context, offsetU, _ int64, ft *storage.FrameTable) (storage.RangeReader, error) { +func decompressingRangeReader(compressed []byte) func(context.Context, int64, int64, *storage.FrameTable) (storage.RangeReader, storage.Source, error) { + return func(_ context.Context, offsetU, _ int64, ft *storage.FrameTable) (storage.RangeReader, storage.Source, error) { r, err := ft.LocateCompressed(offsetU) if err != nil { - return nil, err + return nil, storage.SourceFS, err } end := min(r.Offset+int64(r.Length), int64(len(compressed))) - return storage.NewDecompressingReader(storage.NewRangeReader(io.NopCloser(bytes.NewReader(compressed[r.Offset:end]))), ft.CompressionType()) + rc, err := storage.NewDecompressReader(storage.NewRangeReader(io.NopCloser(bytes.NewReader(compressed[r.Offset:end]))), ft.CompressionType(), storage.UnknownSource, storage.UnknownSeekableObjectType) + + return rc, storage.SourceFS, err } } diff --git a/packages/orchestrator/pkg/sandbox/build_upload_v3.go b/packages/orchestrator/pkg/sandbox/build_upload_v3.go index fb474a112f..e07301fad6 100644 --- a/packages/orchestrator/pkg/sandbox/build_upload_v3.go +++ b/packages/orchestrator/pkg/sandbox/build_upload_v3.go @@ -62,7 +62,7 @@ func (u *Upload) runV3(ctx context.Context) error { if err != nil { return fmt.Errorf("memfile stat: %w", err) } - _, _, err = storage.UploadFramed(egCtx, u.store, u.paths.Memfile(), storage.MemfileObjectType, memfilePath, meta) + _, _, err = storage.UploadFramed(egCtx, u.store, u.paths.Memfile(), memfilePath, meta) if err != nil { return err } @@ -80,7 +80,7 @@ func (u *Upload) runV3(ctx context.Context) error { if err != nil { return fmt.Errorf("rootfs stat: %w", err) } - _, _, err = storage.UploadFramed(egCtx, u.store, u.paths.Rootfs(), storage.RootFSObjectType, rootfsPath, meta) + _, _, err = storage.UploadFramed(egCtx, u.store, u.paths.Rootfs(), rootfsPath, meta) if err != nil { return err } @@ -96,11 +96,11 @@ func (u *Upload) runV3(ctx context.Context) error { return nil } - return uploadBlobWithMetrics(egCtx, u.store, u.paths.Snapfile(), storage.SnapfileObjectType, u.snap.Snapfile.Path(), uploadFileSnap, meta) + return uploadBlobWithMetrics(egCtx, u.store, u.paths.Snapfile(), u.snap.Snapfile.Path(), uploadFileSnap, meta) }) eg.Go(func() error { - return uploadBlobWithMetrics(egCtx, u.store, u.paths.Metadata(), storage.MetadataObjectType, u.snap.Metafile.Path(), uploadFileMeta, meta) + return uploadBlobWithMetrics(egCtx, u.store, u.paths.Metadata(), u.snap.Metafile.Path(), uploadFileMeta, meta) }) if err := eg.Wait(); err != nil { diff --git a/packages/orchestrator/pkg/sandbox/build_upload_v4.go b/packages/orchestrator/pkg/sandbox/build_upload_v4.go index 1db05b99bc..82fbb31e7a 100644 --- a/packages/orchestrator/pkg/sandbox/build_upload_v4.go +++ b/packages/orchestrator/pkg/sandbox/build_upload_v4.go @@ -61,11 +61,11 @@ func (u *Upload) runV4(ctx context.Context) error { return nil } - return uploadBlobWithMetrics(ctx, u.store, u.paths.Snapfile(), storage.SnapfileObjectType, u.snap.Snapfile.Path(), uploadFileSnap, meta) + return uploadBlobWithMetrics(ctx, u.store, u.paths.Snapfile(), u.snap.Snapfile.Path(), uploadFileSnap, meta) }) eg.Go(func() error { - return uploadBlobWithMetrics(ctx, u.store, u.paths.Metadata(), storage.MetadataObjectType, u.snap.Metafile.Path(), uploadFileMeta, meta) + return uploadBlobWithMetrics(ctx, u.store, u.paths.Metadata(), u.snap.Metafile.Path(), uploadFileMeta, meta) }) return eg.Wait() @@ -81,7 +81,7 @@ func (u *Upload) uploadFramed( var selfBuild headers.BuildData if srcPath != "" { - fullFT, checksum, err := storage.UploadFramed(ctx, u.store, u.paths.DataFile(string(fileType), cfg.CompressionType()), seekableTypeFor(fileType), srcPath, storage.WithCompressConfig(cfg), storage.WithMetadata(u.objectMetadata), storage.WithChecksumSHA256()) + fullFT, checksum, err := storage.UploadFramed(ctx, u.store, u.paths.DataFile(string(fileType), cfg.CompressionType()), srcPath, storage.WithCompressConfig(cfg), storage.WithMetadata(u.objectMetadata), storage.WithChecksumSHA256()) if err != nil { return fmt.Errorf("%s upload: %w", fileType, err) } @@ -187,14 +187,3 @@ func (u *Upload) appendAncestorBuilds( return nil } - -func seekableTypeFor(fileType build.DiffType) storage.SeekableObjectType { - switch fileType { - case build.Memfile: - return storage.MemfileObjectType - case build.Rootfs: - return storage.RootFSObjectType - } - - return storage.UnknownSeekableObjectType -} diff --git a/packages/orchestrator/pkg/sandbox/nbd/testutils/template_rootfs.go b/packages/orchestrator/pkg/sandbox/nbd/testutils/template_rootfs.go index d11e45dc98..292351a561 100644 --- a/packages/orchestrator/pkg/sandbox/nbd/testutils/template_rootfs.go +++ b/packages/orchestrator/pkg/sandbox/nbd/testutils/template_rootfs.go @@ -32,7 +32,7 @@ func TemplateRootfs(ctx context.Context, buildID string) (*BuildDevice, *Cleaner return nil, &cleaner, fmt.Errorf("failed to get storage provider: %w", err) } - obj, err := s.OpenBlob(ctx, paths.RootfsHeader(), storage.RootFSHeaderObjectType) + obj, err := s.OpenBlob(ctx, paths.RootfsHeader()) if err != nil { return nil, &cleaner, fmt.Errorf("failed to open object: %w", err) } @@ -44,7 +44,7 @@ func TemplateRootfs(ctx context.Context, buildID string) (*BuildDevice, *Cleaner return nil, &cleaner, fmt.Errorf("failed to parse build id: %w", err) } - r, err := s.OpenSeekable(ctx, paths.Rootfs(), storage.RootFSObjectType) + r, err := s.OpenSeekable(ctx, paths.Rootfs()) if err != nil { return nil, &cleaner, fmt.Errorf("failed to open object: %w", err) } diff --git a/packages/orchestrator/pkg/sandbox/template/peerclient/blob.go b/packages/orchestrator/pkg/sandbox/template/peerclient/blob.go index 93a677a694..5f0ee8decc 100644 --- a/packages/orchestrator/pkg/sandbox/template/peerclient/blob.go +++ b/packages/orchestrator/pkg/sandbox/template/peerclient/blob.go @@ -7,6 +7,7 @@ import ( "io" "sync" "sync/atomic" + "time" "go.uber.org/zap" @@ -60,7 +61,8 @@ func (b *peerBlob) Metadata(ctx context.Context) (storage.ObjectMetadata, error) } func (b *peerBlob) WriteTo(ctx context.Context, dst io.Writer) (int64, error) { - res, err := tryPeer(ctx, &b.peerHandle, "peer-blob-write-to", attrOpWriteTo, + start := time.Now() + res, err := tryPeer(ctx, &b.peerHandle, "peer-blob-write-to", func(ctx context.Context) (peerAttempt[int64], error) { streamCtx, cancel := context.WithCancel(ctx) @@ -87,6 +89,8 @@ func (b *peerBlob) WriteTo(ctx context.Context, dst io.Writer) (int64, error) { return peerAttempt[int64]{value: n, bytes: n, hit: true}, nil }) if res.hit { + storage.RecordReadBlob(ctx, time.Since(start), res.value, b.name, storage.SourcePeer, err) + return res.value, err } @@ -99,7 +103,7 @@ func (b *peerBlob) WriteTo(ctx context.Context, dst io.Writer) (int64, error) { } func (b *peerBlob) Exists(ctx context.Context) (bool, error) { - res, err := tryPeer(ctx, &b.peerHandle, "peer-blob-exists", attrOpExists, + res, err := tryPeer(ctx, &b.peerHandle, "peer-blob-exists", func(ctx context.Context) (peerAttempt[bool], error) { resp, err := b.client.GetBuildFileExists(ctx, &orchestrator.GetBuildFileExistsRequest{ BuildId: b.buildID, diff --git a/packages/orchestrator/pkg/sandbox/template/peerclient/blob_test.go b/packages/orchestrator/pkg/sandbox/template/peerclient/blob_test.go index 2038326329..708d688bca 100644 --- a/packages/orchestrator/pkg/sandbox/template/peerclient/blob_test.go +++ b/packages/orchestrator/pkg/sandbox/template/peerclient/blob_test.go @@ -60,7 +60,7 @@ func TestPeerBlob_WriteTo_PeerNotAvailable_FallsBackToBase(t *testing.T) { return int64(n), err }) base := storage.NewMockStorageProvider(t) - base.EXPECT().OpenBlob(mock.Anything, "build-1/snapfile", storage.SnapfileObjectType).Return(baseBlob, nil) + base.EXPECT().OpenBlob(mock.Anything, "build-1/snapfile").Return(baseBlob, nil) blob := &peerBlob{ peerHandle: peerHandle{ @@ -70,7 +70,7 @@ func TestPeerBlob_WriteTo_PeerNotAvailable_FallsBackToBase(t *testing.T) { uploaded: &atomic.Bool{}, }, openBase: func(ctx context.Context) (storage.Blob, error) { - return base.OpenBlob(ctx, "build-1/snapfile", storage.SnapfileObjectType) + return base.OpenBlob(ctx, "build-1/snapfile") }, } @@ -94,7 +94,7 @@ func TestPeerBlob_WriteTo_PeerError_FallsBackToBase(t *testing.T) { return int64(n), err }) base := storage.NewMockStorageProvider(t) - base.EXPECT().OpenBlob(mock.Anything, "build-1/snapfile", storage.SnapfileObjectType).Return(baseBlob, nil) + base.EXPECT().OpenBlob(mock.Anything, "build-1/snapfile").Return(baseBlob, nil) blob := &peerBlob{ peerHandle: peerHandle{ @@ -104,7 +104,7 @@ func TestPeerBlob_WriteTo_PeerError_FallsBackToBase(t *testing.T) { uploaded: &atomic.Bool{}, }, openBase: func(ctx context.Context) (storage.Blob, error) { - return base.OpenBlob(ctx, "build-1/snapfile", storage.SnapfileObjectType) + return base.OpenBlob(ctx, "build-1/snapfile") }, } @@ -141,7 +141,7 @@ func TestPeerBlob_WriteTo_UploadedSetMidStream_CompletesFromPeerThenFallsBack(t return int64(n), err }) base := storage.NewMockStorageProvider(t) - base.EXPECT().OpenBlob(mock.Anything, "build-1/snapfile", storage.SnapfileObjectType).Return(baseBlob, nil) + base.EXPECT().OpenBlob(mock.Anything, "build-1/snapfile").Return(baseBlob, nil) blob := &peerBlob{ peerHandle: peerHandle{ @@ -151,7 +151,7 @@ func TestPeerBlob_WriteTo_UploadedSetMidStream_CompletesFromPeerThenFallsBack(t uploaded: uploaded, }, openBase: func(ctx context.Context) (storage.Blob, error) { - return base.OpenBlob(ctx, "build-1/snapfile", storage.SnapfileObjectType) + return base.OpenBlob(ctx, "build-1/snapfile") }, } @@ -194,7 +194,7 @@ func TestPeerBlob_Exists_PeerNotAvailable_FallsBackToBase(t *testing.T) { baseBlob := storage.NewMockBlob(t) baseBlob.EXPECT().Exists(mock.Anything).Return(true, nil) base := storage.NewMockStorageProvider(t) - base.EXPECT().OpenBlob(mock.Anything, "build-1/snapfile", storage.SnapfileObjectType).Return(baseBlob, nil) + base.EXPECT().OpenBlob(mock.Anything, "build-1/snapfile").Return(baseBlob, nil) blob := &peerBlob{ peerHandle: peerHandle{ @@ -204,7 +204,7 @@ func TestPeerBlob_Exists_PeerNotAvailable_FallsBackToBase(t *testing.T) { uploaded: &atomic.Bool{}, }, openBase: func(ctx context.Context) (storage.Blob, error) { - return base.OpenBlob(ctx, "build-1/snapfile", storage.SnapfileObjectType) + return base.OpenBlob(ctx, "build-1/snapfile") }, } @@ -222,7 +222,7 @@ func TestPeerBlob_Exists_UseStorage_FallsBackToBase(t *testing.T) { baseBlob := storage.NewMockBlob(t) baseBlob.EXPECT().Exists(mock.Anything).Return(true, nil) base := storage.NewMockStorageProvider(t) - base.EXPECT().OpenBlob(mock.Anything, "build-1/snapfile", storage.SnapfileObjectType).Return(baseBlob, nil) + base.EXPECT().OpenBlob(mock.Anything, "build-1/snapfile").Return(baseBlob, nil) uploaded := &atomic.Bool{} blob := &peerBlob{ @@ -233,7 +233,7 @@ func TestPeerBlob_Exists_UseStorage_FallsBackToBase(t *testing.T) { uploaded: uploaded, }, openBase: func(ctx context.Context) (storage.Blob, error) { - return base.OpenBlob(ctx, "build-1/snapfile", storage.SnapfileObjectType) + return base.OpenBlob(ctx, "build-1/snapfile") }, } diff --git a/packages/orchestrator/pkg/sandbox/template/peerclient/seekable.go b/packages/orchestrator/pkg/sandbox/template/peerclient/seekable.go index ee0c8a972f..8d973dd99a 100644 --- a/packages/orchestrator/pkg/sandbox/template/peerclient/seekable.go +++ b/packages/orchestrator/pkg/sandbox/template/peerclient/seekable.go @@ -6,6 +6,7 @@ import ( "fmt" "sync" "sync/atomic" + "time" "go.uber.org/zap" @@ -25,7 +26,6 @@ type peerSeekable struct { peerHandle basePersistence storage.StorageProvider - objType storage.SeekableObjectType mu sync.Mutex base storage.Seekable @@ -46,7 +46,7 @@ func (s *peerSeekable) getBase(ctx context.Context, ct storage.CompressionType) path := storage.Paths{BuildID: s.buildID}.DataFile(s.name, ct) - base, err := s.basePersistence.OpenSeekable(ctx, path, s.objType) + base, err := s.basePersistence.OpenSeekable(ctx, path) if err != nil { return nil, err } @@ -68,7 +68,8 @@ func (s *peerSeekable) getBase(ctx context.Context, ct storage.CompressionType) // no wrapper involved. func (s *peerSeekable) Size(ctx context.Context) (int64, error) { - res, err := tryPeer(ctx, &s.peerHandle, "size peer-seekable", attrOpSize, + start := time.Now() + res, err := tryPeer(ctx, &s.peerHandle, "size peer-seekable", func(ctx context.Context) (peerAttempt[int64], error) { resp, err := s.client.GetBuildFileSize(ctx, &orchestrator.GetBuildFileSizeRequest{ BuildId: s.buildID, @@ -84,21 +85,20 @@ func (s *peerSeekable) Size(ctx context.Context) (int64, error) { return peerAttempt[int64]{}, nil }) - if res.hit { - return res.value, err + // On a miss, Size can't resolve the compression type from a caller frame + // table (the basic-name fall-through would 404 on compressed V4 builds), so + // transition to the authoritative header — and record that same transition. + if !res.hit { + err = &storage.PeerTransitionedError{} } + storage.RecordReadSize(ctx, time.Since(start), storage.UnknownSeekableObjectType, storage.SourcePeer, err) - // Size has no caller-provided frame table to source the compression type - // from, and the basic-name fall-through would 404 on compressed V4 builds - // (data lives at .zstd). Surface PeerTransitionedError unconditionally on - // miss so the caller refreshes against the authoritative header — which - // knows the compression type — and either recovers or surfaces a clean "not - // yet on storage" error. - return 0, &storage.PeerTransitionedError{} + return res.value, err } -func (s *peerSeekable) OpenRangeReader(ctx context.Context, off int64, length int64, frameTable *storage.FrameTable) (storage.RangeReader, error) { - res, err := tryPeer(ctx, &s.peerHandle, "peer-seekable-open-range-reader", attrOpRangeReader, +func (s *peerSeekable) OpenRangeReader(ctx context.Context, off int64, length int64, frameTable *storage.FrameTable) (storage.RangeReader, storage.Source, error) { + start := time.Now() + res, err := tryPeer(ctx, &s.peerHandle, "peer-seekable-open-range-reader", func(ctx context.Context) (peerAttempt[storage.RangeReader], error) { streamCtx, cancel := context.WithCancel(ctx) @@ -121,15 +121,26 @@ func (s *peerSeekable) OpenRangeReader(ctx context.Context, off int64, length in }, nil }) if res.hit { - return res.value, err + storage.RecordReadOpen(ctx, time.Since(start), storage.UnknownSeekableObjectType, storage.SourcePeer, frameTable.CompressionType(), err) + + return res.value, storage.SourcePeer, err } + // Record the peer attempt under source=peer so its latency isn't folded into + // the source that ultimately serves the read. file_type is unknown — peer + // routing keys on the build, not the artifact. The outcome must match what we + // return: a transition when uploaded, else a not_found miss that falls to base. + ct := frameTable.CompressionType() if s.uploaded.Load() { - return nil, &storage.PeerTransitionedError{} + err = &storage.PeerTransitionedError{} + storage.RecordReadOpen(ctx, time.Since(start), storage.UnknownSeekableObjectType, storage.SourcePeer, ct, err) + + return nil, storage.SourcePeer, err } + storage.RecordReadOpen(ctx, time.Since(start), storage.UnknownSeekableObjectType, storage.SourcePeer, ct, storage.ErrObjectNotExist) base, err := s.getBase(ctx, frameTable.CompressionType()) if err != nil { - return nil, err + return nil, storage.SourcePeer, err } return base.OpenRangeReader(ctx, off, length, frameTable) diff --git a/packages/orchestrator/pkg/sandbox/template/peerclient/seekable_test.go b/packages/orchestrator/pkg/sandbox/template/peerclient/seekable_test.go index 5c1f8ea9d6..eadf078b64 100644 --- a/packages/orchestrator/pkg/sandbox/template/peerclient/seekable_test.go +++ b/packages/orchestrator/pkg/sandbox/template/peerclient/seekable_test.go @@ -51,7 +51,6 @@ func TestPeerSeekable_Size_PeerNotAvailable_EmitsPeerTransitionedError(t *testin uploaded: &atomic.Bool{}, }, basePersistence: base, - objType: storage.MemfileObjectType, } _, err := s.Size(t.Context()) var transErr *storage.PeerTransitionedError @@ -73,7 +72,7 @@ func TestPeerSeekable_OpenRangeReader_PeerSucceeds(t *testing.T) { })).Return(stream, nil) s := &peerSeekable{peerHandle: peerHandle{client: client, buildID: "build-1", name: storage.MemfileName, uploaded: &atomic.Bool{}}} - rc, err := s.OpenRangeReader(t.Context(), 10, int64(len(data)), nil) + rc, _, err := s.OpenRangeReader(t.Context(), 10, int64(len(data)), nil) require.NoError(t, err) defer rc.Close(t.Context()) @@ -90,10 +89,10 @@ func TestPeerSeekable_OpenRangeReader_PeerError_FallsBackToBase(t *testing.T) { client.EXPECT().ReadAtBuildSeekable(mock.Anything, mock.Anything).Return(nil, errors.New("peer unavailable")) baseSeekable := storage.NewMockSeekable(t) - baseSeekable.EXPECT().OpenRangeReader(mock.Anything, int64(0), int64(len(baseData)), (*storage.FrameTable)(nil)).Return(storage.NewRangeReader(io.NopCloser(bytes.NewReader(baseData))), nil) + baseSeekable.EXPECT().OpenRangeReader(mock.Anything, int64(0), int64(len(baseData)), (*storage.FrameTable)(nil)).Return(storage.NewRangeReader(io.NopCloser(bytes.NewReader(baseData))), storage.SourceFS, nil) base := storage.NewMockStorageProvider(t) - base.EXPECT().OpenSeekable(mock.Anything, "build-1/memfile", storage.MemfileObjectType).Return(baseSeekable, nil) + base.EXPECT().OpenSeekable(mock.Anything, "build-1/memfile").Return(baseSeekable, nil) s := &peerSeekable{ peerHandle: peerHandle{ @@ -103,9 +102,8 @@ func TestPeerSeekable_OpenRangeReader_PeerError_FallsBackToBase(t *testing.T) { uploaded: &atomic.Bool{}, }, basePersistence: base, - objType: storage.MemfileObjectType, } - rc, err := s.OpenRangeReader(t.Context(), 0, int64(len(baseData)), nil) + rc, _, err := s.OpenRangeReader(t.Context(), 0, int64(len(baseData)), nil) require.NoError(t, err) defer rc.Close(t.Context()) @@ -134,10 +132,9 @@ func TestPeerSeekable_OpenRangeReader_Uploaded_ReturnsPeerTransitionedError(t *t uploaded: uploaded, }, basePersistence: base, - objType: storage.MemfileObjectType, } - _, err := s.OpenRangeReader(t.Context(), 0, 100, nil) + _, _, err := s.OpenRangeReader(t.Context(), 0, 100, nil) require.Error(t, err) var transErr *storage.PeerTransitionedError @@ -177,19 +174,20 @@ func TestPeerStorageProvider_TransitionEmitsError(t *testing.T) { base := storage.NewMockStorageProvider(t) p := newPeerStorageProvider(base, client, uploaded) - seekable, err := p.OpenSeekable(t.Context(), "build-1/memfile", storage.MemfileObjectType) + seekable, err := p.OpenSeekable(t.Context(), "build-1/memfile") require.NoError(t, err) - rc, err := seekable.OpenRangeReader(t.Context(), 0, int64(len(prePeerBytes)), + rc, _, err := seekable.OpenRangeReader(t.Context(), 0, int64(len(prePeerBytes)), storage.NewFullFrameTable(storage.CompressionNone, nil).Table()) require.NoError(t, err) got, err := io.ReadAll(rc) require.NoError(t, err) - require.NoError(t, rc.Close(t.Context())) + _, err = rc.Close(t.Context()) + require.NoError(t, err) assert.Equal(t, prePeerBytes, got) require.True(t, uploaded.Load(), "uploaded flag should be set after peer EOF with UseStorage") - _, err = seekable.OpenRangeReader(t.Context(), 0, 1, + _, _, err = seekable.OpenRangeReader(t.Context(), 0, 1, storage.NewFullFrameTable(storage.CompressionNone, nil).Table()) var transErr *storage.PeerTransitionedError require.ErrorAs(t, err, &transErr) diff --git a/packages/orchestrator/pkg/sandbox/template/peerclient/storage.go b/packages/orchestrator/pkg/sandbox/template/peerclient/storage.go index de51c870b8..09699b957c 100644 --- a/packages/orchestrator/pkg/sandbox/template/peerclient/storage.go +++ b/packages/orchestrator/pkg/sandbox/template/peerclient/storage.go @@ -16,24 +16,10 @@ import ( "github.com/e2b-dev/infra/packages/shared/pkg/grpc/orchestrator" "github.com/e2b-dev/infra/packages/shared/pkg/storage" "github.com/e2b-dev/infra/packages/shared/pkg/telemetry" - "github.com/e2b-dev/infra/packages/shared/pkg/utils" ) var ( tracer = otel.Tracer("github.com/e2b-dev/infra/packages/orchestrator/pkg/sandbox/template/peerclient") - meter = otel.Meter("github.com/e2b-dev/infra/packages/orchestrator/pkg/sandbox/template/peerclient") - - peerReadTimerFactory = utils.Must(telemetry.NewTimerFactory(meter, - "orchestrator.storage.peer.read", - "Duration of peer orchestrator reads", - "Total bytes read from peer orchestrator", - "Total peer orchestrator reads", - )) - - attrOpWriteTo = attribute.String("operation", "WriteTo") - attrOpExists = attribute.String("operation", "Exists") - attrOpSize = attribute.String("operation", "Size") - attrOpRangeReader = attribute.String("operation", "OpenRangeReader") attrResolveRedisError = attribute.String("peer_resolve", "redis_error") attrResolveNoPeer = attribute.String("peer_resolve", "no_peer") @@ -92,16 +78,16 @@ func (p *routingProvider) resolveProvider(ctx context.Context, buildID string) s return newPeerStorageProvider(p.base, res.client, res.uploaded) } -func (p *routingProvider) OpenBlob(ctx context.Context, path string, objType storage.ObjectType) (storage.Blob, error) { +func (p *routingProvider) OpenBlob(ctx context.Context, path string) (storage.Blob, error) { buildID, _ := storage.SplitPath(path) - return p.resolveProvider(ctx, buildID).OpenBlob(ctx, path, objType) + return p.resolveProvider(ctx, buildID).OpenBlob(ctx, path) } -func (p *routingProvider) OpenSeekable(ctx context.Context, path string, objType storage.SeekableObjectType) (storage.Seekable, error) { +func (p *routingProvider) OpenSeekable(ctx context.Context, path string) (storage.Seekable, error) { buildID, _ := storage.SplitPath(path) - return p.resolveProvider(ctx, buildID).OpenSeekable(ctx, path, objType) + return p.resolveProvider(ctx, buildID).OpenSeekable(ctx, path) } func (p *routingProvider) DeleteObjectsWithPrefix(ctx context.Context, prefix string) error { @@ -139,7 +125,7 @@ func newPeerStorageProvider( } } -func (p *peerStorageProvider) OpenBlob(_ context.Context, path string, objType storage.ObjectType) (storage.Blob, error) { +func (p *peerStorageProvider) OpenBlob(_ context.Context, path string) (storage.Blob, error) { buildID, t := storage.SplitPath(path) return &peerBlob{ @@ -150,12 +136,12 @@ func (p *peerStorageProvider) OpenBlob(_ context.Context, path string, objType s uploaded: p.uploaded, }, openBase: func(ctx context.Context) (storage.Blob, error) { - return p.base.OpenBlob(ctx, path, objType) + return p.base.OpenBlob(ctx, path) }, }, nil } -func (p *peerStorageProvider) OpenSeekable(_ context.Context, path string, objType storage.SeekableObjectType) (storage.Seekable, error) { +func (p *peerStorageProvider) OpenSeekable(_ context.Context, path string) (storage.Seekable, error) { // Strip any compression suffix so peerSeekable holds the basic name. The // base fallthrough path composes the actual storage path from // (buildID, name, ct) per-call. Peer routing usually engages only @@ -175,7 +161,6 @@ func (p *peerStorageProvider) OpenSeekable(_ context.Context, path string, objTy uploaded: p.uploaded, }, basePersistence: p.base, - objType: objType, }, nil } @@ -232,7 +217,6 @@ func tryPeer[T any]( ctx context.Context, h *peerHandle, spanName string, - opAttr attribute.KeyValue, peerFn func(ctx context.Context) (peerAttempt[T], error), ) (peerAttempt[T], error) { ctx, span := tracer.Start(ctx, spanName, trace.WithAttributes( @@ -246,19 +230,15 @@ func tryPeer[T any]( return peerAttempt[T]{}, nil } - timer := peerReadTimerFactory.Begin(opAttr) - res, err := peerFn(ctx) if res.hit { if err != nil { span.RecordError(err) - timer.Failure(ctx, res.bytes) return res, err } span.SetAttributes(attrPeerHitTrue) - timer.Success(ctx, res.bytes) return res, nil } @@ -267,7 +247,6 @@ func tryPeer[T any]( span.RecordError(err) } - timer.Failure(ctx, 0) span.SetAttributes(attrPeerHitFalse) return peerAttempt[T]{}, nil @@ -282,6 +261,9 @@ type peerStreamReader struct { current *bytes.Reader done bool cancel context.CancelFunc + + bytes int64 + read time.Duration } func newPeerStreamReader(recv func() ([]byte, error), cancel context.CancelFunc) *peerStreamReader { @@ -291,7 +273,13 @@ func newPeerStreamReader(recv func() ([]byte, error), cancel context.CancelFunc) } } -func (r *peerStreamReader) Read(p []byte) (int, error) { +func (r *peerStreamReader) Read(p []byte) (n int, err error) { + t0 := time.Now() + defer func() { + r.read += time.Since(t0) + r.bytes += int64(n) + }() + for { if r.current != nil && r.current.Len() > 0 { return r.current.Read(p) @@ -303,11 +291,12 @@ func (r *peerStreamReader) Read(p []byte) (int, error) { // gRPC Recv returns (nil, io.EOF) separately from the last data message, // so no data is lost here. - data, err := r.recv() + var data []byte + data, err = r.recv() if errors.Is(err, io.EOF) { r.done = true - return 0, io.EOF + continue } if err != nil { return 0, fmt.Errorf("failed to receive chunk from peer: %w", err) @@ -317,8 +306,12 @@ func (r *peerStreamReader) Read(p []byte) (int, error) { } } -func (r *peerStreamReader) Close(context.Context) error { +func (r *peerStreamReader) Close(context.Context) (*storage.ReadStats, error) { r.cancel() - return nil + return &storage.ReadStats{ + StoredBytes: r.bytes, + DeliveredBytes: r.bytes, + Read: r.read, + }, nil } diff --git a/packages/orchestrator/pkg/sandbox/template/peerclient/storage_test.go b/packages/orchestrator/pkg/sandbox/template/peerclient/storage_test.go index ac34565de0..19c9783cb1 100644 --- a/packages/orchestrator/pkg/sandbox/template/peerclient/storage_test.go +++ b/packages/orchestrator/pkg/sandbox/template/peerclient/storage_test.go @@ -30,7 +30,7 @@ func TestPeerStorageProvider_OpenBlob_ExtractsFileName(t *testing.T) { base := storage.NewMockStorageProvider(t) p := newPeerStorageProvider(base, client, &atomic.Bool{}) - blob, err := p.OpenBlob(t.Context(), "build-1/snapfile", storage.SnapfileObjectType) + blob, err := p.OpenBlob(t.Context(), "build-1/snapfile") require.NoError(t, err) var buf bytes.Buffer @@ -50,7 +50,7 @@ func TestPeerStorageProvider_OpenSeekable_ExtractsFileName(t *testing.T) { base := storage.NewMockStorageProvider(t) p := newPeerStorageProvider(base, client, &atomic.Bool{}) - ff, err := p.OpenSeekable(t.Context(), "build-1/memfile", storage.MemfileObjectType) + ff, err := p.OpenSeekable(t.Context(), "build-1/memfile") require.NoError(t, err) size, err := ff.Size(t.Context()) diff --git a/packages/orchestrator/pkg/sandbox/template/storage.go b/packages/orchestrator/pkg/sandbox/template/storage.go index c7170947b8..d0c180bdcd 100644 --- a/packages/orchestrator/pkg/sandbox/template/storage.go +++ b/packages/orchestrator/pkg/sandbox/template/storage.go @@ -24,17 +24,6 @@ type Storage struct { source *build.File } -func objectType(diffType build.DiffType) (storage.SeekableObjectType, bool) { - switch diffType { - case build.Memfile: - return storage.MemfileObjectType, true - case build.Rootfs: - return storage.RootFSObjectType, true - default: - return storage.UnknownSeekableObjectType, false - } -} - func NewStorage( ctx context.Context, store *build.DiffStore, @@ -66,11 +55,6 @@ func NewStorage( // If we can't find the diff header in storage, we try to find the "old" style template without a header as a fallback. if h == nil { - objectType, ok := objectType(fileType) - if !ok { - return nil, build.UnknownDiffTypeError{DiffType: fileType} - } - var dataPath string switch fileType { case build.Memfile: @@ -81,7 +65,7 @@ func NewStorage( return nil, build.UnknownDiffTypeError{DiffType: fileType} } - object, err := persistence.OpenSeekable(ctx, dataPath, objectType) + object, err := persistence.OpenSeekable(ctx, dataPath) if err != nil { return nil, err } diff --git a/packages/orchestrator/pkg/sandbox/template/storage_file.go b/packages/orchestrator/pkg/sandbox/template/storage_file.go index 1c16c120a9..b2a7f02275 100644 --- a/packages/orchestrator/pkg/sandbox/template/storage_file.go +++ b/packages/orchestrator/pkg/sandbox/template/storage_file.go @@ -20,7 +20,6 @@ func newStorageFile( persistence storage.StorageProvider, objectPath string, path string, - objectType storage.ObjectType, ) (*storageFile, error) { f, err := os.Create(path) if err != nil { @@ -29,7 +28,7 @@ func newStorageFile( defer f.Close() - object, err := persistence.OpenBlob(ctx, objectPath, objectType) + object, err := persistence.OpenBlob(ctx, objectPath) if err != nil { return nil, err } diff --git a/packages/orchestrator/pkg/sandbox/template/storage_template.go b/packages/orchestrator/pkg/sandbox/template/storage_template.go index 7601b96198..3f7340c445 100644 --- a/packages/orchestrator/pkg/sandbox/template/storage_template.go +++ b/packages/orchestrator/pkg/sandbox/template/storage_template.go @@ -97,7 +97,6 @@ func (t *storageTemplate) Fetch(ctx context.Context, buildStore *build.DiffStore t.persistence, t.paths.Snapfile(), t.paths.CacheSnapfile(), - storage.SnapfileObjectType, ) if snapfileErr != nil { errMsg := fmt.Errorf("failed to fetch snapfile: %w", snapfileErr) @@ -130,7 +129,6 @@ func (t *storageTemplate) Fetch(ctx context.Context, buildStore *build.DiffStore t.persistence, t.paths.Metadata(), t.paths.CacheMetadata(), - storage.MetadataObjectType, ) if err != nil && !errors.Is(err, storage.ErrObjectNotExist) { sourceErr := fmt.Errorf("failed to fetch metafile: %w", err) diff --git a/packages/orchestrator/pkg/sandbox/upload_metrics.go b/packages/orchestrator/pkg/sandbox/upload_metrics.go index 4e3ac7c004..bf587bc569 100644 --- a/packages/orchestrator/pkg/sandbox/upload_metrics.go +++ b/packages/orchestrator/pkg/sandbox/upload_metrics.go @@ -64,12 +64,12 @@ func storeHeaderWithMetrics(ctx context.Context, store storage.StorageProvider, return nil } -func uploadBlobWithMetrics(ctx context.Context, store storage.StorageProvider, path string, objectType storage.ObjectType, sourcePath, fileType string, opts ...storage.PutOption) error { +func uploadBlobWithMetrics(ctx context.Context, store storage.StorageProvider, path string, sourcePath, fileType string, opts ...storage.PutOption) error { info, err := os.Stat(sourcePath) if err != nil { return fmt.Errorf("%s stat: %w", fileType, err) } - if err := storage.UploadBlob(ctx, store, path, objectType, sourcePath, opts...); err != nil { + if err := storage.UploadBlob(ctx, store, path, sourcePath, opts...); err != nil { return err } recordUploadCompression(ctx, fileType, storage.CompressConfig{}, info.Size(), info.Size()) diff --git a/packages/orchestrator/pkg/template/build/builder.go b/packages/orchestrator/pkg/template/build/builder.go index a3ea7ffc11..1e2a07f473 100644 --- a/packages/orchestrator/pkg/template/build/builder.go +++ b/packages/orchestrator/pkg/template/build/builder.go @@ -470,7 +470,7 @@ func getRootfsSize( s storage.StorageProvider, paths storage.Paths, ) (uint64, error) { - obj, err := s.OpenBlob(ctx, paths.RootfsHeader(), storage.RootFSHeaderObjectType) + obj, err := s.OpenBlob(ctx, paths.RootfsHeader()) if err != nil { return 0, fmt.Errorf("error opening rootfs header object: %w", err) } diff --git a/packages/orchestrator/pkg/template/build/commands/copy.go b/packages/orchestrator/pkg/template/build/commands/copy.go index 7db4bdddd2..828d6d0018 100644 --- a/packages/orchestrator/pkg/template/build/commands/copy.go +++ b/packages/orchestrator/pkg/template/build/commands/copy.go @@ -82,7 +82,7 @@ func (c *Copy) Execute( } // 1) Download the layer tar file from the storage to the local filesystem - obj, err := c.FilesStorage.OpenBlob(ctx, paths.GetLayerFilesCachePath(c.CacheScope, step.GetFilesHash()), storage.BuildLayerFileObjectType) + obj, err := c.FilesStorage.OpenBlob(ctx, paths.GetLayerFilesCachePath(c.CacheScope, step.GetFilesHash())) if err != nil { return metadata.Context{}, fmt.Errorf("failed to open files object from storage: %w", err) } diff --git a/packages/orchestrator/pkg/template/build/storage/cache/cache.go b/packages/orchestrator/pkg/template/build/storage/cache/cache.go index dc37b6e33b..194c3b8581 100644 --- a/packages/orchestrator/pkg/template/build/storage/cache/cache.go +++ b/packages/orchestrator/pkg/template/build/storage/cache/cache.go @@ -64,7 +64,7 @@ func (h *HashIndex) LayerMetaFromHash(ctx context.Context, hash string) (LayerMe ctx, span := tracer.Start(ctx, "get layer_metadata") defer span.End() - obj, err := h.indexStorage.OpenBlob(ctx, paths.HashToPath(h.cacheScope, hash), storage.LayerMetadataObjectType) + obj, err := h.indexStorage.OpenBlob(ctx, paths.HashToPath(h.cacheScope, hash)) if err != nil { return LayerMetadata{}, fmt.Errorf("error opening object for layer metadata: %w", err) } @@ -91,7 +91,7 @@ func (h *HashIndex) SaveLayerMeta(ctx context.Context, hash string, template Lay ctx, span := tracer.Start(ctx, "save layer_metadata") defer span.End() - obj, err := h.indexStorage.OpenBlob(ctx, paths.HashToPath(h.cacheScope, hash), storage.LayerMetadataObjectType) + obj, err := h.indexStorage.OpenBlob(ctx, paths.HashToPath(h.cacheScope, hash)) if err != nil { return fmt.Errorf("error creating object for saving UUID: %w", err) } diff --git a/packages/orchestrator/pkg/template/metadata/prefetch.go b/packages/orchestrator/pkg/template/metadata/prefetch.go index b12abc75cd..d6796d9556 100644 --- a/packages/orchestrator/pkg/template/metadata/prefetch.go +++ b/packages/orchestrator/pkg/template/metadata/prefetch.go @@ -53,7 +53,7 @@ func UploadMetadata(ctx context.Context, persistence storage.StorageProvider, t metadataPath := storage.Paths{BuildID: t.Template.BuildID}.Metadata() - object, err := persistence.OpenBlob(ctx, metadataPath, storage.MetadataObjectType) + object, err := persistence.OpenBlob(ctx, metadataPath) if err != nil { return fmt.Errorf("failed to open metadata object: %w", err) } diff --git a/packages/orchestrator/pkg/template/metadata/template_metadata.go b/packages/orchestrator/pkg/template/metadata/template_metadata.go index 1534217ce8..0d764f0dda 100644 --- a/packages/orchestrator/pkg/template/metadata/template_metadata.go +++ b/packages/orchestrator/pkg/template/metadata/template_metadata.go @@ -221,7 +221,7 @@ func fromTemplate(ctx context.Context, s storage.StorageProvider, paths storage. ctx, span := tracer.Start(ctx, "from template") defer span.End() - obj, err := s.OpenBlob(ctx, paths.Metadata(), storage.MetadataObjectType) + obj, err := s.OpenBlob(ctx, paths.Metadata()) if err != nil { return Template{}, fmt.Errorf("error opening object for template metadata: %w", err) } diff --git a/packages/orchestrator/pkg/template/server/upload_layer_files_template.go b/packages/orchestrator/pkg/template/server/upload_layer_files_template.go index 2776500077..17626a1117 100644 --- a/packages/orchestrator/pkg/template/server/upload_layer_files_template.go +++ b/packages/orchestrator/pkg/template/server/upload_layer_files_template.go @@ -9,7 +9,6 @@ import ( "github.com/e2b-dev/infra/packages/orchestrator/pkg/template/build/storage/paths" templatemanager "github.com/e2b-dev/infra/packages/shared/pkg/grpc/template-manager" - "github.com/e2b-dev/infra/packages/shared/pkg/storage" ) const signedUrlExpiration = time.Minute * 30 @@ -25,7 +24,7 @@ func (s *ServerStore) InitLayerFileUpload(ctx context.Context, in *templatemanag } path := paths.GetLayerFilesCachePath(cacheScope, in.GetHash()) - obj, err := s.buildStorage.OpenBlob(ctx, path, storage.BuildLayerFileObjectType) + obj, err := s.buildStorage.OpenBlob(ctx, path) if err != nil { return nil, fmt.Errorf("failed to open layer files cache: %w", err) } diff --git a/packages/shared/pkg/storage/compress_decode.go b/packages/shared/pkg/storage/compress_decode.go index a0a706bab3..3c5bf76b35 100644 --- a/packages/shared/pkg/storage/compress_decode.go +++ b/packages/shared/pkg/storage/compress_decode.go @@ -2,6 +2,7 @@ package storage import ( "context" + "errors" "fmt" "io" "sync" @@ -56,25 +57,36 @@ func putZstdDecoder(dec *zstd.Decoder) { zstdDecoderPool.Put(dec) } -// decompressReader decompresses inner on Read; Close releases the codec back -// to its pool and closes inner. +// decompressReader meters raw source pulls (meteredIn) separately from decoded +// output (meteredOut) so read.decompress can split source-read wall from +// decompression CPU on Close. type decompressReader struct { inner RangeReader - dec io.Reader + meteredIn *meteredReader + meteredOut *meteredReader releaseCodec func() + ct CompressionType + source Source + objType SeekableObjectType + readErr error } -func NewDecompressingReader(inner RangeReader, ct CompressionType) (RangeReader, error) { +// NewDecompressReader wraps inner with a decoder for ct, attributing +// read.decompress to src/ot. Callers without that context (tests) pass +// UnknownSource / UnknownSeekableObjectType. +func NewDecompressReader(inner RangeReader, ct CompressionType, src Source, ot SeekableObjectType) (RangeReader, error) { + metered := &meteredReader{inner: inner} + var dec io.Reader var releaseCodec func() switch ct { case CompressionLZ4: - d := getLZ4Decoder(inner) + d := getLZ4Decoder(metered) dec, releaseCodec = d, func() { putLZ4Decoder(d) } case CompressionZstd: - d, err := getZstdDecoder(inner) + d, err := getZstdDecoder(metered) if err != nil { return nil, fmt.Errorf("failed to create zstd decoder: %w", err) } @@ -86,17 +98,37 @@ func NewDecompressingReader(inner RangeReader, ct CompressionType) (RangeReader, return &decompressReader{ inner: inner, - dec: dec, + meteredIn: metered, + meteredOut: &meteredReader{inner: dec}, releaseCodec: releaseCodec, + ct: ct, + source: src, + objType: ot, }, nil } func (r *decompressReader) Read(p []byte) (int, error) { - return r.dec.Read(p) + n, err := r.meteredOut.Read(p) + if err != nil && !errors.Is(err, io.EOF) { + r.readErr = err + } + + return n, err } -func (r *decompressReader) Close(ctx context.Context) error { +func (r *decompressReader) Close(ctx context.Context) (*ReadStats, error) { r.releaseCodec() - return r.inner.Close(ctx) + stats := &ReadStats{ + StoredBytes: r.meteredIn.bytes, + DeliveredBytes: r.meteredOut.bytes, + Read: r.meteredIn.read, + Decompress: max(0, r.meteredOut.read-r.meteredIn.read), + } + + recordDecompressStep(ctx, r, stats, r.readErr) + + _, innerErr := r.inner.Close(ctx) + + return stats, innerErr } diff --git a/packages/shared/pkg/storage/compress_frame_table.go b/packages/shared/pkg/storage/compress_frame_table.go index aa37f68326..196f44d681 100644 --- a/packages/shared/pkg/storage/compress_frame_table.go +++ b/packages/shared/pkg/storage/compress_frame_table.go @@ -14,7 +14,11 @@ const ( CompressionNone = CompressionType(iota) CompressionZstd CompressionLZ4 + // numCompressionTypes counts the codecs above; keep last so it auto-updates. + numCompressionTypes +) +const ( // maxDeserializedFrames caps the number of frames read from a serialized // FrameTable to prevent OOM from corrupted headers. 1M frames = 2 TiB // uncompressed at 2 MiB frame size. diff --git a/packages/shared/pkg/storage/header/serialization.go b/packages/shared/pkg/storage/header/serialization.go index d62ef8d90d..1280303515 100644 --- a/packages/shared/pkg/storage/header/serialization.go +++ b/packages/shared/pkg/storage/header/serialization.go @@ -4,6 +4,7 @@ import ( "context" "errors" "fmt" + "time" "github.com/google/uuid" @@ -80,17 +81,21 @@ func backfillMissingV3UncompressedBuilds(h *Header) { // it to throughput telemetry. Errors (including storage.ErrObjectNotExist) are // returned as-is. func LoadHeader(ctx context.Context, s storage.StorageProvider, path string) (*Header, int, error) { - blob, err := s.OpenBlob(ctx, path, storage.MetadataObjectType) + blob, err := s.OpenBlob(ctx, path) if err != nil { return nil, 0, fmt.Errorf("open blob %s: %w", path, err) } + // read.blob (the transfer) is emitted per-layer inside each backend WriteTo; + // only the deserialize/decompress phase below is single-layer. data, err := storage.GetBlob(ctx, blob) if err != nil { return nil, 0, err } + decStart := time.Now() h, err := DeserializeBytes(data) + storage.RecordReadBlobDecompress(ctx, time.Since(decStart), int64(len(data)), path, headerCodec(h), err) if err != nil { return nil, len(data), err } @@ -102,6 +107,20 @@ func LoadHeader(ctx context.Context, s storage.StorageProvider, path string) (*H return h, len(data), nil } +// headerCodec reports a header format's inner compression (V4/V5 use LZ4). +// Nil-safe for the failed-deserialize path. +func headerCodec(h *Header) storage.CompressionType { + if h == nil { + return storage.CompressionNone + } + switch metadataFormatVersion(h.Metadata.Version) { + case MetadataVersionV4, MetadataVersionV5: + return storage.CompressionLZ4 + default: + return storage.CompressionNone + } +} + // StoreHeader serializes a header, uploads it, and returns the effective // compression config plus the stored and pre-compression byte counts. V3 has // no inner compression so the counts match and cfg is the zero value. Refuses @@ -148,7 +167,7 @@ func StoreHeader(ctx context.Context, s storage.StorageProvider, path string, h return storage.CompressConfig{}, 0, 0, fmt.Errorf("unsupported header version %d", h.Metadata.Version) } - blob, err := s.OpenBlob(ctx, path, storage.MetadataObjectType) + blob, err := s.OpenBlob(ctx, path) if err != nil { return storage.CompressConfig{}, 0, 0, fmt.Errorf("open blob %s: %w", path, err) } diff --git a/packages/shared/pkg/storage/io_wrappers.go b/packages/shared/pkg/storage/io_wrappers.go index 18d5e5ebba..413128ad99 100644 --- a/packages/shared/pkg/storage/io_wrappers.go +++ b/packages/shared/pkg/storage/io_wrappers.go @@ -6,54 +6,112 @@ import ( "errors" "io" "os" + "time" "go.opentelemetry.io/otel/trace" - - "github.com/e2b-dev/infra/packages/shared/pkg/telemetry" ) var ( + _ io.Reader = (*meteredReader)(nil) _ RangeReader = (*sectionReader)(nil) - _ RangeReader = (*observableReader)(nil) + _ RangeReader = (*spanReader)(nil) _ RangeReader = (*rangeReader)(nil) _ RangeReader = (*captureReader)(nil) ) -// rangeReader adapts an io.ReadCloser into a RangeReader by ignoring the -// Close context. +// readMeter accumulates bytes read and time spent reading. Embed it in a reader +// that meters its own source inline: call observe() in Read, stats() in Close. +// Unlike meteredReader it does not wrap anything, so there is no ambiguity about +// which object to read from. +type readMeter struct { + bytes int64 + read time.Duration +} + +func (m *readMeter) observe(n int, since time.Time) { + m.bytes += int64(n) + m.read += time.Since(since) +} + +// stats reports the meter as a ReadStats. Stored and delivered counts are equal — +// these readers don't decompress (decompressReader builds its own). +func (m *readMeter) stats() *ReadStats { + return &ReadStats{ + StoredBytes: m.bytes, + DeliveredBytes: m.bytes, + Read: m.read, + } +} + +// rangeReader adapts an io.ReadCloser into a self-metering RangeReader. type rangeReader struct { - io.ReadCloser + readMeter + + rc io.ReadCloser } -func NewRangeReader(rc io.ReadCloser) RangeReader { return &rangeReader{ReadCloser: rc} } +func NewRangeReader(rc io.ReadCloser) RangeReader { return &rangeReader{rc: rc} } + +func (r *rangeReader) Read(p []byte) (int, error) { + t0 := time.Now() + n, err := r.rc.Read(p) + r.observe(n, t0) -func (p *rangeReader) Close(context.Context) error { - return p.ReadCloser.Close() + return n, err +} + +func (r *rangeReader) Close(context.Context) (*ReadStats, error) { + return r.stats(), r.rc.Close() } type sectionReader struct { - *io.SectionReader + readMeter + sr *io.SectionReader file *os.File } func newSectionReader(f *os.File, off, length int64) *sectionReader { return §ionReader{ - SectionReader: io.NewSectionReader(f, off, length), - file: f, + sr: io.NewSectionReader(f, off, length), + file: f, } } -func (r *sectionReader) Close(context.Context) error { - return r.file.Close() +func (r *sectionReader) Read(p []byte) (int, error) { + t0 := time.Now() + n, err := r.sr.Read(p) + r.observe(n, t0) + + return n, err +} + +func (r *sectionReader) Close(context.Context) (*ReadStats, error) { + return r.stats(), r.file.Close() +} + +// meteredReader meters reads pulled through it by a downstream consumer (a +// decoder in the decompress pipeline), where inline metering isn't possible +// because this reader isn't the one calling the source's Read. +type meteredReader struct { + readMeter + + inner io.Reader +} + +func (m *meteredReader) Read(p []byte) (int, error) { + t0 := time.Now() + n, err := m.inner.Read(p) + m.observe(n, t0) + + return n, err } // captureReader tees every read byte into a buffer and hands the captured -// bytes to onClose on Close. Used by the cache writeback paths. -// +// bytes to onClose on Close. Used by the compressed cache writeback path. // drainOnClose=true reads inner to EOF on Close even if the caller above hasn't -// consumed everything. Needed when capturing under a decoder that stops short -// of EOF on its source (e.g. lz4.Reader skips the 4-byte EndMark). +// consumed everything — the compressed cache needs the full frame regardless +// of how many bytes the decoder happened to demand. type captureReader struct { inner RangeReader buf *bytes.Buffer @@ -79,38 +137,33 @@ func (r *captureReader) Read(p []byte) (int, error) { return n, err } -func (r *captureReader) Close(ctx context.Context) error { +func (r *captureReader) Close(ctx context.Context) (*ReadStats, error) { if r.drainOnClose { _, _ = io.Copy(io.Discard, r) } - err := r.inner.Close(ctx) + stats, err := r.inner.Close(ctx) if err == nil { r.onClose(ctx, r.buf.Bytes()) } - return err + return stats, err } -// observableReader layers OTEL observability (legacy per-backend timer + span) -// onto an inner RangeReader, all applied on Close. timer and span are optional; -// pass nil if unused. -type observableReader struct { - inner RangeReader - timer *telemetry.Stopwatch - span trace.Span - - bytes int64 +// spanReader ends a trace span on Close, recording the close error or the first +// non-EOF read error against it. Stats pass through from inner, which (like every +// RangeReader) self-reports them. +type spanReader struct { + inner RangeReader + span trace.Span readErr error } -func newObservableReader(inner RangeReader, timer *telemetry.Stopwatch, span trace.Span) *observableReader { - return &observableReader{inner: inner, timer: timer, span: span} +func newSpanReader(inner RangeReader, span trace.Span) *spanReader { + return &spanReader{inner: inner, span: span} } -func (r *observableReader) Read(p []byte) (int, error) { +func (r *spanReader) Read(p []byte) (int, error) { n, err := r.inner.Read(p) - r.bytes += int64(n) - if err != nil && !errors.Is(err, io.EOF) { r.readErr = err } @@ -118,26 +171,15 @@ func (r *observableReader) Read(p []byte) (int, error) { return n, err } -func (r *observableReader) Close(ctx context.Context) error { - closeErr := r.inner.Close(ctx) - - if r.timer != nil { - if r.readErr != nil || closeErr != nil { - r.timer.Failure(ctx, r.bytes) - } else { - r.timer.Success(ctx, r.bytes) - } - } - - if r.span != nil { - if closeErr != nil { - recordError(r.span, closeErr) - } else if r.readErr != nil { - recordError(r.span, r.readErr) - } +func (r *spanReader) Close(ctx context.Context) (*ReadStats, error) { + stats, closeErr := r.inner.Close(ctx) - r.span.End() + if closeErr != nil { + recordError(r.span, closeErr) + } else if r.readErr != nil { + recordError(r.span, r.readErr) } + r.span.End() - return closeErr + return stats, closeErr } diff --git a/packages/shared/pkg/storage/metrics.go b/packages/shared/pkg/storage/metrics.go new file mode 100644 index 0000000000..239d14ae4b --- /dev/null +++ b/packages/shared/pkg/storage/metrics.go @@ -0,0 +1,303 @@ +package storage + +import ( + "context" + "errors" + "io/fs" + "time" + + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/metric" + + "github.com/e2b-dev/infra/packages/shared/pkg/storage/lock" + "github.com/e2b-dev/infra/packages/shared/pkg/telemetry" + "github.com/e2b-dev/infra/packages/shared/pkg/utils" +) + +// Attribute vocabulary for the orchestrator.read.* / orchestrator.chunk.* / +// orchestrator.writeback metrics. +const ( + AttrSource = "source" + AttrCodec = "codec" + AttrOutcome = "outcome" + AttrFileType = "file_type" + AttrTrigger = "trigger" +) + +// Writeback triggers: a read-miss cache fill vs a build/store write-through. +const ( + TriggerRead = "read" + TriggerWrite = "write" +) + +const ( + OutcomeOK = "ok" + OutcomeNotFound = "not_found" + OutcomeErrCanceled = "err_canceled" + OutcomeErrIO = "err_io" + OutcomeErrTimeout = "err_timeout" + OutcomeTransitioned = "transitioned" + // OutcomeContended is a writeback skipped because another goroutine held the + // NFS chunk lock — normal cache dedup, nothing written. + OutcomeContended = "contended" +) + +// Source identifies the backend that served a read. +type Source int8 + +const ( + // Order is latency-ascending and load-bearing: Slice records the slowest + // source it touched via max() over per-fetch sources. + UnknownSource Source = iota + SourceMmap + SourceFS + SourcePeer + SourceNFS + SourceGCS + SourceAWS + numSources +) + +func (s Source) String() string { return sourceStrings[s] } + +var sourceStrings = [numSources]string{ + UnknownSource: "unknown", + SourceMmap: "mmap", + SourceFS: "fs", + SourcePeer: "peer", + SourceNFS: "nfs", + SourceGCS: "gcs", + SourceAWS: "aws", +} + +// Outcome maps a read-path error to the outcome enum. PeerTransitionedError is a +// routing signal, not a failure, so it gets its own bucket (not err_io). +func Outcome(err error) string { + var transErr *PeerTransitionedError + switch { + case err == nil: + return OutcomeOK + case errors.Is(err, ErrObjectNotExist), errors.Is(err, fs.ErrNotExist): + return OutcomeNotFound + case errors.Is(err, context.Canceled): + return OutcomeErrCanceled + case errors.Is(err, context.DeadlineExceeded): + return OutcomeErrTimeout + case errors.As(err, &transErr): + return OutcomeTransitioned + case errors.Is(err, lock.ErrLockAlreadyHeld): + return OutcomeContended + default: + return OutcomeErrIO + } +} + +// numCodecs tracks the CompressionType enum so a new codec grows the table +// instead of being clamped to none in safeAttrIdx. +const numCodecs = int(numCompressionTypes) + +// tableOK precomputes the OK-outcome attribute set for the hot path; error and +// blob paths build attrs inline. +var tableOK [numSeekableObjectTypes][numSources][numCodecs]metric.MeasurementOption + +func init() { + set := func(kvs ...attribute.KeyValue) metric.MeasurementOption { + return metric.WithAttributeSet(attribute.NewSet(kvs...)) + } + + for ot := range numSeekableObjectTypes { + ftAttr := attribute.String(AttrFileType, ot.String()) + for s := range numSources { + srcAttr := attribute.String(AttrSource, sourceStrings[s]) + for ct := range CompressionType(numCodecs) { + tableOK[ot][s][ct] = set(ftAttr, srcAttr, + attribute.String(AttrCodec, ct.String()), + attribute.String(AttrOutcome, OutcomeOK)) + } + } + } +} + +func safeAttrIdx(o SeekableObjectType, s Source, c CompressionType) (SeekableObjectType, Source, CompressionType) { + if uint(o) >= uint(numSeekableObjectTypes) { + o = UnknownSeekableObjectType + } + if uint(s) >= uint(numSources) { + s = UnknownSource + } + if uint(c) >= uint(numCodecs) { + c = CompressionNone + } + + return o, s, c +} + +func OKAttrs(o SeekableObjectType, s Source, c CompressionType) metric.MeasurementOption { + o, s, c = safeAttrIdx(o, s, c) + + return tableOK[o][s][c] +} + +func ErrAttrs(o SeekableObjectType, s Source, c CompressionType, err error) metric.MeasurementOption { + return metric.WithAttributes( + attribute.String(AttrFileType, o.String()), + attribute.String(AttrSource, s.String()), + attribute.String(AttrCodec, c.String()), + attribute.String(AttrOutcome, Outcome(err)), + ) +} + +func mustFloatHist(name, desc, unit string) metric.Float64Histogram { + return utils.Must(meter.Float64Histogram(name, + metric.WithDescription(desc), + metric.WithUnit(unit), + )) +} + +var ( + readOpen = utils.Must(telemetry.NewFloatTimerFactory(meter, + "orchestrator.read.open", + "OpenRangeReader (open / TTFB) wall", + "Bytes (always 0 — open transfers no payload)", + )) + readRead = utils.Must(telemetry.NewFloatTimerFactory(meter, + "orchestrator.read.read", + "Raw source-read wall (decompression excluded)", + "Compressed/stored bytes read from the source", + )) + readDecompress = utils.Must(telemetry.NewFloatTimerFactory(meter, + "orchestrator.read.decompress", + "Decompression CPU wall (decoder read time minus source transfer)", + "Uncompressed bytes produced", + )) + readFetch = utils.Must(telemetry.NewFloatTimerFactory(meter, + "orchestrator.read.fetch", + "Total fetch wall — should ≈ open + read + decompress; any excess is overhead (see read.pipeline.efficiency)", + "Bytes delivered to the app", + )) + readPipelineEfficiency = mustFloatHist( + "orchestrator.read.pipeline.efficiency", + "fetch / (open + read + decompress) — 1.0 = fetch wall fully explained by work, >1 = overhead", "1", + ) + + // writeback covers every NFS cache write: a read-miss fill (trigger=read) or + // a build/store write-through (trigger=write). A dedup skip is outcome=contended. + writeback = utils.Must(telemetry.NewFloatTimerFactory(meter, + "orchestrator.writeback", + "NFS cache write wall", + "Bytes written to NFS", + )) + + // Size() transfers nothing, so duration + count only (no bytes counter). + readSize = utils.Must(meter.Float64Histogram( + "orchestrator.read.size", + metric.WithDescription("Size() metadata-lookup wall"), + metric.WithUnit("ms"), + metric.WithExplicitBucketBoundaries(telemetry.SubMillisecondMsBuckets...), + )) + readSizeCount = utils.Must(meter.Int64Counter( + "orchestrator.read.size", + metric.WithDescription("Total orchestrator.read.size events recorded"), + )) + + // read.blob / read.blob.decompress: the blob-path analog of read.read / + // read.decompress. read.blob carries source — the transfer cascades + // peer->NFS->leaf and is recorded per layer; read.blob.decompress is CPU on + // resolved bytes, so it has none. + readBlob = utils.Must(telemetry.NewFloatTimerFactory(meter, + "orchestrator.read.blob", + "Whole-object blob transfer (WriteTo) wall", + "Bytes transferred", + )) + readBlobDecompress = utils.Must(telemetry.NewFloatTimerFactory(meter, + "orchestrator.read.blob.decompress", + "Blob deserialize/decompress wall (e.g. header LZ4 decode + parse)", + "Uncompressed bytes produced", + )) +) + +// RecordReadOpen records one layer's own open attempt (not the delegated inner +// call), so a slow peer/NFS open isn't misattributed to the resolved source. +func RecordReadOpen(ctx context.Context, dur time.Duration, ot SeekableObjectType, src Source, ct CompressionType, err error) { + attrs := OKAttrs(ot, src, ct) + if err != nil { + attrs = ErrAttrs(ot, src, ct, err) + } + readOpen.Record(ctx, dur, 0, attrs) +} + +func RecordReadRead(ctx context.Context, dur time.Duration, bytes int64, attrs metric.MeasurementOption) { + readRead.Record(ctx, dur, bytes, attrs) +} + +func recordDecompressStep(ctx context.Context, r *decompressReader, stats *ReadStats, readErr error) { + attrs := OKAttrs(r.objType, r.source, r.ct) + if readErr != nil { + attrs = ErrAttrs(r.objType, r.source, r.ct, readErr) + } + readDecompress.Record(ctx, stats.Decompress, stats.DeliveredBytes, attrs) +} + +func RecordReadFetch(ctx context.Context, dur time.Duration, bytes int64, attrs metric.MeasurementOption) { + readFetch.Record(ctx, dur, bytes, attrs) +} + +func RecordPipelineEfficiency(ctx context.Context, ratio float64, attrs metric.MeasurementOption) { + readPipelineEfficiency.Record(ctx, ratio, attrs) +} + +// recordWriteback emits orchestrator.writeback. src is the byte origin (the +// read's fetch source, or fs for a build write-through); the write itself always +// targets NFS. trigger is TriggerRead/TriggerWrite. A contended skip wrote +// nothing, so its byte count is zeroed. +func recordWriteback(ctx context.Context, dur time.Duration, bytes int64, ot SeekableObjectType, src Source, ct CompressionType, trigger string, err error) { + outcome := Outcome(err) + if outcome == OutcomeContended { + bytes = 0 + } + writeback.Record(ctx, dur, bytes, metric.WithAttributes( + attribute.String(AttrFileType, ot.String()), + attribute.String(AttrSource, src.String()), + attribute.String(AttrCodec, ct.String()), + attribute.String(AttrOutcome, outcome), + attribute.String(AttrTrigger, trigger), + )) +} + +func RecordReadSize(ctx context.Context, dur time.Duration, ot SeekableObjectType, src Source, err error) { + attrs := OKAttrs(ot, src, CompressionNone) + if err != nil { + attrs = ErrAttrs(ot, src, CompressionNone, err) + } + readSize.Record(ctx, float64(dur)/float64(time.Millisecond), attrs) + readSizeCount.Add(ctx, 1, attrs) +} + +// blob file_type is not a SeekableObjectType, so read.blob* build attrs inline +// rather than via the precomputed OKAttrs table. +func RecordReadBlob(ctx context.Context, dur time.Duration, bytes int64, path string, src Source, err error) { + readBlob.Record(ctx, dur, bytes, metric.WithAttributes( + attribute.String(AttrFileType, blobType(path)), + attribute.String(AttrSource, src.String()), + attribute.String(AttrCodec, CompressionNone.String()), + attribute.String(AttrOutcome, Outcome(err)), + )) +} + +func RecordReadBlobDecompress(ctx context.Context, dur time.Duration, bytes int64, path string, ct CompressionType, err error) { + readBlobDecompress.Record(ctx, dur, bytes, metric.WithAttributes( + attribute.String(AttrFileType, blobType(path)), + attribute.String(AttrCodec, ct.String()), + attribute.String(AttrOutcome, Outcome(err)), + )) +} + +var meter = otel.Meter("github.com/e2b-dev/infra/packages/shared/pkg/storage") + +var googleWriteTimerFactory = utils.Must(telemetry.NewTimerFactory(meter, + "orchestrator.storage.gcs.write", + "Duration of GCS writes", + "Total bytes written to GCS", + "Total writes to GCS", +)) diff --git a/packages/shared/pkg/storage/metrics_test.go b/packages/shared/pkg/storage/metrics_test.go new file mode 100644 index 0000000000..c128ed7f2f --- /dev/null +++ b/packages/shared/pkg/storage/metrics_test.go @@ -0,0 +1,52 @@ +package storage + +import ( + "context" + "errors" + "testing" + + "github.com/stretchr/testify/require" +) + +func TestSourceStringsPopulated(t *testing.T) { + t.Parallel() + + for s := range numSources { + require.NotEmptyf(t, s.String(), "source %d has empty string label", s) + } +} + +func TestSeekableObjectTypeStrings(t *testing.T) { + t.Parallel() + + require.Equal(t, "memfile", MemfileObjectType.String()) + require.Equal(t, "rootfs", RootFSObjectType.String()) + require.Equal(t, "unknown", UnknownSeekableObjectType.String()) + for o := range numSeekableObjectTypes { + require.NotEmptyf(t, o.String(), "object type %d has empty file_type label", o) + } +} + +func TestOutcomeMapping(t *testing.T) { + t.Parallel() + + require.Equal(t, OutcomeOK, Outcome(nil)) + require.Equal(t, OutcomeErrCanceled, Outcome(context.Canceled)) + require.Equal(t, OutcomeErrTimeout, Outcome(context.DeadlineExceeded)) + require.Equal(t, OutcomeErrIO, Outcome(errors.New("boom"))) +} + +// TestPrecomputedAttrsPopulated guards the invariant that every emission site +// finds a non-nil precomputed attribute set — no enum combination is missed by +// the init() loops. +func TestPrecomputedAttrsPopulated(t *testing.T) { + t.Parallel() + + for o := range numSeekableObjectTypes { + for s := range numSources { + for c := range CompressionType(numCodecs) { + require.NotNil(t, OKAttrs(o, s, c)) + } + } + } +} diff --git a/packages/shared/pkg/storage/mock_seekable.go b/packages/shared/pkg/storage/mock_seekable.go index 6c3e18a4fc..3fa5665c56 100644 --- a/packages/shared/pkg/storage/mock_seekable.go +++ b/packages/shared/pkg/storage/mock_seekable.go @@ -38,7 +38,7 @@ func (_m *MockSeekable) EXPECT() *MockSeekable_Expecter { } // OpenRangeReader provides a mock function for the type MockSeekable -func (_mock *MockSeekable) OpenRangeReader(ctx context.Context, offsetU int64, length int64, frameTable *FrameTable) (RangeReader, error) { +func (_mock *MockSeekable) OpenRangeReader(ctx context.Context, offsetU int64, length int64, frameTable *FrameTable) (RangeReader, Source, error) { ret := _mock.Called(ctx, offsetU, length, frameTable) if len(ret) == 0 { @@ -46,8 +46,9 @@ func (_mock *MockSeekable) OpenRangeReader(ctx context.Context, offsetU int64, l } var r0 RangeReader - var r1 error - if returnFunc, ok := ret.Get(0).(func(context.Context, int64, int64, *FrameTable) (RangeReader, error)); ok { + var r1 Source + var r2 error + if returnFunc, ok := ret.Get(0).(func(context.Context, int64, int64, *FrameTable) (RangeReader, Source, error)); ok { return returnFunc(ctx, offsetU, length, frameTable) } if returnFunc, ok := ret.Get(0).(func(context.Context, int64, int64, *FrameTable) RangeReader); ok { @@ -57,12 +58,17 @@ func (_mock *MockSeekable) OpenRangeReader(ctx context.Context, offsetU int64, l r0 = ret.Get(0).(RangeReader) } } - if returnFunc, ok := ret.Get(1).(func(context.Context, int64, int64, *FrameTable) error); ok { + if returnFunc, ok := ret.Get(1).(func(context.Context, int64, int64, *FrameTable) Source); ok { r1 = returnFunc(ctx, offsetU, length, frameTable) } else { - r1 = ret.Error(1) + r1 = ret.Get(1).(Source) } - return r0, r1 + if returnFunc, ok := ret.Get(2).(func(context.Context, int64, int64, *FrameTable) error); ok { + r2 = returnFunc(ctx, offsetU, length, frameTable) + } else { + r2 = ret.Error(2) + } + return r0, r1, r2 } // MockSeekable_OpenRangeReader_Call is a *mock.Call that shadows Run/Return methods with type explicit version for method 'OpenRangeReader' @@ -107,12 +113,12 @@ func (_c *MockSeekable_OpenRangeReader_Call) Run(run func(ctx context.Context, o return _c } -func (_c *MockSeekable_OpenRangeReader_Call) Return(rangeReader RangeReader, err error) *MockSeekable_OpenRangeReader_Call { - _c.Call.Return(rangeReader, err) +func (_c *MockSeekable_OpenRangeReader_Call) Return(rangeReader RangeReader, source Source, err error) *MockSeekable_OpenRangeReader_Call { + _c.Call.Return(rangeReader, source, err) return _c } -func (_c *MockSeekable_OpenRangeReader_Call) RunAndReturn(run func(ctx context.Context, offsetU int64, length int64, frameTable *FrameTable) (RangeReader, error)) *MockSeekable_OpenRangeReader_Call { +func (_c *MockSeekable_OpenRangeReader_Call) RunAndReturn(run func(ctx context.Context, offsetU int64, length int64, frameTable *FrameTable) (RangeReader, Source, error)) *MockSeekable_OpenRangeReader_Call { _c.Call.Return(run) return _c } diff --git a/packages/shared/pkg/storage/mock_storageprovider.go b/packages/shared/pkg/storage/mock_storageprovider.go index 4657bf0754..d40a0f402e 100644 --- a/packages/shared/pkg/storage/mock_storageprovider.go +++ b/packages/shared/pkg/storage/mock_storageprovider.go @@ -140,8 +140,8 @@ func (_c *MockStorageProvider_GetDetails_Call) RunAndReturn(run func() string) * } // OpenBlob provides a mock function for the type MockStorageProvider -func (_mock *MockStorageProvider) OpenBlob(ctx context.Context, path string, objectType ObjectType) (Blob, error) { - ret := _mock.Called(ctx, path, objectType) +func (_mock *MockStorageProvider) OpenBlob(ctx context.Context, path string) (Blob, error) { + ret := _mock.Called(ctx, path) if len(ret) == 0 { panic("no return value specified for OpenBlob") @@ -149,18 +149,18 @@ func (_mock *MockStorageProvider) OpenBlob(ctx context.Context, path string, obj var r0 Blob var r1 error - if returnFunc, ok := ret.Get(0).(func(context.Context, string, ObjectType) (Blob, error)); ok { - return returnFunc(ctx, path, objectType) + if returnFunc, ok := ret.Get(0).(func(context.Context, string) (Blob, error)); ok { + return returnFunc(ctx, path) } - if returnFunc, ok := ret.Get(0).(func(context.Context, string, ObjectType) Blob); ok { - r0 = returnFunc(ctx, path, objectType) + if returnFunc, ok := ret.Get(0).(func(context.Context, string) Blob); ok { + r0 = returnFunc(ctx, path) } else { if ret.Get(0) != nil { r0 = ret.Get(0).(Blob) } } - if returnFunc, ok := ret.Get(1).(func(context.Context, string, ObjectType) error); ok { - r1 = returnFunc(ctx, path, objectType) + if returnFunc, ok := ret.Get(1).(func(context.Context, string) error); ok { + r1 = returnFunc(ctx, path) } else { r1 = ret.Error(1) } @@ -175,12 +175,11 @@ type MockStorageProvider_OpenBlob_Call struct { // OpenBlob is a helper method to define mock.On call // - ctx context.Context // - path string -// - objectType ObjectType -func (_e *MockStorageProvider_Expecter) OpenBlob(ctx interface{}, path interface{}, objectType interface{}) *MockStorageProvider_OpenBlob_Call { - return &MockStorageProvider_OpenBlob_Call{Call: _e.mock.On("OpenBlob", ctx, path, objectType)} +func (_e *MockStorageProvider_Expecter) OpenBlob(ctx interface{}, path interface{}) *MockStorageProvider_OpenBlob_Call { + return &MockStorageProvider_OpenBlob_Call{Call: _e.mock.On("OpenBlob", ctx, path)} } -func (_c *MockStorageProvider_OpenBlob_Call) Run(run func(ctx context.Context, path string, objectType ObjectType)) *MockStorageProvider_OpenBlob_Call { +func (_c *MockStorageProvider_OpenBlob_Call) Run(run func(ctx context.Context, path string)) *MockStorageProvider_OpenBlob_Call { _c.Call.Run(func(args mock.Arguments) { var arg0 context.Context if args[0] != nil { @@ -190,14 +189,9 @@ func (_c *MockStorageProvider_OpenBlob_Call) Run(run func(ctx context.Context, p if args[1] != nil { arg1 = args[1].(string) } - var arg2 ObjectType - if args[2] != nil { - arg2 = args[2].(ObjectType) - } run( arg0, arg1, - arg2, ) }) return _c @@ -208,14 +202,14 @@ func (_c *MockStorageProvider_OpenBlob_Call) Return(blob Blob, err error) *MockS return _c } -func (_c *MockStorageProvider_OpenBlob_Call) RunAndReturn(run func(ctx context.Context, path string, objectType ObjectType) (Blob, error)) *MockStorageProvider_OpenBlob_Call { +func (_c *MockStorageProvider_OpenBlob_Call) RunAndReturn(run func(ctx context.Context, path string) (Blob, error)) *MockStorageProvider_OpenBlob_Call { _c.Call.Return(run) return _c } // OpenSeekable provides a mock function for the type MockStorageProvider -func (_mock *MockStorageProvider) OpenSeekable(ctx context.Context, path string, seekableObjectType SeekableObjectType) (Seekable, error) { - ret := _mock.Called(ctx, path, seekableObjectType) +func (_mock *MockStorageProvider) OpenSeekable(ctx context.Context, path string) (Seekable, error) { + ret := _mock.Called(ctx, path) if len(ret) == 0 { panic("no return value specified for OpenSeekable") @@ -223,18 +217,18 @@ func (_mock *MockStorageProvider) OpenSeekable(ctx context.Context, path string, var r0 Seekable var r1 error - if returnFunc, ok := ret.Get(0).(func(context.Context, string, SeekableObjectType) (Seekable, error)); ok { - return returnFunc(ctx, path, seekableObjectType) + if returnFunc, ok := ret.Get(0).(func(context.Context, string) (Seekable, error)); ok { + return returnFunc(ctx, path) } - if returnFunc, ok := ret.Get(0).(func(context.Context, string, SeekableObjectType) Seekable); ok { - r0 = returnFunc(ctx, path, seekableObjectType) + if returnFunc, ok := ret.Get(0).(func(context.Context, string) Seekable); ok { + r0 = returnFunc(ctx, path) } else { if ret.Get(0) != nil { r0 = ret.Get(0).(Seekable) } } - if returnFunc, ok := ret.Get(1).(func(context.Context, string, SeekableObjectType) error); ok { - r1 = returnFunc(ctx, path, seekableObjectType) + if returnFunc, ok := ret.Get(1).(func(context.Context, string) error); ok { + r1 = returnFunc(ctx, path) } else { r1 = ret.Error(1) } @@ -249,12 +243,11 @@ type MockStorageProvider_OpenSeekable_Call struct { // OpenSeekable is a helper method to define mock.On call // - ctx context.Context // - path string -// - seekableObjectType SeekableObjectType -func (_e *MockStorageProvider_Expecter) OpenSeekable(ctx interface{}, path interface{}, seekableObjectType interface{}) *MockStorageProvider_OpenSeekable_Call { - return &MockStorageProvider_OpenSeekable_Call{Call: _e.mock.On("OpenSeekable", ctx, path, seekableObjectType)} +func (_e *MockStorageProvider_Expecter) OpenSeekable(ctx interface{}, path interface{}) *MockStorageProvider_OpenSeekable_Call { + return &MockStorageProvider_OpenSeekable_Call{Call: _e.mock.On("OpenSeekable", ctx, path)} } -func (_c *MockStorageProvider_OpenSeekable_Call) Run(run func(ctx context.Context, path string, seekableObjectType SeekableObjectType)) *MockStorageProvider_OpenSeekable_Call { +func (_c *MockStorageProvider_OpenSeekable_Call) Run(run func(ctx context.Context, path string)) *MockStorageProvider_OpenSeekable_Call { _c.Call.Run(func(args mock.Arguments) { var arg0 context.Context if args[0] != nil { @@ -264,14 +257,9 @@ func (_c *MockStorageProvider_OpenSeekable_Call) Run(run func(ctx context.Contex if args[1] != nil { arg1 = args[1].(string) } - var arg2 SeekableObjectType - if args[2] != nil { - arg2 = args[2].(SeekableObjectType) - } run( arg0, arg1, - arg2, ) }) return _c @@ -282,7 +270,7 @@ func (_c *MockStorageProvider_OpenSeekable_Call) Return(seekable Seekable, err e return _c } -func (_c *MockStorageProvider_OpenSeekable_Call) RunAndReturn(run func(ctx context.Context, path string, seekableObjectType SeekableObjectType) (Seekable, error)) *MockStorageProvider_OpenSeekable_Call { +func (_c *MockStorageProvider_OpenSeekable_Call) RunAndReturn(run func(ctx context.Context, path string) (Seekable, error)) *MockStorageProvider_OpenSeekable_Call { _c.Call.Return(run) return _c } diff --git a/packages/shared/pkg/storage/paths.go b/packages/shared/pkg/storage/paths.go index 6a9a9df74d..8f790caa39 100644 --- a/packages/shared/pkg/storage/paths.go +++ b/packages/shared/pkg/storage/paths.go @@ -107,3 +107,45 @@ func StripCompression(name string) string { func SizeSidecar(objectPath string) string { return objectPath + "." + MetadataKeyUncompressedSize } + +// seekableObjectType derives the metric file_type and codec from a data-file +// path (e.g. "{buildID}/memfile.zstd"), so they need not be threaded through the +// read path. +func seekableObjectType(path string) (SeekableObjectType, CompressionType) { + _, name := SplitPath(path) + ct := compressionType(name) + + switch StripCompression(name) { + case MemfileName: + return MemfileObjectType, ct + case RootfsName: + return RootFSObjectType, ct + default: + return UnknownSeekableObjectType, ct + } +} + +// blobType derives the metric file_type from a blob's last path segment, +// stripping .header so read.blob shares read.read's file_type vocabulary. +func blobType(path string) string { + name := path + if i := strings.LastIndex(name, "/"); i >= 0 { + name = name[i+1:] + } + if base, ok := strings.CutSuffix(name, HeaderSuffix); ok { + return base + } + + return name +} + +func compressionType(name string) CompressionType { + switch { + case strings.HasSuffix(name, CompressionLZ4.Suffix()): + return CompressionLZ4 + case strings.HasSuffix(name, CompressionZstd.Suffix()): + return CompressionZstd + default: + return CompressionNone + } +} diff --git a/packages/shared/pkg/storage/paths_test.go b/packages/shared/pkg/storage/paths_test.go new file mode 100644 index 0000000000..a7c8ecb0da --- /dev/null +++ b/packages/shared/pkg/storage/paths_test.go @@ -0,0 +1,38 @@ +package storage + +import ( + "testing" + + "github.com/stretchr/testify/require" +) + +func TestSeekableKindFromPath(t *testing.T) { + t.Parallel() + + p := Paths{BuildID: "build"} + + cases := []struct { + name string + path string + want SeekableObjectType + ct CompressionType + }{ + {"memfile", p.DataFile(MemfileName, CompressionNone), MemfileObjectType, CompressionNone}, + {"memfile zstd", p.DataFile(MemfileName, CompressionZstd), MemfileObjectType, CompressionZstd}, + {"memfile lz4", p.DataFile(MemfileName, CompressionLZ4), MemfileObjectType, CompressionLZ4}, + {"rootfs", p.DataFile(RootfsName, CompressionNone), RootFSObjectType, CompressionNone}, + {"rootfs zstd", p.DataFile(RootfsName, CompressionZstd), RootFSObjectType, CompressionZstd}, + {"snapfile is not seekable", p.DataFile(SnapfileName, CompressionNone), UnknownSeekableObjectType, CompressionNone}, + {"header is not a data file", p.HeaderFile(MemfileName), UnknownSeekableObjectType, CompressionNone}, + } + + for _, c := range cases { + t.Run(c.name, func(t *testing.T) { + t.Parallel() + + kind, ct := seekableObjectType(c.path) + require.Equal(t, c.want, kind) + require.Equal(t, c.ct, ct) + }) + } +} diff --git a/packages/shared/pkg/storage/storage.go b/packages/shared/pkg/storage/storage.go index 7a6d311966..1842a5d17b 100644 --- a/packages/shared/pkg/storage/storage.go +++ b/packages/shared/pkg/storage/storage.go @@ -20,10 +20,7 @@ import ( "github.com/e2b-dev/infra/packages/shared/pkg/utils" ) -var ( - tracer = otel.Tracer("github.com/e2b-dev/infra/packages/shared/pkg/storage") - meter = otel.Meter("github.com/e2b-dev/infra/packages/shared/pkg/storage") -) +var tracer = otel.Tracer("github.com/e2b-dev/infra/packages/shared/pkg/storage") var ErrObjectNotExist = errors.New("object does not exist") @@ -81,8 +78,20 @@ const ( UnknownSeekableObjectType SeekableObjectType = iota MemfileObjectType RootFSObjectType + numSeekableObjectTypes ) +func (t SeekableObjectType) String() string { + switch t { + case MemfileObjectType: + return "memfile" + case RootFSObjectType: + return "rootfs" + default: + return "unknown" + } +} + type ObjectType int const ( @@ -98,8 +107,8 @@ const ( type StorageProvider interface { DeleteObjectsWithPrefix(ctx context.Context, prefix string) error UploadSignedURL(ctx context.Context, path string, ttl time.Duration) (string, error) - OpenBlob(ctx context.Context, path string, objectType ObjectType) (Blob, error) - OpenSeekable(ctx context.Context, path string, seekableObjectType SeekableObjectType) (Seekable, error) + OpenBlob(ctx context.Context, path string) (Blob, error) + OpenSeekable(ctx context.Context, path string) (Seekable, error) GetDetails() string } @@ -181,14 +190,24 @@ func BlobCustomMetadata(ctx context.Context, b Blob) (ObjectMetadata, error) { return mr.Metadata(ctx) } +// ReadStats is what a RangeReader did over its lifetime; returned from Close. +type ReadStats struct { + StoredBytes int64 + DeliveredBytes int64 + Read time.Duration // source I/O wall, excluding open and decompression + Decompress time.Duration +} + type RangeReader interface { io.Reader - Close(ctx context.Context) error + // Close returns the reader's lifetime stats, or nil if it doesn't meter. + Close(ctx context.Context) (*ReadStats, error) } // RangeOpener supports progressive reads via a streaming range reader. +// OpenRangeReader returns the Source that served the bytes. type RangeOpener interface { - OpenRangeReader(ctx context.Context, offsetU int64, length int64, frameTable *FrameTable) (RangeReader, error) + OpenRangeReader(ctx context.Context, offsetU int64, length int64, frameTable *FrameTable) (RangeReader, Source, error) } type SeekableWriter interface { @@ -202,8 +221,8 @@ type Seekable interface { Size(ctx context.Context) (int64, error) } -func UploadFramed(ctx context.Context, provider StorageProvider, remotePath string, objType SeekableObjectType, localPath string, opts ...PutOption) (*FullFrameTable, [32]byte, error) { - object, err := provider.OpenSeekable(ctx, remotePath, objType) +func UploadFramed(ctx context.Context, provider StorageProvider, remotePath string, localPath string, opts ...PutOption) (*FullFrameTable, [32]byte, error) { + object, err := provider.OpenSeekable(ctx, remotePath) if err != nil { return nil, [32]byte{}, err } @@ -211,8 +230,8 @@ func UploadFramed(ctx context.Context, provider StorageProvider, remotePath stri return object.StoreFile(ctx, localPath, opts...) } -func UploadBlob(ctx context.Context, provider StorageProvider, remotePath string, objType ObjectType, localPath string, opts ...PutOption) error { - blob, err := provider.OpenBlob(ctx, remotePath, objType) +func UploadBlob(ctx context.Context, provider StorageProvider, remotePath string, localPath string, opts ...PutOption) error { + blob, err := provider.OpenBlob(ctx, remotePath) if err != nil { return err } diff --git a/packages/shared/pkg/storage/storage_aws.go b/packages/shared/pkg/storage/storage_aws.go index 9bac148cfc..a973fe87ad 100644 --- a/packages/shared/pkg/storage/storage_aws.go +++ b/packages/shared/pkg/storage/storage_aws.go @@ -127,7 +127,7 @@ func (s *awsStorage) UploadSignedURL(ctx context.Context, path string, ttl time. return resp.URL, nil } -func (s *awsStorage) OpenSeekable(_ context.Context, path string, _ SeekableObjectType) (Seekable, error) { +func (s *awsStorage) OpenSeekable(_ context.Context, path string) (Seekable, error) { return &awsObject{ client: s.client, bucketName: s.bucketName, @@ -135,7 +135,7 @@ func (s *awsStorage) OpenSeekable(_ context.Context, path string, _ SeekableObje }, nil } -func (s *awsStorage) OpenBlob(_ context.Context, path string, _ ObjectType) (Blob, error) { +func (s *awsStorage) OpenBlob(_ context.Context, path string) (Blob, error) { return &awsObject{ client: s.client, bucketName: s.bucketName, @@ -143,7 +143,10 @@ func (s *awsStorage) OpenBlob(_ context.Context, path string, _ ObjectType) (Blo }, nil } -func (o *awsObject) WriteTo(ctx context.Context, dst io.Writer) (int64, error) { +func (o *awsObject) WriteTo(ctx context.Context, dst io.Writer) (n int64, err error) { + start := time.Now() + defer func() { RecordReadBlob(ctx, time.Since(start), n, o.path, SourceAWS, err) }() + ctx, cancel := context.WithTimeout(ctx, awsReadTimeout) defer cancel() @@ -159,7 +162,9 @@ func (o *awsObject) WriteTo(ctx context.Context, dst io.Writer) (int64, error) { defer resp.Body.Close() - return io.Copy(dst, resp.Body) + n, err = io.Copy(dst, resp.Body) + + return n, err } func (o *awsObject) StoreFile(ctx context.Context, path string, opts ...PutOption) (*FullFrameTable, [32]byte, error) { @@ -238,9 +243,15 @@ func (o *awsObject) Put(ctx context.Context, data []byte, opts ...PutOption) err return nil } -func (o *awsObject) OpenRangeReader(ctx context.Context, off, length int64, frameTable *FrameTable) (RangeReader, error) { +func (o *awsObject) OpenRangeReader(ctx context.Context, off, length int64, frameTable *FrameTable) (_ RangeReader, _ Source, err error) { + start := time.Now() + objType, _ := seekableObjectType(o.path) + defer func() { + RecordReadOpen(ctx, time.Since(start), objType, SourceAWS, frameTable.CompressionType(), err) + }() + if frameTable.IsCompressed() { - return nil, errors.New("compressed reads are not supported on AWS") + return nil, SourceAWS, errors.New("compressed reads are not supported on AWS") } readRange := aws.String(fmt.Sprintf("bytes=%d-%d", off, off+length-1)) @@ -252,16 +263,20 @@ func (o *awsObject) OpenRangeReader(ctx context.Context, off, length int64, fram if err != nil { var nsk *types.NoSuchKey if errors.As(err, &nsk) { - return nil, ErrObjectNotExist + return nil, SourceAWS, ErrObjectNotExist } - return nil, fmt.Errorf("failed to create S3 range reader for %q: %w", o.path, err) + return nil, SourceAWS, fmt.Errorf("failed to create S3 range reader for %q: %w", o.path, err) } - return NewRangeReader(resp.Body), nil + return NewRangeReader(resp.Body), SourceAWS, nil } -func (o *awsObject) Size(ctx context.Context) (int64, error) { +func (o *awsObject) Size(ctx context.Context) (_ int64, err error) { + start := time.Now() + objType, _ := seekableObjectType(o.path) + defer func() { RecordReadSize(ctx, time.Since(start), objType, SourceAWS, err) }() + ctx, cancel := context.WithTimeout(ctx, awsOperationTimeout) defer cancel() diff --git a/packages/shared/pkg/storage/storage_cache.go b/packages/shared/pkg/storage/storage_cache.go index 7d5838758c..61982f3ee7 100644 --- a/packages/shared/pkg/storage/storage_cache.go +++ b/packages/shared/pkg/storage/storage_cache.go @@ -85,8 +85,8 @@ func (c cache) UploadSignedURL(ctx context.Context, path string, ttl time.Durati return c.inner.UploadSignedURL(ctx, path, ttl) } -func (c cache) OpenBlob(ctx context.Context, path string, objectType ObjectType) (Blob, error) { - innerObject, err := c.inner.OpenBlob(ctx, path, objectType) +func (c cache) OpenBlob(ctx context.Context, path string) (Blob, error) { + innerObject, err := c.inner.OpenBlob(ctx, path) if err != nil { return nil, fmt.Errorf("failed to open object: %w", err) } @@ -105,8 +105,8 @@ func (c cache) OpenBlob(ctx context.Context, path string, objectType ObjectType) }, nil } -func (c cache) OpenSeekable(ctx context.Context, path string, objectType SeekableObjectType) (Seekable, error) { - innerObject, err := c.inner.OpenSeekable(ctx, path, objectType) +func (c cache) OpenSeekable(ctx context.Context, path string) (Seekable, error) { + innerObject, err := c.inner.OpenSeekable(ctx, path) if err != nil { return nil, fmt.Errorf("failed to open object: %w", err) } @@ -116,12 +116,15 @@ func (c cache) OpenSeekable(ctx context.Context, path string, objectType Seekabl return nil, fmt.Errorf("failed to create cache directory: %w", err) } + objType, _ := seekableObjectType(path) + return &cachedSeekable{ path: localPath, chunkSize: c.chunkSize, inner: innerObject, flags: c.flags, tracer: c.tracer, + objType: objType, }, nil } diff --git a/packages/shared/pkg/storage/storage_cache_blob.go b/packages/shared/pkg/storage/storage_cache_blob.go index 44bc6866fa..526467989c 100644 --- a/packages/shared/pkg/storage/storage_cache_blob.go +++ b/packages/shared/pkg/storage/storage_cache_blob.go @@ -7,10 +7,13 @@ import ( "io" "os" "sync" + "time" "go.opentelemetry.io/otel/trace" + "go.uber.org/zap" "github.com/e2b-dev/infra/packages/shared/pkg/featureflags" + "github.com/e2b-dev/infra/packages/shared/pkg/logger" "github.com/e2b-dev/infra/packages/shared/pkg/storage/lock" "github.com/e2b-dev/infra/packages/shared/pkg/utils" ) @@ -49,15 +52,15 @@ func (b *cachedBlob) WriteTo(ctx context.Context, dst io.Writer) (n int64, e err span.End() }() + blobStart := time.Now() bytesRead, err := b.copyFullFileFromCache(ctx, dst) + // Records the NFS attempt (hit, or not_found/err); a miss falls through to + // inner.WriteTo, which records its own source. + RecordReadBlob(ctx, time.Since(blobStart), bytesRead, b.path, SourceNFS, err) if err == nil { - recordCacheRead(ctx, true, bytesRead, cacheTypeObject, cacheOpWriteTo) - return bytesRead, nil } - recordCacheReadError(ctx, cacheTypeObject, cacheOpWriteTo, err) - // This is semi-arbitrary. this code path is called for files that tend to be less than 1 MB (headers, metadata, etc), // so 2 MB allows us to read the file without needing to allocate more memory, with some room for growth. If the // file is larger than 2 MB, the buffer will grow, it just won't be as efficient WRT memory allocations. @@ -77,15 +80,10 @@ func (b *cachedBlob) WriteTo(ctx context.Context, dst io.Writer) (n int64, e err ctx, span := b.tracer.Start(ctx, "write file back to cache") defer span.End() - count, err := b.writeFileToCache(ctx, buffer) - if err != nil { - recordCacheWriteError(ctx, cacheTypeObject, cacheOpWriteTo, err) + if _, err := b.writeFileToCache(ctx, buffer); err != nil { recordError(span, err) - - return + logger.L().Warn(ctx, "failed to write object back to cache", zap.Error(err)) } - - recordCacheWrite(ctx, count, cacheTypeObject, cacheOpWriteTo) }) } @@ -94,8 +92,6 @@ func (b *cachedBlob) WriteTo(ctx context.Context, dst io.Writer) (n int64, e err return int64(written), fmt.Errorf("failed to write object: %w", err) } - recordCacheRead(ctx, false, int64(written), cacheTypeObject, cacheOpWriteTo) - return int64(written), err // in case err == EOF } @@ -113,12 +109,9 @@ func (b *cachedBlob) Put(ctx context.Context, data []byte, opts ...PutOption) (e ctx, span := b.tracer.Start(ctx, "write data to cache") defer span.End() - count, err := b.writeFileToCache(ctx, bytes.NewReader(data)) - if err != nil { + if _, err := b.writeFileToCache(ctx, bytes.NewReader(data)); err != nil { recordError(span, err) - recordCacheWriteError(ctx, cacheTypeObject, cacheOpWrite, err) - } else { - recordCacheWrite(ctx, count, cacheTypeObject, cacheOpWrite) + logger.L().Warn(ctx, "failed to write object to cache", zap.Error(err)) } }) } diff --git a/packages/shared/pkg/storage/storage_cache_compressed_test.go b/packages/shared/pkg/storage/storage_cache_compressed_test.go index d19b396c15..38e45587b8 100644 --- a/packages/shared/pkg/storage/storage_cache_compressed_test.go +++ b/packages/shared/pkg/storage/storage_cache_compressed_test.go @@ -69,8 +69,8 @@ func TestDecompressingCacheReader(t *testing.T) { framePath := makeFrameFilename(c.path, Range{Offset: 0, Length: len(compressed)}) capturing := newCaptureReader(bytesRangeReader(compressed), len(compressed), true, - c.compressedFrameWriteback(framePath, 0, len(compressed))) - rc, err := NewDecompressingReader(capturing, CompressionLZ4) + c.compressedFrameWriteback(framePath, 0, len(compressed), SourceFS, CompressionLZ4)) + rc, err := NewDecompressReader(capturing, CompressionLZ4, SourceFS, c.objType) require.NoError(t, err) got, err := io.ReadAll(rc) @@ -88,7 +88,7 @@ func TestDecompressingCacheReader(t *testing.T) { t.Run("io.ReadFull at exact uncompressed size still populates cache (production LZ4 options)", func(t *testing.T) { t.Parallel() - // Mirror the chunker's progressiveRead: io.ReadFull with the EXACT + // Mirror the chunker's progressiveFetch: io.ReadFull with the EXACT // uncompressed byte count, against an encoder configured the way prod // configures it. With BlockChecksumOption(true)+ChecksumOption(false), // the trailing 4-byte EndMark is part of the encoded frame but lz4.Reader @@ -102,8 +102,8 @@ func TestDecompressingCacheReader(t *testing.T) { framePath := makeFrameFilename(c.path, Range{Offset: 0, Length: len(compressedProd)}) capturing := newCaptureReader(bytesRangeReader(compressedProd), len(compressedProd), true, - c.compressedFrameWriteback(framePath, 0, len(compressedProd))) - rc, err := NewDecompressingReader(capturing, CompressionLZ4) + c.compressedFrameWriteback(framePath, 0, len(compressedProd), SourceFS, CompressionLZ4)) + rc, err := NewDecompressReader(capturing, CompressionLZ4, SourceFS, c.objType) require.NoError(t, err) out := make([]byte, len(original)) @@ -112,7 +112,7 @@ func TestDecompressingCacheReader(t *testing.T) { require.Equal(t, len(original), n) require.Equal(t, original, out) - closeErr := rc.Close(t.Context()) + _, closeErr := rc.Close(t.Context()) require.NoError(t, closeErr, "writeback failure must not surface as a read error") c.wg.Wait() @@ -127,15 +127,15 @@ func TestDecompressingCacheReader(t *testing.T) { framePath := makeFrameFilename(c.path, Range{Offset: 0, Length: len(compressed)}) capturing := newCaptureReader(bytesRangeReader(compressed), len(compressed)+100, true, - c.compressedFrameWriteback(framePath, 0, len(compressed)+100)) // wrong expected size - rc, err := NewDecompressingReader(capturing, CompressionLZ4) + c.compressedFrameWriteback(framePath, 0, len(compressed)+100, SourceFS, CompressionLZ4)) // wrong expected size + rc, err := NewDecompressReader(capturing, CompressionLZ4, SourceFS, c.objType) require.NoError(t, err) got, err := io.ReadAll(rc) require.NoError(t, err) require.Equal(t, original, got, "decompressed data should be correct regardless") - closeErr := rc.Close(t.Context()) + _, closeErr := rc.Close(t.Context()) require.NoError(t, closeErr, "writeback failure must not surface as a read error") c.wg.Wait() diff --git a/packages/shared/pkg/storage/storage_cache_metrics.go b/packages/shared/pkg/storage/storage_cache_metrics.go deleted file mode 100644 index 514b34539e..0000000000 --- a/packages/shared/pkg/storage/storage_cache_metrics.go +++ /dev/null @@ -1,142 +0,0 @@ -package storage - -import ( - "context" - "errors" - "os" - - "go.opentelemetry.io/otel/attribute" - "go.opentelemetry.io/otel/metric" - "go.opentelemetry.io/otel/trace" - "go.uber.org/zap" - - "github.com/e2b-dev/infra/packages/shared/pkg/logger" - "github.com/e2b-dev/infra/packages/shared/pkg/storage/lock" - "github.com/e2b-dev/infra/packages/shared/pkg/utils" -) - -var ( - cacheErrorsCounter = utils.Must(meter.Int64Counter("orchestrator.storage.cache.errors", - metric.WithDescription("failed cache operations"))) - cacheOpCounter = utils.Must(meter.Int64Counter("orchestrator.storage.cache.ops", - metric.WithDescription("total cache operations"))) - cacheBytesCounter = utils.Must(meter.Int64Counter("orchestrator.storage.cache.bytes", - metric.WithDescription("total cache bytes processed"), - metric.WithUnit("byte"))) -) - -type cacheOp string - -const ( - cacheOpWriteTo cacheOp = "write_to" - cacheOpWrite cacheOp = "write" - cacheOpSize cacheOp = "size" - - cacheOpOpenRangeReader cacheOp = "open_range_reader" - - cacheOpWriteFromFileSystem cacheOp = "write_from_filesystem" -) - -type cacheType string - -const ( - cacheTypeObject cacheType = "object" - cacheTypeSeekable cacheType = "seekable" -) - -func recordCacheRead(ctx context.Context, isHit bool, bytesRead int64, t cacheType, op cacheOp) { - span := trace.SpanFromContext(ctx) - span.SetAttributes( - attribute.Bool("cache_hit", isHit), - attribute.Int64("bytes_read", bytesRead), - attribute.String("cache_type", string(t)), - attribute.String("op_type", string(op)), - ) - - cacheOpCounter.Add(ctx, 1, metric.WithAttributes( - attribute.String("cache_type", string(t)), - attribute.String("op_type", string(op)), - attribute.Bool("cache_hit", isHit), - )) - - cacheBytesCounter.Add(ctx, bytesRead, metric.WithAttributes( - attribute.String("cache_type", string(t)), - attribute.String("op_type", string(op)), - attribute.Bool("cache_hit", isHit), - )) -} - -func recordCacheWrite(ctx context.Context, bytesWritten int64, t cacheType, op cacheOp) { - span := trace.SpanFromContext(ctx) - span.SetAttributes( - attribute.Int64("bytes_written", bytesWritten), - attribute.String("cache_type", string(t)), - attribute.String("op_type", string(op)), - ) - - cacheOpCounter.Add(ctx, 1, metric.WithAttributes( - attribute.String("cache_type", string(t)), - attribute.String("op_type", string(op)), - )) - - cacheBytesCounter.Add(ctx, bytesWritten, metric.WithAttributes( - attribute.String("cache_type", string(t)), - attribute.String("op_type", string(op)), - )) -} - -func recordCacheReadError[T ~string](ctx context.Context, t cacheType, op T, err error) { - // don't record "we haven't cached this yet" as an error - if errors.Is(err, os.ErrNotExist) { - return - } - - span := trace.SpanFromContext(ctx) - span.SetAttributes( - attribute.String("cache_type", string(t)), - attribute.String("op_type", string(op)), - attribute.String("error_type", "read"), - attribute.String("error", err.Error()), - ) - - logger.L().Warn(ctx, "failed to read from cache", - zap.Error(err), - zap.String("cache_type", string(t)), - zap.String("op_type", string(op)), - ) - - cacheErrorsCounter.Add(ctx, 1, metric.WithAttributes( - attribute.String("cache_type", string(t)), - attribute.String("op_type", string(op)), - attribute.String("error_type", "read"), - )) -} - -func recordCacheWriteError[T ~string](ctx context.Context, t cacheType, op T, err error) { - span := trace.SpanFromContext(ctx) - span.SetAttributes( - attribute.String("cache_type", string(t)), - attribute.String("op_type", string(op)), - attribute.String("error_type", "write"), - attribute.String("error", err.Error()), - ) - - var errorType string - if errors.Is(err, lock.ErrLockAlreadyHeld) { - errorType = "write-lock" - } else { - errorType = "write" - } - - logger.L().Warn(ctx, "failed to write to cache", - zap.Error(err), - zap.String("cache_type", string(t)), - zap.String("op_type", string(op)), - ) - - cacheErrorsCounter.Add(ctx, 1, metric.WithAttributes( - attribute.String("cache_type", string(t)), - attribute.String("op_type", string(op)), - attribute.String("error_type", errorType), - )) -} diff --git a/packages/shared/pkg/storage/storage_cache_seekable.go b/packages/shared/pkg/storage/storage_cache_seekable.go index 2891047aaf..5f12c2ded2 100644 --- a/packages/shared/pkg/storage/storage_cache_seekable.go +++ b/packages/shared/pkg/storage/storage_cache_seekable.go @@ -9,18 +9,17 @@ import ( "path/filepath" "strconv" "sync" + "time" "github.com/google/uuid" "github.com/launchdarkly/go-sdk-common/v3/ldcontext" "go.opentelemetry.io/otel/attribute" - "go.opentelemetry.io/otel/metric" "go.opentelemetry.io/otel/trace" "go.uber.org/zap" "github.com/e2b-dev/infra/packages/shared/pkg/featureflags" "github.com/e2b-dev/infra/packages/shared/pkg/logger" "github.com/e2b-dev/infra/packages/shared/pkg/storage/lock" - "github.com/e2b-dev/infra/packages/shared/pkg/telemetry" "github.com/e2b-dev/infra/packages/shared/pkg/utils" ) @@ -31,34 +30,6 @@ var ( ErrBufferTooLarge = errors.New("buffer is too large") ) -const ( - nfsCacheOperationAttr = "operation" - // Value kept as "ReadAt" dashboard compatibility after the method was - // renamed to OpenRangeReader. - nfsCacheOperationAttrReadAt = "ReadAt" - nfsCacheOperationAttrSize = "Size" -) - -var ( - cacheSlabReadTimerFactory = utils.Must(telemetry.NewTimerFactory(meter, - "orchestrator.storage.slab.nfs.read", - "Duration of NFS reads", - "Total NFS bytes read", - "Total NFS reads", - )) - cacheSlabWriteTimerFactory = utils.Must(telemetry.NewTimerFactory(meter, - "orchestrator.storage.slab.nfs.write", - "Duration of NFS writes", - "Total bytes written to NFS", - "Total writes to NFS", - )) - nfsCacheConcurrentReads = utils.Must(meter.Int64UpDownCounter( - "orchestrator.storage.slab.nfs.read.concurrent", - metric.WithDescription("Number of NFS cache range readers currently open"), - metric.WithUnit("{read}"), - )) -) - type featureFlagsClient interface { BoolFlag(ctx context.Context, flag featureflags.BoolFlag, ldctx ...ldcontext.Context) bool IntFlag(ctx context.Context, flag featureflags.IntFlag, ldctx ...ldcontext.Context) int @@ -70,6 +41,7 @@ type cachedSeekable struct { inner Seekable flags featureFlagsClient tracer trace.Tracer + objType SeekableObjectType wg sync.WaitGroup } @@ -79,7 +51,7 @@ var ( _ RangeOpener = (*cachedSeekable)(nil) ) -func (c *cachedSeekable) OpenRangeReader(ctx context.Context, off int64, length int64, frameTable *FrameTable) (RangeReader, error) { +func (c *cachedSeekable) OpenRangeReader(ctx context.Context, off int64, length int64, frameTable *FrameTable) (RangeReader, Source, error) { compressed := frameTable.IsCompressed() ctx, span := c.tracer.Start(ctx, "read", trace.WithAttributes( @@ -89,83 +61,55 @@ func (c *cachedSeekable) OpenRangeReader(ctx context.Context, off int64, length )) var rc RangeReader + var source Source var err error - if compressed { - rc, err = c.openReaderCompressed(ctx, off, frameTable) - } else if err = c.validateReadParams(length, off); err == nil { - rc, err = c.openReaderUncompressed(ctx, off, length) + switch { + case compressed: + rc, source, err = c.openReaderCompressed(ctx, off, frameTable) + default: + if err = c.validateReadParams(length, off); err == nil { + rc, source, err = c.openReaderUncompressed(ctx, off, length) + } } if err != nil { recordError(span, err) span.End() - return nil, err + return nil, source, err } - return newObservableReader(rc, nil, span), nil + return newSpanReader(rc, span), source, nil } -func (c *cachedSeekable) openReaderUncompressed(ctx context.Context, off, length int64) (RangeReader, error) { - timer := cacheSlabReadTimerFactory.Begin( - attribute.String(nfsCacheOperationAttr, nfsCacheOperationAttrReadAt), - attribute.Bool("compressed", false), - ) - +func (c *cachedSeekable) openReaderUncompressed(ctx context.Context, off, length int64) (RangeReader, Source, error) { chunkPath := c.makeChunkFilename(off) + start := time.Now() fp, err := os.Open(chunkPath) + RecordReadOpen(ctx, time.Since(start), c.objType, SourceNFS, CompressionNone, err) if err == nil { - recordCacheRead(ctx, true, length, cacheTypeSeekable, cacheOpOpenRangeReader) - timer.Success(ctx, length) - - return withNFSGauge(ctx, newSectionReader(fp, 0, length)), nil - } - - if !os.IsNotExist(err) { - recordCacheReadError(ctx, cacheTypeSeekable, cacheOpOpenRangeReader, err) + return newSectionReader(fp, 0, length), SourceNFS, nil } - timer.Failure(ctx, 0) - - rc, err := c.inner.OpenRangeReader(ctx, off, length, nil) + rc, innerSource, err := c.inner.OpenRangeReader(ctx, off, length, nil) if err != nil { - return nil, fmt.Errorf("failed to open inner range reader: %w", err) + return nil, innerSource, fmt.Errorf("failed to open inner range reader: %w", err) } - recordCacheRead(ctx, false, length, cacheTypeSeekable, cacheOpOpenRangeReader) - if !skipCacheWriteback(ctx) { rc = newCaptureReader(rc, int(length), false, - c.uncompressedChunkWriteback(chunkPath, off, length)) + c.uncompressedChunkWriteback(chunkPath, off, length, innerSource)) } - return rc, nil -} - -// nfsGaugeReadCloser wraps a reader and decrements the NFS concurrent reads -// gauge on Close. -type nfsGaugeReadCloser struct { - RangeReader -} - -func (r *nfsGaugeReadCloser) Close(ctx context.Context) error { - nfsCacheConcurrentReads.Add(ctx, -1) - - return r.RangeReader.Close(ctx) -} - -func withNFSGauge(ctx context.Context, rc RangeReader) RangeReader { - nfsCacheConcurrentReads.Add(ctx, 1) - - return &nfsGaugeReadCloser{RangeReader: rc} + return rc, innerSource, nil } // uncompressedChunkWriteback returns a captureReader callback that persists // the captured chunk to the NFS cache in a detached goroutine. Best-effort: // a short capture (e.g. upstream truncation) is dropped silently — a streaming // reader always ends in EOF, so byte count is the only reliable signal. -func (c *cachedSeekable) uncompressedChunkWriteback(chunkPath string, off, expectedLen int64) func(context.Context, []byte) { +func (c *cachedSeekable) uncompressedChunkWriteback(chunkPath string, off, expectedLen int64, src Source) func(context.Context, []byte) { return func(ctx context.Context, captured []byte) { if !isCompleteRead(len(captured), int(expectedLen), nil) { return @@ -175,10 +119,13 @@ func (c *cachedSeekable) uncompressedChunkWriteback(chunkPath string, off, expec ctx, span := c.tracer.Start(ctx, "write range reader chunk back to cache") defer span.End() + start := time.Now() err := c.writeToCache(ctx, off, chunkPath, captured) - if err != nil { + recordWriteback(ctx, time.Since(start), int64(len(captured)), c.objType, src, CompressionNone, TriggerRead, err) + + if err != nil && !errors.Is(err, lock.ErrLockAlreadyHeld) { recordError(span, err) - recordCacheWriteError(ctx, cacheTypeSeekable, cacheOpOpenRangeReader, err) + logger.L().Warn(ctx, "failed to write chunk back to cache", zap.Error(err)) } }) } @@ -191,18 +138,14 @@ func (c *cachedSeekable) Size(ctx context.Context) (n int64, e error) { span.End() }() - readTimer := cacheSlabReadTimerFactory.Begin(attribute.String(nfsCacheOperationAttr, nfsCacheOperationAttrSize)) - + sizeStart := time.Now() size, err := c.readLocalSize(ctx) + // Records the NFS attempt (hit, or not_found/err); a miss falls through to + // inner.Size, which records its own source. + RecordReadSize(ctx, time.Since(sizeStart), c.objType, SourceNFS, err) if err == nil { - recordCacheRead(ctx, true, 0, cacheTypeSeekable, cacheOpSize) - readTimer.Success(ctx, 0) - return size, nil } - readTimer.Failure(ctx, 0) - - recordCacheReadError(ctx, cacheTypeSeekable, cacheOpSize, err) size, err = c.inner.Size(ctx) if err != nil { @@ -216,13 +159,11 @@ func (c *cachedSeekable) Size(ctx context.Context) (n int64, e error) { if err := c.writeLocalSize(ctx, size); err != nil { recordError(span, err) - recordCacheWriteError(ctx, cacheTypeSeekable, cacheOpSize, err) + logger.L().Warn(ctx, "failed to write object size to cache", zap.Error(err)) } }) } - recordCacheRead(ctx, false, 0, cacheTypeSeekable, cacheOpSize) - return size, nil } @@ -239,7 +180,7 @@ func (c *cachedSeekable) StoreFile(ctx context.Context, path string, opts ...Put writeThrough := c.flags.BoolFlag(ctx, featureflags.EnableWriteThroughCacheFlag) if cfg.IsCompressionEnabled() && writeThrough { - opts = append(opts, WithFrameSink(c.frameSink(ctx))) + opts = append(opts, WithFrameSink(c.frameSink(ctx, cfg.CompressionType()))) } if !cfg.IsCompressionEnabled() && writeThrough { @@ -251,16 +192,14 @@ func (c *cachedSeekable) StoreFile(ctx context.Context, path string, opts ...Put size, err := c.createCacheBlocksFromFile(ctx, path) if err != nil { recordError(span, err) - recordCacheWriteError(ctx, cacheTypeSeekable, cacheOpWriteFromFileSystem, fmt.Errorf("failed to create cache blocks: %w", err)) + logger.L().Warn(ctx, "failed to create cache blocks from file system", zap.Error(err)) return } - recordCacheWrite(ctx, size, cacheTypeSeekable, cacheOpWriteFromFileSystem) - if err := c.writeLocalSize(ctx, size); err != nil { recordError(span, err) - recordCacheWriteError(ctx, cacheTypeSeekable, cacheOpWriteFromFileSystem, fmt.Errorf("failed to write local file size: %w", err)) + logger.L().Warn(ctx, "failed to write object size to cache", zap.Error(err)) } }) } @@ -271,7 +210,7 @@ func (c *cachedSeekable) StoreFile(ctx context.Context, path string, opts ...Put // frameSink writes each compressed frame to a .frm file at its C-space offset, // the layout openReaderCompressed expects. Writes are async (goCtx) and capped // by MaxCacheWriterConcurrencyFlag. -func (c *cachedSeekable) frameSink(ctx context.Context) FrameSink { +func (c *cachedSeekable) frameSink(ctx context.Context, ct CompressionType) FrameSink { maxConcurrency := c.flags.IntFlag(ctx, featureflags.MaxCacheWriterConcurrencyFlag) if maxConcurrency <= 0 { logger.L().Warn(ctx, "max cache writer concurrency is too low, falling back to 1", @@ -293,8 +232,12 @@ func (c *cachedSeekable) frameSink(ctx context.Context) FrameSink { defer func() { <-sem }() framePath := makeFrameFilename(c.path, Range{Offset: cOffset, Length: len(data)}) - if err := c.writeToCache(ctx, cOffset, framePath, data); err != nil { - recordCacheWriteError(ctx, cacheTypeSeekable, cacheOpWriteFromFileSystem, err) + start := time.Now() + err := c.writeToCache(ctx, cOffset, framePath, data) + recordWriteback(ctx, time.Since(start), int64(len(data)), c.objType, SourceFS, ct, TriggerWrite, err) + // ErrLockAlreadyHeld is normal dedup, not a write failure. + if err != nil && !errors.Is(err, lock.ErrLockAlreadyHeld) { + logger.L().Warn(ctx, "failed to write frame back to cache", zap.Error(err)) } }) } @@ -353,17 +296,10 @@ func (c *cachedSeekable) validateReadParams(buffSize, offset int64) error { } func (c *cachedSeekable) writeToCache(ctx context.Context, offset int64, finalPath string, bytes []byte) error { - writeTimer := cacheSlabWriteTimerFactory.Begin() - - // Try to acquire lock for this chunk write to NFS cache + // Lock contention surfaces as ErrLockAlreadyHeld; callers skip it as dedup. lockFile, err := lock.TryAcquireLock(ctx, finalPath) if err != nil { - // failed to acquire lock, which is a different category of failure than "write failed" - recordCacheWriteError(ctx, cacheTypeSeekable, cacheOpOpenRangeReader, err) - - writeTimer.Failure(ctx, 0) - - return nil + return err } // Release lock after write completes @@ -382,19 +318,13 @@ func (c *cachedSeekable) writeToCache(ctx context.Context, offset int64, finalPa if err := os.WriteFile(tempPath, bytes, cacheFilePermissions); err != nil { go safelyRemoveFile(ctx, tempPath) - writeTimer.Failure(ctx, int64(len(bytes))) - return fmt.Errorf("failed to write temp cache file: %w", err) } if err := utils.RenameOrDeleteFile(ctx, tempPath, finalPath); err != nil { - writeTimer.Failure(ctx, int64(len(bytes))) - return fmt.Errorf("failed to rename temp file: %w", err) } - writeTimer.Success(ctx, int64(len(bytes))) - return nil } @@ -483,34 +413,30 @@ func (c *cachedSeekable) writeChunkFromFile(ctx context.Context, offset int64, i _, span := c.tracer.Start(ctx, "write chunk from file at offset", trace.WithAttributes( attribute.Int64("offset", offset), )) + start := time.Now() + var count int64 defer func() { recordError(span, err) span.End() + recordWriteback(ctx, time.Since(start), count, c.objType, SourceFS, CompressionNone, TriggerWrite, err) }() - writeTimer := cacheSlabWriteTimerFactory.Begin() - chunkPath := c.makeChunkFilename(offset) span.SetAttributes(attribute.String("chunk_path", chunkPath)) output, err := os.OpenFile(chunkPath, os.O_WRONLY|os.O_CREATE|os.O_TRUNC, cacheFilePermissions) if err != nil { - writeTimer.Failure(ctx, 0) - return fmt.Errorf("failed to open file %s: %w", chunkPath, err) } defer utils.Cleanup(ctx, "failed to close file", output.Close) - count, err := io.Copy(output, io.NewSectionReader(input, offset, c.chunkSize)) + count, err = io.Copy(output, io.NewSectionReader(input, offset, c.chunkSize)) if err != nil { - writeTimer.Failure(ctx, count) safelyRemoveFile(ctx, chunkPath) return fmt.Errorf("failed to copy chunk: %w", err) } - writeTimer.Success(ctx, count) - return nil } diff --git a/packages/shared/pkg/storage/storage_cache_seekable_compressed.go b/packages/shared/pkg/storage/storage_cache_seekable_compressed.go index 2e8077c4bb..965a7b44e5 100644 --- a/packages/shared/pkg/storage/storage_cache_seekable_compressed.go +++ b/packages/shared/pkg/storage/storage_cache_seekable_compressed.go @@ -2,98 +2,84 @@ package storage import ( "context" + "errors" "fmt" "os" + "time" - "go.opentelemetry.io/otel/attribute" -) + "go.uber.org/zap" -// Precomputed OTEL attributes for compressed cache reads (avoids per-read allocation). -var compressedCacheReadAttrs = []attribute.KeyValue{ - attribute.String(nfsCacheOperationAttr, nfsCacheOperationAttrReadAt), - attribute.Bool("compressed", true), -} + "github.com/e2b-dev/infra/packages/shared/pkg/logger" + "github.com/e2b-dev/infra/packages/shared/pkg/storage/lock" +) // openReaderCompressed handles the compressed cache path for OpenRangeReader. // NFS stores compressed frames (.frm); on hit we decompress, on miss we fetch // raw compressed bytes and tee them to NFS on Close. -func (c *cachedSeekable) openReaderCompressed(ctx context.Context, offsetU int64, frameTable *FrameTable) (RangeReader, error) { - r, err := frameTable.LocateCompressed(offsetU) +func (c *cachedSeekable) openReaderCompressed(ctx context.Context, offsetU int64, frameTable *FrameTable) (RangeReader, Source, error) { + rng, err := frameTable.LocateCompressed(offsetU) if err != nil { - return nil, fmt.Errorf("frame lookup for offset %d: %w", offsetU, err) + return nil, UnknownSource, fmt.Errorf("frame lookup for offset %d: %w", offsetU, err) } - path := makeFrameFilename(c.path, r) + path := makeFrameFilename(c.path, rng) ct := frameTable.CompressionType() - timer := cacheSlabReadTimerFactory.Begin(compressedCacheReadAttrs...) - - // Cache hit: open compressed frame from NFS, validate size, wrap with decompressor. - if f, err := os.Open(path); err == nil { - fi, statErr := f.Stat() - switch { - case statErr == nil && fi.Size() == int64(r.Length): - recordCacheRead(ctx, true, int64(r.Length), cacheTypeSeekable, cacheOpOpenRangeReader) - timer.Success(ctx, int64(r.Length)) - - dec, err := NewDecompressingReader(NewRangeReader(f), ct) - if err != nil { - f.Close() - - return nil, fmt.Errorf("decompress cached frame: %w", err) - } - - return withNFSGauge(ctx, dec), nil - case statErr == nil: - // Confirmed size mismatch: drop the file so the miss path rewrites it. + // Cache hit: open the compressed frame from NFS, validate its size, and + // decompress. A size mismatch drops the stale file; on any miss/error we fall + // through to a refetch. + start := time.Now() + var dec RangeReader + f, err := os.Open(path) + if err == nil { + var fi os.FileInfo + if fi, err = f.Stat(); err != nil { + f.Close() + } else if fi.Size() != int64(rng.Length) { f.Close() _ = os.Remove(path) - recordCacheReadError(ctx, cacheTypeSeekable, cacheOpOpenRangeReader, - fmt.Errorf("cached frame %s size %d != expected %d", path, fi.Size(), r.Length)) - default: - // Transient stat error: leave the file in place, fall through to miss. + err = fmt.Errorf("cached frame %s size %d != expected %d", path, fi.Size(), rng.Length) + } else if dec, err = NewDecompressReader(NewRangeReader(f), ct, SourceNFS, c.objType); err != nil { f.Close() - recordCacheReadError(ctx, cacheTypeSeekable, cacheOpOpenRangeReader, statErr) + err = fmt.Errorf("decompress cached frame: %w", err) } - } else if !os.IsNotExist(err) { - recordCacheReadError(ctx, cacheTypeSeekable, cacheOpOpenRangeReader, err) } - - timer.Failure(ctx, 0) + RecordReadOpen(ctx, time.Since(start), c.objType, SourceNFS, ct, err) + if err == nil { + return dec, SourceNFS, nil + } // Cache miss: fetch raw compressed bytes via OpenRangeReader(nil frameTable). - raw, err := c.inner.OpenRangeReader(ctx, r.Offset, int64(r.Length), nil) + raw, innerSource, err := c.inner.OpenRangeReader(ctx, rng.Offset, int64(rng.Length), nil) if err != nil { - return nil, fmt.Errorf("raw fetch at C=%d: %w", r.Offset, err) + return nil, innerSource, fmt.Errorf("raw fetch at C=%d: %w", rng.Offset, err) } - recordCacheRead(ctx, false, int64(r.Length), cacheTypeSeekable, cacheOpOpenRangeReader) - - in := raw + frameReader := raw if !skipCacheWriteback(ctx) { - in = newCaptureReader(raw, r.Length, true, - c.compressedFrameWriteback(path, offsetU, r.Length)) + frameReader = newCaptureReader(raw, rng.Length, true, + c.compressedFrameWriteback(path, offsetU, rng.Length, innerSource, ct)) } - dec, err := NewDecompressingReader(in, ct) + dec, err = NewDecompressReader(frameReader, ct, innerSource, c.objType) if err != nil { raw.Close(ctx) - return nil, fmt.Errorf("create decompressor: %w", err) + return nil, innerSource, fmt.Errorf("create decompressor: %w", err) } - return dec, nil + return dec, innerSource, nil } // compressedFrameWriteback returns a captureReader callback that // persists the captured frame to the NFS cache in a detached goroutine. // Best-effort: a short capture is logged and skipped — the caller already // got valid decompressed bytes. -func (c *cachedSeekable) compressedFrameWriteback(framePath string, offset int64, expectedSize int) func(context.Context, []byte) { +func (c *cachedSeekable) compressedFrameWriteback(framePath string, offset int64, expectedSize int, src Source, codec CompressionType) func(context.Context, []byte) { return func(ctx context.Context, frame []byte) { if !isCompleteRead(len(frame), expectedSize, nil) { - recordCacheWriteError(ctx, cacheTypeSeekable, cacheOpOpenRangeReader, - fmt.Errorf("compressed frame cache writeback short: got %d bytes, expected %d for %s", len(frame), expectedSize, framePath)) + logger.L().Warn(ctx, "compressed frame cache writeback short, skipping", + zap.Int("got", len(frame)), zap.Int("expected", expectedSize), zap.String("path", framePath)) return } @@ -102,10 +88,13 @@ func (c *cachedSeekable) compressedFrameWriteback(framePath string, offset int64 ctx, span := c.tracer.Start(ctx, "write compressed frame back to cache") defer span.End() + start := time.Now() err := c.writeToCache(ctx, offset, framePath, frame) - if err != nil { + recordWriteback(ctx, time.Since(start), int64(len(frame)), c.objType, src, codec, TriggerRead, err) + + if err != nil && !errors.Is(err, lock.ErrLockAlreadyHeld) { recordError(span, err) - recordCacheWriteError(ctx, cacheTypeSeekable, cacheOpOpenRangeReader, err) + logger.L().Warn(ctx, "failed to write frame back to cache", zap.Error(err)) } }) } diff --git a/packages/shared/pkg/storage/storage_cache_seekable_test.go b/packages/shared/pkg/storage/storage_cache_seekable_test.go index 81f7364c0a..a7ede5d6a0 100644 --- a/packages/shared/pkg/storage/storage_cache_seekable_test.go +++ b/packages/shared/pkg/storage/storage_cache_seekable_test.go @@ -17,7 +17,8 @@ import ( // mustClose closes a RangeReader and asserts no error. func mustClose(t *testing.T, rc RangeReader) { t.Helper() - require.NoError(t, rc.Close(t.Context())) + _, err := rc.Close(t.Context()) + require.NoError(t, err) } // bytesRangeReader wraps an in-memory byte slice as a RangeReader for tests. @@ -28,14 +29,14 @@ func bytesRangeReader(b []byte) RangeReader { // testReadAt emulates the removed cachedSeekable.ReadAt via OpenRangeReader. // This preserves the base test structure after ReadAt was removed from the Seekable interface. func testReadAt(ctx context.Context, c *cachedSeekable, buff []byte, off int64) (int, error) { - rc, err := c.OpenRangeReader(ctx, off, int64(len(buff)), nil) + rc, _, err := c.OpenRangeReader(ctx, off, int64(len(buff)), nil) if err != nil { return 0, err } n, err := io.ReadFull(rc, buff) - closeErr := rc.Close(ctx) + _, closeErr := rc.Close(ctx) if errors.Is(err, io.ErrUnexpectedEOF) { err = io.EOF } @@ -192,10 +193,10 @@ func TestCachedFileObjectProvider_WriteTo(t *testing.T) { inner.EXPECT(). OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, (*FrameTable)(nil)). - RunAndReturn(func(_ context.Context, off int64, length int64, _ *FrameTable) (RangeReader, error) { + RunAndReturn(func(_ context.Context, off int64, length int64, _ *FrameTable) (RangeReader, Source, error) { end := min(int(off)+int(length), len(fakeData)) - return NewRangeReader(io.NopCloser(bytes.NewReader(fakeData[off:end]))), nil + return NewRangeReader(io.NopCloser(bytes.NewReader(fakeData[off:end]))), UnknownSource, nil }) tempDir := t.TempDir() @@ -327,7 +328,7 @@ func TestCachedSeekableObjectProvider_ReadAt(t *testing.T) { inner := NewMockSeekable(t) inner.EXPECT(). OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, (*FrameTable)(nil)). - Return(NewRangeReader(io.NopCloser(bytes.NewReader(nil))), nil) + Return(NewRangeReader(io.NopCloser(bytes.NewReader(nil))), UnknownSource, nil) c := cachedSeekable{ path: tempDir, @@ -356,7 +357,7 @@ func TestCachedSeekableObjectProvider_ReadAt(t *testing.T) { inner := NewMockSeekable(t) inner.EXPECT(). OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, (*FrameTable)(nil)). - Return(NewRangeReader(io.NopCloser(bytes.NewReader(data))), nil) + Return(NewRangeReader(io.NopCloser(bytes.NewReader(data))), UnknownSource, nil) c := cachedSeekable{ path: tempDir, @@ -418,7 +419,7 @@ func TestCachedSeekable_ReadAt_PreservesEOF(t *testing.T) { inner := NewMockSeekable(t) inner.EXPECT(). OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, (*FrameTable)(nil)). - Return(NewRangeReader(io.NopCloser(bytes.NewReader([]byte{1, 2, 3}))), nil) + Return(NewRangeReader(io.NopCloser(bytes.NewReader([]byte{1, 2, 3}))), UnknownSource, nil) c := cachedSeekable{ path: tempDir, @@ -442,7 +443,7 @@ func TestCachedSeekable_ReadAt_PreservesEOF(t *testing.T) { inner := NewMockSeekable(t) inner.EXPECT(). OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, (*FrameTable)(nil)). - Return(NewRangeReader(io.NopCloser(bytes.NewReader([]byte{1, 2, 3, 4, 5, 6, 7, 8, 9, 10}))), nil) + Return(NewRangeReader(io.NopCloser(bytes.NewReader([]byte{1, 2, 3, 4, 5, 6, 7, 8, 9, 10}))), UnknownSource, nil) c := cachedSeekable{ path: tempDir, @@ -468,8 +469,8 @@ func TestCachedSeekable_ReadAt_SkipCacheWriteback(t *testing.T) { inner := NewMockSeekable(t) inner.EXPECT(). OpenRangeReader(mock.Anything, mock.Anything, mock.Anything, (*FrameTable)(nil)). - RunAndReturn(func(_ context.Context, _ int64, _ int64, _ *FrameTable) (RangeReader, error) { - return NewRangeReader(io.NopCloser(bytes.NewReader(data))), nil + RunAndReturn(func(_ context.Context, _ int64, _ int64, _ *FrameTable) (RangeReader, Source, error) { + return NewRangeReader(io.NopCloser(bytes.NewReader(data))), UnknownSource, nil }) c := cachedSeekable{ @@ -504,7 +505,7 @@ func TestCachedSeekable_OpenRangeReader(t *testing.T) { inner := NewMockSeekable(t) inner.EXPECT(). OpenRangeReader(mock.Anything, int64(0), int64(len(data)), (*FrameTable)(nil)). - Return(NewRangeReader(io.NopCloser(bytes.NewReader(data))), nil). + Return(NewRangeReader(io.NopCloser(bytes.NewReader(data))), UnknownSource, nil). Once() c := cachedSeekable{ @@ -515,25 +516,25 @@ func TestCachedSeekable_OpenRangeReader(t *testing.T) { } // First call: cache miss, reads from inner. - rc, err := c.OpenRangeReader(t.Context(), 0, int64(len(data)), nil) + rc, _, err := c.OpenRangeReader(t.Context(), 0, int64(len(data)), nil) require.NoError(t, err) got, err := io.ReadAll(rc) require.NoError(t, err) assert.Equal(t, data, got) - require.NoError(t, rc.Close(t.Context())) + mustClose(t, rc) c.wg.Wait() // Second call: should serve from NFS cache, inner not called again. c.inner = nil - rc2, err := c.OpenRangeReader(t.Context(), 0, int64(len(data)), nil) + rc2, _, err := c.OpenRangeReader(t.Context(), 0, int64(len(data)), nil) require.NoError(t, err) got2, err := io.ReadAll(rc2) require.NoError(t, err) assert.Equal(t, data, got2) - require.NoError(t, rc2.Close(t.Context())) + mustClose(t, rc2) }) t.Run("skip cache writeback returns inner directly", func(t *testing.T) { @@ -545,8 +546,8 @@ func TestCachedSeekable_OpenRangeReader(t *testing.T) { inner := NewMockSeekable(t) inner.EXPECT(). OpenRangeReader(mock.Anything, int64(0), int64(len(data)), (*FrameTable)(nil)). - RunAndReturn(func(_ context.Context, _ int64, _ int64, _ *FrameTable) (RangeReader, error) { - return NewRangeReader(io.NopCloser(bytes.NewReader(data))), nil + RunAndReturn(func(_ context.Context, _ int64, _ int64, _ *FrameTable) (RangeReader, Source, error) { + return NewRangeReader(io.NopCloser(bytes.NewReader(data))), UnknownSource, nil }). Times(2) @@ -559,13 +560,13 @@ func TestCachedSeekable_OpenRangeReader(t *testing.T) { ctx := WithSkipCacheWriteback(t.Context()) - rc, err := c.OpenRangeReader(ctx, 0, int64(len(data)), nil) + rc, _, err := c.OpenRangeReader(ctx, 0, int64(len(data)), nil) require.NoError(t, err) got, err := io.ReadAll(rc) require.NoError(t, err) assert.Equal(t, data, got) - require.NoError(t, rc.Close(ctx)) + mustClose(t, rc) c.wg.Wait() @@ -574,13 +575,13 @@ func TestCachedSeekable_OpenRangeReader(t *testing.T) { _, err = os.Stat(chunkPath) assert.True(t, os.IsNotExist(err), "skip writeback should not populate cache") - rc2, err := c.OpenRangeReader(ctx, 0, int64(len(data)), nil) + rc2, _, err := c.OpenRangeReader(ctx, 0, int64(len(data)), nil) require.NoError(t, err) got2, err := io.ReadAll(rc2) require.NoError(t, err) assert.Equal(t, data, got2) - require.NoError(t, rc2.Close(ctx)) + mustClose(t, rc2) }) t.Run("truncated inner read does not populate cache", func(t *testing.T) { @@ -591,7 +592,7 @@ func TestCachedSeekable_OpenRangeReader(t *testing.T) { inner := NewMockSeekable(t) inner.EXPECT(). OpenRangeReader(mock.Anything, int64(0), int64(5), (*FrameTable)(nil)). - Return(NewRangeReader(io.NopCloser(bytes.NewReader([]byte{0xAA, 0xBB}))), nil) + Return(NewRangeReader(io.NopCloser(bytes.NewReader([]byte{0xAA, 0xBB}))), UnknownSource, nil) c := cachedSeekable{ path: tempDir, @@ -600,13 +601,13 @@ func TestCachedSeekable_OpenRangeReader(t *testing.T) { tracer: noopTracer, } - rc, err := c.OpenRangeReader(t.Context(), 0, 5, nil) + rc, _, err := c.OpenRangeReader(t.Context(), 0, 5, nil) require.NoError(t, err) got, err := io.ReadAll(rc) require.NoError(t, err) assert.Equal(t, []byte{0xAA, 0xBB}, got) - require.NoError(t, rc.Close(t.Context())) + mustClose(t, rc) c.wg.Wait() @@ -695,13 +696,13 @@ func TestCacheWriteThroughReader(t *testing.T) { inner := NewRangeReader(io.NopCloser(bytes.NewReader(data))) r := newCaptureReader(inner, len(data), false, - c.uncompressedChunkWriteback(c.makeChunkFilename(0), 0, int64(len(data)))) + c.uncompressedChunkWriteback(c.makeChunkFilename(0), 0, int64(len(data)), UnknownSource)) got, err := io.ReadAll(r) require.NoError(t, err) assert.Equal(t, data, got) - require.NoError(t, r.Close(t.Context())) + mustClose(t, r) c.wg.Wait() cached, err := os.ReadFile(c.makeChunkFilename(0)) @@ -719,13 +720,13 @@ func TestCacheWriteThroughReader(t *testing.T) { inner := NewRangeReader(io.NopCloser(bytes.NewReader([]byte{0xAA, 0xBB}))) r := newCaptureReader(inner, 5, false, - c.uncompressedChunkWriteback(c.makeChunkFilename(0), 0, 5)) + c.uncompressedChunkWriteback(c.makeChunkFilename(0), 0, 5, UnknownSource)) got, err := io.ReadAll(r) require.NoError(t, err) assert.Equal(t, []byte{0xAA, 0xBB}, got) - require.NoError(t, r.Close(t.Context())) + mustClose(t, r) c.wg.Wait() _, err = os.Stat(c.makeChunkFilename(0)) @@ -740,7 +741,7 @@ func TestCacheWriteThroughReader(t *testing.T) { inner := NewRangeReader(io.NopCloser(bytes.NewReader(data))) r := newCaptureReader(inner, len(data), false, - c.uncompressedChunkWriteback(c.makeChunkFilename(0), 0, int64(len(data)))) + c.uncompressedChunkWriteback(c.makeChunkFilename(0), 0, int64(len(data)), UnknownSource)) // Read only 2 of 5 bytes, then close without reaching EOF. buf := make([]byte, 2) @@ -748,7 +749,7 @@ func TestCacheWriteThroughReader(t *testing.T) { require.NoError(t, err) assert.Equal(t, 2, n) - require.NoError(t, r.Close(t.Context())) + mustClose(t, r) c.wg.Wait() _, err = os.Stat(c.makeChunkFilename(0)) diff --git a/packages/shared/pkg/storage/storage_fs.go b/packages/shared/pkg/storage/storage_fs.go index fcaac07366..3c4e7f2193 100644 --- a/packages/shared/pkg/storage/storage_fs.go +++ b/packages/shared/pkg/storage/storage_fs.go @@ -30,7 +30,8 @@ type fsStorage struct { var _ StorageProvider = (*fsStorage)(nil) type fsObject struct { - path string + path string + objType SeekableObjectType } var ( @@ -71,18 +72,21 @@ func (s *fsStorage) UploadSignedURL(_ context.Context, path string, ttl time.Dur return u, nil } -func (s *fsStorage) OpenSeekable(_ context.Context, path string, _ SeekableObjectType) (Seekable, error) { +func (s *fsStorage) OpenSeekable(_ context.Context, path string) (Seekable, error) { dir := filepath.Dir(s.getPath(path)) if err := os.MkdirAll(dir, 0o755); err != nil { return nil, err } + objType, _ := seekableObjectType(path) + return &fsObject{ - path: s.getPath(path), + path: s.getPath(path), + objType: objType, }, nil } -func (s *fsStorage) OpenBlob(_ context.Context, path string, _ ObjectType) (Blob, error) { +func (s *fsStorage) OpenBlob(_ context.Context, path string) (Blob, error) { dir := filepath.Dir(s.getPath(path)) if err := os.MkdirAll(dir, 0o755); err != nil { return nil, err @@ -97,7 +101,10 @@ func (s *fsStorage) getPath(path string) string { return filepath.Join(s.basePath, path) } -func (o *fsObject) WriteTo(_ context.Context, dst io.Writer) (int64, error) { +func (o *fsObject) WriteTo(ctx context.Context, dst io.Writer) (n int64, err error) { + start := time.Now() + defer func() { RecordReadBlob(ctx, time.Since(start), n, o.path, SourceFS, err) }() + handle, err := o.getHandle(true) if err != nil { return 0, err @@ -105,7 +112,9 @@ func (o *fsObject) WriteTo(_ context.Context, dst io.Writer) (int64, error) { defer handle.Close() - return io.Copy(dst, handle) + n, err = io.Copy(dst, handle) + + return n, err } func (o *fsObject) Put(_ context.Context, data []byte, _ ...PutOption) error { @@ -214,7 +223,10 @@ func (o *fsObject) Exists(_ context.Context) (bool, error) { return err == nil, err } -func (o *fsObject) Size(_ context.Context) (int64, error) { +func (o *fsObject) Size(ctx context.Context) (_ int64, err error) { + start := time.Now() + defer func() { RecordReadSize(ctx, time.Since(start), o.objType, SourceFS, err) }() + handle, err := o.getHandle(true) if err != nil { return 0, err @@ -303,27 +315,35 @@ func (u *fsPartUploader) Complete(_ context.Context) error { return os.WriteFile(u.fullPath, u.Assemble(), 0o644) } -func (o *fsObject) OpenRangeReader(ctx context.Context, offsetU int64, length int64, frameTable *FrameTable) (RangeReader, error) { +func (o *fsObject) OpenRangeReader(ctx context.Context, offsetU int64, length int64, frameTable *FrameTable) (_ RangeReader, _ Source, err error) { + start := time.Now() + defer func() { RecordReadOpen(ctx, time.Since(start), o.objType, SourceFS, frameTable.CompressionType(), err) }() + if frameTable.IsCompressed() { r, err := frameTable.LocateCompressed(offsetU) if err != nil { - return nil, fmt.Errorf("get frame for offset %d, FS:%s: %w", offsetU, o.path, err) + return nil, SourceFS, fmt.Errorf("get frame for offset %d, FS:%s: %w", offsetU, o.path, err) } raw, err := o.openRangeReader(ctx, r.Offset, int64(r.Length)) if err != nil { - return nil, err + return nil, SourceFS, err } - dec, err := NewDecompressingReader(raw, frameTable.CompressionType()) + dec, err := NewDecompressReader(raw, frameTable.CompressionType(), SourceFS, o.objType) if err != nil { raw.Close(ctx) - return nil, err + return nil, SourceFS, err } - return dec, nil + return dec, SourceFS, nil + } + + raw, err := o.openRangeReader(ctx, offsetU, length) + if err != nil { + return nil, SourceFS, err } - return o.openRangeReader(ctx, offsetU, length) + return raw, SourceFS, nil } diff --git a/packages/shared/pkg/storage/storage_fs_test.go b/packages/shared/pkg/storage/storage_fs_test.go index c01d424072..408ab32413 100644 --- a/packages/shared/pkg/storage/storage_fs_test.go +++ b/packages/shared/pkg/storage/storage_fs_test.go @@ -26,7 +26,7 @@ func TestOpenObject_Write_Exists_WriteTo(t *testing.T) { p := newTempProvider(t) ctx := t.Context() - obj, err := p.OpenBlob(ctx, filepath.Join("sub", "file.txt"), MetadataObjectType) + obj, err := p.OpenBlob(ctx, filepath.Join("sub", "file.txt")) require.NoError(t, err) contents := []byte("hello world") @@ -55,7 +55,7 @@ func TestFSPut(t *testing.T) { const payload = "copy me please" require.NoError(t, os.WriteFile(srcPath, []byte(payload), 0o600)) - obj, err := p.OpenBlob(ctx, "copy/dst.txt", UnknownObjectType) + obj, err := p.OpenBlob(ctx, "copy/dst.txt") require.NoError(t, err) require.NoError(t, obj.Put(t.Context(), []byte(payload))) @@ -70,7 +70,7 @@ func TestDelete(t *testing.T) { p := newTempProvider(t) ctx := t.Context() - obj, err := p.OpenBlob(ctx, "to/delete.txt", 0) + obj, err := p.OpenBlob(ctx, "to/delete.txt") require.NoError(t, err) err = obj.Put(t.Context(), []byte("bye")) @@ -100,7 +100,7 @@ func TestDeleteObjectsWithPrefix(t *testing.T) { "data/sub/c.txt", } for _, pth := range paths { - obj, err := p.OpenBlob(ctx, pth, UnknownObjectType) + obj, err := p.OpenBlob(ctx, pth) require.NoError(t, err) err = obj.Put(t.Context(), []byte("x")) require.NoError(t, err) @@ -121,7 +121,7 @@ func TestWriteToNonExistentObject(t *testing.T) { p := newTempProvider(t) ctx := t.Context() - obj, err := p.OpenBlob(ctx, "missing/file.txt", UnknownObjectType) + obj, err := p.OpenBlob(ctx, "missing/file.txt") require.NoError(t, err) _, err = GetBlob(t.Context(), obj) diff --git a/packages/shared/pkg/storage/storage_google.go b/packages/shared/pkg/storage/storage_google.go index 9e17c14227..32727ab7c6 100644 --- a/packages/shared/pkg/storage/storage_google.go +++ b/packages/shared/pkg/storage/storage_google.go @@ -19,7 +19,6 @@ import ( "cloud.google.com/go/storage" "github.com/googleapis/gax-go/v2" "go.opentelemetry.io/otel/attribute" - "go.opentelemetry.io/otel/metric" "go.uber.org/zap" "google.golang.org/api/iterator" "google.golang.org/api/option" @@ -32,8 +31,6 @@ import ( "github.com/e2b-dev/infra/packages/shared/pkg/env" "github.com/e2b-dev/infra/packages/shared/pkg/limit" "github.com/e2b-dev/infra/packages/shared/pkg/logger" - "github.com/e2b-dev/infra/packages/shared/pkg/telemetry" - "github.com/e2b-dev/infra/packages/shared/pkg/utils" ) const ( @@ -51,31 +48,6 @@ const ( gcsOperationAttr = "operation" gcsOperationAttrWrite = "Write" gcsOperationAttrWriteFromFileSystem = "WriteFromFileSystem" - gcsOperationAttrWriteTo = "WriteTo" - gcsOperationAttrSize = "Size" - // gcsOperationAttrReadAt tags GCS read timer metrics for OpenRangeReader - // (the method was renamed from ReadAt; value kept for dashboard compatibility). - gcsOperationAttrReadAt = "ReadAt" -) - -var ( - googleReadTimerFactory = utils.Must(telemetry.NewTimerFactory(meter, - "orchestrator.storage.gcs.read", - "Duration of GCS reads", - "Total GCS bytes read", - "Total GCS reads", - )) - googleWriteTimerFactory = utils.Must(telemetry.NewTimerFactory(meter, - "orchestrator.storage.gcs.write", - "Duration of GCS writes", - "Total bytes written to GCS", - "Total writes to GCS", - )) - gcsConcurrentReads = utils.Must(meter.Int64UpDownCounter( - "orchestrator.storage.gcs.read.concurrent", - metric.WithDescription("Number of GCS range readers currently open"), - metric.WithUnit("{read}"), - )) ) type gcpStorage struct { @@ -91,6 +63,7 @@ type gcpObject struct { storage *gcpStorage path string handle *storage.ObjectHandle + objType SeekableObjectType limiter *limit.Limiter } @@ -173,7 +146,7 @@ func (s *gcpStorage) UploadSignedURL(_ context.Context, path string, ttl time.Du return url, nil } -func (s *gcpStorage) OpenSeekable(_ context.Context, path string, _ SeekableObjectType) (Seekable, error) { +func (s *gcpStorage) OpenSeekable(_ context.Context, path string) (Seekable, error) { handle := s.bucket.Object(path).Retryer( storage.WithMaxAttempts(googleMaxAttempts), storage.WithPolicy(storage.RetryAlways), @@ -186,16 +159,19 @@ func (s *gcpStorage) OpenSeekable(_ context.Context, path string, _ SeekableObje ), ) + objType, _ := seekableObjectType(path) + return &gcpObject{ storage: s, path: path, handle: handle, + objType: objType, limiter: s.limiter, }, nil } -func (s *gcpStorage) OpenBlob(_ context.Context, path string, _ ObjectType) (Blob, error) { +func (s *gcpStorage) OpenBlob(_ context.Context, path string) (Blob, error) { handle := s.bucket.Object(path).Retryer( storage.WithMaxAttempts(googleMaxAttempts), storage.WithPolicy(storage.RetryAlways), @@ -234,16 +210,15 @@ func (o *gcpObject) Exists(ctx context.Context) (bool, error) { return err == nil, ignoreNotExists(err) } -func (o *gcpObject) Size(ctx context.Context) (int64, error) { - timer := googleReadTimerFactory.Begin(attribute.String(gcsOperationAttr, gcsOperationAttrSize)) +func (o *gcpObject) Size(ctx context.Context) (_ int64, err error) { + start := time.Now() + defer func() { RecordReadSize(ctx, time.Since(start), o.objType, SourceGCS, err) }() ctx, cancel := context.WithTimeout(ctx, googleOperationTimeout) defer cancel() attrs, err := o.handle.Attrs(ctx) if err != nil { - timer.Failure(ctx, 0) - if errors.Is(err, storage.ErrObjectNotExist) { // use ours instead of theirs return 0, fmt.Errorf("failed to get GCS object (%q) attributes: %w", o.path, ErrObjectNotExist) @@ -252,8 +227,6 @@ func (o *gcpObject) Size(ctx context.Context) (int64, error) { return 0, fmt.Errorf("failed to get GCS object (%q) attributes: %w", o.path, err) } - timer.Success(ctx, 0) - if v, ok := attrs.Metadata[MetadataKeyUncompressedSize]; ok { parsed, parseErr := strconv.ParseInt(v, 10, 64) if parseErr == nil { @@ -302,8 +275,6 @@ func (o *gcpObject) openRangeReader(ctx context.Context, off, length int64) (Ran return nil, fmt.Errorf("failed to create GCS range reader for %q at %d+%d: %w", o.path, off, length, err) } - gcsConcurrentReads.Add(ctx, 1) - return &idleTimeoutReader{ ReadCloser: reader, cancel: cancel, @@ -314,6 +285,7 @@ func (o *gcpObject) openRangeReader(ctx context.Context, off, length int64) (Ran // idleTimeoutReader fires cancel() after googleReadTimeout with no Read // activity (in-flight Read with no progress, or no Read called). type idleTimeoutReader struct { + readMeter io.ReadCloser cancel context.CancelFunc @@ -323,7 +295,9 @@ type idleTimeoutReader struct { func (r *idleTimeoutReader) Read(p []byte) (int, error) { r.timer.Reset(googleReadTimeout) + t0 := time.Now() n, err := r.ReadCloser.Read(p) + r.observe(n, t0) if err != nil { r.timer.Stop() } else { @@ -333,12 +307,11 @@ func (r *idleTimeoutReader) Read(p []byte) (int, error) { return n, err } -func (r *idleTimeoutReader) Close(ctx context.Context) error { +func (r *idleTimeoutReader) Close(_ context.Context) (*ReadStats, error) { r.timer.Stop() defer r.cancel() - gcsConcurrentReads.Add(ctx, -1) - return r.ReadCloser.Close() + return r.stats(), r.ReadCloser.Close() } func (o *gcpObject) Put(ctx context.Context, data []byte, opts ...PutOption) error { @@ -389,16 +362,15 @@ func (o *gcpObject) Put(ctx context.Context, data []byte, opts ...PutOption) err return nil } -func (o *gcpObject) WriteTo(ctx context.Context, dst io.Writer) (int64, error) { - timer := googleReadTimerFactory.Begin(attribute.String(gcsOperationAttr, gcsOperationAttrWriteTo)) +func (o *gcpObject) WriteTo(ctx context.Context, dst io.Writer) (n int64, err error) { + start := time.Now() + defer func() { RecordReadBlob(ctx, time.Since(start), n, o.path, SourceGCS, err) }() ctx, cancel := context.WithTimeout(ctx, googleReadTimeout) defer cancel() reader, err := o.handle.NewReader(ctx) if err != nil { - timer.Failure(ctx, 0) - if errors.Is(err, storage.ErrObjectNotExist) { return 0, fmt.Errorf("failed to create reader for %q: %w", o.path, ErrObjectNotExist) } @@ -409,15 +381,11 @@ func (o *gcpObject) WriteTo(ctx context.Context, dst io.Writer) (int64, error) { defer reader.Close() buff := make([]byte, googleBufferSize) - n, err := io.CopyBuffer(dst, reader, buff) + n, err = io.CopyBuffer(dst, reader, buff) if err != nil { - timer.Failure(ctx, n) - return n, fmt.Errorf("failed to copy %q to buffer: %w", o.path, err) } - timer.Success(ctx, n) - return n, nil } @@ -619,43 +587,39 @@ func parseServiceAccountBase64(serviceAccount string) (*gcpServiceToken, error) return &sa, nil } -func (o *gcpObject) OpenRangeReader(ctx context.Context, offsetU int64, length int64, frameTable *FrameTable) (RangeReader, error) { - timer := googleReadTimerFactory.Begin(attribute.String(gcsOperationAttr, gcsOperationAttrReadAt)) +func (o *gcpObject) OpenRangeReader(ctx context.Context, offsetU int64, length int64, frameTable *FrameTable) (_ RangeReader, _ Source, err error) { + start := time.Now() + defer func() { + RecordReadOpen(ctx, time.Since(start), o.objType, SourceGCS, frameTable.CompressionType(), err) + }() if !frameTable.IsCompressed() { rc, err := o.openRangeReader(ctx, offsetU, length) if err != nil { - timer.Failure(ctx, 0) - - return nil, err + return nil, SourceGCS, err } - return newObservableReader(rc, timer, nil), nil + return rc, SourceGCS, nil } r, err := frameTable.LocateCompressed(offsetU) if err != nil { - timer.Failure(ctx, 0) - - return nil, fmt.Errorf("get frame for offset %d, GCS:%s: %w", offsetU, o.path, err) + return nil, SourceGCS, fmt.Errorf("get frame for offset %d, GCS:%s: %w", offsetU, o.path, err) } raw, err := o.openRangeReader(ctx, r.Offset, int64(r.Length)) if err != nil { - timer.Failure(ctx, 0) - - return nil, err + return nil, SourceGCS, err } - dec, err := NewDecompressingReader(raw, frameTable.CompressionType()) + dec, err := NewDecompressReader(raw, frameTable.CompressionType(), SourceGCS, o.objType) if err != nil { raw.Close(ctx) - timer.Failure(ctx, 0) - return nil, err + return nil, SourceGCS, err } - return newObservableReader(dec, timer, nil), nil + return dec, SourceGCS, nil } func isResourceExhausted(err error) bool { diff --git a/packages/shared/pkg/telemetry/meters.go b/packages/shared/pkg/telemetry/meters.go index 2d77c8593e..c9c38002ea 100644 --- a/packages/shared/pkg/telemetry/meters.go +++ b/packages/shared/pkg/telemetry/meters.go @@ -548,6 +548,60 @@ func NewTimerFactory( return TimerFactory{duration, bytes, count}, nil } +// FloatTimerFactory records duration as fractional milliseconds so sub-ms +// operations aren't truncated to 0. The duration histogram and event counter +// share (rate()-friendly); only the bytes counter splits out to +// .size so Grafana's unit detection doesn't conflate ms with By. +type FloatTimerFactory struct { + duration metric.Float64Histogram + bytes metric.Int64Counter + count metric.Int64Counter +} + +// SubMillisecondMsBuckets resolve sub-ms operations (mmap / cache hits) that the +// default OTEL buckets (first boundary 5ms) collapse into one, while still +// covering remote reads to ~10s. +var SubMillisecondMsBuckets = []float64{ + 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10, 25, 50, 100, 250, 500, 1000, 2500, 5000, 10000, +} + +func NewFloatTimerFactory( + meter metric.Meter, + metricName, durationDescription, bytesDescription string, +) (FloatTimerFactory, error) { + duration, err := meter.Float64Histogram(metricName, + metric.WithDescription(durationDescription), + metric.WithUnit("ms"), + metric.WithExplicitBucketBoundaries(SubMillisecondMsBuckets...), + ) + if err != nil { + return FloatTimerFactory{}, fmt.Errorf("failed to create duration histogram: %w", err) + } + + bytes, err := meter.Int64Counter(metricName+".size", + metric.WithDescription(bytesDescription), + metric.WithUnit("By"), + ) + if err != nil { + return FloatTimerFactory{}, fmt.Errorf("failed to create bytes counter: %w", err) + } + + count, err := meter.Int64Counter(metricName, + metric.WithDescription("Total "+metricName+" events recorded"), + ) + if err != nil { + return FloatTimerFactory{}, fmt.Errorf("failed to create count counter: %w", err) + } + + return FloatTimerFactory{duration, bytes, count}, nil +} + +func (f *FloatTimerFactory) Record(ctx context.Context, dur time.Duration, total int64, attrs metric.MeasurementOption) { + f.duration.Record(ctx, float64(dur)/float64(time.Millisecond), attrs) + f.bytes.Add(ctx, total, attrs) + f.count.Add(ctx, 1, attrs) +} + func (f *TimerFactory) Begin(kv ...attribute.KeyValue) *Stopwatch { return &Stopwatch{ histogram: f.duration, @@ -602,9 +656,9 @@ func PrecomputeAttrs(kv ...attribute.KeyValue) metric.MeasurementOption { // RecordRaw records an operation using a precomputed attribute option, it does // not include any previous attributes passed at Begin(). Zero-allocation // alternative to Success/Failure for hot paths. -func (t Stopwatch) RecordRaw(ctx context.Context, total int64, precomputedAttrs metric.MeasurementOption) { +func (t Stopwatch) RecordRaw(ctx context.Context, total int64, allAttrs metric.MeasurementOption) { amount := time.Since(t.start).Milliseconds() - t.histogram.Record(ctx, amount, precomputedAttrs) - t.sum.Add(ctx, total, precomputedAttrs) - t.count.Add(ctx, 1, precomputedAttrs) + t.histogram.Record(ctx, amount, allAttrs) + t.sum.Add(ctx, total, allAttrs) + t.count.Add(ctx, 1, allAttrs) } diff --git a/tests/integration/internal/tests/api/sandboxes/sandbox_rapid_pause_resume_test.go b/tests/integration/internal/tests/api/sandboxes/sandbox_rapid_pause_resume_test.go index 3b36793ff7..6cd1a1c379 100644 --- a/tests/integration/internal/tests/api/sandboxes/sandbox_rapid_pause_resume_test.go +++ b/tests/integration/internal/tests/api/sandboxes/sandbox_rapid_pause_resume_test.go @@ -108,12 +108,12 @@ func verifyChainOnStorage(t *testing.T, ctx context.Context, chain []chainNode) ancestors[node.buildID] = chainAncestors paths := storage.Paths{BuildID: node.buildID} - verifyHeader(t, ctx, persistence, node, paths, storage.MemfileName, paths.MemfileHeader(), storage.MemfileObjectType, chainAncestors) - verifyHeader(t, ctx, persistence, node, paths, storage.RootfsName, paths.RootfsHeader(), storage.RootFSObjectType, chainAncestors) + verifyHeader(t, ctx, persistence, node, paths, storage.MemfileName, paths.MemfileHeader(), chainAncestors) + verifyHeader(t, ctx, persistence, node, paths, storage.RootfsName, paths.RootfsHeader(), chainAncestors) } } -func verifyHeader(t *testing.T, ctx context.Context, persistence storage.StorageProvider, node chainNode, paths storage.Paths, fileName, headerPath string, objType storage.SeekableObjectType, ancestors []string) { +func verifyHeader(t *testing.T, ctx context.Context, persistence storage.StorageProvider, node chainNode, paths storage.Paths, fileName, headerPath string, ancestors []string) { t.Helper() h := loadHeaderWithPolling(t, ctx, persistence, headerPath, node.name, fileName) @@ -129,13 +129,13 @@ func verifyHeader(t *testing.T, ctx context.Context, persistence storage.Storage assert.Truef(t, ok, "%s/%s: Builds map missing ancestor %s — child finalized before parent's SwapHeader", node.name, fileName, ancestor) } - verifyChecksum(t, ctx, persistence, node, paths, fileName, objType, bd) + verifyChecksum(t, ctx, persistence, node, paths, fileName, bd) } // verifyChecksum streams self's data file through SHA-256 and compares to // BuildData.Checksum. For unchanged files (empty diff) the entry has zero // values and this is a no-op. -func verifyChecksum(t *testing.T, ctx context.Context, persistence storage.StorageProvider, node chainNode, paths storage.Paths, fileName string, objType storage.SeekableObjectType, bd header.BuildData) { +func verifyChecksum(t *testing.T, ctx context.Context, persistence storage.StorageProvider, node chainNode, paths storage.Paths, fileName string, bd header.BuildData) { t.Helper() if bd.Size == 0 { @@ -144,10 +144,10 @@ func verifyChecksum(t *testing.T, ctx context.Context, persistence storage.Stora dataPath := paths.DataFile(fileName, bd.FrameData.CompressionType()) - obj, err := persistence.OpenSeekable(ctx, dataPath, objType) + obj, err := persistence.OpenSeekable(ctx, dataPath) require.NoErrorf(t, err, "%s/%s: open data file %s", node.name, fileName, dataPath) - rc, err := obj.OpenRangeReader(ctx, 0, bd.Size, bd.FrameData) + rc, _, err := obj.OpenRangeReader(ctx, 0, bd.Size, bd.FrameData) require.NoErrorf(t, err, "%s/%s: open range reader", node.name, fileName) defer rc.Close(context.WithoutCancel(ctx)) From ae9e7ecdcd128151b3d4083e54bf74f2e26db9ca Mon Sep 17 00:00:00 2001 From: Lev Brouk Date: Mon, 22 Jun 2026 14:38:27 -0700 Subject: [PATCH 2/2] removed another legacy metric (unused) --- .../pkg/sandbox/block/metrics/main.go | 17 +---------------- .../pkg/sandbox/block/streaming_chunk.go | 13 ------------- 2 files changed, 1 insertion(+), 29 deletions(-) diff --git a/packages/orchestrator/pkg/sandbox/block/metrics/main.go b/packages/orchestrator/pkg/sandbox/block/metrics/main.go index ece0849537..50675be4a4 100644 --- a/packages/orchestrator/pkg/sandbox/block/metrics/main.go +++ b/packages/orchestrator/pkg/sandbox/block/metrics/main.go @@ -8,15 +8,9 @@ import ( "github.com/e2b-dev/infra/packages/shared/pkg/telemetry" ) -const ( - orchestratorBlockChunksStore = "orchestrator.blocks.chunks.store" - orchestratorChunkSlice = "orchestrator.chunk.slice" -) +const orchestratorChunkSlice = "orchestrator.chunk.slice" type Metrics struct { - // WriteChunksMetric is used to measure performance of writing chunks to disk. - WriteChunksTimerFactory telemetry.TimerFactory - ChunkSliceTimerFactory telemetry.FloatTimerFactory } @@ -26,15 +20,6 @@ func NewMetrics(meterProvider metric.MeterProvider) (Metrics, error) { blocksMeter := meterProvider.Meter("github.com/e2b-dev/infra/packages/orchestrator/pkg/sandbox/block/metrics") var err error - if m.WriteChunksTimerFactory, err = telemetry.NewTimerFactory( - blocksMeter, orchestratorBlockChunksStore, - "Time taken to write memory chunks to disk", - "Total bytes written to disk", - "Total cache writes", - ); err != nil { - return m, fmt.Errorf("failed to get stored chunks metric: %w", err) - } - if m.ChunkSliceTimerFactory, err = telemetry.NewFloatTimerFactory( blocksMeter, orchestratorChunkSlice, "Time taken by Chunker to serve a Slice() (source=mmap when served from cache)", diff --git a/packages/orchestrator/pkg/sandbox/block/streaming_chunk.go b/packages/orchestrator/pkg/sandbox/block/streaming_chunk.go index 1599fedb84..d92b4233b7 100644 --- a/packages/orchestrator/pkg/sandbox/block/streaming_chunk.go +++ b/packages/orchestrator/pkg/sandbox/block/streaming_chunk.go @@ -15,7 +15,6 @@ import ( "github.com/e2b-dev/infra/packages/orchestrator/pkg/sandbox/block/metrics" "github.com/e2b-dev/infra/packages/shared/pkg/featureflags" "github.com/e2b-dev/infra/packages/shared/pkg/storage" - "github.com/e2b-dev/infra/packages/shared/pkg/telemetry" ) const ( @@ -310,14 +309,8 @@ func (c *Chunker) progressiveFetch(ctx context.Context, s *fetchSession, mmapSli // Read in batches of max(blockSize, minReadBatchSize) to align notification // granularity with the read size and minimize lock/notify overhead. readEnd := min(totalRead+readBatch, s.chunkLen) - sw := c.metrics.WriteChunksTimerFactory.Begin() n, readErr := io.ReadFull(reader, mmapSlice[totalRead:readEnd]) totalRead += int64(n) - if readErr == nil || totalRead >= s.chunkLen { - sw.RecordRaw(ctx, int64(n), writeSuccessAttr) - } else { - sw.RecordRaw(ctx, int64(n), writeFailureAttr) - } if n > 0 { // Dirty marking is deferred to runFetch after the full chunk is fetched. @@ -389,9 +382,3 @@ func (c *Chunker) Size() int64 { func (c *Chunker) FileSize(ctx context.Context) (int64, error) { return c.cache.FileSize(ctx) } - -// writeSuccessAttr and writeFailureAttr are pre-allocated result attributes for mmap write observations. -var ( - writeSuccessAttr = telemetry.PrecomputeAttrs(telemetry.Success) - writeFailureAttr = telemetry.PrecomputeAttrs(telemetry.Failure) -)