accounts/keystore: faster tests (#25827)

This PR removes some optimistic tests -- a'la "do something,
wait a while, and hope it has trickled through and continue" -- and
instead uses some introspection to ensure that prerequisites are met.

accounts/keystore/account_cache.go

@@ -146,6 +146,14 @@ func (ac *accountCache) deleteByFile(path string) {
 	}
 }
 
+// watcherStarted returns true if the watcher loop started running (even if it
+// has since also ended).
+func (ac *accountCache) watcherStarted() bool {
+	ac.mu.Lock()
+	defer ac.mu.Unlock()
+	return ac.watcher.running || ac.watcher.runEnded
+}
+
 func removeAccount(slice []accounts.Account, elem accounts.Account) []accounts.Account {
 	for i := range slice {
 		if slice[i] == elem {

accounts/keystore/account_cache_test.go

@@ -50,6 +50,38 @@ var (
 	}
 )
 
+// waitWatcherStarts waits up to 1s for the keystore watcher to start.
+func waitWatcherStart(ks *KeyStore) bool {
+	// On systems where file watch is not supported, just return "ok".
+	if !ks.cache.watcher.enabled() {
+		return true
+	}
+	// The watcher should start, and then exit.
+	for t0 := time.Now(); time.Since(t0) < 1*time.Second; time.Sleep(100 * time.Millisecond) {
+		if ks.cache.watcherStarted() {
+			return true
+		}
+	}
+	return false
+}
+
+func waitForAccounts(wantAccounts []accounts.Account, ks *KeyStore) error {
+	var list []accounts.Account
+	for t0 := time.Now(); time.Since(t0) < 5*time.Second; time.Sleep(200 * time.Millisecond) {
+		list = ks.Accounts()
+		if reflect.DeepEqual(list, wantAccounts) {
+			// ks should have also received change notifications
+			select {
+			case <-ks.changes:
+			default:
+				return fmt.Errorf("wasn't notified of new accounts")
+			}
+			return nil
+		}
+	}
+	return fmt.Errorf("\ngot  %v\nwant %v", list, wantAccounts)
+}
+
 func TestWatchNewFile(t *testing.T) {
 	t.Parallel()
 
@@ -57,8 +89,9 @@ func TestWatchNewFile(t *testing.T) {
 
 	// Ensure the watcher is started before adding any files.
 	ks.Accounts()
-	time.Sleep(1000 * time.Millisecond)
-
+	if !waitWatcherStart(ks) {
+		t.Fatal("keystore watcher didn't start in time")
+	}
 	// Move in the files.
 	wantAccounts := make([]accounts.Account, len(cachetestAccounts))
 	for i := range cachetestAccounts {
@@ -72,37 +105,25 @@ func TestWatchNewFile(t *testing.T) {
 	}
 
 	// ks should see the accounts.
-	var list []accounts.Account
-	for d := 200 * time.Millisecond; d < 5*time.Second; d *= 2 {
-		list = ks.Accounts()
-		if reflect.DeepEqual(list, wantAccounts) {
-			// ks should have also received change notifications
-			select {
-			case <-ks.changes:
-			default:
-				t.Fatalf("wasn't notified of new accounts")
-			}
-			return
-		}
-		time.Sleep(d)
+	if err := waitForAccounts(wantAccounts, ks); err != nil {
+		t.Error(err)
 	}
-	t.Errorf("got %s, want %s", spew.Sdump(list), spew.Sdump(wantAccounts))
 }
 
 func TestWatchNoDir(t *testing.T) {
 	t.Parallel()
-
 	// Create ks but not the directory that it watches.
 	rand.Seed(time.Now().UnixNano())
 	dir := filepath.Join(os.TempDir(), fmt.Sprintf("eth-keystore-watchnodir-test-%d-%d", os.Getpid(), rand.Int()))
 	ks := NewKeyStore(dir, LightScryptN, LightScryptP)
-
 	list := ks.Accounts()
 	if len(list) > 0 {
 		t.Error("initial account list not empty:", list)
 	}
-	time.Sleep(100 * time.Millisecond)
-
+	// The watcher should start, and then exit.
+	if !waitWatcherStart(ks) {
+		t.Fatal("keystore watcher didn't start in time")
+	}
 	// Create the directory and copy a key file into it.
 	os.MkdirAll(dir, 0700)
 	defer os.RemoveAll(dir)
@@ -295,24 +316,6 @@ func TestCacheFind(t *testing.T) {
 	}
 }
 
-func waitForAccounts(wantAccounts []accounts.Account, ks *KeyStore) error {
-	var list []accounts.Account
-	for d := 200 * time.Millisecond; d < 8*time.Second; d *= 2 {
-		list = ks.Accounts()
-		if reflect.DeepEqual(list, wantAccounts) {
-			// ks should have also received change notifications
-			select {
-			case <-ks.changes:
-			default:
-				return fmt.Errorf("wasn't notified of new accounts")
-			}
-			return nil
-		}
-		time.Sleep(d)
-	}
-	return fmt.Errorf("\ngot  %v\nwant %v", list, wantAccounts)
-}
-
 // TestUpdatedKeyfileContents tests that updating the contents of a keystore file
 // is noticed by the watcher, and the account cache is updated accordingly
 func TestUpdatedKeyfileContents(t *testing.T) {
@@ -327,8 +330,9 @@ func TestUpdatedKeyfileContents(t *testing.T) {
 	if len(list) > 0 {
 		t.Error("initial account list not empty:", list)
 	}
-	time.Sleep(100 * time.Millisecond)
-
+	if !waitWatcherStart(ks) {
+		t.Fatal("keystore watcher didn't start in time")
+	}
 	// Create the directory and copy a key file into it.
 	os.MkdirAll(dir, 0700)
 	defer os.RemoveAll(dir)
@@ -346,9 +350,8 @@ func TestUpdatedKeyfileContents(t *testing.T) {
 		t.Error(err)
 		return
 	}
-
 	// needed so that modTime of `file` is different to its current value after forceCopyFile
-	time.Sleep(1000 * time.Millisecond)
+	time.Sleep(time.Second)
 
 	// Now replace file contents
 	if err := forceCopyFile(file, cachetestAccounts[1].URL.Path); err != nil {
@@ -364,7 +367,7 @@ func TestUpdatedKeyfileContents(t *testing.T) {
 	}
 
 	// needed so that modTime of `file` is different to its current value after forceCopyFile
-	time.Sleep(1000 * time.Millisecond)
+	time.Sleep(time.Second)
 
 	// Now replace file contents again
 	if err := forceCopyFile(file, cachetestAccounts[2].URL.Path); err != nil {
@@ -380,7 +383,7 @@ func TestUpdatedKeyfileContents(t *testing.T) {
 	}
 
 	// needed so that modTime of `file` is different to its current value after os.WriteFile
-	time.Sleep(1000 * time.Millisecond)
+	time.Sleep(time.Second)
 
 	// Now replace file contents with crap
 	if err := os.WriteFile(file, []byte("foo"), 0600); err != nil {

accounts/keystore/keystore.go

@@ -498,6 +498,14 @@ func (ks *KeyStore) ImportPreSaleKey(keyJSON []byte, passphrase string) (account
 	return a, nil
 }
 
+// isUpdating returns whether the event notification loop is running.
+// This method is mainly meant for tests.
+func (ks *KeyStore) isUpdating() bool {
+	ks.mu.RLock()
+	defer ks.mu.RUnlock()
+	return ks.updating
+}
+
 // zeroKey zeroes a private key in memory.
 func zeroKey(k *ecdsa.PrivateKey) {
 	b := k.D.Bits()

accounts/keystore/keystore_test.go

@@ -113,6 +113,7 @@ func TestSignWithPassphrase(t *testing.T) {
 }
 
 func TestTimedUnlock(t *testing.T) {
+	t.Parallel()
 	_, ks := tmpKeyStore(t, true)
 
 	pass := "foo"
@@ -147,6 +148,7 @@ func TestTimedUnlock(t *testing.T) {
 }
 
 func TestOverrideUnlock(t *testing.T) {
+	t.Parallel()
 	_, ks := tmpKeyStore(t, false)
 
 	pass := "foo"
@@ -187,6 +189,7 @@ func TestOverrideUnlock(t *testing.T) {
 
 // This test should fail under -race if signing races the expiration goroutine.
 func TestSignRace(t *testing.T) {
+	t.Parallel()
 	_, ks := tmpKeyStore(t, false)
 
 	// Create a test account.
@@ -211,19 +214,33 @@ func TestSignRace(t *testing.T) {
 	t.Errorf("Account did not lock within the timeout")
 }
 
+// waitForKsUpdating waits until the updating-status of the ks reaches the
+// desired wantStatus.
+// It waits for a maximum time of maxTime, and returns false if it does not
+// finish in time
+func waitForKsUpdating(t *testing.T, ks *KeyStore, wantStatus bool, maxTime time.Duration) bool {
+	t.Helper()
+	// Wait max 250 ms, then return false
+	for t0 := time.Now(); time.Since(t0) < maxTime; {
+		if ks.isUpdating() == wantStatus {
+			return true
+		}
+		time.Sleep(25 * time.Millisecond)
+	}
+	return false
+}
+
 // Tests that the wallet notifier loop starts and stops correctly based on the
 // addition and removal of wallet event subscriptions.
 func TestWalletNotifierLifecycle(t *testing.T) {
+	t.Parallel()
 	// Create a temporary keystore to test with
 	_, ks := tmpKeyStore(t, false)
 
 	// Ensure that the notification updater is not running yet
 	time.Sleep(250 * time.Millisecond)
-	ks.mu.RLock()
-	updating := ks.updating
-	ks.mu.RUnlock()
 
-	if updating {
+	if ks.isUpdating() {
 		t.Errorf("wallet notifier running without subscribers")
 	}
 	// Subscribe to the wallet feed and ensure the updater boots up
@@ -233,38 +250,26 @@ func TestWalletNotifierLifecycle(t *testing.T) {
 	for i := 0; i < len(subs); i++ {
 		// Create a new subscription
 		subs[i] = ks.Subscribe(updates)
-
-		// Ensure the notifier comes online
-		time.Sleep(250 * time.Millisecond)
-		ks.mu.RLock()
-		updating = ks.updating
-		ks.mu.RUnlock()
-
-		if !updating {
+		if !waitForKsUpdating(t, ks, true, 250*time.Millisecond) {
 			t.Errorf("sub %d: wallet notifier not running after subscription", i)
 		}
 	}
-	// Unsubscribe and ensure the updater terminates eventually
-	for i := 0; i < len(subs); i++ {
+	// Close all but one sub
+	for i := 0; i < len(subs)-1; i++ {
 		// Close an existing subscription
 		subs[i].Unsubscribe()
-
-		// Ensure the notifier shuts down at and only at the last close
-		for k := 0; k < int(walletRefreshCycle/(250*time.Millisecond))+2; k++ {
-			ks.mu.RLock()
-			updating = ks.updating
-			ks.mu.RUnlock()
-
-			if i < len(subs)-1 && !updating {
-				t.Fatalf("sub %d: event notifier stopped prematurely", i)
-			}
-			if i == len(subs)-1 && !updating {
-				return
 	}
+	// Check that it is still running
 	time.Sleep(250 * time.Millisecond)
+
+	if !ks.isUpdating() {
+		t.Fatal("event notifier stopped prematurely")
 	}
-	}
+	// Unsubscribe the last one and ensure the updater terminates eventually.
+	subs[len(subs)-1].Unsubscribe()
+	if !waitForKsUpdating(t, ks, false, 4*time.Second) {
 		t.Errorf("wallet notifier didn't terminate after unsubscribe")
+	}
 }
 
 type walletEvent struct {

accounts/keystore/watch.go

@@ -28,8 +28,9 @@ import (
 
 type watcher struct {
 	ac       *accountCache
-	starting bool
-	running  bool
+	running  bool // set to true when runloop begins
+	runEnded bool // set to true when runloop ends
+	starting bool // set to true prior to runloop starting
 	ev       chan notify.EventInfo
 	quit     chan struct{}
 }
@@ -42,6 +43,9 @@ func newWatcher(ac *accountCache) *watcher {
 	}
 }
 
+// enabled returns false on systems not supported.
+func (*watcher) enabled() bool { return true }
+
 // starts the watcher loop in the background.
 // Start a watcher in the background if that's not already in progress.
 // The caller must hold w.ac.mu.
@@ -62,6 +66,7 @@ func (w *watcher) loop() {
 		w.ac.mu.Lock()
 		w.running = false
 		w.starting = false
+		w.runEnded = true
 		w.ac.mu.Unlock()
 	}()
 	logger := log.New("path", w.ac.keydir)

accounts/keystore/watch_fallback.go

@@ -22,8 +22,14 @@
 
 package keystore
 
-type watcher struct{ running bool }
+type watcher struct {
+	running  bool
+	runEnded bool
+}
 
 func newWatcher(*accountCache) *watcher { return new(watcher) }
 func (*watcher) start()                 {}
 func (*watcher) close()                 {}
+
+// enabled returns false on systems not supported.
+func (*watcher) enabled() bool { return false }