Fix test timeouts and races

.github/workflows/build-test.yml

@@ -51,7 +51,7 @@ jobs:
       # Here used to be a make build step, but we separated it into another job
 
       - name: Test
-        run: make test-short
+        run: make test-medium
 
   golangci:
     name: Lint

Makefile

@@ -47,8 +47,11 @@ test: install
 test-short:
 	go test -race -ldflags $(BUILD_LD_FLAGS) --short --count 1 -timeout 25m -failfast $(shell go list ./...)
 
+test-medium:
+	go test -race -ldflags $(BUILD_LD_FLAGS) --short --count 1 -timeout 60m -failfast $(shell go list ./...)
+
 test-cluster: install
-	go test -race -ldflags $(BUILD_LD_FLAGS) --count 1 -timeout 25m -failfast $(shell go list ./tools/cluster/tests/...)
+	go test -race -ldflags $(BUILD_LD_FLAGS) --count 1 -timeout 60m -failfast $(shell go list ./tools/cluster/tests/...)
 
 install-cli:
 	cd tools/wasp-cli && go mod tidy && go install -ldflags $(BUILD_LD_FLAGS)

clients/iota-go/iotatest/faucet.go

@@ -2,6 +2,9 @@ package iotatest
 
 import (
 	"context"
+	"fmt"
+	"math/rand"
+	"strings"
 	"time"
 
 	"github.com/iotaledger/wasp/v2/clients/iota-go/iotaclient"
@@ -23,8 +26,21 @@ func MakeSignerWithFundsFromSeed(
 
 	// there are only 256 different signers can be generated
 	signer := iotasigner.NewSignerByIndex(seed, keySchemeFlag, index)
-	err := iotaclient.RequestFundsFromFaucet(context.Background(), signer.Address(), faucetURL)
-	if err != nil {
+	var err error
+	for i := 0; i < 15; i++ {
+		err = iotaclient.RequestFundsFromFaucet(context.Background(), signer.Address(), faucetURL)
+		if err == nil {
+			break
+		}
+		if i < 14 && (strings.Contains(err.Error(), "429") || strings.Contains(err.Error(), "Too Many Requests")) {
+			delay := time.Duration(float64(time.Second) * (10 * float64(i+1)))
+			jitter := time.Duration(rand.Float64() * float64(5*time.Second))
+			finalDelay := delay + jitter
+
+			fmt.Printf("faucet rate limited (attempt %d/15), sleeping %v before retrying\n", i+1, finalDelay)
+			time.Sleep(finalDelay)
+			continue
+		}
 		panic(err)
 	}
 	if len(reader) > 0 {

clients/iotagraphql/iotaclienttest/api_read_test.go

@@ -23,12 +23,15 @@ func TestGetObject(t *testing.T) {
 	owner := iotago.MustAddressFromHex(testcommon.TestAddress)
 
 	limit := int(1)
-	coinsResp, err := client.GetCoins(ctx, iotaclient.GetCoinsRequest{
-		Owner: owner,
-		Limit: limit,
-	})
-	require.NoError(t, err)
-	require.NotEmpty(t, coinsResp.Data)
+	var coinsResp *iotajsonrpc.CoinPage
+	var err error
+	require.Eventually(t, func() bool {
+		coinsResp, err = client.GetCoins(ctx, iotaclient.GetCoinsRequest{
+			Owner: owner,
+			Limit: limit,
+		})
+		return err == nil && len(coinsResp.Data) > 0
+	}, 120*time.Second, 5*time.Second)
 
 	coin := coinsResp.Data[0]
 	objResp, err := client.GetObject(ctx, iotaclient.GetObjectRequest{
@@ -48,12 +51,15 @@ func TestGetTransactionBlock(t *testing.T) {
 	owner := iotago.MustAddressFromHex(testcommon.TestAddress)
 
 	limit := int(1)
-	coinsResp, err := client.GetCoins(ctx, iotaclient.GetCoinsRequest{
-		Owner: owner,
-		Limit: limit,
-	})
-	require.NoError(t, err)
-	require.NotEmpty(t, coinsResp.Data)
+	var coinsResp *iotajsonrpc.CoinPage
+	var err error
+	require.Eventually(t, func() bool {
+		coinsResp, err = client.GetCoins(ctx, iotaclient.GetCoinsRequest{
+			Owner: owner,
+			Limit: limit,
+		})
+		return err == nil && len(coinsResp.Data) > 0
+	}, 120*time.Second, 5*time.Second)
 
 	digest := &coinsResp.Data[0].PreviousTransaction
 	resp, err := client.GetTransactionBlock(ctx, iotaclient.GetTransactionBlockRequest{
@@ -66,13 +72,16 @@ func TestGetTransactionBlock(t *testing.T) {
 
 func TestQueryTransactionBlocks(t *testing.T) {
 	ctx := context.Background()
-	client := clients.NewGraphQLClient(iotaconn.TestnetGraphQLEndpointURL)
+	client := clients.NewGraphQLClientWithTimeout(iotaconn.TestnetGraphQLEndpointURL, 60*time.Second)
 
-	resp, err := client.QueryTransactionBlocks(ctx, iotaclient.QueryTransactionBlocksRequest{
-		Limit: lo.ToPtr(int(3)),
-	})
-	require.NoError(t, err)
-	require.NotEmpty(t, resp.Data)
+	var resp *iotajsonrpc.TransactionBlocksPage
+	var err error
+	require.Eventually(t, func() bool {
+		resp, err = client.QueryTransactionBlocks(ctx, iotaclient.QueryTransactionBlocksRequest{
+			Limit: lo.ToPtr(int(3)),
+		})
+		return err == nil && len(resp.Data) > 0
+	}, 3*time.Minute, 5*time.Second)
 }
 
 func TestTryGetPastObject(t *testing.T) {
@@ -82,12 +91,15 @@ func TestTryGetPastObject(t *testing.T) {
 	owner := iotago.MustAddressFromHex(testcommon.TestAddress)
 
 	limit := int(1)
-	coinsResp, err := client.GetCoins(ctx, iotaclient.GetCoinsRequest{
-		Owner: owner,
-		Limit: limit,
-	})
-	require.NoError(t, err)
-	require.NotEmpty(t, coinsResp.Data)
+	var coinsResp *iotajsonrpc.CoinPage
+	var err error
+	require.Eventually(t, func() bool {
+		coinsResp, err = client.GetCoins(ctx, iotaclient.GetCoinsRequest{
+			Owner: owner,
+			Limit: limit,
+		})
+		return err == nil && len(coinsResp.Data) > 0
+	}, 120*time.Second, 5*time.Second)
 
 	coin := coinsResp.Data[0]
 	version := coin.Version.Uint64()

clients/iotagraphql/iotaclienttest/api_write_test.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"math/big"
 	"testing"
+	"time"
 
 	"github.com/stretchr/testify/require"
 
@@ -92,9 +93,12 @@ func TestDryRunTransaction(t *testing.T) {
 func TestExecuteTransactionBlock(t *testing.T) {
 	client := clients.NewGraphQLClient(iotaconn.TestnetGraphQLEndpointURL)
 	signer := iotatest.MakeSignerWithFunds(0, iotaconn.TestnetFaucetURL, client)
-	coins, err := client.GetCoins(context.Background(), iotaclient.GetCoinsRequest{Owner: signer.Address(), Limit: 10})
-	require.NoError(t, err)
-	require.NotEmpty(t, coins.Data, "no coins indexed for %v after faucet", signer.Address().String())
+	var coins *iotajsonrpc.CoinPage
+	var err error
+	require.Eventually(t, func() bool {
+		coins, err = client.GetCoins(context.Background(), iotaclient.GetCoinsRequest{Owner: signer.Address(), Limit: 10})
+		return err == nil && len(coins.Data) > 0
+	}, 300*time.Second, 5*time.Second, "no coins indexed for %v after faucet", signer.Address().String())
 	pickedCoins, err := iotajsonrpc.PickupCoins(coins, big.NewInt(100), iotaclient.DefaultGasBudget, 0, 0)
 	require.NoError(t, err)
 	tx, err := client.PayAllIota(
@@ -123,9 +127,12 @@ func TestExecuteTransactionBlock(t *testing.T) {
 func TestSignAndExecuteTransaction(t *testing.T) {
 	client := clients.NewGraphQLClient(iotaconn.TestnetGraphQLEndpointURL)
 	signer := iotatest.MakeSignerWithFunds(0, iotaconn.TestnetFaucetURL, client)
-	coins, err := client.GetCoins(context.Background(), iotaclient.GetCoinsRequest{Owner: signer.Address(), Limit: 10})
-	require.NoError(t, err)
-	require.NotEmpty(t, coins.Data, "no coins indexed for %v after faucet", signer.Address().String())
+	var coins *iotajsonrpc.CoinPage
+	var err error
+	require.Eventually(t, func() bool {
+		coins, err = client.GetCoins(context.Background(), iotaclient.GetCoinsRequest{Owner: signer.Address(), Limit: 10})
+		return err == nil && len(coins.Data) > 0
+	}, 300*time.Second, 5*time.Second, "no coins indexed for %v after faucet", signer.Address().String())
 	pickedCoins, err := iotajsonrpc.PickupCoins(coins, big.NewInt(100), iotaclient.DefaultGasBudget, 0, 0)
 	require.NoError(t, err)
 	tx, err := client.PayAllIota(

components/webapi/webapi_test.go

@@ -2,8 +2,10 @@ package webapi_test
 
 import (
 	"context"
+	"fmt"
 	"io"
 	"log/slog"
+	"net"
 	"net/http"
 	"testing"
 	"time"
@@ -46,19 +48,22 @@ func TestInternalServerErrors(t *testing.T) {
 		log.NewLogger(log.WithHandler(logger)),
 	)
 
-	time.Sleep(5 * time.Second)
-
 	// Add an endpoint that just panics with "foobar" and start the server
 	exceptionText := "foobar"
 	e.GET("/test", func(c echo.Context) error { panic(exceptionText) })
+
+	l, err := net.Listen("tcp", "127.0.0.1:0")
+	require.NoError(t, err)
+	e.Listener = l
+
 	go func() {
-		err := e.Start(":9999")
-		require.ErrorIs(t, http.ErrServerClosed, err)
+		err2 := e.Start("")
+		require.ErrorIs(t, err2, http.ErrServerClosed)
 	}()
 	defer e.Shutdown(context.Background())
 
 	// query the endpoint
-	req, err := http.NewRequest(http.MethodGet, "http://localhost:9999/test", http.NoBody)
+	req, err := http.NewRequest(http.MethodGet, fmt.Sprintf("http://%s/test", e.Listener.Addr().String()), http.NoBody)
 	require.NoError(t, err)
 
 	res, err := http.DefaultClient.Do(req)
@@ -69,7 +74,7 @@ func TestInternalServerErrors(t *testing.T) {
 	res.Body.Close()
 
 	// assert the exception is not present in the response (prevent leaking errors)
-	require.Equal(t, res.StatusCode, http.StatusInternalServerError)
+	require.Equal(t, http.StatusInternalServerError, res.StatusCode)
 	require.NotContains(t, string(resBody), exceptionText)
 
 	// assert the exception is logged

go.work.sum

@@ -12,6 +12,7 @@ dmitri.shuralyov.com/html/belt v0.0.0-20180602232347-f7d459c86be0 h1:SPOUaucgtVl
 dmitri.shuralyov.com/service/change v0.0.0-20181023043359-a85b471d5412 h1:GvWw74lx5noHocd+f6HBMXK6DuggBB1dhVkuGZbv7qM=
 dmitri.shuralyov.com/state v0.0.0-20180228185332-28bcc343414c h1:ivON6cwHK1OH26MZyWDCnbTRZZf0IhNsENoNAKFS1g4=
 git.apache.org/thrift.git v0.0.0-20180902110319-2566ecd5d999 h1:OR8VhtwhcAI3U48/rzBsVOuHi0zDPzYI1xASVcdSgR8=
+github.com/99designs/gqlgen v0.17.57 h1:Ak4p60BRq6QibxY0lEc0JnQhDurfhxA67sp02lMjmPc=
 github.com/99designs/gqlgen v0.17.57/go.mod h1:Jx61hzOSTcR4VJy/HFIgXiQ5rJ0Ypw8DxWLjbYDAUw0=
 github.com/AndreasBriese/bbloom v0.0.0-20180913140656-343706a395b7/go.mod h1:bOvUY6CB00SOBii9/FifXqc0awNKxLFCL/+pkDPuyl8=
 github.com/Azure/azure-sdk-for-go/sdk/azcore v1.7.0 h1:8q4SaHjFsClSvuVne0ID/5Ka8u3fcIHyqkLjcFpNRHQ=
@@ -43,14 +44,17 @@ github.com/aead/chacha20 v0.0.0-20180709150244-8b13a72661da h1:KjTM2ks9d14ZYCvmH
 github.com/aead/chacha20 v0.0.0-20180709150244-8b13a72661da/go.mod h1:eHEWzANqSiWQsof+nXEI9bUVUyV6F53Fp89EuCh2EAA=
 github.com/aead/siphash v1.0.1 h1:FwHfE/T45KPKYuuSAKyyvE+oPWcaQ+CUmFW0bPlM+kg=
 github.com/aerospike/aerospike-client-go v1.35.2/go.mod h1:zj8LBEnWBDOVEIJt8LvaRvDG5ARAoa5dBeHaB472NRc=
+github.com/agnivade/levenshtein v1.1.1 h1:QY8M92nrzkmr798gCo3kmMyqXFzdQVpxLlGPRBij0P8=
 github.com/agnivade/levenshtein v1.1.1/go.mod h1:veldBMzWxcCG2ZvUTKD2kJNRdCk5hVbJomOvKkmgYbo=
 github.com/alecthomas/chroma/v2 v2.14.0 h1:R3+wzpnUArGcQz7fCETQBzO5n9IMNi13iIs46aU4V9E=
 github.com/alecthomas/chroma/v2 v2.14.0/go.mod h1:QolEbTfmUHIMVpBqxeDnNBj2uoeI4EbYP4i6n68SG4I=
 github.com/alecthomas/kingpin/v2 v2.4.0 h1:f48lwail6p8zpO1bC4TxtqACaGqHYA22qkHjHpqDjYY=
 github.com/alecthomas/kingpin/v2 v2.4.0/go.mod h1:0gyi0zQnjuFk8xrkNKamJoyUo382HRL7ATRpFZCw6tE=
 github.com/alecthomas/units v0.0.0-20211218093645-b94a6e3cc137 h1:s6gZFSlWYmbqAuRjVTiNNhvNRfY2Wxp9nhfyel4rklc=
 github.com/alecthomas/units v0.0.0-20211218093645-b94a6e3cc137/go.mod h1:OMCwj8VM1Kc9e19TLln2VL61YJF0x1XFtfdL4JdbSyE=
+github.com/alexflint/go-arg v1.5.1 h1:nBuWUCpuRy0snAG+uIJ6N0UvYxpxA0/ghA/AaHxlT8Y=
 github.com/alexflint/go-arg v1.5.1/go.mod h1:A7vTJzvjoaSTypg4biM5uYNTkJ27SkNTArtYXnlqVO8=
+github.com/alexflint/go-scalar v1.2.0 h1:WR7JPKkeNpnYIOfHRa7ivM21aWAdHD0gEWHCx+WQBRw=
 github.com/alexflint/go-scalar v1.2.0/go.mod h1:LoFvNMqS1CPrMVltza4LvnGKhaSpc3oyLEBUZVhhS2o=
 github.com/anmitsu/go-shlex v0.0.0-20161002113705-648efa622239 h1:kFOfPq6dUM1hTo4JG6LR5AXSUEsOjtdm0kw0FtQtMJA=
 github.com/apache/thrift v0.0.0-20171203172758-327ebb6c2b6d/go.mod h1:cp2SuWMxlEZw2r+iP2GNCdIi4C1qmUzdZFSVb+bacwQ=
@@ -103,6 +107,7 @@ github.com/bmatcuk/doublestar/v4 v4.9.0/go.mod h1:xBQ8jztBU6kakFMg+8WGxn0c6z1fTS
 github.com/bmizerany/assert v0.0.0-20160611221934-b7ed37b82869/go.mod h1:Ekp36dRnpXw/yCqJaO+ZrUyxD+3VXMFFr56k5XYrpB4=
 github.com/boltdb/bolt v1.3.1/go.mod h1:clJnj/oiGkjum5o1McbSZDSLxVThjynRyGBgiAx27Ps=
 github.com/bradfitz/go-smtpd v0.0.0-20170404230938-deb6d6237625 h1:ckJgFhFWywOx+YLEMIJsTb+NV6NexWICk5+AMSuz3ss=
+github.com/bradleyjkemp/cupaloy/v2 v2.6.0 h1:knToPYa2xtfg42U3I6punFEjaGFKWQRXJwj0JTv4mTs=
 github.com/bradleyjkemp/cupaloy/v2 v2.6.0/go.mod h1:bm7JXdkRd4BHJk9HpwqAI8BoAY1lps46Enkdqw6aRX0=
 github.com/btcsuite/btcd v0.24.2 h1:aLmxPguqxza+4ag8R1I2nnJjSu2iFn/kqtHTIImswcY=
 github.com/btcsuite/btcd/btcec/v2 v2.2.1 h1:xP60mv8fvp+0khmrN0zTdPC3cNm24rfeE6lh2R/Yv3E=
@@ -414,6 +419,7 @@ github.com/shurcooL/sanitized_anchor_name v0.0.0-20170918181015-86672fcb3f95 h1:
 github.com/shurcooL/users v0.0.0-20180125191416-49c67e49c537 h1:YGaxtkYjb8mnTvtufv2LKLwCQu2/C7qFB7UtrOlTWOY=
 github.com/shurcooL/webdavfs v0.0.0-20170829043945-18c3829fa133 h1:JtcyT0rk/9PKOdnKQzuDR+FSjh7SGtJwpgVpfZBRKlQ=
 github.com/smartystreets/goconvey v0.0.0-20190330032615-68dc04aab96a/go.mod h1:syvi0/a8iFYH4r/RixwvyeAJjdLS9QV7WQ/tjFTllLA=
+github.com/sosodev/duration v1.3.1 h1:qtHBDMQ6lvMQsL15g4aopM4HEfOaYuhWBw3NPTtlqq4=
 github.com/sosodev/duration v1.3.1/go.mod h1:RQIBBX0+fMLc/D9+Jb/fwvVmo0eZvDDEERAikUR6SDg=
 github.com/sourcegraph/annotate v0.0.0-20160123013949-f4cad6c6324d h1:yKm7XZV6j9Ev6lojP2XaIshpT4ymkqhMeSghO5Ps00E=
 github.com/sourcegraph/conc v0.3.0 h1:OQTbbt6P72L20UqAkXXuLOj79LfEanQ+YQFNpLA9ySo=

packages/cache/cache.go

@@ -86,9 +86,9 @@ func GetStats() *Stats {
 	}
 }
 
-// NewCacheParition creates a new cache partition
+// NewCachePartition creates a new cache partition
 // initializes the cache if not already happened
-func NewCacheParition() (CacheInterface, error) {
+func NewCachePartition() (CacheInterface, error) {
 	mutex.Lock()
 	defer mutex.Unlock()
 

packages/chain/node_test.go

@@ -47,6 +47,7 @@ import (
 	"github.com/iotaledger/wasp/v2/packages/testutil/l1starter"
 	"github.com/iotaledger/wasp/v2/packages/testutil/testchain"
 	"github.com/iotaledger/wasp/v2/packages/testutil/testlogger"
+	"github.com/iotaledger/wasp/v2/packages/testutil/testmisc"
 	"github.com/iotaledger/wasp/v2/packages/testutil/testpeers"
 	"github.com/iotaledger/wasp/v2/packages/transaction"
 	"github.com/iotaledger/wasp/v2/packages/vm/core/accounts"
@@ -68,12 +69,12 @@ func TestMain(m *testing.M) {
 func TestNodeBasic(t *testing.T) {
 	t.Parallel()
 	tests := []tc{
-		{n: 1, f: 0, reliable: true, timeout: 30 * time.Second},   // Low N
-		{n: 2, f: 0, reliable: true, timeout: 40 * time.Second},   // Low N
-		{n: 3, f: 0, reliable: true, timeout: 50 * time.Second},   // Low N
-		{n: 4, f: 0, reliable: true, timeout: 100 * time.Second},  // Minimal robust config.
-		{n: 4, f: 1, reliable: true, timeout: 100 * time.Second},  // Minimal robust config.
-		{n: 10, f: 3, reliable: true, timeout: 150 * time.Second}, // Typical config.
+		{n: 1, f: 0, reliable: true, timeout: 60 * time.Second},   // Low N
+		{n: 2, f: 0, reliable: true, timeout: 60 * time.Second},   // Low N
+		{n: 3, f: 0, reliable: true, timeout: 60 * time.Second},   // Low N
+		{n: 4, f: 0, reliable: true, timeout: 120 * time.Second},  // Minimal robust config.
+		{n: 4, f: 1, reliable: true, timeout: 120 * time.Second},  // Minimal robust config.
+		{n: 10, f: 3, reliable: true, timeout: 180 * time.Second}, // Typical config.
 	}
 	if !testing.Short() {
 		tests = append(tests,
@@ -96,7 +97,7 @@ func testNodeBasic(t *testing.T, n, f int, reliable bool, timeout time.Duration,
 	te := newEnv(t, n, f, reliable, node)
 	defer te.close()
 
-	ctxTimeout, ctxTimeoutCancel := context.WithTimeout(te.ctx, timeout)
+	ctxTimeout, ctxTimeoutCancel := context.WithTimeout(te.ctx, testmisc.GetTimeout(timeout))
 	defer ctxTimeoutCancel()
 
 	te.log.LogDebugf("All started.")
@@ -107,7 +108,7 @@ func testNodeBasic(t *testing.T, n, f int, reliable bool, timeout time.Duration,
 
 	// Create SC L1Client account with some deposit
 	scClient := cryptolib.NewKeyPair()
-	err := te.l1Client.RequestFunds(context.Background(), *scClient.Address())
+	err := te.l1Client.RequestFunds(ctxTimeout, *scClient.Address())
 	require.NoError(t, err)
 
 	//
@@ -145,7 +146,7 @@ func testNodeBasic(t *testing.T, n, f int, reliable bool, timeout time.Duration,
 		require.NoError(t, err)
 		reqRef, err := req.GetCreatedObjectByName(iscmove.RequestModuleName, iscmove.RequestObjectName)
 		require.NoError(t, err)
-		reqWithObj, err := te.l2Client.GetRequestFromObjectID(context.Background(), reqRef.ObjectID)
+		reqWithObj, err := te.l2Client.GetRequestFromObjectID(ctxTimeout, reqRef.ObjectID)
 		require.NoError(t, err)
 
 		incRequests[i] = *reqWithObj

packages/evm/evmlogger/evmlogger.go

@@ -4,14 +4,19 @@ package evmlogger
 import (
 	"context"
 	"log/slog"
+	"sync"
 
 	"github.com/ethereum/go-ethereum/log"
 
 	hiveLog "github.com/iotaledger/hive.go/log"
 )
 
+var initOnce sync.Once
+
 func Init(hiveLogger hiveLog.Logger) {
-	log.SetDefault(log.NewLogger(&hiveLogHandler{hiveLogger}))
+	initOnce.Do(func() {
+		log.SetDefault(log.NewLogger(&hiveLogHandler{hiveLog.NewLogger()}))
+	})
 }
 
 type hiveLogHandler struct{ hiveLog.Logger }

packages/kv/cached.go

@@ -13,7 +13,7 @@ type cachedKVStoreReader struct {
 // IMPORTANT: there is no logic for cache invalidation, so make sure that the
 // underlying KVStoreReader is never mutated.
 func NewCachedKVStoreReader(r KVStoreReader) KVStoreReader {
-	cache, err := cache.NewCacheParition()
+	cache, err := cache.NewCachePartition()
 	if err != nil {
 		panic(err)
 	}