From ca79360fd7621a96382c0304e74e0d1f39b739fc Mon Sep 17 00:00:00 2001 From: obscuren Date: Tue, 17 Jun 2014 18:49:26 +0200 Subject: Verbose logging for VM --- ethchain/state_transition.go | 1 + ethchain/vm.go | 45 +++++++++++++++++++++++++++++++++++++++----- 2 files changed, 41 insertions(+), 5 deletions(-) (limited to 'ethchain') diff --git a/ethchain/state_transition.go b/ethchain/state_transition.go index dc465bbbd..c70dc54b4 100644 --- a/ethchain/state_transition.go +++ b/ethchain/state_transition.go @@ -236,6 +236,7 @@ func (self *StateTransition) Eval(script []byte, context *StateObject) (ret []by Diff: block.Difficulty, Value: tx.Value, }) + vm.Verbose = true ret, _, err = closure.Call(vm, tx.Data, nil) return diff --git a/ethchain/vm.go b/ethchain/vm.go index 690433180..7a4e30a33 100644 --- a/ethchain/vm.go +++ b/ethchain/vm.go @@ -45,6 +45,10 @@ type Vm struct { state *State stateManager *StateManager + + Verbose bool + + logStr string } type RuntimeVars struct { @@ -58,6 +62,23 @@ type RuntimeVars struct { Value *big.Int } +func (self *Vm) Printf(format string, v ...interface{}) *Vm { + if self.Verbose { + self.logStr += fmt.Sprintf(format, v...) + } + + return self +} + +func (self *Vm) Endl() *Vm { + if self.Verbose { + ethutil.Config.Log.Infoln(self.logStr) + self.logStr = "" + } + + return self +} + func NewVm(state *State, stateManager *StateManager, vars RuntimeVars) *Vm { return &Vm{vars: vars, state: state, stateManager: stateManager} } @@ -95,8 +116,6 @@ func (vm *Vm) RunClosure(closure *Closure, hook DebugHook) (ret []byte, err erro step := 0 prevStep := 0 - ethutil.Config.Log.Debugf("# op\n") - for { prevStep = step // The base for all big integer arithmetic @@ -108,7 +127,8 @@ func (vm *Vm) RunClosure(closure *Closure, hook DebugHook) (ret []byte, err erro // Get the opcode (it must be an opcode!) op := OpCode(val.Uint()) - ethutil.Config.Log.Debugf("%-3d %-4s", pc, op.String()) + vm.Printf("(pc) %-3d -o- %-14s", pc, op.String()) + //ethutil.Config.Log.Debugf("%-3d %-4s", pc, op.String()) gas := new(big.Int) addStepGasUsage := func(amount *big.Int) { @@ -193,6 +213,8 @@ func (vm *Vm) RunClosure(closure *Closure, hook DebugHook) (ret []byte, err erro return closure.Return(nil), fmt.Errorf("insufficient gas %v %v", closure.Gas, gas) } + vm.Printf(" (g) %-3v (%v)", gas, closure.Gas) + mem.Resize(newMemSize) switch op { @@ -428,6 +450,8 @@ func (vm *Vm) RunClosure(closure *Closure, hook DebugHook) (ret []byte, err erro pc.Add(pc, a.Sub(a, big.NewInt(1))) step += int(op) - int(PUSH1) + 1 + + vm.Printf(" => %#x", data.Bytes()) case POP: require(1) stack.Pop() @@ -448,11 +472,15 @@ func (vm *Vm) RunClosure(closure *Closure, hook DebugHook) (ret []byte, err erro // Pop value of the stack val, mStart := stack.Popn() mem.Set(mStart.Int64(), 32, ethutil.BigToBytes(val, 256)) + + vm.Printf(" => %#x", val) case MSTORE8: require(2) val, mStart := stack.Popn() base.And(val, new(big.Int).SetInt64(0xff)) mem.Set(mStart.Int64(), 32, ethutil.BigToBytes(base, 256)) + + vm.Printf(" => %#x", val) case SLOAD: require(1) loc := stack.Pop() @@ -466,18 +494,23 @@ func (vm *Vm) RunClosure(closure *Closure, hook DebugHook) (ret []byte, err erro // Add the change to manifest vm.state.manifest.AddStorageChange(closure.Object(), loc.Bytes(), val) + + vm.Printf(" => %#x", val) case JUMP: require(1) pc = stack.Pop() // Reduce pc by one because of the increment that's at the end of this for loop - //pc.Sub(pc, ethutil.Big1) + vm.Printf(" ~> %v", pc).Endl() + continue case JUMPI: require(2) cond, pos := stack.Popn() if cond.Cmp(ethutil.BigTrue) >= 0 { pc = pos - //pc.Sub(pc, ethutil.Big1) + + vm.Printf(" ~> %v", pc).Endl() + continue } case PC: @@ -603,6 +636,8 @@ func (vm *Vm) RunClosure(closure *Closure, hook DebugHook) (ret []byte, err erro pc.Add(pc, ethutil.Big1) + vm.Endl() + if hook != nil { if !hook(prevStep, op, mem, stack, closure.Object()) { return nil, nil -- cgit v1.2.3