From 84ed4c8006d4b08074b41d7266b5b5241e18cbf7 Mon Sep 17 00:00:00 2001 From: Ashu Ghildiyal Date: Fri, 12 Feb 2021 15:03:13 +0530 Subject: [PATCH 1/4] backend: Update semver package Semver/v4 is compatible with go modules and thus this patch replaces semver with semver/v4. --- go.mod | 2 +- go.sum | 2 ++ pkg/api/helpers.go | 2 +- pkg/api/updates.go | 2 +- 4 files changed, 5 insertions(+), 3 deletions(-) diff --git a/go.mod b/go.mod index 6ba84eb82..faf376891 100644 --- a/go.mod +++ b/go.mod @@ -6,7 +6,7 @@ replace github.com/coreos/go-omaha => github.com/kinvolk/go-omaha v0.0.0-2020112 require ( github.com/Depado/ginprom v1.5.0 - github.com/blang/semver v3.5.1+incompatible + github.com/blang/semver/v4 v4.0.0 github.com/coreos/go-omaha v0.0.0 // replaced with github.com/kinvolk/go-omaha github.com/doug-martin/goqu/v9 v9.10.0 github.com/facebookgo/clock v0.0.0-20150410010913-600d898af40a // indirect diff --git a/go.sum b/go.sum index 13ceb2e3b..4fd731346 100644 --- a/go.sum +++ b/go.sum @@ -70,6 +70,8 @@ github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6r github.com/bgentry/speakeasy v0.1.0/go.mod h1:+zsyZBPWlz7T6j88CTgSN5bM796AkVf0kBD4zp0CCIs= github.com/blang/semver v3.5.1+incompatible h1:cQNTCjp13qL8KC3Nbxr/y2Bqb63oX6wdnnjpJbkM4JQ= github.com/blang/semver v3.5.1+incompatible/go.mod h1:kRBLl5iJ+tD4TcOOxsy/0fnwebNt5EWlYSAyrTnjyyk= +github.com/blang/semver/v4 v4.0.0 h1:1PFHFE6yCCTv8C1TeyNNarDzntLi7wMI5i/pzqYIsAM= +github.com/blang/semver/v4 v4.0.0/go.mod h1:IbckMUScFkM3pff0VJDNKRiT6TG/YpiHIM2yvyW5YoQ= github.com/bombsimon/wsl v1.2.5 h1:9gTOkIwVtoDZywvX802SDHokeX4kW1cKnV8ZTVAPkRs= github.com/bombsimon/wsl v1.2.5/go.mod h1:43lEF/i0kpXbLCeDXL9LMT8c92HyBywXb0AsgMHYngM= github.com/casbin/casbin/v2 v2.1.2/go.mod h1:YcPU1XXisHhLzuxH9coDNf2FbKpjGlbCg3n9yuLkIJQ= diff --git a/pkg/api/helpers.go b/pkg/api/helpers.go index 6568a7af3..96193e9a6 100644 --- a/pkg/api/helpers.go +++ b/pkg/api/helpers.go @@ -3,7 +3,7 @@ package api import ( "time" - "github.com/blang/semver" + "github.com/blang/semver/v4" ) const ( diff --git a/pkg/api/updates.go b/pkg/api/updates.go index db0438931..93313ddd7 100644 --- a/pkg/api/updates.go +++ b/pkg/api/updates.go @@ -4,7 +4,7 @@ import ( "errors" "time" - "github.com/blang/semver" + "github.com/blang/semver/v4" ) const ( From e1f15f9ce34172477ab861129dbf886897c588b1 Mon Sep 17 00:00:00 2001 From: Ashu Ghildiyal Date: Sun, 14 Feb 2021 20:25:05 +0530 Subject: [PATCH 2/4] backend: Replace logxi package with zerolog Logxi is not into active development and thus we need to replace it with a better logging library which is also into active development. zerolog is fast and simple to use and meets the above criteria as well. --- cmd/nebraska/auth/auth.go | 9 +- cmd/nebraska/auth/githubauth.go | 124 ++++++++++++------------- cmd/nebraska/controller.go | 158 ++++++++++++++++---------------- cmd/nebraska/metrics.go | 4 +- cmd/nebraska/nebraska.go | 21 +++-- cmd/nebraska/router.go | 20 +--- go.mod | 3 +- go.sum | 8 +- pkg/api/api.go | 7 +- pkg/api/applications.go | 6 +- pkg/api/channels.go | 2 +- pkg/api/events.go | 28 +++--- pkg/api/groups.go | 6 +- pkg/api/instances.go | 2 +- pkg/api/packages.go | 4 +- pkg/api/updates.go | 24 ++--- pkg/omaha/omaha.go | 35 ++++--- pkg/syncer/syncer.go | 42 +++++---- 18 files changed, 254 insertions(+), 249 deletions(-) diff --git a/cmd/nebraska/auth/auth.go b/cmd/nebraska/auth/auth.go index b086239ef..cdbd87753 100644 --- a/cmd/nebraska/auth/auth.go +++ b/cmd/nebraska/auth/auth.go @@ -1,14 +1,19 @@ package auth import ( + "os" + "github.com/gin-gonic/gin" - log "github.com/mgutz/logxi/v1" + "github.com/rs/zerolog" "github.com/kinvolk/nebraska/cmd/nebraska/ginhelpers" ) var ( - logger = log.New("auth") + logger = zerolog.New(zerolog.ConsoleWriter{Out: os.Stderr}).Hook( + zerolog.HookFunc(func(e *zerolog.Event, level zerolog.Level, message string) { + e.Str("context", "auth") + })) ) // Authenticator provides a way to authenticate a user sending an HTTP diff --git a/cmd/nebraska/auth/githubauth.go b/cmd/nebraska/auth/githubauth.go index 4985adbf0..0f37715c4 100644 --- a/cmd/nebraska/auth/githubauth.go +++ b/cmd/nebraska/auth/githubauth.go @@ -154,9 +154,9 @@ func (gha *githubAuth) Authenticate(c *gin.Context) (teamID string, replied bool session.Set("state", oauthState) session.Set("desiredurl", c.Request.URL.String()) sessionSave(c, session, "authMissingTeamID") - logger.Debug("authenticate", "oauthstate", oauthState) + logger.Debug().Str("oauthstate", oauthState).Msg("authenticate") url := gha.oauthConfig.AuthCodeURL(oauthState, oauth2.AccessTypeOnline) - logger.Debug("authenticate", "redirecting to", url) + logger.Debug().Str("redirecting to", url).Msg("authenticate") redirectTo(c, url) teamID = "" replied = true @@ -172,15 +172,15 @@ func (gha *githubAuth) Authenticate(c *gin.Context) (teamID string, replied bool }() splitToken := strings.Fields(authHeader) if len(splitToken) != 2 { - logger.Debug("auth metrics", "malformed authorization header", authHeader) + logger.Debug().Str("malformed authorization header", authHeader).Msg("auth metrics") return } if strings.ToLower(strings.TrimSpace(splitToken[0])) != "bearer" { - logger.Debug("auth metrics", "authorization is not a bearer token", authHeader) + logger.Debug().Str("authorization is not a bearer token", authHeader).Msg("auth metrics") return } bearerToken := strings.TrimSpace(splitToken[1]) - logger.Debug("auth metrics", "going to do the login dance with token", bearerToken) + logger.Debug().Str("going to do the login dance with token", bearerToken).Msg("auth metrics") token := oauth2.Token{ AccessToken: bearerToken, } @@ -219,31 +219,31 @@ func (gha *githubAuth) loginCb(c *gin.Context) { defer sessionSave(c, session, "login cb") desiredURL, ok := session.Get("desiredurl").(string) if !ok { - logger.Error("login cb", "expected to have a valid desiredurl item in session data") + logger.Error().Str("login cb", "expected to have a valid desiredurl item in session data").Send() return } state := c.Request.FormValue("state") - logger.Debug("login cb", "received oauth state", state) + logger.Debug().Str("state", state).Msg("login cb received oauth") expectedState, ok := session.Get("state").(string) if !ok { - logger.Error("login cb", "expected to have a valid state item in session data") + logger.Error().Str("login cb", "expected to have a valid state item in session data").Send() return } if expectedState != state { - logger.Error("login cb: invalid oauth state", "expected", expectedState, "got", state) + logger.Error().Str("expected", expectedState).Str("got", state).Msg("login cb: invalid oauth state") return } code := c.Request.FormValue("code") - logger.Debug("login cb", "received code", code) + logger.Debug().Str("code", code).Msg("login cb received") token, err := gha.oauthConfig.Exchange(c.Request.Context(), code) if err != nil { - logger.Error("login cb: oauth exchange failed", "error", err) + logger.Error().Err(err).Msg("login cb: oauth exchange failed error") return } - logger.Debug("login cb", "received token", token) + logger.Debug().Msgf("login cb received token %s", token) if !token.Valid() { - logger.Error("login cb", "got invalid token") + logger.Error().Err(fmt.Errorf("login cb got invalid token")).Send() return } @@ -257,13 +257,13 @@ func (gha *githubAuth) loginCb(c *gin.Context) { func (gha *githubAuth) loginWebhook(c *gin.Context) { signature := c.Request.Header.Get("X-Hub-Signature") if len(signature) == 0 { - logger.Debug("webhook", "request with missing signature, ignoring it") + logger.Debug().Str("webhook", "request with missing signature, ignoring it").Send() return } eventType := c.Request.Header.Get("X-Github-Event") rawPayload, err := ioutil.ReadAll(c.Request.Body) if err != nil { - logger.Debug("webhook", "failed to read the contents of the message", eventType) + logger.Debug().Str("failed to read the contents of the message", eventType).Msg("webhook") return } mac := hmac.New(sha1.New, []byte(gha.webhookSecret)) @@ -271,11 +271,11 @@ func (gha *githubAuth) loginWebhook(c *gin.Context) { payloadMAC := hex.EncodeToString(mac.Sum(nil)) // [5:] is to drop the "sha1-" part. if !hmac.Equal([]byte(signature[5:]), []byte(payloadMAC)) { - logger.Debug("webhook", "message validation failed") + logger.Debug().Str("webhook", "message validation failed").Send() return } payloadReader := bytes.NewBuffer(rawPayload) - logger.Debug("webhook", "got event of type", eventType) + logger.Debug().Str("got event of type", eventType).Msg("webhook") switch eventType { case "github_app_authorization": gha.loginWebhookAuthorizationEvent(c, payloadReader) @@ -286,7 +286,7 @@ func (gha *githubAuth) loginWebhook(c *gin.Context) { case "team": gha.loginWebhookTeamEvent(c, payloadReader) default: - logger.Debug("webhook", "ignoring event", eventType) + logger.Debug().Str("ignoring event", eventType).Msg("webhook") return } } @@ -323,7 +323,7 @@ func (gha *githubAuth) doLoginDance(c *gin.Context, oauthClient *http.Client) (r gha.enterpriseURL+"/api/v3/upload", oauthClient) if err != nil { - logger.Error("create enterprise client", "failed to create", err) + logger.Error().Err(err).Msg("create enterprise client failed to create") result = resultInternalFailure return } @@ -331,12 +331,12 @@ func (gha *githubAuth) doLoginDance(c *gin.Context, oauthClient *http.Client) (r ghUser, _, err := client.Users.Get(c.Request.Context(), "") if err != nil { - logger.Error("login dance", "failed to get authenticated user", err) + logger.Error().Err(err).Str("login dance", "failed to get authenticated user").Send() result = resultInternalFailure return } if ghUser.Login == nil { - logger.Error("login dance", "authenticated as a user without a login, meh") + logger.Error().Err(fmt.Errorf("login dance authenticated as a user without a login, meh")).Send() return } @@ -355,33 +355,33 @@ checkLoop: for { ghTeams, response, err := client.Teams.ListUserTeams(c.Request.Context(), &listOpts) if err != nil { - logger.Error("login dance", "failed to get user teams", err) + logger.Error().Err(err).Str("login dance", "failed to get user teams").Send() result = resultInternalFailure return } for _, ghTeam := range ghTeams { if ghTeam.Name == nil { - logger.Debug("login dance", "unnamed github team") + logger.Debug().Str("login dance", "unnamed github team").Send() continue } - logger.Debug("login dance", "github team", *ghTeam.Name) + logger.Debug().Str("github team", *ghTeam.Name).Msg("login dance") if ghTeam.Organization == nil { - logger.Debug("login dance", "github team with no org") + logger.Debug().Str("login dance", "github team with no org").Send() continue } if ghTeam.Organization.Login == nil { - logger.Debug("login dance", "github team in unnamed organization") + logger.Debug().Str("login dance", "github team in unnamed organization") continue } - logger.Debug("login dance", "github team in organization", *ghTeam.Organization.Login) + logger.Debug().Str("github team in organization", *ghTeam.Organization.Login).Msg("login dance") fullGithubTeamName := makeTeamName(*ghTeam.Organization.Login, *ghTeam.Name) - logger.Debug("login dance", "trying to find a matching ro or rw team", fullGithubTeamName) + logger.Debug().Str("trying to find a matching ro or rw team", fullGithubTeamName).Msg("login dance") for _, roTeam := range roTeams { if isRO { break } if fullGithubTeamName == roTeam { - logger.Debug("login dance", "found matching ro team", fullGithubTeamName) + logger.Debug().Str("found matching ro team", fullGithubTeamName).Msg("login dance") teamData.org = *ghTeam.Organization.Login teamData.team = ghTeam.Name teamID = gha.defaultTeamID @@ -392,7 +392,7 @@ checkLoop: } for _, rwTeam := range rwTeams { if fullGithubTeamName == rwTeam { - logger.Debug("login dance", "found matching rw team", fullGithubTeamName) + logger.Debug().Str("found matching rw team", fullGithubTeamName).Msg("login dance") teamData.org = *ghTeam.Organization.Login teamData.team = ghTeam.Name teamID = gha.defaultTeamID @@ -410,30 +410,30 @@ checkLoop: listOpts.Page = response.NextPage } if !isRW { - logger.Debug("login dance", "no matching teams found, trying orgs") + logger.Debug().Str("login dance", "no matching teams found, trying orgs").Send() listOpts.Page = 1 checkLoop2: for { ghOrgs, response, err := client.Organizations.List(c.Request.Context(), "", &listOpts) if err != nil { - logger.Error("login dance", "failed to get user orgs", err) + logger.Error().Err(err).Str("login dance", "failed to get user orgs").Send() result = resultInternalFailure return } for _, ghOrg := range ghOrgs { if ghOrg.Login == nil { - logger.Debug("login dance", "unnamed github organization") + logger.Debug().Str("login dance", "unnamed github organization") continue } - logger.Debug("login dance", "github org", *ghOrg.Login) - logger.Debug("login dance", "trying to find a matching ro or rw team", *ghOrg.Login) + logger.Debug().Str("github org", *ghOrg.Login).Msg("login dance") + logger.Debug().Str("trying to find a matching ro or rw team", *ghOrg.Login).Msg("login dance") nebraskaOrgName := *ghOrg.Login for _, roTeam := range roTeams { if isRO { break } if nebraskaOrgName == roTeam { - logger.Debug("login dance", "found matching ro team", nebraskaOrgName) + logger.Debug().Str("found matching ro team", nebraskaOrgName).Msg("login dance") teamData.org = nebraskaOrgName teamID = gha.defaultTeamID isRO = true @@ -443,7 +443,7 @@ checkLoop: } for _, rwTeam := range rwTeams { if nebraskaOrgName == rwTeam { - logger.Debug("login dance", "found matching rw team", nebraskaOrgName) + logger.Debug().Str("found matching rw team", nebraskaOrgName).Msg("login dance") teamData.org = nebraskaOrgName teamID = gha.defaultTeamID session.Set("accesslevel", "rw") @@ -460,7 +460,7 @@ checkLoop: } } if teamID == "" { - logger.Debug("login dance", "not authorized") + logger.Debug().Str("login dance", "not authorized").Send() return } username := *ghUser.Login @@ -525,7 +525,7 @@ func (gha *githubAuth) cleanupSession(c *gin.Context) { func sessionSave(c *gin.Context, session *sessions.Session, msg string) { if err := ginsessions.SaveSession(c, session); err != nil { - logger.Error(msg, "failed to save the session", err) + logger.Error().Err(err).Str("failed to save the session", msg).Send() httpError(c, http.StatusInternalServerError) } } @@ -585,20 +585,20 @@ type ( func (gha *githubAuth) loginWebhookAuthorizationEvent(c *gin.Context, payloadReader io.Reader) { var payload ghAppAuthPayload if err := json.NewDecoder(payloadReader).Decode(&payload); err != nil { - logger.Error("webhook", "error unmarshalling github_app_authorization payload", err.Error()) + logger.Error().Err(err).Str("webhook", "error unmarshalling github_app_authorization payload").Send() httpError(c, http.StatusBadRequest) return } - logger.Debug("webhook", "got github_app_authorization event with action", payload.Action) + logger.Debug().Str("got github_app_authorization event with action", payload.Action).Msg("webhook") if payload.Action != "revoked" { - logger.Debug("webhook", "ignoring github_app_authorization event with action", payload.Action) + logger.Debug().Str("ignoring github_app_authorization event with action", payload.Action).Msg("webhook") return } username := payload.Sender.Login - logger.Debug("webhook", "dropping all the sessions of user", username) + logger.Debug().Str("dropping all the sessions of user", username).Msg("webhook") userSessionIDs := gha.stealUserSessionIDs(username) for _, sessionID := range userSessionIDs { - logger.Debug("webhook", "dropping session", sessionID) + logger.Debug().Str("dropping session", sessionID).Msg("webhook") gha.sessionsStore.MarkOrDestroySessionByID(sessionID) } } @@ -629,20 +629,20 @@ func (gha *githubAuth) stealUserSessionIDs(username string) []string { func (gha *githubAuth) loginWebhookOrganizationEvent(c *gin.Context, payloadReader io.Reader) { var payload ghOrganizationPayload if err := json.NewDecoder(payloadReader).Decode(&payload); err != nil { - logger.Error("webhook", "error unmarshalling organization payload", err.Error()) + logger.Error().Err(err).Str("webhook", "error unmarshalling organization payload").Send() httpError(c, http.StatusBadRequest) return } - logger.Debug("webhook", "got organization event with action", payload.Action) + logger.Debug().Msgf("webhook got organization event with action %s", payload.Action) if payload.Action != "member_removed" { - logger.Debug("webhook", "ignoring organization event with action", payload.Action) + logger.Debug().Str("ignoring organization event with action", payload.Action).Msg("webhook") return } username := payload.Membership.User.Login org := payload.Org.Login sessionIDs := gha.stealUserSessionIDsForOrg(username, org) for _, sessionID := range sessionIDs { - logger.Debug("webhook", "dropping session", sessionID) + logger.Debug().Str("webhook dropping session", sessionID).Send() gha.sessionsStore.MarkOrDestroySessionByID(sessionID) } } @@ -663,7 +663,7 @@ func (gha *githubAuth) stealUserSessionIDsForOrg(username, org string) []string delete(sessionIDsAndTeams, sessionID) } if len(sessionIDsAndTeams) == 0 { - logger.Debug("webhook", "dropped all the sessions of user", username) + logger.Debug().Str("dropped all the sessions of user", username).Msg("webhook") delete(gha.userSessionIDs, username) } } @@ -673,18 +673,18 @@ func (gha *githubAuth) stealUserSessionIDsForOrg(username, org string) []string func (gha *githubAuth) loginWebhookMembershipEvent(c *gin.Context, payloadReader io.Reader) { var payload ghMembershipPayload if err := json.NewDecoder(payloadReader).Decode(&payload); err != nil { - logger.Error("webhook", "error unmarshalling membership payload", err.Error()) + logger.Error().Err(err).Str("webhook", "error unmarshalling membership payload") httpError(c, http.StatusBadRequest) return } - logger.Debug("webhook", "got membership event with action", payload.Action) + logger.Debug().Str("got membership event with action", payload.Action).Msg("webhook") if payload.Action != "removed" { - logger.Debug("webhook", "ignoring membership event with action", payload.Action) + logger.Debug().Str("ignoring membership event with action", payload.Action).Msg("webhook") return } - logger.Debug("webhook", "got membership remove event with scope", payload.Scope) + logger.Debug().Str("got membership remove event with scope", payload.Scope).Msg("webhook") if payload.Scope != "team" { - logger.Debug("webhook", "ignoring membership remove event with scope", payload.Scope) + logger.Debug().Str("ignoring membership remove event with scope", payload.Scope).Msg("webhook") return } username := payload.Member.Login @@ -692,7 +692,7 @@ func (gha *githubAuth) loginWebhookMembershipEvent(c *gin.Context, payloadReader team := payload.Team.Name sessionIDs := gha.stealUserSessionIDsForOrgAndTeam(username, org, team) for _, sessionID := range sessionIDs { - logger.Debug("webhook", "dropping session", sessionID, "user", username) + logger.Debug().Str("dropping session", sessionID).Str("user", username).Msg("webhook") gha.sessionsStore.MarkOrDestroySessionByID(sessionID) } } @@ -720,7 +720,7 @@ func (gha *githubAuth) stealUserSessionIDsForOrgAndTeam(username, org, team stri delete(sessionIDsAndTeams, sessionID) } if len(sessionIDsAndTeams) == 0 { - logger.Debug("webhook", "dropped all the sessions of user", username) + logger.Debug().Str("dropped all the sessions of user", username).Msg("webhook") delete(gha.userSessionIDs, username) } } @@ -730,11 +730,11 @@ func (gha *githubAuth) stealUserSessionIDsForOrgAndTeam(username, org, team stri func (gha *githubAuth) loginWebhookTeamEvent(c *gin.Context, payloadReader io.Reader) { var payload ghTeamPayload if err := json.NewDecoder(payloadReader).Decode(&payload); err != nil { - logger.Error("webhook", "error unmarshalling team payload", err.Error()) + logger.Error().Err(err).Str("webhook", "error unmarshalling team payload").Send() httpError(c, http.StatusBadRequest) return } - logger.Debug("webhook", "got team event with action", payload.Action) + logger.Debug().Str("got team event with action", payload.Action).Msg("webhook") org := payload.Org.Login team := "" switch payload.Action { @@ -742,17 +742,17 @@ func (gha *githubAuth) loginWebhookTeamEvent(c *gin.Context, payloadReader io.Re team = payload.Team.Name case "edited": if payload.Changes.Name.From == "" { - logger.Debug("ignoring edited team event that does not rename the team") + logger.Debug().Msg("ignoring edited team event that does not rename the team") return } team = payload.Changes.Name.From default: - logger.Debug("webhook", "ignoring team event with action", payload.Action) + logger.Debug().Str("ignoring team event with action", payload.Action).Msg("webhook") return } sessionIDs := gha.stealSessionIDsForOrgAndTeam(org, team) for _, sessionID := range sessionIDs { - logger.Debug("webhook", "dropping session", sessionID) + logger.Debug().Str("webhook dropping session", sessionID).Send() gha.sessionsStore.MarkOrDestroySessionByID(sessionID) } } @@ -775,7 +775,7 @@ func (gha *githubAuth) stealSessionIDsForOrgAndTeam(org, team string) []string { delete(sessionIDsAndTeams, sessionID) } if len(sessionIDsAndTeams) == 0 { - logger.Debug("webhook", "dropped all the sessions of user", username) + logger.Debug().Str("dropped all the sessions of user", username).Msg("webhook") delete(gha.userSessionIDs, username) } } diff --git a/cmd/nebraska/controller.go b/cmd/nebraska/controller.go index 90c3b5f28..0f422072c 100644 --- a/cmd/nebraska/controller.go +++ b/cmd/nebraska/controller.go @@ -126,11 +126,11 @@ func NewClientConfig(conf *controllerConfig) *ClientConfig { if *appLogoPath != "" { svg, err := ioutil.ReadFile(*appLogoPath) if err != nil { - logger.Error("Reading svg from path in config", err.Error()) + logger.Error().Err(err).Msg("Reading svg from path in config") return nil } if err := xml.Unmarshal(svg, &struct{}{}); err != nil { - logger.Error("Invalid format for SVG", err) + logger.Error().Err(err).Msg("Invalid format for SVG") return nil } config.Logo = string(svg) @@ -149,7 +149,7 @@ func (ctl *controller) authenticate(c *gin.Context) { if replied { return } - logger.Debug("authenticate", "setting team id in context keys", teamID) + logger.Debug().Str("setting team id in context keys", teamID).Msg("authenticate") c.Set("team_id", teamID) c.Next() } @@ -170,7 +170,7 @@ func (ctl *controller) addApp(c *gin.Context) { app := &api.Application{} if err := json.NewDecoder(c.Request.Body).Decode(app); err != nil { - logger.Error("addApp - decoding payload", "error", err.Error()) + logger.Error().Err(err).Msg("addApp - decoding payload") httpError(c, http.StatusBadRequest) return } @@ -178,26 +178,26 @@ func (ctl *controller) addApp(c *gin.Context) { _, err := ctl.api.AddAppCloning(app, sourceAppID) if err != nil { - logger.Error("addApp - cloning app", "error", err.Error(), "app", app, "sourceAppID", sourceAppID) + logger.Error().Err(err).Str("sourceAppID", sourceAppID).Msgf("addApp - cloning app %v", app) httpError(c, http.StatusBadRequest) return } app, err = ctl.api.GetApp(app.ID) if err != nil { - logger.Error("addApp - getting added app", "error", err.Error(), "appID", app.ID) + logger.Error().Err(err).Str("appID", app.ID).Msgf("addApp - getting added app") httpError(c, http.StatusInternalServerError) return } if err := json.NewEncoder(c.Writer).Encode(app); err != nil { - logger.Error("addApp - encoding app", "error", err.Error(), "app", app) + logger.Error().Err(err).Msgf("addApp - encoding app %v", app) } } func (ctl *controller) updateApp(c *gin.Context) { app := &api.Application{} if err := json.NewDecoder(c.Request.Body).Decode(app); err != nil { - logger.Error("updateApp - decoding payload", "error", err.Error()) + logger.Error().Err(err).Msg("updateApp - decoding payload") httpError(c, http.StatusBadRequest) return } @@ -206,19 +206,19 @@ func (ctl *controller) updateApp(c *gin.Context) { err := ctl.api.UpdateApp(app) if err != nil { - logger.Error("updatedApp - updating app", "error", err.Error(), "app", app) + logger.Error().Err(err).Msgf("updatedApp - updating app %v", app) httpError(c, http.StatusBadRequest) return } app, err = ctl.api.GetApp(app.ID) if err != nil { - logger.Error("updateApp - getting updated app", "error", err.Error(), "appID", app.ID) + logger.Error().Err(err).Str("appID", app.ID).Msg("updateApp - getting updated app") httpError(c, http.StatusInternalServerError) return } if err := json.NewEncoder(c.Writer).Encode(app); err != nil { - logger.Error("updateApp - encoding app", "error", err.Error(), "appID", app.ID) + logger.Error().Err(err).Str("appID", app.ID).Msg("updateApp - encoding app") } } @@ -230,7 +230,7 @@ func (ctl *controller) deleteApp(c *gin.Context) { case nil: c.Status(http.StatusNoContent) default: - logger.Error("deleteApp", "error", err.Error(), "appID", appID) + logger.Error().Err(err).Str("appID", appID).Msg("deleteApp") httpError(c, http.StatusBadRequest) } } @@ -242,12 +242,12 @@ func (ctl *controller) getApp(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(app); err != nil { - logger.Error("getApp - encoding app", "error", err.Error(), "appID", appID) + logger.Error().Err(err).Str("appID", appID).Msg("getApp - encoding app") } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getApp - getting app", "error", err.Error(), "appID", appID) + logger.Error().Err(err).Str("appID", appID).Msg("getApp - getting app") httpError(c, http.StatusBadRequest) } } @@ -261,12 +261,12 @@ func (ctl *controller) getApps(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(apps); err != nil { - logger.Error("getApps - encoding apps", "error", err.Error(), "teamID", teamID) + logger.Error().Err(err).Str("teamID", teamID).Msgf("getApps - encoding apps") } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getApps - getting apps", "error", err.Error(), "teamID", teamID) + logger.Error().Err(err).Str("teamID", teamID).Msg("getApps - getting apps") httpError(c, http.StatusBadRequest) } } @@ -278,7 +278,7 @@ func (ctl *controller) getApps(c *gin.Context) { func (ctl *controller) addGroup(c *gin.Context) { group := &api.Group{} if err := json.NewDecoder(c.Request.Body).Decode(group); err != nil { - logger.Error("addGroup - decoding payload", "error", err.Error()) + logger.Error().Err(err).Msg("addGroup - decoding payload") httpError(c, http.StatusBadRequest) return } @@ -286,26 +286,26 @@ func (ctl *controller) addGroup(c *gin.Context) { _, err := ctl.api.AddGroup(group) if err != nil { - logger.Error("addGroup - adding group", "error", err.Error(), "group", group) + logger.Error().Err(err).Msgf("addGroup - adding group %v", group) httpError(c, http.StatusBadRequest) return } group, err = ctl.api.GetGroup(group.ID) if err != nil { - logger.Error("addGroup - getting added group", "error", err.Error(), "groupID", group.ID) + logger.Error().Err(err).Str("groupID", group.ID).Msgf("addGroup - getting added group") httpError(c, http.StatusInternalServerError) return } if err := json.NewEncoder(c.Writer).Encode(group); err != nil { - logger.Error("addGroup - encoding group", "error", err.Error(), "group", group) + logger.Error().Err(err).Msgf("addGroup - encoding group %v", group) } } func (ctl *controller) updateGroup(c *gin.Context) { group := &api.Group{} if err := json.NewDecoder(c.Request.Body).Decode(group); err != nil { - logger.Error("updateGroup - decoding payload", "error", err.Error()) + logger.Error().Err(err).Msg("updateGroup - decoding payload") httpError(c, http.StatusBadRequest) return } @@ -314,19 +314,19 @@ func (ctl *controller) updateGroup(c *gin.Context) { err := ctl.api.UpdateGroup(group) if err != nil { - logger.Error("updateGroup - updating group", "error", err.Error(), "group", group) + logger.Error().Err(err).Msgf("updateGroup - updating group %v", group) httpError(c, http.StatusBadRequest) return } group, err = ctl.api.GetGroup(group.ID) if err != nil { - logger.Error("updateGroup - fetching updated group", "error", err.Error(), "groupID", group.ID) + logger.Error().Err(err).Str("groupID", group.ID).Msg("updateGroup - fetching updated group") httpError(c, http.StatusInternalServerError) return } if err := json.NewEncoder(c.Writer).Encode(group); err != nil { - logger.Error("updateGroup - encoding group", "error", err.Error(), "group", group) + logger.Error().Err(err).Msgf("updateGroup - encoding group %v", group) } } @@ -338,7 +338,7 @@ func (ctl *controller) deleteGroup(c *gin.Context) { case nil: c.Status(http.StatusNoContent) default: - logger.Error("deleteGroup", "error", err.Error(), "groupID", groupID) + logger.Error().Err(err).Str("groupID", groupID).Msgf("deleteGroup") httpError(c, http.StatusBadRequest) } } @@ -350,12 +350,12 @@ func (ctl *controller) getGroup(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(group); err != nil { - logger.Error("getGroup - encoding group", "error", err.Error(), "group", group) + logger.Error().Err(err).Msgf("getGroup - encoding group %v", group) } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getGroup - getting group", "error", err.Error(), "groupID", groupID) + logger.Error().Err(err).Str("groupID", groupID).Msg("getGroup - getting group") httpError(c, http.StatusBadRequest) } } @@ -369,12 +369,12 @@ func (ctl *controller) getGroups(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(groups); err != nil { - logger.Error("getGroups - encoding groups", "error", err.Error(), "appID", appID) + logger.Error().Err(err).Str("appID", appID).Msg("getGroups - encoding groups") } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getGroups - getting groups", "error", err.Error(), "appID", appID) + logger.Error().Err(err).Str("appID", appID).Msgf("getGroups - getting groups") httpError(c, http.StatusBadRequest) } } @@ -386,12 +386,12 @@ func (ctl *controller) getGroupVersionCountTimeline(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(versionCountTimeline); err != nil { - logger.Error("getGroupVersionCountTimeline - encoding group", "error", err.Error(), "count-timeline", versionCountTimeline) + logger.Error().Err(err).Msgf("getGroupVersionCountTimeline - encoding group count-timeline %v", versionCountTimeline) } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getGroupVersionCountTimeline - getting version timeline", "error", err.Error(), "groupID", groupID) + logger.Error().Err(err).Str("groupID", groupID).Msgf("getGroupVersionCountTimeline - getting version timeline") httpError(c, http.StatusBadRequest) } } @@ -403,12 +403,12 @@ func (ctl *controller) getGroupStatusCountTimeline(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(statusCountTimeline); err != nil { - logger.Error("getGroupStatusCountTimeline - encoding group", "error", err.Error(), "count-timeline", statusCountTimeline) + logger.Error().Err(err).Msgf("getGroupStatusCountTimeline - encoding group count-timeline %v", statusCountTimeline) } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getGroupStatusCountTimeline - getting status timeline", "error", err.Error(), "groupID", groupID) + logger.Error().Err(err).Str("groupID", groupID).Msgf("getGroupStatusCountTimeline - getting status timeline") httpError(c, http.StatusBadRequest) } } @@ -420,12 +420,12 @@ func (ctl *controller) getGroupInstancesStats(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(instancesStats); err != nil { - logger.Error("getGroupInstancesStats - encoding group", "error", err.Error(), "instancesStats", instancesStats) + logger.Error().Err(err).Msgf("getGroupInstancesStats - encoding group instancesStats %v", instancesStats) } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getGroupInstancesStats - getting instances stats", "error", err.Error(), "groupID", groupID) + logger.Error().Err(err).Str("groupID", groupID).Msgf("getGroupInstancesStats - getting instances stats groupID") httpError(c, http.StatusBadRequest) } } @@ -437,12 +437,12 @@ func (ctl *controller) getGroupVersionBreakdown(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(versionBreakdown); err != nil { - logger.Error("getVersionBreakdown - encoding group", "error", err.Error(), "version_breakdown", versionBreakdown) + logger.Error().Err(err).Msgf("getVersionBreakdown - encoding group version_breakdown %v", versionBreakdown) } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getVersionBreakdown - getting version breakdown", "error", err.Error(), "groupID", groupID) + logger.Error().Err(err).Str("groupID", groupID).Msg("getVersionBreakdown - getting version breakdown") httpError(c, http.StatusBadRequest) } } @@ -454,7 +454,7 @@ func (ctl *controller) getGroupVersionBreakdown(c *gin.Context) { func (ctl *controller) addChannel(c *gin.Context) { channel := &api.Channel{} if err := json.NewDecoder(c.Request.Body).Decode(channel); err != nil { - logger.Error("addChannel", "error", err.Error()) + logger.Error().Err(err).Msgf("addChannel") httpError(c, http.StatusBadRequest) return } @@ -462,26 +462,26 @@ func (ctl *controller) addChannel(c *gin.Context) { _, err := ctl.api.AddChannel(channel) if err != nil { - logger.Error("addChannel", "error", err.Error(), "channel", channel) + logger.Error().Err(err).Msgf("addChannel channel %v", channel) httpError(c, http.StatusBadRequest) return } channel, err = ctl.api.GetChannel(channel.ID) if err != nil { - logger.Error("addChannel", "error", err.Error(), "channelID", channel.ID) + logger.Error().Err(err).Str("channelID", channel.ID).Msg("addChannel") httpError(c, http.StatusInternalServerError) return } if err := json.NewEncoder(c.Writer).Encode(channel); err != nil { - logger.Error("addChannel - encoding channel", "error", err.Error(), "channelID", channel.ID) + logger.Error().Err(err).Str("channelID", channel.ID).Msg("addChannel - encoding channel") } } func (ctl *controller) updateChannel(c *gin.Context) { channel := &api.Channel{} if err := json.NewDecoder(c.Request.Body).Decode(channel); err != nil { - logger.Error("updateChannel - decoding payload", "error", err.Error()) + logger.Error().Err(err).Msg("updateChannel - decoding payload") httpError(c, http.StatusBadRequest) return } @@ -490,19 +490,19 @@ func (ctl *controller) updateChannel(c *gin.Context) { err := ctl.api.UpdateChannel(channel) if err != nil { - logger.Error("updateChannel - updating channel", "error", err.Error(), "channel", channel) + logger.Error().Err(err).Msgf("updateChannel - updating channel %v", channel) httpError(c, http.StatusBadRequest) return } channel, err = ctl.api.GetChannel(channel.ID) if err != nil { - logger.Error("updateChannel - getting channel updated", "error", err.Error(), "channelID", channel.ID) + logger.Error().Err(err).Str("channelID", channel.ID).Msg("updateChannel - getting channel updated") httpError(c, http.StatusInternalServerError) return } if err := json.NewEncoder(c.Writer).Encode(channel); err != nil { - logger.Error("updateChannel - encoding channel", "error", err.Error(), "channelID", channel.ID) + logger.Error().Err(err).Str("channelID", channel.ID).Msgf("updateChannel - encoding channel") } } @@ -514,7 +514,7 @@ func (ctl *controller) deleteChannel(c *gin.Context) { case nil: c.Status(http.StatusNoContent) default: - logger.Error("deleteChannel", "error", err.Error(), "channelID", channelID) + logger.Error().Err(err).Str("channelID", channelID).Msg("deleteChannel") httpError(c, http.StatusBadRequest) } } @@ -526,12 +526,12 @@ func (ctl *controller) getChannel(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(channel); err != nil { - logger.Error("getChannel - encoding channel", "error", err.Error(), "channelID", channelID) + logger.Error().Err(err).Str("channelID", channel.ID).Msg("getChannel - encoding channel") } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getChannel - getting updated channel", "error", err.Error(), "channelID", channelID) + logger.Error().Err(err).Str("channelID", channel.ID).Msg("getChannel - getting updated channel") httpError(c, http.StatusBadRequest) } } @@ -545,12 +545,12 @@ func (ctl *controller) getChannels(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(channels); err != nil { - logger.Error("getChannels - encoding channel", "error", err.Error(), "appID", appID) + logger.Error().Err(err).Str("appID", appID).Msg("getChannels - encoding channel") } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getChannels - getting channels", "error", err.Error(), "appID", appID) + logger.Error().Err(err).Str("appID", appID).Msg("getChannels - getting channels") httpError(c, http.StatusBadRequest) } } @@ -562,7 +562,7 @@ func (ctl *controller) getChannels(c *gin.Context) { func (ctl *controller) addPackage(c *gin.Context) { pkg := &api.Package{} if err := json.NewDecoder(c.Request.Body).Decode(pkg); err != nil { - logger.Error("addPackage - decoding payload", "error", err.Error()) + logger.Error().Err(err).Msg("addPackage - decoding payload") httpError(c, http.StatusBadRequest) return } @@ -570,26 +570,26 @@ func (ctl *controller) addPackage(c *gin.Context) { _, err := ctl.api.AddPackage(pkg) if err != nil { - logger.Error("addPackage - adding package", "error", err.Error(), "package", pkg) + logger.Error().Err(err).Msgf("addPackage - adding package %v", pkg) httpError(c, http.StatusBadRequest) return } pkg, err = ctl.api.GetPackage(pkg.ID) if err != nil { - logger.Error("addPackage - getting added package", "error", err.Error(), "packageID", pkg.ID) + logger.Error().Err(err).Str("packageID", pkg.ID).Msg("addPackage - getting added package") httpError(c, http.StatusInternalServerError) return } if err := json.NewEncoder(c.Writer).Encode(pkg); err != nil { - logger.Error("addPackage - encoding package", "error", err.Error(), "packageID", pkg.ID) + logger.Error().Err(err).Str("packageID", pkg.ID).Msgf("addPackage - encoding package") } } func (ctl *controller) updatePackage(c *gin.Context) { pkg := &api.Package{} if err := json.NewDecoder(c.Request.Body).Decode(pkg); err != nil { - logger.Error("updatePackage - decoding payload", "error", err.Error()) + logger.Error().Err(err).Msg("updatePackage - decoding payload") httpError(c, http.StatusBadRequest) return } @@ -598,19 +598,19 @@ func (ctl *controller) updatePackage(c *gin.Context) { err := ctl.api.UpdatePackage(pkg) if err != nil { - logger.Error("updatePackage - updating package", "error", err.Error(), "package", pkg) + logger.Error().Err(err).Msgf("updatePackage - updating package %v", pkg) httpError(c, http.StatusBadRequest) return } pkg, err = ctl.api.GetPackage(pkg.ID) if err != nil { - logger.Error("addPackage - getting updated package", "error", err.Error(), "packageID", pkg.ID) + logger.Error().Err(err).Str("packageID", pkg.ID).Msg("addPackage - getting updated package") httpError(c, http.StatusInternalServerError) return } if err := json.NewEncoder(c.Writer).Encode(pkg); err != nil { - logger.Error("updatePackage - encoding package", "error", err.Error(), "packageID", pkg.ID) + logger.Error().Err(err).Str("packageID", pkg.ID).Msg("updatePackage - encoding package") } } @@ -622,7 +622,7 @@ func (ctl *controller) deletePackage(c *gin.Context) { case nil: c.Status(http.StatusNoContent) default: - logger.Error("deletePackage", "error", err.Error(), "packageID", packageID) + logger.Error().Err(err).Str("packageID", packageID).Msgf("deletePackage") httpError(c, http.StatusBadRequest) } } @@ -634,12 +634,12 @@ func (ctl *controller) getPackage(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(pkg); err != nil { - logger.Error("getPackage - encoding package", "error", err.Error(), "packageID", packageID) + logger.Error().Err(err).Str("packageID", packageID).Msg("getPackage - encoding package") } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getPackage - getting package", "error", err.Error(), "packageID", packageID) + logger.Error().Err(err).Str("packageID", packageID).Msgf("getPackage - getting package") httpError(c, http.StatusBadRequest) } } @@ -653,12 +653,12 @@ func (ctl *controller) getPackages(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(pkgs); err != nil { - logger.Error("getPackages - encoding packages", "error", err.Error(), "appID", appID) + logger.Error().Err(err).Str("appID", appID).Msg("getPackages - encoding packages") } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getPackages - getting packages", "error", err.Error(), "appID", appID) + logger.Error().Err(err).Str("appID", appID).Msg("getPackages - getting packages") httpError(c, http.StatusBadRequest) } } @@ -677,12 +677,12 @@ func (ctl *controller) getInstanceStatusHistory(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(instanceStatusHistory); err != nil { - logger.Error("getInstanceStatusHistory - encoding status history", "error", err.Error(), "appID", appID, "groupID", groupID, "instanceID", instanceID, "limit", limit) + logger.Error().Err(err).Str("appID", appID).Str("groupID", groupID).Str("instanceID", instanceID).Msgf("getInstanceStatusHistory - encoding status history limit %d", limit) } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getInstanceStatusHistory - getting status history", "error", err.Error(), "appID", appID, "groupID", groupID, "instanceID", instanceID, "limit", limit) + logger.Error().Err(err).Str("appID", appID).Str("groupID", groupID).Str("instanceID", instanceID).Msgf("getInstanceStatusHistory - getting status history limit %d", limit) httpError(c, http.StatusBadRequest) } } @@ -703,10 +703,10 @@ func (ctl *controller) getInstances(c *gin.Context) { result, err := ctl.api.GetInstances(p, duration) if err == nil { if err := json.NewEncoder(c.Writer).Encode(result); err != nil { - logger.Error("getInstances - encoding instances", "error", err.Error(), "params", p) + logger.Error().Err(err).Msgf("getInstances - encoding instances params %v", p) } } else { - logger.Error("getInstances - getting instances", "error", err.Error(), "params", p) + logger.Error().Err(err).Msgf("getInstances - getting instances params %v", p) httpError(c, http.StatusBadRequest) } } @@ -723,10 +723,10 @@ func (ctl *controller) getInstancesCount(c *gin.Context) { result, err := ctl.api.GetInstancesCount(p, duration) if err == nil { if err := json.NewEncoder(c.Writer).Encode(result); err != nil { - logger.Error("getInstances - encoding instances", "error", err.Error(), "params", p) + logger.Error().Err(err).Msgf("getInstances - encoding instances params %v", p) } } else { - logger.Error("getInstances - getting instances", "error", err.Error(), "params", p) + logger.Error().Err(err).Msgf("getInstances - getting instances params %v", p) httpError(c, http.StatusBadRequest) } } @@ -737,10 +737,10 @@ func (ctl *controller) getInstance(c *gin.Context) { result, err := ctl.api.GetInstance(instanceID, appID) if err == nil { if err := json.NewEncoder(c.Writer).Encode(result); err != nil { - logger.Error("getInstance - encoding instance", "error", err.Error(), "appID", appID, "instanceID", instanceID) + logger.Error().Err(err).Str("appID", appID).Str("instanceID", instanceID).Msg("getInstance - encoding instance") } } else { - logger.Error("getInstance - getting instance", "error", err.Error(), "appID", appID, "instanceID", instanceID) + logger.Error().Err(err).Str("appID", appID).Str("instanceID", instanceID).Msg("getInstance - getting instance") httpError(c, http.StatusBadRequest) } } @@ -750,24 +750,24 @@ func (ctl *controller) updateInstance(c *gin.Context) { params := struct{ Alias string }{} if err := json.NewDecoder(c.Request.Body).Decode(¶ms); err != nil { - logger.Error("updateInstance - decoding payload", "error", err.Error()) + logger.Error().Err(err).Msg("updateInstance - decoding payload") httpError(c, http.StatusBadRequest) return } instance, err := ctl.api.UpdateInstance(instanceID, params.Alias) if err != nil { - logger.Error("updateInstance - updating instance", "error", err.Error(), "instance", instanceID, "params", params) + logger.Error().Err(err).Str("instance", instanceID).Msgf("updateInstance - updating params %s", params) httpError(c, http.StatusBadRequest) return } if err == nil { if err := json.NewEncoder(c.Writer).Encode(instance); err != nil { - logger.Error("updateInstance - encoding instance", "error", err.Error(), "instance", instanceID, "params", params) + logger.Error().Err(err).Str("instance", instanceID).Msgf("updateInstance - encoding params %s", params) } } else { - logger.Error("updateInstance - getting instance", "error", err.Error(), "instance", instanceID, "params", params) + logger.Error().Err(err).Str("instance", instanceID).Msgf("updateInstance - getting instance %s params", params) httpError(c, http.StatusBadRequest) } } @@ -796,12 +796,12 @@ func (ctl *controller) getActivity(c *gin.Context) { switch err { case nil: if err := json.NewEncoder(c.Writer).Encode(activityEntries); err != nil { - logger.Error("getActivity - encoding activity entries", "error", err.Error(), "params", p) + logger.Error().Err(err).Msgf("getActivity - encoding activity entries params %v", p) } case sql.ErrNoRows: httpError(c, http.StatusNotFound) default: - logger.Error("getActivity", "error", err, "teamID", teamID, "params", p) + logger.Error().Err(err).Str("teamID", teamID).Msgf("getActivity params %v", p) httpError(c, http.StatusBadRequest) } } @@ -814,7 +814,7 @@ func (ctl *controller) processOmahaRequest(c *gin.Context) { c.Writer.Header().Set("Content-Type", "text/xml") c.Request.Body = http.MaxBytesReader(c.Writer, c.Request.Body, UpdateMaxRequestSize) if err := ctl.omahaHandler.Handle(c.Request.Body, c.Writer, getRequestIP(c.Request)); err != nil { - logger.Error("process omaha request", "error", err) + logger.Error().Err(err).Msgf("process omaha request") if uerr := errors.Unwrap(err); uerr != nil && uerr.Error() == "http: request body too large" { httpError(c, http.StatusBadRequest) } @@ -840,7 +840,7 @@ func getRequestIP(r *http.Request) string { func (ctl *controller) getConfig(c *gin.Context) { if err := json.NewEncoder(c.Writer).Encode(ctl.clientConfig); err != nil { - logger.Error("getConfig - encoding config", "error", err.Error()) + logger.Error().Err(err).Msgf("getConfig - encoding config") httpError(c, http.StatusBadRequest) } } diff --git a/cmd/nebraska/metrics.go b/cmd/nebraska/metrics.go index c15e925ed..5d5a74f81 100644 --- a/cmd/nebraska/metrics.go +++ b/cmd/nebraska/metrics.go @@ -62,7 +62,7 @@ func getMetricsRefreshInterval() time.Duration { refreshInterval, err := time.ParseDuration(refreshIntervalEnvValue) if err != nil || refreshInterval <= 0 { - logger.Warn("invalid NEBRASKA_METRICS_UPDATE_INTERVAL value, it must be acceptable by time.ParseDuration and positive", "value", refreshIntervalEnvValue) + logger.Warn().Str("value", refreshIntervalEnvValue).Msg("invalid NEBRASKA_METRICS_UPDATE_INTERVAL, it must be acceptable by time.ParseDuration and positive value") return defaultMetricsUpdateInterval } return refreshInterval @@ -85,7 +85,7 @@ func registerAndInstrumentMetrics(ctl *controller) error { <-metricsTicker err := calculateMetrics(ctl) if err != nil { - logger.Error("registerAndInstrumentMetrics updating the metrics", "error", err.Error()) + logger.Error().Err(err).Msg("registerAndInstrumentMetrics updating the metrics") } } }() diff --git a/cmd/nebraska/nebraska.go b/cmd/nebraska/nebraska.go index 736fb0fbf..a654a9159 100644 --- a/cmd/nebraska/nebraska.go +++ b/cmd/nebraska/nebraska.go @@ -14,7 +14,7 @@ import ( "github.com/Depado/ginprom" "github.com/gin-gonic/gin" - log "github.com/mgutz/logxi/v1" + "github.com/rs/zerolog" "github.com/kinvolk/nebraska/cmd/nebraska/auth" "github.com/kinvolk/nebraska/pkg/api" @@ -46,18 +46,21 @@ var ( ghReadWriteTeams = flag.String("gh-rw-teams", "", "comma-separated list of read-write GitHub teams in the org/team format") ghReadOnlyTeams = flag.String("gh-ro-teams", "", "comma-separated list of read-only GitHub teams in the org/team format") ghEnterpriseURL = flag.String("gh-enterprise-url", "", fmt.Sprintf("base URL of the enterprise instance if using GHE; can be taken from %s env var too", ghEnterpriseURLEnvName)) - logger = log.New("nebraska") - flatcarUpdatesURL = flag.String("sync-update-url", "https://public.update.flatcar-linux.net/v1/update/", "Flatcar update URL to sync from") - checkFrequencyVal = flag.String("sync-interval", "1h", "Sync check interval (the minimum depends on the number of channels to sync, e.g., 8m for 8 channels incl. different architectures)") - appLogoPath = flag.String("client-logo", "", "Client app logo, should be a path to svg file") - appTitle = flag.String("client-title", "", "Client app title") - appHeaderStyle = flag.String("client-header-style", "light", "Client app header style, should be either dark or light") - apiEndpointSuffix = flag.String("api-endpoint-suffix", "", "Additional suffix for the API endpoint to serve Omaha clients on; use a secret to only serve your clients, e.g., mysecret results in /v1/update/mysecret") + logger = zerolog.New(zerolog.ConsoleWriter{Out: os.Stderr}).Hook( + zerolog.HookFunc(func(e *zerolog.Event, level zerolog.Level, message string) { + e.Str("context", "nebraska") + })) + flatcarUpdatesURL = flag.String("sync-update-url", "https://public.update.flatcar-linux.net/v1/update/", "Flatcar update URL to sync from") + checkFrequencyVal = flag.String("sync-interval", "1h", "Sync check interval (the minimum depends on the number of channels to sync, e.g., 8m for 8 channels incl. different architectures)") + appLogoPath = flag.String("client-logo", "", "Client app logo, should be a path to svg file") + appTitle = flag.String("client-title", "", "Client app title") + appHeaderStyle = flag.String("client-header-style", "light", "Client app header style, should be either dark or light") + apiEndpointSuffix = flag.String("api-endpoint-suffix", "", "Additional suffix for the API endpoint to serve Omaha clients on; use a secret to only serve your clients, e.g., mysecret results in /v1/update/mysecret") ) func main() { if err := mainWithError(); err != nil { - logger.Error(err.Error()) + logger.Error().Err(err).Send() os.Exit(1) } } diff --git a/cmd/nebraska/router.go b/cmd/nebraska/router.go index e02e7dbd9..a9f6e5a8f 100644 --- a/cmd/nebraska/router.go +++ b/cmd/nebraska/router.go @@ -20,10 +20,7 @@ func setupUsedRouterLogging(router gin.IRoutes, name string) { if !ok { reqID = -1 } - logger.Debug("router debug", - "request id", reqID, - "router name", name, - ) + logger.Debug().Msgf("router debug request id %s router name %s", reqID, name) c.Next() }) } @@ -34,25 +31,14 @@ func setupRequestLifetimeLogging(router gin.IRoutes) { c.Set(requestIDKey, reqID) start := time.Now() - logger.Debug("request debug", - "request ID", reqID, - "start time", start, - "method", c.Request.Method, - "URL", c.Request.URL.String(), - "client IP", c.ClientIP(), - ) + logger.Debug().Msgf("request debug request ID %d start time %s method %s URL %s client IP %s", reqID, start, c.Request.Method, c.Request.URL.String(), c.ClientIP()) // Process request c.Next() stop := time.Now() latency := stop.Sub(start) - logger.Debug("request debug", - "request ID", reqID, - "stop time", stop, - "latency", latency, - "status", c.Writer.Status(), - ) + logger.Debug().Msgf("request debug request ID %d stop time %s latency %s status %d", reqID, stop, latency, c.Writer.Status()) }) } diff --git a/go.mod b/go.mod index faf376891..196f629b3 100644 --- a/go.mod +++ b/go.mod @@ -30,9 +30,8 @@ require ( github.com/kevinburke/go-bindata v3.16.0+incompatible github.com/lib/pq v1.8.0 github.com/mattn/go-colorable v0.1.8 // indirect - github.com/mgutz/ansi v0.0.0-20200706080929-d51e80ef957d // indirect - github.com/mgutz/logxi v0.0.0-20161027140823-aebf8a7d67ab github.com/prometheus/client_golang v1.5.0 + github.com/rs/zerolog v1.20.0 github.com/rubenv/sql-migrate v0.0.0-20200616145509-8d140a17f351 github.com/stretchr/testify v1.6.1 github.com/ugorji/go v1.1.13 // indirect diff --git a/go.sum b/go.sum index 4fd731346..3a611c5f0 100644 --- a/go.sum +++ b/go.sum @@ -505,10 +505,6 @@ github.com/mattn/go-sqlite3 v1.12.0/go.mod h1:FPy6KqzDD04eiIsT53CuJW3U88zkxoIYsO github.com/mattn/goveralls v0.0.2/go.mod h1:8d1ZMHsd7fW6IRPKQh46F2WRpyib5/X4FOpevwGNQEw= github.com/matttproud/golang_protobuf_extensions v1.0.1 h1:4hp9jkHxhMHkqkrB3Ix0jegS5sx/RkqARlsWZ6pIwiU= github.com/matttproud/golang_protobuf_extensions v1.0.1/go.mod h1:D8He9yQNgCq6Z5Ld7szi9bcBfOoFv/3dc6xSMkL2PC0= -github.com/mgutz/ansi v0.0.0-20200706080929-d51e80ef957d h1:5PJl274Y63IEHC+7izoQE9x6ikvDFZS2mDVS3drnohI= -github.com/mgutz/ansi v0.0.0-20200706080929-d51e80ef957d/go.mod h1:01TrycV0kFyexm33Z7vhZRXopbI8J3TDReVlkTgMUxE= -github.com/mgutz/logxi v0.0.0-20161027140823-aebf8a7d67ab h1:n8cgpHzJ5+EDyDri2s/GC7a9+qK3/YEGnBsd0uS/8PY= -github.com/mgutz/logxi v0.0.0-20161027140823-aebf8a7d67ab/go.mod h1:y1pL58r5z2VvAjeG1VLGc8zOQgSOzbKN7kMHPvFXJ+8= github.com/miekg/dns v1.0.14/go.mod h1:W1PPwlIAgtquWBMBEV9nkV9Cazfe8ScdGz/Lj7v3Nrg= github.com/mitchellh/cli v1.0.0/go.mod h1:hNIlj7HEI86fIcpObd7a0FcrxTWetlwJDGcceTlRvqc= github.com/mitchellh/go-homedir v1.0.0/go.mod h1:SfyaCUpYCn1Vlf4IUYiD9fPX4A5wJrkLzIz1N1q0pr0= @@ -616,7 +612,10 @@ github.com/rogpeppe/go-internal v1.4.0 h1:LUa41nrWTQNGhzdsZ5lTnkwbNjj6rXTdazA1cS github.com/rogpeppe/go-internal v1.4.0/go.mod h1:xXDCJY+GAPziupqXw64V24skbSoqbTEfhy4qGm1nDQc= github.com/rs/xid v1.2.1/go.mod h1:+uKXf+4Djp6Md1KODXJxgGQPKngRmWyn10oCKFzNHOQ= github.com/rs/zerolog v1.13.0/go.mod h1:YbFCdg8HfsridGWAh22vktObvhZbQsZXe4/zB0OKkWU= +github.com/rs/zerolog v1.15.0 h1:uPRuwkWF4J6fGsJ2R0Gn2jB1EQiav9k3S6CSdygQJXY= github.com/rs/zerolog v1.15.0/go.mod h1:xYTKnLHcpfU2225ny5qZjxnj9NvkumZYjJHlAThCjNc= +github.com/rs/zerolog v1.20.0 h1:38k9hgtUBdxFwE34yS8rTHmHBa4eN16E4DJlv177LNs= +github.com/rs/zerolog v1.20.0/go.mod h1:IzD0RJ65iWH0w97OQQebJEvTZYvsCUm9WVLWBQrJRjo= github.com/rubenv/sql-migrate v0.0.0-20200616145509-8d140a17f351 h1:HXr/qUllAWv9riaI4zh2eXWKmCSDqVS/XH1MRHLKRwk= github.com/rubenv/sql-migrate v0.0.0-20200616145509-8d140a17f351/go.mod h1:DCgfY80j8GYL7MLEfvcpSFvjD0L5yZq/aZUJmhZklyg= github.com/russross/blackfriday v1.5.2/go.mod h1:JO/DiYxRf+HjHt06OyowR9PTA263kcR/rfWxYHBV53g= @@ -931,6 +930,7 @@ golang.org/x/tools v0.0.0-20190628153133-6cdbf07be9d0/go.mod h1:/rFqwRUd4F7ZHNgw golang.org/x/tools v0.0.0-20190719005602-e377ae9d6386/go.mod h1:jcCCGcm9btYwXyDqrUWc6MKQKKGJCWEQ3AfLSRIbEuI= golang.org/x/tools v0.0.0-20190816200558-6889da9d5479/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo= golang.org/x/tools v0.0.0-20190823170909-c4a336ef6a2f/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo= +golang.org/x/tools v0.0.0-20190828213141-aed303cbaa74/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo= golang.org/x/tools v0.0.0-20190910044552-dd2b5c81c578/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo= golang.org/x/tools v0.0.0-20190911174233-4f2ddba30aff/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo= golang.org/x/tools v0.0.0-20190930201159-7c411dea38b0/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo= diff --git a/pkg/api/api.go b/pkg/api/api.go index 29d69a1bb..64d06526f 100644 --- a/pkg/api/api.go +++ b/pkg/api/api.go @@ -7,7 +7,7 @@ import ( //register "pgx" sql driver _ "github.com/jackc/pgx/v4/stdlib" "github.com/jmoiron/sqlx" - log "github.com/mgutz/logxi/v1" + "github.com/rs/zerolog" migrate "github.com/rubenv/sql-migrate" // Postgresql driver @@ -37,7 +37,10 @@ func nowUTC() time.Time { } var ( - logger = log.New("api") + logger = zerolog.New(zerolog.ConsoleWriter{Out: os.Stderr}).Hook( + zerolog.HookFunc(func(e *zerolog.Event, level zerolog.Level, message string) { + e.Str("context", "api") + })) // ErrNoRowsAffected indicates that no rows were affected in an update or // delete database operation. diff --git a/pkg/api/applications.go b/pkg/api/applications.go index fd4068343..6dded46cd 100644 --- a/pkg/api/applications.go +++ b/pkg/api/applications.go @@ -59,7 +59,7 @@ func (api *API) AddAppCloning(app *Application, sourceAppID string) (*Applicatio if sourceAppID != "" { sourceApp, err := api.GetApp(sourceAppID) if err != nil { - logger.Error("AddAppCloning - could not get source app", err) + logger.Error().Err(err).Msg("AddAppCloning - could not get source app") return app, nil } @@ -71,7 +71,7 @@ func (api *API) AddAppCloning(app *Application, sourceAppID string) (*Applicatio channel.PackageID = null.String{} channelCopy, err := api.AddChannel(channel) if err != nil { - logger.Error("AddAppCloning - could not add channel", err) + logger.Error().Err(err).Msg("AddAppCloning - could not add channel") return app, nil // FIXME - think about what we should return to the caller } channelsIDsMappings[originalChannelID] = null.StringFrom(channelCopy.ID) @@ -85,7 +85,7 @@ func (api *API) AddAppCloning(app *Application, sourceAppID string) (*Applicatio group.PolicyUpdatesEnabled = true group.ID = "" if _, err := api.AddGroup(group); err != nil { - logger.Error("AddAppCloning - could not add group", err) + logger.Error().Err(err).Msg("AddAppCloning - could not add group") return app, nil // FIXME - think about what we should return to the caller } } diff --git a/pkg/api/channels.go b/pkg/api/channels.go index 0738faa81..4096fc197 100644 --- a/pkg/api/channels.go +++ b/pkg/api/channels.go @@ -100,7 +100,7 @@ func (api *API) UpdateChannel(channel *Channel) error { if channelBeforeUpdate.PackageID.String != channel.PackageID.String && pkg != nil { if err := api.newChannelActivityEntry(activityChannelPackageUpdated, activityInfo, pkg.Version, pkg.ApplicationID, channel.ID); err != nil { - logger.Error("UpdateChannel - could not add channel activity", err) + logger.Error().Err(err).Msg("UpdateChannel - could not add channel activity") } } diff --git a/pkg/api/events.go b/pkg/api/events.go index e5a655693..064e2b258 100644 --- a/pkg/api/events.go +++ b/pkg/api/events.go @@ -92,7 +92,7 @@ func (api *API) RegisterEvent(instanceID, appID, groupID string, etype, eresult } instance, err := api.GetInstance(instanceID, appID) if err != nil { - logger.Error("RegisterEvent - could not get instance (propagates as ErrInvalidInstance)", err) + logger.Error().Err(err).Msg("RegisterEvent - could not get instance (propagates as ErrInvalidInstance)") return ErrInvalidInstance } if instance.Application.ApplicationID != appID { @@ -115,7 +115,7 @@ func (api *API) RegisterEvent(instanceID, appID, groupID string, etype, eresult // The Undefined state is chosen because the instance did not tell that it updated from a previous // version ("" and "0.0.0.0" are not valid but "0.0.0" is because it is used when forcing an update). if err := api.updateInstanceObjStatus(instance, InstanceStatusUndefined); err != nil { - logger.Error("RegisterEvent - could not update instance status", err) + logger.Error().Err(err).Msg("RegisterEvent - could not update instance status") } return ErrFlatcarEventIgnored } @@ -149,7 +149,7 @@ func (api *API) RegisterEvent(instanceID, appID, groupID string, etype, eresult lastUpdateVersion := instance.Application.LastUpdateVersion.String if err := api.triggerEventConsequences(instanceID, appID, groupID, lastUpdateVersion, etype, eresult); err != nil { - logger.Error("RegisterEvent - could not trigger event consequences", err) + logger.Error().Err(err).Msgf("RegisterEvent - could not trigger event consequences") } return nil @@ -167,7 +167,7 @@ func (api *API) triggerEventConsequences(instanceID, appID, groupID, lastUpdateV // TODO: should we also consider ResultSuccess in the next check? Flatcar ~ generic conflicts? if etype == EventUpdateComplete && result == ResultSuccessReboot { if err := api.updateInstanceStatus(instanceID, appID, InstanceStatusComplete); err != nil { - logger.Error("triggerEventConsequences - could not update instance status", err) + logger.Error().Err(err).Msg("triggerEventConsequences - could not update instance status") } updatesStats, err := api.getGroupUpdatesStats(group) @@ -176,38 +176,38 @@ func (api *API) triggerEventConsequences(instanceID, appID, groupID, lastUpdateV } if updatesStats.UpdatesToCurrentVersionSucceeded == updatesStats.TotalInstances { if err := api.setGroupRolloutInProgress(groupID, false); err != nil { - logger.Error("triggerEventConsequences - could not set rollout progress", err) + logger.Error().Err(err).Msg("triggerEventConsequences - could not set rollout progress") } if err := api.newGroupActivityEntry(activityRolloutFinished, activitySuccess, lastUpdateVersion, appID, groupID); err != nil { - logger.Error("triggerEventConsequences - could not add group activity", err) + logger.Error().Err(err).Msg("triggerEventConsequences - could not add group activity") } } } if etype == EventUpdateDownloadStarted && result == ResultSuccess { if err := api.updateInstanceStatus(instanceID, appID, InstanceStatusDownloading); err != nil { - logger.Error("triggerEventConsequences - could not update instance status", err) + logger.Error().Err(err).Msg("triggerEventConsequences - could not update instance status") } } if etype == EventUpdateDownloadFinished && result == ResultSuccess { if err := api.updateInstanceStatus(instanceID, appID, InstanceStatusDownloaded); err != nil { - logger.Error("triggerEventConsequences - could not update instance status", err) + logger.Error().Err(err).Msg("triggerEventConsequences - could not update instance status") } } if etype == EventUpdateInstalled && result == ResultSuccess { if err := api.updateInstanceStatus(instanceID, appID, InstanceStatusInstalled); err != nil { - logger.Error("triggerEventConsequences - could not update instance status", err) + logger.Error().Err(err).Msg("triggerEventConsequences - could not update instance status") } } if result == ResultFailed { if err := api.updateInstanceStatus(instanceID, appID, InstanceStatusError); err != nil { - logger.Error("triggerEventConsequences - could not update instance status", err) + logger.Error().Err(err).Msg("triggerEventConsequences - could not update instance status") } if err := api.newInstanceActivityEntry(activityInstanceUpdateFailed, activityError, lastUpdateVersion, appID, groupID, instanceID); err != nil { - logger.Error("triggerEventConsequences - could not add instance activity", err) + logger.Error().Err(err).Msg("triggerEventConsequences - could not add instance activity") } if api.disableUpdatesOnFailedRollout { @@ -217,13 +217,13 @@ func (api *API) triggerEventConsequences(instanceID, appID, groupID, lastUpdateV } if updatesStats.UpdatesToCurrentVersionAttempted == 1 { if err := api.disableUpdates(groupID); err != nil { - logger.Error("triggerEventConsequences - could not disable updates", err) + logger.Error().Err(err).Msg("triggerEventConsequences - could not disable updates") } if err := api.setGroupRolloutInProgress(groupID, false); err != nil { - logger.Error("triggerEventConsequences - could not set rollout progress", err) + logger.Error().Err(err).Msg("triggerEventConsequences - could not set rollout progress") } if err := api.newGroupActivityEntry(activityRolloutFailed, activityError, lastUpdateVersion, appID, groupID); err != nil { - logger.Error("triggerEventConsequences - could not add group activity", err) + logger.Error().Err(err).Msg("triggerEventConsequences - could not add group activity") } } } diff --git a/pkg/api/groups.go b/pkg/api/groups.go index ba9344d7d..356c966a5 100644 --- a/pkg/api/groups.go +++ b/pkg/api/groups.go @@ -315,7 +315,7 @@ func (api *API) GetGroupID(trackName string, arch Arch) (string, error) { } // Checks boths errors above. if err != nil { - logger.Error("GetGroupID", "error", err.Error()) + logger.Error().Err(err).Msg("GetGroupID error") } else { for _, group := range groups { if group.Channel != nil { @@ -324,11 +324,11 @@ func (api *API) GetGroupID(trackName string, arch Arch) (string, error) { // The newest group with the track name and arch wins. if otherID, ok := cachedGroups[descriptor]; ok { // Log a warning for others. - logger.Warn("GetGroupID - another group already uses the same track name and architecture", "group", group.ID, "group2", otherID, "track", group.Track) + logger.Warn().Str("group", group.ID).Str("group2", otherID).Str("track", group.Track).Msg("GetGroupID - another group already uses the same track name and architecture") } cachedGroups[descriptor] = group.ID } else { - logger.Warn("GetGroupID - no channel found for group", "group", group.ID) + logger.Warn().Str("group", group.ID).Msg("GetGroupID - no channel found for") } } } diff --git a/pkg/api/instances.go b/pkg/api/instances.go index 46311df38..d42d74e54 100644 --- a/pkg/api/instances.go +++ b/pkg/api/instances.go @@ -182,7 +182,7 @@ func (api *API) RegisterInstance(instanceID, instanceAlias, instanceIP, instance } defer func() { if err := tx.Rollback(); err != nil && err != sql.ErrTxDone { - logger.Error("RegisterInstance - could not roll back", err) + logger.Error().Err(err).Msg("RegisterInstance - could not roll back") } }() diff --git a/pkg/api/packages.go b/pkg/api/packages.go index 1ca7d515e..a0d24f9b5 100644 --- a/pkg/api/packages.go +++ b/pkg/api/packages.go @@ -75,7 +75,7 @@ func (api *API) AddPackage(pkg *Package) (*Package, error) { } defer func() { if err := tx.Rollback(); err != nil && err != sql.ErrTxDone { - logger.Error("AddPackage - could not roll back", err) + logger.Error().Err(err).Msg("AddPackage - could not roll back") } }() @@ -157,7 +157,7 @@ func (api *API) UpdatePackage(pkg *Package) error { } defer func() { if err := tx.Rollback(); err != nil && err != sql.ErrTxDone { - logger.Error("UpdatePackage - could not roll back", err) + logger.Error().Err(err).Msg("UpdatePackage - could not roll back") } }() query, _, err := goqu.Update("package"). diff --git a/pkg/api/updates.go b/pkg/api/updates.go index 93313ddd7..26bc1677c 100644 --- a/pkg/api/updates.go +++ b/pkg/api/updates.go @@ -60,7 +60,7 @@ var ( func (api *API) GetUpdatePackage(instanceID, instanceAlias, instanceIP, instanceVersion, appID, groupID string) (*Package, error) { instance, err := api.RegisterInstance(instanceID, instanceAlias, instanceIP, instanceVersion, appID, groupID) if err != nil { - logger.Error("GetUpdatePackage - could not register instance (propagates as ErrRegisterInstanceFailed)", err) + logger.Error().Err(err).Msg("GetUpdatePackage - could not register instance (propagates as ErrRegisterInstanceFailed)") return nil, ErrRegisterInstanceFailed } updateAlreadyGranted := false @@ -81,7 +81,7 @@ func (api *API) GetUpdatePackage(instanceID, instanceAlias, instanceIP, instance if group.Channel == nil || group.Channel.Package == nil { if err := api.newGroupActivityEntry(activityPackageNotFound, activityWarning, "0.0.0", appID, groupID); err != nil { - logger.Error("GetUpdatePackage - could not add new group activity entry", err) + logger.Error().Err(err).Msg("GetUpdatePackage - could not add new group activity entry") } return nil, ErrNoPackageFound } @@ -90,7 +90,7 @@ func (api *API) GetUpdatePackage(instanceID, instanceAlias, instanceIP, instance if blacklistedChannelID == group.Channel.ID { if updateAlreadyGranted { if err := api.updateInstanceObjStatus(instance, InstanceStatusComplete); err != nil { - logger.Error("GetUpdatePackage - could not update instance status", err) + logger.Error().Err(err).Msg("GetUpdatePackage - could not update instance status") } } return nil, ErrNoUpdatePackageAvailable @@ -102,7 +102,7 @@ func (api *API) GetUpdatePackage(instanceID, instanceAlias, instanceIP, instance if !instanceSemver.LT(packageSemver) { if updateAlreadyGranted { if err := api.updateInstanceObjStatus(instance, InstanceStatusComplete); err != nil { - logger.Error("GetUpdatePackage - could not update instance status", err) + logger.Error().Err(err).Msg("GetUpdatePackage - could not update instance status") } } return nil, ErrNoUpdatePackageAvailable @@ -119,18 +119,18 @@ func (api *API) GetUpdatePackage(instanceID, instanceAlias, instanceIP, instance version := group.Channel.Package.Version if err := api.grantUpdate(instance, version); err != nil { - logger.Error("GetUpdatePackage - grantUpdate error (propagates as ErrGrantingUpdate):", err) + logger.Error().Err(err).Msg("GetUpdatePackage - grantUpdate error (propagates as ErrGrantingUpdate):") } if !api.hasRecentActivity(activityRolloutStarted, ActivityQueryParams{Severity: activityInfo, AppID: appID, Version: version, GroupID: group.ID}) { if err := api.newGroupActivityEntry(activityRolloutStarted, activityInfo, version, appID, group.ID); err != nil { - logger.Error("GetUpdatePackage - could not add new group activity entry", err) + logger.Error().Err(err).Msg("GetUpdatePackage - could not add new group activity entry") } } if !group.RolloutInProgress { if err := api.setGroupRolloutInProgress(groupID, true); err != nil { - logger.Error("GetUpdatePackage - could not set rollout progress", err) + logger.Error().Err(err).Msg("GetUpdatePackage - could not set rollout progress") } } @@ -160,7 +160,7 @@ func (api *API) enforceRolloutPolicy(instance *Instance, group *Group) error { updatesStats, err := api.getGroupUpdatesStats(group) if err != nil { - logger.Error("GetUpdatePackage - getGroupUpdatesStats error (propagates as ErrGetUpdatesStatsFailed):", err) + logger.Error().Err(err).Msg("GetUpdatePackage - getGroupUpdatesStats error (propagates as ErrGetUpdatesStatsFailed):") return ErrGetUpdatesStatsFailed } @@ -170,14 +170,14 @@ func (api *API) enforceRolloutPolicy(instance *Instance, group *Group) error { if updatesStats.UpdatesGrantedInLastPeriod >= effectiveMaxUpdates { if err := api.updateInstanceStatus(instance.ID, appID, InstanceStatusOnHold); err != nil { - logger.Error("enforceRolloutPolicy - could not update instance status", err) + logger.Error().Err(err).Msg("enforceRolloutPolicy - could not update instance status") } return ErrMaxUpdatesPerPeriodLimitReached } if updatesStats.UpdatesInProgress >= effectiveMaxUpdates { if err := api.updateInstanceStatus(instance.ID, appID, InstanceStatusOnHold); err != nil { - logger.Error("enforceRolloutPolicy - could not update instance status", err) + logger.Error().Err(err).Msg("enforceRolloutPolicy - could not update instance status") } return ErrMaxConcurrentUpdatesLimitReached } @@ -185,11 +185,11 @@ func (api *API) enforceRolloutPolicy(instance *Instance, group *Group) error { if group.PolicySafeMode && updatesStats.UpdatesTimedOut >= effectiveMaxUpdates { if group.PolicyUpdatesEnabled { if err := api.disableUpdates(group.ID); err != nil { - logger.Error("enforceRolloutPolicy - could not disable updates", err) + logger.Error().Err(err).Msg("enforceRolloutPolicy - could not disable updates") } } if err := api.updateInstanceStatus(instance.ID, appID, InstanceStatusOnHold); err != nil { - logger.Error("enforceRolloutPolicy - could not update instance status", err) + logger.Error().Err(err).Msg("enforceRolloutPolicy - could not update instance status") } return ErrMaxTimedOutUpdatesLimitReached } diff --git a/pkg/omaha/omaha.go b/pkg/omaha/omaha.go index 3364e871c..425759429 100644 --- a/pkg/omaha/omaha.go +++ b/pkg/omaha/omaha.go @@ -5,16 +5,21 @@ import ( "errors" "fmt" "io" + "os" "strconv" omahaSpec "github.com/coreos/go-omaha/omaha" - log "github.com/mgutz/logxi/v1" + + "github.com/rs/zerolog" "github.com/kinvolk/nebraska/pkg/api" ) var ( - logger = log.New("omaha") + logger = zerolog.New(zerolog.ConsoleWriter{Out: os.Stderr}).Hook( + zerolog.HookFunc(func(e *zerolog.Event, level zerolog.Level, message string) { + e.Str("context", "omaha") + })) initialFlatcarGroups = map[string]string{ // amd64 @@ -56,14 +61,14 @@ func (h *Handler) Handle(rawReq io.Reader, respWriter io.Writer, ip string) erro var omahaReq *omahaSpec.Request if err := xml.NewDecoder(rawReq).Decode(&omahaReq); err != nil { - logger.Warn("Handle - malformed omaha request", "error", err.Error()) + logger.Warn().Msgf("Handle - malformed omaha request error %s", err.Error()) return fmt.Errorf("%s: %w", ErrMalformedRequest, err) } trace(omahaReq) omahaResp, err := h.buildOmahaResponse(omahaReq, ip) if err != nil { - logger.Warn("Handle - error building omaha response", "error", err.Error()) + logger.Warn().Msgf("Handle - error building omaha response error %s", err.Error()) return ErrMalformedResponse } trace(omahaResp) @@ -82,7 +87,7 @@ func getArch(os *omahaSpec.OS, appReq *omahaSpec.AppRequest) api.Arch { return arch } } - logger.Warn("getArch - unknown arch, assuming amd64 arch") + logger.Warn().Msg("getArch - unknown arch, assuming amd64 arch") return api.ArchAMD64 } @@ -97,14 +102,14 @@ func (h *Handler) buildOmahaResponse(omahaReq *omahaSpec.Request, ip string) (*o // but also allows the old hard-coded CoreOS group UUIDs until we now that they are not used. group := reqApp.Track if trackName, ok := initialFlatcarGroups[group]; ok { - logger.Info("buildOmahaResponse - found client using a hard-coded group UUID", "uuid", group) + logger.Info().Str("uuid", group).Msgf("buildOmahaResponse - found client using a hard-coded group UUID") group = trackName } groupID, err := h.crAPI.GetGroupID(group, getArch(omahaReq.OS, reqApp)) if err == nil { group = groupID } else { - logger.Info("buildOmahaResponse - no group found for track and arch", "error", err, "track", group) + logger.Info().Str("track", group).Msgf("buildOmahaResponse - no group found for track and arch error %s", err.Error()) respApp.Status = h.getStatusMessage(err) respApp.AddUpdateCheck(omahaSpec.UpdateInternalError) return omahaResp, nil @@ -112,14 +117,14 @@ func (h *Handler) buildOmahaResponse(omahaReq *omahaSpec.Request, ip string) (*o for _, event := range reqApp.Events { if err := h.processEvent(reqApp.MachineID, reqApp.ID, group, event); err != nil { - logger.Warn("processEvent", "error", err.Error()) + logger.Warn().Msgf("processEvent error %s", err.Error()) } respApp.AddEvent() } if reqApp.Ping != nil { if _, err := h.crAPI.RegisterInstance(reqApp.MachineID, reqApp.MachineAlias, ip, reqApp.Version, reqApp.ID, group); err != nil { - logger.Warn("processPing", "error", err.Error()) + logger.Warn().Msgf("processPing error %s", err.Error()) } respApp.AddPing() } @@ -139,7 +144,7 @@ func (h *Handler) buildOmahaResponse(omahaReq *omahaSpec.Request, ip string) (*o } func (h *Handler) processEvent(machineID string, appID string, group string, event *omahaSpec.EventRequest) error { - logger.Info("processEvent", "appID", appID, "group", group, "event", event.Type.String()+"."+event.Result.String(), "eventError", event.ErrorCode, "previousVersion", event.PreviousVersion) + logger.Info().Str("appID", appID).Str("group", group).Str("event", event.Type.String()+"."+event.Result.String()).Str("previousVersion", event.PreviousVersion).Msgf("processEvent eventError %d", event.ErrorCode) return h.crAPI.RegisterEvent(machineID, appID, group, int(event.Type), int(event.Result), event.PreviousVersion, strconv.Itoa(event.ErrorCode)) } @@ -173,7 +178,7 @@ func (h *Handler) getStatusMessageStr(crErr error) string { return "error-updateInProgressOnInstance" } - logger.Warn("getStatusMessage", "error", crErr.Error()) + logger.Warn().Msgf("getStatusMessage error %s", crErr.Error()) return "error-failedToRetrieveUpdatePackageInfo" } @@ -192,7 +197,7 @@ func (h *Handler) prepareUpdateCheck(appResp *omahaSpec.AppResponse, pkg *api.Pa if pkg.Size.Valid { size, err := strconv.ParseUint(pkg.Size.String, 10, 64) if err != nil { - logger.Warn("prepareUpdateCheck", "bad package size", err.Error()) + logger.Warn().Msgf("prepareUpdateCheck bad package size %s", err.Error()) } else { mpkg.Size = size } @@ -223,12 +228,12 @@ func (h *Handler) prepareUpdateCheck(appResp *omahaSpec.AppResponse, pkg *api.Pa } func trace(v interface{}) { - if logger.IsDebug() { + if zerolog.GlobalLevel() == zerolog.DebugLevel { raw, err := xml.MarshalIndent(v, "", " ") if err != nil { - _ = logger.Error(err.Error()) + logger.Error().Err(err).Msg("") return } - logger.Debug("Omaha trace", "XML", string(raw)) + logger.Debug().Str("XML", string(raw)).Msg("Omaha trace") } } diff --git a/pkg/syncer/syncer.go b/pkg/syncer/syncer.go index 0d9469e14..ed4316ab9 100644 --- a/pkg/syncer/syncer.go +++ b/pkg/syncer/syncer.go @@ -18,9 +18,10 @@ import ( "strings" "time" + "github.com/rs/zerolog" + "github.com/coreos/go-omaha/omaha" "github.com/google/uuid" - log "github.com/mgutz/logxi/v1" "gopkg.in/guregu/null.v4" "github.com/kinvolk/nebraska/pkg/api" @@ -31,7 +32,10 @@ const ( ) var ( - logger = log.New("syncer") + logger = zerolog.New(zerolog.ConsoleWriter{Out: os.Stderr}).Hook( + zerolog.HookFunc(func(e *zerolog.Event, level zerolog.Level, message string) { + e.Str("context", "syncer") + })) // ErrInvalidAPIInstance error indicates that no valid api instance was // provided to the syncer constructor. @@ -105,7 +109,7 @@ func New(conf *Config) (*Syncer, error) { // Start makes the syncer start working. It will check for updates every // checkFrequency until it's asked to stop. func (s *Syncer) Start() { - logger.Debug("syncer ready!") + logger.Debug().Msg("syncer ready!") s.ticker = time.NewTicker(s.checkFrequency) _ = s.checkForUpdates() @@ -126,7 +130,7 @@ L: // Stop stops the polling for updates. func (s *Syncer) Stop() { s.ticker.Stop() - logger.Debug("stopping syncer..") + logger.Debug().Msg("stopping syncer..") s.stopCh <- struct{}{} } @@ -166,21 +170,21 @@ func (s *Syncer) initialize() error { // in Nebraska as needed. func (s *Syncer) checkForUpdates() error { for descriptor, currentVersion := range s.versions { - logger.Debug("checking for updates", "channel", descriptor.name, "arch", descriptor.arch.String(), "currentVersion", currentVersion) + logger.Debug().Str("channel", descriptor.name).Str("arch", descriptor.arch.String()).Str("currentVersion", currentVersion).Msg("checking for updates") update, err := s.doOmahaRequest(descriptor, currentVersion) if err != nil { return err } if update != nil && update.Status == "ok" { - logger.Debug("checkForUpdates, got an update", "channel", descriptor.name, "arch", descriptor.arch.String(), "currentVersion", currentVersion, "availableVersion", update.Manifest.Version) + logger.Debug().Str("channel", descriptor.name).Str("arch", descriptor.arch.String()).Str("currentVersion", currentVersion).Str("availableVersion", update.Manifest.Version).Send() if err := s.processUpdate(descriptor, update); err != nil { return err } s.versions[descriptor] = update.Manifest.Version s.bootIDs[descriptor] = "{" + uuid.New().String() + "}" } else { - logger.Debug("checkForUpdates, no update available", "channel", descriptor.name, "arch", descriptor.arch.String(), "currentVersion", currentVersion, "updateStatus", update.Status) + logger.Debug().Str("channel", descriptor.name).Str("arch", descriptor.arch.String()).Str("currentVersion", currentVersion).Msgf("checkForUpdates, no update available updateStatus %v", update.Status) } select { @@ -213,29 +217,29 @@ func (s *Syncer) doOmahaRequest(descriptor channelDescriptor, currentVersion str payload, err := xml.Marshal(req) if err != nil { - logger.Error("checkForUpdates, marshalling request xml", "error", err) + logger.Error().Err(err).Msg("checkForUpdates, marshalling request xml") return nil, err } - logger.Debug("doOmahaRequest", "request", string(payload)) + logger.Debug().Str("request", string(payload)).Msg("doOmahaRequest") resp, err := s.httpClient.Post(s.flatcarUpdatesURL, "text/xml", bytes.NewReader(payload)) if err != nil { - logger.Error("checkForUpdates, posting omaha response", "error", err) + logger.Error().Err(err).Msg("checkForUpdates, posting omaha response") return nil, err } defer resp.Body.Close() body, err := ioutil.ReadAll(resp.Body) if err != nil { - logger.Error("checkForUpdates, reading omaha response", "error", err) + logger.Error().Err(err).Msg("checkForUpdates, reading omaha response") return nil, err } - logger.Debug("doOmahaRequest", "response", string(body)) + logger.Debug().Str("response", string(body)).Msg("doOmahaRequest") oresp := &omaha.Response{} err = xml.Unmarshal(body, oresp) if err != nil { - logger.Error("checkForUpdates, unmarshalling omaha response", "error", err) + logger.Error().Err(err).Msg("checkForUpdates, unmarshalling omaha response") return nil, err } @@ -257,7 +261,7 @@ func (s *Syncer) processUpdate(descriptor channelDescriptor, update *omaha.Updat url = s.packagesURL filename = fmt.Sprintf("flatcar-%s-%s.gz", getArchString(descriptor.arch), update.Manifest.Version) if err := s.downloadPackage(update, filename); err != nil { - logger.Error("processUpdate, downloading package", "error", err, "channel", descriptor.name, "arch", descriptor.arch.String()) + logger.Error().Err(err).Str("channel", descriptor.name).Str("arch", descriptor.arch.String()).Msg("processUpdate, downloading package") return err } } @@ -273,7 +277,7 @@ func (s *Syncer) processUpdate(descriptor channelDescriptor, update *omaha.Updat Arch: descriptor.arch, } if _, err = s.api.AddPackage(pkg); err != nil { - logger.Error("processUpdate, adding package", "error", err, "channel", descriptor.name, "arch", descriptor.arch.String()) + logger.Error().Err(err).Str("channel", descriptor.name).Str("arch", descriptor.arch.String()).Msg("processUpdate, adding package") return err } @@ -290,7 +294,7 @@ func (s *Syncer) processUpdate(descriptor channelDescriptor, update *omaha.Updat PackageID: pkg.ID, } if _, err = s.api.AddFlatcarAction(flatcarAction); err != nil { - logger.Error("processUpdate, adding flatcar action", "error", err, "channel", descriptor.name, "arch", descriptor.arch.String()) + logger.Error().Err(err).Str("channel", descriptor.name).Str("arch", descriptor.arch.String()).Msgf("processUpdate, adding flatcar action") return err } } @@ -298,12 +302,12 @@ func (s *Syncer) processUpdate(descriptor channelDescriptor, update *omaha.Updat // Update channel to point to the package with the new version channel, err := s.api.GetChannel(s.channelsIDs[descriptor]) if err != nil { - logger.Error("processUpdate, getting channel to update", "error", err, "channel", descriptor.name, "arch", descriptor.arch.String()) + logger.Error().Err(err).Str("channel", descriptor.name).Str("arch", descriptor.arch.String()).Msg("processUpdate, getting channel to update") return err } channel.PackageID = null.StringFrom(pkg.ID) if err = s.api.UpdateChannel(channel); err != nil { - logger.Error("processUpdate, updating channel", "error", err, "channel", descriptor.name, "arch", descriptor.arch.String()) + logger.Error().Err(err).Str("channel", descriptor.name).Str("arch", descriptor.arch.String()).Msg("processUpdate, updating") return err } @@ -342,7 +346,7 @@ func (s *Syncer) downloadPackage(update *omaha.UpdateResponse, filename string) defer resp.Body.Close() hashSha256 := sha256.New() - logger.Debug("downloadPackage, downloading..", "url", pkgURL) + logger.Debug().Msgf("downloadPackage, downloading.. url %s", pkgURL) if _, err := io.Copy(io.MultiWriter(tmpFile, hashSha256), resp.Body); err != nil { return err } From 3f5f9d0ad59a0dc33ef0418bd4c7b7d1bea06f66 Mon Sep 17 00:00:00 2001 From: Ashu Ghildiyal Date: Thu, 18 Feb 2021 00:13:13 +0530 Subject: [PATCH 3/4] backend: Remove use of LOGXI env var as we don't use logxi now --- .golangci.yml | 2 +- Makefile | 2 +- docs/authorization.md | 4 ++-- tools/run-local-nebraska.sh | 1 - 4 files changed, 4 insertions(+), 5 deletions(-) diff --git a/.golangci.yml b/.golangci.yml index 4e9a9a8b8..599f016ba 100644 --- a/.golangci.yml +++ b/.golangci.yml @@ -11,7 +11,7 @@ linters: linters-settings: errcheck: - ignore: github.com/mgutz/logxi/v1:Error|Warn|Debug + ignore: github.com/rs/zerolog:Error|Warn|Debug gofmt: simplify: true diff --git a/Makefile b/Makefile index f80f2c35f..911932e80 100644 --- a/Makefile +++ b/Makefile @@ -63,7 +63,7 @@ frontend-lint: cd frontend && npm run lint run-backend: backend-binary - LOGXI=* ./bin/nebraska -auth-mode noop + ./bin/nebraska -auth-mode noop .PHONY: backend backend: run-generators backend-code-checks build-backend-binary diff --git a/docs/authorization.md b/docs/authorization.md index 4103fa261..9c0739627 100644 --- a/docs/authorization.md +++ b/docs/authorization.md @@ -35,7 +35,7 @@ the `postgres` container as follows: - Start the Nebraska backend: - - `LOGXI=* nebraska -auth-mode noop -http-static-dir $PWD/frontend/build + - `nebraska -auth-mode noop -http-static-dir $PWD/frontend/build -http-log` - In the browser, access `http://localhost:8000` @@ -103,7 +103,7 @@ the `postgres` container as follows: - Start the Nebraska backend: - - `LOGXI=* nebraska -auth-mode github -gh-client-id + - `nebraska -auth-mode github -gh-client-id -gh-client-secret -gh-ro-teams -gh-rw-teams -gh-webhook-secret -http-static-dir $PWD/frontend/build -http-log` diff --git a/tools/run-local-nebraska.sh b/tools/run-local-nebraska.sh index 9a662d35d..aebad816c 100755 --- a/tools/run-local-nebraska.sh +++ b/tools/run-local-nebraska.sh @@ -13,7 +13,6 @@ tools_dir="$(dirname "${0}")" binary="${tools_dir}/../bin/nebraska" static_dir="${tools_dir}/../frontend/build" -LOGXI=* \ "${binary}" \ -auth-mode noop \ -http-log \ From a4621e1bf917b73e0c8f7711c6faf5f0a245484a Mon Sep 17 00:00:00 2001 From: Ashu Ghildiyal Date: Wed, 24 Feb 2021 14:09:12 +0530 Subject: [PATCH 4/4] backend: Set default logging level to Info and set debug mode via flag --- cmd/nebraska/nebraska.go | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/cmd/nebraska/nebraska.go b/cmd/nebraska/nebraska.go index a654a9159..3c6eac6d9 100644 --- a/cmd/nebraska/nebraska.go +++ b/cmd/nebraska/nebraska.go @@ -66,6 +66,14 @@ func main() { } func mainWithError() error { + debug := flag.Bool("debug", false, "sets log level to debug") + + zerolog.SetGlobalLevel(zerolog.InfoLevel) + + if *debug { + zerolog.SetGlobalLevel(zerolog.DebugLevel) + } + flag.Parse() if err := checkArgs(); err != nil {