Update/Replace go packages #333

ashu8912 · 2021-02-15T12:13:03Z

fixes #97

krnowak

Oh man, logger library change is painful. Thanks for handling it.

So I haven't gone through every single change here, as there are many. But one thing sticks out - our logging is a mess. Both old logxi and new zerolog are structured loggers, but logxi was rather weak at enforcing it, while zerolog is more stringent in this regard. So with logxi the usual way of passing parameter to logger was logger.Debug(message, key1, value1, key2, value2, …), and we seem to often abuse it in way like logger.Error("stuff failed", err), where err becomes key1. With zerolog, the way of logging looks more like logger.Error().Str(key1, value1).Str(key2, value2).Msg(message). Or logger.Error().Err(err).Msg("stuff failed"). The problem I see here is that in this PR we put all the key-value pairs into the message by turning logger.Debug("message", key1, value1, key2, value2, …) into logger.Debug().Msgf("message %s %s %s %s …", key1, value1, key2, value2, …). I'd prefer to keep the key-value and message separation.

So to summarize:

Please use Err for passing errors (which you mostly already do). Not sure if AnErr comes in handy anywhere.
Please use Str (or some other type-safe function from https://pkg.go.dev/github.com/rs/zerolog#Event) for key-value pairs.
Please come up with some guideline for messages (the Msg or Msgf part). My proposal would be that they are written like "operation - message", so for example "fetching manifest - something bad happened" or "login cb - invalid oauth state".
The loggers were named (logger = log.New("auth")), I suppose this can be useful to preserve (like with zerolog.New(zerolog.ConsoleWriter{…}).With().Str("context", "auth")).
Please fix some of the logging mess/abuse we have.

Some examples:

logger.Debug("auth metrics", "malformed authorization header", authHeader) could become logger.Debug().Str("header", authHeader").Msg("auth metrics - malformed authorization header")

logger.Error("login cb", "expected to have a valid desiredurl item in session data") could become logger.Error().Msg("login cb - expected to have a valid desiredurl item in session data")

logger.Error("addApp - cloning app", "error", err.Error(), "app", app, "sourceAppID", sourceAppID) could become logger.Error().Err(err).Str("app", app).Str("sourceAppID", sourceAppID).Msg("addApp - cloning app failed")

krnowak · 2021-02-15T13:12:07Z

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().Msgf("authenticate oauthstate %s", oauthState)


The way logxi worked was logger.Debug(message, key1, value1, key2, value2, …). So in order to have the same with zerolog, something like logger.Debug().Str(key1, value1).Str(key2, value2).Msg(message). So I think that in this case, it should be something like logger.Debug().Str("oauthstate", oauthstate).Msg("authenticate"). Note that the Msg must come last.

krnowak · 2021-02-15T13:29:03Z

cmd/nebraska/auth/auth.go


 	"github.com/kinvolk/nebraska/cmd/nebraska/ginhelpers"
 )

 var (
-	logger = log.New("auth")
+	logger = zerolog.New(zerolog.ConsoleWriter{Out: os.Stderr})


How about zerolog.New(zerolog.ConsoleWriter{…}).With().Str("context", "auth")?

krnowak · 2021-02-15T13:31:23Z

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().Msgf("invalid NEBRASKA_METRICS_UPDATE_INTERVAL value %s, it must be acceptable by time.ParseDuration and positive value", refreshIntervalEnvValue)


I'd make it logger.Warn().Str("value", refreshIntervalEnvValue).Msg("invalid …").

krnowak · 2021-02-15T13:32:07Z

cmd/nebraska/metrics.go

@@ -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().Msgf("registerAndInstrumentMetrics updating the metrics")


Missing Err(err). Also there's no formatting to do, so simple Msg should suffice.

krnowak · 2021-02-15T13:33:08Z

cmd/nebraska/nebraska.go

@@ -57,7 +57,7 @@ var (

 func main() {
 	if err := mainWithError(); err != nil {
-		logger.Error(err.Error())
+		logger.Error().Err(err).Msg("")


If you have something like an empty message, then maybe consider using Send() instead of Msg("").

krnowak · 2021-02-15T13:38:28Z

pkg/omaha/omaha.go

@@ -223,12 +226,12 @@ func (h *Handler) prepareUpdateCheck(appResp *omahaSpec.AppResponse, pkg *api.Pa
 }

 func trace(v interface{}) {
-	if logger.IsDebug() {
+	if gin.IsDebugging() {


Could zerolog.GlobalLevel() be used here instead? https://pkg.go.dev/github.com/rs/zerolog#GlobalLevel

krnowak · 2021-02-15T13:43:05Z

update_nebraska_db_ts.sh

@@ -0,0 +1,20 @@
+#!/bin/env bash


What is this script for?

This was probably mistakenly added.

joaquimrocha

As Krzesimir had noticed, there's a debug script that has been mistakenly added to the PR.
The choice of Zerolog means changing the logging calls in a lot of places. I am curious to know why it was used over Logrus (it's in no-new-features mode but seems to be actively maintained, and is compatible with the log Go API).

joaquimrocha · 2021-02-17T13:16:36Z

update_nebraska_db_ts.sh

@@ -0,0 +1,20 @@
+#!/bin/env bash


This was probably mistakenly added.

Semver/v4 is compatible with go modules and thus this patch replaces semver with semver/v4.

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.

krnowak

I think there is one more thing to do, which is to set the default logging level to "info", and then either add a debug flag or some environment variable to set the logging to the "debug" level.

ashu8912 requested review from krnowak and joaquimrocha February 15, 2021 12:13

krnowak requested changes Feb 15, 2021

View reviewed changes

joaquimrocha requested changes Feb 17, 2021

View reviewed changes

update_nebraska_db_ts.sh Outdated

@@ -0,0 +1,20 @@

#!/bin/env bash

Copy link

Collaborator

joaquimrocha Feb 17, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This was probably mistakenly added.

ashu8912 force-pushed the update-go-packages branch 2 times, most recently from 4dd4484 to 63161b9 Compare February 17, 2021 18:44

backend: Update semver package

84ed4c8

Semver/v4 is compatible with go modules and thus this patch replaces semver with semver/v4.

ashu8912 force-pushed the update-go-packages branch from 63161b9 to 9db8d55 Compare February 19, 2021 10:48

ashu8912 requested a review from krnowak February 19, 2021 10:48

ashu8912 added 2 commits February 22, 2021 20:15

backend: Replace logxi package with zerolog

e1f15f9

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.

backend: Remove use of LOGXI env var as we don't use logxi now

3f5f9d0

ashu8912 force-pushed the update-go-packages branch from 9db8d55 to 3f5f9d0 Compare February 22, 2021 14:49

ashu8912 requested a review from joaquimrocha February 22, 2021 14:49

krnowak reviewed Feb 23, 2021

View reviewed changes

backend: Set default logging level to Info and set debug mode via flag

a4621e1

ashu8912 requested a review from krnowak February 24, 2021 08:42

joaquimrocha approved these changes Feb 24, 2021

View reviewed changes

joaquimrocha merged commit ee6f943 into master Feb 24, 2021

joaquimrocha deleted the update-go-packages branch February 24, 2021 10:59

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Update/Replace go packages #333

Update/Replace go packages #333

ashu8912 commented Feb 15, 2021

krnowak left a comment

krnowak Feb 15, 2021

krnowak Feb 15, 2021

krnowak Feb 15, 2021

krnowak Feb 15, 2021

krnowak Feb 15, 2021

krnowak Feb 15, 2021

krnowak Feb 15, 2021

joaquimrocha Feb 17, 2021

joaquimrocha left a comment

joaquimrocha Feb 17, 2021

krnowak left a comment

Update/Replace go packages #333

Update/Replace go packages #333

Conversation

ashu8912 commented Feb 15, 2021

krnowak left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

joaquimrocha left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

krnowak left a comment

Choose a reason for hiding this comment