Stop the agent log file from growing without a limit

internal/command/agent/logfile.go

@@ -0,0 +1,98 @@
+package agent
+
+import (
+	"os"
+	"strings"
+	"sync"
+)
+
+// maxLogSize bounds the log the agent is currently writing to. The directory as
+// a whole is pruned when a daemon starts, but that only reaps files nothing has
+// touched for a day: the agent runs for days at a time and writes a single log
+// for its whole lifetime, so its own log is never a candidate.
+const maxLogSize = 128 << 20 // 128MB
+
+// rotatingFile writes to path, moving the file aside once it has taken
+// maxLogSize. Only the previous generation is kept, so the pair costs at most
+// twice maxLogSize until the next daemon start prunes them.
+type rotatingFile struct {
+	path string
+
+	mu      sync.Mutex
+	file    *os.File
+	written int64
+}
+
+func openRotatingFile(path string) (*rotatingFile, error) {
+	file, err := os.OpenFile(path, os.O_WRONLY|os.O_APPEND, 0o600)
+	if err != nil {
+		return nil, err
+	}
+
+	// Resume from the size on disk so restarting the agent against an existing
+	// log doesn't hand it a fresh budget.
+	var written int64
+	if inf, err := file.Stat(); err == nil {
+		written = inf.Size()
+	}
+
+	return &rotatingFile{path: path, file: file, written: written}, nil
+}
+
+func (rf *rotatingFile) Write(p []byte) (int, error) {
+	rf.mu.Lock()
+	defer rf.mu.Unlock()
+
+	if rf.written+int64(len(p)) > maxLogSize {
+		if err := rf.rotate(); err != nil {
+			return 0, err
+		}
+	}
+
+	n, err := rf.file.Write(p)
+	rf.written += int64(n)
+
+	return n, err
+}
+
+// rotate counts the bytes it has written instead of measuring the file, so a
+// log deleted from under the agent is replaced at the next threshold rather
+// than growing forever on an unlinked descriptor.
+func (rf *rotatingFile) rotate() error {
+	// Windows refuses to rename an open file.
+	_ = rf.file.Close()
+
+	if err := os.Rename(rf.path, previousPath(rf.path)); err != nil && !os.IsNotExist(err) {
+		return err
+	}
+
+	file, err := os.OpenFile(rf.path, os.O_WRONLY|os.O_CREATE|os.O_TRUNC|os.O_APPEND, 0o600)
+	if err != nil {
+		return err
+	}
+
+	rf.file = file
+	rf.written = 0
+
+	return nil
+}
+
+func (rf *rotatingFile) Sync() error {
+	rf.mu.Lock()
+	defer rf.mu.Unlock()
+
+	return rf.file.Sync()
+}
+
+func (rf *rotatingFile) Close() error {
+	rf.mu.Lock()
+	defer rf.mu.Unlock()
+
+	return rf.file.Close()
+}
+
+// previousPath keeps the .log suffix: fly doctor diag collects agent logs by
+// that pattern.
+func previousPath(path string) string {
+	return strings.TrimSuffix(path, ".log") + ".prev.log"
+}

internal/command/agent/logfile_test.go

@@ -0,0 +1,85 @@
+package agent
+
+import (
+	"os"
+	"path/filepath"
+	"strings"
+	"testing"
+
+	"github.com/stretchr/testify/require"
+)
+
+// write enough lines to cross the threshold a few times over.
+func writeLines(t *testing.T, rf *rotatingFile, line string, count int) {
+	t.Helper()
+
+	for range count {
+		n, err := rf.Write([]byte(line))
+		require.NoError(t, err)
+		require.Equal(t, len(line), n)
+	}
+}
+
+func TestRotatingFileBoundsTheLog(t *testing.T) {
+	path := filepath.Join(t.TempDir(), "agent.log")
+	require.NoError(t, os.WriteFile(path, nil, 0o600))
+
+	rf, err := openRotatingFile(path)
+	require.NoError(t, err)
+	defer rf.Close()
+
+	line := strings.Repeat("x", 4096) + "\n"
+	writeLines(t, rf, line, 3*(maxLogSize/len(line)))
+
+	inf, err := os.Stat(path)
+	require.NoError(t, err)
+	require.LessOrEqual(t, inf.Size(), int64(maxLogSize))
+
+	prev, err := os.Stat(previousPath(path))
+	require.NoError(t, err, "the previous generation should be kept")
+	require.LessOrEqual(t, prev.Size(), int64(maxLogSize))
+}
+
+func TestRotatingFileResumesFromSizeOnDisk(t *testing.T) {
+	path := filepath.Join(t.TempDir(), "agent.log")
+	require.NoError(t, os.WriteFile(path, make([]byte, maxLogSize), 0o600))
+
+	rf, err := openRotatingFile(path)
+	require.NoError(t, err)
+	defer rf.Close()
+
+	writeLines(t, rf, "hello\n", 1)
+
+	prev, err := os.Stat(previousPath(path))
+	require.NoError(t, err)
+	require.Equal(t, int64(maxLogSize), prev.Size())
+
+	got, err := os.ReadFile(path)
+	require.NoError(t, err)
+	require.Equal(t, "hello\n", string(got))
+}
+
+// The agent kept growing an unlinked descriptor after a user cleared the log
+// directory by hand.
+func TestRotatingFileReplacesADeletedLog(t *testing.T) {
+	path := filepath.Join(t.TempDir(), "agent.log")
+	require.NoError(t, os.WriteFile(path, nil, 0o600))
+
+	rf, err := openRotatingFile(path)
+	require.NoError(t, err)
+	defer rf.Close()
+
+	line := strings.Repeat("x", 4096) + "\n"
+	writeLines(t, rf, line, maxLogSize/len(line)/2)
+	require.NoError(t, os.Remove(path))
+
+	writeLines(t, rf, line, maxLogSize/len(line))
+
+	inf, err := os.Stat(path)
+	require.NoError(t, err, "writes should land in a fresh log")
+	require.LessOrEqual(t, inf.Size(), int64(maxLogSize))
+}
+
+func TestPreviousPathKeepsTheLogSuffix(t *testing.T) {
+	require.Equal(t, "/tmp/agent-logs/123.prev.log", previousPath("/tmp/agent-logs/123.log"))
+}

internal/command/agent/run.go

@@ -77,7 +77,7 @@ func run(ctx context.Context) error {
 func setupLogger(path string) (logger *log.Logger, close func(), err error) {
 	var out io.Writer
 	if path != "" {
-		f, err := os.OpenFile(path, os.O_WRONLY|os.O_APPEND, 0o600)
+		f, err := openRotatingFile(path)
 		if err != nil {
 			return nil, nil, err
 		}