Switch to logrus for structured logging

.golangci.yml

@@ -4,6 +4,7 @@ run:
     - pkg/config/amd64.go
     - pkg/config/arm64.go
     - pkg/config/armhf.go
+    - pkg/messages/resolver.msgpackgen.go
 
 output:
   sort-results: true

cmd/clientsim/main.go

@@ -22,13 +22,13 @@ package main
 import (
 	"context"
 	"fmt"
-	"log"
 	"os"
 	"sync"
 	"time"
 
 	"github.com/justincpresley/go-cobs"
 	"github.com/shamaton/msgpackgen/msgpack"
+	"github.com/sirupsen/logrus"
 
 	"git.cacert.org/cacert-gosigner/pkg/messages"
 )
@@ -38,20 +38,22 @@ const cobsDelimiter = 0x00
 var cobsConfig = cobs.Config{SpecialByte: cobsDelimiter, Delimiter: true, EndingSave: true}
 
 func main() {
-	errorLog := log.New(os.Stderr, "", log.LstdFlags)
+	logger := logrus.New()
+	logger.SetOutput(os.Stdout)
+	logger.SetLevel(logrus.InfoLevel)
 
 	sim := &clientSimulator{
-		errorLog: errorLog,
+		logger: logger,
 	}
 
 	err := sim.Run()
 	if err != nil {
-		errorLog.Printf("simulator returned an error: %v", err)
+		logger.Errorf("simulator returned an error: %v", err)
 	}
 }
 
 type clientSimulator struct {
-	errorLog  *log.Logger
+	logger    *logrus.Logger
 	commands  chan messages.Command
 	responses chan []byte
 }
@@ -139,7 +141,7 @@ func (c *clientSimulator) handleCommands(ctx context.Context) error {
 				return fmt.Errorf("could not unmarshal msgpack data: %w", err)
 			}
 
-			c.errorLog.Printf("received response: %+v", response)
+			c.logger.Errorf("received response: %+v", response)
 		case <-ctx.Done():
 			return nil
 		}
@@ -176,18 +178,18 @@ func (c *clientSimulator) Run() error {
 	var result error
 
 	if err := c.writeTestCommands(ctx); err != nil {
-		c.errorLog.Printf("test commands failed: %v", err)
+		c.logger.Errorf("test commands failed: %v", err)
 	}
 
 	cancel()
 	wg.Wait()
 
 	if inputError != nil {
-		c.errorLog.Printf("reading input failed: %v", inputError)
+		c.logger.Errorf("reading input failed: %v", inputError)
 	}
 
 	if commandError != nil {
-		c.errorLog.Printf("sending commands failed: %v", commandError)
+		c.logger.Errorf("sending commands failed: %v", commandError)
 	}
 
 	return result

cmd/signer/main.go

@@ -19,9 +19,10 @@ package main
 
 import (
 	"flag"
-	"log"
 	"os"
 
+	"github.com/sirupsen/logrus"
+
 	"git.cacert.org/cacert-gosigner/pkg/config"
 	"git.cacert.org/cacert-gosigner/pkg/health"
 	"git.cacert.org/cacert-gosigner/pkg/hsm"
@@ -42,19 +43,21 @@ const (
 func main() {
 	var (
 		showVersion, setupMode, verbose bool
-		signerConfigFile                string
+		signerConfigFile, logLevel      string
-		infoLog, errorLog               *log.Logger
+		logger                          *logrus.Logger
 	)
 
-	infoLog = log.New(os.Stdout, "INFO ", log.Ldate|log.Lmicroseconds|log.LUTC)
+	logger = logrus.New()
-	errorLog = log.New(os.Stderr, "ERROR ", log.Ldate|log.Lmicroseconds|log.LUTC)
+	logger.SetOutput(os.Stdout)
+	logger.SetLevel(logrus.InfoLevel)
 
-	infoLog.Printf("cacert-gosigner %s (%s) - built %s\n", version, commit, date)
+	logger.Infof("cacert-gosigner %s (%s) - built %s\n", version, commit, date)
 
 	flag.StringVar(&signerConfigFile, "config", defaultSignerConfigFile, "signer configuration file")
 	flag.BoolVar(&showVersion, "version", false, "show version")
 	flag.BoolVar(&setupMode, "setup", false, "setup mode")
 	flag.BoolVar(&verbose, "verbose", false, "verbose output")
+	flag.StringVar(&logLevel, "loglevel", "INFO", "log level")
 
 	flag.Parse()
 
@@ -62,9 +65,16 @@ func main() {
 		return
 	}
 
-	caConfig := LoadConfig(signerConfigFile, errorLog)
+	parsedLevel, err := logrus.ParseLevel(logLevel)
+	if err != nil {
+		logger.Fatalf("could not parse log level: %v", err)
+	}
 
-	access := initializeHSM(caConfig, setupMode, verbose, infoLog, errorLog)
+	logger.SetLevel(parsedLevel)
+
+	caConfig := LoadConfig(signerConfigFile, logger)
+
+	access := initializeHSM(caConfig, setupMode, verbose, logger)
 
 	if setupMode {
 		return
@@ -72,32 +82,32 @@ func main() {
 
 	healthHandler := health.New(version, access)
 
-	proto, err := protocol.New(infoLog, errorLog, protocol.RegisterHealthHandler(healthHandler))
+	proto, err := protocol.New(logger, protocol.RegisterHealthHandler(healthHandler))
 	if err != nil {
-		errorLog.Fatalf("could not setup protocol handler: %v", err)
+		logger.Fatalf("could not setup protocol handler: %v", err)
 	}
 
 	serialHandler, err := seriallink.New(caConfig.GetSerial(), proto)
 	if err != nil {
-		errorLog.Fatalf("could not setup serial link handler: %v", err)
+		logger.Fatalf("could not setup serial link handler: %v", err)
 	}
 
 	defer func() { _ = serialHandler.Close() }()
 
 	if err = serialHandler.Run(); err != nil {
-		errorLog.Fatalf("error in serial handler: %v", err)
+		logger.Fatalf("error in serial handler: %v", err)
 	}
 
-	infoLog.Print("setup complete, starting signer operation")
+	logger.Infof("setup complete, starting signer operation")
 }
 
-func initializeHSM(caConfig *config.SignerConfig, setupMode, verbose bool, infoLog, errorLog *log.Logger) *hsm.Access {
+func initializeHSM(caConfig *config.SignerConfig, setupMode, verbose bool, logger *logrus.Logger) *hsm.Access {
 	opts := make([]hsm.ConfigOption, 0)
 
 	opts = append(opts, hsm.CaConfigOption(caConfig))
 
 	if setupMode {
-		infoLog.Print("running in setup mode")
+		logger.Infof("running in setup mode")
 
 		opts = append(opts, hsm.SetupModeOption())
 	}
@@ -106,28 +116,28 @@ func initializeHSM(caConfig *config.SignerConfig, setupMode, verbose bool, infoL
 		opts = append(opts, hsm.VerboseLoggingOption())
 	}
 
-	access, err := hsm.NewAccess(infoLog, opts...)
+	access, err := hsm.NewAccess(logger, opts...)
 	if err != nil {
-		errorLog.Fatalf("could not setup HSM access: %v", err)
+		logger.Fatalf("could not setup HSM access: %v", err)
 	}
 
 	err = access.EnsureCAKeysAndCertificates()
 	if err != nil {
-		errorLog.Fatalf("could not ensure CA keys and certificates exist: %v", err)
+		logger.Fatalf("could not ensure CA keys and certificates exist: %v", err)
 	}
 
 	return access
 }
 
-func LoadConfig(signerConfigFile string, errorLog *log.Logger) *config.SignerConfig {
+func LoadConfig(signerConfigFile string, logger *logrus.Logger) *config.SignerConfig {
 	configFile, err := os.Open(signerConfigFile)
 	if err != nil {
-		errorLog.Fatalf("could not open signer configuration file %s: %v", signerConfigFile, err)
+		logger.Fatalf("could not open signer configuration file %s: %v", signerConfigFile, err)
 	}
 
 	caConfig, err := config.LoadConfiguration(configFile)
 	if err != nil {
-		errorLog.Fatalf("could not load CA hierarchy: %v", err)
+		logger.Fatalf("could not load CA hierarchy: %v", err)
 	}
 
 	return caConfig

go.mod

@@ -13,11 +13,13 @@ require (
 )
 
 require (
+	github.com/dave/jennifer v1.4.1 // indirect
 	github.com/davecgh/go-spew v1.1.1 // indirect
 	github.com/miekg/pkcs11 v1.1.1 // indirect
 	github.com/pkg/errors v0.9.1 // indirect
 	github.com/pmezard/go-difflib v1.0.0 // indirect
 	github.com/shamaton/msgpack/v2 v2.1.0 // indirect
+	github.com/sirupsen/logrus v1.9.0 // indirect
 	github.com/thales-e-security/pool v0.0.2 // indirect
-	golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1 // indirect
+	golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8 // indirect
 )

go.sum

@@ -1,5 +1,6 @@
 github.com/ThalesIgnite/crypto11 v1.2.5 h1:1IiIIEqYmBvUYFeMnHqRft4bwf/O36jryEUpY+9ef8E=
 github.com/ThalesIgnite/crypto11 v1.2.5/go.mod h1:ILDKtnCKiQ7zRoNxcp36Y1ZR8LBPmR2E23+wTQe/MlE=
+github.com/dave/jennifer v1.4.1 h1:XyqG6cn5RQsTj3qlWQTKlRGAyrTcsk1kUmWdZBzRjDw=
 github.com/dave/jennifer v1.4.1/go.mod h1:7jEdnm+qBcxl8PC0zyp7vxcpSRnzXSt9r39tpTVGlwA=
 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=
@@ -18,9 +19,12 @@ github.com/shamaton/msgpack/v2 v2.1.0 h1:9jJ2eGZw2Wa9KExPX3KaDDckVjgr4zhXGFCfWag
 github.com/shamaton/msgpack/v2 v2.1.0/go.mod h1:aTUEmh31ziGX1Ml7wMPLVY0f4vT3CRsCvZRoSCs+VGg=
 github.com/shamaton/msgpackgen v0.3.0 h1:q6o7prOEJFdF9BAPgkOtfzJbs55pQi7g44RUnEVUxtM=
 github.com/shamaton/msgpackgen v0.3.0/go.mod h1:fd99fDDuxuTiWzkHC59uEGzrt/WDu+ltGZTbEWwVXIc=
+github.com/sirupsen/logrus v1.9.0 h1:trlNQbNUG3OdDrDil03MCb1H2o9nJ1x4/5LYw7byDE0=
+github.com/sirupsen/logrus v1.9.0/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ=
 github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
 github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw=
 github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=
+github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
 github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
 github.com/stretchr/testify v1.8.0 h1:pSgiaMZlXftHpm5L7V1+rVB+AZJydKsMxsQBIJw4PKk=
 github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU=
@@ -30,6 +34,8 @@ github.com/thales-e-security/pool v0.0.2 h1:RAPs4q2EbWsTit6tpzuvTFlgFRJ3S8Evf5gt
 github.com/thales-e-security/pool v0.0.2/go.mod h1:qtpMm2+thHtqhLzTwgDBj/OuNnMpupY8mv0Phz0gjhU=
 golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1 h1:SrN+KX8Art/Sf4HNj6Zcz06G7VEz+7w9tdXTPOZ7+l4=
 golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8 h1:0A+M6Uqn+Eje4kHMK80dtF3JCXC4ykBgQG4Fe06QRhQ=
+golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/term v0.0.0-20220411215600-e5f449aeb171 h1:EH1Deb8WZJ0xc0WK//leUHXcX9aLE5SymusoTmMZye8=
 golang.org/x/term v0.0.0-20220411215600-e5f449aeb171/go.mod h1:jbD1KX2456YbFQfuXm/mYQcufACuNUgVhRMnK/tPxf8=
 gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM=

pkg/hsm/context_test.go

@@ -19,13 +19,13 @@ package hsm_test
 
 import (
 	"fmt"
-	"log"
 	"os"
 	"os/exec"
 	"path"
 	"strings"
 	"testing"
 
+	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 
@@ -36,42 +36,42 @@ import (
 func TestCaConfigOption(t *testing.T) {
 	testSignerConfig := config.SignerConfig{}
 
-	access, err := hsm.NewAccess(log.Default(), hsm.CaConfigOption(&testSignerConfig))
+	access, err := hsm.NewAccess(logrus.StandardLogger(), hsm.CaConfigOption(&testSignerConfig))
 	assert.NoError(t, err)
 
 	assert.Equal(t, &testSignerConfig, access.GetSignerConfig())
 }
 
 func TestGetSignerConfig_empty(t *testing.T) {
-	access, err := hsm.NewAccess(log.Default())
+	access, err := hsm.NewAccess(logrus.StandardLogger())
 	assert.NoError(t, err)
 
 	assert.Nil(t, access.GetSignerConfig())
 }
 
 func TestSetupModeOption(t *testing.T) {
-	access, err := hsm.NewAccess(log.Default(), hsm.SetupModeOption())
+	access, err := hsm.NewAccess(logrus.StandardLogger(), hsm.SetupModeOption())
 	assert.NoError(t, err)
 
 	assert.True(t, access.IsSetupMode())
 }
 
 func TestIsSetupMode_not_set(t *testing.T) {
-	access, err := hsm.NewAccess(log.Default())
+	access, err := hsm.NewAccess(logrus.StandardLogger())
 	assert.NoError(t, err)
 
 	assert.False(t, access.IsSetupMode())
 }
 
 func TestVerboseLoggingOption(t *testing.T) {
-	access, err := hsm.NewAccess(log.Default(), hsm.VerboseLoggingOption())
+	access, err := hsm.NewAccess(logrus.StandardLogger(), hsm.VerboseLoggingOption())
 	assert.NoError(t, err)
 
 	assert.True(t, access.IsVerbose())
 }
 
 func TestIsVerbose_not_set(t *testing.T) {
-	access, err := hsm.NewAccess(log.Default())
+	access, err := hsm.NewAccess(logrus.StandardLogger())
 	assert.NoError(t, err)
 
 	assert.False(t, access.IsVerbose())
@@ -81,7 +81,7 @@ func TestSetupContext(t *testing.T) {
 	testConfig := setupSignerConfig(t)
 
 	access, err := hsm.NewAccess(
-		log.Default(),
+		logrus.StandardLogger(),
 		hsm.SetupModeOption(),
 		hsm.VerboseLoggingOption(),
 		hsm.CaConfigOption(testConfig),
@@ -96,7 +96,7 @@ func TestSetupContext(t *testing.T) {
 func TestGetP11Context_unknown_storage(t *testing.T) {
 	testConfig := setupSignerConfig(t)
 
-	access, err := hsm.NewAccess(log.Default(), hsm.SetupModeOption(), hsm.CaConfigOption(testConfig))
+	access, err := hsm.NewAccess(logrus.StandardLogger(), hsm.SetupModeOption(), hsm.CaConfigOption(testConfig))
 	assert.NoError(t, err)
 
 	definition := &config.CaCertificateEntry{Storage: "undefined"}
@@ -114,7 +114,7 @@ func TestGetP11Context_wrong_pin(t *testing.T) {
 
 	t.Setenv("TOKEN_PIN_ACME_TEST_HSM", "wrongpin")
 
-	access, err := hsm.NewAccess(log.Default(), hsm.CaConfigOption(testConfig))
+	access, err := hsm.NewAccess(logrus.StandardLogger(), hsm.CaConfigOption(testConfig))
 	assert.NoError(t, err)
 
 	definition, err := testConfig.GetCADefinition("root")
@@ -130,7 +130,7 @@ func TestGetP11Context_no_pin(t *testing.T) {
 	testConfig := setupSignerConfig(t)
 	setupSoftHsm(t)
 
-	access, err := hsm.NewAccess(log.Default(), hsm.CaConfigOption(testConfig))
+	access, err := hsm.NewAccess(logrus.StandardLogger(), hsm.CaConfigOption(testConfig))
 	assert.NoError(t, err)
 
 	definition, err := testConfig.GetCADefinition("root")
@@ -148,7 +148,7 @@ func TestGetP11Context(t *testing.T) {
 
 	t.Setenv("TOKEN_PIN_ACME_TEST_HSM", "123456")
 
-	access, err := hsm.NewAccess(log.Default(), hsm.CaConfigOption(testConfig))
+	access, err := hsm.NewAccess(logrus.StandardLogger(), hsm.CaConfigOption(testConfig))
 	assert.NoError(t, err)
 
 	definition, err := testConfig.GetCADefinition("root")

pkg/hsm/hsm.go

@@ -28,7 +28,6 @@ import (
 	"encoding/pem"
 	"errors"
 	"fmt"
-	"log"
 	"math/big"
 	"os"
 	"path"
@@ -36,6 +35,7 @@ import (
 	"time"
 
 	"github.com/ThalesIgnite/crypto11"
+	"github.com/sirupsen/logrus"
 
 	"git.cacert.org/cacert-gosigner/pkg/health"
 
@@ -56,7 +56,7 @@ type caFile struct {
 }
 
 type Access struct {
-	infoLog      *log.Logger
+	logger       *logrus.Logger
 	caDirectory  string
 	signerConfig *config.SignerConfig
 	p11Contexts  map[string]*crypto11.Context
@@ -118,8 +118,8 @@ func (a *Access) Healthy() (*health.Info, error) {
 	}, nil
 }
 
-func NewAccess(infoLog *log.Logger, options ...ConfigOption) (*Access, error) {
+func NewAccess(logger *logrus.Logger, options ...ConfigOption) (*Access, error) {
-	access := &Access{infoLog: infoLog}
+	access := &Access{logger: logger}
 	access.setupContext(options...)
 
 	return access, nil

pkg/hsm/hsm_test.go

@@ -19,10 +19,10 @@ package hsm_test
 
 import (
 	"crypto/x509"
-	"log"
 	"strings"
 	"testing"
 
+	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 
@@ -36,7 +36,7 @@ func TestEnsureCAKeysAndCertificates_not_in_setup_mode(t *testing.T) {
 
 	t.Setenv("TOKEN_PIN_ACME_TEST_HSM", "123456")
 
-	acc, err := hsm.NewAccess(log.Default(),
+	acc, err := hsm.NewAccess(logrus.StandardLogger(),
 		hsm.CaConfigOption(testConfig),
 		hsm.CADirectoryOption(t.TempDir()))
 	assert.NoError(t, err)
@@ -59,7 +59,7 @@ func prepareSoftHSM(t *testing.T) *hsm.Access {
 
 	t.Setenv("TOKEN_PIN_ACME_TEST_HSM", "123456")
 
-	acc, err := hsm.NewAccess(log.Default(),
+	acc, err := hsm.NewAccess(logrus.StandardLogger(),
 		hsm.CaConfigOption(testConfig),
 		hsm.SetupModeOption(),
 		hsm.CADirectoryOption(t.TempDir()))
@@ -180,7 +180,7 @@ KeyStorage:
 	t.Setenv("TOKEN_PIN_ACME_TEST_HSM", "123456")
 
 	acc, err := hsm.NewAccess(
-		log.Default(),
+		logrus.StandardLogger(),
 		hsm.CaConfigOption(testConfig),
 		hsm.SetupModeOption(),
 		hsm.CADirectoryOption(t.TempDir()))

pkg/hsm/setup.go

@@ -29,7 +29,7 @@ func (a *Access) EnsureCAKeysAndCertificates() error {
 		}
 
 		if a.IsVerbose() {
-			a.infoLog.Printf(
+			a.logger.Infof(
 				"found root CA certificate %s:\n Subject %s\n Issuer %s\n Valid from %s until %s\n Serial %s",
 				label,
 				crt.Subject,
@@ -38,7 +38,7 @@ func (a *Access) EnsureCAKeysAndCertificates() error {
 				crt.NotAfter,
 				crt.SerialNumber)
 		} else {
-			a.infoLog.Printf("found root CA certificate %s: %s", label, crt.Subject.CommonName)
+			a.logger.Infof("found root CA certificate %s: %s", label, crt.Subject.CommonName)
 		}
 	}
 
@@ -49,7 +49,7 @@ func (a *Access) EnsureCAKeysAndCertificates() error {
 		}
 
 		if a.IsVerbose() {
-			a.infoLog.Printf(
+			a.logger.Infof(
 				"found subordinate CA certificate %s:\n Subject %s\n Issuer %s\n Valid from %s until %s\n Serial %s",
 				label,
 				crt.Subject,
@@ -58,7 +58,7 @@ func (a *Access) EnsureCAKeysAndCertificates() error {
 				crt.NotAfter,
 				crt.SerialNumber)
 		} else {
-			a.infoLog.Printf("found subordinate CA certificate %s: %s", label, crt.Subject.CommonName)
+			a.logger.Infof("found subordinate CA certificate %s: %s", label, crt.Subject.CommonName)
 		}
 	}
 

pkg/hsm/setup_test.go

@@ -19,9 +19,9 @@ package hsm_test
 
 import (
 	"bytes"
-	"log"
 	"testing"
 
+	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/assert"
 
 	"git.cacert.org/cacert-gosigner/pkg/hsm"
@@ -35,7 +35,8 @@ func TestEnsureCAKeysAndCertificates(t *testing.T) {
 
 	buf := bytes.NewBuffer(nil)
 
-	testLogger := log.New(buf, "TEST ", log.LstdFlags)
+	testLogger := logrus.New()
+	testLogger.SetOutput(buf)
 
 	acc, err := hsm.NewAccess(testLogger, hsm.CaConfigOption(testConfig),
 		hsm.SetupModeOption(),
@@ -66,7 +67,8 @@ func TestEnsureCAKeysAndCertificates_verbose(t *testing.T) {
 
 	buf := bytes.NewBuffer(nil)
 
-	testLogger := log.New(buf, "TEST ", log.LstdFlags)
+	testLogger := logrus.New()
+	testLogger.SetOutput(buf)
 
 	acc, err := hsm.NewAccess(testLogger, hsm.CaConfigOption(testConfig),
 		hsm.SetupModeOption(),
@@ -84,6 +86,6 @@ func TestEnsureCAKeysAndCertificates_verbose(t *testing.T) {
 	output := buf.String()
 
 	assert.NoError(t, err)
-	assert.Contains(t, output, "found root CA certificate root:\n Subject")
+	assert.Contains(t, output, "found root CA certificate root:\\n Subject")
-	assert.Contains(t, output, "found subordinate CA certificate sub1:\n Subject")
+	assert.Contains(t, output, "found subordinate CA certificate sub1:\\n Subject")
 }

pkg/hsm/storage.go

@@ -20,12 +20,12 @@ package hsm
 import (
 	"errors"
 	"fmt"
-	"log"
 	"os"
 	"strings"
 	"syscall"
 
 	"github.com/ThalesIgnite/crypto11"
+	"github.com/sirupsen/logrus"
 	"golang.org/x/term"
 )
 
@@ -45,10 +45,10 @@ func (a *Access) prepareCrypto11Context(label string) (*crypto11.Context, error)
 		TokenLabel: storage.Label,
 	}
 
-	a.infoLog.Printf("using PKCS#11 module %s", p11Config.Path)
+	a.logger.Infof("using PKCS#11 module %s", p11Config.Path)
-	a.infoLog.Printf("looking for token with label %s", p11Config.TokenLabel)
+	a.logger.Infof("looking for token with label %s", p11Config.TokenLabel)
 
-	p11Config.Pin, err = getPin(p11Config, a.infoLog)
+	p11Config.Pin, err = getPin(p11Config, a.logger)
 	if err != nil {
 		return nil, err
 	}
@@ -61,7 +61,7 @@ func (a *Access) prepareCrypto11Context(label string) (*crypto11.Context, error)
 	return p11Context, nil
 }
 
-func getPin(p11Config *crypto11.Config, infoLog *log.Logger) (string, error) {
+func getPin(p11Config *crypto11.Config, logger *logrus.Logger) (string, error) {
 	var err error
 
 	tokenPinEnv := strings.NewReplacer(
@@ -75,7 +75,7 @@ func getPin(p11Config *crypto11.Config, infoLog *log.Logger) (string, error) {
 
 	pin, found := os.LookupEnv(tokenPinEnv)
 	if !found {
-		infoLog.Printf("environment variable %s has not been set", tokenPinEnv)
+		logger.Warnf("environment variable %s has not been set", tokenPinEnv)
 
 		if !term.IsTerminal(syscall.Stdin) {
 			return "", errors.New("stdin is not a terminal")

pkg/messages/messages.go

@@ -22,6 +22,7 @@ package messages
 
 import (
 	"fmt"
+	"strings"
 	"time"
 )
 
@@ -53,18 +54,47 @@ const (
 	RspHealth ResponseCode = iota
 )
 
+func (r ResponseCode) String() string {
+	switch r {
+	case RspError:
+		return "ERROR"
+	case RspHealth:
+		return "HEALTH"
+	default:
+		return fmt.Sprintf("unknown (%d)", int(r))
+	}
+}
+
 type Response struct {
 	Code      ResponseCode `msgpack:"code"`
 	TimeStamp time.Time    `msgpack:"created"`
 	Payload   interface{}  `msgpack:"payload"`
 }
 
+func (r *Response) String() string {
+	return fmt.Sprintf("[%s] at %s: %+v", r.Code, r.TimeStamp, r.Payload)
+}
+
 type HealthInfo struct {
 	Source   string
 	Healthy  bool
 	MoreInfo map[string]string
 }
 
+func (i *HealthInfo) String() string {
+	builder := &strings.Builder{}
+
+	_, _ = fmt.Fprintf(builder, "source: %s, healthy: %v, [\n", i.Source, i.Healthy)
+
+	for k, v := range i.MoreInfo {
+		_, _ = fmt.Fprintf(builder, "  %s: '%s'\n", k, v)
+	}
+
+	_, _ = builder.WriteRune(']')
+
+	return builder.String()
+}
+
 type HealthResponse struct {
 	Version string `msgpack:"version"`
 	Healthy bool

pkg/messages/resolver.msgpackgen.go

@@ -4,7 +4,6 @@ package messages
 
 import (
 	"fmt"
-
 	msgpack "github.com/shamaton/msgpackgen/msgpack"
 	dec "github.com/shamaton/msgpackgen/msgpack/dec"
 	enc "github.com/shamaton/msgpackgen/msgpack/enc"

pkg/protocol/protocol.go

@@ -20,10 +20,10 @@ package protocol
 
 import (
 	"fmt"
-	"log"
 	"time"
 
 	"github.com/shamaton/msgpackgen/msgpack"
+	"github.com/sirupsen/logrus"
 
 	"git.cacert.org/cacert-gosigner/pkg/health"
 	"git.cacert.org/cacert-gosigner/pkg/messages"
@@ -35,7 +35,7 @@ type Handler interface {
 }
 
 type MsgPackHandler struct {
-	infoLog, errorLog *log.Logger
+	logger        *logrus.Logger
 	healthHandler *health.Handler
 }
 
@@ -44,7 +44,7 @@ func (m *MsgPackHandler) HandleFrame(frame []byte) ([]byte, error) {
 
 	err := msgpack.Unmarshal(frame, &command)
 	if err != nil {
-		m.errorLog.Printf("unmarshal failed: %v", err)
+		m.logger.Errorf("unmarshal failed: %v", err)
 
 		errorResponse, innerErr := buildErrorResponse("do not understand")
 		if innerErr != nil {
@@ -54,11 +54,11 @@ func (m *MsgPackHandler) HandleFrame(frame []byte) ([]byte, error) {
 		return errorResponse, nil
 	}
 
-	m.infoLog.Printf("Received %s command sent at %s", command.Code, command.TimeStamp)
+	m.logger.Infof("Received %s command sent at %s", command.Code, command.TimeStamp)
 
 	response, err := m.handleCommand(&command)
 	if err != nil {
-		m.errorLog.Printf("command failed: %v", err)
+		m.logger.Errorf("command failed: %v", err)
 
 		errorResponse, innerErr := buildErrorResponse("command failed")
 		if innerErr != nil {
@@ -130,12 +130,11 @@ func buildErrorResponse(errMsg string) ([]byte, error) {
 	return marshal, nil
 }
 
-func New(infoLog *log.Logger, errorLog *log.Logger, handlers ...RegisterHandler) (Handler, error) {
+func New(logger *logrus.Logger, handlers ...RegisterHandler) (Handler, error) {
 	messages.RegisterGeneratedResolver()
 
 	h := &MsgPackHandler{
-		infoLog:  infoLog,
+		logger: logger,
-		errorLog: errorLog,
 	}
 
 	for _, reg := range handlers {