From e0cc5238934f381c92203a96f8e96760bf9704c9 Mon Sep 17 00:00:00 2001 From: Simon Pasquier Date: Tue, 2 Jun 2020 16:13:31 +0200 Subject: [PATCH] api/v2: add path and method to API v2 logs (#2261) * api/v2: add path and method to API v2 logs When an API v2 handler logged a message, the log wouldn't include the path and method. Since different handlers perform the same validations (e.g. matchers for alerts and silences), it isn't easy to know which handler was invoked (though the logged filename + line number provides a hint). Signed-off-by: Simon Pasquier * Capitalize messages + improve logs Signed-off-by: Simon Pasquier --- api/v2/api.go | 65 +++++++++++++++++++++++++++------------------ pkg/labels/parse.go | 9 ++++--- 2 files changed, 44 insertions(+), 30 deletions(-) diff --git a/api/v2/api.go b/api/v2/api.go index 16222161..6cde1972 100644 --- a/api/v2/api.go +++ b/api/v2/api.go @@ -98,13 +98,13 @@ func NewAPI( uptime: time.Now(), } - // load embedded swagger file + // Load embedded swagger file. swaggerSpec, err := loads.Analyzed(restapi.SwaggerJSON, "") if err != nil { return nil, fmt.Errorf("failed to load embedded swagger file: %v", err.Error()) } - // create new service API + // Create new service API. openAPI := operations.NewAlertmanagerAPI(swaggerSpec) // Skip the redoc middleware, only serving the OpenAPI specification and @@ -124,14 +124,16 @@ func NewAPI( openAPI.SilenceGetSilencesHandler = silence_ops.GetSilencesHandlerFunc(api.getSilencesHandler) openAPI.SilencePostSilencesHandler = silence_ops.PostSilencesHandlerFunc(api.postSilencesHandler) - openAPI.Logger = func(s string, i ...interface{}) { level.Error(api.logger).Log(i...) } - handleCORS := cors.Default().Handler api.Handler = handleCORS(openAPI.Serve(nil)) return &api, nil } +func (api *API) requestLogger(req *http.Request) log.Logger { + return log.With(api.logger, "path", req.URL.Path, "method", req.Method) +} + // Update sets the API struct members that may change between reloads of alertmanager. func (api *API) Update(cfg *config.Config, setAlertStatus setAlertStatusFn) { api.mtx.Lock() @@ -216,18 +218,20 @@ func (api *API) getAlertsHandler(params alert_ops.GetAlertsParams) middleware.Re // are no alerts present res = open_api_models.GettableAlerts{} ctx = params.HTTPRequest.Context() + + logger = api.requestLogger(params.HTTPRequest) ) matchers, err := parseFilter(params.Filter) if err != nil { - level.Error(api.logger).Log("msg", "failed to parse matchers", "err", err) + level.Error(logger).Log("msg", "Failed to parse matchers", "err", err) return alertgroup_ops.NewGetAlertGroupsBadRequest().WithPayload(err.Error()) } if params.Receiver != nil { receiverFilter, err = regexp.Compile("^(?:" + *params.Receiver + ")$") if err != nil { - level.Error(api.logger).Log("msg", "failed to compile receiver regex", "err", err) + level.Error(logger).Log("msg", "Failed to compile receiver regex", "err", err) return alert_ops. NewGetAlertsBadRequest(). WithPayload( @@ -272,7 +276,7 @@ func (api *API) getAlertsHandler(params alert_ops.GetAlertsParams) middleware.Re api.mtx.RUnlock() if err != nil { - level.Error(api.logger).Log("msg", "failed to get alerts", "err", err) + level.Error(logger).Log("msg", "Failed to get alerts", "err", err) return alert_ops.NewGetAlertsInternalServerError().WithPayload(err.Error()) } sort.Slice(res, func(i, j int) bool { @@ -283,6 +287,8 @@ func (api *API) getAlertsHandler(params alert_ops.GetAlertsParams) middleware.Re } func (api *API) postAlertsHandler(params alert_ops.PostAlertsParams) middleware.Responder { + logger := api.requestLogger(params.HTTPRequest) + alerts := openAPIAlertsToAlerts(params.Alerts) now := time.Now() @@ -330,12 +336,12 @@ func (api *API) postAlertsHandler(params alert_ops.PostAlertsParams) middleware. validAlerts = append(validAlerts, a) } if err := api.alerts.Put(validAlerts...); err != nil { - level.Error(api.logger).Log("msg", "failed to create alerts", "err", err) + level.Error(logger).Log("msg", "Failed to create alerts", "err", err) return alert_ops.NewPostAlertsInternalServerError().WithPayload(err.Error()) } if validationErrs.Len() > 0 { - level.Error(api.logger).Log("msg", "failed to validate alerts", "err", validationErrs.Error()) + level.Error(logger).Log("msg", "Failed to validate alerts", "err", validationErrs.Error()) return alert_ops.NewPostAlertsBadRequest().WithPayload(validationErrs.Error()) } @@ -343,18 +349,19 @@ func (api *API) postAlertsHandler(params alert_ops.PostAlertsParams) middleware. } func (api *API) getAlertGroupsHandler(params alertgroup_ops.GetAlertGroupsParams) middleware.Responder { - var receiverFilter *regexp.Regexp + logger := api.requestLogger(params.HTTPRequest) matchers, err := parseFilter(params.Filter) if err != nil { - level.Error(api.logger).Log("msg", "failed to parse matchers", "err", err) + level.Error(logger).Log("msg", "Failed to parse matchers", "err", err) return alertgroup_ops.NewGetAlertGroupsBadRequest().WithPayload(err.Error()) } + var receiverFilter *regexp.Regexp if params.Receiver != nil { receiverFilter, err = regexp.Compile("^(?:" + *params.Receiver + ")$") if err != nil { - level.Error(api.logger).Log("msg", "failed to compile receiver regex", "err", err) + level.Error(logger).Log("msg", "Failed to compile receiver regex", "err", err) return alertgroup_ops. NewGetAlertGroupsBadRequest(). WithPayload( @@ -554,12 +561,14 @@ func matchFilterLabels(matchers []*labels.Matcher, sms map[string]string) bool { } func (api *API) getSilencesHandler(params silence_ops.GetSilencesParams) middleware.Responder { + logger := api.requestLogger(params.HTTPRequest) + matchers := []*labels.Matcher{} if params.Filter != nil { for _, matcherString := range params.Filter { matcher, err := labels.ParseMatcher(matcherString) if err != nil { - level.Error(api.logger).Log("msg", "failed to parse matchers", "err", err) + level.Error(logger).Log("msg", "Failed to parse matchers", "err", err) return alert_ops.NewGetAlertsBadRequest().WithPayload(err.Error()) } @@ -569,7 +578,7 @@ func (api *API) getSilencesHandler(params silence_ops.GetSilencesParams) middlew psils, _, err := api.silences.Query() if err != nil { - level.Error(api.logger).Log("msg", "failed to get silences", "err", err) + level.Error(logger).Log("msg", "Failed to get silences", "err", err) return silence_ops.NewGetSilencesInternalServerError().WithPayload(err.Error()) } @@ -577,7 +586,7 @@ func (api *API) getSilencesHandler(params silence_ops.GetSilencesParams) middlew for _, ps := range psils { silence, err := gettableSilenceFromProto(ps) if err != nil { - level.Error(api.logger).Log("msg", "failed to unmarshal silence from proto", "err", err) + level.Error(logger).Log("msg", "Failed to unmarshal silence from proto", "err", err) return silence_ops.NewGetSilencesInternalServerError().WithPayload(err.Error()) } if !gettableSilenceMatchesFilterLabels(silence, matchers) { @@ -639,20 +648,22 @@ func gettableSilenceMatchesFilterLabels(s open_api_models.GettableSilence, match } func (api *API) getSilenceHandler(params silence_ops.GetSilenceParams) middleware.Responder { + logger := api.requestLogger(params.HTTPRequest) + sils, _, err := api.silences.Query(silence.QIDs(params.SilenceID.String())) if err != nil { - level.Error(api.logger).Log("msg", "failed to get silence by id", "err", err) + level.Error(logger).Log("msg", "Failed to get silence by id", "err", err, "id", params.SilenceID.String()) return silence_ops.NewGetSilenceInternalServerError().WithPayload(err.Error()) } if len(sils) == 0 { - level.Error(api.logger).Log("msg", "failed to find silence", "err", err) + level.Error(logger).Log("msg", "Failed to find silence", "err", err, "id", params.SilenceID.String()) return silence_ops.NewGetSilenceNotFound() } sil, err := gettableSilenceFromProto(sils[0]) if err != nil { - level.Error(api.logger).Log("msg", "failed to convert unmarshal from proto", "err", err) + level.Error(logger).Log("msg", "Failed to convert unmarshal from proto", "err", err) return silence_ops.NewGetSilenceInternalServerError().WithPayload(err.Error()) } @@ -660,10 +671,11 @@ func (api *API) getSilenceHandler(params silence_ops.GetSilenceParams) middlewar } func (api *API) deleteSilenceHandler(params silence_ops.DeleteSilenceParams) middleware.Responder { - sid := params.SilenceID.String() + logger := api.requestLogger(params.HTTPRequest) + sid := params.SilenceID.String() if err := api.silences.Expire(sid); err != nil { - level.Error(api.logger).Log("msg", "failed to expire silence", "err", err) + level.Error(logger).Log("msg", "Failed to expire silence", "err", err) return silence_ops.NewDeleteSilenceInternalServerError().WithPayload(err.Error()) } return silence_ops.NewDeleteSilenceOK() @@ -714,30 +726,31 @@ func gettableSilenceFromProto(s *silencepb.Silence) (open_api_models.GettableSil } func (api *API) postSilencesHandler(params silence_ops.PostSilencesParams) middleware.Responder { + logger := api.requestLogger(params.HTTPRequest) sil, err := postableSilenceToProto(params.Silence) if err != nil { - level.Error(api.logger).Log("msg", "failed to marshal silence to proto", "err", err) + level.Error(logger).Log("msg", "Failed to marshal silence to proto", "err", err) return silence_ops.NewPostSilencesBadRequest().WithPayload( fmt.Sprintf("failed to convert API silence to internal silence: %v", err.Error()), ) } if sil.StartsAt.After(sil.EndsAt) || sil.StartsAt.Equal(sil.EndsAt) { - msg := "failed to create silence: start time must be before end time" - level.Error(api.logger).Log("msg", msg, "err", err) + msg := "Failed to create silence: start time must be before end time" + level.Error(logger).Log("msg", msg, "starts_at", sil.StartsAt, "ends_at", sil.EndsAt) return silence_ops.NewPostSilencesBadRequest().WithPayload(msg) } if sil.EndsAt.Before(time.Now()) { - msg := "failed to create silence: end time can't be in the past" - level.Error(api.logger).Log("msg", msg, "err", err) + msg := "Failed to create silence: end time can't be in the past" + level.Error(logger).Log("msg", msg, "ends_at", sil.EndsAt) return silence_ops.NewPostSilencesBadRequest().WithPayload(msg) } sid, err := api.silences.Set(sil) if err != nil { - level.Error(api.logger).Log("msg", "failed to create silence", "err", err) + level.Error(logger).Log("msg", "Failed to create silence", "err", err) if err == silence.ErrNotFound { return silence_ops.NewPostSilencesNotFound().WithPayload(err.Error()) } diff --git a/pkg/labels/parse.go b/pkg/labels/parse.go index a3fbfb10..7f664eca 100644 --- a/pkg/labels/parse.go +++ b/pkg/labels/parse.go @@ -14,9 +14,10 @@ package labels import ( - "fmt" "regexp" "strings" + + "github.com/pkg/errors" ) var ( @@ -70,17 +71,17 @@ func ParseMatcher(s string) (*Matcher, error) { ms := re.FindStringSubmatch(s) if len(ms) < 4 { - return nil, fmt.Errorf("bad matcher format: %s", s) + return nil, errors.Errorf("bad matcher format: %s", s) } name = ms[1] if name == "" { - return nil, fmt.Errorf("failed to parse label name") + return nil, errors.New("failed to parse label name") } matchType, found := typeMap[ms[2]] if !found { - return nil, fmt.Errorf("failed to find match operator") + return nil, errors.New("failed to find match operator") } if ms[3] != "" {