Replace logrus with zap logging
logrus is in maintenance-mode and links to zap and others by itself.
zap has some really good benchmarks and default log output looks a little bit cleaner.
So let's move to zap logging.
Reviewed at https://reviews.imfreedom.org/r/2413/
--- a/access/access.go Fri Mar 31 16:37:25 2023 -0500
+++ b/access/access.go Fri Mar 31 16:55:53 2023 -0500
@@ -7,7 +7,7 @@
- log "github.com/sirupsen/logrus"
@@ -42,7 +42,7 @@
if err := os.Remove(hgwebConfigPath); err != nil {
"failed to remove temporary hgweb config from %q",
@@ -93,7 +93,7 @@
r, err := enforcer.Enforce(user, repo, action)
"failed to authenticate (%q, %q, %q): %v",
--- a/access/enforcer.go Fri Mar 31 16:37:25 2023 -0500
+++ b/access/enforcer.go Fri Mar 31 16:55:53 2023 -0500
@@ -5,7 +5,7 @@
"github.com/casbin/casbin/v2"
- log "github.com/sirupsen/logrus"
@@ -20,12 +20,12 @@
modelFile := filepath.Join(AdminRepoPath(), modelFilename)
policyFile := filepath.Join(AdminRepoPath(), policyFilename)
- log.Debugf("reading model from %q", modelFile)
- log.Debugf("reading policy from %q", policyFile)
+ zap.S().Debugf("reading model from %q", modelFile) + zap.S().Debugf("reading policy from %q", policyFile) e, err := casbin.NewEnforcer(modelFile, policyFile)
- log.Errorf("failed to create new enforcer: %v", err)
+ zap.S().Errorf("failed to create new enforcer: %v", err) --- a/access/users.go Fri Mar 31 16:37:25 2023 -0500
+++ b/access/users.go Fri Mar 31 16:55:53 2023 -0500
@@ -8,7 +8,7 @@
- log "github.com/sirupsen/logrus"
"golang.org/x/crypto/ssh"
@@ -33,7 +33,7 @@
if _, err := os.Stat(keysPath); err != nil {
- log.Error("keys directory not found, no one will be to access hgkeeper")
+ zap.S().Error("keys directory not found, no one will be to access hgkeeper") @@ -56,7 +56,7 @@
func loadSshKey(filename, username string) {
buffer, err := ioutil.ReadFile(filename)
- log.Warnf("failed to read keyfile for user %s: %v", username, err)
+ zap.S().Warnf("failed to read keyfile for user %s: %v", username, err) @@ -68,7 +68,7 @@
pubkey, _, _, buffer, err = ssh.ParseAuthorizedKey(buffer)
if !strings.HasSuffix(err.Error(), "ssh: no key found") {
- log.Warnf("failed to parse key file for user %s: %v", username, err)
+ zap.S().Warnf("failed to parse key file for user %s: %v", username, err) @@ -76,7 +76,7 @@
fingerprint := ssh.FingerprintSHA256(pubkey)
if duppedname, found := usernames[fingerprint]; found {
"duplicate key found for user %s. existing key was for %s.",
@@ -88,7 +88,7 @@
- log.Infof("loaded %d keys for user %q", counter, username)
+ zap.S().Infof("loaded %d keys for user %q", counter, username) // UsernameFromFingerprint looks up a username from an SSH key's fingerprint
--- a/authorized_keys/command.go Fri Mar 31 16:37:25 2023 -0500
+++ b/authorized_keys/command.go Fri Mar 31 16:55:53 2023 -0500
@@ -4,8 +4,7 @@
- log "github.com/sirupsen/logrus"
"keep.imfreedom.org/grim/hgkeeper/access"
"keep.imfreedom.org/grim/hgkeeper/globals"
@@ -18,7 +17,8 @@
func (c *Command) Run(g *globals.Globals) error {
// we're generating output for another command so we need to turn off our
- log.SetLevel(log.FatalLevel)
+ logger, _ := zap.Config{}.Build() + zap.ReplaceGlobals(logger) if err := access.Setup(g.ReposPath, g.AdminRepo); err != nil {
--- a/go.mod Fri Mar 31 16:37:25 2023 -0500
+++ b/go.mod Fri Mar 31 16:55:53 2023 -0500
@@ -5,8 +5,8 @@
github.com/casbin/casbin/v2 v2.65.2
github.com/gliderlabs/ssh v0.3.5
github.com/kballard/go-shellquote v0.0.0-20180428030007-95032a82bc51
- github.com/sirupsen/logrus v1.9.0
- github.com/stretchr/testify v1.7.0
+ github.com/stretchr/testify v1.8.0 + go.uber.org/zap v1.24.0 golang.org/x/crypto v0.7.0
@@ -16,8 +16,10 @@
github.com/anmitsu/go-shlex v0.0.0-20200514113438-38f4b401e2be // indirect
github.com/davecgh/go-spew v1.1.1 // indirect
github.com/pmezard/go-difflib v1.0.0 // indirect
+ go.uber.org/atomic v1.10.0 // indirect + go.uber.org/multierr v1.11.0 // indirect golang.org/x/sys v0.6.0 // indirect
- gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b // indirect
+ gopkg.in/yaml.v3 v3.0.1 // indirect --- a/go.sum Fri Mar 31 16:37:25 2023 -0500
+++ b/go.sum Fri Mar 31 16:55:53 2023 -0500
@@ -20,11 +20,23 @@
github.com/kballard/go-shellquote v0.0.0-20180428030007-95032a82bc51/go.mod h1:CzGEWj7cYgsdH8dAjBGEr58BoE7ScuLd+fwFZ44+/x8=
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/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 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5CcY=
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/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU= +go.uber.org/atomic v1.7.0 h1:ADUqmZGgLDDfbSL9ZmPxKTybcoEYHgpYfELNoN+7hsw= +go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc= +go.uber.org/atomic v1.10.0 h1:9qC72Qh0+3MqyJbAn8YU5xVq1frD8bn3JtD2oXtafVQ= +go.uber.org/atomic v1.10.0/go.mod h1:LUxbIzbOniOlMKjJjyPfpl4v+PKK2cNJn91OQbhoJI0= +go.uber.org/multierr v1.6.0 h1:y6IPFStTAIT5Ytl7/XYmHvzXQ7S3g/IeZW9hyZ5thw4= +go.uber.org/multierr v1.6.0/go.mod h1:cdWPpRnG4AhwMwsgIHip0KRBQjJy5kYEpYjJxpXp9iU= +go.uber.org/multierr v1.11.0 h1:blXXJkSxSSfBVBlC76pxqeO+LN3aDfLQo+309xJstO0= +go.uber.org/multierr v1.11.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y= +go.uber.org/zap v1.24.0 h1:FiJd5l1UOLj0wCgbSE0rwwXHzEdAZS6hiiSnxJN/D60= +go.uber.org/zap v1.24.0/go.mod h1:2kMP+WWQ8aoFoedH3T2sq6iJ2yDWpHbP0f6MQbS9Gkg= golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
golang.org/x/crypto v0.0.0-20220826181053-bd7e27e6170d/go.mod h1:IxCIyHEi3zRg3s0A5j5BB6A9Jmi73HwBIUl50j+osU4=
golang.org/x/crypto v0.7.0 h1:AvwMYaRytfdeVt3u6mLaxYtErKYjxA2OXjJ1HHq6t3A=
@@ -58,3 +70,4 @@
gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b h1:h8qDotaEPuJATrMmW04NCwg7v22aHH28wwpauUhK9Oo=
gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
+gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= --- a/hg/hg.go Fri Mar 31 16:37:25 2023 -0500
+++ b/hg/hg.go Fri Mar 31 16:55:53 2023 -0500
@@ -9,7 +9,7 @@
- log "github.com/sirupsen/logrus"
"keep.imfreedom.org/grim/hgkeeper/access"
@@ -69,7 +69,7 @@
func (c *Command) Teardown() {
if err := os.Remove(c.tmpHgrc); err != nil {
- log.Warnf("failed to remove %q: %v", c.tmpHgrc, err)
+ zap.S().Warnf("failed to remove %q: %v", c.tmpHgrc, err) @@ -117,21 +117,21 @@
if _, err := io.Copy(pstdin, stdin); err != nil {
- log.Errorf("Failed to read stdin: %v", err)
+ zap.S().Errorf("Failed to read stdin: %v", err) if _, err := io.Copy(stdout, pstdout); err != nil {
- log.Errorf("Failed to write stdout: %v", err)
+ zap.S().Errorf("Failed to write stdout: %v", err) if _, err := io.Copy(stderr, pstderr); err != nil {
- log.Errorf("Failed to write stderr: %v", err)
+ zap.S().Errorf("Failed to write stderr: %v", err) --- a/hg/hgweb.go Fri Mar 31 16:37:25 2023 -0500
+++ b/hg/hgweb.go Fri Mar 31 16:55:53 2023 -0500
@@ -5,7 +5,7 @@
- log "github.com/sirupsen/logrus"
func TemplatesDir() (string, error) {
@@ -13,7 +13,7 @@
if err != nil || templatesDir == "" {
- log.Warnf("failed to read web.templates setting from hg: %v", err)
+ zap.S().Warnf("failed to read web.templates setting from hg: %v", err) @@ -27,7 +27,7 @@
raw, err := cmd.CombinedOutput()
- log.Debugf("raw: %#v\n", string(raw))
+ zap.S().Debugf("raw: %#v\n", string(raw)) @@ -36,7 +36,7 @@
return "", fmt.Errorf("failed to find the templates directory")
- log.Infof("using %s as the templates directory\n", templatesDir)
+ zap.S().Infof("using %s as the templates directory\n", templatesDir) --- a/http/authorized_keys.go Fri Mar 31 16:37:25 2023 -0500
+++ b/http/authorized_keys.go Fri Mar 31 16:55:53 2023 -0500
@@ -5,8 +5,7 @@
- log "github.com/sirupsen/logrus"
"keep.imfreedom.org/grim/hgkeeper/access"
@@ -25,7 +24,7 @@
w.WriteHeader(http.StatusNotFound)
fmt.Fprintf(w, "failed to find fingerprint %q", fp)
- log.Errorf("failed to find fingerprint for %s: %v", fp, err)
+ zap.S().Errorf("failed to find fingerprint for %s: %v", fp, err) --- a/http/logger.go Fri Mar 31 16:37:25 2023 -0500
+++ b/http/logger.go Fri Mar 31 16:55:53 2023 -0500
@@ -5,7 +5,7 @@
- log "github.com/sirupsen/logrus"
type loggerResponseWriter struct {
@@ -99,7 +99,7 @@
"%s - %s [%s] \"%s %s %s\" %d %d %q %q\n",
--- a/http/server.go Fri Mar 31 16:37:25 2023 -0500
+++ b/http/server.go Fri Mar 31 16:55:53 2023 -0500
@@ -4,7 +4,7 @@
- log "github.com/sirupsen/logrus"
"keep.imfreedom.org/grim/hgkeeper/hg"
"keep.imfreedom.org/grim/hgkeeper/hgweb"
@@ -42,7 +42,7 @@
staticPath := filepath.Join(templatesDir, "static")
- log.Infof("serving static files from %s", staticPath)
+ zap.S().Infof("serving static files from %s", staticPath) fileServer := http.FileServer(http.Dir(staticPath))
mux := http.NewServeMux()
@@ -51,27 +51,27 @@
if s.externalHostname != "" {
mux.Handle("/hgk/authorized_keys", authorizedKeysHandler(s.externalHostname, s.externalPort))
- log.Infof("added /hgk/authorized_keys endpoint with external hostname %s and export port %s", s.externalHostname, s.externalPort)
+ zap.S().Infof("added /hgk/authorized_keys endpoint with external hostname %s and export port %s", s.externalHostname, s.externalPort) - log.Infof("no external hostname specified, not adding /hgk/authorized_keys endpoint")
+ zap.S().Infof("no external hostname specified, not adding /hgk/authorized_keys endpoint") mux.Handle("/static/", http.StripPrefix("/static", fileServer))
- log.Infof("enabling HGWeb CGI server")
+ zap.S().Infof("enabling HGWeb CGI server") hgwHandler, err := s.hgw.Handler()
mux.Handle("/", hgwHandler)
- log.Infof("not enabling HGWeb CGI server as requested")
+ zap.S().Infof("not enabling HGWeb CGI server as requested") s.server.Handler = Logger(mux)
- log.Infof("http listening on %s", s.listenAddr)
+ zap.S().Infof("http listening on %s", s.listenAddr) return s.server.ListenAndServe()
@@ -79,11 +79,11 @@
func (s *Server) Close() {
if err := s.hgw.Close(); err != nil {
- log.Warnf("failed to close hgweb: %v", err)
+ zap.S().Warnf("failed to close hgweb: %v", err) if err := s.server.Close(); err != nil {
- log.Warnf("failed to shutdown http server: %v", err)
+ zap.S().Warnf("failed to shutdown http server: %v", err) --- a/main.go Fri Mar 31 16:37:25 2023 -0500
+++ b/main.go Fri Mar 31 16:55:53 2023 -0500
@@ -4,7 +4,8 @@
"github.com/alecthomas/kong"
- log "github.com/sirupsen/logrus"
+ "go.uber.org/zap/zapcore" "keep.imfreedom.org/grim/hgkeeper/authorized_keys"
"keep.imfreedom.org/grim/hgkeeper/globals"
@@ -26,18 +27,32 @@
- log.SetOutput(os.Stdout)
- log.SetLevel(log.DebugLevel)
- fmter := &log.TextFormatter{
+ levelEncoder := zapcore.CapitalColorLevelEncoder switch os.Getenv("TERM") {
- fmter.DisableColors = true
+ levelEncoder = zapcore.CapitalLevelEncoder - log.SetFormatter(fmter)
+ logger, _ := zap.Config{ + Level: zap.NewAtomicLevelAt(zapcore.DebugLevel), + OutputPaths: []string{"stdout"}, + ErrorOutputPaths: []string{"stderr"}, + EncoderConfig: zapcore.EncoderConfig{ + EncodeLevel: levelEncoder, + EncodeTime: zapcore.ISO8601TimeEncoder, + zap.ReplaceGlobals(logger) --- a/serve/command.go Fri Mar 31 16:37:25 2023 -0500
+++ b/serve/command.go Fri Mar 31 16:55:53 2023 -0500
@@ -6,7 +6,7 @@
- log "github.com/sirupsen/logrus"
"keep.imfreedom.org/grim/hgkeeper/access"
"keep.imfreedom.org/grim/hgkeeper/globals"
@@ -42,7 +42,7 @@
var sshServer *ssh.Server
- log.Info("SSH server has been disabled")
+ zap.S().Info("SSH server has been disabled") sshServer, err = ssh.NewServer(c.SSHHostKeysPath, g.ReposPath, access.AdminRepoPath())
@@ -79,7 +79,7 @@
- log.Infof("Captured %v signal. Exiting...", s)
+ zap.S().Infof("Captured %v signal. Exiting...", s) --- a/ssh/commands/init.go Fri Mar 31 16:37:25 2023 -0500
+++ b/ssh/commands/init.go Fri Mar 31 16:55:53 2023 -0500
@@ -5,7 +5,7 @@
"github.com/gliderlabs/ssh"
- log "github.com/sirupsen/logrus"
"keep.imfreedom.org/grim/hgkeeper/access"
"keep.imfreedom.org/grim/hgkeeper/hg"
@@ -32,7 +32,7 @@
- log.Info("refreshing access control for new repo")
+ zap.S().Info("refreshing access control for new repo") --- a/ssh/commands/serve.go Fri Mar 31 16:37:25 2023 -0500
+++ b/ssh/commands/serve.go Fri Mar 31 16:55:53 2023 -0500
@@ -5,7 +5,7 @@
"github.com/gliderlabs/ssh"
- log "github.com/sirupsen/logrus"
"keep.imfreedom.org/grim/hgkeeper/access"
"keep.imfreedom.org/grim/hgkeeper/hg"
@@ -36,7 +36,7 @@
if s.repoName == access.AdminRepo() {
- log.Info("admin repo updated, refreshing access control")
+ zap.S().Info("admin repo updated, refreshing access control") --- a/ssh/keys.go Fri Mar 31 16:37:25 2023 -0500
+++ b/ssh/keys.go Fri Mar 31 16:55:53 2023 -0500
@@ -5,7 +5,7 @@
- log "github.com/sirupsen/logrus"
"golang.org/x/crypto/ssh"
@@ -23,20 +23,20 @@
data, err := ioutil.ReadFile(path)
- log.Warnf("failed to read %s", path)
+ zap.S().Warnf("failed to read %s", path) key, err := ssh.ParsePrivateKey(data)
- log.Warnf("%s is not an ssh private key", path)
+ zap.S().Warnf("%s is not an ssh private key", path) - log.Infof("added host key from %s", path)
+ zap.S().Infof("added host key from %s", path) --- a/ssh/server.go Fri Mar 31 16:37:25 2023 -0500
+++ b/ssh/server.go Fri Mar 31 16:55:53 2023 -0500
@@ -4,7 +4,7 @@
"github.com/gliderlabs/ssh"
- log "github.com/sirupsen/logrus"
gossh "golang.org/x/crypto/ssh"
"keep.imfreedom.org/grim/hgkeeper/access"
@@ -40,14 +40,14 @@
func (s *Server) publicKeyHandler(ctx ssh.Context, key ssh.PublicKey) bool {
username, err := access.UsernameFromPubkey(key)
- log.Warnf("authentication failure, unknown key %s", gossh.FingerprintSHA256(key))
+ zap.S().Warnf("authentication failure, unknown key %s", gossh.FingerprintSHA256(key)) ctx.SetValue("username", username)
"%q authenticated with %s",
gossh.FingerprintSHA256(key),
@@ -66,7 +66,7 @@
"%s@%s requested command %q",
@@ -75,13 +75,13 @@
cmd, err := commands.Find(session.RawCommand(), s.reposPath)
- log.Warnf("failed to find command for %q, %v", session.RawCommand(), err)
+ zap.S().Warnf("failed to find command for %q, %v", session.RawCommand(), err) if err := cmd.Run(session, username); err != nil {
"%s@%s command %q failed: %v",
@@ -90,10 +90,10 @@
if err := session.Exit(255); err != nil {
- log.Errorf("session failed to exit: %v", err)
+ zap.S().Errorf("session failed to exit: %v", err)
"%s@%s command %q succeed",
@@ -101,7 +101,7 @@
if err := session.Exit(0); err != nil {
- log.Errorf("session failed to exit: %v", err)
+ zap.S().Errorf("session failed to exit: %v", err) @@ -109,7 +109,7 @@
func (s *Server) Listen(addr string) error {
- log.Infof("ssh listening on %s", s.server.Addr)
+ zap.S().Infof("ssh listening on %s", s.server.Addr) if err := s.server.ListenAndServe(); err != nil {
if err != ssh.ErrServerClosed {