FVM: always enable tracing for user-triggered executions

This commit is contained in:
Aayush 2022-07-14 15:09:31 -04:00
parent af525a4cf2
commit 474a50252b
11 changed files with 31 additions and 16 deletions

View File

@ -82,7 +82,17 @@ type FilecoinBlockMessages struct {
WinCount int64 WinCount int64
} }
func (t *TipSetExecutor) ApplyBlocks(ctx context.Context, sm *stmgr.StateManager, parentEpoch abi.ChainEpoch, pstate cid.Cid, bms []FilecoinBlockMessages, epoch abi.ChainEpoch, r vm.Rand, em stmgr.ExecMonitor, baseFee abi.TokenAmount, ts *types.TipSet) (cid.Cid, cid.Cid, error) { func (t *TipSetExecutor) ApplyBlocks(ctx context.Context,
sm *stmgr.StateManager,
parentEpoch abi.ChainEpoch,
pstate cid.Cid,
bms []FilecoinBlockMessages,
epoch abi.ChainEpoch,
r vm.Rand,
em stmgr.ExecMonitor,
vmTracing bool,
baseFee abi.TokenAmount,
ts *types.TipSet) (cid.Cid, cid.Cid, error) {
done := metrics.Timer(ctx, metrics.VMApplyBlocksTotal) done := metrics.Timer(ctx, metrics.VMApplyBlocksTotal)
defer done() defer done()
@ -104,6 +114,7 @@ func (t *TipSetExecutor) ApplyBlocks(ctx context.Context, sm *stmgr.StateManager
NetworkVersion: sm.GetNetworkVersion(ctx, e), NetworkVersion: sm.GetNetworkVersion(ctx, e),
BaseFee: baseFee, BaseFee: baseFee,
LookbackState: stmgr.LookbackStateGetterForTipset(sm, ts), LookbackState: stmgr.LookbackStateGetterForTipset(sm, ts),
Tracing: vmTracing,
} }
return sm.VMConstructor()(ctx, vmopt) return sm.VMConstructor()(ctx, vmopt)
@ -269,7 +280,11 @@ func (t *TipSetExecutor) ApplyBlocks(ctx context.Context, sm *stmgr.StateManager
return st, rectroot, nil return st, rectroot, nil
} }
func (t *TipSetExecutor) ExecuteTipSet(ctx context.Context, sm *stmgr.StateManager, ts *types.TipSet, em stmgr.ExecMonitor) (stateroot cid.Cid, rectsroot cid.Cid, err error) { func (t *TipSetExecutor) ExecuteTipSet(ctx context.Context,
sm *stmgr.StateManager,
ts *types.TipSet,
em stmgr.ExecMonitor,
vmTracing bool) (stateroot cid.Cid, rectsroot cid.Cid, err error) {
ctx, span := trace.StartSpan(ctx, "computeTipSetState") ctx, span := trace.StartSpan(ctx, "computeTipSetState")
defer span.End() defer span.End()
@ -309,7 +324,7 @@ func (t *TipSetExecutor) ExecuteTipSet(ctx context.Context, sm *stmgr.StateManag
} }
baseFee := blks[0].ParentBaseFee baseFee := blks[0].ParentBaseFee
return t.ApplyBlocks(ctx, sm, parentEpoch, pstate, fbmsgs, blks[0].Height, r, em, baseFee, ts) return t.ApplyBlocks(ctx, sm, parentEpoch, pstate, fbmsgs, blks[0].Height, r, em, vmTracing, baseFee, ts)
} }
var _ stmgr.Executor = &TipSetExecutor{} var _ stmgr.Executor = &TipSetExecutor{}

View File

@ -89,6 +89,7 @@ func (sm *StateManager) Call(ctx context.Context, msg *types.Message, ts *types.
NetworkVersion: sm.GetNetworkVersion(ctx, pheight+1), NetworkVersion: sm.GetNetworkVersion(ctx, pheight+1),
BaseFee: types.NewInt(0), BaseFee: types.NewInt(0),
LookbackState: LookbackStateGetterForTipset(sm, ts), LookbackState: LookbackStateGetterForTipset(sm, ts),
Tracing: true,
} }
vmi, err := sm.newVM(ctx, vmopt) vmi, err := sm.newVM(ctx, vmopt)
@ -226,6 +227,7 @@ func (sm *StateManager) CallWithGas(ctx context.Context, msg *types.Message, pri
NetworkVersion: sm.GetNetworkVersion(ctx, ts.Height()+1), NetworkVersion: sm.GetNetworkVersion(ctx, ts.Height()+1),
BaseFee: ts.Blocks()[0].ParentBaseFee, BaseFee: ts.Blocks()[0].ParentBaseFee,
LookbackState: LookbackStateGetterForTipset(sm, ts), LookbackState: LookbackStateGetterForTipset(sm, ts),
Tracing: true,
} }
vmi, err := sm.newVM(ctx, vmopt) vmi, err := sm.newVM(ctx, vmopt)
if err != nil { if err != nil {
@ -318,7 +320,7 @@ func (sm *StateManager) Replay(ctx context.Context, ts *types.TipSet, mcid cid.C
// message to find // message to find
finder.mcid = mcid finder.mcid = mcid
_, _, err := sm.tsExec.ExecuteTipSet(ctx, sm, ts, &finder) _, _, err := sm.tsExec.ExecuteTipSet(ctx, sm, ts, &finder, true)
if err != nil && !xerrors.Is(err, errHaltExecution) { if err != nil && !xerrors.Is(err, errHaltExecution) {
return nil, nil, xerrors.Errorf("unexpected error during execution: %w", err) return nil, nil, xerrors.Errorf("unexpected error during execution: %w", err)
} }

View File

@ -60,7 +60,7 @@ func (sm *StateManager) TipSetState(ctx context.Context, ts *types.TipSet) (st c
return ts.Blocks()[0].ParentStateRoot, ts.Blocks()[0].ParentMessageReceipts, nil return ts.Blocks()[0].ParentStateRoot, ts.Blocks()[0].ParentMessageReceipts, nil
} }
st, rec, err = sm.tsExec.ExecuteTipSet(ctx, sm, ts, sm.tsExecMonitor) st, rec, err = sm.tsExec.ExecuteTipSet(ctx, sm, ts, sm.tsExecMonitor, false)
if err != nil { if err != nil {
return cid.Undef, cid.Undef, err return cid.Undef, cid.Undef, err
} }
@ -69,7 +69,7 @@ func (sm *StateManager) TipSetState(ctx context.Context, ts *types.TipSet) (st c
} }
func (sm *StateManager) ExecutionTraceWithMonitor(ctx context.Context, ts *types.TipSet, em ExecMonitor) (cid.Cid, error) { func (sm *StateManager) ExecutionTraceWithMonitor(ctx context.Context, ts *types.TipSet, em ExecMonitor) (cid.Cid, error) {
st, _, err := sm.tsExec.ExecuteTipSet(ctx, sm, ts, em) st, _, err := sm.tsExec.ExecuteTipSet(ctx, sm, ts, em, true)
return st, err return st, err
} }

View File

@ -58,7 +58,7 @@ type migration struct {
type Executor interface { type Executor interface {
NewActorRegistry() *vm.ActorRegistry NewActorRegistry() *vm.ActorRegistry
ExecuteTipSet(ctx context.Context, sm *StateManager, ts *types.TipSet, em ExecMonitor) (stateroot cid.Cid, rectsroot cid.Cid, err error) ExecuteTipSet(ctx context.Context, sm *StateManager, ts *types.TipSet, em ExecMonitor, vmTracing bool) (stateroot cid.Cid, rectsroot cid.Cid, err error)
} }
type StateManager struct { type StateManager struct {

View File

@ -94,6 +94,7 @@ func ComputeState(ctx context.Context, sm *StateManager, height abi.ChainEpoch,
NetworkVersion: sm.GetNetworkVersion(ctx, height), NetworkVersion: sm.GetNetworkVersion(ctx, height),
BaseFee: ts.Blocks()[0].ParentBaseFee, BaseFee: ts.Blocks()[0].ParentBaseFee,
LookbackState: LookbackStateGetterForTipset(sm, ts), LookbackState: LookbackStateGetterForTipset(sm, ts),
Tracing: true,
} }
vmi, err := sm.newVM(ctx, vmopt) vmi, err := sm.newVM(ctx, vmopt)
if err != nil { if err != nil {

View File

@ -281,7 +281,7 @@ func defaultFVMOpts(ctx context.Context, opts *VMOpts) (*ffi.FVMOpts, error) {
BaseCircSupply: circToReport, BaseCircSupply: circToReport,
NetworkVersion: opts.NetworkVersion, NetworkVersion: opts.NetworkVersion,
StateBase: opts.StateBase, StateBase: opts.StateBase,
Tracing: EnableDetailedTracing, Tracing: opts.Tracing || EnableDetailedTracing,
}, nil }, nil
} }

View File

@ -59,7 +59,9 @@ func (m *Message) ValueReceived() abi.TokenAmount {
return m.msg.Value return m.msg.Value
} }
// EnableDetailedTracing, if true, outputs gas tracing in execution traces. // EnableDetailedTracing has different behaviour in the LegacyVM and FVM.
// In the LegacyVM, it enables detailed gas tracing, slowing down execution.
// In the FVM, it enables execution traces, which are primarily used to observe subcalls.
var EnableDetailedTracing = os.Getenv("LOTUS_VM_ENABLE_TRACING") == "1" var EnableDetailedTracing = os.Getenv("LOTUS_VM_ENABLE_TRACING") == "1"
type Runtime struct { type Runtime struct {

View File

@ -229,6 +229,7 @@ type VMOpts struct {
NetworkVersion network.Version NetworkVersion network.Version
BaseFee abi.TokenAmount BaseFee abi.TokenAmount
LookbackState LookbackStateGetter LookbackState LookbackStateGetter
Tracing bool
} }
func NewLegacyVM(ctx context.Context, opts *VMOpts) (*LegacyVM, error) { func NewLegacyVM(ctx context.Context, opts *VMOpts) (*LegacyVM, error) {

View File

@ -21,8 +21,6 @@ type Interface interface {
Flush(ctx context.Context) (cid.Cid, error) Flush(ctx context.Context) (cid.Cid, error)
} }
var useFvmForMainnetV15 = os.Getenv("LOTUS_USE_FVM_TO_SYNC_MAINNET_V15") == "1"
// WARNING: You will not affect your node's execution by misusing this feature, but you will confuse yourself thoroughly! // WARNING: You will not affect your node's execution by misusing this feature, but you will confuse yourself thoroughly!
// An envvar that allows the user to specify debug actors bundles to be used by the FVM // An envvar that allows the user to specify debug actors bundles to be used by the FVM
// alongside regular execution. This is basically only to be used to print out specific logging information. // alongside regular execution. This is basically only to be used to print out specific logging information.

View File

@ -169,6 +169,7 @@ func (d *Driver) ExecuteTipset(bs blockstore.Blockstore, ds ds.Batching, params
params.ExecEpoch, params.ExecEpoch,
params.Rand, params.Rand,
recordOutputs, recordOutputs,
true,
params.BaseFee, params.BaseFee,
nil, nil,
) )

View File

@ -22,7 +22,6 @@ import (
"github.com/filecoin-project/lotus/chain/actors/adt" "github.com/filecoin-project/lotus/chain/actors/adt"
lmultisig "github.com/filecoin-project/lotus/chain/actors/builtin/multisig" lmultisig "github.com/filecoin-project/lotus/chain/actors/builtin/multisig"
"github.com/filecoin-project/lotus/chain/types" "github.com/filecoin-project/lotus/chain/types"
"github.com/filecoin-project/lotus/chain/vm"
"github.com/filecoin-project/lotus/itests/kit" "github.com/filecoin-project/lotus/itests/kit"
"github.com/filecoin-project/lotus/itests/multisig" "github.com/filecoin-project/lotus/itests/multisig"
) )
@ -36,7 +35,6 @@ func TestMultisig(t *testing.T) {
//stm: @CHAIN_INCOMING_HANDLE_INCOMING_BLOCKS_001, @CHAIN_INCOMING_VALIDATE_BLOCK_PUBSUB_001, @CHAIN_INCOMING_VALIDATE_MESSAGE_PUBSUB_001 //stm: @CHAIN_INCOMING_HANDLE_INCOMING_BLOCKS_001, @CHAIN_INCOMING_VALIDATE_BLOCK_PUBSUB_001, @CHAIN_INCOMING_VALIDATE_MESSAGE_PUBSUB_001
kit.QuietMiningLogs() kit.QuietMiningLogs()
vm.EnableDetailedTracing = true
blockTime := 5 * time.Millisecond blockTime := 5 * time.Millisecond
client, _, ens := kit.EnsembleMinimal(t, kit.MockProofs(), kit.ThroughRPC()) client, _, ens := kit.EnsembleMinimal(t, kit.MockProofs(), kit.ThroughRPC())
@ -47,8 +45,6 @@ func TestMultisig(t *testing.T) {
// TestMultisigReentrant sends an infinitely recursive message to a multisig. // TestMultisigReentrant sends an infinitely recursive message to a multisig.
func TestMultisigReentrant(t *testing.T) { func TestMultisigReentrant(t *testing.T) {
tracing := vm.EnableDetailedTracing
vm.EnableDetailedTracing = true
//stm: @CHAIN_SYNCER_LOAD_GENESIS_001, @CHAIN_SYNCER_FETCH_TIPSET_001, //stm: @CHAIN_SYNCER_LOAD_GENESIS_001, @CHAIN_SYNCER_FETCH_TIPSET_001,
//stm: @CHAIN_SYNCER_START_001, @CHAIN_SYNCER_SYNC_001, @BLOCKCHAIN_BEACON_VALIDATE_BLOCK_VALUES_01 //stm: @CHAIN_SYNCER_START_001, @CHAIN_SYNCER_SYNC_001, @BLOCKCHAIN_BEACON_VALIDATE_BLOCK_VALUES_01
//stm: @CHAIN_SYNCER_COLLECT_CHAIN_001, @CHAIN_SYNCER_COLLECT_HEADERS_001, @CHAIN_SYNCER_VALIDATE_TIPSET_001 //stm: @CHAIN_SYNCER_COLLECT_CHAIN_001, @CHAIN_SYNCER_COLLECT_HEADERS_001, @CHAIN_SYNCER_VALIDATE_TIPSET_001
@ -138,7 +134,6 @@ func TestMultisigReentrant(t *testing.T) {
require.NoError(t, err, "failed to replay reentrant propose message (StateWaitMsg)") require.NoError(t, err, "failed to replay reentrant propose message (StateWaitMsg)")
require.Equal(t, 1025, countDepth(sl.ExecutionTrace)) require.Equal(t, 1025, countDepth(sl.ExecutionTrace))
vm.EnableDetailedTracing = tracing
} }
func countDepth(trace types.ExecutionTrace) int { func countDepth(trace types.ExecutionTrace) int {