Merge pull request #175 from morph-l2/ryan/tracer-with-logs

feat(tracer): add withLog to callTracer

Author: ryanmorphl2

core/state_transition.go

@@ -355,6 +355,13 @@ func (st *StateTransition) TransitionDb() (*ExecutionResult, error) {
 		return nil, err
 	}
 
+	if st.evm.Config.Debug {
+		st.evm.Config.Tracer.CaptureTxStart(st.initialGas)
+		defer func() {
+			st.evm.Config.Tracer.CaptureTxEnd(st.gas)
+		}()
+	}
+
 	var (
 		msg              = st.msg
 		sender           = vm.AccountRef(msg.From())

core/types/l2trace.go

@@ -85,6 +85,7 @@ type StructLogRes struct {
 	Depth         int               `json:"depth"`
 	Error         string            `json:"error,omitempty"`
 	Stack         []string          `json:"stack,omitempty"`
+	ReturnData    string            `json:"returnData,omitempty"`
 	Memory        []string          `json:"memory,omitempty"`
 	Storage       map[string]string `json:"storage,omitempty"`
 	RefundCounter uint64            `json:"refund,omitempty"`

core/vm/access_list_tracer.go

@@ -175,6 +175,10 @@ func (*AccessListTracer) CaptureEnter(typ OpCode, from common.Address, to common
 
 func (*AccessListTracer) CaptureExit(output []byte, gasUsed uint64, err error) {}
 
+func (t *AccessListTracer) CaptureTxStart(gasLimit uint64) {}
+
+func (t *AccessListTracer) CaptureTxEnd(restGas uint64) {}
+
 // AccessList returns the current accesslist maintained by the tracer.
 func (a *AccessListTracer) AccessList() types.AccessList {
 	return a.list.accessList()

core/vm/logger.go

@@ -19,10 +19,12 @@ package vm
 import (
 	"bytes"
 	"encoding/hex"
+	"encoding/json"
 	"fmt"
 	"io"
 	"math/big"
 	"strings"
+	"sync/atomic"
 	"time"
 
 	"github.com/holiman/uint256"
@@ -127,6 +129,9 @@ func (s *StructLog) ErrorString() string {
 // Note that reference types are actual VM data structures; make copies
 // if you need to retain them beyond the current call.
 type EVMLogger interface {
+	// Transaction level
+	CaptureTxStart(gasLimit uint64)
+	CaptureTxEnd(restGas uint64)
 	CaptureStart(env *EVM, from common.Address, to common.Address, create bool, input []byte, gas uint64, value *big.Int)
 	CaptureState(pc uint64, op OpCode, gas, cost uint64, scope *ScopeContext, rData []byte, depth int, err error)
 	CaptureStateAfter(pc uint64, op OpCode, gas, cost uint64, scope *ScopeContext, rData []byte, depth int, err error)
@@ -162,6 +167,14 @@ type StructLogger struct {
 	logs            []*StructLog
 	output          []byte
 	err             error
+
+	gasLimit uint64
+	usedGas  uint64
+
+	interrupt atomic.Bool // Atomic flag to signal execution interruption
+	reason    error       // Textual reason for the interruption
+
+	ResultL1DataFee *big.Int
 }
 
 // NewStructLogger returns a new logger
@@ -214,6 +227,11 @@ func (l *StructLogger) CaptureStart(env *EVM, from common.Address, to common.Add
 //
 // CaptureState also tracks SLOAD/SSTORE ops to track storage change.
 func (l *StructLogger) CaptureState(pc uint64, op OpCode, gas, cost uint64, scope *ScopeContext, rData []byte, depth int, opErr error) {
+	// If tracing was interrupted, set the error and stop
+	if l.interrupt.Load() {
+		return
+	}
+
 	memory := scope.Memory
 	stack := scope.Stack
 	contract := scope.Contract
@@ -340,6 +358,14 @@ func (l *StructLogger) CaptureExit(output []byte, gasUsed uint64, err error) {
 
 }
 
+func (l *StructLogger) CaptureTxStart(gasLimit uint64) {
+	l.gasLimit = gasLimit
+}
+
+func (l *StructLogger) CaptureTxEnd(restGas uint64) {
+	l.usedGas = l.gasLimit - restGas
+}
+
 // UpdatedAccounts is used to collect all "touched" accounts
 func (l *StructLogger) UpdatedAccounts() map[common.Address]struct{} {
 	return l.statesAffected
@@ -367,6 +393,33 @@ func (l *StructLogger) Error() error { return l.err }
 // Output returns the VM return value captured by the trace.
 func (l *StructLogger) Output() []byte { return l.output }
 
+func (l *StructLogger) GetResult() (json.RawMessage, error) {
+	// Tracing aborted
+	if l.reason != nil {
+		return nil, l.reason
+	}
+	failed := l.err != nil
+	returnData := common.CopyBytes(l.output)
+	// Return data when successful and revert reason when reverted, otherwise empty.
+	returnVal := fmt.Sprintf("%x", returnData)
+	if failed && l.err != ErrExecutionReverted {
+		returnVal = ""
+	}
+	return json.Marshal(&types.ExecutionResult{
+		Gas:         l.usedGas,
+		Failed:      failed,
+		ReturnValue: returnVal,
+		StructLogs:  formatLogs(l.StructLogs()),
+		L1DataFee:   (*hexutil.Big)(l.ResultL1DataFee),
+	})
+}
+
+// Stop terminates execution of the tracer at the first opportune moment.
+func (l *StructLogger) Stop(err error) {
+	l.reason = err
+	l.interrupt.Store(true)
+}
+
 // WriteTrace writes a formatted trace to the given writer
 func WriteTrace(writer io.Writer, logs []*StructLog) {
 	for _, log := range logs {
@@ -487,6 +540,10 @@ func (t *mdLogger) CaptureEnter(typ OpCode, from common.Address, to common.Addre
 
 func (t *mdLogger) CaptureExit(output []byte, gasUsed uint64, err error) {}
 
+func (t *mdLogger) CaptureTxStart(gasLimit uint64) {}
+
+func (t *mdLogger) CaptureTxEnd(restGas uint64) {}
+
 // FormatLogs formats EVM returned structured logs for json output
 func FormatLogs(logs []*StructLog) []*types.StructLogRes {
 	formatted := make([]*types.StructLogRes, 0, len(logs))
@@ -511,3 +568,44 @@ func FormatLogs(logs []*StructLog) []*types.StructLogRes {
 	}
 	return formatted
 }
+
+// formatLogs formats EVM returned structured logs for json output
+func formatLogs(logs []*StructLog) []*types.StructLogRes {
+	formatted := make([]*types.StructLogRes, len(logs))
+	for index, trace := range logs {
+		formatted[index] = &types.StructLogRes{
+			Pc:            trace.Pc,
+			Op:            trace.Op.String(),
+			Gas:           trace.Gas,
+			GasCost:       trace.GasCost,
+			Depth:         trace.Depth,
+			Error:         trace.ErrorString(),
+			RefundCounter: trace.RefundCounter,
+		}
+		if trace.Stack != nil {
+			stack := make([]string, len(trace.Stack))
+			for i, stackValue := range trace.Stack {
+				stack[i] = stackValue.Hex()
+			}
+			formatted[index].Stack = stack
+		}
+		if trace.ReturnData.Len() > 0 {
+			formatted[index].ReturnData = hexutil.Bytes(trace.ReturnData.Bytes()).String()
+		}
+		if trace.Memory.Len() > 0 {
+			memory := make([]string, 0, (trace.Memory.Len()+31)/32)
+			for i := 0; i+32 <= trace.Memory.Len(); i += 32 {
+				memory = append(memory, fmt.Sprintf("%x", trace.Memory.Bytes()[i:i+32]))
+			}
+			formatted[index].Memory = memory
+		}
+		if trace.Storage != nil {
+			storage := make(map[string]string)
+			for i, storageValue := range trace.Storage {
+				storage[fmt.Sprintf("%x", i)] = fmt.Sprintf("%x", storageValue)
+			}
+			formatted[index].Storage = storage
+		}
+	}
+	return formatted
+}

core/vm/logger_json.go

@@ -98,3 +98,7 @@ func (l *JSONLogger) CaptureEnter(typ OpCode, from common.Address, to common.Add
 }
 
 func (l *JSONLogger) CaptureExit(output []byte, gasUsed uint64, err error) {}
+
+func (t *JSONLogger) CaptureTxStart(gasLimit uint64) {}
+
+func (t *JSONLogger) CaptureTxEnd(restGas uint64) {}

core/vm/runtime/runtime_test.go

@@ -376,7 +376,7 @@ func benchmarkNonModifyingCode(gas uint64, code []byte, name string, tracerCode
 	cfg.State, _ = state.New(common.Hash{}, state.NewDatabase(rawdb.NewMemoryDatabase()), nil)
 	cfg.GasLimit = gas
 	if len(tracerCode) > 0 {
-		tracer, err := tracers.New(tracerCode, new(tracers.Context))
+		tracer, err := tracers.New(tracerCode, new(tracers.Context), nil)
 		if err != nil {
 			b.Fatal(err)
 		}
@@ -877,7 +877,7 @@ func TestRuntimeJSTracer(t *testing.T) {
 			statedb.SetCode(common.HexToAddress("0xee"), calleeCode)
 			statedb.SetCode(common.HexToAddress("0xff"), depressedCode)
 
-			tracer, err := tracers.New(jsTracer, new(tracers.Context))
+			tracer, err := tracers.New(jsTracer, new(tracers.Context), nil)
 			if err != nil {
 				t.Fatal(err)
 			}
@@ -912,7 +912,7 @@ func TestJSTracerCreateTx(t *testing.T) {
 	code := []byte{byte(vm.PUSH1), 0, byte(vm.PUSH1), 0, byte(vm.RETURN)}
 
 	statedb, _ := state.New(common.Hash{}, state.NewDatabase(rawdb.NewMemoryDatabase()), nil)
-	tracer, err := tracers.New(jsTracer, new(tracers.Context))
+	tracer, err := tracers.New(jsTracer, new(tracers.Context), nil)
 	if err != nil {
 		t.Fatal(err)
 	}

eth/tracers/api.go

@@ -20,6 +20,7 @@ import (
 	"bufio"
 	"bytes"
 	"context"
+	"encoding/json"
 	"errors"
 	"fmt"
 	"io/ioutil"
@@ -173,15 +174,15 @@ type TraceConfig struct {
 	Tracer  *string
 	Timeout *string
 	Reexec  *uint64
+	// Config specific to given tracer. Note struct logger
+	// config are historically embedded in main object.
+	TracerConfig json.RawMessage
 }
 
 // TraceCallConfig is the config for traceCall API. It holds one more
 // field to override the state for tracing.
 type TraceCallConfig struct {
-	*vm.LogConfig
-	Tracer         *string
-	Timeout        *string
-	Reexec         *uint64
+	TraceConfig
 	StateOverrides *ethapi.StateOverride
 }
 
@@ -898,12 +899,7 @@ func (api *API) TraceCall(ctx context.Context, args ethapi.TransactionArgs, bloc
 
 	var traceConfig *TraceConfig
 	if config != nil {
-		traceConfig = &TraceConfig{
-			LogConfig: config.LogConfig,
-			Tracer:    config.Tracer,
-			Timeout:   config.Timeout,
-			Reexec:    config.Reexec,
-		}
+		traceConfig = &config.TraceConfig
 	}
 
 	signer := types.MakeSigner(api.backend.ChainConfig(), block.Number())
@@ -921,75 +917,58 @@ func (api *API) TraceCall(ctx context.Context, args ethapi.TransactionArgs, bloc
 func (api *API) traceTx(ctx context.Context, message core.Message, txctx *Context, vmctx vm.BlockContext, statedb *state.StateDB, config *TraceConfig, l1DataFee *big.Int) (interface{}, error) {
 	// Assemble the structured logger or the JavaScript tracer
 	var (
-		tracer    vm.EVMLogger
+		tracer    Tracer
 		err       error
+		timeout   = defaultTraceTimeout
 		txContext = core.NewEVMTxContext(message)
 	)
-	switch {
-	case config == nil:
-		tracer = vm.NewStructLogger(nil)
-	case config.Tracer != nil:
-		// Define a meaningful timeout of a single transaction trace
-		timeout := defaultTraceTimeout
-		if config.Timeout != nil {
-			if timeout, err = time.ParseDuration(*config.Timeout); err != nil {
-				return nil, err
-			}
-		}
-		if t, err := New(*config.Tracer, txctx); err != nil {
+	if config == nil {
+		config = &TraceConfig{}
+	}
+	// Default tracer is the struct logger
+	tracer = vm.NewStructLogger(config.LogConfig)
+	if config.Tracer != nil {
+		tracer, err = New(*config.Tracer, txctx, config.TracerConfig)
+		if err != nil {
 			return nil, err
-		} else {
-			deadlineCtx, cancel := context.WithTimeout(ctx, timeout)
-			go func() {
-				<-deadlineCtx.Done()
-				if errors.Is(deadlineCtx.Err(), context.DeadlineExceeded) {
-					t.Stop(errors.New("execution timeout"))
-				}
-			}()
-			defer cancel()
-			tracer = t
 		}
-	default:
-		tracer = vm.NewStructLogger(config.LogConfig)
 	}
 	// Run the transaction with tracing enabled.
 	vmenv := vm.NewEVM(vmctx, txContext, statedb, api.backend.ChainConfig(), vm.Config{Debug: true, Tracer: tracer, NoBaseFee: true})
 
+	// Define a meaningful timeout of a single transaction trace
+	if config.Timeout != nil {
+		if timeout, err = time.ParseDuration(*config.Timeout); err != nil {
+			return nil, err
+		}
+	}
+	deadlineCtx, cancel := context.WithTimeout(ctx, timeout)
+	go func() {
+		<-deadlineCtx.Done()
+		if errors.Is(deadlineCtx.Err(), context.DeadlineExceeded) {
+			tracer.Stop(errors.New("execution timeout"))
+			// Stop evm execution. Note cancellation is not necessarily immediate.
+			vmenv.Cancel()
+		}
+	}()
+	defer cancel()
+
 	// If gasPrice is 0, make sure that the account has sufficient balance to cover `l1DataFee`.
 	if message.GasPrice().Cmp(big.NewInt(0)) == 0 {
 		statedb.AddBalance(message.From(), l1DataFee)
 	}
-
 	// Call Prepare to clear out the statedb access list
 	statedb.SetTxContext(txctx.TxHash, txctx.TxIndex)
-
 	result, err := core.ApplyMessage(vmenv, message, new(core.GasPool).AddGas(message.Gas()), l1DataFee)
 	if err != nil {
 		return nil, fmt.Errorf("tracing failed: %w", err)
 	}
 
-	// Depending on the tracer type, format and return the output.
-	switch tracer := tracer.(type) {
-	case *vm.StructLogger:
-		// If the result contains a revert reason, return it.
-		returnVal := fmt.Sprintf("%x", result.Return())
-		if len(result.Revert()) > 0 {
-			returnVal = fmt.Sprintf("%x", result.Revert())
-		}
-		return &types.ExecutionResult{
-			Gas:         result.UsedGas,
-			Failed:      result.Failed(),
-			ReturnValue: returnVal,
-			StructLogs:  vm.FormatLogs(tracer.StructLogs()),
-			L1DataFee:   (*hexutil.Big)(result.L1DataFee),
-		}, nil
-
-	case Tracer:
-		return tracer.GetResult()
-
-	default:
-		panic(fmt.Sprintf("bad tracer type %T", tracer))
+	l, ok := tracer.(*vm.StructLogger)
+	if ok {
+		l.ResultL1DataFee = result.L1DataFee
 	}
+	return tracer.GetResult()
 }
 
 // APIs return the collection of RPC services the tracer package offers.

eth/tracers/internal/tracetest/calltrace_test.go

@@ -184,7 +184,7 @@ func testCallTracer(tracerName string, dirPath string, t *testing.T) {
 				}
 				_, statedb = tests.MakePreState(rawdb.NewMemoryDatabase(), test.Genesis.Alloc, false)
 			)
-			tracer, err := tracers.New(tracerName, new(tracers.Context))
+			tracer, err := tracers.New(tracerName, new(tracers.Context), nil)
 			if err != nil {
 				t.Fatalf("failed to create call tracer: %v", err)
 			}
@@ -302,7 +302,7 @@ func benchTracer(tracerName string, test *callTracerTest, b *testing.B) {
 	b.ReportAllocs()
 	b.ResetTimer()
 	for i := 0; i < b.N; i++ {
-		tracer, err := tracers.New(tracerName, new(tracers.Context))
+		tracer, err := tracers.New(tracerName, new(tracers.Context), nil)
 		if err != nil {
 			b.Fatalf("failed to create call tracer: %v", err)
 		}
@@ -372,7 +372,7 @@ func TestZeroValueToNotExitCall(t *testing.T) {
 	}
 	_, statedb := tests.MakePreState(rawdb.NewMemoryDatabase(), alloc, false)
 	// Create the tracer, the EVM environment and run it
-	tracer, err := tracers.New("callTracer", nil)
+	tracer, err := tracers.New("callTracer", nil, nil)
 	if err != nil {
 		t.Fatalf("failed to create call tracer: %v", err)
 	}