Make errors structured #1937

blixtra · 2016-01-06T10:49:35Z

This PR is intended to get feedback on the general approach.

Up to now errors in rkt have been a concatenated string. This often
ended with the user being presented with a very long, hard to decipher
error message. Furthermore, sometimes the message was prefixed with the
name of the command, sometimes not. In essencce, errors messages were
inconsistent and confusing.

This patch introduces structured error messages using the errwrap
package. The goal is to have errors be useful & consistant, and have a
single location (common/errors.go) where we can modify the error output.

The common/errors.go provides a type called ErrorSanitizer that manages
error output. It is set up in the cobra.Command's PresisentPreRun func
so that each subcommand is able to initialize errOut with the
evaluated --debug flag. This also allows each subcommand to set the
prefix appropriately. It uses the --debug flag to decide whether to show
just the inner-most error or all errors. The format of the error with
--debug=false is...

cat-manifest: problem retrieving pod
└─no matches found for "asdfasdf"

With --debug=true the output show all the errors.

cat-manifest: problem retrieving pod
└─unable to resolve UUID
  └─no matches found for "asdfasdf"

In this case only one more but some errors are 5 or more deep. See
#1550 for an example.

This change does not change messages that are simply printing
a message to stderr. These still use the stderr function.

This change only handles errors but it may be useful to make
ErrorSanitizer a more general "output" type that handles all output to
console in a central place.

I think the ErrorSanitizer methods Print and Error could be better named. Also I'm thinking it may be better to have the error message only be on one line when --debug is false. For example, the one line output could be...

cat-manifest: problem retrieving pod: no matches found for "asdfasdf"

and the --debug=true output could be...

cat-manifest: problem retrieving pod: no matches found for "asdfasdf"
└─unable to resolve UUID
  └─no matches found for "asdfasdf"

This PR will intend to fix #1550 and #1754.

Note: This will not pass the tests because the tests parse error output and I've not yet updated those.

alban · 2016-01-06T13:36:43Z

rkt/rkt.go

@@ -105,6 +111,11 @@ func init() {
 	cmdRkt.PersistentFlags().BoolVar(&globalFlags.TrustKeysFromHttps, "trust-keys-from-https",
 		true, "automatically trust gpg keys fetched from https")

+	// Run this before the execution of each subcommand to set up output
+	cmdRkt.PersistentPreRun = func(cmd *cobra.Command, args []string) {
+		errOut = common.NewErrorSanitizer(os.Stderr, cmd.Name(), globalFlags.Debug)


common.NewErrorSanitizer is only called in the rkt binary but not in stage1's binaries (init or gc). How does it print the errors when the errors are not generated from the rkt binary?

right. We need to separate the idea of making the errors structured and outputting the errors. For stage1 binaries, the errors have now been structured but I haven't dealt with output part yet. A large majority, if not all, of the output for stage1 goes to log.

Currently the wrapped errors will only show the outer most message. Will probable need to change that.

jonboulle · 2016-01-09T14:51:13Z

common/errors.go

+	"github.com/coreos/rkt/Godeps/_workspace/src/github.com/hashicorp/errwrap"
+)
+
+// ErrorSanitizer is designed to handle


designed to handle ...

blixtra · 2016-01-20T00:38:39Z

This is close to the final PR. Need to fix the tests now.

blixtra · 2016-01-20T09:06:39Z

Please review. I'm currently working on getting the tests to past but the main code is pretty much where I want it.

krnowak · 2016-01-20T10:49:08Z

pkg/fileutil/fileutil_unsupported.go

@@ -16,7 +16,10 @@

 package fileutil

-import "syscall"
+import (
+	"os"


Nice catch!

krnowak · 2016-01-20T13:23:54Z

rkt/config/config_test.go

@@ -151,7 +153,7 @@ func verifyFailure(shouldFail bool, contents string, err error) error {
 	var vErr error = nil
 	if err != nil {
 		if !shouldFail {
-			vErr = fmt.Errorf("Expected test to succeed, failed unexpectedly (contents: `%s`): %v", contents, err)
+			vErr = errwrap.Wrapf(fmt.Sprintf("Expected test to succeed, failed unexpectedly (contents: `%s`): {{err}}", contents), err)


I'm not sure if there is a point in using errwrap in unit tests.

krnowak · 2016-01-27T14:26:33Z

store/store.go

@@ -134,7 +135,7 @@ func (s *Store) populateSize() error {
 		return err
 	})
 	if err != nil {
-		return fmt.Errorf("populateSize(): error retrieving ACI Infos: %v", err)
+		return errwrap.Wrap(errors.New("populateSize(): error retrieving ACI Infos"), err)


I'd remove that populateSize(): prefix.

krnowak · 2016-01-27T14:32:25Z

About stderr in rkt/pubkey and rkt/image packages - I suggest forwarding the logger from the users of those packages, that is - make *rktlog.Logger a member of pubkey.Manager and image.action structs. I guess that this member will need to be added to other fetchers as well.

iaguis · 2016-01-28T14:03:38Z

There're some panic()s that are not changed to PanicE()s but I don't thing this is a blocker.

iaguis · 2016-01-28T14:31:55Z

Missing wrapping: https://github.com/coreos/rkt/blob/dc837ae7fe6f36552cf3bcde7b938f307361c7d2/stage1/common/run.go

We should document this new way of handling errors (for example, in hacking.md) so developers use it.

iaguis · 2016-01-28T14:42:29Z

Otherwise, LGTM.

I'm sure we're missing some things but we'll fix them eventually.

errwrap provides a means of structuring error messages.

Up to now errors in rkt have been a concatenated string. This often ended with the user being presented with a very long, hard to decipher error message. Furthermore, sometimes the message was prefixed with the name of the command, sometimes not. In essencce, errors messages were inconsistent and confusing. This patch introduces structured error messages using the errwrap package. The goal is to have errors be useful & consistant, and have a single location (common/errors.go) where we can modify the error output. Errors are stored as an inner and outer errors. We do this by nesting errors using errwrap.Wrap. With this structure we have much more control over how we can display errors.

This change creates a new type, Logger, that wraps go's own Logger type to provide consistent output across go commands. Along with the methods from go's log package, there are also methods that accept our structured error type introduced in the previous commit. These commands append an 'E' to the end of the familiar methods. For example, we now have 'PrintE', 'PanicE', & 'FatalE'. With this, we have one, central location to modify the way output is displayed in rkt. The output generated when printing errors is: ``` cat-manifest: problem retrieving pod: no matches found for "asf" ``` or when using the `--debug` flag we'll get the entire error stack. ``` cat-manifest: problem retrieving pod └─unable to resolve UUID └─no matches found for "asf" ``` From this example we can see that when no `--debug` flag is used, you get the innermost error as the last output on the line. All other errors are hidden. This text between the 'command name' is the programmer defined message that accompanies the errors sent to output. This can be left empty. When using the `--debug` flag we only get the 'command name' and accompanying message on the first line. Under that we get the unwound error messages, with the innermost one at the bottom. Furthermore, all output to stderr has a prefix that is either programatically set using the command or subsommand name, or one set in the package. refs: rkt#1550 fixes: rkt#1754

This makes casing for diagnostic and error messages consistent across rkt.

With the changes in error and diagnostic tests, some strings needed to be updated.

Make errors structured

alban reviewed Jan 6, 2016
View reviewed changes

alban added this to the v0.16.0 milestone Jan 7, 2016

alban added the area/usability label Jan 7, 2016

alban assigned blixtra Jan 7, 2016

jonboulle reviewed Jan 9, 2016
View reviewed changes

alban added the do not merge label Jan 10, 2016

alban added needs/some-changes priority/P2 labels Jan 18, 2016

blixtra force-pushed the blixtra/make-errors-structured branch from c2b21e7 to 4c7935e Compare January 20, 2016 00:37

blixtra changed the title ~~Make errors structured [DO NOT MERGE]~~ Make errors structured Jan 20, 2016

krnowak reviewed Jan 20, 2016
View reviewed changes

pkg/fileutil/fileutil_unsupported.go

@@ -16,7 +16,10 @@

package fileutil

import "syscall"

import (

"os"

Copy link

Collaborator

krnowak Jan 20, 2016

Choose a reason for hiding this comment

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

Nice catch!

blixtra mentioned this pull request Jan 20, 2016

bad error message when dependences imageID does not match #1550

Closed

krnowak reviewed Jan 20, 2016
View reviewed changes

krnowak reviewed Jan 27, 2016
View reviewed changes

blixtra force-pushed the blixtra/make-errors-structured branch 2 times, most recently from 9d25ed6 to f028b20 Compare January 28, 2016 16:04

blixtra added 16 commits January 28, 2016 17:07

godeps: add errwrap package dependency

d0ba73a

errwrap provides a means of structuring error messages.

rkt: make error messages start lowercase

b01a806

This makes casing for diagnostic and error messages consistent across rkt.

tests: update output matches in tests

c5ca860

With the changes in error and diagnostic tests, some strings needed to be updated.

tests: add unit test for pkg/log

ab3236a

rkt: use Logger for image & pubkey packages

696b9b5

Add missing import in keygen

fc6db5c

tests: match against HTTP status in auth test

24e3fbc

Fix various logging and error msg issues

362b8ac

Remove extra line in api_service init

0f83965

Wrap missed errors found in review

ba984d4

tests: update prefix in image test matches

fadf116

docs: add documentation for errors & output

ae0dc5c

Remove empty line from pkg/log_test.go

d4c17f4

Wrap errors in common/run

23b4412

blixtra force-pushed the blixtra/make-errors-structured branch from f028b20 to 23b4412 Compare January 28, 2016 16:20

iaguis added a commit that referenced this pull request Jan 28, 2016

Merge pull request #1937 from kinvolk/blixtra/make-errors-structured

ca97bfa

Make errors structured

iaguis merged commit ca97bfa into rkt:master Jan 28, 2016

jonboulle mentioned this pull request Jan 29, 2016

CHANGELOG: Add entry for error and output changes #2048

Merged

iaguis mentioned this pull request Feb 3, 2016

CHANGELOG: wrap PR numbers in parenthesis #2099

Merged

alban mentioned this pull request Feb 9, 2016

stage1,tests: add support for non-numerical uid/gid #2159

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Make errors structured #1937

Make errors structured #1937

blixtra commented Jan 6, 2016

alban Jan 6, 2016

blixtra Jan 8, 2016

jonboulle Jan 9, 2016

blixtra commented Jan 20, 2016

blixtra commented Jan 20, 2016

krnowak Jan 20, 2016

krnowak Jan 20, 2016

krnowak Jan 27, 2016

krnowak commented Jan 27, 2016

iaguis commented Jan 28, 2016

iaguis commented Jan 28, 2016

iaguis commented Jan 28, 2016

Make errors structured #1937

Make errors structured #1937

Conversation

blixtra commented Jan 6, 2016

alban Jan 6, 2016

Choose a reason for hiding this comment

blixtra Jan 8, 2016

Choose a reason for hiding this comment

jonboulle Jan 9, 2016

Choose a reason for hiding this comment

blixtra commented Jan 20, 2016

blixtra commented Jan 20, 2016

krnowak Jan 20, 2016

Choose a reason for hiding this comment

krnowak Jan 20, 2016

Choose a reason for hiding this comment

krnowak Jan 27, 2016

Choose a reason for hiding this comment

krnowak commented Jan 27, 2016

iaguis commented Jan 28, 2016

iaguis commented Jan 28, 2016

iaguis commented Jan 28, 2016