feat: add --debug & --verbose flags & http request/response debug…

… log (#457)

- added debug flag for sign/verify commands
- added verbose flag for sign/verify commands
- added http request/response debug log

Signed-off-by: Junjie Gao <[email protected]>

cmd/notation/list.go

@@ -44,7 +44,7 @@ func listCommand(opts *listOpts) *cobra.Command {
 func runList(command *cobra.Command, opts *listOpts) error {
 	// initialize
 	reference := opts.reference
-	sigRepo, err := getSignatureRepository(&opts.SecureFlagOpts, reference)
+	sigRepo, err := getSignatureRepository(command.Context(), &opts.SecureFlagOpts, reference)
 	if err != nil {
 		return err
 	}

cmd/notation/login.go

@@ -82,7 +82,7 @@ func runLogin(cmd *cobra.Command, opts *loginOpts) error {
 }
 
 func validateAuthConfig(ctx context.Context, opts *loginOpts, serverAddress string) error {
-	registry, err := getRegistryClient(&opts.SecureFlagOpts, serverAddress)
+	registry, err := getRegistryClient(ctx, &opts.SecureFlagOpts, serverAddress)
 	if err != nil {
 		return err
 	}

cmd/notation/manifest.go

@@ -21,7 +21,7 @@ func getManifestDescriptor(ctx context.Context, opts *SecureFlagOpts, reference
 	if ref.Reference == "" {
 		return ocispec.Descriptor{}, registry.Reference{}, errors.New("reference is missing digest or tag")
 	}
-	repo, err := getRepositoryClient(opts, ref)
+	repo, err := getRepositoryClient(ctx, opts, ref)
 	if err != nil {
 		return ocispec.Descriptor{}, registry.Reference{}, err
 	}

cmd/notation/registry.go

@@ -4,52 +4,71 @@ import (
 	"context"
 	"errors"
 	"net"
+	"net/http"
 
+	"github.com/notaryproject/notation-go/log"
 	notationregistry "github.com/notaryproject/notation-go/registry"
+	"github.com/notaryproject/notation/internal/trace"
 	"github.com/notaryproject/notation/internal/version"
 	loginauth "github.com/notaryproject/notation/pkg/auth"
 	"github.com/notaryproject/notation/pkg/configutil"
+	"github.com/sirupsen/logrus"
 	"oras.land/oras-go/v2/registry"
 	"oras.land/oras-go/v2/registry/remote"
 	"oras.land/oras-go/v2/registry/remote/auth"
 )
 
-func getSignatureRepository(opts *SecureFlagOpts, reference string) (notationregistry.Repository, error) {
+func getSignatureRepository(ctx context.Context, opts *SecureFlagOpts, reference string) (notationregistry.Repository, error) {
 	ref, err := registry.ParseReference(reference)
 	if err != nil {
 		return nil, err
 	}
-	return getRepositoryClient(opts, ref)
+
+	// generate notation repository
+	return getRepositoryClient(ctx, opts, ref)
 }
 
-func getRegistryClient(opts *SecureFlagOpts, serverAddress string) (*remote.Registry, error) {
+func getRegistryClient(ctx context.Context, opts *SecureFlagOpts, serverAddress string) (*remote.Registry, error) {
 	reg, err := remote.NewRegistry(serverAddress)
 	if err != nil {
 		return nil, err
 	}
 
-	reg.Client, reg.PlainHTTP, err = getAuthClient(opts, reg.Reference)
+	reg.Client, reg.PlainHTTP, err = getAuthClient(ctx, opts, reg.Reference)
 	if err != nil {
 		return nil, err
 	}
 	return reg, nil
 }
 
-func getRepositoryClient(opts *SecureFlagOpts, ref registry.Reference) (notationregistry.Repository, error) {
-	authClient, plainHTTP, err := getAuthClient(opts, ref)
+func getRepositoryClient(ctx context.Context, opts *SecureFlagOpts, ref registry.Reference) (notationregistry.Repository, error) {
+	authClient, plainHTTP, err := getAuthClient(ctx, opts, ref)
 	if err != nil {
 		return nil, err
 	}
-	repo := &remote.Repository{
+
+	remoteRepo := &remote.Repository{
 		Client:    authClient,
 		Reference: ref,
 		PlainHTTP: plainHTTP,
 	}
+	return notationregistry.NewRepository(remoteRepo), nil
+}
 
-	return notationregistry.NewRepository(repo), nil
+func setHttpDebugLog(ctx context.Context, authClient *auth.Client) {
+	if logrusLog, ok := log.GetLogger(ctx).(*logrus.Logger); ok && logrusLog.Level != logrus.DebugLevel {
+		return
+	}
+	if authClient.Client == nil {
+		authClient.Client = http.DefaultClient
+	}
+	if authClient.Client.Transport == nil {
+		authClient.Client.Transport = http.DefaultTransport
+	}
+	authClient.Client.Transport = trace.NewTransport(authClient.Client.Transport)
 }
 
-func getAuthClient(opts *SecureFlagOpts, ref registry.Reference) (*auth.Client, bool, error) {
+func getAuthClient(ctx context.Context, opts *SecureFlagOpts, ref registry.Reference) (*auth.Client, bool, error) {
 	var plainHTTP bool
 
 	if opts.PlainHTTP {
@@ -94,6 +113,9 @@ func getAuthClient(opts *SecureFlagOpts, ref registry.Reference) (*auth.Client,
 	}
 	authClient.SetUserAgent("notation/" + version.GetVersion())
 
+	// update authClient
+	setHttpDebugLog(ctx, authClient)
+
 	return authClient, plainHTTP, nil
 }
 

cmd/notation/sign.go

@@ -15,6 +15,7 @@ import (
 )
 
 type signOpts struct {
+	cmd.LoggingFlagOpts
 	cmd.SignerFlagOpts
 	SecureFlagOpts
 	expiry       time.Duration
@@ -59,31 +60,34 @@ Example - Sign an OCI artifact stored in a registry and specify the signature ex
 			return runSign(cmd, opts)
 		},
 	}
+	opts.LoggingFlagOpts.ApplyFlags(command.Flags())
 	opts.SignerFlagOpts.ApplyFlags(command.Flags())
 	opts.SecureFlagOpts.ApplyFlags(command.Flags())
 	cmd.SetPflagExpiry(command.Flags(), &opts.expiry)
 	cmd.SetPflagPluginConfig(command.Flags(), &opts.pluginConfig)
-
 	return command
 }
 
 func runSign(command *cobra.Command, cmdOpts *signOpts) error {
+	// set log level
+	ctx := cmdOpts.LoggingFlagOpts.SetLoggerLevel(command.Context())
+
 	// initialize
 	signer, err := cmd.GetSigner(&cmdOpts.SignerFlagOpts)
 	if err != nil {
 		return err
 	}
 
 	// core process
-	opts, ref, err := prepareSigningContent(command.Context(), cmdOpts)
+	opts, ref, err := prepareSigningContent(ctx, cmdOpts)
 	if err != nil {
 		return err
 	}
-	sigRepo, err := getSignatureRepository(&cmdOpts.SecureFlagOpts, cmdOpts.reference)
+	sigRepo, err := getSignatureRepository(ctx, &cmdOpts.SecureFlagOpts, cmdOpts.reference)
 	if err != nil {
 		return err
 	}
-	_, err = notation.Sign(command.Context(), signer, sigRepo, opts)
+	_, err = notation.Sign(ctx, signer, sigRepo, opts)
 	if err != nil {
 		return err
 	}

cmd/notation/verify.go

@@ -7,17 +7,16 @@ import (
 	"math"
 
 	"github.com/notaryproject/notation-go"
-	notationregistry "github.com/notaryproject/notation-go/registry"
 	"github.com/notaryproject/notation-go/verifier"
 	"github.com/notaryproject/notation/internal/cmd"
 	ocispec "github.com/opencontainers/image-spec/specs-go/v1"
 
 	"github.com/spf13/cobra"
 	"oras.land/oras-go/v2/registry"
-	"oras.land/oras-go/v2/registry/remote"
 )
 
 type verifyOpts struct {
+	cmd.LoggingFlagOpts
 	SecureFlagOpts
 	reference    string
 	pluginConfig []string
@@ -51,12 +50,16 @@ Example - Verify a signature on an OCI artifact identified by a tag  (Notation w
 			return runVerify(cmd, opts)
 		},
 	}
-	opts.ApplyFlags(command.Flags())
+	opts.LoggingFlagOpts.ApplyFlags(command.Flags())
+	opts.SecureFlagOpts.ApplyFlags(command.Flags())
 	command.Flags().StringArrayVarP(&opts.pluginConfig, "plugin-config", "c", nil, "{key}={value} pairs that are passed as it is to a plugin, if the verification is associated with a verification plugin, refer plugin documentation to set appropriate values")
 	return command
 }
 
 func runVerify(command *cobra.Command, opts *verifyOpts) error {
+	// set log level
+	ctx := opts.LoggingFlagOpts.SetLoggerLevel(command.Context())
+
 	// resolve the given reference and set the digest
 	ref, err := resolveReference(command.Context(), &opts.SecureFlagOpts, opts.reference, func(ref registry.Reference, manifestDesc ocispec.Descriptor) {
 		fmt.Printf("Resolved artifact tag `%s` to digest `%s` before verification.\n", ref.Reference, manifestDesc.Digest.String())
@@ -71,15 +74,12 @@ func runVerify(command *cobra.Command, opts *verifyOpts) error {
 	if err != nil {
 		return err
 	}
-	authClient, plainHTTP, _ := getAuthClient(&opts.SecureFlagOpts, ref)
-	remoteRepo := remote.Repository{
-		Client:    authClient,
-		Reference: ref,
-		PlainHTTP: plainHTTP,
-	}
-	repo := notationregistry.NewRepository(&remoteRepo)
 
-	// set up verification plugin config
+	repo, err := getRepositoryClient(ctx, &opts.SecureFlagOpts, ref)
+	if err != nil {
+		return err
+	}
+	// set up verification plugin config.
 	configs, err := cmd.ParseFlagPluginConfig(opts.pluginConfig)
 	if err != nil {
 		return err
@@ -93,8 +93,8 @@ func runVerify(command *cobra.Command, opts *verifyOpts) error {
 		MaxSignatureAttempts: math.MaxInt64,
 	}
 
-	// core verify process
-	_, outcomes, err := notation.Verify(command.Context(), verifier, repo, verifyOpts)
+	// core verify process.
+	_, outcomes, err := notation.Verify(ctx, verifier, repo, verifyOpts)
 
 	// write out
 	// on failure

go.mod

@@ -8,6 +8,7 @@ require (
 	github.com/notaryproject/notation-go v0.12.0-beta.1.0.20221205052202-e9545a718368
 	github.com/opencontainers/go-digest v1.0.0
 	github.com/opencontainers/image-spec v1.1.0-rc2
+	github.com/sirupsen/logrus v1.8.1
 	github.com/spf13/cobra v1.6.1
 	github.com/spf13/pflag v1.0.5
 	github.com/veraison/go-cose v1.0.0-rc.2

go.sum

@@ -4,6 +4,7 @@ github.com/Azure/go-ntlmssp v0.0.0-20221128193559-754e69321358/go.mod h1:chxPXzS
 github.com/cpuguy83/go-md2man/v2 v2.0.2/go.mod h1:tgQtvFlXSQOSOSIRvRPT7W67SCa46tRHOmNcaadrF8o=
 github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
+github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/docker/docker-credential-helpers v0.7.0 h1:xtCHsjxogADNZcdv1pKUHXryefjlVRqWqIhk/uXJp0A=
 github.com/docker/docker-credential-helpers v0.7.0/go.mod h1:rETQfLdHNT3foU5kuNkFR1R1V12OJRRO5lzt2D1b5X0=
 github.com/fxamacker/cbor/v2 v2.4.0 h1:ri0ArlOR+5XunOP8CRUowT0pSJOwhW098ZCUyskZD88=
@@ -28,11 +29,14 @@ github.com/opencontainers/image-spec v1.1.0-rc2/go.mod h1:3OVijpioIKYWTqjiG0zfF6
 github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
 github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
 github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM=
+github.com/sirupsen/logrus v1.8.1 h1:dJKuHgqk1NNQlqoA6BTlM1Wf9DOH3NBjQyu0h9+AZZE=
+github.com/sirupsen/logrus v1.8.1/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0=
 github.com/spf13/cobra v1.6.1 h1:o94oiPyS4KD1mPy2fmcYYHHfCxLqYjJOhGsCHFZtEzA=
 github.com/spf13/cobra v1.6.1/go.mod h1:IOw/AERYS7UzyrGinqmz6HLUo219MORXGxhbaJUqzrY=
 github.com/spf13/pflag v1.0.5 h1:iy+VFUOCP1a+8yFto/drg2CJ5u0yRoB7fZw3DKv/JXA=
 github.com/spf13/pflag v1.0.5/go.mod h1:McXfInJRrz4CZXVZOBLb0bTZqETkiAhM9Iw0y3An2Bg=
 github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
+github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
 github.com/stretchr/testify v1.7.2 h1:4jaiDzPyXQvSd7D0EjG45355tLlV3VOECpq10pLC+8s=
 github.com/stretchr/testify v1.7.2/go.mod h1:R6va5+xMeoiuVRoj+gSkQ7d3FALtqAAGI1FQKckRals=
 github.com/veraison/go-cose v1.0.0-rc.2 h1:zH3QmP4N5kwpdGauceIT3aJm8iUyV9OqpUOb+7CF7rQ=
@@ -45,6 +49,7 @@ golang.org/x/crypto v0.3.0/go.mod h1:hebNnKkNXi2UzZN1eVRvBB7co0a+JxK6XbPiWVs/3J4
 golang.org/x/net v0.0.0-20211112202133-69e39bad7dc2/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y=
 golang.org/x/sync v0.1.0 h1:wsuoTGHzEhffawBOhz5CYhcrV4IdKZbEyZjBMuTp12o=
 golang.org/x/sync v0.1.0/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
+golang.org/x/sys v0.0.0-20191026070338-33540a1f6037/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 golang.org/x/sys v0.0.0-20210423082822-04245dca01da/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=

internal/cmd/options.go

@@ -1,6 +1,10 @@
 package cmd
 
 import (
+	"context"
+
+	"github.com/notaryproject/notation/internal/trace"
+	"github.com/sirupsen/logrus"
 	"github.com/spf13/pflag"
 )
 
@@ -15,3 +19,25 @@ func (opts *SignerFlagOpts) ApplyFlags(fs *pflag.FlagSet) {
 	SetPflagKey(fs, &opts.Key)
 	SetPflagSignatureFormat(fs, &opts.SignatureFormat)
 }
+
+// LoggingFlagOpts option struct.
+type LoggingFlagOpts struct {
+	Debug   bool
+	Verbose bool
+}
+
+// ApplyFlags applies flags to a command flag set.
+func (opts *LoggingFlagOpts) ApplyFlags(fs *pflag.FlagSet) {
+	fs.BoolVarP(&opts.Debug, "debug", "d", false, "debug mode")
+	fs.BoolVarP(&opts.Verbose, "verbose", "v", false, "verbose mode")
+}
+
+// SetLoggerLevel sets up the logger based on common options.
+func (opts *LoggingFlagOpts) SetLoggerLevel(ctx context.Context) context.Context {
+	if opts.Debug {
+		return trace.WithLoggerLevel(ctx, logrus.DebugLevel)
+	} else if opts.Verbose {
+		return trace.WithLoggerLevel(ctx, logrus.InfoLevel)
+	}
+	return ctx
+}

internal/trace/context.go

@@ -0,0 +1,43 @@
+// Copied and adapted from oras (https://github.com/oras-project/oras)
+/*
+Copyright The ORAS Authors.
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+package trace
+
+import (
+	"context"
+
+	"github.com/notaryproject/notation-go/log"
+	"github.com/sirupsen/logrus"
+)
+
+// WithLoggerLevel returns a context with logrus log entry.
+func WithLoggerLevel(ctx context.Context, level logrus.Level) context.Context {
+	// set formatter
+	var formatter logrus.TextFormatter
+	if level == logrus.DebugLevel {
+		formatter.FullTimestamp = true
+	} else {
+		formatter.DisableTimestamp = true
+	}
+
+	// create logger
+	logger := logrus.New()
+	logger.SetFormatter(&formatter)
+	logger.SetLevel(level)
+
+	// save logger to context
+	return log.WithLogger(ctx, logger)
+}