Skip to content

Commit

Permalink
add relaxed log method duration threshold (#2301)
Browse files Browse the repository at this point in the history
  • Loading branch information
badgersrus authored Feb 10, 2025
1 parent 25b7bb6 commit 5e0b611
Show file tree
Hide file tree
Showing 4 changed files with 43 additions and 16 deletions.
2 changes: 1 addition & 1 deletion go/enclave/components/rollup_consumer.go
Original file line number Diff line number Diff line change
Expand Up @@ -52,7 +52,7 @@ func NewRollupConsumer(

// ProcessRollups - processes the rollups found in the block, verifies the rollups and stores them
func (rc *rollupConsumerImpl) ProcessRollups(ctx context.Context, rollups []*common.ExtRollup) ([]common.ExtRollupMetadata, error) {
defer core.LogMethodDuration(rc.logger, measure.NewStopwatch(), "Rollup consumer processed blobs")
defer core.LogMethodDuration(rc.logger, measure.NewStopwatch(), "Rollup consumer processed blobs", &core.RelaxedThresholds)

rollupMetadata := make([]common.ExtRollupMetadata, len(rollups))
for idx, rollup := range rollups {
Expand Down
49 changes: 38 additions & 11 deletions go/enclave/core/utils.go
Original file line number Diff line number Diff line change
Expand Up @@ -30,28 +30,55 @@ func GetAuthenticatedSender(chainID int64, tx *types.Transaction) (*gethcommon.A
return &sender, nil
}

const (
// log level for requests that take longer than this threshold in millis
_errorThreshold = 500
_warnThreshold = 200
_infoThreshold = 100
_debugThreshold = 50
type DurationThresholds struct {
Error int64
Warn int64
Info int64
Debug int64
}

var (
// default thresholds for quick operations
DefaultThresholds = DurationThresholds{
Error: 500,
Warn: 200,
Info: 100,
Debug: 50,
}

// relaxed thresholds for known longer operations
RelaxedThresholds = DurationThresholds{
Error: 4000,
Warn: 1000,
Info: 100,
Debug: 50,
}
)

// LogMethodDuration - call only with "defer"
func LogMethodDuration(logger gethlog.Logger, stopWatch *measure.Stopwatch, msg string, args ...any) {
var thresholds *DurationThresholds
if len(args) > 0 {
if t, ok := args[0].(*DurationThresholds); ok {
thresholds = t
args = args[1:] // remove thresholds from args if present
}
}
if thresholds == nil {
thresholds = &DefaultThresholds
}

var f func(msg string, ctx ...interface{})
durationMillis := stopWatch.Measure().Milliseconds()

// we adjust the logging level based on the time
switch {
case durationMillis > _errorThreshold:
case durationMillis > thresholds.Error:
f = logger.Error
case durationMillis > _warnThreshold:
case durationMillis > thresholds.Warn:
f = logger.Warn
case durationMillis > _infoThreshold:
case durationMillis > thresholds.Info:
f = logger.Info
case durationMillis > _debugThreshold:
case durationMillis > thresholds.Debug:
f = logger.Debug
default:
f = logger.Trace
Expand Down
6 changes: 3 additions & 3 deletions go/enclave/enclave_admin_service.go
Original file line number Diff line number Diff line change
Expand Up @@ -221,7 +221,7 @@ func (e *enclaveAdminService) SubmitBatch(ctx context.Context, extBatch *common.
e.logger.Crit("Can't submit a batch to the active sequencer")
}

defer core.LogMethodDuration(e.logger, measure.NewStopwatch(), "SubmitBatch call completed.", log.BatchHashKey, extBatch.Hash())
defer core.LogMethodDuration(e.logger, measure.NewStopwatch(), "SubmitBatch call completed.", &core.RelaxedThresholds, log.BatchHashKey, extBatch.Hash())

e.logger.Info("Received new p2p batch", log.BatchHeightKey, extBatch.Header.Number, log.BatchHashKey, extBatch.Hash(), "l1", extBatch.Header.L1Proof)
seqNo := extBatch.Header.SequencerOrderNo.Uint64()
Expand Down Expand Up @@ -271,7 +271,7 @@ func (e *enclaveAdminService) CreateBatch(ctx context.Context, skipBatchIfEmpty
e.logger.Crit("Only the active sequencer can create batches")
}

defer core.LogMethodDuration(e.logger, measure.NewStopwatch(), "CreateBatch call ended")
defer core.LogMethodDuration(e.logger, measure.NewStopwatch(), "CreateBatch call ended", &core.RelaxedThresholds)

e.dataInMutex.RLock()
defer e.dataInMutex.RUnlock()
Expand All @@ -288,7 +288,7 @@ func (e *enclaveAdminService) CreateRollup(ctx context.Context, fromSeqNo uint64
if !e.isActiveSequencer(ctx) {
e.logger.Crit("Only the active sequencer can create rollups")
}
defer core.LogMethodDuration(e.logger, measure.NewStopwatch(), "CreateRollup call ended")
defer core.LogMethodDuration(e.logger, measure.NewStopwatch(), "CreateRollup call ended", &core.RelaxedThresholds)

// allow the simultaneous production of rollups and batches
e.dataInMutex.RLock()
Expand Down
2 changes: 1 addition & 1 deletion go/host/rpc/enclaverpc/enclave_client.go
Original file line number Diff line number Diff line change
Expand Up @@ -332,7 +332,7 @@ func (c *Client) HealthCheck(ctx context.Context) (bool, common.SystemError) {
}

func (c *Client) CreateBatch(ctx context.Context, skipIfEmpty bool) common.SystemError {
defer core.LogMethodDuration(c.logger, measure.NewStopwatch(), "CreateBatch rpc call")
defer core.LogMethodDuration(c.logger, measure.NewStopwatch(), "CreateBatch rpc call", &core.RelaxedThresholds)

response, err := c.protoClient.CreateBatch(ctx, &generated.CreateBatchRequest{SkipIfEmpty: skipIfEmpty})
if err != nil {
Expand Down

0 comments on commit 5e0b611

Please sign in to comment.