Less verbose logging in Golang Cataloger #904

jonasagx · 2022-03-21T04:09:55Z

Before

After

Signed-off-by: Jonas Galvão Xavier jonas.agx@gmail.com

Signed-off-by: Jonas Galvão Xavier <jonas.agx@gmail.com>

luhring

Hey @jonasagx — thanks for the attention to the log noisiness. I'm not sure about this particular change, and I've added a comment. Curious for your thoughts!

luhring · 2022-03-21T12:04:26Z

syft/pkg/cataloger/golang/scan_bin.go

@@ -33,7 +33,7 @@ func scanFile(reader unionReader, filename string) ([]*debug.BuildInfo, []string
 	for _, r := range readers {
 		bi, err := buildinfo.Read(r)
 		if err != nil {
-			log.Warnf("golang cataloger: scanning file %s: %v", filename, err)
+			log.Debugf("golang cataloger: scanning file %s: %v", filename, err)


So my opinion is that this should be a WARN log entry. If Syft knows for sure that it missed an opportunity to scan and surface a piece of the software, that's noteworthy (the same idea that's culminated in #518). For example, it might be that the scanned Go binaries has no known vulnerabilities... except in the section that Syft missed. It's important to have a way to signal to the user the difference between "Everything is fine ✅ " and "Everything that we scanned is fine, but we weren't able to scan everything. ⚠️ "

If Syft knows for sure that it missed an opportunity to scan and surface a piece of the software, that's noteworthy (the same idea that's culminated in #518). For example, it might be that the scanned Go binaries has no known vulnerabilities... except in the section that Syft missed. It's important to have a way to signal to the user the difference between "Everything is fine ✅ " and "Everything that we scanned is fine, but we weren't able to scan everything. ⚠️ "

100% agree.

However, in this case this is a little bit grey. The golang cataloger selects candidate files based on MIME type (get all executables). There is no distinction of the binary being analyzed being a go-compiled binary (we don't know if it should be). Defaulting to warning here seems wrong since it seems to imply that we were expecting that all inputs are go-compiled binaries (which is not true).

That being said, I also agree that we don't want to not report up skipping a file that was intended to be analyzed by the golang cataloger but was not. We should show warnings for these cases.

Given the above context, we should probably default to having this being a debug (though it does really seem like it should be warning at a first glance).

Maybe we could check the error? If it is a "not a go executable" error, ignore it (no log) but any other error we show as a warning?

However, in this case this is a little bit grey. The golang cataloger selects candidate files based on MIME type (get all executables). There is no distinction of the binary being analyzed being a go-compiled binary (we don't know if it should be). Defaulting to warning here seems wrong since it seems to imply that we were expecting that all inputs are go-compiled binaries (which is not true).

That being said, I also agree that we don't want to not report up skipping a file that was intended to be analyzed by the golang cataloger but was not. We should show warnings for these cases.

This part resonates! I hesitate to default to debug regardless — but I do like the idea of distinguishing between two scenarios here. Your last suggestion makes a lot of sense to me! 🙌

I like the idea of debug not a go executable and warn on any other error. My design north here is: how would things look like once we add more binary catalogers? In this future scenario log messages of the type not a X executable are more noise than information, but we are not there yet.

Signed-off-by: Jonas Galvão Xavier <jonas.agx@gmail.com>

wagoodman · 2022-03-21T18:36:49Z

syft/pkg/cataloger/golang/parse_go_bin.go

+
+	// errNotGoExe is returned when a given executable file is valid but does
+	// not contain Go build information.
+	errNotGoExe = errors.New("not a Go executable")


I don't think this will work since this is a different error instance than the actual error being raised. Does the stdlib expose this error to use directly?

I pushed a change 22bd9fc that makes the behavior consistent with #904 (comment) (warn only when there is an error and it is not from a "not go executable" error... so removed the debug case).

Since the stdlib does not export this error variable we cannot use it with errors.Is or errors.As (any error will match). The check I put in is brittle, but functional.

kzantow · 2022-03-21T19:16:51Z

Based on an earlier discussion, it sounds like this might be better suited as data exported by Syft instead of any sort of log warnings at all?

luhring · 2022-03-21T19:31:43Z

Based on an earlier discussion, it sounds like this might be better suited as data exported by Syft instead of any sort of log warnings at all?

My thinking is that one solution doesn't negate the value of the other. For now, logged warnings are a nice short-term achievement, consistent with much of the other cataloging code.

syft/pkg/cataloger/golang/scan_bin.go

Signed-off-by: Alex Goodman <alex.goodman@anchore.com>

kzantow

👍

luhring · 2022-03-22T14:55:04Z

syft/pkg/cataloger/golang/scan_bin.go

+				// binary, we should not show warnings/logs in this case.
+				return nil, nil
+			}
+			// in this case we could not read the or parse the file, but not explicitly because it is not a


but not explicitly because it is not a go-compiled binary (though it still might be)

nit: this phrasing is just a little difficult to parse, I think because of having "but not ... not ... though ...". If we can think of a more direct way to say this, I think that'd help (still thinking 🤔 )

Maybe something like "We don't know if this is a Go binary, but we weren't able to read it, so we should alert the user."?

(I'm still making sure I understand the intent of this comment, so let me know if I'm off-base!)

* Less verbose logging in Golang Cataloger Signed-off-by: Jonas Galvão Xavier <jonas.agx@gmail.com> * debug for known gray errors Signed-off-by: Jonas Galvão Xavier <jonas.agx@gmail.com> * only show warnings when a binary is not a go executable Signed-off-by: Alex Goodman <alex.goodman@anchore.com> Co-authored-by: Alex Goodman <alex.goodman@anchore.com>

Less verbose logging in Golang Cataloger

482a8cd

Signed-off-by: Jonas Galvão Xavier <jonas.agx@gmail.com>

jonasagx self-assigned this Mar 21, 2022

jonasagx requested a review from a team March 21, 2022 05:17

luhring reviewed Mar 21, 2022

View reviewed changes

debug for known gray errors

df3feff

Signed-off-by: Jonas Galvão Xavier <jonas.agx@gmail.com>

wagoodman reviewed Mar 21, 2022

View reviewed changes

kzantow reviewed Mar 22, 2022

View reviewed changes

syft/pkg/cataloger/golang/scan_bin.go Outdated Show resolved Hide resolved

only show warnings when a binary is not a go executable

22bd9fc

Signed-off-by: Alex Goodman <alex.goodman@anchore.com>

wagoodman force-pushed the less-verbose-golang-cataloger branch from 9d26515 to 22bd9fc Compare March 22, 2022 14:19

kzantow approved these changes Mar 22, 2022

View reviewed changes

luhring approved these changes Mar 22, 2022

View reviewed changes

spiffcs approved these changes Mar 22, 2022

View reviewed changes

wagoodman approved these changes Mar 22, 2022

View reviewed changes

jonasagx merged commit c0b547b into anchore:main Mar 22, 2022

jonasagx deleted the less-verbose-golang-cataloger branch March 22, 2022 17:19

wagoodman added the bug Something isn't working label Mar 23, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Less verbose logging in Golang Cataloger #904

Less verbose logging in Golang Cataloger #904

jonasagx commented Mar 21, 2022 •

edited

luhring left a comment

luhring Mar 21, 2022

wagoodman Mar 21, 2022

wagoodman Mar 21, 2022

luhring Mar 21, 2022

jonasagx Mar 21, 2022

wagoodman Mar 21, 2022

wagoodman Mar 22, 2022 •

edited

kzantow commented Mar 21, 2022

luhring commented Mar 21, 2022

kzantow left a comment

luhring Mar 22, 2022

luhring Mar 22, 2022

Less verbose logging in Golang Cataloger #904

Less verbose logging in Golang Cataloger #904

Conversation

jonasagx commented Mar 21, 2022 • edited

Before

After

luhring 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

wagoodman Mar 22, 2022 • edited

Choose a reason for hiding this comment

kzantow commented Mar 21, 2022

luhring commented Mar 21, 2022

kzantow left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jonasagx commented Mar 21, 2022 •

edited

wagoodman Mar 22, 2022 •

edited