diff --git a/core/vm/interpreter.go b/core/vm/interpreter.go
index 01914913238..cf64e6a3e90 100644
--- a/core/vm/interpreter.go
+++ b/core/vm/interpreter.go
@@ -17,7 +17,9 @@
package vm
import (
+ "fmt"
"hash"
+ "io"
"sync/atomic"
"github.com/ledgerwatch/erigon/common"
@@ -26,17 +28,70 @@ import (
"github.com/ledgerwatch/log/v3"
)
+type InstrumenterLog struct {
+ Pc uint64 `json:"pc"`
+ Op OpCode `json:"op"`
+ TimeNs int64 `json:"timeNs"`
+ TimerTimeNs int64 `json:"timerTimeNs"`
+}
+
+type InstrumenterLogger struct {
+ Logs []InstrumenterLog
+ StartTime int64
+
+ // worker fields, just to avoid reallocation of local vars
+ OpCodeDuration int64
+ TimerDuration int64
+ TotalExecutionDuration int64
+ Log InstrumenterLog
+}
+
+// NewInstrumenterLogger returns a new logger
+func NewInstrumenterLogger() *InstrumenterLogger {
+ logger := &InstrumenterLogger{}
+ return logger
+}
+
+// WriteTrace writes a formatted trace to the given writer
+func WriteInstrumentation(writer io.Writer, logs []InstrumenterLog) {
+ for _, log := range logs {
+ fmt.Fprintf(writer, "%-16spc=%08d time_ns=%v timer_time_ns=%v", log.Op, log.Pc, log.TimeNs, log.TimerTimeNs)
+ fmt.Fprintln(writer)
+ }
+}
+
+func WriteCSVInstrumentationTotal(writer io.Writer, instrumenter *InstrumenterLogger, runId int) {
+ fmt.Fprintf(writer, "%v,%v,%v", runId, instrumenter.TotalExecutionDuration, instrumenter.TimerDuration)
+ fmt.Fprintln(writer)
+}
+
+func WriteCSVInstrumentationAll(writer io.Writer, logs []InstrumenterLog, runId int) {
+ // CSV header must be in sync with these fields here :(, but it's in measurements.py
+ for instructionId, log := range logs {
+ fmt.Fprintf(writer, "%v,%v,%v,%v", runId, instructionId, log.TimeNs, log.TimerTimeNs)
+ fmt.Fprintln(writer)
+ }
+}
+
+func (instrumenter *InstrumenterLogger) tick() {
+ instrumenter.TotalExecutionDuration = runtimeNano()
+ instrumenter.TimerDuration = runtimeNano()
+ instrumenter.TimerDuration -= instrumenter.TotalExecutionDuration
+ instrumenter.TotalExecutionDuration -= instrumenter.StartTime
+}
+
// Config are the configuration options for the Interpreter
type Config struct {
Debug bool // Enables debugging
Tracer Tracer // Opcode logger
- NoRecursion bool // Disables call, callcode, delegate call and create
- NoBaseFee bool // Forces the EIP-1559 baseFee to 0 (needed for 0 price calls)
- SkipAnalysis bool // Whether we can skip jumpdest analysis based on the checked history
- TraceJumpDest bool // Print transaction hashes where jumpdest analysis was useful
- NoReceipts bool // Do not calculate receipts
- ReadOnly bool // Do no perform any block finalisation
- EnableTEMV bool // true if execution with TEVM enable flag
+ Instrumenter *InstrumenterLogger
+ NoRecursion bool // Disables call, callcode, delegate call and create
+ NoBaseFee bool // Forces the EIP-1559 baseFee to 0 (needed for 0 price calls)
+ SkipAnalysis bool // Whether we can skip jumpdest analysis based on the checked history
+ TraceJumpDest bool // Print transaction hashes where jumpdest analysis was useful
+ NoReceipts bool // Do not calculate receipts
+ ReadOnly bool // Do no perform any block finalisation
+ EnableTEMV bool // true if execution with TEVM enable flag
ExtraEips []int // Additional EIPS that are to be enabled
}
@@ -232,6 +287,10 @@ func (in *EVMInterpreter) Run(contract *Contract, input []byte, readOnly bool) (
}
}()
}
+
+ // start timer
+ in.cfg.Instrumenter.StartTime = runtimeNano()
+
// The Interpreter main run loop (contextual). This loop runs until either an
// explicit STOP, RETURN or SELFDESTRUCT is executed, an error occurred during
// the execution of one of the operations or until the done flag is set by the
@@ -324,15 +383,39 @@ func (in *EVMInterpreter) Run(contract *Contract, input []byte, readOnly bool) (
switch {
case err != nil:
+ // BEGIN COPY PASTE BLOCK
+ in.cfg.Instrumenter.TotalExecutionDuration = runtimeNano()
+ in.cfg.Instrumenter.TimerDuration = runtimeNano()
+ in.cfg.Instrumenter.TimerDuration -= in.cfg.Instrumenter.TotalExecutionDuration
+ in.cfg.Instrumenter.TotalExecutionDuration -= in.cfg.Instrumenter.StartTime
+ // END COPY PASTE BLOCK
return nil, err
case operation.reverts:
+ // BEGIN COPY PASTE BLOCK
+ in.cfg.Instrumenter.TotalExecutionDuration = runtimeNano()
+ in.cfg.Instrumenter.TimerDuration = runtimeNano()
+ in.cfg.Instrumenter.TimerDuration -= in.cfg.Instrumenter.TotalExecutionDuration
+ in.cfg.Instrumenter.TotalExecutionDuration -= in.cfg.Instrumenter.StartTime
+ // END COPY PASTE BLOCK
return res, ErrExecutionReverted
case operation.halts:
+ // BEGIN COPY PASTE BLOCK
+ in.cfg.Instrumenter.TotalExecutionDuration = runtimeNano()
+ in.cfg.Instrumenter.TimerDuration = runtimeNano()
+ in.cfg.Instrumenter.TimerDuration -= in.cfg.Instrumenter.TotalExecutionDuration
+ in.cfg.Instrumenter.TotalExecutionDuration -= in.cfg.Instrumenter.StartTime
+ // END COPY PASTE BLOCK
return res, nil
case !operation.jumps:
pc++
}
}
+ // BEGIN COPY PASTE BLOCK
+ in.cfg.Instrumenter.TotalExecutionDuration = runtimeNano()
+ in.cfg.Instrumenter.TimerDuration = runtimeNano()
+ in.cfg.Instrumenter.TimerDuration -= in.cfg.Instrumenter.TotalExecutionDuration
+ in.cfg.Instrumenter.TotalExecutionDuration -= in.cfg.Instrumenter.StartTime
+ // END COPY PASTE BLOCK
return nil, nil
}
diff --git a/core/vm/runtime/env.go b/core/vm/runtime/env.go
index bf514f74e03..31c6488b70a 100644
--- a/core/vm/runtime/env.go
+++ b/core/vm/runtime/env.go
@@ -17,9 +17,9 @@
package runtime
import (
+ "github.com/ledgerwatch/erigon/common"
"github.com/ledgerwatch/erigon/core"
"github.com/ledgerwatch/erigon/core/vm"
- "github.com/ledgerwatch/erigon/ethdb"
)
func NewEnv(cfg *Config) *vm.EVM {
@@ -29,10 +29,11 @@ func NewEnv(cfg *Config) *vm.EVM {
}
blockContext := vm.BlockContext{
- CanTransfer: core.CanTransfer,
- Transfer: core.Transfer,
- GetHash: cfg.GetHashFn,
- ContractHasTEVM: ethdb.GetHasTEVM(cfg.kv),
+ CanTransfer: core.CanTransfer,
+ Transfer: core.Transfer,
+ GetHash: cfg.GetHashFn,
+ //imapp_benchmark: disable TEVM for all storages
+ ContractHasTEVM: func(common.Hash) (bool, error) { return false, nil },
Coinbase: cfg.Coinbase,
BlockNumber: cfg.BlockNumber.Uint64(),
Time: cfg.Time.Uint64(),
diff --git a/core/vm/time.go b/core/vm/time.go
new file mode 100644
index 00000000000..a5c8bfa3620
--- /dev/null
+++ b/core/vm/time.go
@@ -0,0 +1,9 @@
+package vm
+
+// this portion ensures that we have access to the least-overhead timer
+
+import _ "unsafe"
+
+// runtimeNano returns the current value of the runtime clock in nanoseconds.
+//go:linkname runtimeNano runtime.nanotime
+func runtimeNano() int64
diff --git a/tests/imapp_measure/imapp_measurement.go b/tests/imapp_measure/imapp_measurement.go
new file mode 100644
index 00000000000..92c27c52bea
--- /dev/null
+++ b/tests/imapp_measure/imapp_measurement.go
@@ -0,0 +1,161 @@
+package main
+
+import (
+ "context"
+ "flag"
+ "fmt"
+ "math"
+ "math/big"
+ "os"
+ go_runtime "runtime"
+ "strings"
+ "time"
+
+ _ "unsafe"
+
+ "github.com/holiman/uint256"
+ "github.com/ledgerwatch/erigon-lib/kv/memdb"
+ "github.com/ledgerwatch/erigon/common"
+ "github.com/ledgerwatch/erigon/core/state"
+ "github.com/ledgerwatch/erigon/core/vm"
+ "github.com/ledgerwatch/erigon/core/vm/runtime"
+ "github.com/ledgerwatch/erigon/crypto"
+ "github.com/ledgerwatch/erigon/params"
+)
+
+var calldata []byte
+
+func main() {
+
+ bytecodePtr := flag.String("bytecode", "", "EVM bytecode to execute and measure")
+ sampleSizePtr := flag.Int("sampleSize", 10, "Size of the sample - number of measured repetitions of execution")
+ printEachPtr := flag.Bool("printEach", true, "If false, printing of each execution time is skipped")
+ printCSVPtr := flag.Bool("printCSV", false, "If true, will print a CSV with standard results to STDOUT")
+ modePtr := flag.String("mode", "total", "Measurement mode. Available options: all, total, trace")
+
+ flag.Parse()
+
+ bytecode := common.Hex2Bytes(*bytecodePtr)
+ sampleSize := *sampleSizePtr
+ printEach := *printEachPtr
+ printCSV := *printCSVPtr
+ mode := *modePtr
+
+ if mode != "total" {
+ fmt.Fprintln(os.Stderr, "Invalid measurement mode: ", mode)
+ os.Exit(1)
+ }
+
+ fmt.Fprintln(os.Stderr, "Config: ", *bytecodePtr)
+ cfg := new(runtime.Config)
+ setDefaults(cfg)
+
+ fmt.Fprintln(os.Stderr, "db")
+ db := memdb.New()
+ tx, err := db.BeginRw(context.Background())
+ if err != nil {
+ fmt.Println(err)
+ return
+ }
+ cfg.State = state.New(state.NewDbStateReader(tx))
+
+ // Initialize some constant calldata of 128KB, 2^17 bytes.
+ // This means, if we offset between 0th and 2^16th byte, we can fetch between 0 and 2^16 bytes (64KB)
+ // In consequence, we need args to memory-copying OPCODEs to be between 0 and 2^16, 2^16 fits in a PUSH3,
+ // which we'll be using to generate arguments for those OPCODEs.
+ calldata = []byte(strings.Repeat("{", 1<<17))
+
+ cfg.EVMConfig.Debug = false
+ cfg.EVMConfig.Instrumenter = vm.NewInstrumenterLogger()
+ fmt.Fprintln(os.Stderr, "warmup")
+ retWarmUp, _, errWarmUp := runtime.Execute(bytecode, calldata, cfg, 0)
+ // End warm-up
+
+ fmt.Fprintln(os.Stderr, "loop count: ", sampleSize)
+
+ sampleStart := time.Now()
+ for i := 0; i < sampleSize; i++ {
+ if mode == "total" {
+ MeasureTotal(cfg, bytecode, printEach, printCSV, i)
+ }
+ }
+
+ fmt.Fprintln(os.Stderr, "Done")
+
+ sampleDuration := time.Since(sampleStart)
+
+ if errWarmUp != nil {
+ fmt.Fprintln(os.Stderr, errWarmUp)
+ }
+ fmt.Fprintln(os.Stderr, "Program: ", *bytecodePtr)
+ fmt.Fprintln(os.Stderr, "Return:", retWarmUp)
+ fmt.Fprintln(os.Stderr, "Sample duration:", sampleDuration)
+}
+
+func MeasureTotal(cfg *runtime.Config, bytecode []byte, printEach bool, printCSV bool, sampleId int) {
+ cfg.EVMConfig.Instrumenter = vm.NewInstrumenterLogger()
+ go_runtime.GC()
+
+ _, _, err := runtime.Execute(bytecode, calldata, cfg, 0)
+
+ if err != nil {
+ fmt.Fprintln(os.Stderr, err)
+ }
+
+ if printCSV {
+ vm.WriteCSVInstrumentationTotal(os.Stdout, cfg.EVMConfig.Instrumenter, sampleId)
+ }
+}
+
+// copied directly from github.com/ledgerwatch/erigon/core/vm/runtime/runtime.go
+// so that we skip this in measured code
+func setDefaults(cfg *runtime.Config) {
+ if cfg.ChainConfig == nil {
+ cfg.ChainConfig = ¶ms.ChainConfig{
+ ChainID: big.NewInt(1),
+ HomesteadBlock: new(big.Int),
+ DAOForkBlock: new(big.Int),
+ DAOForkSupport: false,
+ TangerineWhistleBlock: new(big.Int),
+ TangerineWhistleHash: common.Hash{},
+ SpuriousDragonBlock: new(big.Int),
+ ByzantiumBlock: new(big.Int),
+ ConstantinopleBlock: new(big.Int),
+ PetersburgBlock: new(big.Int),
+ IstanbulBlock: new(big.Int),
+ MuirGlacierBlock: new(big.Int),
+ BerlinBlock: new(big.Int),
+ LondonBlock: new(big.Int),
+ ArrowGlacierBlock: new(big.Int),
+ }
+ }
+
+ if cfg.Difficulty == nil {
+ cfg.Difficulty = new(big.Int)
+ }
+ if cfg.Time == nil {
+ cfg.Time = big.NewInt(time.Now().Unix())
+ }
+ if cfg.GasLimit == 0 {
+ cfg.GasLimit = math.MaxUint64
+ }
+ if cfg.GasPrice == nil {
+ cfg.GasPrice = new(big.Int)
+ }
+ if cfg.Value == nil {
+ cfg.Value = new(uint256.Int)
+ }
+ if cfg.BlockNumber == nil {
+ cfg.BlockNumber = new(big.Int)
+ }
+ if cfg.GetHashFn == nil {
+ cfg.GetHashFn = func(n uint64) common.Hash {
+ return common.BytesToHash(crypto.Keccak256([]byte(new(big.Int).SetUint64(n).String())))
+ }
+ }
+
+}
+
+// runtimeNano returns the current value of the runtime clock in nanoseconds.
+//go:linkname runtimeNano runtime.nanotime
+func runtimeNano() int64