Migrate to logrus so we can auto-rotate the log file

Makefile

@@ -3,7 +3,7 @@ forcetest:
 	HISHTORY_TEST=1 go test -p 1 -timeout 30m ./...
 
 test:
-	HISHTORY_TEST=1 go test -v -p 1 -timeout 30m ./...
+	HISHTORY_TEST=1 go test -p 1 -timeout 30m ./...
 
 acttest:
 	act push -j test -e .github/push_event.json --reuse --container-architecture linux/amd64

client/client_test.go

@@ -1882,7 +1882,7 @@ func captureTerminalOutputWithShellNameAndDimensions(t *testing.T, tester shellT
 	fullCommand += " sleep 0.5\n"
 	fullCommand += " tmux capture-pane -p\n"
 	fullCommand += " tmux kill-session -t foo\n"
-	hctx.GetLogger().Printf("Running tmux command: " + fullCommand)
+	hctx.GetLogger().Infof("Running tmux command: " + fullCommand)
 	return strings.TrimSpace(tester.RunInteractiveShell(t, fullCommand))
 }
 
@@ -2126,7 +2126,6 @@ type deviceOp struct {
 }
 
 func createDevice(t *testing.T, tester shellTester, devices *deviceSet, key, deviceId string) {
-	hctx.GetLogger().Printf("devices=%#v\n", devices)
 	d := device{key, deviceId}
 	_, ok := (*devices.deviceMap)[d]
 	if ok {

client/hctx/hctx.go

@@ -6,13 +6,14 @@ import (
 	"errors"
 	"fmt"
 	"io/ioutil"
-	"log"
 	"os"
 	"path"
 	"sync"
 	"time"
 
 	"github.com/ddworken/hishtory/client/data"
+	"github.com/sirupsen/logrus"
+	"gopkg.in/natefinch/lumberjack.v2"
 	"gorm.io/gorm"
 	"gorm.io/gorm/logger"
 
@@ -21,13 +22,11 @@ import (
 )
 
 var (
-	hishtoryLogger *log.Logger
+	hishtoryLogger *logrus.Logger
 	getLoggerOnce  sync.Once
 )
 
-// TODO: Can we auto-rotate the log file?
-
-func GetLogger() *log.Logger {
+func GetLogger() *logrus.Logger {
 	getLoggerOnce.Do(func() {
 		homedir, err := os.UserHomeDir()
 		if err != nil {
@@ -37,12 +36,22 @@ func GetLogger() *log.Logger {
 		if err != nil {
 			panic(err)
 		}
-		f, err := os.OpenFile(path.Join(homedir, data.HISHTORY_PATH, "hishtory.log"), os.O_RDWR|os.O_CREATE|os.O_APPEND, 0o660)
-		if err != nil {
-			panic(fmt.Errorf("failed to open hishtory.log: %v", err))
+
+		lumberjackLogger := &lumberjack.Logger{
+			Filename:   path.Join(homedir, data.HISHTORY_PATH, "hishtory.log"),
+			MaxSize:    1, // MB
+			MaxBackups: 10,
+			MaxAge:     30, // days
 		}
-		// Purposefully not closing the file. Yes, this is a dangling file handle. But hishtory is short lived so this is okay.
-		hishtoryLogger = log.New(f, "\n", log.LstdFlags|log.Lshortfile)
+
+		logFormatter := new(logrus.TextFormatter)
+		logFormatter.TimestampFormat = time.RFC3339
+		logFormatter.FullTimestamp = true
+
+		hishtoryLogger = logrus.New()
+		hishtoryLogger.SetFormatter(logFormatter)
+		hishtoryLogger.SetLevel(logrus.InfoLevel)
+		hishtoryLogger.SetOutput(lumberjackLogger)
 	})
 	return hishtoryLogger
 }
@@ -68,9 +77,8 @@ func OpenLocalSqliteDb() (*gorm.DB, error) {
 	if err != nil {
 		return nil, err
 	}
-	hishtoryLogger := GetLogger()
 	newLogger := logger.New(
-		hishtoryLogger,
+		GetLogger(),
 		logger.Config{
 			SlowThreshold:             100 * time.Millisecond,
 			LogLevel:                  logger.Warn,

client/lib/lib.go

@@ -69,7 +69,7 @@ func getCwd(ctx *context.Context) (string, string, error) {
 
 func BuildHistoryEntry(ctx *context.Context, args []string) (*data.HistoryEntry, error) {
 	if len(args) < 6 {
-		hctx.GetLogger().Printf("BuildHistoryEntry called with args=%#v, which has too few entries! This can happen in specific edge cases for newly opened terminals and is likely not a problem.", args)
+		hctx.GetLogger().Warnf("BuildHistoryEntry called with args=%#v, which has too few entries! This can happen in specific edge cases for newly opened terminals and is likely not a problem.", args)
 		return nil, nil
 	}
 	shell := args[2]
@@ -179,7 +179,7 @@ func buildCustomColumns(ctx *context.Context) (data.CustomColumns, error) {
 		err = cmd.Wait()
 		if err != nil {
 			// Log a warning, but don't crash. This way commands can exit with a different status and still work.
-			hctx.GetLogger().Printf("failed to execute custom command named %v (stdout=%#v, stderr=%#v)", cc.ColumnName, stdout.String(), stderr.String())
+			hctx.GetLogger().Warnf("failed to execute custom command named %v (stdout=%#v, stderr=%#v)", cc.ColumnName, stdout.String(), stderr.String())
 		}
 		ccv := data.CustomColumn{
 			Name: cc.ColumnName,
@@ -1100,9 +1100,8 @@ func assertIdenticalBinaries(bin1Path, bin2Path string) error {
 			differences = append(differences, fmt.Sprintf("diff at index %d: %s[%d]=%x, %s[%d]=%x", i, bin1Path, i, b1, bin2Path, i, b2))
 		}
 	}
-	logger := hctx.GetLogger()
 	for _, d := range differences {
-		logger.Printf("comparing binaries: %#v\n", d)
+		hctx.GetLogger().Infof("comparing binaries: %#v\n", d)
 	}
 	if len(differences) > 5 {
 		return fmt.Errorf("found %d differences in the binary", len(differences))
@@ -1218,7 +1217,7 @@ func ApiGet(path string) ([]byte, error) {
 		return nil, fmt.Errorf("failed to read response body from GET %s%s: %v", getServerHostname(), path, err)
 	}
 	duration := time.Since(start)
-	hctx.GetLogger().Printf("ApiGet(%#v): %s\n", path, duration.String())
+	hctx.GetLogger().Infof("ApiGet(%#v): %s\n", path, duration.String())
 	return respBody, nil
 }
 
@@ -1246,7 +1245,7 @@ func ApiPost(path, contentType string, data []byte) ([]byte, error) {
 		return nil, fmt.Errorf("failed to read response body from POST %s: %v", path, err)
 	}
 	duration := time.Since(start)
-	hctx.GetLogger().Printf("ApiPost(%#v): %s\n", path, duration.String())
+	hctx.GetLogger().Infof("ApiPost(%#v): %s\n", path, duration.String())
 	return respBody, nil
 }
 

hishtory.go

@@ -368,7 +368,7 @@ func maybeUploadSkippedHistoryEntries(ctx *context.Context) error {
 	if err != nil {
 		return fmt.Errorf("failed to retrieve history entries that haven't been uploaded yet: %v", err)
 	}
-	hctx.GetLogger().Printf("Uploading %d history entries that previously failed to upload (query=%#v)\n", len(entries), query)
+	hctx.GetLogger().Infof("Uploading %d history entries that previously failed to upload (query=%#v)\n", len(entries), query)
 	jsonValue, err := lib.EncryptAndMarshal(config, entries)
 	if err != nil {
 		return err
@@ -392,13 +392,13 @@ func maybeUploadSkippedHistoryEntries(ctx *context.Context) error {
 func saveHistoryEntry(ctx *context.Context) {
 	config := hctx.GetConf(ctx)
 	if !config.IsEnabled {
-		hctx.GetLogger().Printf("Skipping saving a history entry because hishtory is disabled\n")
+		hctx.GetLogger().Infof("Skipping saving a history entry because hishtory is disabled\n")
 		return
 	}
 	entry, err := lib.BuildHistoryEntry(ctx, os.Args)
 	lib.CheckFatalError(err)
 	if entry == nil {
-		hctx.GetLogger().Printf("Skipping saving a history entry because we did not build a history entry (was the command prefixed with a space and/or empty?)\n")
+		hctx.GetLogger().Infof("Skipping saving a history entry because we did not build a history entry (was the command prefixed with a space and/or empty?)\n")
 		return
 	}
 
@@ -414,7 +414,7 @@ func saveHistoryEntry(ctx *context.Context) {
 		_, err = lib.ApiPost("/api/v1/submit?source_device_id="+config.DeviceId, "application/json", jsonValue)
 		if err != nil {
 			if lib.IsOfflineError(err) {
-				hctx.GetLogger().Printf("Failed to remotely persist hishtory entry because we failed to connect to the remote server! This is likely because the device is offline, but also could be because the remote server is having reliability issues. Original error: %v", err)
+				hctx.GetLogger().Infof("Failed to remotely persist hishtory entry because we failed to connect to the remote server! This is likely because the device is offline, but also could be because the remote server is having reliability issues. Original error: %v", err)
 				if !config.HaveMissedUploads {
 					config.HaveMissedUploads = true
 					config.MissedUploadTimestamp = time.Now().Unix()
@@ -432,7 +432,7 @@ func saveHistoryEntry(ctx *context.Context) {
 		if lib.IsOfflineError(err) {
 			// It is fine to just ignore this, the next command will retry the API and eventually we will respond to any pending dump requests
 			dumpRequests = []*shared.DumpRequest{}
-			hctx.GetLogger().Printf("Failed to check for dump requests because we failed to connect to the remote server!")
+			hctx.GetLogger().Infof("Failed to check for dump requests because we failed to connect to the remote server!")
 		} else {
 			lib.CheckFatalError(err)
 		}