rocsp-tool: Add syslog support (#6010)

Add a logging stanza to rocsp-tool's config, and initialize a boulder
logger rather than using Go's default log facilities.

Fixes #5976

cmd/rocsp-tool/client.go

@@ -5,7 +5,6 @@ import (
 	"database/sql"
 	"fmt"
 	"io/ioutil"
-	"log"
 	"math/rand"
 	"strings"
 	"sync/atomic"
@@ -14,6 +13,7 @@ import (
 	"github.com/jmhodges/clock"
 	capb "github.com/letsencrypt/boulder/ca/proto"
 	"github.com/letsencrypt/boulder/core"
+	blog "github.com/letsencrypt/boulder/log"
 	"github.com/letsencrypt/boulder/rocsp"
 	rocsp_config "github.com/letsencrypt/boulder/rocsp/config"
 	"github.com/letsencrypt/boulder/sa"
@@ -28,6 +28,7 @@ type client struct {
 	ocspGenerator capb.OCSPGeneratorClient
 	clk           clock.Clock
 	scanBatchSize int
+	logger        blog.Logger
 }
 
 // processResult represents the result of attempting to sign and store status
@@ -107,18 +108,18 @@ func (cl *client) loadFromDB(ctx context.Context, speed ProcessingSpeed, startFr
 				(errorCount < 1000 && rand.Intn(1000) < 100) ||
 				(errorCount < 100000 && rand.Intn(1000) < 10) ||
 				(rand.Intn(1000) < 1) {
-				log.Printf("error: %s", result.err)
+				cl.logger.Errf("error: %s", result.err)
 			}
 		} else {
 			successCount++
 		}
 
 		if (successCount+errorCount)%10 == 0 {
-			log.Printf("stored %d responses, %d errors", successCount, errorCount)
+			cl.logger.Infof("stored %d responses, %d errors", successCount, errorCount)
 		}
 	}
 
-	log.Printf("done. processed %d successes and %d errors\n", successCount, errorCount)
+	cl.logger.Infof("done. processed %d successes and %d errors\n", successCount, errorCount)
 	if inflightIDs.len() != 0 {
 		return fmt.Errorf("inflightIDs non-empty! has %d items, lowest %d", inflightIDs.len(), inflightIDs.min())
 	}
@@ -140,7 +141,7 @@ func (cl *client) scanFromDB(ctx context.Context, prevID int64, maxID int64, fre
 		for currentMin < maxID {
 			currentMin, err = cl.scanFromDBOneBatch(ctx, currentMin, frequency, statusesToSign, inflightIDs)
 			if err != nil {
-				log.Printf("error scanning rows: %s", err)
+				cl.logger.Infof("error scanning rows: %s", err)
 			}
 		}
 	}()
@@ -163,7 +164,7 @@ func (cl *client) scanFromDBOneBatch(ctx context.Context, prevID int64, frequenc
 	defer func() {
 		rerr := rows.Close()
 		if rerr != nil {
-			log.Printf("closing rows: %s", rerr)
+			cl.logger.Infof("closing rows: %s", rerr)
 		}
 	}()
 
@@ -183,7 +184,7 @@ func (cl *client) scanFromDBOneBatch(ctx context.Context, prevID int64, frequenc
 		// will emit about 2150 log lines. This probably strikes a good balance
 		// between too spammy and having a reasonably frequent checkpoint.
 		if scanned%100000 == 0 {
-			log.Printf("scanned %d certificateStatus rows. minimum inflight ID %d", scanned, inflightIDs.min())
+			cl.logger.Infof("scanned %d certificateStatus rows. minimum inflight ID %d", scanned, inflightIDs.min())
 		}
 		output <- status
 		previousID = status.ID
@@ -288,7 +289,7 @@ func (cl *client) storeResponse(ctx context.Context, respBytes []byte, ttl *time
 		ttl = &ttl_temp
 	}
 
-	log.Printf("storing response for %s, generated %s, ttl %g hours",
+	cl.logger.Infof("storing response for %s, generated %s, ttl %g hours",
 		serial,
 		resp.ThisUpdate,
 		ttl.Hours(),
@@ -308,6 +309,6 @@ func (cl *client) storeResponse(ctx context.Context, respBytes []byte, ttl *time
 	if err != nil {
 		return fmt.Errorf("parsing retrieved response: %w", err)
 	}
-	log.Printf("retrieved %s", helper.PrettyResponse(parsedRetrievedResponse))
+	cl.logger.Infof("retrieved %s", helper.PrettyResponse(parsedRetrievedResponse))
 	return nil
 }

cmd/rocsp-tool/client_test.go

@@ -12,7 +12,7 @@ import (
 	capb "github.com/letsencrypt/boulder/ca/proto"
 	"github.com/letsencrypt/boulder/cmd"
 	"github.com/letsencrypt/boulder/core"
-	"github.com/letsencrypt/boulder/log"
+	blog "github.com/letsencrypt/boulder/log"
 	"github.com/letsencrypt/boulder/metrics"
 	"github.com/letsencrypt/boulder/rocsp"
 	rocsp_config "github.com/letsencrypt/boulder/rocsp/config"
@@ -52,7 +52,7 @@ func TestGetStartingID(t *testing.T) {
 	dbMap, err := sa.NewDbMap(vars.DBConnSAFullPerms, sa.DbSettings{})
 	test.AssertNotError(t, err, "failed setting up db client")
 	defer test.ResetSATestDatabase(t)()
-	sa.SetSQLDebug(dbMap, log.Get())
+	sa.SetSQLDebug(dbMap, blog.Get())
 
 	cs := core.CertificateStatus{
 		Serial:   "1337",
@@ -108,6 +108,7 @@ func TestStoreResponse(t *testing.T) {
 		db:            nil,
 		ocspGenerator: nil,
 		clk:           clk,
+		logger:        blog.NewMock(),
 	}
 
 	ttl := time.Hour
@@ -153,6 +154,7 @@ func TestLoadFromDB(t *testing.T) {
 		ocspGenerator: mockOCSPGenerator{},
 		clk:           clk,
 		scanBatchSize: 10,
+		logger:        blog.NewMock(),
 	}
 
 	speed := ProcessingSpeed{

cmd/rocsp-tool/main.go

@@ -6,7 +6,6 @@ import (
 	"encoding/base64"
 	"flag"
 	"fmt"
-	"log"
 	"math/rand"
 	"os"
 	"time"
@@ -25,6 +24,7 @@ import (
 
 type Config struct {
 	ROCSPTool struct {
+		cmd.ServiceConfig
 		Redis rocsp_config.RedisConfig
 		// Issuers is a map from filenames to short issuer IDs.
 		// Each filename must contain an issuer certificate. The short issuer
@@ -37,6 +37,7 @@ type Config struct {
 		// and the CA. Otherwise, it's optional.
 		LoadFromDB *LoadFromDBConfig
 	}
+	Syslog cmd.SyslogConfig
 }
 
 // LoadFromDBConfig provides the credentials and configuration needed to load
@@ -73,7 +74,7 @@ func init() {
 func main() {
 	err := main2()
 	if err != nil {
-		log.Fatal(err)
+		cmd.FailOnError(err, "")
 	}
 }
 
@@ -85,7 +86,6 @@ func main2() error {
 		flag.Usage()
 		os.Exit(1)
 	}
-
 	rand.Seed(time.Now().UnixNano())
 
 	var c Config
@@ -94,12 +94,16 @@ func main2() error {
 		return fmt.Errorf("reading JSON config file: %w", err)
 	}
 
+	_, logger := cmd.StatsAndLogging(c.Syslog, c.ROCSPTool.DebugAddr)
+	defer logger.AuditPanic()
+	logger.Info(cmd.VersionString())
+
 	issuers, err := rocsp_config.LoadIssuers(c.ROCSPTool.Issuers)
 	if err != nil {
 		return fmt.Errorf("loading issuers: %w", err)
 	}
 	if len(issuers) == 0 {
-		return fmt.Errorf("'issuers' section of config JSON is required.")
+		return fmt.Errorf("'issuers' section of config JSON is required")
 	}
 	clk := cmd.Clock()
 	redisClient, err := rocsp_config.MakeClient(&c.ROCSPTool.Redis, clk, metrics.NoopRegisterer)
@@ -140,6 +144,7 @@ func main2() error {
 		ocspGenerator: ocspGenerator,
 		clk:           clk,
 		scanBatchSize: scanBatchSize,
+		logger:        logger,
 	}
 	switch flag.Arg(0) {
 	case "get":
@@ -150,10 +155,10 @@ func main2() error {
 			}
 			parsed, err := ocsp.ParseResponse(resp, nil)
 			if err != nil {
-				log.Printf("parsing error on %x: %s", resp, err)
+				logger.Infof("parsing error on %x: %s", resp, err)
 				continue
 			} else {
-				log.Printf("%s", helper.PrettyResponse(parsed))
+				logger.Infof("%s", helper.PrettyResponse(parsed))
 			}
 		}
 	case "store":
@@ -173,21 +178,21 @@ func main2() error {
 		results := cl.redis.ScanMetadata(ctx, "*")
 		for r := range results {
 			if r.Err != nil {
-				log.Fatalf("scanning: %s", r.Err)
+				cmd.FailOnError(err, "while scanning")
 			}
 			age := clk.Now().Sub(r.Metadata.ThisUpdate)
-			fmt.Printf("%s: %g\n", r.Serial, age.Hours())
+			logger.Infof("%s: %g\n", r.Serial, age.Hours())
 		}
 	case "scan-responses":
 		results := cl.redis.ScanResponses(ctx, "*")
 		for r := range results {
 			if r.Err != nil {
-				log.Fatalf("scanning: %s", r.Err)
+				cmd.FailOnError(err, "while scanning")
 			}
-			fmt.Printf("%s: %s\n", r.Serial, base64.StdEncoding.EncodeToString(r.Body))
+			logger.Infof("%s: %s\n", r.Serial, base64.StdEncoding.EncodeToString(r.Body))
 		}
 	default:
-		fmt.Fprintf(os.Stderr, "unrecognized subcommand %q\n", flag.Arg(0))
+		logger.Errf("unrecognized subcommand %q\n", flag.Arg(0))
 		helpExit()
 	}
 	return nil

test/config/rocsp-tool.json

@@ -39,5 +39,9 @@
       ".hierarchy/intermediate-cert-rsa-a.pem": 3,
       ".hierarchy/intermediate-cert-rsa-b.pem": 4
     }
+  },
+  "syslog": {
+    "stdoutlevel": 6,
+    "sysloglevel": 6
   }
 }