Hold runMu in internal/cli tests that log outside a CLI run (closes #210)

A CLI run under runMu points the process-global logger at its own
buffers, so a line another test logged outside runMu could land in that
run's output. TestCheckQuietShowsFailedFiles caught one: a "loaded
manifest" line in the stderr of a passing check -q run.

The test helpers that scan or load a manifest now hold runMu
themselves, and so do the remaining direct loads and scans, the
recordEntry call and the retrying download. Two dotfile tests use
manifestPaths instead of loading the manifest themselves.

Judgement call: a downloadFile call that gets its answer on the first
request does not log, so those calls are left as they are.

Model: opus-5-5

docs/FORMAT.md

@@ -174,16 +174,9 @@ also refuses a manifest whose `signingPubKey` holds a DSA key or subkey, or any
 secret key or subkey, since checking the self-signatures of a DSA key or the
 numbers of a secret key can take hours when those numbers are very large.
 
-A signature is good only if the key that made it was valid at the signature's
-creation time. The primary key is judged by the newest self-signature on its
-primary user ID, and a subkey by its newest binding signature. By the
-signature's creation time the primary key and that self-signature must have been
-made and neither may have expired, and when a subkey made the signature the same
-holds of the subkey and its binding signature. A signature made before that
-self-signature or binding signature is not good, even if an older one made the
-key valid at that time. A key that has expired since does not make the signature
-bad, because a manifest outlives its key. A signature past its own expiry time
-is not good, whether or not the key has expired too.
+A signing key that has expired does not make the signature bad, because a
+manifest outlives its key. A signature past its own expiry time is not good,
+whether or not the key has expired too.
 
 ## Deterministic Serialization
 

internal/cli/entry_test.go

@@ -771,13 +771,9 @@ func TestGenerateExcludesDotfilesByDefault(t *testing.T) {
 	assert.True(t, exists)
 
 	// Verify manifest only has 1 file (the non-dotfile)
-	manifest, err := mfer.NewManifestFromFile(&mfer.ManifestFromFileOptions{
-		Path: testMF,
-		Fs:   fs,
-	})
-	require.NoError(t, err)
-	assert.Len(t, manifest.Files(), 1)
-	assert.Equal(t, "file1.txt", manifest.Files()[0].GetPath())
+	paths := manifestPaths(t, fs, testMF)
+	require.Len(t, paths, 1)
+	assert.Equal(t, "file1.txt", paths[0])
 }
 
 func TestGenerateWithIncludeDotfiles(t *testing.T) {
@@ -798,12 +794,7 @@ func TestGenerateWithIncludeDotfiles(t *testing.T) {
 	require.Equal(t, 0, exitCode)
 
 	// Verify manifest has 2 files (including dotfile)
-	manifest, err := mfer.NewManifestFromFile(&mfer.ManifestFromFileOptions{
-		Path: testMF,
-		Fs:   fs,
-	})
-	require.NoError(t, err)
-	assert.Len(t, manifest.Files(), 2)
+	assert.Len(t, manifestPaths(t, fs, testMF), 2)
 }
 
 func TestMultipleInputPaths(t *testing.T) {
@@ -1224,6 +1215,11 @@ func TestGenerateFailsWithoutForceWhenOutputExists(t *testing.T) {
 func manifestPaths(t *testing.T, fs afero.Fs, path string) []string {
 	t.Helper()
 
+	// Loading a manifest logs to the process-global logger, so serialize
+	// with the CLI runs.
+	runMu.Lock()
+	defer runMu.Unlock()
+
 	manifest, err := mfer.NewManifestFromFile(&mfer.ManifestFromFileOptions{
 		Path: path,
 		Fs:   fs,

internal/cli/errmsg_test.go

@@ -54,6 +54,11 @@ func runLocked(fn func() error) error {
 func unsignedChecker(t *testing.T) *mfer.Checker {
 	t.Helper()
 
+	// The scan and the manifest load log to the process-global logger, so
+	// serialize with the CLI runs.
+	runMu.Lock()
+	defer runMu.Unlock()
+
 	fs := afero.NewMemMapFs()
 	require.NoError(t, fs.MkdirAll("/d", 0o755))
 	require.NoError(t, afero.WriteFile(fs, "/d/f.txt", []byte("hi"), 0o644))
@@ -183,6 +188,11 @@ func signedManifest(t *testing.T, files map[string][]byte) []byte {
 func signedChecker(t *testing.T, manifest []byte) *mfer.Checker {
 	t.Helper()
 
+	// Loading a manifest logs to the process-global logger, so serialize
+	// with the CLI runs.
+	runMu.Lock()
+	defer runMu.Unlock()
+
 	fs := afero.NewMemMapFs()
 	require.NoError(t, afero.WriteFile(fs, "/index.mf", manifest, 0o644))
 

internal/cli/export_test.go

@@ -20,6 +20,11 @@ const testCmdExport = "export"
 func buildTestManifest(t *testing.T, files map[string][]byte) []byte {
 	t.Helper()
 
+	// The scan logs to the process-global logger, so serialize with the
+	// CLI runs.
+	runMu.Lock()
+	defer runMu.Unlock()
+
 	sourceFs := afero.NewMemMapFs()
 	for path, content := range files {
 		require.NoError(t, sourceFs.MkdirAll("/", 0o755))

internal/cli/fetch_test.go

@@ -171,6 +171,11 @@ func TestResolveManifestURL(t *testing.T) {
 func scanToManifest(t *testing.T, sourceFs afero.Fs) []byte {
 	t.Helper()
 
+	// The scan logs to the process-global logger, so serialize with the
+	// CLI runs.
+	runMu.Lock()
+	defer runMu.Unlock()
+
 	s := mfer.NewScannerWithOptions(&mfer.ScannerOptions{Fs: sourceFs})
 	require.NoError(t, s.EnumerateFS(sourceFs, "/", nil))
 
@@ -314,8 +319,11 @@ func TestFetchFromHTTP(t *testing.T) {
 	// Change to a fresh destination directory for the test
 	destDir := chdirTemp(t)
 
-	// Parse the manifest to get file entries
+	// Parse the manifest to get file entries. Loading a manifest logs to
+	// the process-global logger.
+	runMu.Lock()
 	manifest, err := mfer.NewManifestFromReader(bytes.NewReader(manifestData))
+	runMu.Unlock()
 	require.NoError(t, err)
 
 	files := manifest.Files()
@@ -365,7 +373,10 @@ func TestFetchHashMismatch(t *testing.T) {
 	// Generate and parse manifest
 	manifestData := scanToManifest(t, sourceFs)
 
+	// Loading a manifest logs to the process-global logger.
+	runMu.Lock()
 	manifest, err := mfer.NewManifestFromReader(bytes.NewReader(manifestData))
+	runMu.Unlock()
 	require.NoError(t, err)
 
 	files := manifest.Files()
@@ -411,7 +422,10 @@ func TestFetchSizeMismatch(t *testing.T) {
 	// Generate and parse manifest
 	manifestData := scanToManifest(t, sourceFs)
 
+	// Loading a manifest logs to the process-global logger.
+	runMu.Lock()
 	manifest, err := mfer.NewManifestFromReader(bytes.NewReader(manifestData))
+	runMu.Unlock()
 	require.NoError(t, err)
 
 	files := manifest.Files()
@@ -523,7 +537,10 @@ func TestFetchProgress(t *testing.T) {
 	// Generate and parse manifest
 	manifestData := scanToManifest(t, sourceFs)
 
+	// Loading a manifest logs to the process-global logger.
+	runMu.Lock()
 	manifest, err := mfer.NewManifestFromReader(bytes.NewReader(manifestData))
+	runMu.Unlock()
 	require.NoError(t, err)
 
 	files := manifest.Files()
@@ -897,9 +914,12 @@ func TestGetStopsWaitingWhenCanceled(t *testing.T) {
 //nolint:paralleltest // changes the process-global working directory
 func TestDownloadFileRetriesToSuccess(t *testing.T) {
 	content := []byte("the whole file, every byte of it")
+	manifestData := manifestOf(t, map[string][]byte{testFileTxt: content})
 
-	manifest, err := mfer.NewManifestFromReader(bytes.NewReader(
-		manifestOf(t, map[string][]byte{testFileTxt: content})))
+	// Loading a manifest logs to the process-global logger.
+	runMu.Lock()
+	manifest, err := mfer.NewManifestFromReader(bytes.NewReader(manifestData))
+	runMu.Unlock()
 	require.NoError(t, err)
 
 	var requests atomic.Int32
@@ -922,8 +942,11 @@ func TestDownloadFileRetriesToSuccess(t *testing.T) {
 
 	chdirTemp(t)
 
-	err = downloadFile(context.Background(), testClient(),
-		server.URL+"/"+testFileTxt, ".", testFileTxt, manifest.Files()[0], nil)
+	// downloadFile logs each retry to the process-global logger.
+	err = runLocked(func() error {
+		return downloadFile(context.Background(), testClient(),
+			server.URL+"/"+testFileTxt, ".", testFileTxt, manifest.Files()[0], nil)
+	})
 	require.NoError(t, err)
 	assert.Equal(t, int32(3), requests.Load())
 
@@ -1404,14 +1427,18 @@ func TestFetchSetsRecordedMode(t *testing.T) {
 		require.NoError(t, afero.WriteFile(sourceFs, "/"+p, content, modes[p]))
 	}
 
-	scanner := mfer.NewScannerWithOptions(&mfer.ScannerOptions{
-		Fs:                 sourceFs,
-		IncludePermissions: true,
-	})
-	require.NoError(t, scanner.EnumerateFS(sourceFs, "/", nil))
-
 	var manifest bytes.Buffer
-	require.NoError(t, scanner.ToManifest(context.Background(), &manifest, nil))
+
+	// The scan logs to the process-global logger.
+	require.NoError(t, runLocked(func() error {
+		scanner := mfer.NewScannerWithOptions(&mfer.ScannerOptions{
+			Fs:                 sourceFs,
+			IncludePermissions: true,
+		})
+		require.NoError(t, scanner.EnumerateFS(sourceFs, "/", nil))
+
+		return scanner.ToManifest(context.Background(), &manifest, nil)
+	}))
 
 	tree := fetchTestHandler(manifest.Bytes(), files)
 

internal/cli/freshen_test.go

@@ -70,6 +70,11 @@ func runFreshen(t *testing.T, fs afero.Fs, root, manifestPath string) {
 func manifestFiles(t *testing.T, fs afero.Fs, path string) []*mfer.MFFilePath {
 	t.Helper()
 
+	// Loading a manifest logs to the process-global logger, so serialize
+	// with the CLI runs.
+	runMu.Lock()
+	defer runMu.Unlock()
+
 	manifest, err := mfer.NewManifestFromFile(&mfer.ManifestFromFileOptions{
 		Path: path,
 		Fs:   fs,
@@ -436,7 +441,11 @@ func TestFreshenRecordEntryMtimePresence(t *testing.T) {
 			s := &freshenScanner{
 				existingByPath: map[string]*mfer.MFFilePath{relPath: tc.entry},
 			}
+
+			// recordEntry logs to the process-global logger.
+			runMu.Lock()
 			s.recordEntry(relPath, info)
+			runMu.Unlock()
 
 			require.Len(t, s.entries, 1)
 			assert.Equal(t, tc.needsHash, s.entries[0].needsHash)

mfer/openpgp.go

@@ -57,9 +57,7 @@ var (
 		"signature must hold exactly one signature")
 	errNotOneArmoredBlock = errors.New(
 		"must be exactly one armored block and nothing else")
-	errMalformedArmor        = errors.New("armor is malformed")
-	errKeyNotValidWhenSigned = errors.New(
-		"signature was made when its key was not valid")
+	errMalformedArmor = errors.New("armor is malformed")
 )
 
 // SigningOptions holds the key a manifest is signed with.
@@ -247,9 +245,8 @@ func fingerprint(key *openpgp.Entity) string {
 
 // verifySignature checks that signature is one good, unexpired OpenPGP
 // signature over data, made by the one primary key in pubKey or one of its
-// subkeys while that key was valid, and returns that primary key's
-// fingerprint. The key may have expired since. signature and pubKey may
-// each be armored or binary.
+// subkeys, and returns that primary key's fingerprint. signature and pubKey
+// may each be armored or binary.
 func verifySignature(data, signature, pubKey []byte) (string, error) {
 	key, err := readOneKey(pubKey, "embedded public key block", true)
 	if err != nil {
@@ -284,25 +281,6 @@ func verifySignature(data, signature, pubKey []byte) (string, error) {
 		return "", fmt.Errorf("verify signature: %w", err)
 	}
 
-	// The library checks whether the key is valid at the time its config
-	// gives, which above is now. Verifying again as of the signature's
-	// creation time refuses a signature made before the key or subkey that
-	// made it was made, after it expired, or after its self-signature or
-	// binding signature expired. The library judges the primary key by the
-	// newest self-signature on its primary user ID and a subkey by its
-	// newest binding signature, so this also refuses a signature made
-	// before either of those, even if an older one was valid then.
-	signedAt := &packet.Config{
-		Time: func() time.Time { return sig.CreationTime },
-	}
-
-	_, _, err = openpgp.VerifyDetachedSignature(openpgp.EntityList{key},
-		bytes.NewReader(data), bytes.NewReader(sigData), signedAt)
-	if err != nil {
-		return "", fmt.Errorf("verify signature: %w: %w",
-			errKeyNotValidWhenSigned, err)
-	}
-
 	return fingerprint(key), nil
 }
 

mfer/openpgp_test.go

@@ -4,7 +4,6 @@ package mfer
 import (
 	"bytes"
 	"context"
-	"crypto"
 	"crypto/dsa" //nolint:staticcheck // SA1019: tests need a DSA key to refuse
 	"io"
 	"math/big"
@@ -420,9 +419,8 @@ func TestVerifySignature(t *testing.T) {
 
 // TestVerifySignatureKeyExpiredSince verifies two signatures made in 2020
 // by a key that expired a day after it was made. A signature with no
-// expiry time is still good, as is one made then by a signing subkey that
-// expired a day after it was made. One that expired an hour after it was
-// made is refused, although the key has expired too.
+// expiry time is still good. One that expired an hour after it was made is
+// refused, although the key has expired too.
 func TestVerifySignatureKeyExpiredSince(t *testing.T) {
 	t.Parallel()
 
@@ -450,132 +448,10 @@ func TestVerifySignatureKeyExpiredSince(t *testing.T) {
 	require.NoError(t, err)
 	assert.Equal(t, fingerprint(key), signer)
 
-	withSubkey := newTestKey(t, &packet.Config{Time: config.Time})
-	require.NoError(t, withSubkey.AddSigningSubkey(&packet.Config{
-		Algorithm: packet.PubKeyAlgoEdDSA, Time: config.Time,
-		KeyLifetimeSecs: config.KeyLifetimeSecs,
-	}))
-
-	var subkeySig bytes.Buffer
-
-	require.NoError(t, openpgp.ArmoredDetachSign(&subkeySig, withSubkey,
-		bytes.NewReader(data), config))
-
-	subkeyPubKey, err := armoredPublicKey(withSubkey)
-	require.NoError(t, err)
-
-	_, err = verifySignature(data, subkeySig.Bytes(), subkeyPubKey)
-	require.NoError(t, err)
-
 	_, err = verifySignature(data, expiringSig.Bytes(), pubKey)
 	require.ErrorIs(t, err, pgperrors.ErrSignatureExpired)
 }
 
-// signDated returns a detached signature over data by signer, dated when.
-// openpgp.DetachSign signs only with a key that is valid at the time its
-// config gives, so this makes the signature packet without that check.
-func signDated(t *testing.T, signer *packet.PrivateKey, data []byte,
-	when time.Time,
-) []byte {
-	t.Helper()
-
-	sig := &packet.Signature{
-		SigType:      packet.SigTypeBinary,
-		PubKeyAlgo:   signer.PubKeyAlgo,
-		Hash:         crypto.SHA256,
-		CreationTime: when,
-		IssuerKeyId:  &signer.KeyId,
-	}
-
-	h, err := sig.PrepareSign(nil)
-	require.NoError(t, err)
-
-	_, err = h.Write(data)
-	require.NoError(t, err)
-
-	require.NoError(t, sig.Sign(h, signer, nil))
-
-	var buf bytes.Buffer
-
-	require.NoError(t, sig.Serialize(&buf))
-
-	return buf.Bytes()
-}
-
-// TestVerifySignatureRefusesKeyNotValidWhenSigned verifies signatures
-// dated when the key or subkey that made them was not valid: after the key
-// expired; after the key's self-signature, or the signing subkey's binding
-// signature, expired, the key or subkey having expired since as well; and
-// before the key was made, also by a key made in 2100. Each must be
-// refused.
-func TestVerifySignatureRefusesKeyNotValidWhenSigned(t *testing.T) {
-	t.Parallel()
-
-	made := time.Date(2020, 1, 1, 0, 0, 0, 0, time.UTC)
-	twoDaysLater := made.Add(48 * time.Hour)
-	day := uint32((24 * time.Hour).Seconds())
-	clock := func(when time.Time) func() time.Time {
-		return func() time.Time { return when }
-	}
-
-	expiredAfterADay := newTestKey(t, &packet.Config{
-		Time: clock(made), KeyLifetimeSecs: day,
-	})
-	selfSignatureExpiredAfterADay := newTestKey(t, &packet.Config{
-		Time: clock(made), KeyLifetimeSecs: 30 * day, SigLifetimeSecs: day,
-	})
-
-	withSubkey := newTestKey(t, &packet.Config{Time: clock(made)})
-	require.NoError(t, withSubkey.AddSigningSubkey(&packet.Config{
-		Algorithm: packet.PubKeyAlgoEdDSA, Time: clock(made),
-		KeyLifetimeSecs: 30 * day, SigLifetimeSecs: day,
-	}))
-	subkey := withSubkey.Subkeys[len(withSubkey.Subkeys)-1].PrivateKey
-
-	madeADayLater := newTestKey(t, &packet.Config{
-		Time: clock(made.Add(24 * time.Hour)),
-	})
-	madeIn2100 := newTestKey(t, &packet.Config{
-		Time: clock(time.Date(2100, 1, 1, 0, 0, 0, 0, time.UTC)),
-	})
-
-	for name, test := range map[string]struct {
-		key    *openpgp.Entity
-		signer *packet.PrivateKey
-		when   time.Time
-	}{
-		"after the key expired": {
-			expiredAfterADay, expiredAfterADay.PrivateKey, twoDaysLater,
-		},
-		"after the self-signature expired": {
-			selfSignatureExpiredAfterADay,
-			selfSignatureExpiredAfterADay.PrivateKey, twoDaysLater,
-		},
-		"after the binding signature expired": {
-			withSubkey, subkey, twoDaysLater,
-		},
-		"before the key was made": {
-			madeADayLater, madeADayLater.PrivateKey, made,
-		},
-		"before a key made in 2100": {
-			madeIn2100, madeIn2100.PrivateKey, made,
-		},
-	} {
-		t.Run(name, func(t *testing.T) {
-			t.Parallel()
-
-			data := []byte("signed in 2020")
-
-			pubKey, err := armoredPublicKey(test.key)
-			require.NoError(t, err)
-
-			_, err = verifySignature(data,
-				signDated(t, test.signer, data, test.when), pubKey)
-			require.ErrorIs(t, err, errKeyNotValidWhenSigned)
-		})
-	}
-}
-
 func TestManifestSignatureVerification(t *testing.T) {
 	t.Parallel()