Skip to content

Commit

Permalink
use middleware to capture HTTP server metrics (#753)
Browse files Browse the repository at this point in the history
* use middleware to capture HTTP server metrics

* small refactor of package api

* api: only record named path's metrics

* update url names

* add tests for metrics middleware

* api metrics: add testcases for internal server error
  • Loading branch information
libotony authored May 27, 2024
1 parent 74d0c8d commit ee2b7da
Show file tree
Hide file tree
Showing 16 changed files with 245 additions and 78 deletions.
18 changes: 12 additions & 6 deletions api/accounts/accounts.go
Original file line number Diff line number Diff line change
Expand Up @@ -354,21 +354,27 @@ func (a *Accounts) Mount(root *mux.Router, pathPrefix string) {

sub.Path("/*").
Methods(http.MethodPost).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "accounts_call_batch_code", a.handleCallBatchCode))
Name("accounts_call_batch_code").
HandlerFunc(utils.WrapHandlerFunc(a.handleCallBatchCode))
sub.Path("/{address}").
Methods(http.MethodGet).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "accounts_get_account", a.handleGetAccount))
Name("accounts_get_account").
HandlerFunc(utils.WrapHandlerFunc(a.handleGetAccount))
sub.Path("/{address}/code").
Methods(http.MethodGet).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "accounts_get_code", a.handleGetCode))
Name("accounts_get_code").
HandlerFunc(utils.WrapHandlerFunc(a.handleGetCode))
sub.Path("/{address}/storage/{key}").
Methods("GET").
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "accounts_get_storage", a.handleGetStorage))
Name("accounts_get_storage").
HandlerFunc(utils.WrapHandlerFunc(a.handleGetStorage))
// These two methods are currently deprecated
sub.Path("").
Methods(http.MethodPost).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "accounts_api_call_contract", a.handleCallContract))
Name("accounts_call_contract").
HandlerFunc(utils.WrapHandlerFunc(a.handleCallContract))
sub.Path("/{address}").
Methods(http.MethodPost).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "accounts_call_contract_address", a.handleCallContract))
Name("accounts_call_contract_address").
HandlerFunc(utils.WrapHandlerFunc(a.handleCallContract))
}
15 changes: 10 additions & 5 deletions api/api.go
Original file line number Diff line number Diff line change
Expand Up @@ -40,14 +40,15 @@ func New(
logDB *logdb.LogDB,
bft bft.Finalizer,
nw node.Network,
forkConfig thor.ForkConfig,
allowedOrigins string,
backtraceLimit uint32,
callGasLimit uint64,
pprofOn bool,
skipLogs bool,
allowCustomTracer bool,
isReqLoggerEnabled bool,
forkConfig thor.ForkConfig,
enableReqLogger bool,
enableMetrics bool,
) (http.HandlerFunc, func()) {
origins := strings.Split(strings.TrimSpace(allowedOrigins), ",")
for i, o := range origins {
Expand Down Expand Up @@ -95,16 +96,20 @@ func New(
router.PathPrefix("/debug/pprof/").HandlerFunc(pprof.Index)
}

handler := handlers.CompressHandler(router)
if isReqLoggerEnabled {
handler = RequestLoggerHandler(handler, log)
if enableMetrics {
router.Use(metricsMiddleware)
}

handler := handlers.CompressHandler(router)
handler = handlers.CORS(
handlers.AllowedOrigins(origins),
handlers.AllowedHeaders([]string{"content-type", "x-genesis-id"}),
handlers.ExposedHeaders([]string{"x-genesis-id", "x-thorest-ver"}),
)(handler)

if enableReqLogger {
handler = RequestLoggerHandler(handler, log)
}

return handler.ServeHTTP, subs.Close // subscriptions handles hijacked conns, which need to be closed
}
3 changes: 2 additions & 1 deletion api/blocks/blocks.go
Original file line number Diff line number Diff line change
Expand Up @@ -95,5 +95,6 @@ func (b *Blocks) Mount(root *mux.Router, pathPrefix string) {
sub := root.PathPrefix(pathPrefix).Subrouter()
sub.Path("/{revision}").
Methods(http.MethodGet).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "blocks_get_block", b.handleGetBlock))
Name("blocks_get_block").
HandlerFunc(utils.WrapHandlerFunc(b.handleGetBlock))
}
9 changes: 6 additions & 3 deletions api/debug/debug.go
Original file line number Diff line number Diff line change
Expand Up @@ -424,11 +424,14 @@ func (d *Debug) Mount(root *mux.Router, pathPrefix string) {

sub.Path("/tracers").
Methods(http.MethodPost).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "debug_trace_clause", d.handleTraceClause))
Name("debug_trace_clause").
HandlerFunc(utils.WrapHandlerFunc(d.handleTraceClause))
sub.Path("/tracers/call").
Methods(http.MethodPost).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "debug_trace_call", d.handleTraceCall))
Name("debug_trace_call").
HandlerFunc(utils.WrapHandlerFunc(d.handleTraceCall))
sub.Path("/storage-range").
Methods(http.MethodPost).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "debug_debug_storage", d.handleDebugStorage))
Name("debug_trace_storage").
HandlerFunc(utils.WrapHandlerFunc(d.handleDebugStorage))
}
3 changes: 2 additions & 1 deletion api/events/events.go
Original file line number Diff line number Diff line change
Expand Up @@ -63,5 +63,6 @@ func (e *Events) Mount(root *mux.Router, pathPrefix string) {

sub.Path("").
Methods(http.MethodPost).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "events_filter", e.handleFilter))
Name("logs_filter_event").
HandlerFunc(utils.WrapHandlerFunc(e.handleFilter))
}
63 changes: 63 additions & 0 deletions api/metrics.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,63 @@
// Copyright (c) 2024 The VeChainThor developers

// Distributed under the GNU Lesser General Public License v3.0 software license, see the accompanying
// file LICENSE or <https://www.gnu.org/licenses/lgpl-3.0.html>

package api

import (
"net/http"
"strconv"
"time"

"github.com/gorilla/mux"
"github.com/vechain/thor/v2/metrics"
)

var (
metricHttpReqCounter = metrics.LazyLoadCounterVec("api_request_count", []string{"name", "code", "method"})
metricHttpReqDuration = metrics.LazyLoadHistogramVec("api_duration_ms", []string{"name", "code", "method"}, metrics.BucketHTTPReqs)
)

// metricsResponseWriter is a wrapper around http.ResponseWriter that captures the status code.
type metricsResponseWriter struct {
http.ResponseWriter
statusCode int
}

func newMetricsResponseWriter(w http.ResponseWriter) *metricsResponseWriter {
return &metricsResponseWriter{w, http.StatusOK}
}

func (m *metricsResponseWriter) WriteHeader(code int) {
m.statusCode = code
m.ResponseWriter.WriteHeader(code)
}

// metricsMiddleware is a middleware that records metrics for each request.
func metricsMiddleware(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
rt := mux.CurrentRoute(r)

var (
enabled = false
name = ""
)

// all named route will be recorded
if rt != nil && rt.GetName() != "" {
enabled = true
name = rt.GetName()
}

now := time.Now()
mrw := newMetricsResponseWriter(w)

next.ServeHTTP(mrw, r)

if enabled {
metricHttpReqCounter().AddWithLabel(1, map[string]string{"name": name, "code": strconv.Itoa(mrw.statusCode), "method": r.Method})
metricHttpReqDuration().ObserveWithLabels(time.Since(now).Milliseconds(), map[string]string{"name": name, "code": strconv.Itoa(mrw.statusCode), "method": r.Method})
}
})
}
117 changes: 117 additions & 0 deletions api/metrics_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,117 @@
// Copyright (c) 2024 The VeChainThor developers

// Distributed under the GNU Lesser General Public License v3.0 software license, see the accompanying
// file LICENSE or <https://www.gnu.org/licenses/lgpl-3.0.html>

package api

import (
"bytes"
"crypto/rand"
"io"
"math"
"net/http"
"net/http/httptest"
"testing"

"github.com/gorilla/mux"
"github.com/prometheus/common/expfmt"
"github.com/stretchr/testify/assert"
"github.com/vechain/thor/v2/api/accounts"
"github.com/vechain/thor/v2/chain"
"github.com/vechain/thor/v2/cmd/thor/solo"
"github.com/vechain/thor/v2/genesis"
"github.com/vechain/thor/v2/metrics"
"github.com/vechain/thor/v2/muxdb"
"github.com/vechain/thor/v2/state"
"github.com/vechain/thor/v2/thor"
)

func init() {
metrics.InitializePrometheusMetrics()
}

func TestMetricsMiddleware(t *testing.T) {
db := muxdb.NewMem()
stater := state.NewStater(db)
gene := genesis.NewDevnet()

b, _, _, err := gene.Build(stater)
if err != nil {
t.Fatal(err)
}
repo, _ := chain.NewRepository(db, b)

// inject some invalid data to db
data := db.NewStore("chain.data")
var blkID thor.Bytes32
rand.Read(blkID[:])
data.Put(blkID[:], []byte("invalid data"))

// get summary should fail since the block data is not rlp encoded
_, err = repo.GetBlockSummary(blkID)
assert.NotNil(t, err)

router := mux.NewRouter()
acc := accounts.New(repo, stater, math.MaxUint64, thor.NoFork, solo.NewBFTEngine(repo))
acc.Mount(router, "/accounts")
router.PathPrefix("/metrics").Handler(metrics.HTTPHandler())
router.Use(metricsMiddleware)
ts := httptest.NewServer(router)

httpGet(t, ts.URL+"/accounts/0x")
httpGet(t, ts.URL+"/accounts/"+thor.Address{}.String())

_, code := httpGet(t, ts.URL+"/accounts/"+thor.Address{}.String()+"?revision="+blkID.String())
assert.Equal(t, 500, code)

body, _ := httpGet(t, ts.URL+"/metrics")
parser := expfmt.TextParser{}
metrics, err := parser.TextToMetricFamilies(bytes.NewReader(body))
assert.Nil(t, err)

m := metrics["thor_metrics_api_request_count"].GetMetric()
assert.Equal(t, 3, len(m), "should be 3 metric entries")
assert.Equal(t, float64(1), m[0].GetCounter().GetValue())
assert.Equal(t, float64(1), m[1].GetCounter().GetValue())

labels := m[0].GetLabel()
assert.Equal(t, 3, len(labels))
assert.Equal(t, "code", labels[0].GetName())
assert.Equal(t, "200", labels[0].GetValue())
assert.Equal(t, "method", labels[1].GetName())
assert.Equal(t, "GET", labels[1].GetValue())
assert.Equal(t, "name", labels[2].GetName())
assert.Equal(t, "accounts_get_account", labels[2].GetValue())

labels = m[1].GetLabel()
assert.Equal(t, 3, len(labels))
assert.Equal(t, "code", labels[0].GetName())
assert.Equal(t, "400", labels[0].GetValue())
assert.Equal(t, "method", labels[1].GetName())
assert.Equal(t, "GET", labels[1].GetValue())
assert.Equal(t, "name", labels[2].GetName())
assert.Equal(t, "accounts_get_account", labels[2].GetValue())

labels = m[2].GetLabel()
assert.Equal(t, 3, len(labels))
assert.Equal(t, "code", labels[0].GetName())
assert.Equal(t, "500", labels[0].GetValue())
assert.Equal(t, "method", labels[1].GetName())
assert.Equal(t, "GET", labels[1].GetValue())
assert.Equal(t, "name", labels[2].GetName())
assert.Equal(t, "accounts_get_account", labels[2].GetValue())
}

func httpGet(t *testing.T, url string) ([]byte, int) {
res, err := http.Get(url) // nolint:gosec
if err != nil {
t.Fatal(err)
}
r, err := io.ReadAll(res.Body)
res.Body.Close()
if err != nil {
t.Fatal(err)
}
return r, res.StatusCode
}
3 changes: 2 additions & 1 deletion api/node/node.go
Original file line number Diff line number Diff line change
Expand Up @@ -35,5 +35,6 @@ func (n *Node) Mount(root *mux.Router, pathPrefix string) {

sub.Path("/network/peers").
Methods(http.MethodGet).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "node_network", n.handleNetwork))
Name("node_get_peers").
HandlerFunc(utils.WrapHandlerFunc(n.handleNetwork))
}
6 changes: 4 additions & 2 deletions api/subscriptions/subscriptions.go
Original file line number Diff line number Diff line change
Expand Up @@ -383,8 +383,10 @@ func (s *Subscriptions) Mount(root *mux.Router, pathPrefix string) {

sub.Path("/txpool").
Methods(http.MethodGet).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "subscriptions_pending_transactions", s.handlePendingTransactions))
Name("subscriptions_pending_tx").
HandlerFunc(utils.WrapHandlerFunc(s.handlePendingTransactions))
sub.Path("/{subject}").
Methods(http.MethodGet).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "subscriptions_subject", s.handleSubject))
Name("subscriptions_subject").
HandlerFunc(utils.WrapHandlerFunc(s.handleSubject))
}
9 changes: 6 additions & 3 deletions api/transactions/transactions.go
Original file line number Diff line number Diff line change
Expand Up @@ -219,11 +219,14 @@ func (t *Transactions) Mount(root *mux.Router, pathPrefix string) {

sub.Path("").
Methods(http.MethodPost).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "transactions_send_transaction", t.handleSendTransaction))
Name("transactions_send_tx").
HandlerFunc(utils.WrapHandlerFunc(t.handleSendTransaction))
sub.Path("/{id}").
Methods(http.MethodGet).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "transactions_get_transaction_by_id", t.handleGetTransactionByID))
Name("transactions_get_tx").
HandlerFunc(utils.WrapHandlerFunc(t.handleGetTransactionByID))
sub.Path("/{id}/receipt").
Methods(http.MethodGet).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "transactions_get_transaction_by_receipt", t.handleGetTransactionReceiptByID))
Name("transactions_get_receipt").
HandlerFunc(utils.WrapHandlerFunc(t.handleGetTransactionReceiptByID))
}
3 changes: 2 additions & 1 deletion api/transfers/transfers.go
Original file line number Diff line number Diff line change
Expand Up @@ -69,5 +69,6 @@ func (t *Transfers) Mount(root *mux.Router, pathPrefix string) {

sub.Path("").
Methods(http.MethodPost).
HandlerFunc(utils.MetricsWrapHandlerFunc(pathPrefix, "transfers_transfer_logs", t.handleFilterTransferLogs))
Name("logs_filter_transfer").
HandlerFunc(utils.WrapHandlerFunc(t.handleFilterTransferLogs))
}
37 changes: 0 additions & 37 deletions api/utils/http.go
Original file line number Diff line number Diff line change
Expand Up @@ -9,11 +9,6 @@ import (
"encoding/json"
"io"
"net/http"
"strconv"
"strings"
"time"

"github.com/vechain/thor/v2/metrics"
)

type httpError struct {
Expand Down Expand Up @@ -72,38 +67,6 @@ func WrapHandlerFunc(f HandlerFunc) http.HandlerFunc {
}
}

// MetricsWrapHandlerFunc wraps a given handler and adds metrics to it
func MetricsWrapHandlerFunc(pathPrefix, endpoint string, f HandlerFunc) http.HandlerFunc {
fixedPath := strings.ReplaceAll(pathPrefix, "/", "_") // ensure no unexpected slashes
httpReqCounter := metrics.CounterVec(fixedPath+"_request_count", []string{"path", "code", "method"})
httpReqDuration := metrics.HistogramVec(
fixedPath+"_duration_ms", []string{"path", "code", "method"}, metrics.BucketHTTPReqs,
)

return func(w http.ResponseWriter, r *http.Request) {
now := time.Now()
err := f(w, r)

method := r.Method
status := http.StatusOK
if err != nil {
if he, ok := err.(*httpError); ok {
if he.cause != nil {
http.Error(w, he.cause.Error(), he.status)
} else {
w.WriteHeader(he.status)
}
status = he.status
} else {
http.Error(w, err.Error(), http.StatusInternalServerError)
status = http.StatusInternalServerError
}
}
httpReqCounter.AddWithLabel(1, map[string]string{"path": endpoint, "code": strconv.Itoa(status), "method": method})
httpReqDuration.ObserveWithLabels(time.Since(now).Milliseconds(), map[string]string{"path": endpoint, "code": strconv.Itoa(status), "method": method})
}
}

// content types
const (
JSONContentType = "application/json; charset=utf-8"
Expand Down
Loading

0 comments on commit ee2b7da

Please sign in to comment.