refactor: redesign logging system for CLI-friendly output (#561)

* refactor: redesign logging system for CLI-friendly output
* refactor: remove ANSI color support from logger
* fix: address PR review feedback
This commit is contained in:
Roger
2026-04-07 16:50:01 +08:00
committed by GitHub
parent a0b4412bf2
commit 5f42d4fe5f
13 changed files with 287 additions and 199 deletions
+1 -1
View File
@@ -46,7 +46,7 @@ go mod verify
- **Platform code**: use build tags (`_darwin.go`, `_windows.go`, `_linux.go`)
- **Error handling**: `fmt.Errorf("context: %w", err)` for wrapping, never `_ =` to ignore errors
- **Logging**: `log.Debugf` for record-level issues, `log.Warnf` for user-visible warnings. Extract methods should return errors, not log them.
- **Logging**: `log.Debugf` for record-level diagnostics, `log.Infof` for user-facing progress/status, `log.Warnf` for unexpected conditions. Extract methods should return errors, not log them.
- **Naming**: follow Go conventions — `Config` not `BrowserConfig`, `Extract` not `BrowsingData`
- **Tests**: use `t.TempDir()` for filesystem tests, `go-sqlmock` for database tests
- **Architecture**: see `rfcs/` for design documents
-1
View File
@@ -187,7 +187,6 @@ func (b *Browser) extractCategory(data *types.BrowserData, cat types.Category, m
func discoverProfiles(userDataDir string, sources map[types.Category][]sourcePath) []string {
entries, err := os.ReadDir(userDataDir)
if err != nil {
log.Debugf("read user data dir %s: %v", userDataDir, err)
return nil
}
+7 -1
View File
@@ -16,6 +16,8 @@ const defaultCookieQuery = `SELECT name, encrypted_value, host_key, path,
has_expires, is_persistent FROM cookies`
func extractCookies(masterKey []byte, path string) ([]types.CookieEntry, error) {
var decryptFails int
var lastErr error
cookies, err := sqliteutil.QueryRows(path, false, defaultCookieQuery,
func(rows *sql.Rows) (types.CookieEntry, error) {
var (
@@ -33,7 +35,8 @@ func extractCookies(masterKey []byte, path string) ([]types.CookieEntry, error)
value, err := decryptValue(masterKey, encryptedValue)
if err != nil {
log.Debugf("decrypt cookie %s on %s: %v", name, host, err)
decryptFails++
lastErr = err
}
value = stripCookieHash(value, host)
return types.CookieEntry{
@@ -52,6 +55,9 @@ func extractCookies(masterKey []byte, path string) ([]types.CookieEntry, error)
if err != nil {
return nil, err
}
if decryptFails > 0 {
log.Debugf("decrypt cookies: %d failed: %v", decryptFails, lastErr)
}
sort.Slice(cookies, func(i, j int) bool {
return cookies[i].CreatedAt.After(cookies[j].CreatedAt)
+12 -2
View File
@@ -12,7 +12,9 @@ const defaultCreditCardQuery = `SELECT COALESCE(guid, ''), name_on_card, expirat
card_number_encrypted, COALESCE(nickname, ''), COALESCE(billing_address_id, '') FROM credit_cards`
func extractCreditCards(masterKey []byte, path string) ([]types.CreditCardEntry, error) {
return sqliteutil.QueryRows(path, false, defaultCreditCardQuery,
var decryptFails int
var lastErr error
cards, err := sqliteutil.QueryRows(path, false, defaultCreditCardQuery,
func(rows *sql.Rows) (types.CreditCardEntry, error) {
var guid, name, month, year, nickname, address string
var encNumber []byte
@@ -21,7 +23,8 @@ func extractCreditCards(masterKey []byte, path string) ([]types.CreditCardEntry,
}
number, err := decryptValue(masterKey, encNumber)
if err != nil {
log.Debugf("decrypt credit card for %s: %v", name, err)
decryptFails++
lastErr = err
}
return types.CreditCardEntry{
GUID: guid,
@@ -33,4 +36,11 @@ func extractCreditCards(masterKey []byte, path string) ([]types.CreditCardEntry,
Address: address,
}, nil
})
if err != nil {
return nil, err
}
if decryptFails > 0 {
log.Debugf("decrypt credit cards: %d failed: %v", decryptFails, lastErr)
}
return cards, nil
}
+7 -1
View File
@@ -16,6 +16,8 @@ func extractPasswords(masterKey []byte, path string) ([]types.LoginEntry, error)
}
func extractPasswordsWithQuery(masterKey []byte, path, query string) ([]types.LoginEntry, error) {
var decryptFails int
var lastErr error
logins, err := sqliteutil.QueryRows(path, false, query,
func(rows *sql.Rows) (types.LoginEntry, error) {
var url, username string
@@ -26,7 +28,8 @@ func extractPasswordsWithQuery(masterKey []byte, path, query string) ([]types.Lo
}
password, err := decryptValue(masterKey, pwd)
if err != nil {
log.Debugf("decrypt password for %s: %v", url, err)
decryptFails++
lastErr = err
}
return types.LoginEntry{
URL: url,
@@ -38,6 +41,9 @@ func extractPasswordsWithQuery(masterKey []byte, path, query string) ([]types.Lo
if err != nil {
return nil, err
}
if decryptFails > 0 {
log.Debugf("decrypt passwords: %d failed: %v", decryptFails, lastErr)
}
sort.Slice(logins, func(i, j int) bool {
return logins[i].CreatedAt.After(logins[j].CreatedAt)
+9 -2
View File
@@ -37,6 +37,8 @@ func extractPasswords(masterKey []byte, path string) ([]types.LoginEntry, error)
}
var logins []types.LoginEntry
var decryptFails int
var lastErr error
for _, v := range gjson.GetBytes(data, "logins").Array() {
url := v.Get("formSubmitURL").String()
if url == "" {
@@ -45,11 +47,13 @@ func extractPasswords(masterKey []byte, path string) ([]types.LoginEntry, error)
user, err := decryptPBE(v.Get("encryptedUsername").String(), masterKey)
if err != nil {
log.Debugf("decrypt firefox username for %s: %v", url, err)
decryptFails++
lastErr = err
}
pwd, err := decryptPBE(v.Get("encryptedPassword").String(), masterKey)
if err != nil {
log.Debugf("decrypt firefox password for %s: %v", url, err)
decryptFails++
lastErr = err
}
logins = append(logins, types.LoginEntry{
@@ -59,6 +63,9 @@ func extractPasswords(masterKey []byte, path string) ([]types.LoginEntry, error)
CreatedAt: timestamp(v.Get("timeCreated").Int() / 1000),
})
}
if decryptFails > 0 {
log.Debugf("decrypt firefox login fields: %d failed: %v", decryptFails, lastErr)
}
sort.Slice(logins, func(i, j int) bool {
return logins[i].CreatedAt.After(logins[j].CreatedAt)
-1
View File
@@ -188,7 +188,6 @@ type resolvedPath struct {
func discoverProfiles(userDataDir string, sources map[types.Category][]sourcePath) []string {
entries, err := os.ReadDir(userDataDir)
if err != nil {
log.Debugf("read user data dir %s: %v", userDataDir, err)
return nil
}
+2 -1
View File
@@ -58,6 +58,7 @@ func dumpCmd() *cobra.Command {
}
for _, b := range browsers {
log.Infof("Extracting %s/%s...", b.BrowserName(), b.ProfileName())
data, extractErr := b.Extract(categories)
if extractErr != nil {
log.Errorf("extract %s/%s: %v", b.BrowserName(), b.ProfileName(), extractErr)
@@ -73,7 +74,7 @@ func dumpCmd() *cobra.Command {
if err := fileutil.CompressDir(outputDir); err != nil {
return fmt.Errorf("compress: %w", err)
}
log.Warnf("compressed: %s/%s.zip", outputDir, filepath.Base(outputDir))
log.Infof("Compressed: %s/%s.zip", outputDir, filepath.Base(outputDir))
}
return nil
},
+12 -7
View File
@@ -1,6 +1,6 @@
package level
package log
// Level defines all the available levels we can log at
// Level defines all the available levels we can log at.
type Level int32
const (
@@ -8,6 +8,9 @@ const (
// Debug logs are intended for debugging and development purposes.
DebugLevel Level = iota + 1
// InfoLevel is used for user-facing progress and status messages.
InfoLevel
// WarnLevel is used for undesired but relatively expected events,
// which may indicate a problem.
WarnLevel
@@ -24,14 +27,16 @@ const (
func (l Level) String() string {
switch l {
case DebugLevel:
return "DEBUG"
return "DBG"
case InfoLevel:
return "INF"
case WarnLevel:
return "WARN"
return "WRN"
case ErrorLevel:
return "ERROR"
return "ERR"
case FatalLevel:
return "FATAL"
return "FTL"
default:
return "UNKNOWN"
return "???"
}
}
+20 -12
View File
@@ -1,44 +1,52 @@
package log
import (
"github.com/moond4rk/hackbrowserdata/log/level"
)
import "fmt"
// defaultLogger is the default logger used by the package-level functions.
var defaultLogger = NewLogger(nil)
func SetVerbose() {
defaultLogger.SetLevel(level.DebugLevel)
defaultLogger.SetLevel(DebugLevel)
}
func Debug(args ...any) {
defaultLogger.Debug(args...)
defaultLogger.logMsg(DebugLevel, fmt.Sprint(args...))
}
func Debugf(format string, args ...any) {
defaultLogger.Debugf(format, args...)
defaultLogger.logMsg(DebugLevel, fmt.Sprintf(format, args...))
}
func Info(args ...any) {
defaultLogger.logMsg(InfoLevel, fmt.Sprint(args...))
}
func Infof(format string, args ...any) {
defaultLogger.logMsg(InfoLevel, fmt.Sprintf(format, args...))
}
func Warn(args ...any) {
defaultLogger.Warn(args...)
defaultLogger.logMsg(WarnLevel, fmt.Sprint(args...))
}
func Warnf(format string, args ...any) {
defaultLogger.Warnf(format, args...)
defaultLogger.logMsg(WarnLevel, fmt.Sprintf(format, args...))
}
func Error(args ...any) {
defaultLogger.Error(args...)
defaultLogger.logMsg(ErrorLevel, fmt.Sprint(args...))
}
func Errorf(format string, args ...any) {
defaultLogger.Errorf(format, args...)
defaultLogger.logMsg(ErrorLevel, fmt.Sprintf(format, args...))
}
func Fatal(args ...any) {
defaultLogger.Fatal(args...)
defaultLogger.logMsg(FatalLevel, fmt.Sprint(args...))
osExit(1)
}
func Fatalf(format string, args ...any) {
defaultLogger.Fatalf(format, args...)
defaultLogger.logMsg(FatalLevel, fmt.Sprintf(format, args...))
osExit(1)
}
+99 -121
View File
@@ -3,180 +3,158 @@ package log
import (
"fmt"
"io"
stdlog "log"
"os"
"path/filepath"
"runtime"
"strings"
"sync"
"sync/atomic"
"github.com/moond4rk/hackbrowserdata/log/level"
)
// NewLogger creates and returns a new instance of Logger.
// Log level is set to DebugLevel by default.
// Default level is InfoLevel (Debug messages are suppressed unless SetVerbose is called).
func NewLogger(base Base) *Logger {
if base == nil {
base = newBase(os.Stderr)
}
return &Logger{base: base, minLevel: level.WarnLevel}
return &Logger{base: base, minLevel: InfoLevel}
}
// Logger logs message to io.Writer at various log levels.
// Logger logs messages to io.Writer at various log levels.
type Logger struct {
base Base
// Minimum log level for this logger.
// Message with level lower than this level won't be outputted.
minLevel level.Level
// Messages with level lower than this won't be outputted.
minLevel Level
}
// canLogAt reports whether logger can log at level v.
func (l *Logger) canLogAt(v level.Level) bool {
return v >= level.Level(atomic.LoadInt32((*int32)(&l.minLevel)))
func (l *Logger) canLogAt(v Level) bool {
return v >= Level(atomic.LoadInt32((*int32)(&l.minLevel)))
}
// SetLevel sets the logger level.
// It panics if v is less than DebugLevel or greater than FatalLevel.
func (l *Logger) SetLevel(v level.Level) {
if v < level.DebugLevel || v > level.FatalLevel {
func (l *Logger) SetLevel(v Level) {
if v < DebugLevel || v > FatalLevel {
panic("log: invalid log level")
}
atomic.StoreInt32((*int32)(&l.minLevel), int32(v))
}
// baseCallerSkip is the number of frames to skip in runtime.Caller to reach
// the actual call site. Both package-level functions (log.Xxx -> logMsg -> base.Log)
// and Logger methods (Logger.Xxx -> logMsg -> base.Log) add exactly one frame
// above logMsg, so the skip is the same: base.Log(0) -> logMsg(1) -> caller_wrapper(2) -> caller(3).
const baseCallerSkip = 3
// logMsg is the internal method all public methods delegate to.
func (l *Logger) logMsg(lvl Level, msg string) {
if !l.canLogAt(lvl) {
return
}
l.base.Log(baseCallerSkip, lvl, msg)
}
func (l *Logger) Debug(args ...any) {
if !l.canLogAt(level.DebugLevel) {
return
}
l.base.Debug(args...)
}
func (l *Logger) Warn(args ...any) {
if !l.canLogAt(level.WarnLevel) {
return
}
l.base.Warn(args...)
}
func (l *Logger) Error(args ...any) {
if !l.canLogAt(level.ErrorLevel) {
return
}
l.base.Error(args...)
}
func (l *Logger) Fatal(args ...any) {
if !l.canLogAt(level.FatalLevel) {
return
}
l.base.Fatal(args...)
l.logMsg(DebugLevel, fmt.Sprint(args...))
}
func (l *Logger) Debugf(format string, args ...any) {
if !l.canLogAt(level.DebugLevel) {
return
}
l.base.Debug(fmt.Sprintf(format, args...))
l.logMsg(DebugLevel, fmt.Sprintf(format, args...))
}
func (l *Logger) Info(args ...any) {
l.logMsg(InfoLevel, fmt.Sprint(args...))
}
func (l *Logger) Infof(format string, args ...any) {
l.logMsg(InfoLevel, fmt.Sprintf(format, args...))
}
func (l *Logger) Warn(args ...any) {
l.logMsg(WarnLevel, fmt.Sprint(args...))
}
func (l *Logger) Warnf(format string, args ...any) {
if !l.canLogAt(level.WarnLevel) {
return
}
l.base.Warn(fmt.Sprintf(format, args...))
l.logMsg(WarnLevel, fmt.Sprintf(format, args...))
}
func (l *Logger) Error(args ...any) {
l.logMsg(ErrorLevel, fmt.Sprint(args...))
}
func (l *Logger) Errorf(format string, args ...any) {
if !l.canLogAt(level.ErrorLevel) {
return
}
l.base.Error(fmt.Sprintf(format, args...))
l.logMsg(ErrorLevel, fmt.Sprintf(format, args...))
}
func (l *Logger) Fatal(args ...any) {
l.logMsg(FatalLevel, fmt.Sprint(args...))
osExit(1)
}
func (l *Logger) Fatalf(format string, args ...any) {
if !l.canLogAt(level.FatalLevel) {
return
}
l.base.Fatal(fmt.Sprintf(format, args...))
l.logMsg(FatalLevel, fmt.Sprintf(format, args...))
osExit(1)
}
// Base is the interface that underlies the Logger. It receives the caller
// skip count, log level, and formatted message.
type Base interface {
Debug(args ...any)
Warn(args ...any)
Error(args ...any)
Fatal(args ...any)
Log(callerSkip int, lvl Level, msg string)
}
// baseLogger is a wrapper object around log.Logger from the standard library.
// It supports logging at various log levels.
// baseLogger writes formatted log messages to an io.Writer.
// Output format:
//
// [DBG] file.go:42: message
// [INF] message
// [WRN] message
// [ERR] message
// [FTL] message
type baseLogger struct {
*stdlog.Logger
callDepth int
out io.Writer
mu sync.Mutex
}
func newBase(out io.Writer) *baseLogger {
prefix := "[hack-browser-data] "
base := &baseLogger{
Logger: stdlog.New(out, prefix, stdlog.Lshortfile),
}
base.callDepth = base.calculateCallDepth()
return base
}
// calculateCallDepth returns the call depth for the logger.
func (l *baseLogger) calculateCallDepth() int {
return l.getCallDepth()
}
func (l *baseLogger) prefixPrint(prefix string, args ...any) {
args = append([]any{prefix}, args...)
if err := l.Output(l.callDepth, fmt.Sprint(args...)); err != nil {
_, _ = fmt.Fprintf(os.Stderr, "log output error: %v\n", err)
}
}
func (l *baseLogger) getCallDepth() int {
defaultCallDepth := 2
pcs := make([]uintptr, 10)
n := runtime.Callers(defaultCallDepth, pcs)
frames := runtime.CallersFrames(pcs[:n])
for i := 0; i < n; i++ {
frame, more := frames.Next()
if !l.isLoggerPackage(frame.Function) {
return i + 1
}
if !more {
break
}
}
return defaultCallDepth
}
func (l *baseLogger) isLoggerPackage(funcName string) bool {
const loggerFuncName = "hackbrowserdata/log"
return strings.Contains(funcName, loggerFuncName)
}
// Debug logs a message at Debug level.
func (l *baseLogger) Debug(args ...any) {
l.prefixPrint("DEBUG: ", args...)
}
// Warn logs a message at Warning level.
func (l *baseLogger) Warn(args ...any) {
l.prefixPrint("WARN: ", args...)
}
// Error logs a message at Error level.
func (l *baseLogger) Error(args ...any) {
l.prefixPrint("ERROR: ", args...)
return &baseLogger{out: out}
}
var osExit = os.Exit
// Fatal logs a message at Fatal level
// and process will exit with status set to 1.
func (l *baseLogger) Fatal(args ...any) {
l.prefixPrint("FATAL: ", args...)
osExit(1)
// continuation is the indent for multi-line messages.
// Width matches "[DBG] " (6 chars).
const continuation = " "
func (l *baseLogger) Log(callerSkip int, lvl Level, msg string) {
msg = strings.TrimRight(msg, "\n")
if strings.Contains(msg, "\n") {
msg = strings.ReplaceAll(msg, "\n", "\n"+continuation)
}
label := l.formatLabel(lvl)
var line string
if lvl == DebugLevel {
_, file, num, ok := runtime.Caller(callerSkip)
if ok {
file = filepath.Base(file)
} else {
file = "???"
num = 0
}
line = fmt.Sprintf("%s %s:%d: %s\n", label, file, num, msg)
} else {
line = fmt.Sprintf("%s %s\n", label, msg)
}
l.mu.Lock()
_, _ = io.WriteString(l.out, line)
l.mu.Unlock()
}
// formatLabel returns the bracketed level label, e.g. "[DBG]".
func (l *baseLogger) formatLabel(lvl Level) string {
return "[" + lvl.String() + "]"
}
+108 -47
View File
@@ -6,19 +6,13 @@ import (
"testing"
"github.com/stretchr/testify/assert"
level2 "github.com/moond4rk/hackbrowserdata/log/level"
)
const (
pattern = `^\[hack\-browser\-data] \w+\.go:\d+:`
)
type baseTestCase struct {
description string
message string
suffix string
level level2.Level
level Level
wantedPattern string
}
@@ -38,13 +32,13 @@ var baseTestCases = []baseTestCase{
func TestLoggerDebug(t *testing.T) {
for _, tc := range baseTestCases {
tc := tc
tc.level = level2.DebugLevel
tc.level = DebugLevel
message := tc.message + tc.suffix
tc.wantedPattern = fmt.Sprintf("%s %s: %s\n$", pattern, tc.level, tc.message)
tc.wantedPattern = fmt.Sprintf(`^\[DBG\] \w+\.go:\d+: %s\n$`, tc.message)
t.Run(tc.description, func(t *testing.T) {
var buf bytes.Buffer
logger := NewLogger(newBase(&buf))
logger.SetLevel(level2.DebugLevel)
logger.SetLevel(DebugLevel)
logger.Debug(message)
got := buf.String()
assert.Regexp(t, tc.wantedPattern, got)
@@ -52,12 +46,28 @@ func TestLoggerDebug(t *testing.T) {
}
}
func TestLoggerInfo(t *testing.T) {
for _, tc := range baseTestCases {
tc := tc
tc.level = InfoLevel
message := tc.message + tc.suffix
tc.wantedPattern = fmt.Sprintf(`^\[INF\] %s\n$`, tc.message)
t.Run(tc.description, func(t *testing.T) {
var buf bytes.Buffer
logger := NewLogger(newBase(&buf))
logger.Info(message)
got := buf.String()
assert.Regexp(t, tc.wantedPattern, got)
})
}
}
func TestLoggerWarn(t *testing.T) {
for _, tc := range baseTestCases {
tc := tc
tc.level = level2.WarnLevel
tc.level = WarnLevel
message := tc.message + tc.suffix
tc.wantedPattern = fmt.Sprintf("%s %s: %s\n$", pattern, tc.level, tc.message)
tc.wantedPattern = fmt.Sprintf(`^\[WRN\] %s\n$`, tc.message)
t.Run(tc.description, func(t *testing.T) {
var buf bytes.Buffer
logger := NewLogger(newBase(&buf))
@@ -71,9 +81,9 @@ func TestLoggerWarn(t *testing.T) {
func TestLoggerError(t *testing.T) {
for _, tc := range baseTestCases {
tc := tc
tc.level = level2.ErrorLevel
tc.level = ErrorLevel
message := tc.message + tc.suffix
tc.wantedPattern = fmt.Sprintf("%s %s: %s\n$", pattern, tc.level, tc.message)
tc.wantedPattern = fmt.Sprintf(`^\[ERR\] %s\n$`, tc.message)
t.Run(tc.description, func(t *testing.T) {
var buf bytes.Buffer
logger := NewLogger(newBase(&buf))
@@ -90,9 +100,9 @@ func TestLoggerFatal(t *testing.T) {
for _, tc := range baseTestCases {
tc := tc
tc.level = level2.FatalLevel
tc.level = FatalLevel
message := tc.message + tc.suffix
tc.wantedPattern = fmt.Sprintf("%s %s: %s\n$", pattern, tc.level, tc.message)
tc.wantedPattern = fmt.Sprintf(`^\[FTL\] %s\n$`, tc.message)
t.Run(tc.description, func(t *testing.T) {
var buf bytes.Buffer
exitCalled := false
@@ -115,23 +125,23 @@ type formatTestCase struct {
description string
format string
args []interface{}
level level2.Level
level Level
wantedPattern string
}
var formatTestCases = []formatTestCase{
{
description: "message with format prefix",
description: "message with string format",
format: "hello, %s!",
args: []any{"Hacker"},
},
{
description: "message with format prefix",
description: "message with int format",
format: "hello, %d,%d,%d!",
args: []any{1, 2, 3},
},
{
description: "message with format prefix",
description: "message with mixed format",
format: "hello, %s,%d,%d!",
args: []any{"Hacker", 2, 3},
},
@@ -140,13 +150,13 @@ var formatTestCases = []formatTestCase{
func TestLoggerDebugf(t *testing.T) {
for _, tc := range formatTestCases {
tc := tc
tc.level = level2.DebugLevel
tc.level = DebugLevel
message := fmt.Sprintf(tc.format, tc.args...)
tc.wantedPattern = fmt.Sprintf("%s %s: %s\n$", pattern, tc.level, message)
tc.wantedPattern = fmt.Sprintf(`^\[DBG\] \w+\.go:\d+: %s\n$`, message)
t.Run(tc.description, func(t *testing.T) {
var buf bytes.Buffer
logger := NewLogger(newBase(&buf))
logger.SetLevel(level2.DebugLevel)
logger.SetLevel(DebugLevel)
logger.Debugf(tc.format, tc.args...)
got := buf.String()
assert.Regexp(t, tc.wantedPattern, got)
@@ -154,12 +164,28 @@ func TestLoggerDebugf(t *testing.T) {
}
}
func TestLoggerInfof(t *testing.T) {
for _, tc := range formatTestCases {
tc := tc
tc.level = InfoLevel
message := fmt.Sprintf(tc.format, tc.args...)
tc.wantedPattern = fmt.Sprintf(`^\[INF\] %s\n$`, message)
t.Run(tc.description, func(t *testing.T) {
var buf bytes.Buffer
logger := NewLogger(newBase(&buf))
logger.Infof(tc.format, tc.args...)
got := buf.String()
assert.Regexp(t, tc.wantedPattern, got)
})
}
}
func TestLoggerWarnf(t *testing.T) {
for _, tc := range formatTestCases {
tc := tc
tc.level = level2.WarnLevel
tc.level = WarnLevel
message := fmt.Sprintf(tc.format, tc.args...)
tc.wantedPattern = fmt.Sprintf("%s %s: %s\n$", pattern, tc.level, message)
tc.wantedPattern = fmt.Sprintf(`^\[WRN\] %s\n$`, message)
t.Run(tc.description, func(t *testing.T) {
var buf bytes.Buffer
logger := NewLogger(newBase(&buf))
@@ -173,9 +199,9 @@ func TestLoggerWarnf(t *testing.T) {
func TestLoggerErrorf(t *testing.T) {
for _, tc := range formatTestCases {
tc := tc
tc.level = level2.ErrorLevel
tc.level = ErrorLevel
message := fmt.Sprintf(tc.format, tc.args...)
tc.wantedPattern = fmt.Sprintf("%s %s: %s\n$", pattern, tc.level, message)
tc.wantedPattern = fmt.Sprintf(`^\[ERR\] %s\n$`, message)
t.Run(tc.description, func(t *testing.T) {
var buf bytes.Buffer
logger := NewLogger(newBase(&buf))
@@ -191,9 +217,9 @@ func TestLoggerFatalf(t *testing.T) {
defer func() { osExit = originalOsExit }()
for _, tc := range formatTestCases {
tc := tc
tc.level = level2.FatalLevel
tc.level = FatalLevel
message := fmt.Sprintf(tc.format, tc.args...)
tc.wantedPattern = fmt.Sprintf("%s %s: %s\n$", pattern, tc.level, message)
tc.wantedPattern = fmt.Sprintf(`^\[FTL\] %s\n$`, message)
t.Run(tc.description, func(t *testing.T) {
var buf bytes.Buffer
exitCalled := false
@@ -213,19 +239,20 @@ func TestLoggerFatalf(t *testing.T) {
}
func TestLoggerWithLowerLevels(t *testing.T) {
// Logger should not log messages at a level
// lower than the specified level.
levels := []level2.Level{level2.DebugLevel, level2.WarnLevel, level2.ErrorLevel, level2.FatalLevel}
originalOsExit := osExit
defer func() { osExit = originalOsExit }()
levels := []Level{DebugLevel, InfoLevel, WarnLevel, ErrorLevel, FatalLevel}
ops := []struct {
op string
level level2.Level
logFunc func(*Logger)
expected bool
op string
level Level
logFunc func(*Logger)
}{
{"Debug", level2.DebugLevel, func(l *Logger) { l.Debug("hello") }, false},
{"Warn", level2.WarnLevel, func(l *Logger) { l.Warn("hello") }, false},
{"Error", level2.ErrorLevel, func(l *Logger) { l.Error("hello") }, false},
{"Fatal", level2.FatalLevel, func(l *Logger) { l.Fatal("hello") }, false},
{"Debug", DebugLevel, func(l *Logger) { l.Debug("hello") }},
{"Info", InfoLevel, func(l *Logger) { l.Info("hello") }},
{"Warn", WarnLevel, func(l *Logger) { l.Warn("hello") }},
{"Error", ErrorLevel, func(l *Logger) { l.Error("hello") }},
{"Fatal", FatalLevel, func(l *Logger) { l.Fatal("hello") }},
}
for _, setLevel := range levels {
@@ -236,23 +263,57 @@ func TestLoggerWithLowerLevels(t *testing.T) {
expectedOutput := op.level >= setLevel
exitCalled := false
exitCode := 0
osExit = func(code int) {
exitCalled = true
exitCode = code
}
op.logFunc(logger)
output := buf.String()
if expectedOutput {
assert.NotEmpty(t, output)
assert.NotEmpty(t, output, "setLevel=%s op=%s should produce output", setLevel, op.op)
} else {
assert.Empty(t, output)
assert.Empty(t, output, "setLevel=%s op=%s should be suppressed", setLevel, op.op)
}
if op.op == "Fatal" {
assert.True(t, exitCalled)
assert.Equal(t, 1, exitCode)
if op.op == "Fatal" && expectedOutput {
assert.True(t, exitCalled, "Fatal should call osExit")
}
}
}
}
func TestDefaultLevelIsInfo(t *testing.T) {
var buf bytes.Buffer
logger := NewLogger(newBase(&buf))
// Debug should be suppressed at default level (InfoLevel).
logger.Debug("debug msg")
assert.Empty(t, buf.String(), "Debug should be suppressed at default InfoLevel")
// Info should be visible at default level.
logger.Info("info msg")
assert.Contains(t, buf.String(), "info msg")
}
func TestDebugIncludesFileLine(t *testing.T) {
var buf bytes.Buffer
logger := NewLogger(newBase(&buf))
logger.SetLevel(DebugLevel)
logger.Debug("test location")
got := buf.String()
assert.Regexp(t, `^\[DBG\] logger_test\.go:\d+: test location\n$`, got)
}
func TestInfoHasLabel(t *testing.T) {
var buf bytes.Buffer
logger := NewLogger(newBase(&buf))
logger.Info("clean message")
assert.Equal(t, "[INF] clean message\n", buf.String())
}
func TestMultilineMessageIndented(t *testing.T) {
var buf bytes.Buffer
logger := NewLogger(newBase(&buf))
logger.Warn("line1\nline2\nline3")
got := buf.String()
assert.Equal(t, "[WRN] line1\n line2\n line3\n", got)
}
+10 -2
View File
@@ -60,11 +60,20 @@ func (o *Writer) Write() error {
if err := os.MkdirAll(o.dir, 0o750); err != nil {
return fmt.Errorf("create output dir: %w", err)
}
for _, cs := range o.aggregate() {
agg := o.aggregate()
for _, cs := range agg {
if err := o.writeFile(cs.name, cs.rows); err != nil {
return err
}
}
if len(agg) > 0 {
fmt.Fprintln(os.Stderr)
log.Infof("Exported to %s/", o.dir)
for _, cs := range agg {
filename := fmt.Sprintf("%s.%s", cs.name, o.formatter.ext())
log.Infof(" %-24s %d entries", filename, len(cs.rows))
}
}
return nil
}
@@ -155,6 +164,5 @@ func (o *Writer) writeFile(category string, rows []row) (err error) {
if _, err := f.Write(buf.Bytes()); err != nil {
return fmt.Errorf("write %s: %w", filename, err)
}
log.Warnf("export: %s", path)
return nil
}