diff --git a/go.mod b/go.mod index 5244d774f..fbb8ab8ff 100644 --- a/go.mod +++ b/go.mod @@ -46,10 +46,12 @@ require ( github.com/danieljoos/wincred v1.2.0 // indirect github.com/davecgh/go-spew v1.1.1 // indirect github.com/dustin/go-humanize v1.0.1 // indirect + github.com/felixge/httpsnoop v1.0.0 // indirect github.com/fxamacker/cbor v1.5.1 // indirect github.com/fxamacker/cbor/v2 v2.5.0 // indirect github.com/go-ole/go-ole v1.3.0 // indirect github.com/gofrs/uuid v4.4.0+incompatible // indirect + github.com/golang/gddo v0.0.0-20180823221919-9d8ff1c67be5 // indirect github.com/google/btree v1.1.2 // indirect github.com/google/go-cmp v0.5.9 // indirect github.com/google/uuid v1.3.1 // indirect @@ -62,6 +64,7 @@ require ( github.com/mdlayher/netlink v1.7.2 // indirect github.com/mdlayher/socket v0.4.1 // indirect github.com/mitchellh/copystructure v1.2.0 // indirect + github.com/mitchellh/go-server-timing v1.0.1 // indirect github.com/mitchellh/reflectwalk v1.0.2 // indirect github.com/mr-tron/base58 v1.2.0 // indirect github.com/pkg/errors v0.9.1 // indirect diff --git a/go.sum b/go.sum index b220c6833..8c95f3277 100644 --- a/go.sum +++ b/go.sum @@ -58,6 +58,8 @@ github.com/dgryski/go-farm v0.0.0-20190423205320-6a90982ecee2/go.mod h1:SqUrOPUn github.com/dustin/go-humanize v1.0.0/go.mod h1:HtrtbFcZ19U5GC7JDqmcUSB87Iq5E25KnS6fMYU6eOk= github.com/dustin/go-humanize v1.0.1 h1:GzkhY7T5VNhEkwH0PVJgjz+fX1rhBrR7pRT3mDkpeCY= github.com/dustin/go-humanize v1.0.1/go.mod h1:Mu1zIs6XwVuF/gI1OepvI0qD18qycQx+mFykh5fBlto= +github.com/felixge/httpsnoop v1.0.0 h1:gh8fMGz0rlOv/1WmRZm7OgncIOTsAj21iNJot48omJQ= +github.com/felixge/httpsnoop v1.0.0/go.mod h1:3+D9sFq0ahK/JeJPhCBUV1xlf4/eIYrUQaxulT0VzX8= github.com/florianl/go-conntrack v0.4.0 h1:TlYkxytdwgVayfU0cKwkHurQA0Rd1ZSEBRckRYDUu18= github.com/florianl/go-conntrack v0.4.0/go.mod h1:iPDx4oIats2T7X7Jm3PFyRCJM1GfZhJaSHOWROYOrE8= github.com/florianl/go-nfqueue v1.3.1 h1:khQ9fYCrjbu5CF8dZF55G2RTIEIQRI0Aj5k3msJR6Gw= @@ -82,6 +84,8 @@ github.com/gofrs/uuid v4.2.0+incompatible/go.mod h1:b2aQJv3Z4Fp6yNu3cdSllBxTCLRx github.com/gofrs/uuid v4.3.0+incompatible/go.mod h1:b2aQJv3Z4Fp6yNu3cdSllBxTCLRxnplIgP/c0N/04lM= github.com/gofrs/uuid v4.4.0+incompatible h1:3qXRTX8/NbyulANqlc0lchS1gqAVxRgsuW1YrTJupqA= github.com/gofrs/uuid v4.4.0+incompatible/go.mod h1:b2aQJv3Z4Fp6yNu3cdSllBxTCLRxnplIgP/c0N/04lM= +github.com/golang/gddo v0.0.0-20180823221919-9d8ff1c67be5 h1:yrv1uUvgXH/tEat+wdvJMRJ4g51GlIydtDpU9pFjaaI= +github.com/golang/gddo v0.0.0-20180823221919-9d8ff1c67be5/go.mod h1:xEhNfoBDX1hzLm2Nf80qUvZ2sVwoMZ8d6IE2SrsQfh4= github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b/go.mod h1:SBH7ygxi8pfUlaOkMMuAQtPIUF8ecWP5IEl/CR7VP2Q= github.com/golang/glog v1.0.0/go.mod h1:EWib/APOK0SL3dFbYqvxE3UYd8E6s1ouQ7iEp/0LWV4= github.com/golang/glog v1.1.1 h1:jxpi2eWoU84wbX9iIEyAeeoac3FLuifZpY9tcNUD9kw= @@ -94,6 +98,7 @@ github.com/google/btree v1.1.2/go.mod h1:qOPhT0dTNdNzV6Z/lhRX0YXUafgPLFUh+gZMl76 github.com/google/go-cmp v0.2.0/go.mod h1:oXzfMopK8JAjlY9xF4vHSVASa0yLyX7SntLO5aqRK0M= github.com/google/go-cmp v0.3.1/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMywk6iLU= github.com/google/go-cmp v0.4.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= +github.com/google/go-cmp v0.4.1/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.5.2/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.5.4/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.5.5/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= @@ -183,6 +188,8 @@ github.com/miekg/dns v1.1.55/go.mod h1:uInx36IzPl7FYnDcMeVWxj9byh7DutNykX4G9Sj60 github.com/mitchellh/copystructure v1.2.0 h1:vpKXTN4ewci03Vljg/q9QvCGUDttBOGBIa15WveJJGw= github.com/mitchellh/copystructure v1.2.0/go.mod h1:qLl+cE2AmVv+CoeAwDPye/v+N2HKCj9FbZEVFJRxO9s= github.com/mitchellh/go-homedir v1.1.0/go.mod h1:SfyaCUpYCn1Vlf4IUYiD9fPX4A5wJrkLzIz1N1q0pr0= +github.com/mitchellh/go-server-timing v1.0.1 h1:f00/aIe8T3MrnLhQHu3tSWvnwc5GV/p5eutuu3hF/tE= +github.com/mitchellh/go-server-timing v1.0.1/go.mod h1:Mo6GKi9FSLwWFAMn3bqVPWe20y5ri5QGQuO9D9MCOxk= github.com/mitchellh/mapstructure v1.1.2/go.mod h1:FVVH3fgwuzCH5S8UJGiWEs2h04kUh9fWfEaFds41c1Y= github.com/mitchellh/reflectwalk v1.0.2 h1:G2LzWKi524PWgd3mLHV8Y5k7s6XUvT0Gef6zxSIeXaQ= github.com/mitchellh/reflectwalk v1.0.2/go.mod h1:mSTlrgnPZtwu0c4WaC2kGObEpuNDbx0jmZXqmk4esnw= diff --git a/netquery/module_api.go b/netquery/module_api.go index c51f9a3aa..5e182fd17 100644 --- a/netquery/module_api.go +++ b/netquery/module_api.go @@ -7,6 +7,7 @@ import ( "time" "github.com/hashicorp/go-multierror" + servertiming "github.com/mitchellh/go-server-timing" "github.com/safing/portbase/api" "github.com/safing/portbase/config" @@ -93,7 +94,7 @@ func (m *module) prepare() error { Read: api.PermitUser, // Needs read+write as the query is sent using POST data. Write: api.PermitUser, // Needs read+write as the query is sent using POST data. BelongsTo: m.Module, - HandlerFunc: queryHander.ServeHTTP, + HandlerFunc: servertiming.Middleware(queryHander, nil).ServeHTTP, }); err != nil { return fmt.Errorf("failed to register API endpoint: %w", err) } @@ -105,7 +106,7 @@ func (m *module) prepare() error { MimeType: "application/json", Write: api.PermitUser, BelongsTo: m.Module, - HandlerFunc: chartHandler.ServeHTTP, + HandlerFunc: servertiming.Middleware(chartHandler, nil).ServeHTTP, }); err != nil { return fmt.Errorf("failed to register API endpoint: %w", err) } diff --git a/netquery/query_handler.go b/netquery/query_handler.go index cb64db4de..0f6ec7251 100644 --- a/netquery/query_handler.go +++ b/netquery/query_handler.go @@ -9,8 +9,8 @@ import ( "net/http" "regexp" "strings" - "time" + servertiming "github.com/mitchellh/go-server-timing" "github.com/safing/portbase/log" "github.com/safing/portmaster/netquery/orm" ) @@ -33,7 +33,12 @@ type ( ) func (qh *QueryHandler) ServeHTTP(resp http.ResponseWriter, req *http.Request) { - start := time.Now() + timing := servertiming.FromContext(req.Context()) + + timingQueryParsed := timing.NewMetric("query_parsed"). + WithDesc("Query has been parsed"). + Start() + requestPayload, err := parseQueryRequestPayload[QueryRequestPayload](req) if err != nil { http.Error(resp, err.Error(), http.StatusBadRequest) @@ -41,7 +46,11 @@ func (qh *QueryHandler) ServeHTTP(resp http.ResponseWriter, req *http.Request) { return } - queryParsed := time.Since(start) + timingQueryParsed.Stop() + + timingQueryBuilt := timing.NewMetric("query_built"). + WithDesc("The SQL query has been built"). + Start() query, paramMap, err := requestPayload.generateSQL(req.Context(), qh.Database.Schema) if err != nil { @@ -50,7 +59,11 @@ func (qh *QueryHandler) ServeHTTP(resp http.ResponseWriter, req *http.Request) { return } - sqlQueryBuilt := time.Since(start) + timingQueryBuilt.Stop() + + timingQueryExecute := timing.NewMetric("sql_exec"). + WithDesc("SQL query execution time"). + Start() // actually execute the query against the database and collect the result var result []map[string]interface{} @@ -65,7 +78,7 @@ func (qh *QueryHandler) ServeHTTP(resp http.ResponseWriter, req *http.Request) { return } - sqlQueryFinished := time.Since(start) + timingQueryExecute.Stop() // send the HTTP status code resp.WriteHeader(http.StatusOK) @@ -86,12 +99,6 @@ func (qh *QueryHandler) ServeHTTP(resp http.ResponseWriter, req *http.Request) { "orderBy": requestPayload.OrderBy, "groupBy": requestPayload.GroupBy, "selects": requestPayload.Select, - "times": map[string]interface{}{ - "start_time": start, - "query_parsed_after": queryParsed.String(), - "query_built_after": sqlQueryBuilt.String(), - "query_executed_after": sqlQueryFinished.String(), - }, } } else { resultBody = make(map[string]interface{})