From 914ed40320b45ac2f37bb882049f06910446c25b Mon Sep 17 00:00:00 2001 From: Marcin Rataj Date: Wed, 16 Mar 2022 18:19:32 +0100 Subject: [PATCH] feat(gw): response type histogram metrics Adds: - response-type agnostic firstContentBlockGetMetric which counts the latency til the first content block. - car/block/file/gen-dir-index duration histogram metrics that show how long each response type takes --- core/corehttp/gateway_handler.go | 105 ++++++++++++++----- core/corehttp/gateway_handler_block.go | 6 +- core/corehttp/gateway_handler_car.go | 6 +- core/corehttp/gateway_handler_unixfs.go | 7 +- core/corehttp/gateway_handler_unixfs_dir.go | 8 +- core/corehttp/gateway_handler_unixfs_file.go | 6 +- 6 files changed, 104 insertions(+), 34 deletions(-) diff --git a/core/corehttp/gateway_handler.go b/core/corehttp/gateway_handler.go index cbef40f4f67..57f0fa86bb9 100644 --- a/core/corehttp/gateway_handler.go +++ b/core/corehttp/gateway_handler.go @@ -62,8 +62,15 @@ type gatewayHandler struct { config GatewayConfig api coreiface.CoreAPI - unixfsGetMetric *prometheus.SummaryVec - unixfsGetHistMetric *prometheus.HistogramVec + // generic metrics + firstContentBlockGetMetric *prometheus.HistogramVec + unixfsGetMetric *prometheus.SummaryVec // deprecated, use firstContentBlockGetMetric + + // response type metrics + unixfsFileGetMetric *prometheus.HistogramVec + unixfsGenDirGetMetric *prometheus.HistogramVec + carStreamGetMetric *prometheus.HistogramVec + rawBlockGetMetric *prometheus.HistogramVec } // StatusResponseWriter enables us to override HTTP Status Code passed to @@ -86,48 +93,93 @@ func (sw *statusResponseWriter) WriteHeader(code int) { sw.ResponseWriter.WriteHeader(code) } -func newGatewayHandler(c GatewayConfig, api coreiface.CoreAPI) *gatewayHandler { - unixfsGetMetric := prometheus.NewSummaryVec( - // TODO: deprecate and switch to content type agnostic metrics: https://github.com/ipfs/go-ipfs/issues/8441 +func newGatewaySummaryMetric(name string, help string) *prometheus.SummaryVec { + summaryMetric := prometheus.NewSummaryVec( prometheus.SummaryOpts{ Namespace: "ipfs", Subsystem: "http", - Name: "unixfs_get_latency_seconds", - Help: "The time till the first block is received when 'getting' a file from the gateway.", + Name: name, + Help: help, }, []string{"gateway"}, ) - if err := prometheus.Register(unixfsGetMetric); err != nil { + if err := prometheus.Register(summaryMetric); err != nil { if are, ok := err.(prometheus.AlreadyRegisteredError); ok { - unixfsGetMetric = are.ExistingCollector.(*prometheus.SummaryVec) + summaryMetric = are.ExistingCollector.(*prometheus.SummaryVec) } else { - log.Errorf("failed to register unixfsGetMetric: %v", err) + log.Errorf("failed to register ipfs_http_%s: %v", name, err) } } + return summaryMetric +} - unixfsGetHistMetric := prometheus.NewHistogramVec( +func newGatewayHistogramMetric(name string, help string) *prometheus.HistogramVec { + // We can add buckets as a parameter in the future, but for now using static defaults + // suggested in https://github.com/ipfs/go-ipfs/issues/8441 + defaultBuckets := []float64{0.1, 0.5, 1, 2, 3, 5, 8, 13} + histogramMetric := prometheus.NewHistogramVec( prometheus.HistogramOpts{ Namespace: "ipfs", Subsystem: "http", - Name: "unixfs_get_latency_hist_seconds", - Help: "The time till the first block is received when 'getting' a file from the gateway.", - Buckets: []float64{0.1, 0.5, 1, 2, 3, 5, 8, 13}, + Name: name, + Help: help, + Buckets: defaultBuckets, }, []string{"gateway"}, ) - if err := prometheus.Register(unixfsGetHistMetric); err != nil { + if err := prometheus.Register(histogramMetric); err != nil { if are, ok := err.(prometheus.AlreadyRegisteredError); ok { - unixfsGetHistMetric = are.ExistingCollector.(*prometheus.HistogramVec) + histogramMetric = are.ExistingCollector.(*prometheus.HistogramVec) } else { - log.Errorf("failed to register unixfsGetMetric: %v", err) + log.Errorf("failed to register ipfs_http_%s: %v", name, err) } } + return histogramMetric +} +func newGatewayHandler(c GatewayConfig, api coreiface.CoreAPI) *gatewayHandler { i := &gatewayHandler{ - config: c, - api: api, - unixfsGetMetric: unixfsGetMetric, - unixfsGetHistMetric: unixfsGetHistMetric, + config: c, + api: api, + // Improved Metrics + // ---------------------------- + // Time till the first content block (bar in /ipfs/cid/foo/bar) + // (format-agnostic, across all response types) + firstContentBlockGetMetric: newGatewayHistogramMetric( + "gw_first_content_block_get_latency_seconds", + "The time till the first content block is received on GET from the gateway.", + ), + + // Response-type specific metrics + // ---------------------------- + // UnixFS: time it takes to return a file + unixfsFileGetMetric: newGatewayHistogramMetric( + "gw_unixfs_file_get_duration_seconds", + "The time it takes till the entire file is served on GET from the gateway.", + ), + // UnixFS: time it takes to generate static HTML with directory listing + unixfsGenDirGetMetric: newGatewayHistogramMetric( + "gw_unixfs_gen_dir_listing_get_duration_seconds", + "The time it takes till generated HTML with directory listing is served on GET from the gateway.", + ), + // CAR: time it takes to return requested CAR stream + carStreamGetMetric: newGatewayHistogramMetric( + "gw_car_stream_get_duration_seconds", + "The time it takes to get entire CAR stream on GET from the gateway.", + ), + // Block: time it takes to return requested Block + rawBlockGetMetric: newGatewayHistogramMetric( + "gw_raw_block_get_duration_seconds", + "The time it takes to get entire raw Block on GET from the gateway.", + ), + + // Legacy Metrics + // ---------------------------- + unixfsGetMetric: newGatewaySummaryMetric( // TODO: remove? + // (deprecated, use firstContentBlockGetMetric instead) + "unixfs_get_latency_seconds", + "The time till the first unixfs node is received on GET from the gateway.", + ), } return i } @@ -311,9 +363,10 @@ func (i *gatewayHandler) getOrHeadHandler(w http.ResponseWriter, r *http.Request webError(w, "ipfs block get "+resolvedPath.Cid().String(), err, http.StatusInternalServerError) return } + ns := contentPath.Namespace() timeToGetFirstContentBlock := time.Since(begin).Seconds() - i.unixfsGetMetric.WithLabelValues(contentPath.Namespace()).Observe(timeToGetFirstContentBlock) - i.unixfsGetHistMetric.WithLabelValues(contentPath.Namespace()).Observe(timeToGetFirstContentBlock) + i.unixfsGetMetric.WithLabelValues(ns).Observe(timeToGetFirstContentBlock) // deprecated, use firstContentBlockGetMetric instead + i.firstContentBlockGetMetric.WithLabelValues(ns).Observe(timeToGetFirstContentBlock) // HTTP Headers i.addUserHeaders(w) // ok, _now_ write user's headers. @@ -330,15 +383,15 @@ func (i *gatewayHandler) getOrHeadHandler(w http.ResponseWriter, r *http.Request switch responseFormat { case "": // The implicit response format is UnixFS logger.Debugw("serving unixfs", "path", contentPath) - i.serveUnixFs(w, r, resolvedPath, contentPath, logger) + i.serveUnixFs(w, r, resolvedPath, contentPath, begin, logger) return case "application/vnd.ipld.raw": logger.Debugw("serving raw block", "path", contentPath) - i.serveRawBlock(w, r, resolvedPath.Cid(), contentPath) + i.serveRawBlock(w, r, resolvedPath.Cid(), contentPath, begin) return case "application/vnd.ipld.car", "application/vnd.ipld.car; version=1": logger.Debugw("serving car stream", "path", contentPath) - i.serveCar(w, r, resolvedPath.Cid(), contentPath) + i.serveCar(w, r, resolvedPath.Cid(), contentPath, begin) return default: // catch-all for unsuported application/vnd.* err := fmt.Errorf("unsupported format %q", responseFormat) diff --git a/core/corehttp/gateway_handler_block.go b/core/corehttp/gateway_handler_block.go index 3b93851d214..13d7ebefd9f 100644 --- a/core/corehttp/gateway_handler_block.go +++ b/core/corehttp/gateway_handler_block.go @@ -4,13 +4,14 @@ import ( "bytes" "io/ioutil" "net/http" + "time" cid "github.com/ipfs/go-cid" ipath "github.com/ipfs/interface-go-ipfs-core/path" ) // serveRawBlock returns bytes behind a raw block -func (i *gatewayHandler) serveRawBlock(w http.ResponseWriter, r *http.Request, blockCid cid.Cid, contentPath ipath.Path) { +func (i *gatewayHandler) serveRawBlock(w http.ResponseWriter, r *http.Request, blockCid cid.Cid, contentPath ipath.Path, begin time.Time) { blockReader, err := i.api.Block().Get(r.Context(), contentPath) if err != nil { webError(w, "ipfs block get "+blockCid.String(), err, http.StatusInternalServerError) @@ -35,4 +36,7 @@ func (i *gatewayHandler) serveRawBlock(w http.ResponseWriter, r *http.Request, b // Done: http.ServeContent will take care of // If-None-Match+Etag, Content-Length and range requests http.ServeContent(w, r, name, modtime, content) + + // Update metrics + i.rawBlockGetMetric.WithLabelValues(contentPath.Namespace()).Observe(time.Since(begin).Seconds()) } diff --git a/core/corehttp/gateway_handler_car.go b/core/corehttp/gateway_handler_car.go index 43ce99eef53..5f0f2117fc7 100644 --- a/core/corehttp/gateway_handler_car.go +++ b/core/corehttp/gateway_handler_car.go @@ -3,6 +3,7 @@ package corehttp import ( "context" "net/http" + "time" blocks "github.com/ipfs/go-block-format" cid "github.com/ipfs/go-cid" @@ -13,7 +14,7 @@ import ( ) // serveCar returns a CAR stream for specific DAG+selector -func (i *gatewayHandler) serveCar(w http.ResponseWriter, r *http.Request, rootCid cid.Cid, contentPath ipath.Path) { +func (i *gatewayHandler) serveCar(w http.ResponseWriter, r *http.Request, rootCid cid.Cid, contentPath ipath.Path, begin time.Time) { ctx, cancel := context.WithCancel(r.Context()) defer cancel() @@ -59,6 +60,9 @@ func (i *gatewayHandler) serveCar(w http.ResponseWriter, r *http.Request, rootCi w.Header().Set("X-Stream-Error", err.Error()) return } + + // Update metrics + i.carStreamGetMetric.WithLabelValues(contentPath.Namespace()).Observe(time.Since(begin).Seconds()) } type dagStore struct { diff --git a/core/corehttp/gateway_handler_unixfs.go b/core/corehttp/gateway_handler_unixfs.go index 6f476b2afe3..ed15f41393b 100644 --- a/core/corehttp/gateway_handler_unixfs.go +++ b/core/corehttp/gateway_handler_unixfs.go @@ -4,13 +4,14 @@ import ( "fmt" "html" "net/http" + "time" files "github.com/ipfs/go-ipfs-files" ipath "github.com/ipfs/interface-go-ipfs-core/path" "go.uber.org/zap" ) -func (i *gatewayHandler) serveUnixFs(w http.ResponseWriter, r *http.Request, resolvedPath ipath.Resolved, contentPath ipath.Path, logger *zap.SugaredLogger) { +func (i *gatewayHandler) serveUnixFs(w http.ResponseWriter, r *http.Request, resolvedPath ipath.Resolved, contentPath ipath.Path, begin time.Time, logger *zap.SugaredLogger) { // Handling UnixFS dr, err := i.api.Unixfs().Get(r.Context(), resolvedPath) if err != nil { @@ -22,7 +23,7 @@ func (i *gatewayHandler) serveUnixFs(w http.ResponseWriter, r *http.Request, res // Handling Unixfs file if f, ok := dr.(files.File); ok { logger.Debugw("serving unixfs file", "path", contentPath) - i.serveFile(w, r, contentPath, resolvedPath.Cid(), f) + i.serveFile(w, r, contentPath, resolvedPath.Cid(), f, begin) return } @@ -33,5 +34,5 @@ func (i *gatewayHandler) serveUnixFs(w http.ResponseWriter, r *http.Request, res return } logger.Debugw("serving unixfs directory", "path", contentPath) - i.serveDirectory(w, r, resolvedPath, contentPath, dir, logger) + i.serveDirectory(w, r, resolvedPath, contentPath, dir, begin, logger) } diff --git a/core/corehttp/gateway_handler_unixfs_dir.go b/core/corehttp/gateway_handler_unixfs_dir.go index 8e7e131ddf8..87708159e8e 100644 --- a/core/corehttp/gateway_handler_unixfs_dir.go +++ b/core/corehttp/gateway_handler_unixfs_dir.go @@ -5,6 +5,7 @@ import ( "net/url" gopath "path" "strings" + "time" "github.com/dustin/go-humanize" files "github.com/ipfs/go-ipfs-files" @@ -18,7 +19,7 @@ import ( // serveDirectory returns the best representation of UnixFS directory // // It will return index.html if present, or generate directory listing otherwise. -func (i *gatewayHandler) serveDirectory(w http.ResponseWriter, r *http.Request, resolvedPath ipath.Resolved, contentPath ipath.Path, dir files.Directory, logger *zap.SugaredLogger) { +func (i *gatewayHandler) serveDirectory(w http.ResponseWriter, r *http.Request, resolvedPath ipath.Resolved, contentPath ipath.Path, dir files.Directory, begin time.Time, logger *zap.SugaredLogger) { // HostnameOption might have constructed an IPNS/IPFS path using the Host header. // In this case, we need the original path for constructing redirects @@ -62,7 +63,7 @@ func (i *gatewayHandler) serveDirectory(w http.ResponseWriter, r *http.Request, logger.Debugw("serving index.html file", "path", idxPath) // write to request - i.serveFile(w, r, idxPath, resolvedPath.Cid(), f) + i.serveFile(w, r, idxPath, resolvedPath.Cid(), f, begin) return case resolver.ErrNoLink: logger.Debugw("no index.html; noop", "path", idxPath) @@ -194,4 +195,7 @@ func (i *gatewayHandler) serveDirectory(w http.ResponseWriter, r *http.Request, internalWebError(w, err) return } + + // Update metrics + i.unixfsGenDirGetMetric.WithLabelValues(contentPath.Namespace()).Observe(time.Since(begin).Seconds()) } diff --git a/core/corehttp/gateway_handler_unixfs_file.go b/core/corehttp/gateway_handler_unixfs_file.go index 19e6d6795e5..9807969fee0 100644 --- a/core/corehttp/gateway_handler_unixfs_file.go +++ b/core/corehttp/gateway_handler_unixfs_file.go @@ -7,6 +7,7 @@ import ( "net/http" gopath "path" "strings" + "time" "github.com/gabriel-vasile/mimetype" cid "github.com/ipfs/go-cid" @@ -16,7 +17,7 @@ import ( // serveFile returns data behind a file along with HTTP headers based on // the file itself, its CID and the contentPath used for accessing it. -func (i *gatewayHandler) serveFile(w http.ResponseWriter, r *http.Request, contentPath ipath.Path, fileCid cid.Cid, file files.File) { +func (i *gatewayHandler) serveFile(w http.ResponseWriter, r *http.Request, contentPath ipath.Path, fileCid cid.Cid, file files.File, begin time.Time) { // Set Cache-Control and read optional Last-Modified time modtime := addCacheControlHeaders(w, r, contentPath, fileCid) @@ -80,4 +81,7 @@ func (i *gatewayHandler) serveFile(w http.ResponseWriter, r *http.Request, conte // Done: http.ServeContent will take care of // If-None-Match+Etag, Content-Length and range requests http.ServeContent(w, r, name, modtime, content) + + // Update metrics + i.unixfsFileGetMetric.WithLabelValues(contentPath.Namespace()).Observe(time.Since(begin).Seconds()) }