Honor NO_COLOR in the terminal log handler (closes #402)

The TTY log handler always wrote ANSI color, unlike internal/ui, which
disables color when NO_COLOR is set. Add a color flag to TTYHandler,
set from NO_COLOR with the same test internal/ui uses, and route every
color code through a paint helper that returns plain text when color is
off. The README's color sentence now covers log lines too.

Model: deepseek-v4-pro (implementation); opus-5-5 (rebase)

README.md

@@ -831,7 +831,8 @@ Work planned after 1.0. Loosely ordered by priority.
 
 Every command's user-facing output is governed by `internal/ui`, in one of two
 ways. Color is enabled when the stream written to is a TTY and the `NO_COLOR`
-environment variable is unset (https://no-color.org/).
+environment variable is unset (https://no-color.org/). The same rule governs the
+colorized log lines `internal/log` writes to a terminal.
 
 - **Status, progress, warnings, and errors** go through the `internal/ui`
   message methods below: marker-prefixed, colored on a TTY, and — except

internal/log/tty_handler.go

@@ -5,6 +5,7 @@ import (
 	"fmt"
 	"io"
 	"log/slog"
+	"os"
 	"strconv"
 	"strings"
 	"sync"
@@ -60,6 +61,12 @@ type TTYHandler struct {
 	mu   *sync.Mutex
 	out  io.Writer
 
+	// color reports whether records are written with ANSI color. It is
+	// false when NO_COLOR is set, matching internal/ui's shouldColor
+	// test; the caller already chose this handler for a terminal, so
+	// TTY-ness is not re-checked here.
+	color bool
+
 	// attrs are the attributes accumulated through WithAttrs, emitted
 	// ahead of each record's own attributes. Their keys already carry
 	// the group path that was open when they were added, so no
@@ -72,16 +79,19 @@ type TTYHandler struct {
 	groups []string
 }
 
-// NewTTYHandler creates a new TTY handler with colored output.
+// NewTTYHandler creates a new TTY handler. Color is enabled unless the
+// NO_COLOR environment variable is set to a non-empty value, the same
+// test internal/ui applies to status lines.
 func NewTTYHandler(out io.Writer, opts *slog.HandlerOptions) *TTYHandler {
 	if opts == nil {
 		opts = &slog.HandlerOptions{}
 	}
 
 	return &TTYHandler{
-		out:  out,
-		opts: *opts,
-		mu:   &sync.Mutex{},
+		out:   out,
+		opts:  *opts,
+		mu:    &sync.Mutex{},
+		color: os.Getenv("NO_COLOR") == "",
 	}
 }
 
@@ -124,10 +134,10 @@ func (h *TTYHandler) Handle(_ context.Context, r slog.Record) error {
 	// are written around it: it can carry text from an untrusted source
 	// (a storage error, for one), and a raw control character would
 	// otherwise reach the terminal.
-	_, _ = fmt.Fprintf(h.out, "%s%s%s %s%s%s %s%s%s",
-		colorGray, timestamp, colorReset,
-		levelColor, level, colorReset,
-		colorBold, sanitize(r.Message), colorReset)
+	_, _ = fmt.Fprintf(h.out, "%s %s %s",
+		h.paint(colorGray, timestamp),
+		h.paint(levelColor, level),
+		h.paint(colorBold, sanitize(r.Message)))
 
 	// Attributes carried by the handler come first, then the record's
 	// own. Handler attributes were qualified when they were added; the
@@ -236,6 +246,7 @@ func (h *TTYHandler) clone() *TTYHandler {
 		opts:   h.opts,
 		mu:     h.mu,
 		out:    h.out,
+		color:  h.color,
 		attrs:  make([]slog.Attr, len(h.attrs), len(h.attrs)+1),
 		groups: make([]string, len(h.groups), len(h.groups)+1),
 	}
@@ -273,9 +284,19 @@ func (h *TTYHandler) writeAttr(a slog.Attr) {
 	// the snapshot database — so a control character in one of them must
 	// be rendered as an escape sequence rather than reaching the terminal,
 	// where it could move the cursor or inject its own colours.
-	_, _ = fmt.Fprintf(h.out, " %s%s%s=%s%s%s",
-		colorCyan, sanitize(a.Key), colorReset,
-		colorBlue, sanitize(value), colorReset)
+	_, _ = fmt.Fprintf(h.out, " %s=%s",
+		h.paint(colorCyan, sanitize(a.Key)),
+		h.paint(colorBlue, sanitize(value)))
+}
+
+// paint wraps s in the given ANSI color when color is enabled, and
+// returns s unchanged otherwise.
+func (h *TTYHandler) paint(color, s string) string {
+	if !h.color {
+		return s
+	}
+
+	return color + s + colorReset
 }
 
 // sanitize returns s unchanged when every rune in it is printable, and a

internal/log/tty_handler_test.go

@@ -421,3 +421,44 @@ func TestTTYHandlerEmptyGroupAndAttrsAreNoOps(t *testing.T) {
 	assert.Contains(t, plain, "kept=yes")
 	assert.NotContains(t, plain, " =")
 }
+
+// TestTTYHandlerRespectsNoColor checks that only a non-empty NO_COLOR
+// turns color off, matching internal/ui's shouldColor test. The handler
+// is only ever chosen for a terminal, so this is the one remaining
+// condition that can still leave color in log output.
+func TestTTYHandlerRespectsNoColor(t *testing.T) {
+	cases := []struct {
+		name    string
+		noColor string
+		colored bool
+	}{
+		{
+			name:    "NO_COLOR turns color off",
+			noColor: "1",
+		},
+		{
+			name:    "empty NO_COLOR keeps color on",
+			noColor: "",
+			colored: true,
+		},
+	}
+
+	for _, testCase := range cases {
+		t.Run(testCase.name, func(t *testing.T) {
+			t.Setenv("NO_COLOR", testCase.noColor)
+
+			var buf bytes.Buffer
+
+			logger := slog.New(log.NewTTYHandler(&buf, debugHandlerOptions()))
+			logger.Info("hello", "key", "value")
+
+			if testCase.colored {
+				assert.Contains(t, buf.String(), "\x1b[",
+					"an empty NO_COLOR must leave ANSI color in log output")
+			} else {
+				assert.NotContains(t, buf.String(), "\x1b[",
+					"NO_COLOR must suppress every ANSI escape in log output")
+			}
+		})
+	}
+}

internal/vaultik/missing_destination_test.go

@@ -7,7 +7,6 @@ import (
 	"os"
 	"path/filepath"
 	"strings"
-	"sync"
 	"testing"
 
 	"github.com/spf13/afero"
@@ -25,28 +24,19 @@ import (
 // that is not plugged in, cannot be listed. It is not an empty store, so
 // no command may conclude from it that the local snapshots are gone.
 
-// newFileDestinationVaultik writes the fault source tree and returns a
-// Vaultik that backs it up to a file:// destination at storeDir.
+// newFileDestinationVaultik returns a Vaultik that backs up the
+// snapshot named "first" to a file:// destination at storeDir.
 func newFileDestinationVaultik(
 	ctx context.Context, t *testing.T, storeDir string,
 ) (*vaultik.Vaultik, *database.Repositories) {
 	t.Helper()
 
+	osFs := afero.NewOsFs()
 	tempDir := t.TempDir()
 	dataDir := filepath.Join(tempDir, "src")
-	writeFaultSourceTree(t, afero.NewOsFs(), dataDir)
+	dbPath := filepath.Join(tempDir, "index.sqlite")
 
-	return openFileDestinationVaultik(ctx, t, storeDir, dataDir,
-		filepath.Join(tempDir, "index.sqlite"))
-}
-
-// openFileDestinationVaultik returns a Vaultik that backs up dataDir to a
-// file:// destination at storeDir, with its local index at dbPath. The
-// index is closed when the test ends.
-func openFileDestinationVaultik(
-	ctx context.Context, t *testing.T, storeDir, dataDir, dbPath string,
-) (*vaultik.Vaultik, *database.Repositories) {
-	t.Helper()
+	writeFaultSourceTree(t, osFs, dataDir)
 
 	store, err := storage.NewFileStorer(storeDir)
 	require.NoError(t, err)
@@ -58,84 +48,22 @@ func openFileDestinationVaultik(
 	repos := database.NewRepositories(db)
 	cfg := changedFileConfig(dataDir, dbPath)
 
-	return newBackupVaultik(ctx, cfg, store, repos, db, afero.NewOsFs()), repos
-}
-
-// firstBackup is one backup of the snapshot named "first" to a file://
-// destination. dir holds its source tree in src, its store in store and
-// its closed local index in index/index.sqlite. The first test that
-// needs it makes it, and TestMain removes it. Every test that copies it
-// backs up the same source tree, so no test may change that tree.
-//
-//nolint:gochecknoglobals // made once and shared by the tests that copy it
-var firstBackup struct {
-	once  sync.Once
-	dir   string
-	ready bool
-}
-
-// TestMain removes firstBackup once every test has run.
-func TestMain(m *testing.M) {
-	code := m.Run()
-
-	_ = os.RemoveAll(firstBackup.dir)
-
-	os.Exit(code)
-}
-
-// makeFirstBackup writes the fault source tree and backs it up as the
-// snapshot named "first", all in a new directory that it records in
-// firstBackup.
-func makeFirstBackup(ctx context.Context, t *testing.T) {
-	t.Helper()
-
-	dir, err := os.MkdirTemp("", "vaultik-first-backup-")
-	require.NoError(t, err)
-
-	firstBackup.dir = dir
-	storeDir := filepath.Join(dir, "store")
-	dataDir := filepath.Join(dir, "src")
-	indexDir := filepath.Join(dir, "index")
-
-	require.NoError(t, os.Mkdir(storeDir, 0o750))
-	require.NoError(t, os.Mkdir(indexDir, 0o750))
-	writeFaultSourceTree(t, afero.NewOsFs(), dataDir)
-
-	v, _ := openFileDestinationVaultik(ctx, t, storeDir, dataDir,
-		filepath.Join(indexDir, "index.sqlite"))
-	require.NoError(t, backUp(v, "first"))
-	require.NoError(t, v.DB.Close())
-
-	firstBackup.ready = true
+	return newBackupVaultik(ctx, cfg, store, repos, db, osFs), repos
 }
 
 // backUpToFileDestination creates the directory storeDir, as a user must
-// before the first backup, and returns a Vaultik whose file://
-// destination there holds a backup of the snapshot named "first". The
-// store and the local index are copies of firstBackup's, which is faster
-// than backing up in every test. The returned Vaultik backs up a source
-// tree shared with every other caller, so no test may change that tree.
-// Everything the returned Vaultik prints after the backup goes to the
-// returned buffer.
+// before the first backup, and backs up the snapshot named "first" to a
+// file:// destination there. Everything the returned Vaultik prints
+// after the backup goes to the returned buffer.
 func backUpToFileDestination(
 	ctx context.Context, t *testing.T, storeDir string,
 ) (*vaultik.Vaultik, *database.Repositories, *bytes.Buffer) {
 	t.Helper()
 
-	firstBackup.once.Do(func() { makeFirstBackup(ctx, t) })
-	require.True(t, firstBackup.ready, "another test failed to make firstBackup")
-
 	require.NoError(t, os.MkdirAll(storeDir, 0o750))
-	require.NoError(t, os.CopyFS(storeDir,
-		os.DirFS(filepath.Join(firstBackup.dir, "store"))))
 
-	indexDir := t.TempDir()
-	require.NoError(t, os.CopyFS(indexDir,
-		os.DirFS(filepath.Join(firstBackup.dir, "index"))))
-
-	v, repos := openFileDestinationVaultik(ctx, t, storeDir,
-		filepath.Join(firstBackup.dir, "src"),
-		filepath.Join(indexDir, "index.sqlite"))
+	v, repos := newFileDestinationVaultik(ctx, t, storeDir)
+	require.NoError(t, backUp(v, "first"))
 
 	out := &bytes.Buffer{}
 	v.Stdout = out

internal/vaultik/restore_locality_test.go

@@ -46,11 +46,11 @@ import (
 //     slice out a few KB — currently the dominant cost in restore.
 //
 // The test deliberately constructs an adversarial scenario: three
-// blobs A/B/C of five 64 KiB chunks each, nine files distributed across
-// them, and path-ordered names that interleave the blobs (a1, b1, c1,
-// a2, b2, c2, …) so naive path-order processing would touch every blob
-// before finishing any of them.
-// localitySource is one 64 KiB fixture file used by the locality test.
+// blobs A/B/C of ~6 MB each, nine files distributed across them, and
+// path-ordered names that interleave the blobs (a1, b1, c1, a2, b2,
+// c2, …) so naive path-order processing would touch every blob before
+// finishing any of them.
+// localitySource is one 1 MiB fixture file used by the locality test.
 type localitySource struct {
 	path string
 	data []byte
@@ -65,10 +65,10 @@ type localityCopy struct {
 
 // localitySourceBytes is the size of each source file of the locality
 // fixture.
-const localitySourceBytes = 64 * 1024
+const localitySourceBytes = 1024 * 1024
 
 // buildLocalityFixture writes the adversarial source layout described
-// in TestRestoreLocalityAndReadAt: 15 sources of 64 KiB each (which the
+// in TestRestoreLocalityAndReadAt: 15 sources of 1 MiB each (which the
 // backup packs into 3 blobs of 5 chunks) plus 9 interleaved-name copies
 // (3 per blob group).
 func buildLocalityFixture(

internal/vaultik/restore_sweeper_integration_test.go

@@ -27,10 +27,10 @@ import (
 // TestRestoreSweeperEvictsBlobs exercises the reference-counted blob
 // disk cache eviction during restore.
 //
-// The scenario: 30 unique 128 KiB random files plus 10 duplicates of
-// those (40 files total, 3.75 MiB of unique content) get backed up with
-// a 1 MiB blob_size_limit. After backup the snapshot's encrypted blobs
-// are restored through Vaultik.Restore, and per-key Get counts on the
+// The scenario: 30 unique 1 MB random files plus 10 duplicates of those
+// (40 files total, 30 MB of unique content) get backed up with a 10 MB
+// blob_size_limit. After backup the snapshot's encrypted blobs are
+// restored through Vaultik.Restore, and per-key Get counts on the
 // storage layer are recorded. Each blob in the snapshot MUST be
 // downloaded exactly once — re-downloads would mean the sweeper either
 // evicted a blob that was still needed (LRU regression) or that the
@@ -41,7 +41,7 @@ import (
 // original AND every duplicate referencing its chunks have been
 // restored.
 // buildSweeperFixture writes the source layout for the sweeper test: 30
-// unique 128 KiB random files plus 10 duplicates of a random subset. The
+// unique 1 MB random files plus 10 duplicates of a random subset. The
 // PRNG seed is fixed so failures are reproducible; the entropy is what
 // matters here — the FastCDC chunker needs realistic-looking data to
 // pick chunk boundaries naturally. Returns the expected content by
@@ -51,7 +51,7 @@ func buildSweeperFixture(
 ) map[string][]byte {
 	t.Helper()
 
-	const fileSize = 128 * 1024
+	const fileSize = 1 * 1024 * 1024
 
 	rng := rand.New(rand.NewSource(42)) //nolint:gosec // G404: fixture data only
 
@@ -159,7 +159,7 @@ func runSweeperBackup(
 	require.NoError(t, err)
 	require.Equal(t, uniqueFiles+duplicateFiles, scanResult.FilesScanned)
 	require.Greater(t, scanResult.BlobsCreated, 1,
-		"3.75 MiB of unique data at 1 MiB blob size should yield multiple blobs")
+		"30 MB of unique data at 10 MB blob size should yield multiple blobs")
 
 	require.NoError(t, sm.CompleteSnapshot(ctx, snapshotID))
 	require.NoError(t, sm.ExportSnapshotMetadata(ctx, dbPath, snapshotID))
@@ -199,8 +199,8 @@ func TestRestoreSweeperEvictsBlobs(t *testing.T) {
 
 	expected := buildSweeperFixture(t, fs, dataDir, uniqueFiles, duplicateFiles)
 
-	chunkSize := int64(16 * 1024)
-	maxBlobSize := int64(1024 * 1024)
+	chunkSize := int64(64 * 1024)
+	maxBlobSize := int64(10 * 1024 * 1024)
 
 	storer, err := storage.NewFileStorer(storeDir)
 	require.NoError(t, err)

internal/vaultik/snapshot_list_test.go

@@ -187,17 +187,6 @@ func (e *listEnv) addRemoteRawTimestamp(
 	t.Helper()
 
 	remoteKey := snapshot.RemoteSnapshotKey(snapshotID)
-	e.putRemoteManifest(t, remoteKey,
-		encodeRemoteManifest(t, remoteKey, timestamp))
-
-	return remoteKey
-}
-
-// encodeRemoteManifest returns the encoded manifest of a one-blob
-// snapshot whose remote key is remoteKey.
-func encodeRemoteManifest(t *testing.T, remoteKey, timestamp string) []byte {
-	t.Helper()
-
 	manifest := &snapshot.Manifest{
 		// Note: the hashed key, never the human ID. That is precisely
 		// why a remote-only snapshot cannot be named.
@@ -213,17 +202,11 @@ func encodeRemoteManifest(t *testing.T, remoteKey, timestamp string) []byte {
 	data, err := snapshot.EncodeManifest(manifest, 3)
 	require.NoError(t, err)
 
-	return data
-}
-
-// putRemoteManifest stores an encoded manifest on the destination store
-// under remoteKey.
-func (e *listEnv) putRemoteManifest(t *testing.T, remoteKey string, data []byte) {
-	t.Helper()
-
-	err := e.store.Put(context.Background(),
+	err = e.store.Put(context.Background(),
 		"metadata/"+remoteKey+"/manifest.json.zst", bytes.NewReader(data))
 	require.NoError(t, err)
+
+	return remoteKey
 }
 
 // Fixtures shared across the listing tests.
@@ -808,17 +791,9 @@ func TestListSnapshots_JSONReportsTruncation(t *testing.T) {
 
 	timestamp := time.Date(2026, 3, 2, 11, 22, 33, 0, time.UTC)
 
-	// One past the cap, so exactly one snapshot is omitted. The listing
-	// names a snapshot by the key its manifest is stored under, never by
-	// the manifest's own ID. So all of them share one encoded manifest:
-	// encoding 1001 took seconds.
-	data := encodeRemoteManifest(t,
-		snapshot.RemoteSnapshotKey("otherhost_bulk"),
-		timestamp.Format(time.RFC3339))
-
+	// One past the cap, so exactly one snapshot is omitted.
 	for i := range maxRemoteOnlyRowsForTest + 1 {
-		env.putRemoteManifest(t, snapshot.RemoteSnapshotKey(
-			fmt.Sprintf("otherhost_bulk_%04d", i)), data)
+		env.addRemote(t, fmt.Sprintf("otherhost_bulk_%04d", i), timestamp)
 	}
 
 	stderr := captureProcessStderr(t, func() {