Adjusts log levels for ErrExceedsMaxMempoolSize

assertions/BUILD.bazel

@@ -23,6 +23,7 @@ go_library(
         "//runtime",
         "//solgen/go/rollupgen",
         "//util/stopwaiter",
+        "//util/log",
         "@com_github_ethereum_go_ethereum//accounts/abi/bind",
         "@com_github_ethereum_go_ethereum//common",
         "@com_github_ethereum_go_ethereum//core/types",

assertions/confirmation.go

@@ -11,6 +11,7 @@ import (
 	"github.com/OffchainLabs/bold/challenge-manager/types"
 	"github.com/OffchainLabs/bold/containers/option"
 	retry "github.com/OffchainLabs/bold/runtime"
+	utillog "github.com/OffchainLabs/bold/util/log"
 	"github.com/ethereum/go-ethereum/accounts/abi/bind"
 	"github.com/ethereum/go-ethereum/log"
 )
@@ -55,6 +56,10 @@ func (m *Manager) keepTryingAssertionConfirmation(ctx context.Context, assertion
 		log.Error("Could not get prev assertion creation info", "err", err)
 		return
 	}
+
+	backoffLogLevel := time.Second
+	exceedsMaxMempoolSizeEphemeralErrorHandler := utillog.NewEphemeralErrorHandler(10*time.Minute, "posting this transaction will exceed max mempool size", 0)
+
 	ticker := time.NewTicker(m.confirmationAttemptInterval)
 	defer ticker.Stop()
 	for {
@@ -83,11 +88,24 @@ func (m *Manager) keepTryingAssertionConfirmation(ctx context.Context, assertion
 			confirmed, err := solimpl.TryConfirmingAssertion(ctx, creationInfo.AssertionHash, prevCreationInfo.ConfirmPeriodBlocks+creationInfo.CreationBlock, m.chain, m.averageTimeForBlockCreation, option.None[protocol.EdgeId]())
 			if err != nil {
 				if !strings.Contains(err.Error(), "PREV_NOT_LATEST_CONFIRMED") {
-					log.Error("Could not confirm assertion", "err", err, "assertionHash", assertionHash.Hash)
+					backoffLogLevel *= 2
+					logLevel := log.Error
+					if backoffLogLevel > time.Minute {
+						backoffLogLevel = time.Minute
+					} else {
+						logLevel = log.Warn
+					}
+					logLevel = exceedsMaxMempoolSizeEphemeralErrorHandler.LogLevel(err, logLevel)
+
+					logLevel("Could not confirm assertion", "err", err, "assertionHash", assertionHash.Hash)
 					errorConfirmingAssertionByTimeCounter.Inc(1)
 				}
 				continue
 			}
+
+			exceedsMaxMempoolSizeEphemeralErrorHandler.Reset()
+			backoffLogLevel = time.Second
+
 			if confirmed {
 				assertionConfirmedCounter.Inc(1)
 				log.Info("Confirmed assertion by time", "assertionHash", creationInfo.AssertionHash)

assertions/poster.go

@@ -14,6 +14,7 @@ import (
 	"github.com/OffchainLabs/bold/containers"
 	"github.com/OffchainLabs/bold/containers/option"
 	l2stateprovider "github.com/OffchainLabs/bold/layer2-state-provider"
+	utillog "github.com/OffchainLabs/bold/util/log"
 	"github.com/ethereum/go-ethereum/log"
 	"github.com/ethereum/go-ethereum/metrics"
 	"github.com/pkg/errors"
@@ -30,10 +31,18 @@ func (m *Manager) postAssertionRoutine(ctx context.Context) {
 		log.Warn("Staker strategy not configured to stake on latest assertions")
 		return
 	}
+
+	backoffLogLevel := time.Second
+	exceedsMaxMempoolSizeEphemeralErrorHandler := utillog.NewEphemeralErrorHandler(10*time.Minute, "posting this transaction will exceed max mempool size", 0)
+
 	log.Info("Ready to post")
 	if _, err := m.PostAssertion(ctx); err != nil {
 		if !errors.Is(err, solimpl.ErrAlreadyExists) {
-			log.Error("Could not submit latest assertion to L1", "err", err)
+			backoffLogLevel *= 2
+			logLevel := log.Warn
+			logLevel = exceedsMaxMempoolSizeEphemeralErrorHandler.LogLevel(err, logLevel)
+
+			logLevel("Could not submit latest assertion to L1", "err", err)
 			errorPostingAssertionCounter.Inc(1)
 		}
 	}
@@ -49,9 +58,21 @@ func (m *Manager) postAssertionRoutine(ctx context.Context) {
 				case errors.Is(err, solimpl.ErrBatchNotYetFound):
 					log.Info("Waiting for more batches to post assertions about them onchain")
 				default:
-					log.Error("Could not submit latest assertion", "err", err, "validatorName", m.validatorName)
+					backoffLogLevel *= 2
+					logLevel := log.Error
+					if backoffLogLevel > time.Minute {
+						backoffLogLevel = time.Minute
+					} else {
+						logLevel = log.Warn
+					}
+					logLevel = exceedsMaxMempoolSizeEphemeralErrorHandler.LogLevel(err, logLevel)
+
+					logLevel("Could not submit latest assertion", "err", err, "validatorName", m.validatorName)
 					errorPostingAssertionCounter.Inc(1)
 				}
+			} else {
+				exceedsMaxMempoolSizeEphemeralErrorHandler.Reset()
+				backoffLogLevel = time.Second
 			}
 		case <-ctx.Done():
 			return

challenge-manager/chain-watcher/BUILD.bazel

@@ -17,6 +17,7 @@ go_library(
         "//runtime",
         "//solgen/go/challengeV2gen",
         "//util/stopwaiter",
+        "//util/log",
         "@com_github_ethereum_go_ethereum//accounts/abi/bind",
         "@com_github_ethereum_go_ethereum//common",
         "@com_github_ethereum_go_ethereum//log",

challenge-manager/chain-watcher/watcher.go

@@ -25,6 +25,7 @@ import (
 	l2stateprovider "github.com/OffchainLabs/bold/layer2-state-provider"
 	retry "github.com/OffchainLabs/bold/runtime"
 	"github.com/OffchainLabs/bold/solgen/go/challengeV2gen"
+	utillog "github.com/OffchainLabs/bold/util/log"
 	"github.com/OffchainLabs/bold/util/stopwaiter"
 
 	"github.com/ethereum/go-ethereum/accounts/abi/bind"
@@ -866,6 +867,9 @@ func (w *Watcher) confirmAssertionByChallengeWinner(ctx context.Context, edge pr
 		challengeGracePeriodBlocks,
 	)
 
+	backoffLogLevel := time.Second
+	exceedsMaxMempoolSizeEphemeralErrorHandler := utillog.NewEphemeralErrorHandler(10*time.Minute, "posting this transaction will exceed max mempool size", 0)
+
 	// Compute the number of blocks until we reach the assertion's
 	// deadline for confirmation.
 	ticker := time.NewTicker(w.assertionConfirmingInterval)
@@ -884,10 +888,23 @@ func (w *Watcher) confirmAssertionByChallengeWinner(ctx context.Context, edge pr
 				option.Some(edge.Id()),
 			)
 			if err != nil {
-				log.Error("Could not confirm assertion", "err", err, "assertionHash", common.Hash(claimId))
+				backoffLogLevel *= 2
+				logLevel := log.Error
+				if backoffLogLevel > time.Minute {
+					backoffLogLevel = time.Minute
+				} else {
+					logLevel = log.Warn
+				}
+				logLevel = exceedsMaxMempoolSizeEphemeralErrorHandler.LogLevel(err, logLevel)
+
+				logLevel("Could not confirm assertion", "err", err, "assertionHash", common.Hash(claimId))
 				errorConfirmingAssertionByWinnerCounter.Inc(1)
 				continue
 			}
+
+			exceedsMaxMempoolSizeEphemeralErrorHandler.Reset()
+			backoffLogLevel = time.Second
+
 			if confirmed {
 				assertionConfirmedCounter.Inc(1)
 				w.challenges.Delete(challengeParentAssertionHash)

util/log/BUILD.bazel

@@ -0,0 +1,9 @@
+load("@io_bazel_rules_go//go:def.bzl", "go_library")
+
+go_library(
+    name = "log",
+    srcs = ["log.go"],
+    importpath = "github.com/OffchainLabs/bold/util/log",
+    visibility = ["//visibility:public"],
+    deps = ["@com_github_ethereum_go_ethereum//log"],
+)

util/log/log.go

@@ -0,0 +1,67 @@
+package log
+
+import (
+	"strings"
+	"time"
+
+	"github.com/ethereum/go-ethereum/log"
+)
+
+// EphemeralErrorHandler handles errors that are ephemeral in nature i.h these are errors
+// that we would like to log as a warning unless they repeat for more than a certain duration of time.
+type EphemeralErrorHandler struct {
+	Duration        time.Duration
+	ErrorString     string
+	FirstOccurrence *time.Time
+
+	IgnoreDuration     time.Duration
+	IgnoredErrLogLevel func(string, ...interface{}) // Default IgnoredErrLogLevel is log.Debug
+}
+
+func NewEphemeralErrorHandler(duration time.Duration, errorString string, ignoreDuration time.Duration) *EphemeralErrorHandler {
+	return &EphemeralErrorHandler{
+		Duration:           duration,
+		ErrorString:        errorString,
+		FirstOccurrence:    &time.Time{},
+		IgnoreDuration:     ignoreDuration,
+		IgnoredErrLogLevel: log.Debug,
+	}
+}
+
+// LogLevel method defaults to returning the input currentLogLevel if the given error doesnt contain the errorSubstring,
+// but if it does, then returns one of the corresponding loglevels as follows
+//   - IgnoredErrLogLevel - if the error has been repeating for less than the IgnoreDuration of time. Defaults to log.Debug
+//   - log.Warn - if the error has been repeating for less than the given duration of time
+//   - log.Error - Otherwise
+//
+// # Usage Examples
+//
+//	ephemeralErrorHandler.Loglevel(err, log.Error)("msg")
+//	ephemeralErrorHandler.Loglevel(err, log.Error)("msg", "key1", val1, "key2", val2)
+//	ephemeralErrorHandler.Loglevel(err, log.Error)("msg", "key1", val1)
+func (h *EphemeralErrorHandler) LogLevel(err error, currentLogLevel func(msg string, ctx ...interface{})) func(string, ...interface{}) {
+	if h.ErrorString != "" && !strings.Contains(err.Error(), h.ErrorString) {
+		h.Reset()
+		return currentLogLevel
+	}
+
+	if *h.FirstOccurrence == (time.Time{}) {
+		*h.FirstOccurrence = time.Now()
+	}
+
+	if h.IgnoreDuration != 0 && time.Since(*h.FirstOccurrence) < h.IgnoreDuration {
+		if h.IgnoredErrLogLevel != nil {
+			return h.IgnoredErrLogLevel
+		}
+		return log.Debug
+	}
+
+	if time.Since(*h.FirstOccurrence) < h.Duration {
+		return log.Warn
+	}
+	return log.Error
+}
+
+func (h *EphemeralErrorHandler) Reset() {
+	*h.FirstOccurrence = time.Time{}
+}

util/log/log_test.go

@@ -0,0 +1,70 @@
+package log
+
+import (
+	"errors"
+	"reflect"
+	"testing"
+	"time"
+
+	"github.com/ethereum/go-ethereum/log"
+)
+
+func compareFunctions(f1, f2 func(msg string, ctx ...interface{})) bool {
+	return reflect.ValueOf(f1).Pointer() == reflect.ValueOf(f2).Pointer()
+}
+func TestSimple(t *testing.T) {
+	allErrHandler := NewEphemeralErrorHandler(2500*time.Millisecond, "", time.Second)
+	err := errors.New("sample error")
+	logLevel := allErrHandler.LogLevel(err, log.Error)
+	if !compareFunctions(log.Debug, logLevel) {
+		t.Fatalf("incorrect loglevel output. Want: Debug")
+	}
+
+	time.Sleep(1 * time.Second)
+	logLevel = allErrHandler.LogLevel(err, log.Error)
+	if !compareFunctions(log.Warn, logLevel) {
+		t.Fatalf("incorrect loglevel output. Want: Warn")
+	}
+
+	time.Sleep(2 * time.Second)
+	logLevel = allErrHandler.LogLevel(err, log.Error)
+	if !compareFunctions(log.Error, logLevel) {
+		t.Fatalf("incorrect loglevel output. Want: Error")
+	}
+}
+
+func TestComplex(t *testing.T) {
+	// Simulation: errorA happens continuously for 2 seconds and then errorB happens
+	errorAHandler := NewEphemeralErrorHandler(time.Second, "errorA", 0)
+	errorBHandler := NewEphemeralErrorHandler(1500*time.Millisecond, "errorB", 0)
+
+	// Computes result of chaining two ephemeral error handlers for a given recurring error
+	chainingErrHandlers := func(err error) func(string, ...interface{}) {
+		logLevel := log.Error
+		logLevel = errorAHandler.LogLevel(err, logLevel)
+		logLevel = errorBHandler.LogLevel(err, logLevel)
+		return logLevel
+	}
+
+	errA := errors.New("this is a sample errorA")
+	if !compareFunctions(log.Warn, chainingErrHandlers(errA)) {
+		t.Fatalf("incorrect loglevel output. Want: Warn")
+	}
+	time.Sleep(2 * time.Second)
+	if !compareFunctions(log.Error, chainingErrHandlers(errA)) {
+		t.Fatalf("incorrect loglevel output. Want: Error")
+	}
+
+	errB := errors.New("this is a sample errorB")
+	if !compareFunctions(log.Warn, chainingErrHandlers(errB)) {
+		t.Fatalf("incorrect loglevel output. Want: Warn")
+	}
+	if !compareFunctions(log.Warn, chainingErrHandlers(errA)) {
+		t.Fatalf("incorrect loglevel output. Want: Warn")
+	}
+
+	errC := errors.New("random error")
+	if !compareFunctions(log.Error, chainingErrHandlers(errC)) {
+		t.Fatalf("incorrect loglevel output. Want: Error")
+	}
+}