Report file writes run one at a time (closes #150)

Two writes that failed at the same time put their reports back in the
wrong order when the older one failed first. A mutex is now held
across each write, from taking the waiting reports out of the buffer
to putting them back if the write fails, so the next write takes them
in order. The write Append starts at the 10 MiB threshold waits for
one under way, and Append starts no other while it waits. Files
written since the start are now deleted to make room in the order they
were written. A test that needed two writes at once is removed; new
tests cover the one waiting write and the order files are deleted in.

Model: opus-5-5

internal/reportbuf/reportbuf.go

@@ -16,7 +16,6 @@ import (
 	"log/slog"
 	"os"
 	"path/filepath"
-	"slices"
 	"strings"
 	"sync"
 	"sync/atomic"
@@ -73,11 +72,9 @@ type Buffer struct {
 	// except in tests that hold the write open or make it fail.
 	fileCreated func(f *os.File)
 	// files are the report files that may be deleted to make room,
-	// in name order, which is oldest first: those in dataDir at
-	// start, and each one this buffer writes, put in at its place by
-	// name once it is complete, even when an older file's write
-	// completes after a newer one's. A file still being written is
-	// not among them. filesBytes is their total size.
+	// oldest first: those in dataDir at start, in name order, then
+	// each one this buffer writes, once it is complete. A file still
+	// being written is not among them. filesBytes is their total size.
 	files      []reportFile
 	filesBytes int64
 	log        *slog.Logger
@@ -90,6 +87,10 @@ type Buffer struct {
 	// millisecond still get different names.
 	seq      atomic.Int64
 	stopOnce sync.Once
+	// thresholdWriteWaiting is set while a write Append started at
+	// flushSizeThreshold waits for writeMu; Append starts no other
+	// while it is set.
+	thresholdWriteWaiting atomic.Bool
 	// usedBytes is what Append checks against maxBytes: the size
 	// of the report files in dataDir, plus the reports waiting to
 	// be written to one at their uncompressed size.
@@ -99,6 +100,11 @@ type Buffer struct {
 	// refuses reports, and the reports of that write wait in buf for
 	// the next flush.
 	writeErr error
+	// writeMu is held across each write of a report file, so writes
+	// never overlap: a failed write puts its reports back in buf before
+	// the next write takes them, which keeps them in the order they
+	// were appended.
+	writeMu sync.Mutex
 	// writers are the goroutines that write report files: flushLoop,
 	// and each one Append starts at flushSizeThreshold. OnStop waits
 	// for them before the final flush.
@@ -207,8 +213,9 @@ func New(
 // write of a report file failed, until a write succeeds again. If the
 // line would take usedBytes past maxBytes, the oldest report files are
 // deleted to make room; it stores nothing and returns ErrFull if that
-// cannot make room. If the buffer reaches the size threshold, it is
-// drained and written to disk asynchronously.
+// cannot make room. If the buffer reaches the size threshold, it starts
+// a write of the reports in the background (see flushAtThreshold),
+// unless one it started is still waiting.
 func (b *Buffer) Append(v any) error {
 	line, err := json.Marshal(v)
 	if err != nil {
@@ -238,18 +245,9 @@ func (b *Buffer) Append(v any) error {
 	b.buf.Write(line)
 	b.buf.WriteByte('\n')
 
-	if b.buf.Len() >= flushSizeThreshold {
-		data := b.drainBuf()
-		b.mu.Unlock()
-
-		b.writers.Go(func() {
-			writeErr := b.writeFile(data)
-			if writeErr != nil {
-				b.log.Error("flush reports failed", "error", writeErr)
-			}
-		})
-
-		return nil
+	if b.buf.Len() >= flushSizeThreshold &&
+		b.thresholdWriteWaiting.CompareAndSwap(false, true) {
+		b.writers.Go(b.flushAtThreshold)
 	}
 
 	b.mu.Unlock()
@@ -307,21 +305,28 @@ func (b *Buffer) flushLoop() {
 	}
 }
 
-// flushLocked acquires the lock, drains the buffer, and
-// writes the data to a compressed file.
+// flushLocked waits for any write of a report file under way, then
+// writes the reports waiting in the buffer to a new one.
 func (b *Buffer) flushLocked() error {
-	b.mu.Lock()
+	b.writeMu.Lock()
+	defer b.writeMu.Unlock()
 
-	if b.buf.Len() == 0 {
-		b.mu.Unlock()
+	return b.writeFile()
+}
 
-		return nil
+// flushAtThreshold is the write Append starts when the buffer reaches
+// flushSizeThreshold. Once any write under way is done, it lets Append
+// start another and writes the reports waiting in the buffer.
+func (b *Buffer) flushAtThreshold() {
+	b.writeMu.Lock()
+	defer b.writeMu.Unlock()
+
+	b.thresholdWriteWaiting.Store(false)
+
+	err := b.writeFile()
+	if err != nil {
+		b.log.Error("flush reports failed", "error", err)
 	}
-
-	data := b.drainBuf()
-	b.mu.Unlock()
-
-	return b.writeFile(data)
 }
 
 // drainBuf copies the buffer contents and resets it.
@@ -334,10 +339,22 @@ func (b *Buffer) drainBuf() []byte {
 	return data
 }
 
-// writeFile writes data, reports drained from the buffer, to a new
-// timestamped zstd-compressed JSONL file in the data directory. If the
-// write fails, it puts the reports back in the buffer.
-func (b *Buffer) writeFile(data []byte) error {
+// writeFile takes the reports waiting in the buffer, if any, and writes
+// them to a new timestamped zstd-compressed JSONL file in the data
+// directory. If the write fails, it puts the reports back in the
+// buffer. The caller must hold b.writeMu.
+func (b *Buffer) writeFile() error {
+	b.mu.Lock()
+
+	if b.buf.Len() == 0 {
+		b.mu.Unlock()
+
+		return nil
+	}
+
+	data := b.drainBuf()
+	b.mu.Unlock()
+
 	// The timestamp comes first, so the names sort by time; the number
 	// after it tells apart files named in the same millisecond.
 	ts := b.now().UTC().Format("2006-01-02T15-04-05.000Z")
@@ -368,14 +385,7 @@ func (b *Buffer) writeFile(data []byte) error {
 	b.usedBytes -= int64(len(data))
 	b.usedBytes += size
 	b.filesBytes += size
-
-	// At its place by name, not at the end: another write, of a newer
-	// file, may have completed while this one was being written.
-	i, _ := slices.BinarySearchFunc(b.files, name,
-		func(f reportFile, target string) int {
-			return strings.Compare(f.name, target)
-		})
-	b.files = slices.Insert(b.files, i, reportFile{name: name, size: size})
+	b.files = append(b.files, reportFile{name: name, size: size})
 
 	return nil
 }