refactor: restructure codebase to internal/ directory with modular architecture

- Move all source files to internal/{app,backend,config,executor,logger,parser,utils}
- Integrate third-party libraries: zerolog, goccy/go-json, gopsutil, cobra/viper
- Add comprehensive unit tests for utils package (94.3% coverage)
- Add performance benchmarks for string operations
- Fix error display: cleanup warnings no longer pollute Recent Errors
- Add GitHub Actions CI workflow
- Add Makefile for build automation
- Add README documentation

Generated with SWE-Agent.ai

Co-Authored-By: SWE-Agent.ai <noreply@swe-agent.ai>
This commit is contained in:
cexll
2026-01-20 17:34:26 +08:00
parent 90c630e30e
commit fa617d1599
82 changed files with 4516 additions and 3730 deletions

View File

@@ -0,0 +1,59 @@
package logger
import "sync/atomic"
var loggerPtr atomic.Pointer[Logger]
func setLogger(l *Logger) {
loggerPtr.Store(l)
}
func closeLogger() error {
logger := loggerPtr.Swap(nil)
if logger == nil {
return nil
}
return logger.Close()
}
func activeLogger() *Logger {
return loggerPtr.Load()
}
func logDebug(msg string) {
if logger := activeLogger(); logger != nil {
logger.Debug(msg)
}
}
func logInfo(msg string) {
if logger := activeLogger(); logger != nil {
logger.Info(msg)
}
}
func logWarn(msg string) {
if logger := activeLogger(); logger != nil {
logger.Warn(msg)
}
}
func logError(msg string) {
if logger := activeLogger(); logger != nil {
logger.Error(msg)
}
}
func SetLogger(l *Logger) { setLogger(l) }
func CloseLogger() error { return closeLogger() }
func ActiveLogger() *Logger { return activeLogger() }
func LogInfo(msg string) { logInfo(msg) }
func LogDebug(msg string) { logDebug(msg) }
func LogWarn(msg string) { logWarn(msg) }
func LogError(msg string) { logError(msg) }

View File

@@ -0,0 +1,683 @@
package logger
import (
"bufio"
"context"
"errors"
"fmt"
"hash/crc32"
"os"
"path/filepath"
"strconv"
"strings"
"sync"
"sync/atomic"
"time"
"github.com/rs/zerolog"
)
// Logger writes log messages asynchronously to a temp file.
// It is intentionally minimal: a buffered channel + single worker goroutine
// to avoid contention while keeping ordering guarantees.
type Logger struct {
path string
file *os.File
writer *bufio.Writer
zlogger zerolog.Logger
ch chan logEntry
flushReq chan chan struct{}
done chan struct{}
closed atomic.Bool
closeOnce sync.Once
workerWG sync.WaitGroup
pendingWG sync.WaitGroup
flushMu sync.Mutex
workerErr error
errorEntries []string // Cache of recent ERROR/WARN entries
errorMu sync.Mutex
}
type logEntry struct {
msg string
level zerolog.Level
isError bool // true for ERROR or WARN levels
}
// CleanupStats captures the outcome of a cleanupOldLogs run.
type CleanupStats struct {
Scanned int
Deleted int
Kept int
Errors int
DeletedFiles []string
KeptFiles []string
}
var (
processRunningCheck = isProcessRunning
processStartTimeFn = getProcessStartTime
removeLogFileFn = os.Remove
globLogFiles = filepath.Glob
fileStatFn = os.Lstat // Use Lstat to detect symlinks
evalSymlinksFn = filepath.EvalSymlinks
)
const maxLogSuffixLen = 64
var logSuffixCounter atomic.Uint64
// NewLogger creates the async logger and starts the worker goroutine.
// The log file is created under os.TempDir() using the required naming scheme.
func NewLogger() (*Logger, error) {
return NewLoggerWithSuffix("")
}
// NewLoggerWithSuffix creates a logger with an optional suffix in the filename.
// Useful for tests that need isolated log files within the same process.
func NewLoggerWithSuffix(suffix string) (*Logger, error) {
pid := os.Getpid()
filename := fmt.Sprintf("%s-%d", PrimaryLogPrefix(), pid)
var safeSuffix string
if suffix != "" {
safeSuffix = sanitizeLogSuffix(suffix)
}
if safeSuffix != "" {
filename += "-" + safeSuffix
}
filename += ".log"
path := filepath.Clean(filepath.Join(os.TempDir(), filename))
if err := os.MkdirAll(filepath.Dir(path), 0o700); err != nil {
return nil, err
}
f, err := os.OpenFile(path, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0o600)
if err != nil {
return nil, err
}
l := &Logger{
path: path,
file: f,
writer: bufio.NewWriterSize(f, 4096),
ch: make(chan logEntry, 1000),
flushReq: make(chan chan struct{}, 1),
done: make(chan struct{}),
}
l.zlogger = zerolog.New(l.writer).With().Timestamp().Logger()
l.workerWG.Add(1)
go l.run()
return l, nil
}
func sanitizeLogSuffix(raw string) string {
trimmed := strings.TrimSpace(raw)
if trimmed == "" {
return fallbackLogSuffix()
}
var b strings.Builder
changed := false
for _, r := range trimmed {
if isSafeLogRune(r) {
b.WriteRune(r)
} else {
changed = true
b.WriteByte('-')
}
if b.Len() >= maxLogSuffixLen {
changed = true
break
}
}
sanitized := strings.Trim(b.String(), "-.")
if sanitized != b.String() {
changed = true // Mark if trim removed any characters
}
if sanitized == "" {
return fallbackLogSuffix()
}
if changed || len(sanitized) > maxLogSuffixLen {
hash := crc32.ChecksumIEEE([]byte(trimmed))
hashStr := fmt.Sprintf("%x", hash)
maxPrefix := maxLogSuffixLen - len(hashStr) - 1
if maxPrefix < 1 {
maxPrefix = 1
}
if len(sanitized) > maxPrefix {
sanitized = sanitized[:maxPrefix]
}
sanitized = fmt.Sprintf("%s-%s", sanitized, hashStr)
}
return sanitized
}
func fallbackLogSuffix() string {
next := logSuffixCounter.Add(1)
return fmt.Sprintf("task-%d", next)
}
func isSafeLogRune(r rune) bool {
switch {
case r >= 'a' && r <= 'z':
return true
case r >= 'A' && r <= 'Z':
return true
case r >= '0' && r <= '9':
return true
case r == '-', r == '_', r == '.':
return true
default:
return false
}
}
// Path returns the underlying log file path (useful for tests/inspection).
func (l *Logger) Path() string {
if l == nil {
return ""
}
return l.path
}
func (l *Logger) IsClosed() bool {
if l == nil {
return true
}
return l.closed.Load()
}
// Info logs at INFO level.
func (l *Logger) Info(msg string) { l.logWithLevel(zerolog.InfoLevel, msg) }
// Warn logs at WARN level.
func (l *Logger) Warn(msg string) { l.logWithLevel(zerolog.WarnLevel, msg) }
// Debug logs at DEBUG level.
func (l *Logger) Debug(msg string) { l.logWithLevel(zerolog.DebugLevel, msg) }
// Error logs at ERROR level.
func (l *Logger) Error(msg string) { l.logWithLevel(zerolog.ErrorLevel, msg) }
// Close signals the worker to flush and close the log file.
// The log file is NOT removed, allowing inspection after program exit.
// It is safe to call multiple times.
// Waits up to CODEAGENT_LOGGER_CLOSE_TIMEOUT_MS (default: 5000) for shutdown; set to 0 to wait indefinitely.
// Returns an error if shutdown doesn't complete within the timeout.
func (l *Logger) Close() error {
if l == nil {
return nil
}
var closeErr error
l.closeOnce.Do(func() {
l.closed.Store(true)
close(l.done)
timeout := loggerCloseTimeout()
workerDone := make(chan struct{})
go func() {
l.workerWG.Wait()
close(workerDone)
}()
if timeout > 0 {
select {
case <-workerDone:
// Worker stopped gracefully
case <-time.After(timeout):
closeErr = fmt.Errorf("logger worker timeout during close")
return
}
} else {
<-workerDone
}
if l.workerErr != nil && closeErr == nil {
closeErr = l.workerErr
}
})
return closeErr
}
func loggerCloseTimeout() time.Duration {
const defaultTimeout = 5 * time.Second
raw := strings.TrimSpace(os.Getenv("CODEAGENT_LOGGER_CLOSE_TIMEOUT_MS"))
if raw == "" {
return defaultTimeout
}
ms, err := strconv.Atoi(raw)
if err != nil {
return defaultTimeout
}
if ms <= 0 {
return 0
}
return time.Duration(ms) * time.Millisecond
}
// RemoveLogFile removes the log file. Should only be called after Close().
func (l *Logger) RemoveLogFile() error {
if l == nil {
return nil
}
return os.Remove(l.path)
}
// ExtractRecentErrors returns the most recent ERROR and WARN entries from memory cache.
// Returns up to maxEntries entries in chronological order.
func (l *Logger) ExtractRecentErrors(maxEntries int) []string {
if l == nil || maxEntries <= 0 {
return nil
}
l.errorMu.Lock()
defer l.errorMu.Unlock()
if len(l.errorEntries) == 0 {
return nil
}
// Return last N entries
start := 0
if len(l.errorEntries) > maxEntries {
start = len(l.errorEntries) - maxEntries
}
result := make([]string, len(l.errorEntries)-start)
copy(result, l.errorEntries[start:])
return result
}
// Flush waits for all pending log entries to be written. Primarily for tests.
// Returns after a 5-second timeout to prevent indefinite blocking.
func (l *Logger) Flush() {
if l == nil {
return
}
l.flushMu.Lock()
defer l.flushMu.Unlock()
// Wait for pending entries with timeout
done := make(chan struct{})
go func() {
l.pendingWG.Wait()
close(done)
}()
ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
defer cancel()
select {
case <-done:
// All pending entries processed
case <-ctx.Done():
// Timeout - return without full flush
return
}
// Trigger writer flush
flushDone := make(chan struct{})
select {
case l.flushReq <- flushDone:
// Wait for flush to complete
select {
case <-flushDone:
// Flush completed
case <-time.After(1 * time.Second):
// Flush timeout
}
case <-l.done:
// Logger is closing
case <-time.After(1 * time.Second):
// Timeout sending flush request
}
}
func (l *Logger) logWithLevel(entryLevel zerolog.Level, msg string) {
if l == nil {
return
}
if l.closed.Load() {
return
}
isError := entryLevel == zerolog.WarnLevel || entryLevel == zerolog.ErrorLevel
entry := logEntry{msg: msg, level: entryLevel, isError: isError}
l.flushMu.Lock()
l.pendingWG.Add(1)
l.flushMu.Unlock()
select {
case l.ch <- entry:
// Successfully sent to channel
case <-l.done:
// Logger is closing, drop this entry
l.pendingWG.Done()
return
}
}
func (l *Logger) run() {
defer l.workerWG.Done()
ticker := time.NewTicker(500 * time.Millisecond)
defer ticker.Stop()
writeEntry := func(entry logEntry) {
l.zlogger.WithLevel(entry.level).Msg(entry.msg)
// Cache error/warn entries in memory for fast extraction
if entry.isError {
l.errorMu.Lock()
l.errorEntries = append(l.errorEntries, entry.msg)
if len(l.errorEntries) > 100 { // Keep last 100
l.errorEntries = l.errorEntries[1:]
}
l.errorMu.Unlock()
}
l.pendingWG.Done()
}
finalize := func() {
if err := l.writer.Flush(); err != nil && l.workerErr == nil {
l.workerErr = err
}
if err := l.file.Sync(); err != nil && l.workerErr == nil {
l.workerErr = err
}
if err := l.file.Close(); err != nil && l.workerErr == nil {
l.workerErr = err
}
}
for {
select {
case entry, ok := <-l.ch:
if !ok {
finalize()
return
}
writeEntry(entry)
case <-ticker.C:
_ = l.writer.Flush()
case flushDone := <-l.flushReq:
// Explicit flush request - flush writer and sync to disk
_ = l.writer.Flush()
_ = l.file.Sync()
close(flushDone)
case <-l.done:
for {
select {
case entry, ok := <-l.ch:
if !ok {
finalize()
return
}
writeEntry(entry)
default:
finalize()
return
}
}
}
}
}
// cleanupOldLogs scans os.TempDir() for wrapper log files and removes those
// whose owning process is no longer running (i.e., orphaned logs).
// It includes safety checks for:
// - PID reuse: Compares file modification time with process start time
// - Symlink attacks: Ensures files are within TempDir and not symlinks
func cleanupOldLogs() (CleanupStats, error) {
var stats CleanupStats
tempDir := os.TempDir()
prefixes := LogPrefixes()
seen := make(map[string]struct{})
var matches []string
for _, prefix := range prefixes {
pattern := filepath.Join(tempDir, fmt.Sprintf("%s-*.log", prefix))
found, err := globLogFiles(pattern)
if err != nil {
logWarn(fmt.Sprintf("cleanupOldLogs: failed to list logs: %v", err))
return stats, fmt.Errorf("cleanupOldLogs: %w", err)
}
for _, path := range found {
if _, ok := seen[path]; ok {
continue
}
seen[path] = struct{}{}
matches = append(matches, path)
}
}
var removeErr error
for _, path := range matches {
stats.Scanned++
filename := filepath.Base(path)
// Security check: Verify file is not a symlink and is within tempDir
if shouldSkipFile, reason := isUnsafeFile(path, tempDir); shouldSkipFile {
stats.Kept++
stats.KeptFiles = append(stats.KeptFiles, filename)
if reason != "" {
// Use Debug level to avoid polluting Recent Errors with cleanup noise
logDebug(fmt.Sprintf("cleanupOldLogs: skipping %s: %s", filename, reason))
}
continue
}
pid, ok := parsePIDFromLog(path)
if !ok {
stats.Kept++
stats.KeptFiles = append(stats.KeptFiles, filename)
continue
}
// Check if process is running
if !processRunningCheck(pid) {
// Process not running, safe to delete
if err := removeLogFileFn(path); err != nil {
if errors.Is(err, os.ErrNotExist) {
// File already deleted by another process, don't count as success
stats.Kept++
stats.KeptFiles = append(stats.KeptFiles, filename+" (already deleted)")
continue
}
stats.Errors++
logWarn(fmt.Sprintf("cleanupOldLogs: failed to remove %s: %v", filename, err))
removeErr = errors.Join(removeErr, fmt.Errorf("failed to remove %s: %w", filename, err))
continue
}
stats.Deleted++
stats.DeletedFiles = append(stats.DeletedFiles, filename)
continue
}
// Process is running, check for PID reuse
if isPIDReused(path, pid) {
// PID was reused, the log file is orphaned
if err := removeLogFileFn(path); err != nil {
if errors.Is(err, os.ErrNotExist) {
stats.Kept++
stats.KeptFiles = append(stats.KeptFiles, filename+" (already deleted)")
continue
}
stats.Errors++
logWarn(fmt.Sprintf("cleanupOldLogs: failed to remove %s (PID reused): %v", filename, err))
removeErr = errors.Join(removeErr, fmt.Errorf("failed to remove %s: %w", filename, err))
continue
}
stats.Deleted++
stats.DeletedFiles = append(stats.DeletedFiles, filename)
continue
}
// Process is running and owns this log file
stats.Kept++
stats.KeptFiles = append(stats.KeptFiles, filename)
}
if removeErr != nil {
return stats, fmt.Errorf("cleanupOldLogs: %w", removeErr)
}
return stats, nil
}
// isUnsafeFile checks if a file is unsafe to delete (symlink or outside tempDir).
// Returns (true, reason) if the file should be skipped.
func isUnsafeFile(path string, tempDir string) (bool, string) {
// Check if file is a symlink
info, err := fileStatFn(path)
if err != nil {
if errors.Is(err, os.ErrNotExist) {
return true, "" // File disappeared, skip silently
}
return true, fmt.Sprintf("stat failed: %v", err)
}
// Check if it's a symlink
if info.Mode()&os.ModeSymlink != 0 {
return true, "refusing to delete symlink"
}
// Resolve any path traversal and verify it's within tempDir
resolvedPath, err := evalSymlinksFn(path)
if err != nil {
return true, fmt.Sprintf("path resolution failed: %v", err)
}
// Get absolute path of tempDir
absTempDir, err := filepath.Abs(tempDir)
if err != nil {
return true, fmt.Sprintf("tempDir resolution failed: %v", err)
}
// Ensure resolved path is within tempDir
relPath, err := filepath.Rel(absTempDir, resolvedPath)
if err != nil || strings.HasPrefix(relPath, "..") {
return true, "file is outside tempDir"
}
return false, ""
}
// isPIDReused checks if a PID has been reused by comparing file modification time
// with process start time. Returns true if the log file was created by a different
// process that previously had the same PID.
func isPIDReused(logPath string, pid int) bool {
// Get file modification time (when log was last written)
info, err := fileStatFn(logPath)
if err != nil {
// If we can't stat the file, be conservative and keep it
return false
}
fileModTime := info.ModTime()
// Get process start time
procStartTime := processStartTimeFn(pid)
if procStartTime.IsZero() {
// Can't determine process start time
// Check if file is very old (>7 days), likely from a dead process
return time.Since(fileModTime) > 7*24*time.Hour
}
// If the log file was modified before the process started, PID was reused
// Add a small buffer (1 second) to account for clock skew and file system timing
return fileModTime.Add(1 * time.Second).Before(procStartTime)
}
func parsePIDFromLog(path string) (int, bool) {
name := filepath.Base(path)
prefixes := LogPrefixes()
for _, prefix := range prefixes {
prefixWithDash := fmt.Sprintf("%s-", prefix)
if !strings.HasPrefix(name, prefixWithDash) || !strings.HasSuffix(name, ".log") {
continue
}
core := strings.TrimSuffix(strings.TrimPrefix(name, prefixWithDash), ".log")
if core == "" {
continue
}
pidPart := core
if idx := strings.IndexRune(core, '-'); idx != -1 {
pidPart = core[:idx]
}
if pidPart == "" {
continue
}
pid, err := strconv.Atoi(pidPart)
if err != nil || pid <= 0 {
continue
}
return pid, true
}
return 0, false
}
func logConcurrencyPlanning(limit, total int) {
logger := activeLogger()
if logger == nil {
return
}
logger.Info(fmt.Sprintf("parallel: worker_limit=%s total_tasks=%d", renderWorkerLimit(limit), total))
}
func logConcurrencyState(event, taskID string, active, limit int) {
logger := activeLogger()
if logger == nil {
return
}
logger.Debug(fmt.Sprintf("parallel: %s task=%s active=%d limit=%s", event, taskID, active, renderWorkerLimit(limit)))
}
func renderWorkerLimit(limit int) string {
if limit <= 0 {
return "unbounded"
}
return strconv.Itoa(limit)
}
func CleanupOldLogs() (CleanupStats, error) { return cleanupOldLogs() }
func IsUnsafeFile(path string, tempDir string) (bool, string) { return isUnsafeFile(path, tempDir) }
func IsPIDReused(logPath string, pid int) bool { return isPIDReused(logPath, pid) }
func ParsePIDFromLog(path string) (int, bool) { return parsePIDFromLog(path) }
func LogConcurrencyPlanning(limit, total int) { logConcurrencyPlanning(limit, total) }
func LogConcurrencyState(event, taskID string, active, limit int) {
logConcurrencyState(event, taskID, active, limit)
}
func SanitizeLogSuffix(raw string) string { return sanitizeLogSuffix(raw) }

View File

@@ -0,0 +1,158 @@
package logger
import (
"fmt"
"os"
"path/filepath"
"strings"
"testing"
)
func TestLoggerNilReceiverNoop(t *testing.T) {
var logger *Logger
logger.Info("info")
logger.Warn("warn")
logger.Debug("debug")
logger.Error("error")
logger.Flush()
if err := logger.Close(); err != nil {
t.Fatalf("Close() on nil logger should return nil, got %v", err)
}
}
func TestLoggerConcurrencyLogHelpers(t *testing.T) {
setTempDirEnv(t, t.TempDir())
logger, err := NewLoggerWithSuffix("concurrency")
if err != nil {
t.Fatalf("NewLoggerWithSuffix error: %v", err)
}
setLogger(logger)
defer func() { _ = closeLogger() }()
logConcurrencyPlanning(0, 2)
logConcurrencyPlanning(3, 2)
logConcurrencyState("start", "task-1", 1, 0)
logConcurrencyState("done", "task-1", 0, 3)
logger.Flush()
data, err := os.ReadFile(logger.Path())
if err != nil {
t.Fatalf("failed to read log file: %v", err)
}
output := string(data)
checks := []string{
"parallel: worker_limit=unbounded total_tasks=2",
"parallel: worker_limit=3 total_tasks=2",
"parallel: start task=task-1 active=1 limit=unbounded",
"parallel: done task=task-1 active=0 limit=3",
}
for _, c := range checks {
if !strings.Contains(output, c) {
t.Fatalf("log output missing %q, got: %s", c, output)
}
}
}
func TestLoggerConcurrencyLogHelpersNoopWithoutActiveLogger(t *testing.T) {
_ = closeLogger()
logConcurrencyPlanning(1, 1)
logConcurrencyState("start", "task-1", 0, 1)
}
func TestLoggerCleanupOldLogsSkipsUnsafeAndHandlesAlreadyDeleted(t *testing.T) {
tempDir := setTempDirEnv(t, t.TempDir())
unsafePath := createTempLog(t, tempDir, fmt.Sprintf("%s-%d.log", PrimaryLogPrefix(), 222))
orphanPath := createTempLog(t, tempDir, fmt.Sprintf("%s-%d.log", PrimaryLogPrefix(), 111))
stubFileStat(t, func(path string) (os.FileInfo, error) {
if path == unsafePath {
return fakeFileInfo{mode: os.ModeSymlink}, nil
}
return os.Lstat(path)
})
stubProcessRunning(t, func(pid int) bool {
if pid == 111 {
_ = os.Remove(orphanPath)
}
return false
})
stats, err := cleanupOldLogs()
if err != nil {
t.Fatalf("cleanupOldLogs() unexpected error: %v", err)
}
if stats.Scanned != 2 {
t.Fatalf("scanned = %d, want %d", stats.Scanned, 2)
}
if stats.Deleted != 0 {
t.Fatalf("deleted = %d, want %d", stats.Deleted, 0)
}
if stats.Kept != 2 {
t.Fatalf("kept = %d, want %d", stats.Kept, 2)
}
if stats.Errors != 0 {
t.Fatalf("errors = %d, want %d", stats.Errors, 0)
}
hasSkip := false
hasAlreadyDeleted := false
for _, name := range stats.KeptFiles {
if strings.Contains(name, "already deleted") {
hasAlreadyDeleted = true
}
if strings.Contains(name, filepath.Base(unsafePath)) {
hasSkip = true
}
}
if !hasSkip {
t.Fatalf("expected kept files to include unsafe log %q, got %+v", filepath.Base(unsafePath), stats.KeptFiles)
}
if !hasAlreadyDeleted {
t.Fatalf("expected kept files to include already deleted marker, got %+v", stats.KeptFiles)
}
}
func TestLoggerIsUnsafeFileErrorPaths(t *testing.T) {
tempDir := t.TempDir()
t.Run("stat ErrNotExist", func(t *testing.T) {
stubFileStat(t, func(string) (os.FileInfo, error) {
return nil, os.ErrNotExist
})
unsafe, reason := isUnsafeFile("missing.log", tempDir)
if !unsafe || reason != "" {
t.Fatalf("expected missing file to be skipped silently, got unsafe=%v reason=%q", unsafe, reason)
}
})
t.Run("stat error", func(t *testing.T) {
stubFileStat(t, func(string) (os.FileInfo, error) {
return nil, fmt.Errorf("boom")
})
unsafe, reason := isUnsafeFile("broken.log", tempDir)
if !unsafe || !strings.Contains(reason, "stat failed") {
t.Fatalf("expected stat failure to be unsafe, got unsafe=%v reason=%q", unsafe, reason)
}
})
t.Run("EvalSymlinks error", func(t *testing.T) {
stubFileStat(t, func(string) (os.FileInfo, error) {
return fakeFileInfo{}, nil
})
stubEvalSymlinks(t, func(string) (string, error) {
return "", fmt.Errorf("resolve failed")
})
unsafe, reason := isUnsafeFile("cannot-resolve.log", tempDir)
if !unsafe || !strings.Contains(reason, "path resolution failed") {
t.Fatalf("expected resolution failure to be unsafe, got unsafe=%v reason=%q", unsafe, reason)
}
})
}

View File

@@ -0,0 +1,115 @@
package logger
import (
"fmt"
"os"
"path/filepath"
"strings"
"testing"
)
func TestLoggerWithSuffixNamingAndIsolation(t *testing.T) {
tempDir := setTempDirEnv(t, t.TempDir())
taskA := "task-1"
taskB := "task-2"
loggerA, err := NewLoggerWithSuffix(taskA)
if err != nil {
t.Fatalf("NewLoggerWithSuffix(%q) error = %v", taskA, err)
}
defer loggerA.Close()
loggerB, err := NewLoggerWithSuffix(taskB)
if err != nil {
t.Fatalf("NewLoggerWithSuffix(%q) error = %v", taskB, err)
}
defer loggerB.Close()
wantA := filepath.Join(tempDir, fmt.Sprintf("%s-%d-%s.log", PrimaryLogPrefix(), os.Getpid(), taskA))
if loggerA.Path() != wantA {
t.Fatalf("loggerA path = %q, want %q", loggerA.Path(), wantA)
}
wantB := filepath.Join(tempDir, fmt.Sprintf("%s-%d-%s.log", PrimaryLogPrefix(), os.Getpid(), taskB))
if loggerB.Path() != wantB {
t.Fatalf("loggerB path = %q, want %q", loggerB.Path(), wantB)
}
if loggerA.Path() == loggerB.Path() {
t.Fatalf("expected different log files, got %q", loggerA.Path())
}
loggerA.Info("from taskA")
loggerB.Info("from taskB")
loggerA.Flush()
loggerB.Flush()
dataA, err := os.ReadFile(loggerA.Path())
if err != nil {
t.Fatalf("failed to read loggerA file: %v", err)
}
dataB, err := os.ReadFile(loggerB.Path())
if err != nil {
t.Fatalf("failed to read loggerB file: %v", err)
}
if !strings.Contains(string(dataA), "from taskA") {
t.Fatalf("loggerA missing its message, got: %q", string(dataA))
}
if strings.Contains(string(dataA), "from taskB") {
t.Fatalf("loggerA contains loggerB message, got: %q", string(dataA))
}
if !strings.Contains(string(dataB), "from taskB") {
t.Fatalf("loggerB missing its message, got: %q", string(dataB))
}
if strings.Contains(string(dataB), "from taskA") {
t.Fatalf("loggerB contains loggerA message, got: %q", string(dataB))
}
}
func TestLoggerWithSuffixReturnsErrorWhenTempDirNotWritable(t *testing.T) {
base := t.TempDir()
noWrite := filepath.Join(base, "ro")
if err := os.Mkdir(noWrite, 0o500); err != nil {
t.Fatalf("failed to create read-only temp dir: %v", err)
}
t.Cleanup(func() { _ = os.Chmod(noWrite, 0o700) })
setTempDirEnv(t, noWrite)
logger, err := NewLoggerWithSuffix("task-err")
if err == nil {
_ = logger.Close()
t.Fatalf("expected error when temp dir is not writable")
}
}
func TestLoggerWithSuffixSanitizesUnsafeSuffix(t *testing.T) {
tempDir := setTempDirEnv(t, t.TempDir())
raw := "../bad id/with?chars"
safe := sanitizeLogSuffix(raw)
if safe == "" {
t.Fatalf("sanitizeLogSuffix returned empty string")
}
if strings.ContainsAny(safe, "/\\") {
t.Fatalf("sanitized suffix should not contain path separators, got %q", safe)
}
logger, err := NewLoggerWithSuffix(raw)
if err != nil {
t.Fatalf("NewLoggerWithSuffix(%q) error = %v", raw, err)
}
t.Cleanup(func() {
_ = logger.Close()
_ = os.Remove(logger.Path())
})
wantBase := fmt.Sprintf("%s-%d-%s.log", PrimaryLogPrefix(), os.Getpid(), safe)
if gotBase := filepath.Base(logger.Path()); gotBase != wantBase {
t.Fatalf("log filename = %q, want %q", gotBase, wantBase)
}
if dir := filepath.Dir(logger.Path()); dir != tempDir {
t.Fatalf("logger path dir = %q, want %q", dir, tempDir)
}
}

View File

@@ -0,0 +1,903 @@
package logger
import (
"bufio"
"errors"
"fmt"
"math"
"os"
"path/filepath"
"strconv"
"strings"
"sync"
"testing"
"time"
)
func compareCleanupStats(got, want CleanupStats) bool {
if got.Scanned != want.Scanned || got.Deleted != want.Deleted || got.Kept != want.Kept || got.Errors != want.Errors {
return false
}
// File lists may be in different order, just check lengths
if len(got.DeletedFiles) != want.Deleted || len(got.KeptFiles) != want.Kept {
return false
}
return true
}
func TestLoggerCreatesFileWithPID(t *testing.T) {
tempDir := t.TempDir()
t.Setenv("TMPDIR", tempDir)
logger, err := NewLogger()
if err != nil {
t.Fatalf("NewLogger() error = %v", err)
}
defer logger.Close()
expectedPath := filepath.Join(tempDir, fmt.Sprintf("codeagent-wrapper-%d.log", os.Getpid()))
if logger.Path() != expectedPath {
t.Fatalf("logger path = %s, want %s", logger.Path(), expectedPath)
}
if _, err := os.Stat(expectedPath); err != nil {
t.Fatalf("log file not created: %v", err)
}
}
func TestLoggerWritesLevels(t *testing.T) {
tempDir := t.TempDir()
t.Setenv("TMPDIR", tempDir)
logger, err := NewLogger()
if err != nil {
t.Fatalf("NewLogger() error = %v", err)
}
defer logger.Close()
logger.Info("info message")
logger.Warn("warn message")
logger.Debug("debug message")
logger.Error("error message")
logger.Flush()
data, err := os.ReadFile(logger.Path())
if err != nil {
t.Fatalf("failed to read log file: %v", err)
}
content := string(data)
checks := []string{"info message", "warn message", "debug message", "error message"}
for _, c := range checks {
if !strings.Contains(content, c) {
t.Fatalf("log file missing entry %q, content: %s", c, content)
}
}
}
func TestLoggerCloseStopsWorkerAndKeepsFile(t *testing.T) {
tempDir := t.TempDir()
t.Setenv("TMPDIR", tempDir)
logger, err := NewLogger()
if err != nil {
t.Fatalf("NewLogger() error = %v", err)
}
logger.Info("before close")
logger.Flush()
logPath := logger.Path()
if err := logger.Close(); err != nil {
t.Fatalf("Close() returned error: %v", err)
}
// After recent changes, log file is kept for debugging - NOT removed
if _, err := os.Stat(logPath); os.IsNotExist(err) {
t.Fatalf("log file should exist after Close for debugging, but got IsNotExist")
}
// Clean up manually for test
defer os.Remove(logPath)
}
func TestLoggerConcurrentWritesSafe(t *testing.T) {
tempDir := t.TempDir()
t.Setenv("TMPDIR", tempDir)
logger, err := NewLogger()
if err != nil {
t.Fatalf("NewLogger() error = %v", err)
}
defer logger.Close()
const goroutines = 10
const perGoroutine = 50
var wg sync.WaitGroup
wg.Add(goroutines)
for i := 0; i < goroutines; i++ {
go func(id int) {
defer wg.Done()
for j := 0; j < perGoroutine; j++ {
logger.Debug(fmt.Sprintf("g%d-%d", id, j))
}
}(i)
}
wg.Wait()
logger.Flush()
f, err := os.Open(logger.Path())
if err != nil {
t.Fatalf("failed to open log file: %v", err)
}
defer f.Close()
scanner := bufio.NewScanner(f)
count := 0
for scanner.Scan() {
count++
}
if err := scanner.Err(); err != nil {
t.Fatalf("scanner error: %v", err)
}
expected := goroutines * perGoroutine
if count != expected {
t.Fatalf("unexpected log line count: got %d, want %d", count, expected)
}
}
func TestLoggerCleanupOldLogsRemovesOrphans(t *testing.T) {
tempDir := setTempDirEnv(t, t.TempDir())
orphan1 := createTempLog(t, tempDir, "codeagent-wrapper-111.log")
orphan2 := createTempLog(t, tempDir, "codeagent-wrapper-222-suffix.log")
running1 := createTempLog(t, tempDir, "codeagent-wrapper-333.log")
running2 := createTempLog(t, tempDir, "codeagent-wrapper-444-extra-info.log")
untouched := createTempLog(t, tempDir, "unrelated.log")
runningPIDs := map[int]bool{333: true, 444: true}
stubProcessRunning(t, func(pid int) bool {
return runningPIDs[pid]
})
// Stub process start time to be in the past so files won't be considered as PID reused
stubProcessStartTime(t, func(pid int) time.Time {
if runningPIDs[pid] {
// Return a time before file creation
return time.Now().Add(-1 * time.Hour)
}
return time.Time{}
})
stats, err := cleanupOldLogs()
if err != nil {
t.Fatalf("cleanupOldLogs() unexpected error: %v", err)
}
want := CleanupStats{Scanned: 4, Deleted: 2, Kept: 2}
if !compareCleanupStats(stats, want) {
t.Fatalf("cleanup stats mismatch: got %+v, want %+v", stats, want)
}
if _, err := os.Stat(orphan1); !os.IsNotExist(err) {
t.Fatalf("expected orphan %s to be removed, err=%v", orphan1, err)
}
if _, err := os.Stat(orphan2); !os.IsNotExist(err) {
t.Fatalf("expected orphan %s to be removed, err=%v", orphan2, err)
}
if _, err := os.Stat(running1); err != nil {
t.Fatalf("expected running log %s to remain, err=%v", running1, err)
}
if _, err := os.Stat(running2); err != nil {
t.Fatalf("expected running log %s to remain, err=%v", running2, err)
}
if _, err := os.Stat(untouched); err != nil {
t.Fatalf("expected unrelated file %s to remain, err=%v", untouched, err)
}
}
func TestLoggerCleanupOldLogsHandlesInvalidNamesAndErrors(t *testing.T) {
tempDir := setTempDirEnv(t, t.TempDir())
invalid := []string{
"codeagent-wrapper-.log",
"codeagent-wrapper.log",
"codeagent-wrapper-foo-bar.txt",
"not-a-codex.log",
}
for _, name := range invalid {
createTempLog(t, tempDir, name)
}
target := createTempLog(t, tempDir, "codeagent-wrapper-555-extra.log")
var checked []int
stubProcessRunning(t, func(pid int) bool {
checked = append(checked, pid)
return false
})
stubProcessStartTime(t, func(pid int) time.Time {
return time.Time{} // Return zero time for processes not running
})
removeErr := errors.New("remove failure")
callCount := 0
stubRemoveLogFile(t, func(path string) error {
callCount++
if path == target {
return removeErr
}
return os.Remove(path)
})
stats, err := cleanupOldLogs()
if err == nil {
t.Fatalf("cleanupOldLogs() expected error")
}
if !errors.Is(err, removeErr) {
t.Fatalf("cleanupOldLogs error = %v, want %v", err, removeErr)
}
want := CleanupStats{Scanned: 2, Kept: 1, Errors: 1}
if !compareCleanupStats(stats, want) {
t.Fatalf("cleanup stats mismatch: got %+v, want %+v", stats, want)
}
if len(checked) != 1 || checked[0] != 555 {
t.Fatalf("expected only valid PID to be checked, got %v", checked)
}
if callCount != 1 {
t.Fatalf("expected remove to be called once, got %d", callCount)
}
if _, err := os.Stat(target); err != nil {
t.Fatalf("expected errored file %s to remain for manual cleanup, err=%v", target, err)
}
}
func TestLoggerCleanupOldLogsHandlesGlobFailures(t *testing.T) {
stubProcessRunning(t, func(pid int) bool {
t.Fatalf("process check should not run when glob fails")
return false
})
stubProcessStartTime(t, func(int) time.Time {
return time.Time{}
})
globErr := errors.New("glob failure")
stubGlobLogFiles(t, func(pattern string) ([]string, error) {
return nil, globErr
})
stats, err := cleanupOldLogs()
if err == nil {
t.Fatalf("cleanupOldLogs() expected error")
}
if !errors.Is(err, globErr) {
t.Fatalf("cleanupOldLogs error = %v, want %v", err, globErr)
}
if stats.Scanned != 0 || stats.Deleted != 0 || stats.Kept != 0 || stats.Errors != 0 || len(stats.DeletedFiles) != 0 || len(stats.KeptFiles) != 0 {
t.Fatalf("cleanup stats mismatch: got %+v, want zero", stats)
}
}
func TestLoggerCleanupOldLogsEmptyDirectoryStats(t *testing.T) {
setTempDirEnv(t, t.TempDir())
stubProcessRunning(t, func(int) bool {
t.Fatalf("process check should not run for empty directory")
return false
})
stubProcessStartTime(t, func(int) time.Time {
return time.Time{}
})
stats, err := cleanupOldLogs()
if err != nil {
t.Fatalf("cleanupOldLogs() unexpected error: %v", err)
}
if stats.Scanned != 0 || stats.Deleted != 0 || stats.Kept != 0 || stats.Errors != 0 || len(stats.DeletedFiles) != 0 || len(stats.KeptFiles) != 0 {
t.Fatalf("cleanup stats mismatch: got %+v, want zero", stats)
}
}
func TestLoggerCleanupOldLogsHandlesTempDirPermissionErrors(t *testing.T) {
tempDir := setTempDirEnv(t, t.TempDir())
paths := []string{
createTempLog(t, tempDir, "codeagent-wrapper-6100.log"),
createTempLog(t, tempDir, "codeagent-wrapper-6101.log"),
}
stubProcessRunning(t, func(int) bool { return false })
stubProcessStartTime(t, func(int) time.Time { return time.Time{} })
var attempts int
stubRemoveLogFile(t, func(path string) error {
attempts++
return &os.PathError{Op: "remove", Path: path, Err: os.ErrPermission}
})
stats, err := cleanupOldLogs()
if err == nil {
t.Fatalf("cleanupOldLogs() expected error")
}
if !errors.Is(err, os.ErrPermission) {
t.Fatalf("cleanupOldLogs error = %v, want permission", err)
}
want := CleanupStats{Scanned: len(paths), Errors: len(paths)}
if !compareCleanupStats(stats, want) {
t.Fatalf("cleanup stats mismatch: got %+v, want %+v", stats, want)
}
if attempts != len(paths) {
t.Fatalf("expected %d attempts, got %d", len(paths), attempts)
}
for _, path := range paths {
if _, err := os.Stat(path); err != nil {
t.Fatalf("expected protected file %s to remain, err=%v", path, err)
}
}
}
func TestLoggerCleanupOldLogsHandlesPermissionDeniedFile(t *testing.T) {
tempDir := setTempDirEnv(t, t.TempDir())
protected := createTempLog(t, tempDir, "codeagent-wrapper-6200.log")
deletable := createTempLog(t, tempDir, "codeagent-wrapper-6201.log")
stubProcessRunning(t, func(int) bool { return false })
stubProcessStartTime(t, func(int) time.Time { return time.Time{} })
stubRemoveLogFile(t, func(path string) error {
if path == protected {
return &os.PathError{Op: "remove", Path: path, Err: os.ErrPermission}
}
return os.Remove(path)
})
stats, err := cleanupOldLogs()
if err == nil {
t.Fatalf("cleanupOldLogs() expected error")
}
if !errors.Is(err, os.ErrPermission) {
t.Fatalf("cleanupOldLogs error = %v, want permission", err)
}
want := CleanupStats{Scanned: 2, Deleted: 1, Errors: 1}
if !compareCleanupStats(stats, want) {
t.Fatalf("cleanup stats mismatch: got %+v, want %+v", stats, want)
}
if _, err := os.Stat(protected); err != nil {
t.Fatalf("expected protected file to remain, err=%v", err)
}
if _, err := os.Stat(deletable); !os.IsNotExist(err) {
t.Fatalf("expected deletable file to be removed, err=%v", err)
}
}
func TestLoggerCleanupOldLogsPerformanceBound(t *testing.T) {
tempDir := setTempDirEnv(t, t.TempDir())
const fileCount = 400
fakePaths := make([]string, fileCount)
for i := 0; i < fileCount; i++ {
name := fmt.Sprintf("codeagent-wrapper-%d.log", 10000+i)
fakePaths[i] = createTempLog(t, tempDir, name)
}
stubGlobLogFiles(t, func(pattern string) ([]string, error) {
return fakePaths, nil
})
stubProcessRunning(t, func(int) bool { return false })
stubProcessStartTime(t, func(int) time.Time { return time.Time{} })
var removed int
stubRemoveLogFile(t, func(path string) error {
removed++
return nil
})
start := time.Now()
stats, err := cleanupOldLogs()
elapsed := time.Since(start)
if err != nil {
t.Fatalf("cleanupOldLogs() unexpected error: %v", err)
}
if removed != fileCount {
t.Fatalf("expected %d removals, got %d", fileCount, removed)
}
if elapsed > 100*time.Millisecond {
t.Fatalf("cleanup took too long: %v for %d files", elapsed, fileCount)
}
want := CleanupStats{Scanned: fileCount, Deleted: fileCount}
if !compareCleanupStats(stats, want) {
t.Fatalf("cleanup stats mismatch: got %+v, want %+v", stats, want)
}
}
func TestLoggerCleanupOldLogsKeepsCurrentProcessLog(t *testing.T) {
tempDir := setTempDirEnv(t, t.TempDir())
currentPID := os.Getpid()
currentLog := createTempLog(t, tempDir, fmt.Sprintf("codeagent-wrapper-%d.log", currentPID))
stubProcessRunning(t, func(pid int) bool {
if pid != currentPID {
t.Fatalf("unexpected pid check: %d", pid)
}
return true
})
stubProcessStartTime(t, func(pid int) time.Time {
if pid == currentPID {
return time.Now().Add(-1 * time.Hour)
}
return time.Time{}
})
stats, err := cleanupOldLogs()
if err != nil {
t.Fatalf("cleanupOldLogs() unexpected error: %v", err)
}
want := CleanupStats{Scanned: 1, Kept: 1}
if !compareCleanupStats(stats, want) {
t.Fatalf("cleanup stats mismatch: got %+v, want %+v", stats, want)
}
if _, err := os.Stat(currentLog); err != nil {
t.Fatalf("expected current process log to remain, err=%v", err)
}
}
func TestLoggerIsPIDReusedScenarios(t *testing.T) {
now := time.Now()
tests := []struct {
name string
statErr error
modTime time.Time
startTime time.Time
want bool
}{
{"stat error", errors.New("stat failed"), time.Time{}, time.Time{}, false},
{"old file unknown start", nil, now.Add(-8 * 24 * time.Hour), time.Time{}, true},
{"recent file unknown start", nil, now.Add(-2 * time.Hour), time.Time{}, false},
{"pid reused", nil, now.Add(-2 * time.Hour), now.Add(-30 * time.Minute), true},
{"pid active", nil, now.Add(-30 * time.Minute), now.Add(-2 * time.Hour), false},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
stubFileStat(t, func(string) (os.FileInfo, error) {
if tt.statErr != nil {
return nil, tt.statErr
}
return fakeFileInfo{modTime: tt.modTime}, nil
})
stubProcessStartTime(t, func(int) time.Time {
return tt.startTime
})
if got := isPIDReused("log", 1234); got != tt.want {
t.Fatalf("isPIDReused() = %v, want %v", got, tt.want)
}
})
}
}
func TestLoggerIsUnsafeFileSecurityChecks(t *testing.T) {
tempDir := t.TempDir()
absTempDir, err := filepath.Abs(tempDir)
if err != nil {
t.Fatalf("filepath.Abs() error = %v", err)
}
t.Run("symlink", func(t *testing.T) {
stubFileStat(t, func(string) (os.FileInfo, error) {
return fakeFileInfo{mode: os.ModeSymlink}, nil
})
stubEvalSymlinks(t, func(path string) (string, error) {
return filepath.Join(absTempDir, filepath.Base(path)), nil
})
unsafe, reason := isUnsafeFile(filepath.Join(absTempDir, "codeagent-wrapper-1.log"), tempDir)
if !unsafe || reason != "refusing to delete symlink" {
t.Fatalf("expected symlink to be rejected, got unsafe=%v reason=%q", unsafe, reason)
}
})
t.Run("path traversal", func(t *testing.T) {
stubFileStat(t, func(string) (os.FileInfo, error) {
return fakeFileInfo{}, nil
})
outside := filepath.Join(filepath.Dir(absTempDir), "etc", "passwd")
stubEvalSymlinks(t, func(string) (string, error) {
return outside, nil
})
unsafe, reason := isUnsafeFile(filepath.Join("..", "..", "etc", "passwd"), tempDir)
if !unsafe || reason != "file is outside tempDir" {
t.Fatalf("expected traversal path to be rejected, got unsafe=%v reason=%q", unsafe, reason)
}
})
t.Run("outside temp dir", func(t *testing.T) {
stubFileStat(t, func(string) (os.FileInfo, error) {
return fakeFileInfo{}, nil
})
otherDir := t.TempDir()
stubEvalSymlinks(t, func(string) (string, error) {
return filepath.Join(otherDir, "codeagent-wrapper-9.log"), nil
})
unsafe, reason := isUnsafeFile(filepath.Join(otherDir, "codeagent-wrapper-9.log"), tempDir)
if !unsafe || reason != "file is outside tempDir" {
t.Fatalf("expected outside file to be rejected, got unsafe=%v reason=%q", unsafe, reason)
}
})
}
func TestLoggerPathAndRemove(t *testing.T) {
tempDir := t.TempDir()
t.Setenv("TMPDIR", tempDir)
logger, err := NewLoggerWithSuffix("sample")
if err != nil {
t.Fatalf("NewLoggerWithSuffix() error = %v", err)
}
path := logger.Path()
if path == "" {
_ = logger.Close()
t.Fatalf("logger.Path() returned empty path")
}
if err := logger.Close(); err != nil {
t.Fatalf("Close() error = %v", err)
}
if err := logger.RemoveLogFile(); err != nil {
t.Fatalf("RemoveLogFile() error = %v", err)
}
if _, err := os.Stat(path); !os.IsNotExist(err) {
t.Fatalf("expected log file to be removed, err=%v", err)
}
var nilLogger *Logger
if nilLogger.Path() != "" {
t.Fatalf("nil logger Path() should be empty")
}
if err := nilLogger.RemoveLogFile(); err != nil {
t.Fatalf("nil logger RemoveLogFile() should return nil, got %v", err)
}
}
func TestLoggerParsePIDFromLog(t *testing.T) {
hugePID := strconv.FormatInt(math.MaxInt64, 10) + "0"
tests := []struct {
name string
pid int
ok bool
}{
{"codeagent-wrapper-123.log", 123, true},
{"codeagent-wrapper-999-extra.log", 999, true},
{"codeagent-wrapper-.log", 0, false},
{"invalid-name.log", 0, false},
{"codeagent-wrapper--5.log", 0, false},
{"codeagent-wrapper-0.log", 0, false},
{fmt.Sprintf("codeagent-wrapper-%s.log", hugePID), 0, false},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
got, ok := parsePIDFromLog(filepath.Join("/tmp", tt.name))
if ok != tt.ok {
t.Fatalf("parsePIDFromLog ok = %v, want %v", ok, tt.ok)
}
if ok && got != tt.pid {
t.Fatalf("pid = %d, want %d", got, tt.pid)
}
})
}
}
func createTempLog(t *testing.T, dir, name string) string {
t.Helper()
path := filepath.Join(dir, name)
if err := os.WriteFile(path, []byte("test"), 0o644); err != nil {
t.Fatalf("failed to create temp log %s: %v", path, err)
}
return path
}
func setTempDirEnv(t *testing.T, dir string) string {
t.Helper()
resolved := dir
if eval, err := filepath.EvalSymlinks(dir); err == nil {
resolved = eval
}
t.Setenv("TMPDIR", resolved)
t.Setenv("TEMP", resolved)
t.Setenv("TMP", resolved)
return resolved
}
func stubProcessRunning(t *testing.T, fn func(int) bool) {
t.Helper()
t.Cleanup(SetProcessRunningCheck(fn))
}
func stubProcessStartTime(t *testing.T, fn func(int) time.Time) {
t.Helper()
t.Cleanup(SetProcessStartTimeFn(fn))
}
func stubRemoveLogFile(t *testing.T, fn func(string) error) {
t.Helper()
t.Cleanup(SetRemoveLogFileFn(fn))
}
func stubGlobLogFiles(t *testing.T, fn func(string) ([]string, error)) {
t.Helper()
t.Cleanup(SetGlobLogFilesFn(fn))
}
func stubFileStat(t *testing.T, fn func(string) (os.FileInfo, error)) {
t.Helper()
t.Cleanup(SetFileStatFn(fn))
}
func stubEvalSymlinks(t *testing.T, fn func(string) (string, error)) {
t.Helper()
t.Cleanup(SetEvalSymlinksFn(fn))
}
type fakeFileInfo struct {
modTime time.Time
mode os.FileMode
}
func (f fakeFileInfo) Name() string { return "fake" }
func (f fakeFileInfo) Size() int64 { return 0 }
func (f fakeFileInfo) Mode() os.FileMode { return f.mode }
func (f fakeFileInfo) ModTime() time.Time { return f.modTime }
func (f fakeFileInfo) IsDir() bool { return false }
func (f fakeFileInfo) Sys() interface{} { return nil }
func TestLoggerExtractRecentErrors(t *testing.T) {
tests := []struct {
name string
logs []struct{ level, msg string }
maxEntries int
want []string
}{
{
name: "empty log",
logs: nil,
maxEntries: 10,
want: nil,
},
{
name: "no errors",
logs: []struct{ level, msg string }{
{"INFO", "started"},
{"DEBUG", "processing"},
},
maxEntries: 10,
want: nil,
},
{
name: "single error",
logs: []struct{ level, msg string }{
{"INFO", "started"},
{"ERROR", "something failed"},
},
maxEntries: 10,
want: []string{"something failed"},
},
{
name: "error and warn",
logs: []struct{ level, msg string }{
{"INFO", "started"},
{"WARN", "warning message"},
{"ERROR", "error message"},
},
maxEntries: 10,
want: []string{
"warning message",
"error message",
},
},
{
name: "truncate to max",
logs: []struct{ level, msg string }{
{"ERROR", "error 1"},
{"ERROR", "error 2"},
{"ERROR", "error 3"},
{"ERROR", "error 4"},
{"ERROR", "error 5"},
},
maxEntries: 3,
want: []string{
"error 3",
"error 4",
"error 5",
},
},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
logger, err := NewLoggerWithSuffix("extract-test")
if err != nil {
t.Fatalf("NewLoggerWithSuffix() error = %v", err)
}
defer logger.Close()
defer func() { _ = logger.RemoveLogFile() }()
// Write logs using logger methods
for _, entry := range tt.logs {
switch entry.level {
case "INFO":
logger.Info(entry.msg)
case "WARN":
logger.Warn(entry.msg)
case "ERROR":
logger.Error(entry.msg)
case "DEBUG":
logger.Debug(entry.msg)
}
}
logger.Flush()
got := logger.ExtractRecentErrors(tt.maxEntries)
if len(got) != len(tt.want) {
t.Fatalf("ExtractRecentErrors() got %d entries, want %d", len(got), len(tt.want))
}
for i, entry := range got {
if entry != tt.want[i] {
t.Errorf("entry[%d] = %q, want %q", i, entry, tt.want[i])
}
}
})
}
}
func TestLoggerExtractRecentErrorsNilLogger(t *testing.T) {
var logger *Logger
if got := logger.ExtractRecentErrors(10); got != nil {
t.Fatalf("nil logger ExtractRecentErrors() should return nil, got %v", got)
}
}
func TestLoggerExtractRecentErrorsEmptyPath(t *testing.T) {
logger := &Logger{}
if got := logger.ExtractRecentErrors(10); got != nil {
t.Fatalf("empty path ExtractRecentErrors() should return nil, got %v", got)
}
}
func TestLoggerExtractRecentErrorsFileNotExist(t *testing.T) {
logger := &Logger{}
if got := logger.ExtractRecentErrors(10); got != nil {
t.Fatalf("nonexistent file ExtractRecentErrors() should return nil, got %v", got)
}
}
func TestSanitizeLogSuffixNoDuplicates(t *testing.T) {
testCases := []string{
"task",
"task.",
".task",
"-task",
"task-",
"--task--",
"..task..",
}
seen := make(map[string]string)
for _, input := range testCases {
result := sanitizeLogSuffix(input)
if result == "" {
t.Fatalf("sanitizeLogSuffix(%q) returned empty string", input)
}
if prev, exists := seen[result]; exists {
t.Fatalf("collision detected: %q and %q both produce %q", input, prev, result)
}
seen[result] = input
// Verify result is safe for file names
if strings.ContainsAny(result, "/\\:*?\"<>|") {
t.Fatalf("sanitizeLogSuffix(%q) = %q contains unsafe characters", input, result)
}
}
}
func TestExtractRecentErrorsBoundaryCheck(t *testing.T) {
logger, err := NewLoggerWithSuffix("boundary-test")
if err != nil {
t.Fatalf("NewLoggerWithSuffix() error = %v", err)
}
defer logger.Close()
defer func() { _ = logger.RemoveLogFile() }()
// Write some errors
logger.Error("error 1")
logger.Warn("warn 1")
logger.Error("error 2")
logger.Flush()
// Test zero
result := logger.ExtractRecentErrors(0)
if result != nil {
t.Fatalf("ExtractRecentErrors(0) should return nil, got %v", result)
}
// Test negative
result = logger.ExtractRecentErrors(-5)
if result != nil {
t.Fatalf("ExtractRecentErrors(-5) should return nil, got %v", result)
}
// Test positive still works
result = logger.ExtractRecentErrors(10)
if len(result) != 3 {
t.Fatalf("ExtractRecentErrors(10) expected 3 entries, got %d", len(result))
}
}
func TestErrorEntriesMaxLimit(t *testing.T) {
logger, err := NewLoggerWithSuffix("max-limit-test")
if err != nil {
t.Fatalf("NewLoggerWithSuffix() error = %v", err)
}
defer logger.Close()
defer func() { _ = logger.RemoveLogFile() }()
// Write 150 error/warn entries
for i := 1; i <= 150; i++ {
if i%2 == 0 {
logger.Error(fmt.Sprintf("error-%03d", i))
} else {
logger.Warn(fmt.Sprintf("warn-%03d", i))
}
}
logger.Flush()
// Extract all cached errors
result := logger.ExtractRecentErrors(200) // Request more than cache size
// Should only have last 100 entries (entries 51-150 in sequence)
if len(result) != 100 {
t.Fatalf("expected 100 cached entries, got %d", len(result))
}
// Verify entries are the last 100 (entries 51-150)
if !strings.Contains(result[0], "051") {
t.Fatalf("first cached entry should be entry 51, got: %s", result[0])
}
if !strings.Contains(result[99], "150") {
t.Fatalf("last cached entry should be entry 150, got: %s", result[99])
}
// Verify order is preserved - simplified logic
for i := 0; i < len(result)-1; i++ {
expectedNum := 51 + i
nextNum := 51 + i + 1
expectedEntry := fmt.Sprintf("%03d", expectedNum)
nextEntry := fmt.Sprintf("%03d", nextNum)
if !strings.Contains(result[i], expectedEntry) {
t.Fatalf("entry at index %d should contain %s, got: %s", i, expectedEntry, result[i])
}
if !strings.Contains(result[i+1], nextEntry) {
t.Fatalf("entry at index %d should contain %s, got: %s", i+1, nextEntry, result[i+1])
}
}
}

View File

@@ -0,0 +1,63 @@
package logger
import (
"errors"
"math"
"time"
"github.com/shirou/gopsutil/v3/process"
)
func pidToInt32(pid int) (int32, bool) {
if pid <= 0 || pid > math.MaxInt32 {
return 0, false
}
return int32(pid), true
}
// isProcessRunning reports whether a process with the given pid appears to be running.
// It is intentionally conservative on errors to avoid deleting logs for live processes.
func isProcessRunning(pid int) bool {
pid32, ok := pidToInt32(pid)
if !ok {
return false
}
exists, err := process.PidExists(pid32)
if err == nil {
return exists
}
// If we can positively identify that the process doesn't exist, report false.
if errors.Is(err, process.ErrorProcessNotRunning) {
return false
}
// Permission/inspection failures: assume it's running to be safe.
return true
}
// getProcessStartTime returns the start time of a process.
// Returns zero time if the start time cannot be determined.
func getProcessStartTime(pid int) time.Time {
pid32, ok := pidToInt32(pid)
if !ok {
return time.Time{}
}
proc, err := process.NewProcess(pid32)
if err != nil {
return time.Time{}
}
ms, err := proc.CreateTime()
if err != nil || ms <= 0 {
return time.Time{}
}
return time.UnixMilli(ms)
}
func IsProcessRunning(pid int) bool { return isProcessRunning(pid) }
func GetProcessStartTime(pid int) time.Time { return getProcessStartTime(pid) }

View File

@@ -0,0 +1,112 @@
package logger
import (
"math"
"os"
"os/exec"
"runtime"
"strconv"
"testing"
"time"
)
func TestIsProcessRunning(t *testing.T) {
t.Run("boundary values", func(t *testing.T) {
if isProcessRunning(0) {
t.Fatalf("pid 0 should never be treated as running")
}
if isProcessRunning(-1) {
t.Fatalf("negative pid should never be treated as running")
}
})
t.Run("pid out of int32 range", func(t *testing.T) {
if strconv.IntSize <= 32 {
t.Skip("int cannot represent values above int32 range")
}
pid := int(int64(math.MaxInt32) + 1)
if isProcessRunning(pid) {
t.Fatalf("expected pid %d (out of int32 range) to be treated as not running", pid)
}
})
t.Run("current process", func(t *testing.T) {
if !isProcessRunning(os.Getpid()) {
t.Fatalf("expected current process (pid=%d) to be running", os.Getpid())
}
})
t.Run("fake pid", func(t *testing.T) {
const nonexistentPID = 1 << 30
if isProcessRunning(nonexistentPID) {
t.Fatalf("expected pid %d to be reported as not running", nonexistentPID)
}
})
t.Run("terminated process", func(t *testing.T) {
pid := exitedProcessPID(t)
if isProcessRunning(pid) {
t.Fatalf("expected exited child process (pid=%d) to be reported as not running", pid)
}
})
}
func exitedProcessPID(t *testing.T) int {
t.Helper()
var cmd *exec.Cmd
if runtime.GOOS == "windows" {
cmd = exec.Command("cmd", "/c", "exit 0")
} else {
cmd = exec.Command("sh", "-c", "exit 0")
}
if err := cmd.Start(); err != nil {
t.Fatalf("failed to start helper process: %v", err)
}
pid := cmd.Process.Pid
if err := cmd.Wait(); err != nil {
t.Fatalf("helper process did not exit cleanly: %v", err)
}
time.Sleep(50 * time.Millisecond)
return pid
}
func TestGetProcessStartTimeReadsProcStat(t *testing.T) {
start := getProcessStartTime(os.Getpid())
if start.IsZero() {
t.Fatalf("expected non-zero start time for current process")
}
if start.After(time.Now().Add(5 * time.Second)) {
t.Fatalf("start time is unexpectedly in the future: %v", start)
}
}
func TestGetProcessStartTimeInvalidData(t *testing.T) {
if !getProcessStartTime(0).IsZero() {
t.Fatalf("expected zero time for pid 0")
}
if !getProcessStartTime(-1).IsZero() {
t.Fatalf("expected zero time for negative pid")
}
if !getProcessStartTime(1 << 30).IsZero() {
t.Fatalf("expected zero time for non-existent pid")
}
if strconv.IntSize > 32 {
pid := int(int64(math.MaxInt32) + 1)
if !getProcessStartTime(pid).IsZero() {
t.Fatalf("expected zero time for pid %d (out of int32 range)", pid)
}
}
}
func TestGetBootTimeParsesBtime(t *testing.T) {
t.Skip("legacy boot-time probing removed; start time now uses gopsutil")
}
func TestGetBootTimeInvalidData(t *testing.T) {
t.Skip("legacy boot-time probing removed; start time now uses gopsutil")
}

View File

@@ -0,0 +1,67 @@
package logger
import (
"os"
"path/filepath"
"time"
)
func SetProcessRunningCheck(fn func(int) bool) (restore func()) {
prev := processRunningCheck
if fn != nil {
processRunningCheck = fn
} else {
processRunningCheck = isProcessRunning
}
return func() { processRunningCheck = prev }
}
func SetProcessStartTimeFn(fn func(int) time.Time) (restore func()) {
prev := processStartTimeFn
if fn != nil {
processStartTimeFn = fn
} else {
processStartTimeFn = getProcessStartTime
}
return func() { processStartTimeFn = prev }
}
func SetRemoveLogFileFn(fn func(string) error) (restore func()) {
prev := removeLogFileFn
if fn != nil {
removeLogFileFn = fn
} else {
removeLogFileFn = os.Remove
}
return func() { removeLogFileFn = prev }
}
func SetGlobLogFilesFn(fn func(string) ([]string, error)) (restore func()) {
prev := globLogFiles
if fn != nil {
globLogFiles = fn
} else {
globLogFiles = filepath.Glob
}
return func() { globLogFiles = prev }
}
func SetFileStatFn(fn func(string) (os.FileInfo, error)) (restore func()) {
prev := fileStatFn
if fn != nil {
fileStatFn = fn
} else {
fileStatFn = os.Lstat
}
return func() { fileStatFn = prev }
}
func SetEvalSymlinksFn(fn func(string) (string, error)) (restore func()) {
prev := evalSymlinksFn
if fn != nil {
evalSymlinksFn = fn
} else {
evalSymlinksFn = filepath.EvalSymlinks
}
return func() { evalSymlinksFn = prev }
}

View File

@@ -0,0 +1,13 @@
package logger
// WrapperName is the fixed name for this tool.
const WrapperName = "codeagent-wrapper"
// CurrentWrapperName returns the wrapper name (always "codeagent-wrapper").
func CurrentWrapperName() string { return WrapperName }
// LogPrefixes returns the log file name prefixes to look for.
func LogPrefixes() []string { return []string{WrapperName} }
// PrimaryLogPrefix returns the preferred filename prefix for log files.
func PrimaryLogPrefix() string { return WrapperName }