add subcall timing to compute state output

chain/types/execresult.go

@@ -1,9 +1,12 @@
 package types
 
+import "time"
+
 type ExecutionResult struct {
-	Msg    *Message
+	Msg      *Message
-	MsgRct *MessageReceipt
+	MsgRct   *MessageReceipt
-	Error  string
+	Error    string
+	Duration time.Duration
 
 	Subcalls []*ExecutionResult
 }

chain/vm/runtime.go

@@ -5,6 +5,8 @@ import (
 	"context"
 	"encoding/binary"
 	"fmt"
+	"time"
+
 	"github.com/filecoin-project/go-address"
 	"github.com/filecoin-project/specs-actors/actors/abi"
 	"github.com/filecoin-project/specs-actors/actors/abi/big"
@@ -366,6 +368,7 @@ func (rs *Runtime) Send(to address.Address, method abi.MethodNum, m vmr.CBORMars
 }
 
 func (rt *Runtime) internalSend(from, to address.Address, method abi.MethodNum, value types.BigInt, params []byte) ([]byte, aerrors.ActorError) {
+	start := time.Now()
 	ctx, span := trace.StartSpan(rt.ctx, "vmc.Send")
 	defer span.End()
 	if span.IsRecordingEvents() {
@@ -405,8 +408,9 @@ func (rt *Runtime) internalSend(from, to address.Address, method abi.MethodNum,
 	}
 
 	er := types.ExecutionResult{
-		Msg:    msg,
+		Msg:      msg,
-		MsgRct: &mr,
+		MsgRct:   &mr,
+		Duration: time.Since(start),
 	}
 
 	if errSend != nil {

cmd/lotus-storage-miner/proving.go

@@ -3,6 +3,8 @@ package main
 import (
 	"bytes"
 	"fmt"
+	"time"
+
 	"github.com/filecoin-project/lotus/build"
 	"github.com/filecoin-project/lotus/chain/types"
 	lcli "github.com/filecoin-project/lotus/cli"
@@ -10,7 +12,6 @@ import (
 	"github.com/filecoin-project/specs-actors/actors/builtin/miner"
 	"golang.org/x/xerrors"
 	"gopkg.in/urfave/cli.v2"
-	"time"
 )
 
 var provingCmd = &cli.Command{