From bf4155846cf1adaf03e6395a93ce911f315acdbf Mon Sep 17 00:00:00 2001 From: Jeffrey Wilcke Date: Wed, 1 Mar 2017 10:19:15 +0100 Subject: [PATCH 1/2] 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) } } From f30733c806561a97900613517dade377bf57528c Mon Sep 17 00:00:00 2001 From: Jeffrey Wilcke Date: Wed, 1 Mar 2017 11:52:57 +0100 Subject: [PATCH 2/2] cmd/evm: removed -sysstat and moved content to -debug flag Added the ability to directly compile and run ethereum assembly using the evm utility: `evm run `. This is equivalant to `evm compile | evm run`. --- cmd/evm/main.go | 5 ----- cmd/evm/runner.go | 33 +++++++++++++++++++++------------ 2 files changed, 21 insertions(+), 17 deletions(-) diff --git a/cmd/evm/main.go b/cmd/evm/main.go index 5ce45b9ca6..2e7d985574 100644 --- a/cmd/evm/main.go +++ b/cmd/evm/main.go @@ -66,10 +66,6 @@ var ( Name: "input", Usage: "input for the EVM", } - SysStatFlag = cli.BoolFlag{ - Name: "sysstat", - Usage: "display system stats", - } VerbosityFlag = cli.IntFlag{ Name: "verbosity", Usage: "sets the verbosity level", @@ -89,7 +85,6 @@ func init() { CreateFlag, DebugFlag, VerbosityFlag, - SysStatFlag, CodeFlag, CodeFileFlag, GasFlag, diff --git a/cmd/evm/runner.go b/cmd/evm/runner.go index 8a71a92f7b..6ef9230f4f 100644 --- a/cmd/evm/runner.go +++ b/cmd/evm/runner.go @@ -25,6 +25,7 @@ import ( goruntime "runtime" + "github.com/ethereum/go-ethereum/cmd/evm/internal/compiler" "github.com/ethereum/go-ethereum/cmd/utils" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/core/state" @@ -61,7 +62,18 @@ func runCmd(ctx *cli.Context) error { ret []byte err error ) - if ctx.GlobalString(CodeFlag.Name) != "" { + if fn := ctx.Args().First(); len(fn) > 0 { + src, err := ioutil.ReadFile(fn) + if err != nil { + return err + } + + bin, err := compiler.Compile(fn, src, false) + if err != nil { + return err + } + code = common.Hex2Bytes(bin) + } else if ctx.GlobalString(CodeFlag.Name) != "" { code = common.Hex2Bytes(ctx.GlobalString(CodeFlag.Name)) } else { var hexcode []byte @@ -106,7 +118,7 @@ func runCmd(ctx *cli.Context) error { ret, err = runtime.Call(receiver, common.Hex2Bytes(ctx.GlobalString(InputFlag.Name)), &runtimeConfig) } - vmdone := time.Since(tstart) + execTime := time.Since(tstart) if ctx.GlobalBool(DumpFlag.Name) { statedb.Commit(true) @@ -118,19 +130,16 @@ func runCmd(ctx *cli.Context) error { 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 goruntime.ReadMemStats(&mem) - fmt.Printf("vm took %v\n", vmdone) - fmt.Printf(`alloc: %d -tot alloc: %d -no. malloc: %d -heap alloc: %d -heap objs: %d -num gc: %d -`, mem.Alloc, mem.TotalAlloc, mem.Mallocs, mem.HeapAlloc, mem.HeapObjects, mem.NumGC) + fmt.Fprintf(os.Stderr, `evm execution time: %v +heap objects: %d +allocations: %d +total allocations: %d +GC calls: %d + +`, execTime, mem.HeapObjects, mem.Alloc, mem.TotalAlloc, mem.NumGC) } fmt.Printf("0x%x", ret)