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.

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: logger initialization before flags parsing #7372

Conversation

DmitriyLewen
Copy link
Contributor

@DmitriyLewen DmitriyLewen commented Aug 22, 2024

Description

We need to init logger before flags parsing to avoid wrong log messages format.

before:

➜  trivy -d image alpine -c config.yaml --vuln-type os 
2024/08/22 14:09:16 WARN '--vuln-type' is deprecated. Use '--pkg-types' instead.
2024/08/22 14:09:16 INFO Loaded file_path=config.yaml
2024-08-22T14:09:16+06:00       DEBUG   Parsed severities       severities=[UNKNOWN LOW MEDIUM HIGH CRITICAL]
...

➜ trivy -q image alpine -c config.yaml --vuln-type os  
2024/08/22 16:22:17 WARN '--vuln-type' is deprecated. Use '--pkg-types' instead.
2024/08/22 16:22:17 INFO Loaded file_path=config.yaml

alpine (alpine 3.20.2)

Total: 0 (UNKNOWN: 0, LOW: 0, MEDIUM: 0, HIGH: 0, CRITICAL: 0)

after

➜  trivy -d image alpine -c config.yaml --vuln-type os
2024-08-22T14:08:58+06:00       WARN    '--vuln-type' is deprecated. Use '--pkg-types' instead.
2024-08-22T14:08:58+06:00       INFO    Loaded  file_path="config.yaml"
2024-08-22T14:08:58+06:00       DEBUG   Parsed severities       severities=[UNKNOWN LOW MEDIUM HIGH CRITICAL]
...

➜ trivy -q image alpine -c config.yaml --vuln-type os

alpine (alpine 3.20.2)

Total: 0 (UNKNOWN: 0, LOW: 0, MEDIUM: 0, HIGH: 0, CRITICAL: 0)

Related issues

Checklist

  • I've read the guidelines for contributing to this repository.
  • I've followed the conventions in the PR title.
  • I've added tests that prove my fix is effective or that my feature works.
  • I've updated the documentation with the relevant information (if needed).
  • I've added usage information (if the PR introduces new options)
  • I've included a "before" and "after" example to the description (if the PR is a user interface change).

@DmitriyLewen DmitriyLewen self-assigned this Aug 22, 2024
// Initialize the logger for `flag` and `app` packages.
// To display logs from these packages in Trivy format.
// We will set the `debug` and `disable` format after parsing the `--debug` and `--quiet` flags.
log.InitLogger(false, false)
Copy link
Contributor Author

@DmitriyLewen DmitriyLewen Aug 22, 2024

Choose a reason for hiding this comment

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

I simply added init logger before parsing flags.
But there is a problem logs from app and flags packages:
if the --quiet flag is used - we still show the logs or don't show debug logs:

➜  ./trivy -q image alpine -c config.yaml --vuln-type os
2024-08-22T16:17:11+06:00       WARN    '--vuln-type' is deprecated. Use '--pkg-types' instead.
2024-08-22T16:17:11+06:00       INFO    Loaded  file_path="config.yaml"

alpine (alpine 3.20.2)

As another way - I added DeferredLogger to save log messages and print them on command (in our case after logger initialization)
See 6ad1098

With this solution:

➜  ./trivy -q image alpine -c config.yaml --vuln-type os

alpine (alpine 3.20.2)

Total: 0 (UNKNOWN: 0, LOW: 0, MEDIUM: 0, HIGH: 0, CRITICAL: 0)

@knqyf263 Can you take a look, when you have time, please?

@DmitriyLewen DmitriyLewen changed the title fix(log): logger initialization before flags parsing log: logger initialization before flags parsing Aug 22, 2024
@DmitriyLewen DmitriyLewen changed the title log: logger initialization before flags parsing fix: logger initialization before flags parsing Aug 22, 2024
})
}

func (d *deferredLogger) PrintLogs() {
Copy link
Contributor Author

Choose a reason for hiding this comment

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

We can add this into:

trivy/pkg/log/logger.go

Lines 38 to 42 in 6ad1098

func InitLogger(debug, disable bool) {
level := lo.Ternary(debug, slog.LevelDebug, slog.LevelInfo)
out := lo.Ternary(disable, io.Discard, io.Writer(os.Stderr))
slog.SetDefault(New(NewHandler(out, &Options{Level: level})))
}

But perhaps it won't be entirely obvious

@DmitriyLewen DmitriyLewen marked this pull request as ready for review August 22, 2024 11:16
Copy link
Collaborator

@knqyf263 knqyf263 left a comment

Choose a reason for hiding this comment

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

I like the idea of DeferredLogger, but the current implementation allows us to miss log emissions before logger initialization. For example, although LoadAll() is called before parsing CLI flags, we forgot to replace it with log.DeferredLogger.

m.logger.WarnContext(ctx, "Plugin load error", log.Err(err))

Thus, I think we should replace the default logger or handler.

Also, we need to handle WithPrefix and WithAttrs, but the current implementation doesn't work with them.

logger: log.WithPrefix("plugin"),

To resolve these problems, I implemented DeferredHandler. PTAL, @DmitriyLewen.

@DmitriyLewen
Copy link
Contributor Author

Nice upgrade of my idea!
Looks good.

@knqyf263 knqyf263 added this pull request to the merge queue Sep 2, 2024
Merged via the queue into aquasecurity:main with commit c929290 Sep 2, 2024
12 checks passed
@aqua-bot aqua-bot mentioned this pull request Sep 2, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

bug(log): incorrect log format for flag messages
2 participants