Skip to content

Commit

Permalink
eth/tracers: refactor traceTx to separate out struct logging (ethereu…
Browse files Browse the repository at this point in the history 
…m#24326)

* eth/tracers: refactor traceTx to separate out struct logging

review fix

Update eth/tracers/api.go

Co-authored-by: Martin Holst Swende <martin@swende.se>

Mv ExecutionResult type to logger package

review fix

impl GetResult for StructLogger

make formatLogs private

confused exit and end..

account for intrinsicGas in structlogger, fix TraceCall test

Add Stop method to logger

Simplify traceTx

Fix test

rm logger from blockchain test

account for refund in structLogger

* use tx hooks in struct logger

* minor

* avoid executionResult in struct logger

* revert blockchain test changes
  • Loading branch information
@s1na
s1na authored and jagdeep sidhu committed Apr 6, 2022
1 parent 937a2c5 commit 28f648e
Show file tree
Hide file tree
Showing 4 changed files with 164 additions and 136 deletions.
77 changes: 26 additions & 51 deletions eth/tracers/api.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -871,71 +871,46 @@ func (api *API) TraceCall(ctx context.Context, args ethapi.TransactionArgs, bloc
// executes the given message in the provided environment. The return value will
// be tracer dependent.
func (api *API) traceTx(ctx context.Context, message core.Message, txctx *Context, vmctx vm.BlockContext, statedb *state.StateDB, config *TraceConfig) (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 = logger.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 config == nil {
config = &TraceConfig{}
}
// Default tracer is the struct logger
tracer = logger.NewStructLogger(config.Config)
if config.Tracer != nil {
tracer, err = New(*config.Tracer, txctx)
if err != nil {
return nil, err
}
if t, err := New(*config.Tracer, txctx); err != nil {
}
// 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
} 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 = logger.NewStructLogger(config.Config)
}
deadlineCtx, cancel := context.WithTimeout(ctx, timeout)
go func() {
<-deadlineCtx.Done()
if errors.Is(deadlineCtx.Err(), context.DeadlineExceeded) {
tracer.Stop(errors.New("execution timeout"))
}
}()
defer cancel()

// Run the transaction with tracing enabled.
vmenv := vm.NewEVM(vmctx, txContext, statedb, api.backend.ChainConfig(), vm.Config{Debug: true, Tracer: tracer, NoBaseFee: true})

// Call Prepare to clear out the statedb access list
statedb.Prepare(txctx.TxHash, txctx.TxIndex)

result, err := core.ApplyMessage(vmenv, message, new(core.GasPool).AddGas(message.Gas()))
if err != nil {
if _, err = core.ApplyMessage(vmenv, message, new(core.GasPool).AddGas(message.Gas())); 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 *logger.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 &ethapi.ExecutionResult{
Gas: result.UsedGas,
Failed: result.Failed(),
ReturnValue: returnVal,
StructLogs: ethapi.FormatLogs(tracer.StructLogs()),
}, nil

case Tracer:
return tracer.GetResult()

default:
panic(fmt.Sprintf("bad tracer type %T", tracer))
}
return tracer.GetResult()
}

// APIs return the collection of RPC services the tracer package offers.
Expand Down
33 changes: 21 additions & 12 deletions eth/tracers/api_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,7 @@ import (
"github.com/ethereum/go-ethereum/core/types"
"github.com/ethereum/go-ethereum/core/vm"
"github.com/ethereum/go-ethereum/crypto"
"github.com/ethereum/go-ethereum/eth/tracers/logger"
"github.com/ethereum/go-ethereum/ethdb"
"github.com/ethereum/go-ethereum/internal/ethapi"
"github.com/ethereum/go-ethereum/params"
Expand Down Expand Up @@ -217,11 +218,11 @@ func TestTraceCall(t *testing.T) {
},
config: nil,
expectErr: nil,
expect: &ethapi.ExecutionResult{
expect: &logger.ExecutionResult{
Gas: params.TxGas,
Failed: false,
ReturnValue: "",
StructLogs: []ethapi.StructLogRes{},
StructLogs: []logger.StructLogRes{},
},
},
// Standard JSON trace upon the head, plain transfer.
Expand All @@ -234,11 +235,11 @@ func TestTraceCall(t *testing.T) {
},
config: nil,
expectErr: nil,
expect: &ethapi.ExecutionResult{
expect: &logger.ExecutionResult{
Gas: params.TxGas,
Failed: false,
ReturnValue: "",
StructLogs: []ethapi.StructLogRes{},
StructLogs: []logger.StructLogRes{},
},
},
// Standard JSON trace upon the non-existent block, error expects
Expand All @@ -263,11 +264,11 @@ func TestTraceCall(t *testing.T) {
},
config: nil,
expectErr: nil,
expect: &ethapi.ExecutionResult{
expect: &logger.ExecutionResult{
Gas: params.TxGas,
Failed: false,
ReturnValue: "",
StructLogs: []ethapi.StructLogRes{},
StructLogs: []logger.StructLogRes{},
},
},
// Standard JSON trace upon the pending block
Expand All @@ -280,11 +281,11 @@ func TestTraceCall(t *testing.T) {
},
config: nil,
expectErr: nil,
expect: &ethapi.ExecutionResult{
expect: &logger.ExecutionResult{
Gas: params.TxGas,
Failed: false,
ReturnValue: "",
StructLogs: []ethapi.StructLogRes{},
StructLogs: []logger.StructLogRes{},
},
},
}
Expand All @@ -303,8 +304,12 @@ func TestTraceCall(t *testing.T) {
t.Errorf("Expect no error, get %v", err)
continue
}
if !reflect.DeepEqual(result, testspec.expect) {
t.Errorf("Result mismatch, want %v, get %v", testspec.expect, result)
var have *logger.ExecutionResult
if err := json.Unmarshal(result.(json.RawMessage), &have); err != nil {
t.Errorf("failed to unmarshal result %v", err)
}
if !reflect.DeepEqual(have, testspec.expect) {
t.Errorf("Result mismatch, want %v, get %v", testspec.expect, have)
}
}
}
Expand Down Expand Up @@ -333,11 +338,15 @@ func TestTraceTransaction(t *testing.T) {
if err != nil {
t.Errorf("Failed to trace transaction %v", err)
}
if !reflect.DeepEqual(result, &ethapi.ExecutionResult{
var have *logger.ExecutionResult
if err := json.Unmarshal(result.(json.RawMessage), &have); err != nil {
t.Errorf("failed to unmarshal result %v", err)
}
if !reflect.DeepEqual(have, &logger.ExecutionResult{
Gas: params.TxGas,
Failed: false,
ReturnValue: "",
StructLogs: []ethapi.StructLogRes{},
StructLogs: []logger.StructLogRes{},
}) {
t.Error("Transaction tracing result is different")
}
Expand Down
127 changes: 117 additions & 10 deletions eth/tracers/logger/logger.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -18,10 +18,12 @@ package logger

import (
"encoding/hex"
"encoding/json"
"fmt"
"io"
"math/big"
"strings"
"sync/atomic"
"time"

"github.com/ethereum/go-ethereum/common"
Expand Down Expand Up @@ -108,10 +110,15 @@ type StructLogger struct {
cfg Config
env *vm.EVM

storage map[common.Address]Storage
logs []StructLog
output []byte
err error
storage map[common.Address]Storage
logs []StructLog
output []byte
err error
gasLimit uint64
usedGas uint64

interrupt uint32 // Atomic flag to signal execution interruption
reason error // Textual reason for the interruption
}

// NewStructLogger returns a new logger
Expand Down Expand Up @@ -142,13 +149,19 @@ func (l *StructLogger) CaptureStart(env *vm.EVM, from common.Address, to common.
//
// CaptureState also tracks SLOAD/SSTORE ops to track storage change.
func (l *StructLogger) CaptureState(pc uint64, op vm.OpCode, gas, cost uint64, scope *vm.ScopeContext, rData []byte, depth int, err error) {
memory := scope.Memory
stack := scope.Stack
contract := scope.Contract
// If tracing was interrupted, set the error and stop
if atomic.LoadUint32(&l.interrupt) > 0 {
l.env.Cancel()
return
}
// check if already accumulated the specified number of logs
if l.cfg.Limit != 0 && l.cfg.Limit <= len(l.logs) {
return
}

memory := scope.Memory
stack := scope.Stack
contract := scope.Contract
// Copy a snapshot of the current memory state to a new buffer
var mem []byte
if l.cfg.EnableMemory {
Expand Down Expand Up @@ -221,11 +234,42 @@ func (l *StructLogger) CaptureEnd(output []byte, gasUsed uint64, t time.Duration
func (l *StructLogger) CaptureEnter(typ vm.OpCode, from common.Address, to common.Address, input []byte, gas uint64, value *big.Int) {
}

func (l *StructLogger) CaptureExit(output []byte, gasUsed uint64, err error) {}
func (l *StructLogger) CaptureExit(output []byte, gasUsed uint64, err error) {
}

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 != vm.ErrExecutionReverted {
returnVal = ""
}
return json.Marshal(&ExecutionResult{
Gas: l.usedGas,
Failed: failed,
ReturnValue: returnVal,
StructLogs: formatLogs(l.StructLogs()),
})
}

func (*StructLogger) CaptureTxStart(gasLimit uint64) {}
// Stop terminates execution of the tracer at the first opportune moment.
func (l *StructLogger) Stop(err error) {
l.reason = err
atomic.StoreUint32(&l.interrupt, 1)
}

func (*StructLogger) CaptureTxEnd(restGas uint64) {}
func (l *StructLogger) CaptureTxStart(gasLimit uint64) {
l.gasLimit = gasLimit
}

func (l *StructLogger) CaptureTxEnd(restGas uint64) {
l.usedGas = l.gasLimit - restGas
}

// StructLogs returns the captured log entries.
func (l *StructLogger) StructLogs() []StructLog { return l.logs }
Expand Down Expand Up @@ -355,3 +399,66 @@ func (t *mdLogger) CaptureExit(output []byte, gasUsed uint64, err error) {}
func (*mdLogger) CaptureTxStart(gasLimit uint64) {}

func (*mdLogger) CaptureTxEnd(restGas uint64) {}

// ExecutionResult groups all structured logs emitted by the EVM
// while replaying a transaction in debug mode as well as transaction
// execution status, the amount of gas used and the return value
type ExecutionResult struct {
Gas uint64 `json:"gas"`
Failed bool `json:"failed"`
ReturnValue string `json:"returnValue"`
StructLogs []StructLogRes `json:"structLogs"`
}

// StructLogRes stores a structured log emitted by the EVM while replaying a
// transaction in debug mode
type StructLogRes struct {
Pc uint64 `json:"pc"`
Op string `json:"op"`
Gas uint64 `json:"gas"`
GasCost uint64 `json:"gasCost"`
Depth int `json:"depth"`
Error string `json:"error,omitempty"`
Stack *[]string `json:"stack,omitempty"`
Memory *[]string `json:"memory,omitempty"`
Storage *map[string]string `json:"storage,omitempty"`
RefundCounter uint64 `json:"refund,omitempty"`
}

// formatLogs formats EVM returned structured logs for json output
func formatLogs(logs []StructLog) []StructLogRes {
formatted := make([]StructLogRes, len(logs))
for index, trace := range logs {
formatted[index] = 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.Memory != nil {
memory := make([]string, 0, (len(trace.Memory)+31)/32)
for i := 0; i+32 <= len(trace.Memory); i += 32 {
memory = append(memory, fmt.Sprintf("%x", trace.Memory[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
}
Loading

0 comments on commit 28f648e

Please sign in to comment.