quorum/eth/api_tracer.go

728 lines
25 KiB
Go

// Copyright 2017 The go-ethereum Authors
// This file is part of the go-ethereum library.
//
// The go-ethereum library is free software: you can redistribute it and/or modify
// it under the terms of the GNU Lesser General Public License as published by
// the Free Software Foundation, either version 3 of the License, or
// (at your option) any later version.
//
// The go-ethereum library is distributed in the hope that it will be useful,
// but WITHOUT ANY WARRANTY; without even the implied warranty of
// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
// GNU Lesser General Public License for more details.
//
// You should have received a copy of the GNU Lesser General Public License
// along with the go-ethereum library. If not, see <http://www.gnu.org/licenses/>.
package eth
import (
"bytes"
"context"
"errors"
"fmt"
"io/ioutil"
"runtime"
"sync"
"sync/atomic"
"time"
"github.com/ethereum/go-ethereum/common"
"github.com/ethereum/go-ethereum/common/hexutil"
"github.com/ethereum/go-ethereum/core"
"github.com/ethereum/go-ethereum/core/state"
"github.com/ethereum/go-ethereum/core/types"
"github.com/ethereum/go-ethereum/core/vm"
"github.com/ethereum/go-ethereum/eth/tracers"
"github.com/ethereum/go-ethereum/ethdb"
"github.com/ethereum/go-ethereum/internal/ethapi"
"github.com/ethereum/go-ethereum/log"
"github.com/ethereum/go-ethereum/rlp"
"github.com/ethereum/go-ethereum/rpc"
"github.com/ethereum/go-ethereum/trie"
)
const (
// defaultTraceTimeout is the amount of time a single transaction can execute
// by default before being forcefully aborted.
defaultTraceTimeout = 5 * time.Second
// defaultTraceReexec is the number of blocks the tracer is willing to go back
// and reexecute to produce missing historical state necessary to run a specific
// trace.
defaultTraceReexec = uint64(128)
)
// TraceConfig holds extra parameters to trace functions.
type TraceConfig struct {
*vm.LogConfig
Tracer *string
Timeout *string
Reexec *uint64
}
// txTraceResult is the result of a single transaction trace.
type txTraceResult struct {
Result interface{} `json:"result,omitempty"` // Trace results produced by the tracer
Error string `json:"error,omitempty"` // Trace failure produced by the tracer
}
// blockTraceTask represents a single block trace task when an entire chain is
// being traced.
type blockTraceTask struct {
statedb *state.StateDB // Intermediate state prepped for tracing
block *types.Block // Block to trace the transactions from
results []*txTraceResult // Trace results procudes by the task
}
// blockTraceResult represets the results of tracing a single block when an entire
// chain is being traced.
type blockTraceResult struct {
Block hexutil.Uint64 `json:"block"` // Block number corresponding to this trace
Hash common.Hash `json:"hash"` // Block hash corresponding to this trace
Traces []*txTraceResult `json:"traces"` // Trace results produced by the task
}
// txTraceTask represents a single transaction trace task when an entire block
// is being traced.
type txTraceTask struct {
statedb *state.StateDB // Intermediate state prepped for tracing
index int // Transaction offset in the block
}
// ephemeralDatabase is a memory wrapper around a proper database, which acts as
// an ephemeral write layer. This construct is used by the chain tracer to write
// state tries for intermediate blocks without serializing to disk, but at the
// same time to allow disk fallback for reads that do no hit the memory layer.
type ephemeralDatabase struct {
diskdb ethdb.Database // Persistent disk database to fall back to with reads
memdb *ethdb.MemDatabase // Ephemeral memory database for primary reads and writes
}
func (db *ephemeralDatabase) Put(key []byte, value []byte) error { return db.memdb.Put(key, value) }
func (db *ephemeralDatabase) Delete(key []byte) error { return errors.New("delete not supported") }
func (db *ephemeralDatabase) Close() { db.memdb.Close() }
func (db *ephemeralDatabase) NewBatch() ethdb.Batch {
return db.memdb.NewBatch()
}
func (db *ephemeralDatabase) Has(key []byte) (bool, error) {
if has, _ := db.memdb.Has(key); has {
return has, nil
}
return db.diskdb.Has(key)
}
func (db *ephemeralDatabase) Get(key []byte) ([]byte, error) {
if blob, _ := db.memdb.Get(key); blob != nil {
return blob, nil
}
return db.diskdb.Get(key)
}
// Prune does a state sync into a new memory write layer and replaces the old one.
// This allows us to discard entries that are no longer referenced from the current
// state.
func (db *ephemeralDatabase) Prune(root common.Hash) {
// Pull the still relevant state data into memory
sync := state.NewStateSync(root, db.diskdb)
for sync.Pending() > 0 {
hash := sync.Missing(1)[0]
// Move the next trie node from the memory layer into a sync struct
node, err := db.memdb.Get(hash[:])
if err != nil {
panic(err) // memdb must have the data
}
if _, _, err := sync.Process([]trie.SyncResult{{Hash: hash, Data: node}}); err != nil {
panic(err) // it's not possible to fail processing a node
}
}
// Discard the old memory layer and write a new one
db.memdb, _ = ethdb.NewMemDatabaseWithCap(db.memdb.Len())
if _, err := sync.Commit(db); err != nil {
panic(err) // writing into a memdb cannot fail
}
}
// TraceChain returns the structured logs created during the execution of EVM
// between two blocks (excluding start) and returns them as a JSON object.
func (api *PrivateDebugAPI) TraceChain(ctx context.Context, start, end rpc.BlockNumber, config *TraceConfig) (*rpc.Subscription, error) {
// Fetch the block interval that we want to trace
var from, to *types.Block
switch start {
case rpc.PendingBlockNumber:
from = api.eth.miner.PendingBlock()
case rpc.LatestBlockNumber:
from = api.eth.blockchain.CurrentBlock()
default:
from = api.eth.blockchain.GetBlockByNumber(uint64(start))
}
switch end {
case rpc.PendingBlockNumber:
to = api.eth.miner.PendingBlock()
case rpc.LatestBlockNumber:
to = api.eth.blockchain.CurrentBlock()
default:
to = api.eth.blockchain.GetBlockByNumber(uint64(end))
}
// Trace the chain if we've found all our blocks
if from == nil {
return nil, fmt.Errorf("starting block #%d not found", start)
}
if to == nil {
return nil, fmt.Errorf("end block #%d not found", end)
}
return api.traceChain(ctx, from, to, config)
}
// traceChain configures a new tracer according to the provided configuration, and
// executes all the transactions contained within. The return value will be one item
// per transaction, dependent on the requestd tracer.
func (api *PrivateDebugAPI) traceChain(ctx context.Context, start, end *types.Block, config *TraceConfig) (*rpc.Subscription, error) {
// Tracing a chain is a **long** operation, only do with subscriptions
notifier, supported := rpc.NotifierFromContext(ctx)
if !supported {
return &rpc.Subscription{}, rpc.ErrNotificationsUnsupported
}
sub := notifier.CreateSubscription()
// Ensure we have a valid starting state before doing any work
origin := start.NumberU64()
memdb, _ := ethdb.NewMemDatabase()
db := &ephemeralDatabase{
diskdb: api.eth.ChainDb(),
memdb: memdb,
}
if number := start.NumberU64(); number > 0 {
start = api.eth.blockchain.GetBlock(start.ParentHash(), start.NumberU64()-1)
if start == nil {
return nil, fmt.Errorf("parent block #%d not found", number-1)
}
}
statedb, err := state.New(start.Root(), state.NewDatabase(db))
if err != nil {
// If the starting state is missing, allow some number of blocks to be reexecuted
reexec := defaultTraceReexec
if config != nil && config.Reexec != nil {
reexec = *config.Reexec
}
// Find the most recent block that has the state available
for i := uint64(0); i < reexec; i++ {
start = api.eth.blockchain.GetBlock(start.ParentHash(), start.NumberU64()-1)
if start == nil {
break
}
if statedb, err = state.New(start.Root(), state.NewDatabase(db)); err == nil {
break
}
}
// If we still don't have the state available, bail out
if err != nil {
switch err.(type) {
case *trie.MissingNodeError:
return nil, errors.New("required historical state unavailable")
default:
return nil, err
}
}
}
// Execute all the transaction contained within the chain concurrently for each block
blocks := int(end.NumberU64() - origin)
threads := runtime.NumCPU()
if threads > blocks {
threads = blocks
}
var (
pend = new(sync.WaitGroup)
tasks = make(chan *blockTraceTask, threads)
results = make(chan *blockTraceTask, threads)
)
for th := 0; th < threads; th++ {
pend.Add(1)
go func() {
defer pend.Done()
// Fetch and execute the next block trace tasks
for task := range tasks {
signer := types.MakeSigner(api.config, task.block.Number())
// Trace all the transactions contained within
for i, tx := range task.block.Transactions() {
msg, _ := tx.AsMessage(signer)
vmctx := core.NewEVMContext(msg, task.block.Header(), api.eth.blockchain, nil)
res, err := api.traceTx(ctx, msg, vmctx, task.statedb, config)
if err != nil {
task.results[i] = &txTraceResult{Error: err.Error()}
log.Warn("Tracing failed", "err", err)
break
}
task.statedb.DeleteSuicides()
task.results[i] = &txTraceResult{Result: res}
}
// Stream the result back to the user or abort on teardown
select {
case results <- task:
case <-notifier.Closed():
return
}
}
}()
}
// Start a goroutine to feed all the blocks into the tracers
begin := time.Now()
complete := start.NumberU64()
go func() {
var (
logged time.Time
number uint64
traced uint64
failed error
)
// Ensure everything is properly cleaned up on any exit path
defer func() {
close(tasks)
pend.Wait()
switch {
case failed != nil:
log.Warn("Chain tracing failed", "start", start.NumberU64(), "end", end.NumberU64(), "transactions", traced, "elapsed", time.Since(begin), "err", failed)
case number < end.NumberU64():
log.Warn("Chain tracing aborted", "start", start.NumberU64(), "end", end.NumberU64(), "abort", number, "transactions", traced, "elapsed", time.Since(begin))
default:
log.Info("Chain tracing finished", "start", start.NumberU64(), "end", end.NumberU64(), "transactions", traced, "elapsed", time.Since(begin))
}
close(results)
}()
// Feed all the blocks both into the tracer, as well as fast process concurrently
for number = start.NumberU64() + 1; number <= end.NumberU64(); number++ {
// Stop tracing if interruption was requested
select {
case <-notifier.Closed():
return
default:
}
// Print progress logs if long enough time elapsed
if time.Since(logged) > 8*time.Second {
if number > origin {
log.Info("Tracing chain segment", "start", origin, "end", end.NumberU64(), "current", number, "transactions", traced, "elapsed", time.Since(begin))
} else {
log.Info("Preparing state for chain trace", "block", number, "start", origin, "elapsed", time.Since(begin))
}
logged = time.Now()
}
// Retrieve the next block to trace
block := api.eth.blockchain.GetBlockByNumber(number)
if block == nil {
failed = fmt.Errorf("block #%d not found", number)
break
}
// Send the block over to the concurrent tracers (if not in the fast-forward phase)
if number > origin {
txs := block.Transactions()
select {
case tasks <- &blockTraceTask{statedb: statedb.Copy(), block: block, results: make([]*txTraceResult, len(txs))}:
case <-notifier.Closed():
return
}
traced += uint64(len(txs))
} else {
atomic.StoreUint64(&complete, number)
}
// Generate the next state snapshot fast without tracing
_, _, _, err := api.eth.blockchain.Processor().Process(block, statedb, vm.Config{})
if err != nil {
failed = err
break
}
// Finalize the state so any modifications are written to the trie
root, err := statedb.CommitTo(db, true)
if err != nil {
failed = err
break
}
if err := statedb.Reset(root); err != nil {
failed = err
break
}
// After every N blocks, prune the database to only retain relevant data
if (number-start.NumberU64())%4096 == 0 {
// Wait until currently pending trace jobs finish
for atomic.LoadUint64(&complete) != number {
select {
case <-time.After(100 * time.Millisecond):
case <-notifier.Closed():
return
}
}
// No more concurrent access at this point, prune the database
var (
nodes = db.memdb.Len()
start = time.Now()
)
db.Prune(root)
log.Info("Pruned tracer state entries", "deleted", nodes-db.memdb.Len(), "left", db.memdb.Len(), "elapsed", time.Since(start))
statedb, _ = state.New(root, state.NewDatabase(db))
}
}
}()
// Keep reading the trace results and stream the to the user
go func() {
var (
done = make(map[uint64]*blockTraceResult)
next = origin + 1
)
for res := range results {
// Queue up next received result
result := &blockTraceResult{
Block: hexutil.Uint64(res.block.NumberU64()),
Hash: res.block.Hash(),
Traces: res.results,
}
done[uint64(result.Block)] = result
// Stream completed traces to the user, aborting on the first error
for result, ok := done[next]; ok; result, ok = done[next] {
if len(result.Traces) > 0 || next == end.NumberU64() {
notifier.Notify(sub.ID, result)
}
atomic.StoreUint64(&complete, next)
delete(done, next)
next++
}
}
}()
return sub, nil
}
// TraceBlockByNumber returns the structured logs created during the execution of
// EVM and returns them as a JSON object.
func (api *PrivateDebugAPI) TraceBlockByNumber(ctx context.Context, number rpc.BlockNumber, config *TraceConfig) ([]*txTraceResult, error) {
// Fetch the block that we want to trace
var block *types.Block
switch number {
case rpc.PendingBlockNumber:
block = api.eth.miner.PendingBlock()
case rpc.LatestBlockNumber:
block = api.eth.blockchain.CurrentBlock()
default:
block = api.eth.blockchain.GetBlockByNumber(uint64(number))
}
// Trace the block if it was found
if block == nil {
return nil, fmt.Errorf("block #%d not found", number)
}
return api.traceBlock(ctx, block, config)
}
// TraceBlockByHash returns the structured logs created during the execution of
// EVM and returns them as a JSON object.
func (api *PrivateDebugAPI) TraceBlockByHash(ctx context.Context, hash common.Hash, config *TraceConfig) ([]*txTraceResult, error) {
block := api.eth.blockchain.GetBlockByHash(hash)
if block == nil {
return nil, fmt.Errorf("block #%x not found", hash)
}
return api.traceBlock(ctx, block, config)
}
// TraceBlock returns the structured logs created during the execution of EVM
// and returns them as a JSON object.
func (api *PrivateDebugAPI) TraceBlock(ctx context.Context, blob []byte, config *TraceConfig) ([]*txTraceResult, error) {
block := new(types.Block)
if err := rlp.Decode(bytes.NewReader(blob), block); err != nil {
return nil, fmt.Errorf("could not decode block: %v", err)
}
return api.traceBlock(ctx, block, config)
}
// TraceBlockFromFile returns the structured logs created during the execution of
// EVM and returns them as a JSON object.
func (api *PrivateDebugAPI) TraceBlockFromFile(ctx context.Context, file string, config *TraceConfig) ([]*txTraceResult, error) {
blob, err := ioutil.ReadFile(file)
if err != nil {
return nil, fmt.Errorf("could not read file: %v", err)
}
return api.TraceBlock(ctx, blob, config)
}
// traceBlock configures a new tracer according to the provided configuration, and
// executes all the transactions contained within. The return value will be one item
// per transaction, dependent on the requestd tracer.
func (api *PrivateDebugAPI) traceBlock(ctx context.Context, block *types.Block, config *TraceConfig) ([]*txTraceResult, error) {
// Create the parent state database
if err := api.eth.engine.VerifyHeader(api.eth.blockchain, block.Header(), true); err != nil {
return nil, err
}
parent := api.eth.blockchain.GetBlock(block.ParentHash(), block.NumberU64()-1)
if parent == nil {
return nil, fmt.Errorf("parent %x not found", block.ParentHash())
}
reexec := defaultTraceReexec
if config != nil && config.Reexec != nil {
reexec = *config.Reexec
}
statedb, err := api.computeStateDB(parent, reexec)
if err != nil {
return nil, err
}
// Execute all the transaction contained within the block concurrently
var (
signer = types.MakeSigner(api.config, block.Number())
txs = block.Transactions()
results = make([]*txTraceResult, len(txs))
pend = new(sync.WaitGroup)
jobs = make(chan *txTraceTask, len(txs))
)
threads := runtime.NumCPU()
if threads > len(txs) {
threads = len(txs)
}
for th := 0; th < threads; th++ {
pend.Add(1)
go func() {
defer pend.Done()
// Fetch and execute the next transaction trace tasks
for task := range jobs {
msg, _ := txs[task.index].AsMessage(signer)
vmctx := core.NewEVMContext(msg, block.Header(), api.eth.blockchain, nil)
res, err := api.traceTx(ctx, msg, vmctx, task.statedb, config)
if err != nil {
results[task.index] = &txTraceResult{Error: err.Error()}
continue
}
results[task.index] = &txTraceResult{Result: res}
}
}()
}
// Feed the transactions into the tracers and return
var failed error
for i, tx := range txs {
// Send the trace task over for execution
jobs <- &txTraceTask{statedb: statedb.Copy(), index: i}
// Generate the next state snapshot fast without tracing
msg, _ := tx.AsMessage(signer)
vmctx := core.NewEVMContext(msg, block.Header(), api.eth.blockchain, nil)
vmenv := vm.NewEVM(vmctx, statedb, api.config, vm.Config{})
if _, _, _, err := core.ApplyMessage(vmenv, msg, new(core.GasPool).AddGas(msg.Gas())); err != nil {
failed = err
break
}
// Finalize the state so any modifications are written to the trie
statedb.Finalise(true)
}
close(jobs)
pend.Wait()
// If execution failed in between, abort
if failed != nil {
return nil, failed
}
return results, nil
}
// computeStateDB retrieves the state database associated with a certain block.
// If no state is locally available for the given block, a number of blocks are
// attempted to be reexecuted to generate the desired state.
func (api *PrivateDebugAPI) computeStateDB(block *types.Block, reexec uint64) (*state.StateDB, error) {
// If we have the state fully available, use that
statedb, err := api.eth.blockchain.StateAt(block.Root())
if err == nil {
return statedb, nil
}
// Otherwise try to reexec blocks until we find a state or reach our limit
origin := block.NumberU64()
memdb, _ := ethdb.NewMemDatabase()
db := &ephemeralDatabase{
diskdb: api.eth.ChainDb(),
memdb: memdb,
}
for i := uint64(0); i < reexec; i++ {
block = api.eth.blockchain.GetBlock(block.ParentHash(), block.NumberU64()-1)
if block == nil {
break
}
if statedb, err = state.New(block.Root(), state.NewDatabase(db)); err == nil {
break
}
}
if err != nil {
switch err.(type) {
case *trie.MissingNodeError:
return nil, errors.New("required historical state unavailable")
default:
return nil, err
}
}
// State was available at historical point, regenerate
var (
start = time.Now()
logged time.Time
)
for block.NumberU64() < origin {
// Print progress logs if long enough time elapsed
if time.Since(logged) > 8*time.Second {
log.Info("Regenerating historical state", "block", block.NumberU64()+1, "target", origin, "elapsed", time.Since(start))
logged = time.Now()
}
// Retrieve the next block to regenerate and process it
if block = api.eth.blockchain.GetBlockByNumber(block.NumberU64() + 1); block == nil {
return nil, fmt.Errorf("block #%d not found", block.NumberU64()+1)
}
_, _, _, err := api.eth.blockchain.Processor().Process(block, statedb, vm.Config{})
if err != nil {
return nil, err
}
// Finalize the state so any modifications are written to the trie
root, err := statedb.CommitTo(db, true)
if err != nil {
return nil, err
}
if err := statedb.Reset(root); err != nil {
return nil, err
}
// After every N blocks, prune the database to only retain relevant data
if block.NumberU64()%4096 == 0 || block.NumberU64() == origin {
var (
nodes = db.memdb.Len()
begin = time.Now()
)
db.Prune(root)
log.Info("Pruned tracer state entries", "deleted", nodes-db.memdb.Len(), "left", db.memdb.Len(), "elapsed", time.Since(begin))
statedb, _ = state.New(root, state.NewDatabase(db))
}
}
log.Info("Historical state regenerated", "block", block.NumberU64(), "elapsed", time.Since(start))
return statedb, nil
}
// TraceTransaction returns the structured logs created during the execution of EVM
// and returns them as a JSON object.
func (api *PrivateDebugAPI) TraceTransaction(ctx context.Context, hash common.Hash, config *TraceConfig) (interface{}, error) {
// Retrieve the transaction and assemble its EVM context
tx, blockHash, _, index := core.GetTransaction(api.eth.ChainDb(), hash)
if tx == nil {
return nil, fmt.Errorf("transaction %x not found", hash)
}
reexec := defaultTraceReexec
if config != nil && config.Reexec != nil {
reexec = *config.Reexec
}
msg, vmctx, statedb, err := api.computeTxEnv(blockHash, int(index), reexec)
if err != nil {
return nil, err
}
// Trace the transaction and return
return api.traceTx(ctx, msg, vmctx, statedb, config)
}
// traceTx configures a new tracer according to the provided configuration, and
// executes the given message in the provided environment. The return value will
// be tracer dependent.
func (api *PrivateDebugAPI) traceTx(ctx context.Context, message core.Message, vmctx vm.Context, statedb *state.StateDB, config *TraceConfig) (interface{}, error) {
// Assemble the structured logger or the JavaScript tracer
var (
tracer vm.Tracer
err error
)
switch {
case config != nil && 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
}
}
// Constuct the JavaScript tracer to execute with
if tracer, err = tracers.New(*config.Tracer); err != nil {
return nil, err
}
// Handle timeouts and RPC cancellations
deadlineCtx, cancel := context.WithTimeout(ctx, timeout)
go func() {
<-deadlineCtx.Done()
tracer.(*tracers.Tracer).Stop(errors.New("execution timeout"))
}()
defer cancel()
case config == nil:
tracer = vm.NewStructLogger(nil)
default:
tracer = vm.NewStructLogger(config.LogConfig)
}
// Run the transaction with tracing enabled.
vmenv := vm.NewEVM(vmctx, statedb, api.config, vm.Config{Debug: true, Tracer: tracer})
ret, gas, failed, err := core.ApplyMessage(vmenv, message, new(core.GasPool).AddGas(message.Gas()))
if err != nil {
return nil, fmt.Errorf("tracing failed: %v", err)
}
// Depending on the tracer type, format and return the output
switch tracer := tracer.(type) {
case *vm.StructLogger:
return &ethapi.ExecutionResult{
Gas: gas,
Failed: failed,
ReturnValue: fmt.Sprintf("%x", ret),
StructLogs: ethapi.FormatLogs(tracer.StructLogs()),
}, nil
case *tracers.Tracer:
return tracer.GetResult()
default:
panic(fmt.Sprintf("bad tracer type %T", tracer))
}
}
// computeTxEnv returns the execution environment of a certain transaction.
func (api *PrivateDebugAPI) computeTxEnv(blockHash common.Hash, txIndex int, reexec uint64) (core.Message, vm.Context, *state.StateDB, error) {
// Create the parent state database
block := api.eth.blockchain.GetBlockByHash(blockHash)
if block == nil {
return nil, vm.Context{}, nil, fmt.Errorf("block %x not found", blockHash)
}
parent := api.eth.blockchain.GetBlock(block.ParentHash(), block.NumberU64()-1)
if parent == nil {
return nil, vm.Context{}, nil, fmt.Errorf("parent %x not found", block.ParentHash())
}
statedb, err := api.computeStateDB(parent, reexec)
if err != nil {
return nil, vm.Context{}, nil, err
}
// Recompute transactions up to the target index.
signer := types.MakeSigner(api.config, block.Number())
for idx, tx := range block.Transactions() {
// Assemble the transaction call message and return if the requested offset
msg, _ := tx.AsMessage(signer)
context := core.NewEVMContext(msg, block.Header(), api.eth.blockchain, nil)
if idx == txIndex {
return msg, context, statedb, nil
}
// Not yet the searched for transaction, execute on top of the current state
vmenv := vm.NewEVM(context, statedb, api.config, vm.Config{})
if _, _, _, err := core.ApplyMessage(vmenv, msg, new(core.GasPool).AddGas(tx.Gas())); err != nil {
return nil, vm.Context{}, nil, fmt.Errorf("tx %x failed: %v", tx.Hash(), err)
}
statedb.DeleteSuicides()
}
return nil, vm.Context{}, nil, fmt.Errorf("tx index %d out of range for block %x", txIndex, blockHash)
}