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

Remove extra output from uds run #916

Closed
UncleGedd opened this issue Sep 9, 2024 · 3 comments · Fixed by #925
Closed

Remove extra output from uds run #916

UncleGedd opened this issue Sep 9, 2024 · 3 comments · Fixed by #925
Milestone

Comments

@UncleGedd
Copy link
Collaborator

Describe what should be investigated or refactored

When running Maru tasks via uds run, remove the "Saving log file" notes

Screenshot 2024-09-09 at 1 58 38 PM

@UncleGedd UncleGedd added this to the v0.16.0 milestone Sep 9, 2024
@catsby
Copy link
Collaborator

catsby commented Sep 10, 2024

Unless I'm mistaken, maru-runner doesn't seem to allow silencing this NOTE: without completely disabling the logs entirely.

We can remove this NOTE: here by completely turning off logging for Zarf and Maru-runner in src/cmd/vendored.go:

diff --git a/src/cmd/vendored.go b/src/cmd/vendored.go
index 47cf4d5..eda265a 100644
--- a/src/cmd/vendored.go
+++ b/src/cmd/vendored.go
@@ -26,6 +26,11 @@ var runnerCmd = &cobra.Command{
 	Use:     "run",
 	Aliases: []string{"r"},
 	Short:   lang.CmdRunShort,
+	PersistentPreRunE: func(cmd *cobra.Command, _ []string) error {
+		// disable Zarf log file
+		config.SkipLogFile = true
+		return nil
+	},
 	RunE: func(_ *cobra.Command, _ []string) error {
 		os.Args = os.Args[1:] // grab 'run' and onward from the CLI args
 
@@ -57,6 +62,9 @@ var runnerCmd = &cobra.Command{
 		}
 
 		runnerCLI.RootCmd().SetArgs(os.Args)
+		// disable maru-runner log file
+		runnerCLI.RootCmd().PersistentFlags().Set("no-log-file", "true")
+
 		runnerCLI.Execute()
 
 		return nil

but that turns off logging for them both entirely, as opposed to just silencing the message. Is that what we want?

@UncleGedd
Copy link
Collaborator Author

#919 removes the extra Zarf output, still need to address the Maru output

@catsby
Copy link
Collaborator

catsby commented Sep 18, 2024

PR for this is here #925 but it depends on a Maru PR

Racer159 added a commit to defenseunicorns/maru-runner that referenced this issue Sep 19, 2024
## Short Description

This PR updates Maru's logging to match the standard library's
`log/slog` package, and appropriately filters log messages according to
levels. Tests included and feedback very welcome.

## Long Description

The current implementation of log level handling is misleading because
our [custom
handler](https://github.com/defenseunicorns/maru-runner/blob/535258256cd1714f55e643075ae15919316e4aec/src/message/slog.go#L20-L23)
doesn't filter by level. The code comment mentions logging functions
already being aware if they are allowed to be called, but in practice I
have not found that to be true. This is further complicated by Maru's
log levels not matching what `log/slog` uses both in values and in
ordering.

Example: slog uses these levels/ordering

```go
const (
	LevelDebug Level = -4
	LevelInfo  Level = 0
	LevelWarn  Level = 4
	LevelError Level = 8
)
```

(See here for source and long explaination to the numbers used:
https://pkg.go.dev/log/slog#Level)

Where as Maru uses these levels/ordering:
```go
const (
	// WarnLevel level. Non-critical entries that deserve eyes.
	WarnLevel LogLevel = iota
	// InfoLevel level. General operational entries about what's going on inside the
	// application.
	InfoLevel
	// DebugLevel level. Usually only enabled when debugging. Very verbose logging.
	DebugLevel
	// TraceLevel level. Designates finer-grained informational events than the Debug.
	TraceLevel
)
```

(source:
[src/message/logging.go#L16-L29](https://github.com/defenseunicorns/maru-runner/blob/535258256cd1714f55e643075ae15919316e4aec/src/message/logging.go#L16-L29))

In theory, implementing the [`Handler`
interface](https://cs.opensource.google/go/go/+/refs/tags/go1.23.1:src/log/slog/handler.go;l=29-33)
would have us ignore messages with a lower level than the one set. Maru
sets it's default log level to `InfoLevel` (from Maru's constants, not
slog's) which results in a value of `1`. However because our `InfoLevel`
is `1` and slog's `LevelInfo` is `0`, then in theory Maru's logger
should actually ignore it because it's a lower level. A call to
`message.SLog.Info()` ([ex. in
utils.go](https://github.com/defenseunicorns/maru-runner/blob/535258256cd1714f55e643075ae15919316e4aec/src/pkg/utils/utils.go#L35))
invokes slog's `Info()` method, which calls an internal [method
`log()`](https://cs.opensource.google/go/go/+/refs/tags/go1.23.1:src/log/slog/logger.go;l=208-211)
with slog's `LevelInfo` level which is a value of `0`. The [`log()`
method](https://cs.opensource.google/go/go/+/refs/tags/go1.23.1:src/log/slog/logger.go;l=238-258)
calls the handlers `Enabled()` method to see if it should log the
message, which for maru always returns `true`, and then passes it on to
the handlers `Handle()` method (Maru's `Handle()` method
[here](https://github.com/defenseunicorns/maru-runner/blob/535258256cd1714f55e643075ae15919316e4aec/src/message/slog.go#L37))
and we print the message, even though we shouldn't because it's a lower
value than our default.

The net effect is setting the log level with `--log-level` has no
effect, except for when setting to `trace`, in which case we output
pterm debugging information with lines for errors/traces and debug
calls. Otherwise Maru will always output all of the logs from `Debug()`,
`Info()`, `Warn()` or `Error()` regardless of the level set.

This PR updates Maru's log level constants both in values and ordering
to match the standard library `log/slog` package, and implements the
`Enabled()` method in the handler to filter correctly based on level.
The net effect of this PR should be benign in that we aren't changing
any usage details, but going forward we'll correctly output logs
according to the set level.

**NOTE:** This PR is based off of [my other PR (#140) for changing the
`Makefile`](#140)
with regards to `test-unit` and `test-e2e` tests.

## Test output:

```zsh
 ➜ go test ./src/message/... -v -count=1
=== RUN   Test_LogLevel_Diff
=== RUN   Test_LogLevel_Diff/DebugLevel
=== RUN   Test_LogLevel_Diff/InfoLevel
=== RUN   Test_LogLevel_Diff/InfoWarnLevel
=== RUN   Test_LogLevel_Diff/WarnInfoLevel
=== RUN   Test_LogLevel_Diff/InfoTraceLevel
=== RUN   Test_LogLevel_Diff/TraceInfoLevel
=== RUN   Test_LogLevel_Diff/TraceLevel
--- PASS: Test_LogLevel_Diff (0.00s)
    --- PASS: Test_LogLevel_Diff/DebugLevel (0.00s)
    --- PASS: Test_LogLevel_Diff/InfoLevel (0.00s)
    --- PASS: Test_LogLevel_Diff/InfoWarnLevel (0.00s)
    --- PASS: Test_LogLevel_Diff/WarnInfoLevel (0.00s)
    --- PASS: Test_LogLevel_Diff/InfoTraceLevel (0.00s)
    --- PASS: Test_LogLevel_Diff/TraceInfoLevel (0.00s)
    --- PASS: Test_LogLevel_Diff/TraceLevel (0.00s)
PASS
ok      github.com/defenseunicorns/maru-runner/src/message      0.235s
```

## Related

- defenseunicorns/uds-cli#916

## Type of change

- [x] Bug fix (non-breaking change which fixes an issue)
- [x] New feature (non-breaking change which adds functionality)
- [x] Other (security config, docs update, etc)

## Checklist before merging

- [x] Test, docs, adr added or updated as needed
- [x] [Contributor Guide
Steps](https://github.com/defenseunicorns/maru-runner/blob/main/CONTRIBUTING.md)
followed

---------

Signed-off-by: catsby <clint@ctshryock.com>
Co-authored-by: Wayne Starr <Racer159@users.noreply.github.com>
Co-authored-by: Eric Wyles <23637493+ericwyles@users.noreply.github.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants