log: Initial logr/logrusr implementation

Signed-off-by: Stephen Augustus <[email protected]>

checks/binary_artifact_test.go

@@ -65,9 +65,6 @@ func TestBinaryArtifacts(t *testing.T) {
 				t.Errorf("githubrepo.NewLogger: %v", err)
 			}
 
-			// nolint
-			defer logger.Zap.Sync()
-
 			ctrl := gomock.NewController(t)
 			repo, err := localdir.MakeLocalDirRepo(tt.inputFolder)
 

checks/license_test.go

@@ -147,9 +147,6 @@ func TestLicenseFileSubdirectory(t *testing.T) {
 				t.Errorf("githubrepo.NewLogger: %v", err)
 			}
 
-			// nolint
-			defer logger.Zap.Sync()
-
 			ctrl := gomock.NewController(t)
 			repo, err := localdir.MakeLocalDirRepo(tt.inputFolder)
 

clients/githubrepo/client.go

@@ -181,7 +181,7 @@ func (client *Client) Close() error {
 // CreateGithubRepoClient returns a Client which implements RepoClient interface.
 func CreateGithubRepoClient(ctx context.Context, logger *log.Logger) clients.RepoClient {
 	// Use our custom roundtripper
-	rt := roundtripper.NewTransport(ctx, logger.Zap.Sugar())
+	rt := roundtripper.NewTransport(ctx, logger)
 	httpClient := &http.Client{
 		Transport: rt,
 	}

clients/githubrepo/roundtripper/rate_limit.go

@@ -20,13 +20,12 @@ import (
 	"strconv"
 	"time"
 
-	"go.uber.org/zap"
-
 	sce "github.com/ossf/scorecard/v4/errors"
+	"github.com/ossf/scorecard/v4/log"
 )
 
 // MakeRateLimitedTransport returns a RoundTripper which rate limits GitHub requests.
-func MakeRateLimitedTransport(innerTransport http.RoundTripper, logger *zap.SugaredLogger) http.RoundTripper {
+func MakeRateLimitedTransport(innerTransport http.RoundTripper, logger *log.Logger) http.RoundTripper {
 	return &rateLimitTransport{
 		logger:         logger,
 		innerTransport: innerTransport,
@@ -35,7 +34,7 @@ func MakeRateLimitedTransport(innerTransport http.RoundTripper, logger *zap.Suga
 
 // rateLimitTransport is a rate-limit aware http.Transport for Github.
 type rateLimitTransport struct {
-	logger         *zap.SugaredLogger
+	logger         *log.Logger
 	innerTransport http.RoundTripper
 }
 
@@ -58,11 +57,13 @@ func (gh *rateLimitTransport) RoundTrip(r *http.Request) (*http.Response, error)
 		}
 
 		duration := time.Until(time.Unix(int64(reset), 0))
-		gh.logger.Warnf("Rate limit exceeded. Waiting %s to retry...", duration)
+		// TODO(log): Previously Warn. Consider logging an error here.
+		gh.logger.Info(fmt.Sprintf("Rate limit exceeded. Waiting %s to retry...", duration))
 
 		// Retry
 		time.Sleep(duration)
-		gh.logger.Warnf("Rate limit exceeded. Retrying...")
+		// TODO(log): Previously Warn. Consider logging an error here.
+		gh.logger.Info(fmt.Sprintf("Rate limit exceeded. Retrying..."))
 		return gh.RoundTrip(r)
 	}
 

clients/githubrepo/roundtripper/roundtripper.go

@@ -17,15 +17,15 @@ package roundtripper
 
 import (
 	"context"
-	"log"
+	"fmt"
 	"net/http"
 	"os"
 	"strconv"
 
 	"github.com/bradleyfalzon/ghinstallation/v2"
-	"go.uber.org/zap"
 
 	"github.com/ossf/scorecard/v4/clients/githubrepo/roundtripper/tokens"
+	"github.com/ossf/scorecard/v4/log"
 )
 
 const (
@@ -38,7 +38,7 @@ const (
 )
 
 // NewTransport returns a configured http.Transport for use with GitHub.
-func NewTransport(ctx context.Context, logger *zap.SugaredLogger) http.RoundTripper {
+func NewTransport(ctx context.Context, logger *log.Logger) http.RoundTripper {
 	transport := http.DefaultTransport
 
 	// nolint
@@ -48,19 +48,19 @@ func NewTransport(ctx context.Context, logger *zap.SugaredLogger) http.RoundTrip
 	} else if keyPath := os.Getenv(githubAppKeyPath); keyPath != "" { // Also try a GITHUB_APP
 		appID, err := strconv.Atoi(os.Getenv(githubAppID))
 		if err != nil {
-			log.Panic(err)
+			logger.Error(err, "getting GitHub application ID from environment")
 		}
 		installationID, err := strconv.Atoi(os.Getenv(githubAppInstallationID))
 		if err != nil {
-			log.Panic(err)
+			logger.Error(err, "getting GitHub application installation ID")
 		}
 		transport, err = ghinstallation.NewKeyFromFile(transport, int64(appID), int64(installationID), keyPath)
 		if err != nil {
-			log.Panic(err)
+			logger.Error(err, "getting a private key from file")
 		}
 	} else {
-		log.Fatalf("GitHub token env var is not set. " +
-			"Please read https://github.com/ossf/scorecard#authentication")
+		// TODO(log): Improve error message
+		logger.Error(fmt.Errorf("an error occurred while getting GitHub credentials"), "GitHub token env var is not set. Please read https://github.com/ossf/scorecard#authentication")
 	}
 
 	return MakeCensusTransport(MakeRateLimitedTransport(transport, logger))

clients/localdir/client_test.go

@@ -67,8 +67,6 @@ func TestClient_CreationAndCaching(t *testing.T) {
 			if err != nil {
 				t.Errorf("githubrepo.NewLogger: %v", err)
 			}
-			// nolint
-			defer logger.Zap.Sync() // Flushes buffer, if any.
 
 			// Create repo.
 			repo, err := MakeLocalDirRepo(tt.inputFolder)

cmd/root.go

@@ -192,8 +192,6 @@ func scorecardCmd(cmd *cobra.Command, args []string) {
 	if err != nil {
 		log.Panic(err)
 	}
-	// nolint: errcheck
-	defer logger.Zap.Sync() // Flushes buffer, if any.
 
 	repoURI, repoClient, ossFuzzRepoClient, ciiClient, vulnsClient, repoType, err := getRepoAccessors(ctx, uri, logger)
 	if err != nil {

cmd/serve.go

@@ -43,14 +43,15 @@ var serveCmd = &cobra.Command{
 	Run: func(cmd *cobra.Command, args []string) {
 		logger, err := githubrepo.NewLogger(sclog.Level(logLevel))
 		if err != nil {
+			// TODO(log): Drop stdlib log
 			log.Fatalf("unable to construct logger: %v", err)
 		}
-		//nolint
-		defer logger.Zap.Sync() // flushes buffer, if any
-		sugar := logger.Zap.Sugar()
+
 		t, err := template.New("webpage").Parse(tpl)
 		if err != nil {
-			sugar.Panic(err)
+			// TODO(log): Should this actually panic?
+			logger.Error(err, "parsing webpage template")
+			panic(err)
 		}
 
 		http.HandleFunc("/", func(rw http.ResponseWriter, r *http.Request) {
@@ -69,27 +70,29 @@ var serveCmd = &cobra.Command{
 			ossFuzzRepoClient, err := githubrepo.CreateOssFuzzRepoClient(ctx, logger)
 			vulnsClient := clients.DefaultVulnerabilitiesClient()
 			if err != nil {
-				sugar.Error(err)
+				logger.Error(err, "initializing clients")
 				rw.WriteHeader(http.StatusInternalServerError)
 			}
 			defer ossFuzzRepoClient.Close()
 			ciiClient := clients.DefaultCIIBestPracticesClient()
 			repoResult, err := pkg.RunScorecards(ctx, repo, false, checks.AllChecks, repoClient,
 				ossFuzzRepoClient, ciiClient, vulnsClient)
 			if err != nil {
-				sugar.Error(err)
+				logger.Error(err, "running enabled scorecard checks on repo")
 				rw.WriteHeader(http.StatusInternalServerError)
 			}
 
 			if r.Header.Get("Content-Type") == "application/json" {
 				if err := repoResult.AsJSON(showDetails, sclog.Level(logLevel), rw); err != nil {
-					sugar.Error(err)
+					// TODO(log): Improve error message
+					logger.Error(err, "")
 					rw.WriteHeader(http.StatusInternalServerError)
 				}
 				return
 			}
 			if err := t.Execute(rw, repoResult); err != nil {
-				sugar.Warn(err)
+				// TODO(log): Improve error message
+				logger.Error(err, "")
 			}
 		})
 		port := os.Getenv("PORT")
@@ -99,7 +102,9 @@ var serveCmd = &cobra.Command{
 		fmt.Printf("Listening on localhost:%s\n", port)
 		err = http.ListenAndServe(fmt.Sprintf("0.0.0.0:%s", port), nil)
 		if err != nil {
-			log.Fatal("ListenAndServe ", err)
+			// TODO(log): Should this actually panic?
+			logger.Error(err, "listening and serving")
+			panic(err)
 		}
 	},
 }

cron/worker/main.go

@@ -68,7 +68,7 @@ func processRequest(ctx context.Context,
 		return fmt.Errorf("error during BlobExists: %w", err)
 	}
 	if exists1 && exists2 {
-		logger.Zap.Info(fmt.Sprintf("Already processed shard %s. Nothing to do.", filename))
+		logger.Info(fmt.Sprintf("Already processed shard %s. Nothing to do.", filename))
 		// We have already processed this request, nothing to do.
 		return nil
 	}
@@ -77,10 +77,11 @@ func processRequest(ctx context.Context,
 	var buffer2 bytes.Buffer
 	// TODO: run Scorecard for each repo in a separate thread.
 	for _, repo := range batchRequest.GetRepos() {
-		logger.Zap.Info(fmt.Sprintf("Running Scorecard for repo: %s", *repo.Url))
+		logger.Info(fmt.Sprintf("Running Scorecard for repo: %s", *repo.Url))
 		repo, err := githubrepo.MakeGithubRepo(*repo.Url)
 		if err != nil {
-			logger.Zap.Warn(fmt.Sprintf("invalid GitHub URL: %v", err))
+			// TODO(log): Previously Warn. Consider logging an error here.
+			logger.Info(fmt.Sprintf("invalid GitHub URL: %v", err))
 			continue
 		}
 		repo.AppendMetadata(repo.Metadata()...)
@@ -103,7 +104,8 @@ func processRequest(ctx context.Context,
 				// nolint: goerr113
 				return errors.New(errorMsg)
 			}
-			logger.Zap.Warn(errorMsg)
+			// TODO(log): Previously Warn. Consider logging an error here.
+			logger.Info(errorMsg)
 		}
 		result.Date = batchRequest.GetJobTime().AsTime()
 		if err := format.AsJSON(&result, true /*showDetails*/, log.InfoLevel, &buffer); err != nil {
@@ -122,7 +124,7 @@ func processRequest(ctx context.Context,
 		return fmt.Errorf("error during WriteToBlobStore2: %w", err)
 	}
 
-	logger.Zap.Info(fmt.Sprintf("Write to shard file successful: %s", filename))
+	logger.Info(fmt.Sprintf("Write to shard file successful: %s", filename))
 
 	return nil
 }
@@ -206,7 +208,8 @@ func main() {
 
 	// Exposed for monitoring runtime profiles
 	go func() {
-		logger.Zap.Fatal(fmt.Sprintf("%v", http.ListenAndServe(":8080", nil)))
+		// TODO(log): Previously Fatal. Need to handle the error here.
+		logger.Info(fmt.Sprintf("%v", http.ListenAndServe(":8080", nil)))
 	}()
 
 	checksToRun := checks.AllChecks
@@ -218,21 +221,23 @@ func main() {
 		if err != nil {
 			panic(err)
 		}
-		logger.Zap.Info("Received message from subscription")
+
+		logger.Info("Received message from subscription")
 		if req == nil {
-			logger.Zap.Warn("subscription returned nil message during Receive, exiting")
+			// TODO(log): Previously Warn. Consider logging an error here.
+			logger.Info("subscription returned nil message during Receive, exiting")
 			break
 		}
 		if err := processRequest(ctx, req, checksToRun,
 			bucketURL, bucketURL2, checkDocs,
 			repoClient, ossFuzzRepoClient, ciiClient, vulnsClient, logger); err != nil {
-			logger.Zap.Warn(fmt.Sprintf("error processing request: %v", err))
+			// TODO(log): Previously Warn. Consider logging an error here.
+			logger.Info(fmt.Sprintf("error processing request: %v", err))
 			// Nack the message so that another worker can retry.
 			subscriber.Nack()
 			continue
 		}
-		// nolint: errcheck // flushes buffer
-		logger.Zap.Sync()
+
 		exporter.Flush()
 		subscriber.Ack()
 	}

go.mod

@@ -36,7 +36,10 @@ require (
 )
 
 require (
+	github.com/bombsimon/logrusr/v2 v2.0.1
+	github.com/go-logr/logr v1.0.0
 	github.com/rhysd/actionlint v1.6.8
+	github.com/sirupsen/logrus v1.8.1
 	gotest.tools v2.2.0+incompatible
 )
 
@@ -89,7 +92,6 @@ require (
 	github.com/rivo/uniseg v0.2.0 // indirect
 	github.com/robfig/cron v1.2.0 // indirect
 	github.com/sergi/go-diff v1.1.0 // indirect
-	github.com/sirupsen/logrus v1.8.1 // indirect
 	github.com/spf13/pflag v1.0.5 // indirect
 	github.com/vbatts/tar-split v0.11.2 // indirect
 	github.com/xanzy/ssh-agent v0.3.0 // indirect

go.sum

@@ -292,6 +292,8 @@ github.com/blang/semver v3.1.0+incompatible/go.mod h1:kRBLl5iJ+tD4TcOOxsy/0fnweb
 github.com/blang/semver v3.5.0+incompatible/go.mod h1:kRBLl5iJ+tD4TcOOxsy/0fnwebNt5EWlYSAyrTnjyyk=
 github.com/blang/semver v3.5.1+incompatible/go.mod h1:kRBLl5iJ+tD4TcOOxsy/0fnwebNt5EWlYSAyrTnjyyk=
 github.com/bmizerany/assert v0.0.0-20160611221934-b7ed37b82869/go.mod h1:Ekp36dRnpXw/yCqJaO+ZrUyxD+3VXMFFr56k5XYrpB4=
+github.com/bombsimon/logrusr/v2 v2.0.1 h1:1VgxVNQMCvjirZIYaT9JYn6sAVGVEcNtRE0y4mvaOAM=
+github.com/bombsimon/logrusr/v2 v2.0.1/go.mod h1:ByVAX+vHdLGAfdroiMg6q0zgq2FODY2lc5YJvzmOJio=
 github.com/bombsimon/wsl/v2 v2.0.0/go.mod h1:mf25kr/SqFEPhhcxW1+7pxzGlW+hIl/hYTKY95VwV8U=
 github.com/bombsimon/wsl/v2 v2.2.0/go.mod h1:Azh8c3XGEJl9LyX0/sFC+CKMc7Ssgua0g+6abzXN4Pg=
 github.com/bombsimon/wsl/v3 v3.0.0/go.mod h1:st10JtZYLE4D5sC7b8xV4zTKZwAQjCH/Hy2Pm1FNZIc=
@@ -584,6 +586,8 @@ github.com/go-logfmt/logfmt v0.3.0/go.mod h1:Qt1PoO58o5twSAckw1HlFXLmHsOX5/0LbT9
 github.com/go-logfmt/logfmt v0.4.0/go.mod h1:3RMwSq7FuexP4Kalkev3ejPJsZTpXXBr9+V4qmtdjCk=
 github.com/go-logr/logr v0.1.0/go.mod h1:ixOQHD9gLJUVQQ2ZOR7zLEifBX6tGkNJF4QyIY7sIas=
 github.com/go-logr/logr v0.2.0/go.mod h1:z6/tIYblkpsD+a4lm/fGIIU9mZ+XfAiaFtq7xTgseGU=
+github.com/go-logr/logr v1.0.0 h1:kH951GinvFVaQgy/ki/B3YYmQtRpExGigSJg6O8z5jo=
+github.com/go-logr/logr v1.0.0/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A=
 github.com/go-ole/go-ole v1.2.1/go.mod h1:7FAglXiTm7HKlQRDeOQ6ZNUHidzCWXuZWq/1dTyBNF8=
 github.com/go-openapi/jsonpointer v0.0.0-20160704185906-46af16f9f7b1/go.mod h1:+35s3my2LFTysnkMfxsJBAMHj/DoqoB9knIWoYG/Vk0=
 github.com/go-openapi/jsonpointer v0.19.2/go.mod h1:3akKfEdA7DF1sugOqz1dVQHBcuDBPKZGEoHC/NkiQRg=
@@ -1710,6 +1714,7 @@ golang.org/x/sys v0.0.0-20210503080704-8803ae5d1324/go.mod h1:h1NjWce9XRLGQEsW7w
 golang.org/x/sys v0.0.0-20210510120138-977fb7262007/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210514084401-e8d321eab015/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210603125802-9665404d3644/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/sys v0.0.0-20210608053332-aa57babbf139/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210616094352-59db8d763f22/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=

log/log.go

@@ -15,35 +15,55 @@
 package log
 
 import (
-	"fmt"
-
-	"go.uber.org/zap"
+	"github.com/bombsimon/logrusr/v2"
+	"github.com/go-logr/logr"
+	"github.com/sirupsen/logrus"
 	"go.uber.org/zap/zapcore"
 )
 
+// TODO(log): Remove zap logic
+
 // Logger exposes logging capabilities.
 // The struct name was chosen to closely mimic other logging facilities within
 // to project to make them easier to search/replace.
 // Initial implementation was designed to encapsulate calls to `zap`, but
 // future iterations will seek to directly expose logging methods.
 type Logger struct {
-	Zap *zap.Logger
+	*logr.Logger
+	// Zap *zap.Logger
 }
 
 // NewLogger creates an instance of *zap.Logger.
 // Copied from clients/githubrepo/client.go.
 func NewLogger(logLevel Level) (*Logger, error) {
-	zapCfg := zap.NewProductionConfig()
-	zapLevel := parseLogLevelZap(string(logLevel))
-	zapCfg.Level.SetLevel(zapLevel)
+	logrusLog := logrus.New()
+	log := logrusr.New(logrusLog)
 
-	zapLogger, err := zapCfg.Build()
-	if err != nil {
-		return nil, fmt.Errorf("configuring zap logger: %w", err)
-	}
+	// TODO(log): Consider adopting production config from zap
+	// NewProductionConfig is a reasonable production logging configuration.
+	// Logging is enabled at InfoLevel and above.
+	//
+	// It uses a JSON encoder, writes to standard error, and enables sampling.
+	// Stacktraces are automatically included on logs of ErrorLevel and above.
+	/*
+	   func NewProductionConfig() Config {
+	   	return Config{
+	   		Level:       NewAtomicLevelAt(InfoLevel),
+	   		Development: false,
+	   		Sampling: &SamplingConfig{
+	   			Initial:    100,
+	   			Thereafter: 100,
+	   		},
+	   		Encoding:         "json",
+	   		EncoderConfig:    NewProductionEncoderConfig(),
+	   		OutputPaths:      []string{"stderr"},
+	   		ErrorOutputPaths: []string{"stderr"},
+	   	}
+	   }
+	*/
 
 	logger := &Logger{
-		Zap: zapLogger,
+		&log,
 	}
 
 	return logger, nil