cmd/evm, eth/tracers: refactor structlogger + make it streamable

This commit is contained in:
Martin Holst Swende 2024-11-25 13:01:07 +01:00
parent 02159d553f
commit c2da651260
No known key found for this signature in database
GPG Key ID: 683B438C05A5DDF0
3 changed files with 93 additions and 82 deletions

View File

@ -18,6 +18,7 @@ package main
import ( import (
"bytes" "bytes"
"encoding/hex"
"encoding/json" "encoding/json"
"fmt" "fmt"
"io" "io"
@ -35,6 +36,7 @@ import (
"github.com/ethereum/go-ethereum/core/rawdb" "github.com/ethereum/go-ethereum/core/rawdb"
"github.com/ethereum/go-ethereum/core/state" "github.com/ethereum/go-ethereum/core/state"
"github.com/ethereum/go-ethereum/core/tracing" "github.com/ethereum/go-ethereum/core/tracing"
"github.com/ethereum/go-ethereum/core/types"
"github.com/ethereum/go-ethereum/core/vm" "github.com/ethereum/go-ethereum/core/vm"
"github.com/ethereum/go-ethereum/core/vm/runtime" "github.com/ethereum/go-ethereum/core/vm/runtime"
"github.com/ethereum/go-ethereum/eth/tracers/logger" "github.com/ethereum/go-ethereum/eth/tracers/logger"
@ -148,10 +150,10 @@ func runCmd(ctx *cli.Context) error {
if ctx.Bool(MachineFlag.Name) { if ctx.Bool(MachineFlag.Name) {
tracer = logger.NewJSONLogger(logconfig, os.Stdout) tracer = logger.NewJSONLogger(logconfig, os.Stdout)
} else if ctx.Bool(DebugFlag.Name) { } else if ctx.Bool(DebugFlag.Name) {
debugLogger = logger.NewStructLogger(logconfig) debugLogger = logger.NewStreamingStructLogger(logconfig, os.Stderr)
tracer = debugLogger.Hooks() tracer = debugLogger.Hooks()
} else { } else {
debugLogger = logger.NewStructLogger(logconfig) debugLogger = logger.NewStreamingStructLogger(logconfig, os.Stderr)
} }
initialGas := ctx.Uint64(GasFlag.Name) initialGas := ctx.Uint64(GasFlag.Name)
@ -305,12 +307,10 @@ func runCmd(ctx *cli.Context) error {
} }
if ctx.Bool(DebugFlag.Name) { if ctx.Bool(DebugFlag.Name) {
if debugLogger != nil { if logs := statedb.Logs(); len(logs) > 0 {
fmt.Fprintln(os.Stderr, "#### TRACE ####") fmt.Fprintln(os.Stderr, "### LOGS")
logger.WriteTrace(os.Stderr, debugLogger.StructLogs()) writeLogs(os.Stderr, statedb.Logs())
} }
fmt.Fprintln(os.Stderr, "#### LOGS ####")
logger.WriteLogs(os.Stderr, statedb.Logs())
} }
if bench || ctx.Bool(StatDumpFlag.Name) { if bench || ctx.Bool(StatDumpFlag.Name) {
@ -329,3 +329,16 @@ allocated bytes: %d
return nil return nil
} }
// writeLogs writes vm logs in a readable format to the given writer
func writeLogs(writer io.Writer, logs []*types.Log) {
for _, log := range logs {
fmt.Fprintf(writer, "LOG%d: %x bn=%d txi=%x\n", len(log.Topics), log.Address, log.BlockNumber, log.TxIndex)
for i, topic := range log.Topics {
fmt.Fprintf(writer, "%08d %x\n", i, topic)
}
fmt.Fprint(writer, hex.Dump(log.Data))
fmt.Fprintln(writer)
}
}

View File

@ -88,7 +88,7 @@ func stateTestCmd(ctx *cli.Context) error {
cfg.Tracer = logger.NewJSONLogger(config, os.Stderr) cfg.Tracer = logger.NewJSONLogger(config, os.Stderr)
case ctx.Bool(DebugFlag.Name): case ctx.Bool(DebugFlag.Name):
cfg.Tracer = logger.NewStructLogger(config).Hooks() cfg.Tracer = logger.NewStreamingStructLogger(config, os.Stderr).Hooks()
} }
// Load the test content from the input file // Load the test content from the input file
if len(ctx.Args().First()) != 0 { if len(ctx.Args().First()) != 0 {

View File

@ -21,7 +21,9 @@ import (
"encoding/json" "encoding/json"
"fmt" "fmt"
"io" "io"
"maps"
"math/big" "math/big"
"slices"
"strings" "strings"
"sync/atomic" "sync/atomic"
@ -38,15 +40,6 @@ import (
// Storage represents a contract's storage. // Storage represents a contract's storage.
type Storage map[common.Hash]common.Hash type Storage map[common.Hash]common.Hash
// Copy duplicates the current storage.
func (s Storage) Copy() Storage {
cpy := make(Storage, len(s))
for key, value := range s {
cpy[key] = value
}
return cpy
}
// Config are the configuration options for structured logger the EVM // Config are the configuration options for structured logger the EVM
type Config struct { type Config struct {
EnableMemory bool // enable memory capture EnableMemory bool // enable memory capture
@ -102,11 +95,43 @@ func (s *StructLog) ErrorString() string {
return "" return ""
} }
func (log *StructLog) WriteTo(writer io.Writer) {
fmt.Fprintf(writer, "%-16spc=%08d gas=%v cost=%v", log.Op, log.Pc, log.Gas, log.GasCost)
if log.Err != nil {
fmt.Fprintf(writer, " ERROR: %v", log.Err)
}
fmt.Fprintln(writer)
if len(log.Stack) > 0 {
fmt.Fprintln(writer, "Stack:")
for i := len(log.Stack) - 1; i >= 0; i-- {
fmt.Fprintf(writer, "%08d %s\n", len(log.Stack)-i-1, log.Stack[i].Hex())
}
}
if len(log.Memory) > 0 {
fmt.Fprintln(writer, "Memory:")
fmt.Fprint(writer, hex.Dump(log.Memory))
}
if len(log.Storage) > 0 {
fmt.Fprintln(writer, "Storage:")
for h, item := range log.Storage {
fmt.Fprintf(writer, "%x: %x\n", h, item)
}
}
if len(log.ReturnData) > 0 {
fmt.Fprintln(writer, "ReturnData:")
fmt.Fprint(writer, hex.Dump(log.ReturnData))
}
fmt.Fprintln(writer)
}
// StructLogger is an EVM state logger and implements EVMLogger. // StructLogger is an EVM state logger and implements EVMLogger.
// //
// StructLogger can capture state based on the given Log configuration and also keeps // StructLogger can capture state based on the given Log configuration and also keeps
// a track record of modified storage which is used in reporting snapshots of the // a track record of modified storage which is used in reporting snapshots of the
// contract their storage. // contract their storage.
//
// A StructLogger can either yield it's output immediately (streaming) or store for
// later output.
type StructLogger struct { type StructLogger struct {
cfg Config cfg Config
env *tracing.VMContext env *tracing.VMContext
@ -117,11 +142,20 @@ type StructLogger struct {
err error err error
usedGas uint64 usedGas uint64
writer io.Writer // If set, the logger will stream instead of store logs
interrupt atomic.Bool // Atomic flag to signal execution interruption interrupt atomic.Bool // Atomic flag to signal execution interruption
reason error // Textual reason for the interruption reason error // Textual reason for the interruption
} }
// NewStructLogger returns a new logger // NewStructLogger returns a new logger
func NewStreamingStructLogger(cfg *Config, writer io.Writer) *StructLogger {
l := NewStructLogger(cfg)
l.writer = writer
return l
}
// NewStructLogger construct a new (non-streaming) struct logger.
func NewStructLogger(cfg *Config) *StructLogger { func NewStructLogger(cfg *Config) *StructLogger {
logger := &StructLogger{ logger := &StructLogger{
storage: make(map[common.Address]Storage), storage: make(map[common.Address]Storage),
@ -153,7 +187,7 @@ func (l *StructLogger) Reset() {
// //
// OnOpcode also tracks SLOAD/SSTORE ops to track storage change. // OnOpcode also tracks SLOAD/SSTORE ops to track storage change.
func (l *StructLogger) OnOpcode(pc uint64, opcode byte, gas, cost uint64, scope tracing.OpContext, rData []byte, depth int, err error) { func (l *StructLogger) OnOpcode(pc uint64, opcode byte, gas, cost uint64, scope tracing.OpContext, rData []byte, depth int, err error) {
// If tracing was interrupted, set the error and stop // If tracing was interrupted, exit
if l.interrupt.Load() { if l.interrupt.Load() {
return return
} }
@ -161,24 +195,24 @@ func (l *StructLogger) OnOpcode(pc uint64, opcode byte, gas, cost uint64, scope
if l.cfg.Limit != 0 && l.cfg.Limit <= len(l.logs) { if l.cfg.Limit != 0 && l.cfg.Limit <= len(l.logs) {
return return
} }
var (
op := vm.OpCode(opcode) op = vm.OpCode(opcode)
memory := scope.MemoryData() memory = scope.MemoryData()
stack := scope.StackData() contractAddr = scope.Address()
// Copy a snapshot of the current memory state to a new buffer stack = scope.StackData()
var mem []byte stackLen = len(stack)
)
log := StructLog{pc, op, gas, cost, nil, len(memory), nil, nil, nil, depth, l.env.StateDB.GetRefund(), err}
if l.cfg.EnableMemory { if l.cfg.EnableMemory {
mem = make([]byte, len(memory)) log.Memory = memory
copy(mem, memory)
} }
// Copy a snapshot of the current stack state to a new buffer
var stck []uint256.Int
if !l.cfg.DisableStack { if !l.cfg.DisableStack {
stck = make([]uint256.Int, len(stack)) log.Stack = scope.StackData()
copy(stck, stack)
} }
contractAddr := scope.Address() if l.cfg.EnableReturnData {
stackLen := len(stack) log.ReturnData = rData
}
// Copy a snapshot of the current storage to a new container // Copy a snapshot of the current storage to a new container
var storage Storage var storage Storage
if !l.cfg.DisableStorage && (op == vm.SLOAD || op == vm.SSTORE) { if !l.cfg.DisableStorage && (op == vm.SLOAD || op == vm.SSTORE) {
@ -194,7 +228,7 @@ func (l *StructLogger) OnOpcode(pc uint64, opcode byte, gas, cost uint64, scope
value = l.env.StateDB.GetState(contractAddr, address) value = l.env.StateDB.GetState(contractAddr, address)
) )
l.storage[contractAddr][address] = value l.storage[contractAddr][address] = value
storage = l.storage[contractAddr].Copy() storage = maps.Clone(l.storage[contractAddr])
} else if op == vm.SSTORE && stackLen >= 2 { } else if op == vm.SSTORE && stackLen >= 2 {
// capture SSTORE opcodes and record the written entry in the local storage. // capture SSTORE opcodes and record the written entry in the local storage.
var ( var (
@ -202,17 +236,20 @@ func (l *StructLogger) OnOpcode(pc uint64, opcode byte, gas, cost uint64, scope
address = common.Hash(stack[stackLen-1].Bytes32()) address = common.Hash(stack[stackLen-1].Bytes32())
) )
l.storage[contractAddr][address] = value l.storage[contractAddr][address] = value
storage = l.storage[contractAddr].Copy() storage = maps.Clone(l.storage[contractAddr])
} }
} }
var rdata []byte log.Storage = storage
if l.cfg.EnableReturnData { // create a log
rdata = make([]byte, len(rData)) if l.writer == nil {
copy(rdata, rData) // Non-streaming, need to copy slices.
} log.Memory = slices.Clone(log.Memory)
// create a new snapshot of the EVM. log.Stack = slices.Clone(log.Stack)
log := StructLog{pc, op, gas, cost, mem, len(memory), stck, rdata, storage, depth, l.env.StateDB.GetRefund(), err} log.ReturnData = slices.Clone(rData)
l.logs = append(l.logs, log) l.logs = append(l.logs, log)
return
}
log.WriteTo(l.writer)
} }
// OnExit is called a call frame finishes processing. // OnExit is called a call frame finishes processing.
@ -283,49 +320,10 @@ func (l *StructLogger) Error() error { return l.err }
func (l *StructLogger) Output() []byte { return l.output } func (l *StructLogger) Output() []byte { return l.output }
// WriteTrace writes a formatted trace to the given writer // WriteTrace writes a formatted trace to the given writer
// @deprecated
func WriteTrace(writer io.Writer, logs []StructLog) { func WriteTrace(writer io.Writer, logs []StructLog) {
for _, log := range logs { for _, log := range logs {
fmt.Fprintf(writer, "%-16spc=%08d gas=%v cost=%v", log.Op, log.Pc, log.Gas, log.GasCost) log.WriteTo(writer)
if log.Err != nil {
fmt.Fprintf(writer, " ERROR: %v", log.Err)
}
fmt.Fprintln(writer)
if len(log.Stack) > 0 {
fmt.Fprintln(writer, "Stack:")
for i := len(log.Stack) - 1; i >= 0; i-- {
fmt.Fprintf(writer, "%08d %s\n", len(log.Stack)-i-1, log.Stack[i].Hex())
}
}
if len(log.Memory) > 0 {
fmt.Fprintln(writer, "Memory:")
fmt.Fprint(writer, hex.Dump(log.Memory))
}
if len(log.Storage) > 0 {
fmt.Fprintln(writer, "Storage:")
for h, item := range log.Storage {
fmt.Fprintf(writer, "%x: %x\n", h, item)
}
}
if len(log.ReturnData) > 0 {
fmt.Fprintln(writer, "ReturnData:")
fmt.Fprint(writer, hex.Dump(log.ReturnData))
}
fmt.Fprintln(writer)
}
}
// WriteLogs writes vm logs in a readable format to the given writer
func WriteLogs(writer io.Writer, logs []*types.Log) {
for _, log := range logs {
fmt.Fprintf(writer, "LOG%d: %x bn=%d txi=%x\n", len(log.Topics), log.Address, log.BlockNumber, log.TxIndex)
for i, topic := range log.Topics {
fmt.Fprintf(writer, "%08d %x\n", i, topic)
}
fmt.Fprint(writer, hex.Dump(log.Data))
fmt.Fprintln(writer)
} }
} }