test(lint): refactor logs and add linting rules

.github/workflows/golangci-lint.yaml

@@ -45,3 +45,6 @@ jobs:
       - name: Run linter from make target
         run: |
           make check
+      - name: Run log linter
+        run: |
+          make check-logs

Makefile

@@ -311,6 +311,10 @@ $(GOLINTER):
 	curl -sSfL https://raw.githubusercontent.com/golangci/golangci-lint/master/install.sh | sh -s -- -b $(TOOLSDIR)/bin $(GOLINTER_VERSION)
 	$(GOLINTER) version
 
+.PHONY: check-logs
+check-logs: 
+	@./scripts/check_logs.sh
+
 .PHONY: check
 check: $(if $(findstring ui,$(BUILD_LABELS)), ui)
 check: ./golangcilint.yaml $(GOLINTER)

pkg/api/authn.go

@@ -86,7 +86,7 @@
 
 	groups, err := ctlr.MetaDB.GetUserGroups(request.Context())
 	if err != nil {
-		ctlr.Log.Err(err).Str("identity", identity).Msg("can not get user profile in DB")
+		ctlr.Log.Err(err).Str("identity", identity).Msg("failed to get user profile in DB")
 
 		return false, err
 	}
@@ -134,7 +134,7 @@
 
 			// we have already populated the request context with userAc
 			if err := ctlr.MetaDB.SetUserGroups(request.Context(), groups); err != nil {
-				ctlr.Log.Error().Err(err).Str("identity", identity).Msg("couldn't update user profile")
+				ctlr.Log.Error().Err(err).Str("identity", identity).Msg("failed to update user profile")
 
 				return false, err
 			}
@@ -172,7 +172,7 @@
 
 			// we have already populated the request context with userAc
 			if err := ctlr.MetaDB.SetUserGroups(request.Context(), groups); err != nil {
-				ctlr.Log.Error().Err(err).Str("identity", identity).Msg("couldn't update user profile")
+				ctlr.Log.Error().Err(err).Str("identity", identity).Msg("failed to update user profile")
 
 				return false, err
 			}
@@ -186,7 +186,7 @@
 		apiKey := passphrase
 
 		if !strings.HasPrefix(apiKey, constants.APIKeysPrefix) {
-			ctlr.Log.Error().Msg("api token has invalid format")
+			ctlr.Log.Error().Msg("invalid api token format")
 
 			return false, nil
 		}
@@ -198,12 +198,12 @@
 		storedIdentity, err := ctlr.MetaDB.GetUserAPIKeyInfo(hashedKey)
 		if err != nil {
 			if errors.Is(err, zerr.ErrUserAPIKeyNotFound) {
-				ctlr.Log.Info().Err(err).Msgf("can not find any user info for hashed key %s in DB", hashedKey)
+				ctlr.Log.Info().Err(err).Msgf("failed to find any user info for hashed key %s in DB", hashedKey)
 
 				return false, nil
 			}
 
-			ctlr.Log.Error().Err(err).Msgf("can not get user info for hashed key %s in DB", hashedKey)
+			ctlr.Log.Error().Err(err).Msgf("failed to get user info for hashed key %s in DB", hashedKey)
 
 			return false, err
 		}
@@ -215,7 +215,7 @@
 			// check if api key expired
 			isExpired, err := ctlr.MetaDB.IsAPIKeyExpired(request.Context(), hashedKey)
 			if err != nil {
-				ctlr.Log.Err(err).Str("identity", identity).Msg("can not verify if api key expired")
+				ctlr.Log.Err(err).Str("identity", identity).Msg("failed to verify if api key expired")
 
 				return false, err
 			}
@@ -226,14 +226,14 @@
 
 			err = ctlr.MetaDB.UpdateUserAPIKeyLastUsed(request.Context(), hashedKey)
 			if err != nil {
-				ctlr.Log.Err(err).Str("identity", identity).Msg("can not update user profile in DB")
+				ctlr.Log.Err(err).Str("identity", identity).Msg("failed to update user profile in DB")
 
 				return false, err
 			}
 
 			groups, err := ctlr.MetaDB.GetUserGroups(request.Context())
 			if err != nil {
-				ctlr.Log.Err(err).Str("identity", identity).Msg("can not get user's groups in DB")
+				ctlr.Log.Err(err).Str("identity", identity).Msg("failed to get user's groups in DB")
 
 				return false, err
 			}
@@ -376,7 +376,7 @@
 				authenticated, err := amw.sessionAuthn(ctlr, userAc, response, request)
 				if err != nil {
 					if errors.Is(err, zerr.ErrUserDataNotFound) {
-						ctlr.Log.Err(err).Msg("can not find user profile in DB")
+						ctlr.Log.Err(err).Msg("failed to find user profile in DB")
 
 						authFail(response, request, ctlr.Config.HTTP.Realm, delay)
 					}
@@ -419,7 +419,7 @@
 		EmptyDefaultNamespace: true,
 	})
 	if err != nil {
-		ctlr.Log.Panic().Err(err).Msg("error creating bearer authorizer")
+		ctlr.Log.Panic().Err(err).Msg("failed to create bearer authorizer")
 	}
 
 	return func(next http.Handler) http.Handler {
@@ -452,7 +452,7 @@
 
 			permissions, err := authorizer.Authorize(header, action, name)
 			if err != nil {
-				ctlr.Log.Error().Err(err).Msg("issue parsing Authorization header")
+				ctlr.Log.Error().Err(err).Msg("failed to parse Authorization header")
 				response.Header().Set("Content-Type", "application/json")
 				zcommon.WriteJSON(response, http.StatusInternalServerError, apiErr.NewError(apiErr.UNSUPPORTED))
 
@@ -523,7 +523,7 @@
 
 		client, ok := rh.c.RelyingParties[provider]
 		if !ok {
-			rh.c.Log.Error().Msg("unrecognized openid provider")
+			rh.c.Log.Error().Msg("failed to authenticate due to unrecognized openid provider")
 
 			w.WriteHeader(http.StatusBadRequest)
 
@@ -547,7 +547,7 @@
 		// let the session set its own id
 		err := session.Save(r, w)
 		if err != nil {
-			rh.c.Log.Error().Err(err).Msg("unable to save http session")
+			rh.c.Log.Error().Err(err).Msg("failed to save http session")
 
 			w.WriteHeader(http.StatusInternalServerError)
 
@@ -720,7 +720,7 @@
 
 	userEmails, _, err := client.Users.ListEmails(ctx, nil)
 	if err != nil {
-		log.Error().Msg("couldn't set user record for empty email value")
+		log.Error().Msg("failed to set user record for empty email value")
 
 		return "", []string{}, err
 	}
@@ -737,7 +737,7 @@
 
 	orgs, _, err := client.Organizations.List(ctx, "", nil)
 	if err != nil {
-		log.Error().Msg("couldn't set user record for empty email value")
+		log.Error().Msg("failed to set user record for empty email value")
 
 		return "", []string{}, err
 	}
@@ -764,7 +764,7 @@
 	// let the session set its own id
 	err := session.Save(request, response)
 	if err != nil {
-		log.Error().Err(err).Str("identity", identity).Msg("unable to save http session")
+		log.Error().Err(err).Str("identity", identity).Msg("failed to save http session")
 
 		return err
 	}
@@ -790,13 +790,15 @@
 
 	stateOrigin, ok := stateCookie.Values["state"].(string)
 	if !ok {
-		ctlr.Log.Error().Err(zerr.ErrInvalidStateCookie).Msg("openID: unable to get 'state' cookie from request")
+		ctlr.Log.Error().Err(zerr.ErrInvalidStateCookie).Str("component", "openID").
+			Msg(": failed to get 'state' cookie from request")
 
 		return "", zerr.ErrInvalidStateCookie
 	}
 
 	if stateOrigin != state {
-		ctlr.Log.Error().Err(zerr.ErrInvalidStateCookie).Msg("openID: 'state' cookie differs from the actual one")
+		ctlr.Log.Error().Err(zerr.ErrInvalidStateCookie).Str("component", "openID").
+			Msg(": 'state' cookie differs from the actual one")
 
 		return "", zerr.ErrInvalidStateCookie
 	}
@@ -813,7 +815,7 @@
 	}
 
 	if err := ctlr.MetaDB.SetUserGroups(r.Context(), groups); err != nil {
-		ctlr.Log.Error().Err(err).Str("identity", email).Msg("couldn't update the user profile")
+		ctlr.Log.Error().Err(err).Str("identity", email).Msg("failed to update the user profile")
 
 		return "", err
 	}
@@ -841,7 +843,7 @@
 ) (string, bool) {
 	session, err := cookieStore.Get(request, "session")
 	if err != nil {
-		log.Error().Err(err).Msg("can not decode existing session")
+		log.Error().Err(err).Msg("failed to decode existing session")
 		// expired cookie, no need to return err
 		return "", false
 	}
@@ -854,14 +856,14 @@
 
 	authenticated := session.Values["authStatus"]
 	if authenticated != true {
-		log.Error().Msg("can not get `user` session value")
+		log.Error().Msg("failed to get `user` session value")
 
 		return "", false
 	}
 
 	identity, ok := session.Values["user"].(string)
 	if !ok {
-		log.Error().Msg("can not get `user` session value")
+		log.Error().Msg("failed to get `user` session value")
 
 		return "", false
 	}
@@ -873,7 +875,7 @@
 ) (string, string, error) {
 	apiKeyBase, err := uuidGenerator.NewV4()
 	if err != nil {
-		log.Error().Err(err).Msg("unable to generate uuid for api key base")
+		log.Error().Err(err).Msg("failed to generate uuid for api key base")
 
 		return "", "", err
 	}
@@ -883,7 +885,7 @@
 	// will be used for identifying a specific api key
 	apiKeyID, err := uuidGenerator.NewV4()
 	if err != nil {
-		log.Error().Err(err).Msg("unable to generate uuid for api key id")
+		log.Error().Err(err).Msg("failed to generate uuid for api key id")
 
 		return "", "", err
 	}

pkg/api/authn_test.go

@@ -129,7 +129,7 @@ func TestAPIKeys(t *testing.T) {
 		conf.Extensions.UI.Enable = &defaultVal
 
 		ctlr := api.NewController(conf)
-		ctlr.Log.Info().Int64("seedUser", seedUser).Int64("seedPass", seedPass).Msg("random seed for username & password")
+		ctlr.Log.Info().Int64("seedUser", seedUser).Int64("seedPass", seedPass).Msg("Random seed for username & password")
 		dir := t.TempDir()
 
 		ctlr.Config.Storage.RootDirectory = dir

pkg/api/controller.go

@@ -438,7 +438,7 @@ func (c *Controller) StartBackgroundTasks(reloadCtx context.Context) {
 		//nolint: contextcheck
 		syncOnDemand, err := ext.EnableSyncExtension(c.Config, c.MetaDB, c.StoreController, c.taskScheduler, c.Log)
 		if err != nil {
-			c.Log.Error().Err(err).Msg("unable to start sync extension")
+			c.Log.Error().Err(err).Msg("failed to start sync extension")
 		}
 
 		c.SyncOnDemand = syncOnDemand

pkg/api/controller_test.go

@@ -8950,7 +8950,7 @@ func TestPeriodicGC(t *testing.T) {
 		So(err, ShouldBeNil)
 		So(string(data), ShouldContainSubstring,
 			"\"GC\":true,\"Commit\":false,\"GCDelay\":1000000000,\"GCInterval\":3600000000000")
-		So(string(data), ShouldContainSubstring, "failure walking storage root-dir") //nolint:lll
+		So(string(data), ShouldContainSubstring, "failed to walk storage root-dir") //nolint:lll
 	})
 }
 

pkg/api/ldap.go

@@ -49,7 +49,7 @@
 		if !lc.UseSSL {
 			l, err = ldap.Dial("tcp", address)
 			if err != nil {
-				lc.Log.Error().Err(err).Str("address", address).Msg("non-TLS connection failed")
+				lc.Log.Error().Err(err).Str("address", address).Msg("failed to establish a TCP connection")
 
 				return err
 			}
@@ -68,7 +68,7 @@
 				err = l.StartTLS(config)
 
 				if err != nil {
-					lc.Log.Error().Err(err).Str("address", address).Msg("TLS connection failed")
+					lc.Log.Error().Err(err).Str("address", address).Msg("failed to establish a TLS connection")
 
 					return err
 				}
@@ -85,7 +85,7 @@
 			}
 			l, err = ldap.DialTLS("tcp", address, config)
 			if err != nil {
-				lc.Log.Error().Err(err).Str("address", address).Msg("TLS connection failed")
+				lc.Log.Error().Err(err).Str("address", address).Msg("failed to establish a TLS connection")
 
 				return err
 			}
@@ -143,7 +143,7 @@
 		if lc.BindPassword != "" {
 			err := lc.Conn.Bind(lc.BindDN, lc.BindPassword)
 			if err != nil {
-				lc.Log.Error().Err(err).Str("bindDN", lc.BindDN).Msg("bind failed")
+				lc.Log.Error().Err(err).Str("bindDN", lc.BindDN).Msg("failed to bind")
 				// clean up the cached conn, so we can retry
 				lc.Conn.Close()
 				lc.Conn = nil
@@ -153,7 +153,7 @@
 		} else {
 			err := lc.Conn.UnauthenticatedBind(lc.BindDN)
 			if err != nil {
-				lc.Log.Error().Err(err).Str("bindDN", lc.BindDN).Msg("bind failed")
+				lc.Log.Error().Err(err).Str("bindDN", lc.BindDN).Msg("failed to bind")
 				// clean up the cached conn, so we can retry
 				lc.Conn.Close()
 				lc.Conn = nil
@@ -167,7 +167,7 @@
 
 	// exhausted all retries?
 	if !connected {
-		lc.Log.Error().Err(errors.ErrLDAPBadConn).Msg("exhausted all retries")
+		lc.Log.Error().Err(errors.ErrLDAPBadConn).Msg("failed to authenticate, exhausted all retries")
 
 		return false, nil, nil, errors.ErrLDAPBadConn
 	}
@@ -194,23 +194,23 @@
 	if err != nil {
 		fmt.Printf("%v\n", err)
 		lc.Log.Error().Err(err).Str("bindDN", lc.BindDN).Str("username", username).
-			Str("baseDN", lc.Base).Msg("search failed")
+			Str("baseDN", lc.Base).Msg("failed to perform a search request")
 
 		return false, nil, nil, err
 	}
 
 	if len(search.Entries) < 1 {
 		err := errors.ErrBadUser
 		lc.Log.Error().Err(err).Str("bindDN", lc.BindDN).Str("username", username).
-			Str("baseDN", lc.Base).Msg("entries not found")
+			Str("baseDN", lc.Base).Msg("failed to find entry")
 
 		return false, nil, nil, err
 	}
 
 	if len(search.Entries) > 1 {
 		err := errors.ErrEntriesExceeded
 		lc.Log.Error().Err(err).Str("bindDN", lc.BindDN).Str("username", username).
-			Str("baseDN", lc.Base).Msg("too many entries")
+			Str("baseDN", lc.Base).Msg("failed to retrieve due to an excessive amount of entries")
 
 		return false, nil, nil, err
 	}
@@ -227,7 +227,7 @@
 	// Bind as the user to verify their password
 	err = lc.Conn.Bind(userDN, password)
 	if err != nil {
-		lc.Log.Error().Err(err).Str("bindDN", userDN).Msg("user bind failed")
+		lc.Log.Error().Err(err).Str("bindDN", userDN).Msg("failed to bind user")
 
 		return false, user, userGroups, err
 	}