diff --git a/cmd/evm/internal/t8ntool/file_tracer.go b/cmd/evm/internal/t8ntool/file_tracer.go index 9e5132b279..931be51e84 100644 --- a/cmd/evm/internal/t8ntool/file_tracer.go +++ b/cmd/evm/internal/t8ntool/file_tracer.go @@ -17,73 +17,107 @@ package t8ntool import ( - "github.com/ethereum/go-ethereum/common" - "github.com/ethereum/go-ethereum/core/tracing" - "github.com/ethereum/go-ethereum/core/types" - "github.com/ethereum/go-ethereum/eth/tracers" - "github.com/ethereum/go-ethereum/eth/tracers/logger" - "github.com/ethereum/go-ethereum/log" - "github.com/ethereum/go-ethereum/params" - "encoding/json" "fmt" "io" "math/big" "os" "path/filepath" + + "github.com/ethereum/go-ethereum/common" + "github.com/ethereum/go-ethereum/core/tracing" + "github.com/ethereum/go-ethereum/core/types" + "github.com/ethereum/go-ethereum/eth/tracers" + "github.com/ethereum/go-ethereum/log" ) // fileWritingTracer wraps either a tracer or a logger. On tx start, // it instantiates a tracer/logger, creates a new file to direct output to, // and on tx end it closes the file. type fileWritingTracer struct { - txIndex int - inner *tracing.Hooks - destination io.WriteCloser - baseDir string - - // for json-tracing - logConfig *logger.Config + txIndex int // transaction counter + inner *tracing.Hooks // inner hooks + destination io.WriteCloser // the currently open file (if any) + baseDir string // baseDir to write output-files to + suffix string // suffix is the suffix to use when creating files // for custom tracing - tracerName string - tracerConf json.RawMessage - chainConfig *params.ChainConfig - getResult func() (json.RawMessage, error) + getResult func() (json.RawMessage, error) } -// jsonToFile creates hooks which uses an underlying jsonlogger, and writes the -// jsonl-delimited output to a file, one per tx. -func jsonToFile(baseDir string, logConfig *logger.Config, callFrames bool) *tracing.Hooks { +func (l *fileWritingTracer) Write(p []byte) (n int, err error) { + if l.destination != nil { + return l.destination.Write(p) + } + log.Warn("Tracer wrote to non-existing output") + // It is tempting to return an error here, however, the json encoder + // will no retry writing to an io.Writer once it has returned an error once. + // Therefore, we must squash the error. + return n, nil +} + +// newFileWriter creates a set of hooks which wraps inner hooks (typically a logger), +// and writes the output to a file, one file per transaction. +func newFileWriter(baseDir string, innerFn func(out io.Writer) *tracing.Hooks) *tracing.Hooks { + t := &fileWritingTracer{ + baseDir: baseDir, + suffix: "jsonl", + } + t.inner = innerFn(t) // instantiate the inner tracer + return t.hooks() +} + +// newResultWriter creates a set of hooks wraps and invokes an underlying tracer, +// and writes the result (getResult-output) to file, one per transaction. +func newResultWriter(baseDir string, tracer *tracers.Tracer) *tracing.Hooks { t := &fileWritingTracer{ baseDir: baseDir, - logConfig: logConfig, - } - hooks := t.hooks() - if !callFrames { - hooks.OnEnter = nil - } - return hooks -} - -// tracerToFile creates hooks which uses an underlying tracer, and writes the -// json-result to file, one per tx. -func tracerToFile(baseDir, tracerName string, traceConfig json.RawMessage, chainConfig *params.ChainConfig) *tracing.Hooks { - t := &fileWritingTracer{ - baseDir: baseDir, - tracerName: tracerName, - chainConfig: chainConfig, + getResult: tracer.GetResult, + inner: tracer.Hooks, + suffix: "json", } return t.hooks() } +// OnTxStart creates a new output-file specific for this transaction, and invokes +// the inner OnTxStart handler. +func (l *fileWritingTracer) OnTxStart(env *tracing.VMContext, tx *types.Transaction, from common.Address) { + // Open a new file, + fname := filepath.Join(l.baseDir, fmt.Sprintf("trace-%d-%v.%v", l.txIndex, tx.Hash().String(), l.suffix)) + traceFile, err := os.Create(fname) + if err != nil { + log.Warn("Failed creating trace-file", "err", err) + } + log.Info("Created tracing-file", "path", fname) + l.destination = traceFile + + if l.inner.OnTxStart != nil { + l.inner.OnTxStart(env, tx, from) + } +} + +// OnTxEnd writes result (if getResult exist), closes any currently open output-file, +// and invokes the inner OnTxEnd handler. +func (l *fileWritingTracer) OnTxEnd(receipt *types.Receipt, err error) { + if l.inner.OnTxEnd != nil { + l.inner.OnTxEnd(receipt, err) + } + if l.getResult != nil && l.destination != nil { + if result, err := l.getResult(); result != nil { + json.NewEncoder(l.destination).Encode(result) + } else { + log.Warn("Error obtaining tracer result", "err", err) + } + l.destination.Close() + l.destination = nil + } + l.txIndex++ +} + func (l *fileWritingTracer) hooks() *tracing.Hooks { - hooks := &tracing.Hooks{ - OnTxStart: l.OnTxStartJSONL, + return &tracing.Hooks{ + OnTxStart: l.OnTxStart, OnTxEnd: l.OnTxEnd, - // intentional no-op: we instantiate the l.inner on tx start, which has - // not yet happened at this point - //OnSystemCallStart: func() {}, OnEnter: func(depth int, typ byte, from common.Address, to common.Address, input []byte, gas uint64, value *big.Int) { if l.inner != nil && l.inner.OnEnter != nil { l.inner.OnEnter(depth, typ, from, to, input, gas, value) @@ -104,66 +138,15 @@ func (l *fileWritingTracer) hooks() *tracing.Hooks { l.inner.OnFault(pc, op, gas, cost, scope, depth, err) } }, - } - if len(l.tracerName) > 0 { // a custom tracer - hooks.OnTxStart = l.OnTxStartJSON - } - return hooks -} - -// OnTxStartJSONL is the OnTxStart-handler for jsonl logger. -func (l *fileWritingTracer) OnTxStartJSONL(env *tracing.VMContext, tx *types.Transaction, from common.Address) { - // Open a new file, - fname := filepath.Join(l.baseDir, fmt.Sprintf("trace-%d-%v.jsonl", l.txIndex, tx.Hash().String())) - traceFile, err := os.Create(fname) - if err != nil { - log.Warn("Failed creating trace-file", "err", err) - } - log.Debug("Created tracing-file", "path", fname) - l.destination = traceFile - l.inner = logger.NewJSONLoggerWithCallFrames(l.logConfig, traceFile) - if l.inner.OnTxStart != nil { - l.inner.OnTxStart(env, tx, from) + OnSystemCallStart: func() { + if l.inner != nil && l.inner.OnSystemCallStart != nil { + l.inner.OnSystemCallStart() + } + }, + OnSystemCallEnd: func() { + if l.inner != nil && l.inner.OnSystemCallEnd != nil { + l.inner.OnSystemCallEnd() + } + }, } } - -// OnTxStartJSONL is the OnTxStart-handler for custom tracer. -func (l *fileWritingTracer) OnTxStartJSON(env *tracing.VMContext, tx *types.Transaction, from common.Address) { - // Open a new file, - fname := filepath.Join(l.baseDir, fmt.Sprintf("trace-%d-%v.json", l.txIndex, tx.Hash().String())) - traceFile, err := os.Create(fname) - if err != nil { - log.Warn("Failed creating trace-file", "err", err) - } - fmt.Printf("Created tracing-file %v\n", fname) - log.Info("Created tracing-file", "path", fname) - l.destination = traceFile - inner, err := tracers.DefaultDirectory.New(l.tracerName, nil, l.tracerConf, l.chainConfig) - if err != nil { - log.Warn("Failed instantiating tracer", "err", err) - return - } - l.getResult = inner.GetResult - l.inner = inner.Hooks - if l.inner.OnTxStart != nil { - l.inner.OnTxStart(env, tx, from) - } -} - -func (l *fileWritingTracer) OnTxEnd(receipt *types.Receipt, err error) { - if l.inner.OnTxEnd != nil { - l.inner.OnTxEnd(receipt, err) - } - if l.getResult != nil { - if result, err := l.getResult(); result != nil { - json.NewEncoder(l.destination).Encode(result) - } else { - log.Warn("Error obtaining tracer result", "err", err) - } - } - if l.destination != nil { // Close old file - l.destination.Close() - l.destination = nil - } - l.txIndex++ -} diff --git a/cmd/evm/internal/t8ntool/transition.go b/cmd/evm/internal/t8ntool/transition.go index aed81e040a..e946ccddd5 100644 --- a/cmd/evm/internal/t8ntool/transition.go +++ b/cmd/evm/internal/t8ntool/transition.go @@ -20,6 +20,7 @@ import ( "encoding/json" "errors" "fmt" + "io" "math/big" "os" "path/filepath" @@ -28,8 +29,10 @@ import ( "github.com/ethereum/go-ethereum/common/hexutil" "github.com/ethereum/go-ethereum/consensus/misc/eip1559" "github.com/ethereum/go-ethereum/core/state" + "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/eth/tracers" "github.com/ethereum/go-ethereum/eth/tracers/logger" "github.com/ethereum/go-ethereum/log" "github.com/ethereum/go-ethereum/params" @@ -151,14 +154,27 @@ func Transition(ctx *cli.Context) error { // Configure tracer if ctx.IsSet(TraceTracerFlag.Name) { // Custom tracing config := json.RawMessage(ctx.String(TraceTracerConfigFlag.Name)) - vmConfig.Tracer = tracerToFile(baseDir, ctx.String(TraceTracerFlag.Name), config, chainConfig) + tracer, err := tracers.DefaultDirectory.New(ctx.String(TraceTracerFlag.Name), + nil, config, chainConfig) + if err != nil { + return NewError(ErrorConfig, fmt.Errorf("failed instantiating tracer: %v", err)) + } + vmConfig.Tracer = newResultWriter(baseDir, tracer) } else if ctx.Bool(TraceFlag.Name) { // JSON opcode tracing logConfig := &logger.Config{ DisableStack: ctx.Bool(TraceDisableStackFlag.Name), EnableMemory: ctx.Bool(TraceEnableMemoryFlag.Name), EnableReturnData: ctx.Bool(TraceEnableReturnDataFlag.Name), } - vmConfig.Tracer = jsonToFile(baseDir, logConfig, ctx.Bool(TraceEnableCallFramesFlag.Name)) + if ctx.Bool(TraceEnableCallFramesFlag.Name) { + vmConfig.Tracer = newFileWriter(baseDir, func(out io.Writer) *tracing.Hooks { + return logger.NewJSONLoggerWithCallFrames(logConfig, out) + }) + } else { + vmConfig.Tracer = newFileWriter(baseDir, func(out io.Writer) *tracing.Hooks { + return logger.NewJSONLogger(logConfig, out) + }) + } } // Run the test and aggregate the result s, result, body, err := prestate.Apply(vmConfig, chainConfig, txIt, ctx.Int64(RewardFlag.Name)) diff --git a/cmd/evm/t8n_test.go b/cmd/evm/t8n_test.go index 85caf010b3..87aa516931 100644 --- a/cmd/evm/t8n_test.go +++ b/cmd/evm/t8n_test.go @@ -341,6 +341,103 @@ func lineIterator(path string) func() (string, error) { } } +// TestT8nTracing is a test that checks the tracing-output from t8n. +func TestT8nTracing(t *testing.T) { + t.Parallel() + tt := new(testT8n) + tt.TestCmd = cmdtest.NewTestCmd(t, tt) + for i, tc := range []struct { + base string + input t8nInput + expExitCode int + extraArgs []string + expectedTraces []string + }{ + { + base: "./testdata/31", + input: t8nInput{ + "alloc.json", "txs.json", "env.json", "Cancun", "", + }, + extraArgs: []string{"--trace"}, + expectedTraces: []string{"trace-0-0x88f5fbd1524731a81e49f637aa847543268a5aaf2a6b32a69d2c6d978c45dcfb.jsonl", + "trace-1-0x03a7b0a91e61a170d64ea94b8263641ef5a8bbdb10ac69f466083a6789c77fb8.jsonl", + "trace-2-0xd96e0ce6418ee3360e11d3c7b6886f5a9a08f7ef183da72c23bb3b2374530128.jsonl"}, + }, + { + base: "./testdata/31", + input: t8nInput{ + "alloc.json", "txs.json", "env.json", "Cancun", "", + }, + extraArgs: []string{"--trace.tracer", ` +{ count: 0, + result: function(){ + this.count = this.count + 1; + return "hello world " + this.count + }, + fault: function(){} +}`}, + expectedTraces: []string{"trace-0-0x88f5fbd1524731a81e49f637aa847543268a5aaf2a6b32a69d2c6d978c45dcfb.json", + "trace-1-0x03a7b0a91e61a170d64ea94b8263641ef5a8bbdb10ac69f466083a6789c77fb8.json", + "trace-2-0xd96e0ce6418ee3360e11d3c7b6886f5a9a08f7ef183da72c23bb3b2374530128.json"}, + }, + { + base: "./testdata/32", + input: t8nInput{ + "alloc.json", "txs.json", "env.json", "Paris", "", + }, + extraArgs: []string{"--trace", "--trace.callframes"}, + expectedTraces: []string{"trace-0-0x47806361c0fa084be3caa18afe8c48156747c01dbdfc1ee11b5aecdbe4fcf23e.jsonl"}, + }, + } { + args := []string{"t8n"} + args = append(args, tc.input.get(tc.base)...) + // Place the output somewhere we can find it + outdir := t.TempDir() + args = append(args, "--output.basedir", outdir) + args = append(args, tc.extraArgs...) + + var qArgs []string // quoted args for debugging purposes + for _, arg := range args { + if len(arg) == 0 { + qArgs = append(qArgs, `""`) + } else { + qArgs = append(qArgs, arg) + } + } + tt.Logf("args: %v\n", strings.Join(qArgs, " ")) + tt.Run("evm-test", args...) + t.Log(string(tt.Output())) + + // Compare the expected traces + for _, traceFile := range tc.expectedTraces { + haveFn := lineIterator(filepath.Join(outdir, traceFile)) + wantFn := lineIterator(filepath.Join(tc.base, traceFile)) + + for line := 0; ; line++ { + want, wErr := wantFn() + have, hErr := haveFn() + if want != have { + t.Fatalf("test %d, trace %v, line %d\nwant: %v\nhave: %v\n", + i, traceFile, line, want, have) + } + if wErr != nil && hErr != nil { + break + } + if wErr != nil { + t.Fatal(wErr) + } + if hErr != nil { + t.Fatal(hErr) + } + t.Logf("%v\n", want) + } + } + if have, want := tt.ExitStatus(), tc.expExitCode; have != want { + t.Fatalf("test %d: wrong exit code, have %d, want %d", i, have, want) + } + } +} + type t9nInput struct { inTxs string stFork string diff --git a/cmd/evm/testdata/31/README.md b/cmd/evm/testdata/31/README.md index 305e4f52da..b337c1eb62 100644 --- a/cmd/evm/testdata/31/README.md +++ b/cmd/evm/testdata/31/README.md @@ -1 +1,11 @@ This test does some EVM execution, and can be used to test the tracers and trace-outputs. +This test should yield three output-traces, in separate files + +For example: +``` +[user@work evm]$ go run . t8n --input.alloc ./testdata/31/alloc.json --input.txs ./testdata/31/txs.json --input.env ./testdata/31/env.json --state.fork Cancun --output.basedir /tmp --trace +INFO [12-06|09:53:32.123] Created tracing-file path=/tmp/trace-0-0x88f5fbd1524731a81e49f637aa847543268a5aaf2a6b32a69d2c6d978c45dcfb.jsonl +INFO [12-06|09:53:32.124] Created tracing-file path=/tmp/trace-1-0x03a7b0a91e61a170d64ea94b8263641ef5a8bbdb10ac69f466083a6789c77fb8.jsonl +INFO [12-06|09:53:32.125] Created tracing-file path=/tmp/trace-2-0xd96e0ce6418ee3360e11d3c7b6886f5a9a08f7ef183da72c23bb3b2374530128.jsonl +``` + diff --git a/cmd/evm/testdata/31/trace-0-0x88f5fbd1524731a81e49f637aa847543268a5aaf2a6b32a69d2c6d978c45dcfb.json b/cmd/evm/testdata/31/trace-0-0x88f5fbd1524731a81e49f637aa847543268a5aaf2a6b32a69d2c6d978c45dcfb.json index cd4bc1ab64..dfa1d7c7cb 100644 --- a/cmd/evm/testdata/31/trace-0-0x88f5fbd1524731a81e49f637aa847543268a5aaf2a6b32a69d2c6d978c45dcfb.json +++ b/cmd/evm/testdata/31/trace-0-0x88f5fbd1524731a81e49f637aa847543268a5aaf2a6b32a69d2c6d978c45dcfb.json @@ -1 +1 @@ -"hello world" +"hello world 1" diff --git a/cmd/evm/testdata/31/trace-1-0x03a7b0a91e61a170d64ea94b8263641ef5a8bbdb10ac69f466083a6789c77fb8.json b/cmd/evm/testdata/31/trace-1-0x03a7b0a91e61a170d64ea94b8263641ef5a8bbdb10ac69f466083a6789c77fb8.json new file mode 100644 index 0000000000..25980291c7 --- /dev/null +++ b/cmd/evm/testdata/31/trace-1-0x03a7b0a91e61a170d64ea94b8263641ef5a8bbdb10ac69f466083a6789c77fb8.json @@ -0,0 +1 @@ +"hello world 2" diff --git a/cmd/evm/testdata/31/trace-1-0x03a7b0a91e61a170d64ea94b8263641ef5a8bbdb10ac69f466083a6789c77fb8.jsonl b/cmd/evm/testdata/31/trace-1-0x03a7b0a91e61a170d64ea94b8263641ef5a8bbdb10ac69f466083a6789c77fb8.jsonl new file mode 100644 index 0000000000..26e5c7ee4e --- /dev/null +++ b/cmd/evm/testdata/31/trace-1-0x03a7b0a91e61a170d64ea94b8263641ef5a8bbdb10ac69f466083a6789c77fb8.jsonl @@ -0,0 +1,6 @@ +{"pc":0,"op":96,"gas":"0x13498","gasCost":"0x3","memSize":0,"stack":[],"depth":1,"refund":0,"opName":"PUSH1"} +{"pc":2,"op":96,"gas":"0x13495","gasCost":"0x3","memSize":0,"stack":["0x40"],"depth":1,"refund":0,"opName":"PUSH1"} +{"pc":4,"op":96,"gas":"0x13492","gasCost":"0x3","memSize":0,"stack":["0x40","0x40"],"depth":1,"refund":0,"opName":"PUSH1"} +{"pc":6,"op":96,"gas":"0x1348f","gasCost":"0x3","memSize":0,"stack":["0x40","0x40","0x40"],"depth":1,"refund":0,"opName":"PUSH1"} +{"pc":8,"op":0,"gas":"0x1348c","gasCost":"0x0","memSize":0,"stack":["0x40","0x40","0x40","0x40"],"depth":1,"refund":0,"opName":"STOP"} +{"output":"","gasUsed":"0xc"} diff --git a/cmd/evm/testdata/31/trace-2-0xd96e0ce6418ee3360e11d3c7b6886f5a9a08f7ef183da72c23bb3b2374530128.json b/cmd/evm/testdata/31/trace-2-0xd96e0ce6418ee3360e11d3c7b6886f5a9a08f7ef183da72c23bb3b2374530128.json new file mode 100644 index 0000000000..242587bd83 --- /dev/null +++ b/cmd/evm/testdata/31/trace-2-0xd96e0ce6418ee3360e11d3c7b6886f5a9a08f7ef183da72c23bb3b2374530128.json @@ -0,0 +1 @@ +"hello world 3" diff --git a/cmd/evm/testdata/31/trace-2-0xd96e0ce6418ee3360e11d3c7b6886f5a9a08f7ef183da72c23bb3b2374530128.jsonl b/cmd/evm/testdata/31/trace-2-0xd96e0ce6418ee3360e11d3c7b6886f5a9a08f7ef183da72c23bb3b2374530128.jsonl new file mode 100644 index 0000000000..26e5c7ee4e --- /dev/null +++ b/cmd/evm/testdata/31/trace-2-0xd96e0ce6418ee3360e11d3c7b6886f5a9a08f7ef183da72c23bb3b2374530128.jsonl @@ -0,0 +1,6 @@ +{"pc":0,"op":96,"gas":"0x13498","gasCost":"0x3","memSize":0,"stack":[],"depth":1,"refund":0,"opName":"PUSH1"} +{"pc":2,"op":96,"gas":"0x13495","gasCost":"0x3","memSize":0,"stack":["0x40"],"depth":1,"refund":0,"opName":"PUSH1"} +{"pc":4,"op":96,"gas":"0x13492","gasCost":"0x3","memSize":0,"stack":["0x40","0x40"],"depth":1,"refund":0,"opName":"PUSH1"} +{"pc":6,"op":96,"gas":"0x1348f","gasCost":"0x3","memSize":0,"stack":["0x40","0x40","0x40"],"depth":1,"refund":0,"opName":"PUSH1"} +{"pc":8,"op":0,"gas":"0x1348c","gasCost":"0x0","memSize":0,"stack":["0x40","0x40","0x40","0x40"],"depth":1,"refund":0,"opName":"STOP"} +{"output":"","gasUsed":"0xc"} diff --git a/cmd/evm/testdata/31/txs.json b/cmd/evm/testdata/31/txs.json index 473c1526f4..da8f5761f6 100644 --- a/cmd/evm/testdata/31/txs.json +++ b/cmd/evm/testdata/31/txs.json @@ -10,5 +10,29 @@ "r" : "0x0", "s" : "0x0", "secretKey" : "0x45a915e4d060149eb4365960e6a7a45f334393093061116b197e3240065ff2d8" + }, + { + "gas": "0x186a0", + "gasPrice": "0x600", + "input": "0x", + "nonce": "0x1", + "to": "0x1111111111111111111111111111111111111111", + "value": "0x1", + "v" : "0x0", + "r" : "0x0", + "s" : "0x0", + "secretKey" : "0x45a915e4d060149eb4365960e6a7a45f334393093061116b197e3240065ff2d8" + }, + { + "gas": "0x186a0", + "gasPrice": "0x600", + "input": "0x", + "nonce": "0x2", + "to": "0x1111111111111111111111111111111111111111", + "value": "0x1", + "v" : "0x0", + "r" : "0x0", + "s" : "0x0", + "secretKey" : "0x45a915e4d060149eb4365960e6a7a45f334393093061116b197e3240065ff2d8" } ] diff --git a/eth/tracers/logger/logger_json.go b/eth/tracers/logger/logger_json.go index 622daf9cd6..52ac3945d4 100644 --- a/eth/tracers/logger/logger_json.go +++ b/eth/tracers/logger/logger_json.go @@ -69,11 +69,11 @@ func NewJSONLogger(cfg *Config, writer io.Writer) *tracing.Hooks { l.cfg = &Config{} } l.hooks = &tracing.Hooks{ - OnTxStart: l.OnTxStart, - //OnSystemCallStart: l.onSystemCallStart, - OnExit: l.OnExit, - OnOpcode: l.OnOpcode, - OnFault: l.OnFault, + OnTxStart: l.OnTxStart, + OnSystemCallStart: l.onSystemCallStart, + OnExit: l.OnExit, + OnOpcode: l.OnOpcode, + OnFault: l.OnFault, } return l.hooks } @@ -86,12 +86,12 @@ func NewJSONLoggerWithCallFrames(cfg *Config, writer io.Writer) *tracing.Hooks { l.cfg = &Config{} } l.hooks = &tracing.Hooks{ - OnTxStart: l.OnTxStart, - //OnSystemCallStart: l.onSystemCallStart, - OnEnter: l.OnEnter, - OnExit: l.OnExit, - OnOpcode: l.OnOpcode, - OnFault: l.OnFault, + OnTxStart: l.OnTxStart, + OnSystemCallStart: l.onSystemCallStart, + OnEnter: l.OnEnter, + OnExit: l.OnExit, + OnOpcode: l.OnOpcode, + OnFault: l.OnFault, } return l.hooks }