From 766edbc421911b39637fdbe6550734f407ce023a Mon Sep 17 00:00:00 2001 From: Aliaksandr Valialkin Date: Wed, 7 Jul 2021 12:59:03 +0300 Subject: [PATCH] lib/httpserver: print full requestURI in httpserver.Errorf This should simplify debugging. --- app/vmagent/main.go | 12 +++--- app/vmalert/web.go | 6 +-- app/vminsert/main.go | 12 +++--- app/vmselect/main.go | 55 +++++++++---------------- docs/CHANGELOG.md | 1 + lib/httpserver/httpserver.go | 21 +++++++++- lib/ingestserver/opentsdbhttp/server.go | 2 +- 7 files changed, 56 insertions(+), 53 deletions(-) diff --git a/app/vmagent/main.go b/app/vmagent/main.go index 22be00942..e1e28d5c1 100644 --- a/app/vmagent/main.go +++ b/app/vmagent/main.go @@ -165,7 +165,7 @@ func requestHandler(w http.ResponseWriter, r *http.Request) bool { prometheusWriteRequests.Inc() if err := promremotewrite.InsertHandler(r); err != nil { prometheusWriteErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.WriteHeader(http.StatusNoContent) @@ -174,7 +174,7 @@ func requestHandler(w http.ResponseWriter, r *http.Request) bool { vmimportRequests.Inc() if err := vmimport.InsertHandler(r); err != nil { vmimportErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.WriteHeader(http.StatusNoContent) @@ -183,7 +183,7 @@ func requestHandler(w http.ResponseWriter, r *http.Request) bool { csvimportRequests.Inc() if err := csvimport.InsertHandler(r); err != nil { csvimportErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.WriteHeader(http.StatusNoContent) @@ -192,7 +192,7 @@ func requestHandler(w http.ResponseWriter, r *http.Request) bool { prometheusimportRequests.Inc() if err := prometheusimport.InsertHandler(r); err != nil { prometheusimportErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.WriteHeader(http.StatusNoContent) @@ -201,7 +201,7 @@ func requestHandler(w http.ResponseWriter, r *http.Request) bool { nativeimportRequests.Inc() if err := native.InsertHandler(r); err != nil { nativeimportErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.WriteHeader(http.StatusNoContent) @@ -210,7 +210,7 @@ func requestHandler(w http.ResponseWriter, r *http.Request) bool { influxWriteRequests.Inc() if err := influx.InsertHandlerForHTTP(r); err != nil { influxWriteErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.WriteHeader(http.StatusNoContent) diff --git a/app/vmalert/web.go b/app/vmalert/web.go index 51ff476a7..8e8a6e2f4 100644 --- a/app/vmalert/web.go +++ b/app/vmalert/web.go @@ -34,7 +34,7 @@ func (rh *requestHandler) handler(w http.ResponseWriter, r *http.Request) bool { case "/api/v1/groups": data, err := rh.listGroups() if err != nil { - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.Header().Set("Content-Type", "application/json; charset=utf-8") @@ -43,7 +43,7 @@ func (rh *requestHandler) handler(w http.ResponseWriter, r *http.Request) bool { case "/api/v1/alerts": data, err := rh.listAlerts() if err != nil { - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.Header().Set("Content-Type", "application/json; charset=utf-8") @@ -61,7 +61,7 @@ func (rh *requestHandler) handler(w http.ResponseWriter, r *http.Request) bool { // /api/v1///status data, err := rh.alert(r.URL.Path) if err != nil { - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.Header().Set("Content-Type", "application/json; charset=utf-8") diff --git a/app/vminsert/main.go b/app/vminsert/main.go index e428c4020..bed5cb764 100644 --- a/app/vminsert/main.go +++ b/app/vminsert/main.go @@ -97,7 +97,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { prometheusWriteRequests.Inc() if err := promremotewrite.InsertHandler(r); err != nil { prometheusWriteErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.WriteHeader(http.StatusNoContent) @@ -106,7 +106,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { vmimportRequests.Inc() if err := vmimport.InsertHandler(r); err != nil { vmimportErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.WriteHeader(http.StatusNoContent) @@ -115,7 +115,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { csvimportRequests.Inc() if err := csvimport.InsertHandler(r); err != nil { csvimportErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.WriteHeader(http.StatusNoContent) @@ -124,7 +124,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { prometheusimportRequests.Inc() if err := prometheusimport.InsertHandler(r); err != nil { prometheusimportErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.WriteHeader(http.StatusNoContent) @@ -133,7 +133,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { nativeimportRequests.Inc() if err := native.InsertHandler(r); err != nil { nativeimportErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.WriteHeader(http.StatusNoContent) @@ -142,7 +142,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { influxWriteRequests.Inc() if err := influx.InsertHandlerForHTTP(r); err != nil { influxWriteErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.WriteHeader(http.StatusNoContent) diff --git a/app/vmselect/main.go b/app/vmselect/main.go index c2d620421..109496273 100644 --- a/app/vmselect/main.go +++ b/app/vmselect/main.go @@ -77,7 +77,7 @@ var ( }) ) -// RequestHandler handles remote read API requests for Prometheus +// RequestHandler handles remote read API requests func RequestHandler(w http.ResponseWriter, r *http.Request) bool { startTime := time.Now() // Limit the number of concurrent queries. @@ -117,7 +117,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { d := time.Since(actualStartTime) if d >= *logSlowQueryDuration { remoteAddr := httpserver.GetQuotedRemoteAddr(r) - requestURI := getRequestURI(r) + requestURI := httpserver.GetRequestURI(r) logger.Warnf("slow query according to -search.logSlowQueryDuration=%s: remoteAddr=%s, duration=%.3f seconds; requestURI: %q", *logSlowQueryDuration, remoteAddr, d.Seconds(), requestURI) slowQueries.Inc() @@ -164,7 +164,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { graphiteTagValuesRequests.Inc() if err := graphite.TagValuesHandler(startTime, tagName, w, r); err != nil { graphiteTagValuesErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -249,7 +249,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { exportRequests.Inc() if err := prometheus.ExportHandler(startTime, w, r); err != nil { exportErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -257,7 +257,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { exportCSVRequests.Inc() if err := prometheus.ExportCSVHandler(startTime, w, r); err != nil { exportCSVErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -265,7 +265,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { exportNativeRequests.Inc() if err := prometheus.ExportNativeHandler(startTime, w, r); err != nil { exportNativeErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -273,7 +273,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { federateRequests.Inc() if err := prometheus.FederateHandler(startTime, w, r); err != nil { federateErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -282,7 +282,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { httpserver.EnableCORS(w, r) if err := graphite.MetricsFindHandler(startTime, w, r); err != nil { graphiteMetricsFindErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -291,7 +291,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { httpserver.EnableCORS(w, r) if err := graphite.MetricsExpandHandler(startTime, w, r); err != nil { graphiteMetricsExpandErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -300,7 +300,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { httpserver.EnableCORS(w, r) if err := graphite.MetricsIndexHandler(startTime, w, r); err != nil { graphiteMetricsIndexErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -308,7 +308,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { graphiteTagsTagSeriesRequests.Inc() if err := graphite.TagsTagSeriesHandler(startTime, w, r); err != nil { graphiteTagsTagSeriesErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -316,7 +316,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { graphiteTagsTagMultiSeriesRequests.Inc() if err := graphite.TagsTagMultiSeriesHandler(startTime, w, r); err != nil { graphiteTagsTagMultiSeriesErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -324,7 +324,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { graphiteTagsRequests.Inc() if err := graphite.TagsHandler(startTime, w, r); err != nil { graphiteTagsErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -332,7 +332,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { graphiteTagsFindSeriesRequests.Inc() if err := graphite.TagsFindSeriesHandler(startTime, w, r); err != nil { graphiteTagsFindSeriesErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -341,7 +341,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { httpserver.EnableCORS(w, r) if err := graphite.TagsAutoCompleteTagsHandler(startTime, w, r); err != nil { graphiteTagsAutoCompleteTagsErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -350,7 +350,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { httpserver.EnableCORS(w, r) if err := graphite.TagsAutoCompleteValuesHandler(startTime, w, r); err != nil { graphiteTagsAutoCompleteValuesErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -363,7 +363,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { } if err := graphite.TagsDelSeriesHandler(startTime, w, r); err != nil { graphiteTagsDelSeriesErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } return true @@ -400,7 +400,7 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) bool { } if err := prometheus.DeleteHandler(startTime, r); err != nil { deleteErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return true } w.WriteHeader(http.StatusNoContent) @@ -423,7 +423,7 @@ func isGraphiteTagsPath(path string) bool { } func sendPrometheusError(w http.ResponseWriter, r *http.Request, err error) { - logger.Warnf("error in %q: %s", r.RequestURI, err) + logger.Warnf("error in %q: %s", httpserver.GetRequestURI(r), err) w.Header().Set("Content-Type", "application/json; charset=utf-8") statusCode := http.StatusUnprocessableEntity @@ -435,23 +435,6 @@ func sendPrometheusError(w http.ResponseWriter, r *http.Request, err error) { prometheus.WriteErrorResponse(w, statusCode, err) } -func getRequestURI(r *http.Request) string { - requestURI := r.RequestURI - if r.Method != "POST" { - return requestURI - } - _ = r.ParseForm() - queryArgs := r.PostForm.Encode() - if len(queryArgs) == 0 { - return requestURI - } - delimiter := "?" - if strings.Contains(requestURI, delimiter) { - delimiter = "&" - } - return requestURI + delimiter + queryArgs -} - var ( labelValuesRequests = metrics.NewCounter(`vm_http_requests_total{path="/api/v1/label/{}/values"}`) labelValuesErrors = metrics.NewCounter(`vm_http_request_errors_total{path="/api/v1/label/{}/values"}`) diff --git a/docs/CHANGELOG.md b/docs/CHANGELOG.md index 8b10b12ec..2aba59349 100644 --- a/docs/CHANGELOG.md +++ b/docs/CHANGELOG.md @@ -8,6 +8,7 @@ sort: 15 * FEATURE: vmagent: dynamically reload client TLS certificates from disk on every [mTLS connection](https://developers.cloudflare.com/cloudflare-one/identity/devices/mutual-tls-authentication). This should allow using `vmagent` with [Istio service mesh](https://istio.io/latest/about/service-mesh/). See [this feature request](https://github.com/VictoriaMetrics/VictoriaMetrics/issues/1420). * FEATURE: reduce memory usage when performing heavy queries over big number of time series. +* FEATURE: log http request path plus all the query args on errors during request processing. Previously only http request path was logged without query args, so it could be hard debugging such errors. * BUGFIX: vmagent: remove `{ %space %}` typo in `/targets` output. The typo has been introduced in v1.62.0. See [this issue](https://github.com/VictoriaMetrics/VictoriaMetrics/issues/1408). * BUGFIX: vmagent: fix CSS styles on `/targets` page. See [this issue](https://github.com/VictoriaMetrics/VictoriaMetrics/issues/1422). diff --git a/lib/httpserver/httpserver.go b/lib/httpserver/httpserver.go index a5dff2e55..512b8deb7 100644 --- a/lib/httpserver/httpserver.go +++ b/lib/httpserver/httpserver.go @@ -569,7 +569,8 @@ func GetQuotedRemoteAddr(r *http.Request) string { func Errorf(w http.ResponseWriter, r *http.Request, format string, args ...interface{}) { errStr := fmt.Sprintf(format, args...) remoteAddr := GetQuotedRemoteAddr(r) - errStr = fmt.Sprintf("remoteAddr: %s; %s", remoteAddr, errStr) + requestURI := GetRequestURI(r) + errStr = fmt.Sprintf("remoteAddr: %s; requestURI: %s; %s", remoteAddr, requestURI, errStr) logger.WarnfSkipframes(1, "%s", errStr) // Extract statusCode from args @@ -630,3 +631,21 @@ func WriteAPIHelp(w io.Writer, pathList [][2]string) { fmt.Fprintf(w, "%s - %s
", p, p, doc) } } + +// GetRequestURI returns requestURI for r. +func GetRequestURI(r *http.Request) string { + requestURI := r.RequestURI + if r.Method != "POST" { + return requestURI + } + _ = r.ParseForm() + queryArgs := r.PostForm.Encode() + if len(queryArgs) == 0 { + return requestURI + } + delimiter := "?" + if strings.Contains(requestURI, delimiter) { + delimiter = "&" + } + return requestURI + delimiter + queryArgs +} diff --git a/lib/ingestserver/opentsdbhttp/server.go b/lib/ingestserver/opentsdbhttp/server.go index 591ee4232..6eec2f5f1 100644 --- a/lib/ingestserver/opentsdbhttp/server.go +++ b/lib/ingestserver/opentsdbhttp/server.go @@ -89,7 +89,7 @@ func newRequestHandler(insertHandler func(r *http.Request) error) http.Handler { writeRequests.Inc() if err := insertHandler(r); err != nil { writeErrors.Inc() - httpserver.Errorf(w, r, "error in %q: %s", r.URL.Path, err) + httpserver.Errorf(w, r, "%s", err) return } w.WriteHeader(http.StatusNoContent)