Add debug logs (#590)

* Add more logs
Fixed some logs that didn't log the error buffer from the invocation
image.
* Update cnab-to-oci dependency
And pass a logger when pushing and pulling

Signed-off-by: Djordje Lukic <djordje.lukic@docker.com>

Author: rumpl

Gopkg.lock

@@ -183,7 +183,7 @@ func TestDetectApp(t *testing.T) {
 	cmd.Dir = dir.Join("render")
 	icmd.RunCmd(cmd).Assert(t, icmd.Expected{
 		ExitCode: 1,
-		Err:      "Error: multiple applications found in current directory, specify the application name on the command line",
+		Err:      "multiple applications found in current directory, specify the application name on the command line",
 	})
 }
 

e2e/commands_test.go

@@ -20,6 +20,7 @@ import (
 	dockertypes "github.com/docker/docker/api/types"
 	"github.com/docker/docker/pkg/jsonmessage"
 	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
 	"github.com/spf13/cobra"
 )
 
@@ -88,6 +89,7 @@ func makeBundle(dockerCli command.Cli, appName string, refOverride reference.Nam
 }
 
 func makeBundleFromApp(dockerCli command.Cli, app *types.App, refOverride reference.NamedTagged) (*bundle.Bundle, error) {
+	logrus.Debug("Making app bundle")
 	meta := app.Metadata()
 	invocationImageName, err := makeInvocationImageName(meta, refOverride)
 	if err != nil {
@@ -99,6 +101,7 @@ func makeBundleFromApp(dockerCli command.Cli, app *types.App, refOverride refere
 		return nil, err
 	}
 
+	logrus.Debugf("Building invocation image %s", invocationImageName)
 	buildResp, err := dockerCli.Client().ImageBuild(context.TODO(), buildContext, dockertypes.ImageBuildOptions{
 		Dockerfile: "Dockerfile",
 		Tags:       []string{invocationImageName},

internal/commands/bundle.go

@@ -39,7 +39,7 @@ func runInspect(dockerCli command.Cli, appname string, opts inspectOptions) erro
 		return err
 	}
 	if err := action.Run(&installation.Claim, nil, nil); err != nil {
-		return fmt.Errorf("inspect failed: %s", errBuf)
+		return fmt.Errorf("inspect failed: %s\n%s", err, errBuf)
 	}
 	return nil
 }

internal/commands/inspect.go

@@ -9,6 +9,7 @@ import (
 	"github.com/docker/app/internal/store"
 	"github.com/docker/cli/cli"
 	"github.com/docker/cli/cli/command"
+	"github.com/sirupsen/logrus"
 	"github.com/spf13/cobra"
 )
 
@@ -91,6 +92,7 @@ func runInstall(dockerCli command.Cli, appname string, opts installOptions) erro
 	if installationName == "" {
 		installationName = bndl.Name
 	}
+	logrus.Debugf(`Looking for a previous installation "%q"`, installationName)
 	if installation, err := installationStore.Read(installationName); err == nil {
 		// A failed installation can be overridden, but with a warning
 		if isInstallationFailed(installation) {
@@ -100,6 +102,8 @@ func runInstall(dockerCli command.Cli, appname string, opts installOptions) erro
 			// their was already a successful installation.
 			return fmt.Errorf("Installation %q already exists, use 'docker app upgrade' instead", installationName)
 		}
+	} else {
+		logrus.Debug(err)
 	}
 	installation, err := store.NewInstallation(installationName, ref)
 	if err != nil {
@@ -134,7 +138,7 @@ func runInstall(dockerCli command.Cli, appname string, opts installOptions) erro
 	// so any installation needs a clean uninstallation.
 	err2 := installationStore.Store(installation)
 	if err != nil {
-		return fmt.Errorf("Installation failed: %s\n%s", errBuf, err)
+		return fmt.Errorf("Installation failed: %s\n%s", err, errBuf)
 	}
 	if err2 != nil {
 		return err2

internal/commands/install.go

@@ -9,9 +9,9 @@ import (
 	"os"
 	"strings"
 
-	"github.com/containerd/containerd/log"
 	"github.com/containerd/containerd/platforms"
 	"github.com/deislabs/cnab-go/bundle"
+	"github.com/docker/app/internal/log"
 	"github.com/docker/app/types/metadata"
 	"github.com/docker/cli/cli"
 	"github.com/docker/cli/cli/command"
@@ -83,6 +83,7 @@ func runPush(dockerCli command.Cli, name string, opts pushOptions) error {
 		return err
 	}
 	if retag.shouldRetag {
+		logrus.Debugf(`Retagging invocation image "%q"`, retag.invocationImageRef.String())
 		if err := retagInvocationImage(dockerCli, bndl, retag.invocationImageRef.String()); err != nil {
 			return err
 		}
@@ -112,6 +113,7 @@ func resolveReferenceAndBundle(dockerCli command.Cli, name string) (*bundle.Bund
 }
 
 func pushInvocationImage(dockerCli command.Cli, retag retagResult) error {
+	logrus.Debugf("Pushing the invocation image %q", retag.invocationImageRef)
 	repoInfo, err := registry.ParseRepositoryInfo(retag.invocationImageRef)
 	if err != nil {
 		return err
@@ -150,21 +152,15 @@ func pushBundle(dockerCli command.Cli, opts pushOptions, bndl *bundle.Bundle, re
 		return errors.Wrapf(err, "fixing up %q for push", retag.cnabRef)
 	}
 	// push bundle manifest
-	descriptor, err := remotes.Push(newMuteLogContext(), bndl, retag.cnabRef, resolver, true, withAppAnnotations)
+	logrus.Debugf("Pushing the bundle %q", retag.cnabRef)
+	descriptor, err := remotes.Push(log.WithLogContext(context.Background()), bndl, retag.cnabRef, resolver, true, withAppAnnotations)
 	if err != nil {
 		return errors.Wrapf(err, "pushing to %q", retag.cnabRef)
 	}
 	fmt.Fprintf(os.Stdout, "Successfully pushed bundle to %s. Digest is %s.\n", retag.cnabRef.String(), descriptor.Digest)
 	return nil
 }
 
-func newMuteLogContext() context.Context {
-	logger := logrus.New()
-	logger.SetLevel(logrus.ErrorLevel)
-	logger.SetOutput(ioutil.Discard)
-	return log.WithLogger(context.Background(), logrus.NewEntry(logger))
-}
-
 func withAppAnnotations(index *ocischemav1.Index) error {
 	if index.Annotations == nil {
 		index.Annotations = make(map[string]string)

internal/commands/push.go

@@ -60,7 +60,7 @@ func runRender(dockerCli command.Cli, appname string, opts renderOptions) error
 	installation.Parameters[internal.ParameterRenderFormatName] = opts.formatDriver
 
 	if err := action.Run(&installation.Claim, nil, nil); err != nil {
-		return fmt.Errorf("render failed: %s", errBuf)
+		return fmt.Errorf("render failed: %s\n%s", err, errBuf)
 	}
 	return nil
 }

internal/commands/render.go

@@ -90,7 +90,7 @@ func runUpgrade(dockerCli command.Cli, installationName string, opts upgradeOpti
 	err = u.Run(&installation.Claim, creds, os.Stdout)
 	err2 := installationStore.Store(installation)
 	if err != nil {
-		return fmt.Errorf("Upgrade failed: %s", errBuf)
+		return fmt.Errorf("Upgrade failed: %s\n%s", err, errBuf)
 	}
 	if err2 != nil {
 		return err2

internal/commands/upgrade.go

@@ -0,0 +1,14 @@
+package log
+
+import (
+	"context"
+
+	"github.com/containerd/containerd/log"
+	"github.com/sirupsen/logrus"
+)
+
+func WithLogContext(ctx context.Context) context.Context {
+	logger := logrus.New()
+	logger.SetLevel(logrus.GetLevel())
+	return log.WithLogger(ctx, logrus.NewEntry(logger))
+}

internal/log/log.go

@@ -1,11 +1,14 @@
 package packager
 
 import (
+	"encoding/json"
+
 	"github.com/deislabs/cnab-go/bundle"
 	"github.com/deislabs/cnab-go/bundle/definition"
 	"github.com/docker/app/internal"
 	"github.com/docker/app/internal/compose"
 	"github.com/docker/app/types"
+	"github.com/sirupsen/logrus"
 )
 
 const (
@@ -120,7 +123,7 @@ func ToCNAB(app *types.App, invocationImageName string) (*bundle.Bundle, error)
 		return nil, err
 	}
 
-	return &bundle.Bundle{
+	bndl := &bundle.Bundle{
 		SchemaVersion: CNABVersion1_0_0,
 		Credentials: map[string]bundle.Credential{
 			internal.CredentialDockerContextName: {
@@ -162,7 +165,13 @@ func ToCNAB(app *types.App, invocationImageName string) (*bundle.Bundle, error)
 			},
 		},
 		Images: bundleImages,
-	}, nil
+	}
+
+	if js, err := json.Marshal(bndl); err == nil {
+		logrus.Debugf("App converted to CNAB %q", string(js))
+	}
+
+	return bndl, nil
 }
 
 func extractBundleImages(composeFiles [][]byte) (map[string]bundle.Image, error) {