From bf4155846cf1adaf03e6395a93ce911f315acdbf Mon Sep 17 00:00:00 2001 From: Jeffrey Wilcke Date: Wed, 1 Mar 2017 10:19:15 +0100 Subject: [PATCH] core/evm, core/vm: improved evm trace output * Improved the standard evm tracer output and renamed it to WriteTrace which now takes an io.Writer to write the logs to. * Added WriteLogs which writes logs to the given writer in a readable format. * evm utility now also prints logs generated during the execution. --- cmd/evm/runner.go | 51 ++++++++++++++++++++++------------------------- core/vm/logger.go | 40 +++++++++++++++++++++++-------------- 2 files changed, 49 insertions(+), 42 deletions(-) diff --git a/cmd/evm/runner.go b/cmd/evm/runner.go index 0bed46894b..8a71a92f7b 100644 --- a/cmd/evm/runner.go +++ b/cmd/evm/runner.go @@ -53,7 +53,6 @@ func runCmd(ctx *cli.Context) error { statedb, _ = state.New(common.Hash{}, db) sender = common.StringToAddress("sender") logger = vm.NewStructLogger(nil) - tstart = time.Now() ) statedb.CreateAccount(sender) @@ -84,36 +83,28 @@ func runCmd(ctx *cli.Context) error { code = common.Hex2Bytes(string(bytes.TrimRight(hexcode, "\n"))) } + runtimeConfig := runtime.Config{ + Origin: sender, + State: statedb, + GasLimit: ctx.GlobalUint64(GasFlag.Name), + GasPrice: utils.GlobalBig(ctx, PriceFlag.Name), + Value: utils.GlobalBig(ctx, ValueFlag.Name), + EVMConfig: vm.Config{ + Tracer: logger, + Debug: ctx.GlobalBool(DebugFlag.Name), + DisableGasMetering: ctx.GlobalBool(DisableGasMeteringFlag.Name), + }, + } + + tstart := time.Now() if ctx.GlobalBool(CreateFlag.Name) { input := append(code, common.Hex2Bytes(ctx.GlobalString(InputFlag.Name))...) - ret, _, err = runtime.Create(input, &runtime.Config{ - Origin: sender, - State: statedb, - GasLimit: ctx.GlobalUint64(GasFlag.Name), - GasPrice: utils.GlobalBig(ctx, PriceFlag.Name), - Value: utils.GlobalBig(ctx, ValueFlag.Name), - EVMConfig: vm.Config{ - Tracer: logger, - Debug: ctx.GlobalBool(DebugFlag.Name), - DisableGasMetering: ctx.GlobalBool(DisableGasMeteringFlag.Name), - }, - }) + ret, _, err = runtime.Create(input, &runtimeConfig) } else { receiver := common.StringToAddress("receiver") statedb.SetCode(receiver, code) - ret, err = runtime.Call(receiver, common.Hex2Bytes(ctx.GlobalString(InputFlag.Name)), &runtime.Config{ - Origin: sender, - State: statedb, - GasLimit: ctx.GlobalUint64(GasFlag.Name), - GasPrice: utils.GlobalBig(ctx, PriceFlag.Name), - Value: utils.GlobalBig(ctx, ValueFlag.Name), - EVMConfig: vm.Config{ - Tracer: logger, - Debug: ctx.GlobalBool(DebugFlag.Name), - DisableGasMetering: ctx.GlobalBool(DisableGasMeteringFlag.Name), - }, - }) + ret, err = runtime.Call(receiver, common.Hex2Bytes(ctx.GlobalString(InputFlag.Name)), &runtimeConfig) } vmdone := time.Since(tstart) @@ -121,7 +112,13 @@ func runCmd(ctx *cli.Context) error { statedb.Commit(true) fmt.Println(string(statedb.Dump())) } - vm.StdErrFormat(logger.StructLogs()) + + if ctx.GlobalBool(DebugFlag.Name) { + fmt.Fprintln(os.Stderr, "#### TRACE ####") + vm.WriteTrace(os.Stderr, logger.StructLogs()) + fmt.Fprintln(os.Stderr, "#### LOGS ####") + vm.WriteLogs(os.Stderr, statedb.Logs()) + } if ctx.GlobalBool(SysStatFlag.Name) { var mem goruntime.MemStats @@ -136,7 +133,7 @@ num gc: %d `, mem.Alloc, mem.TotalAlloc, mem.Mallocs, mem.HeapAlloc, mem.HeapObjects, mem.NumGC) } - fmt.Printf("OUT: 0x%x", ret) + fmt.Printf("0x%x", ret) if err != nil { fmt.Printf(" error: %v", err) } diff --git a/core/vm/logger.go b/core/vm/logger.go index ccdf21a4bf..3d7e1c95fe 100644 --- a/core/vm/logger.go +++ b/core/vm/logger.go @@ -19,11 +19,12 @@ package vm import ( "encoding/hex" "fmt" + "io" "math/big" - "os" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/common/math" + "github.com/ethereum/go-ethereum/core/types" ) type Storage map[common.Hash]common.Hash @@ -168,29 +169,38 @@ func (l *StructLogger) StructLogs() []StructLog { return l.logs } -// StdErrFormat formats a slice of StructLogs to human readable format -func StdErrFormat(logs []StructLog) { - fmt.Fprintf(os.Stderr, "VM STAT %d OPs\n", len(logs)) +// WriteTrace writes a formatted trace to the given writer +func WriteTrace(writer io.Writer, logs []StructLog) { for _, log := range logs { - fmt.Fprintf(os.Stderr, "PC %08d: %s GAS: %v COST: %v", log.Pc, log.Op, log.Gas, log.GasCost) + fmt.Fprintf(writer, "%-10spc=%08d gas=%v cost=%v", log.Op, log.Pc, log.Gas, log.GasCost) if log.Err != nil { - fmt.Fprintf(os.Stderr, " ERROR: %v", log.Err) + fmt.Fprintf(writer, " ERROR: %v", log.Err) } - fmt.Fprintf(os.Stderr, "\n") - - fmt.Fprintln(os.Stderr, "STACK =", len(log.Stack)) + fmt.Fprintf(writer, "\n") for i := len(log.Stack) - 1; i >= 0; i-- { - fmt.Fprintf(os.Stderr, "%04d: %x\n", len(log.Stack)-i-1, math.PaddedBigBytes(log.Stack[i], 32)) + fmt.Fprintf(writer, "%08d %x\n", len(log.Stack)-i-1, math.PaddedBigBytes(log.Stack[i], 32)) } - fmt.Fprintln(os.Stderr, "MEM =", len(log.Memory)) - fmt.Fprintln(os.Stderr, hex.Dump(log.Memory)) + fmt.Fprint(writer, hex.Dump(log.Memory)) - fmt.Fprintln(os.Stderr, "STORAGE =", len(log.Storage)) for h, item := range log.Storage { - fmt.Fprintf(os.Stderr, "%x: %x\n", h, item) + fmt.Fprintf(writer, "%x: %x\n", h, item) + } + 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.Fprintln(os.Stderr) + + fmt.Fprint(writer, hex.Dump(log.Data)) + fmt.Fprintln(writer) } }