Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix(log): refactor some logs #1899

Closed
wants to merge 1 commit into from
Closed

fix(log): refactor some logs #1899

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
10 changes: 10 additions & 0 deletions .github/workflows/golangci-lint.yaml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -44,3 +44,13 @@ jobs:
- name: Run linter from make target
run: |
make check
- name: Run log linter
run: |
set +e

# log messages should never start upper-cased
find . -name '*.go' | grep -v '_test.go' | xargs grep -n "Msg(\"[A-Z]" | grep -v -E "Msg\(\"HTTP|OpenID|OAuth|TLS"
if [ $? -eq 0 ]; then
exit 1
fi
exit 0
4 changes: 2 additions & 2 deletions errors/errors.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -89,8 +89,8 @@ var (
ErrImgStoreNotFound = errors.New("routes: image store not found corresponding to given route")
ErrEmptyValue = errors.New("cache: empty value")
ErrEmptyRepoList = errors.New("search: no repository found")
ErrCVESearchDisabled = errors.New("search: CVE search is disabled")
ErrCVEDBNotFound = errors.New("cve: CVE DB is not present")
ErrCVESearchDisabled = errors.New("search: cve search is disabled")
ErrCVEDBNotFound = errors.New("cve: cve-db is not present")
ErrInvalidRepositoryName = errors.New("repository: not a valid repository name")
ErrSyncMissingCatalog = errors.New("sync: couldn't fetch upstream registry's catalog")
ErrMethodNotSupported = errors.New("storage: method not supported")
Expand Down
2 changes: 1 addition & 1 deletion pkg/api/authn.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -449,7 +449,7 @@ func bearerAuthHandler(ctlr *Controller) mux.MiddlewareFunc {
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 {
Expand Down
28 changes: 12 additions & 16 deletions pkg/api/routes.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -547,7 +547,7 @@ func getReferrers(ctx context.Context, routeHandler *RouteHandler,
if errSync := routeHandler.c.SyncOnDemand.SyncReference(ctx, name, digest.String(),
syncConstants.OCI); errSync != nil {
routeHandler.c.Log.Err(errSync).Str("repository", name).Str("reference", digest.String()).
Msg("error encounter while syncing OCI reference for image")
Msg("failed to sync OCI reference for image")
}

refs, err = imgStore.GetReferrers(name, digest, artifactTypes)
Expand Down Expand Up @@ -605,7 +605,7 @@ func (rh *RouteHandler) GetReferrers(response http.ResponseWriter, request *http
rh.c.Log.Error().Err(err).Str("name", name).Str("digest", digest.String()).Msg("manifest not found")
response.WriteHeader(http.StatusNotFound)
} else {
rh.c.Log.Error().Err(err).Str("name", name).Str("digest", digest.String()).Msg("unable to get references")
rh.c.Log.Error().Err(err).Str("name", name).Str("digest", digest.String()).Msg("failed to get references")
response.WriteHeader(http.StatusInternalServerError)
}

Expand All @@ -614,7 +614,7 @@ func (rh *RouteHandler) GetReferrers(response http.ResponseWriter, request *http

out, err := json.Marshal(referrers)
if err != nil {
rh.c.Log.Error().Err(err).Str("name", name).Str("digest", digest.String()).Msg("unable to marshal json")
rh.c.Log.Error().Err(err).Str("name", name).Str("digest", digest.String()).Msg("failed to marshal json")
response.WriteHeader(http.StatusInternalServerError)

return
Expand Down Expand Up @@ -1221,8 +1221,6 @@ func (rh *RouteHandler) CreateBlobUpload(response http.ResponseWriter, request *
return
}

rh.c.Log.Info().Int64("r.ContentLength", request.ContentLength).Msg("DEBUG")

digestStr := digests[0]

digest := godigest.Digest(digestStr)
Expand Down Expand Up @@ -1494,8 +1492,6 @@ func (rh *RouteHandler) UpdateBlobUpload(response http.ResponseWriter, request *
return
}

rh.c.Log.Info().Int64("r.ContentLength", request.ContentLength).Msg("DEBUG")

contentPresent := true

contentLen, err := strconv.ParseInt(request.Header.Get("Content-Length"), 10, 64)
Expand Down Expand Up @@ -1918,7 +1914,7 @@ func getImageManifest(ctx context.Context, routeHandler *RouteHandler, imgStore

if errSync := routeHandler.c.SyncOnDemand.SyncImage(ctx, name, reference); errSync != nil {
routeHandler.c.Log.Err(errSync).Str("repository", name).Str("reference", reference).
Msg("error encounter while syncing image")
Msg("failed to sync image")
}
}

Expand All @@ -1939,7 +1935,7 @@ func getOrasReferrers(ctx context.Context, routeHandler *RouteHandler,
if errSync := routeHandler.c.SyncOnDemand.SyncReference(ctx, name, digest.String(),
syncConstants.Oras); errSync != nil {
routeHandler.c.Log.Error().Err(err).Str("name", name).Str("digest", digest.String()).
Msg("unable to get references")
Msg("failed to get references")
}

refs, err = imgStore.GetOrasReferrers(name, digest, artifactType)
Expand Down Expand Up @@ -2009,7 +2005,7 @@ func (rh *RouteHandler) GetOrasReferrers(response http.ResponseWriter, request *
rh.c.Log.Error().Err(err).Str("name", name).Str("digest", digest.String()).Msg("manifest not found")
response.WriteHeader(http.StatusNotFound)
} else {
rh.c.Log.Error().Err(err).Str("name", name).Str("digest", digest.String()).Msg("unable to get references")
rh.c.Log.Error().Err(err).Str("name", name).Str("digest", digest.String()).Msg("failed to get references")
response.WriteHeader(http.StatusInternalServerError)
}

Expand Down Expand Up @@ -2039,7 +2035,7 @@ type APIKeyPayload struct { //nolint:revive
func (rh *RouteHandler) GetAPIKeys(resp http.ResponseWriter, req *http.Request) {
apiKeys, err := rh.c.MetaDB.GetUserAPIKeys(req.Context())
if err != nil {
rh.c.Log.Error().Err(err).Msg("error getting list of API keys for user")
rh.c.Log.Error().Err(err).Msg("failed to get list of api keys for user")
resp.WriteHeader(http.StatusInternalServerError)

return
Expand All @@ -2055,7 +2051,7 @@ func (rh *RouteHandler) GetAPIKeys(resp http.ResponseWriter, req *http.Request)

data, err := json.Marshal(apiKeyResponse)
if err != nil {
rh.c.Log.Error().Err(err).Msg("unable to marshal api key response")
rh.c.Log.Error().Err(err).Msg("failed to marshal api key response")

resp.WriteHeader(http.StatusInternalServerError)

Expand Down Expand Up @@ -2083,7 +2079,7 @@ func (rh *RouteHandler) CreateAPIKey(resp http.ResponseWriter, req *http.Request

body, err := io.ReadAll(req.Body)
if err != nil {
rh.c.Log.Error().Msg("unable to read request body")
rh.c.Log.Error().Msg("failed to read request body")
resp.WriteHeader(http.StatusInternalServerError)

return
Expand Down Expand Up @@ -2138,7 +2134,7 @@ func (rh *RouteHandler) CreateAPIKey(resp http.ResponseWriter, req *http.Request

err = rh.c.MetaDB.AddUserAPIKey(req.Context(), hashedAPIKey, apiKeyDetails)
if err != nil {
rh.c.Log.Error().Err(err).Msg("error storing API key")
rh.c.Log.Error().Err(err).Msg("failed to store api key")
resp.WriteHeader(http.StatusInternalServerError)

return
Expand All @@ -2156,7 +2152,7 @@ func (rh *RouteHandler) CreateAPIKey(resp http.ResponseWriter, req *http.Request

data, err := json.Marshal(apiKeyResponse)
if err != nil {
rh.c.Log.Error().Err(err).Msg("unable to marshal api key response")
rh.c.Log.Error().Err(err).Msg("failed to marshal api key response")

resp.WriteHeader(http.StatusInternalServerError)

Expand Down Expand Up @@ -2191,7 +2187,7 @@ func (rh *RouteHandler) RevokeAPIKey(resp http.ResponseWriter, req *http.Request

err := rh.c.MetaDB.DeleteUserAPIKey(req.Context(), keyID)
if err != nil {
rh.c.Log.Error().Err(err).Str("keyID", keyID).Msg("error deleting API key")
rh.c.Log.Error().Err(err).Str("keyID", keyID).Msg("failed to delete api key")
resp.WriteHeader(http.StatusInternalServerError)

return
Expand Down
4 changes: 3 additions & 1 deletion pkg/api/session.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -121,7 +121,8 @@ func SessionLogger(ctlr *Controller) mux.MiddlewareFunc {
monitoring.ObserveHTTPMethodLatency(ctlr.Metrics, method, latency) // histogram
}

log.Str("clientIP", clientIP).
log.Str("component", "session").
Str("clientIP", clientIP).
Str("method", method).
Str("path", path).
Int("statusCode", statusCode).
Expand Down Expand Up @@ -172,6 +173,7 @@ func SessionAuditLogger(audit *log.Logger) mux.MiddlewareFunc {
method == http.MethodPatch || method == http.MethodDelete) &&
(statusCode == http.StatusOK || statusCode == http.StatusCreated || statusCode == http.StatusAccepted) {
audit.Info().
Str("component", "session").
Str("clientIP", clientIP).
Str("subject", username).
Str("action", method).
Expand Down
2 changes: 1 addition & 1 deletion pkg/cli/server/config_reloader.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -112,7 +112,7 @@ func (hr *HotReloader) Start() context.Context {
}()

if err := hr.watcher.Add(hr.filePath); err != nil {
log.Error().Err(err).Str("config", hr.filePath).Msg("error adding config file to FsNotify watcher")
log.Error().Err(err).Str("config", hr.filePath).Msg("failed to add config file to fsnotity watcher")
panic(err)
}

Expand Down
2 changes: 1 addition & 1 deletion pkg/cli/server/config_reloader_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -393,7 +393,7 @@ func TestConfigReloader(t *testing.T) {
time.Sleep(5 * time.Second)

found, err := test.ReadLogFileAndSearchString(logFile.Name(),
"Error downloading Trivy DB to destination dir", 30*time.Second)
"failed to download trivy-db to destination dir", 30*time.Second)
So(err, ShouldBeNil)
So(found, ShouldBeTrue)

Expand Down
12 changes: 6 additions & 6 deletions pkg/cli/server/extensions_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -785,7 +785,7 @@ func TestServeScrubExtension(t *testing.T) {
So(dataStr, ShouldContainSubstring,
"\"Extensions\":{\"Search\":null,\"Sync\":null,\"Metrics\":null,\"Scrub\":{\"Enable\":true,\"Interval\":86400000000000},\"Lint\":null") //nolint:lll // gofumpt conflicts with lll
So(dataStr, ShouldNotContainSubstring,
"Scrub interval set to too-short interval < 2h, changing scrub duration to 2 hours and continuing.")
"scrub interval set to too-short interval < 2h, changing scrub duration to 2 hours and continuing.")
})

Convey("scrub implicitly enabled, but with scrub interval param set", t, func(c C) {
Expand Down Expand Up @@ -817,7 +817,7 @@ func TestServeScrubExtension(t *testing.T) {
dataStr := string(data)
So(dataStr, ShouldContainSubstring, "\"Scrub\":{\"Enable\":true,\"Interval\":3600000000000}")
So(dataStr, ShouldContainSubstring,
"Scrub interval set to too-short interval < 2h, changing scrub duration to 2 hours and continuing.")
"scrub interval set to too-short interval < 2h, changing scrub duration to 2 hours and continuing.")
})

Convey("scrub explicitly enabled, but without scrub interval param set", t, func(c C) {
Expand Down Expand Up @@ -849,7 +849,7 @@ func TestServeScrubExtension(t *testing.T) {
So(dataStr, ShouldContainSubstring,
"\"Extensions\":{\"Search\":null,\"Sync\":null,\"Metrics\":null,\"Scrub\":{\"Enable\":true,\"Interval\":86400000000000},\"Lint\":null") //nolint:lll // gofumpt conflicts with lll
So(dataStr, ShouldNotContainSubstring,
"Scrub interval set to too-short interval < 2h, changing scrub duration to 2 hours and continuing.")
"scrub interval set to too-short interval < 2h, changing scrub duration to 2 hours and continuing.")
})

Convey("scrub explicitly disabled", t, func(c C) {
Expand Down Expand Up @@ -879,9 +879,9 @@ func TestServeScrubExtension(t *testing.T) {
defer os.Remove(logPath) // clean up
dataStr := string(data)
So(dataStr, ShouldContainSubstring, "\"Scrub\":{\"Enable\":false,\"Interval\":86400000000000}")
So(dataStr, ShouldContainSubstring, "Scrub config not provided, skipping scrub")
So(dataStr, ShouldContainSubstring, "scrub config not provided, skipping scrub")
So(dataStr, ShouldNotContainSubstring,
"Scrub interval set to too-short interval < 2h, changing scrub duration to 2 hours and continuing.")
"scrub interval set to too-short interval < 2h, changing scrub duration to 2 hours and continuing.")
})
}

Expand Down Expand Up @@ -1046,7 +1046,7 @@ func TestServeSearchEnabledCVE(t *testing.T) {
So(found, ShouldBeTrue)
So(err, ShouldBeNil)

found, err = ReadLogFileAndSearchString(logPath, "updating the CVE database", readLogFileTimeout)
found, err = ReadLogFileAndSearchString(logPath, "updating cve-db", readLogFileTimeout)
So(found, ShouldBeTrue)
So(err, ShouldBeNil)
})
Expand Down
40 changes: 20 additions & 20 deletions pkg/cli/server/root.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -71,7 +71,7 @@ func newServeCmd(conf *config.Config) *cobra.Command {
}

if err := ctlr.Run(reloaderCtx); err != nil {
ctlr.Log.Fatal().Err(err).Msg("unable to start controller, exiting")
ctlr.Log.Fatal().Err(err).Msg("failed to start controller, exiting")
}
},
}
Expand Down Expand Up @@ -105,15 +105,15 @@ func newScrubCmd(conf *config.Config) *cobra.Command {
fmt.Sprintf("http://%s/v2", net.JoinHostPort(conf.HTTP.Address, conf.HTTP.Port)),
nil)
if err != nil {
log.Error().Err(err).Msg("unable to create a new http request")
log.Error().Err(err).Msg("failed to create a new http request")
panic(err)
}

response, err := http.DefaultClient.Do(req)
if err == nil {
response.Body.Close()
log.Warn().Msg("The server is running, in order to perform the scrub command the server should be shut down")
panic("Error: server is running")
log.Warn().Msg("server is running, in order to perform the scrub command the server should be shut down")
panic("server is running")
} else {
// server is down
ctlr := api.NewController(conf)
Expand Down Expand Up @@ -146,11 +146,11 @@ func newVerifyCmd(conf *config.Config) *cobra.Command {
Run: func(cmd *cobra.Command, args []string) {
if len(args) > 0 {
if err := LoadConfiguration(conf, args[0]); err != nil {
log.Error().Str("config", args[0]).Msg("Config file is invalid")
log.Error().Str("config", args[0]).Msg("config file is invalid")
panic(err)
}

log.Info().Str("config", args[0]).Msg("Config file is valid")
log.Info().Str("config", args[0]).Msg("config file is valid")
}
},
}
Expand Down Expand Up @@ -291,19 +291,19 @@ func validateCacheConfig(cfg *config.Config, log zlog.Logger) error {

func validateExtensionsConfig(cfg *config.Config, log zlog.Logger) error {
if cfg.Extensions != nil && cfg.Extensions.Mgmt != nil {
log.Warn().Msg("The mgmt extensions configuration option has been made redundant and will be ignored.")
log.Warn().Msg("mgmt extensions configuration option has been made redundant and will be ignored.")
}

if cfg.Extensions != nil && cfg.Extensions.APIKey != nil {
log.Warn().Msg("The apikey extension configuration will be ignored as API keys " +
log.Warn().Msg("apikey extension configuration will be ignored as API keys " +
"are now configurable in the HTTP settings.")
}

if cfg.Extensions != nil && cfg.Extensions.UI != nil && cfg.Extensions.UI.Enable != nil && *cfg.Extensions.UI.Enable {
// it would make sense to also check for mgmt and user prefs to be enabled,
// but those are both enabled by having the search and ui extensions enabled
if cfg.Extensions.Search == nil || !*cfg.Extensions.Search.Enable {
log.Error().Err(zerr.ErrBadConfig).Msg("UI functionality can't be used without search extension.")
log.Error().Err(zerr.ErrBadConfig).Msg("ui functionality can't be used without search extension.")

return zerr.ErrBadConfig
}
Expand All @@ -312,7 +312,7 @@ func validateExtensionsConfig(cfg *config.Config, log zlog.Logger) error {
//nolint:lll
if cfg.Storage.StorageDriver != nil && cfg.Extensions != nil && cfg.Extensions.Search != nil &&
cfg.Extensions.Search.Enable != nil && *cfg.Extensions.Search.Enable && cfg.Extensions.Search.CVE != nil {
log.Error().Err(zerr.ErrBadConfig).Msg("CVE functionality can't be used with remote storage. Please disable CVE")
log.Error().Err(zerr.ErrBadConfig).Msg("cve functionality can't be used with remote storage - please disable cve")

return zerr.ErrBadConfig
}
Expand All @@ -321,7 +321,7 @@ func validateExtensionsConfig(cfg *config.Config, log zlog.Logger) error {
//nolint:lll
if subPath.StorageDriver != nil && cfg.Extensions != nil && cfg.Extensions.Search != nil &&
cfg.Extensions.Search.Enable != nil && *cfg.Extensions.Search.Enable && cfg.Extensions.Search.CVE != nil {
log.Error().Err(zerr.ErrBadConfig).Msg("CVE functionality can't be used with remote storage. Please disable CVE")
log.Error().Err(zerr.ErrBadConfig).Msg("cve functionality can't be used with remote storage - please disable cve")

return zerr.ErrBadConfig
}
Expand Down Expand Up @@ -534,7 +534,7 @@ func applyDefaultValues(config *config.Config, viperInstance *viper.Viper, log z
if config.Extensions.Search.CVE.UpdateInterval < defaultUpdateInterval {
config.Extensions.Search.CVE.UpdateInterval = defaultUpdateInterval

log.Warn().Msg("CVE update interval set to too-short interval < 2h, " +
log.Warn().Msg("cve update interval set to too-short interval < 2h, " +
"changing update duration to 2 hours and continuing.")
}

Expand All @@ -544,15 +544,15 @@ func applyDefaultValues(config *config.Config, viperInstance *viper.Viper, log z

if config.Extensions.Search.CVE.Trivy.DBRepository == "" {
defaultDBDownloadURL := "ghcr.io/aquasecurity/trivy-db"
log.Info().Str("trivyDownloadURL", defaultDBDownloadURL).
Msg("Config: using default Trivy DB download URL.")
log.Info().Str("url", defaultDBDownloadURL).
Msg("config: using default trivy-db download URL.")
config.Extensions.Search.CVE.Trivy.DBRepository = defaultDBDownloadURL
}

if config.Extensions.Search.CVE.Trivy.JavaDBRepository == "" {
defaultJavaDBDownloadURL := "ghcr.io/aquasecurity/trivy-java-db"
log.Info().Str("trivyJavaDownloadURL", defaultJavaDBDownloadURL).
Msg("Config: using default Trivy Java DB download URL.")
log.Info().Str("url", defaultJavaDBDownloadURL).
Msg("config: using default trivy-java-db download URL.")
config.Extensions.Search.CVE.Trivy.JavaDBRepository = defaultJavaDBDownloadURL
}
}
Expand Down Expand Up @@ -621,7 +621,7 @@ func applyDefaultValues(config *config.Config, viperInstance *viper.Viper, log z
cachePath := path.Join(cacheDir, storageConstants.BoltdbName+storageConstants.DBExtensionName)

if _, err := os.Stat(cachePath); err == nil {
log.Info().Msg("Config: dedupe set to false for s3 driver but used to be true.")
log.Info().Msg("config: dedupe set to false for s3 driver but used to be true.")
log.Info().Str("cache path", cachePath).Msg("found cache database")

config.Storage.RemoteCache = false
Expand All @@ -642,7 +642,7 @@ func applyDefaultValues(config *config.Config, viperInstance *viper.Viper, log z
subpathCachePath := path.Join(subpathCacheDir, storageConstants.BoltdbName+storageConstants.DBExtensionName)

if _, err := os.Stat(subpathCachePath); err == nil {
log.Info().Msg("Config: dedupe set to false for s3 driver but used to be true. ")
log.Info().Msg("config: dedupe set to false for s3 driver but used to be true. ")
log.Info().Str("cache path", subpathCachePath).Msg("found cache database")

storageConfig.RemoteCache = false
Expand Down Expand Up @@ -701,14 +701,14 @@ func LoadConfiguration(config *config.Config, configPath string) error {
viperInstance.SetConfigFile(configPath)

if err := viperInstance.ReadInConfig(); err != nil {
log.Error().Err(err).Msg("error while reading configuration")
log.Error().Err(err).Msg("failed to read configuration")

return err
}

metaData := &mapstructure.Metadata{}
if err := viperInstance.Unmarshal(&config, metadataConfig(metaData)); err != nil {
log.Error().Err(err).Msg("error while unmarshaling new config")
log.Error().Err(err).Msg("failed to unmarshaling new config")

return err
}
Expand Down
Loading
Loading