many: make snap pack --check-skeleton error logs consistent #14547

ZeyadYasser · 2024-09-27T12:54:32Z

This improves some inconsistencies in "snap pack --check-skeleton" error logs.

Shows detailed logs only if SNAPD_DEBUG is set.
Returns first error caught

It should be explored how to aggregate errors with consistency in mind as this is parsed by snapcraft.

For more context: https://warthogs.atlassian.net/browse/SNAPDENG-23795

This fixes inconsistencies in "snap pack --check-skeleton" error logs consistent. - shows detailed logs only if SNAPD_DEBUG is set. - returns first error caught It should be explored how to aggregate errors with consistency in mind as this is parsed by snapcraft. Signed-off-by: Zeyad Gouda <zeyad.gouda@canonical.com>

Signed-off-by: Zeyad Gouda <zeyad.gouda@canonical.com>

codecov · 2024-09-27T13:37:20Z

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 78.88%. Comparing base (ac897ee) to head (30aac23).
Report is 47 commits behind head on master.

Additional details and impacted files

@@            Coverage Diff             @@
##           master   #14547      +/-   ##
==========================================
+ Coverage   78.85%   78.88%   +0.02%     
==========================================
  Files        1079     1082       +3     
  Lines      145615   146075     +460     
==========================================
+ Hits       114828   115232     +404     
- Misses      23601    23646      +45     
- Partials     7186     7197      +11

Flag	Coverage Δ
unittests	`78.88% <100.00%> (+0.02%)`	⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

zyga

LGTM, looks very good.

I left a question about error wrapping with fmt.Errorf and a suggestion for one more like of tests but consider this approved.

zyga · 2024-09-28T10:43:45Z

snap/container.go

+ if firstBadModeErr != nil {
+ // TODO: fmt.Errorf("%w: %w", ErrBadModes, firstBadModeErr) when using go 1.20+
+ // TODO: aggregate bad mode errors not just the first one
+ return fmt.Errorf("%w: %v", ErrBadModes, firstBadModeErr)


Can we use %w twice? I think we can but I'm not sure if this goes all the way back to go 1.18.

Unfortunately we can't, I believe we need go 1.20 for that https://tip.golang.org/doc/go1.20#errors

zyga · 2024-09-28T10:44:32Z

snap/container_test.go

@@ -107,7 +107,7 @@ version: 1
 c.Assert(err, IsNil)

 err = snap.ValidateSnapContainer(s.container(), info, discard)
- c.Check(err, Equals, snap.ErrBadModes)
+ c.Check(err, ErrorMatches, `snap is unusable due to bad permissions: "." should be world-readable and executable, and isn't: drwx------`)


Perhaps add something that checks with the equivalent of errors.Is, for completeness.

good point, thanks! I added those to all relevant tests

Signed-off-by: Zeyad Gouda <zeyad.gouda@canonical.com>

ernestl

Thanks, looks good, one nitpick question, and idea for generalising accumulation/first error.

ernestl · 2024-09-30T08:21:22Z

snap/pack/pack.go

@@ -122,7 +122,7 @@ func loadAndValidate(sourceDir string, yaml []byte) (*snap.Info, error) {
 return nil, fmt.Errorf("cannot validate snap %q: %v", info.InstanceName(), err)
 }

- if err := snap.ValidateSnapContainer(container, info, logger.Noticef); err != nil {
+ if err := snap.ValidateSnapContainer(container, info, logger.Debugf); err != nil {


This seems little beyond the short term requirement. Concern is anyone relying on the log entries..., preference is to do this as part of larger rework for aggregation.

@pedronis

Switched back to Noticef to avoid breaking scripts that depend on the logs until we have a long term soln.

ernestl · 2024-09-30T08:25:16Z

snap/pack/pack.go

@@ -122,7 +122,7 @@ func loadAndValidate(sourceDir string, yaml []byte) (*snap.Info, error) {
 return nil, fmt.Errorf("cannot validate snap %q: %v", info.InstanceName(), err)
 }

- if err := snap.ValidateSnapContainer(container, info, logger.Noticef); err != nil {
+ if err := snap.ValidateSnapContainer(container, info, logger.Debugf); err != nil {
 return nil, err


Wondering if it makes sense to give context that we are busy with "container validation", similar to what is done for "snap validation" with "cannot validate snap %q:"...

but perhaps not worth the repercussions as part of short term minimal fix...

I agree, it's better to avoid breaking scripts that depend on some regex until we have a good plan.

ernestl · 2024-09-30T08:40:18Z

snap/container.go

- hasBadModes = true
+ err := fmt.Errorf("%q should be world-readable and executable, and isn't: %s", path, mode)
+ logf("in %s %q: %v", contType, name, err)
+ if firstBadModeErr == nil {


This works.
It made me think about error aggregation and identification of first instance as a generally useful concept.

Could create error type for aggregation, containing list of Errors []error that defaults to error[0] for message, but can be iterated to concert errors to e.g. json output or detail log entry etc as required.
This could the become e.g. accErrorBadModes.add(...)

Anyways, more applicable to longer term solution...

Signed-off-by: Zeyad Gouda <zeyad.gouda@canonical.com>

ernestl · 2024-09-30T10:20:58Z

Blocked, requested and now awaiting feedback from snapcraft team before merging.

mr-cal

Is it possible to hide the container.go error? I'm still seeing it in stderr.

before:

> snapcraft pack
Cannot pack snap: 2024/09/30 08:52:01.680392 container.go:360: in snap "hello-world": "foo" should be world-readable and executable, and isn't: -rw-rw-r--
error: snap is unusable due to bad permissions
Full execution log: '/home/developer/.local/state/snapcraft/log/snapcraft-20240930-085200.474382.log'

after:

> snapcraft pack
Cannot pack snap: 2024/09/30 08:39:22.700825 container.go:366: in snap "hello-world": "foo" should be world-readable and executable, and isn't: -rw-rw-r--
error: snap is unusable due to bad permissions: "foo" should be world-readable and executable, and isn't: -rw-rw-r--
Full execution log: '/home/developer/.local/state/snapcraft/log/snapcraft-20240930-083921.722642.log'

ZeyadYasser · 2024-10-01T06:19:36Z

Is it possible to hide the container.go error? I'm still seeing it in stderr.

That was the initial approach, but we decided to make the change smaller to avoid breaking anything that depended on those logs.

mr-cal

Since the internal container.go messages can't be omitted at this time, snapcraft will have to parse the output. This should be feasible since only one line will begin with error: and now always contains details of the first error.

Thanks!

Signed-off-by: Zeyad Gouda <zeyad.gouda@canonical.com>

ernestl · 2024-10-01T21:01:40Z

Failures are all unrelated to the changes.

ZeyadYasser requested review from zyga and ernestl September 27, 2024 12:54

ZeyadYasser added this to the 2.66 milestone Sep 27, 2024

snap/pack/pack_test.go: adjust tested file permissions

a195b7e

Signed-off-by: Zeyad Gouda <zeyad.gouda@canonical.com>

zyga approved these changes Sep 28, 2024

View reviewed changes

snap: add error type checks in unit tests

e0c053f

Signed-off-by: Zeyad Gouda <zeyad.gouda@canonical.com>

ernestl approved these changes Sep 30, 2024

View reviewed changes

snap/pack: revert to Noticef logger to avoid regressions

919676a

Signed-off-by: Zeyad Gouda <zeyad.gouda@canonical.com>

ernestl added the ⛔ Blocked label Sep 30, 2024

mr-cal reviewed Sep 30, 2024

View reviewed changes

mr-cal approved these changes Oct 1, 2024

View reviewed changes

cmd/snap: fix flakey TestPackPacksFailsForMissingPaths test

30aac23

Signed-off-by: Zeyad Gouda <zeyad.gouda@canonical.com>

ZeyadYasser removed the ⛔ Blocked label Oct 1, 2024

ernestl merged commit 7446f59 into canonical:master Oct 1, 2024
48 of 56 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

many: make snap pack --check-skeleton error logs consistent #14547

many: make snap pack --check-skeleton error logs consistent #14547

ZeyadYasser commented Sep 27, 2024

codecov bot commented Sep 27, 2024 •

edited

Loading

zyga left a comment

zyga Sep 28, 2024

ZeyadYasser Sep 30, 2024

zyga Sep 28, 2024

ZeyadYasser Sep 30, 2024

ernestl left a comment

ernestl Sep 30, 2024 •

edited

Loading

ZeyadYasser Sep 30, 2024

ernestl Sep 30, 2024 •

edited

Loading

ZeyadYasser Sep 30, 2024

ernestl Sep 30, 2024

ernestl commented Sep 30, 2024

mr-cal left a comment •

edited

Loading

ZeyadYasser commented Oct 1, 2024

mr-cal left a comment

ernestl commented Oct 1, 2024

many: make snap pack --check-skeleton error logs consistent #14547

many: make snap pack --check-skeleton error logs consistent #14547

Conversation

ZeyadYasser commented Sep 27, 2024

codecov bot commented Sep 27, 2024 • edited Loading

Codecov Report

zyga left a comment

Choose a reason for hiding this comment

zyga Sep 28, 2024

Choose a reason for hiding this comment

ZeyadYasser Sep 30, 2024

Choose a reason for hiding this comment

zyga Sep 28, 2024

Choose a reason for hiding this comment

ZeyadYasser Sep 30, 2024

Choose a reason for hiding this comment

ernestl left a comment

Choose a reason for hiding this comment

ernestl Sep 30, 2024 • edited Loading

Choose a reason for hiding this comment

ZeyadYasser Sep 30, 2024

Choose a reason for hiding this comment

ernestl Sep 30, 2024 • edited Loading

Choose a reason for hiding this comment

ZeyadYasser Sep 30, 2024

Choose a reason for hiding this comment

ernestl Sep 30, 2024

Choose a reason for hiding this comment

ernestl commented Sep 30, 2024

mr-cal left a comment • edited Loading

Choose a reason for hiding this comment

ZeyadYasser commented Oct 1, 2024

mr-cal left a comment

Choose a reason for hiding this comment

ernestl commented Oct 1, 2024

codecov bot commented Sep 27, 2024 •

edited

Loading

ernestl Sep 30, 2024 •

edited

Loading

ernestl Sep 30, 2024 •

edited

Loading

mr-cal left a comment •

edited

Loading