From 254daf0968cfa5e4cdc04ec4239f4dc499248309 Mon Sep 17 00:00:00 2001 From: Rod Vagg Date: Tue, 21 Jan 2025 21:13:16 +1100 Subject: [PATCH] feat(shed): gas-sim compact-sectors * simulate a CompactSectors prior to a miner message * improve gas table printing and handling --- chain/stmgr/call.go | 16 +- cmd/lotus-shed/gas-estimation.go | 376 ++++++++++++++++++++++++------- cmd/lotus-shed/main.go | 11 +- cmd/lotus-shed/msg.go | 122 ++++++---- itests/kit/init.go | 4 +- node/impl/eth/api.go | 2 +- node/impl/eth/gas.go | 2 +- 7 files changed, 400 insertions(+), 133 deletions(-) diff --git a/chain/stmgr/call.go b/chain/stmgr/call.go index 90c193b95f8..8bf33fec515 100644 --- a/chain/stmgr/call.go +++ b/chain/stmgr/call.go @@ -28,7 +28,7 @@ import ( type execMessageStrategy int const ( - execNoMessages execMessageStrategy = iota // apply no prior or current tipset messages + execNoMessages execMessageStrategy = iota // apply no prior or current tipset messages unless supplied execAllMessages // apply all prior and current tipset messages execSameSenderMessages // apply all prior messages and any current tipset messages from the same sender ) @@ -60,8 +60,8 @@ func (sm *StateManager) Call(ctx context.Context, msg *types.Message, ts *types. } // ApplyOnStateWithGas applies the given message on top of the given state root with gas tracing enabled -func (sm *StateManager) ApplyOnStateWithGas(ctx context.Context, stateCid cid.Cid, msg *types.Message, ts *types.TipSet) (*api.InvocResult, error) { - return sm.callInternal(ctx, msg, nil, ts, stateCid, sm.GetNetworkVersion, true, execNoMessages) +func (sm *StateManager) ApplyOnStateWithGas(ctx context.Context, stateCid cid.Cid, msg *types.Message, priorMsgs []types.ChainMsg, ts *types.TipSet) (*api.InvocResult, error) { + return sm.callInternal(ctx, msg, priorMsgs, ts, stateCid, sm.GetNetworkVersion, true, execNoMessages) } // CallWithGas calculates the state for a given tipset, and then applies the given message on top of that state. @@ -174,7 +174,7 @@ func (sm *StateManager) callInternal(ctx context.Context, msg *types.Message, pr switch strategy { case execNoMessages: - // Do nothing + // Do nothing, unless we have prior messages to apply case execAllMessages, execSameSenderMessages: tsMsgs, err := sm.cs.MessagesForTipset(ctx, ts) if err != nil { @@ -190,13 +190,19 @@ func (sm *StateManager) callInternal(ctx context.Context, msg *types.Message, pr filteredTsMsgs = append(filteredTsMsgs, tsMsg) } } + log.Debugf("applying %d additional messages from same sender", len(filteredTsMsgs)) priorMsgs = append(filteredTsMsgs, priorMsgs...) } + } + + if len(priorMsgs) > 0 { for i, m := range priorMsgs { - _, err = vmi.ApplyMessage(ctx, m) + ret, err := vmi.ApplyMessage(ctx, m) if err != nil { return nil, xerrors.Errorf("applying prior message (%d, %s): %w", i, m.Cid(), err) } + // TODO: return this information to the caller + log.Debugf("applied prior message %s: %d [%x]: %s", m.Cid(), ret.MessageReceipt.ExitCode, ret.MessageReceipt.Return, ret.ActorErr) } // We flush to get the VM's view of the state tree after applying the above messages diff --git a/cmd/lotus-shed/gas-estimation.go b/cmd/lotus-shed/gas-estimation.go index b1c61b62f2c..064a811be82 100644 --- a/cmd/lotus-shed/gas-estimation.go +++ b/cmd/lotus-shed/gas-estimation.go @@ -4,22 +4,30 @@ import ( "context" "fmt" "io" - "os" + "math" "strconv" - "text/tabwriter" + "strings" + "github.com/fatih/color" "github.com/ipfs/go-cid" + "github.com/ipfs/go-datastore" + cbor "github.com/ipfs/go-ipld-cbor" "github.com/urfave/cli/v2" "golang.org/x/xerrors" + "github.com/filecoin-project/go-bitfield" "github.com/filecoin-project/go-state-types/abi" "github.com/filecoin-project/go-state-types/network" + "github.com/filecoin-project/lotus/blockstore" "github.com/filecoin-project/lotus/build/buildconstants" + "github.com/filecoin-project/lotus/chain/actors" + "github.com/filecoin-project/lotus/chain/actors/builtin/miner" "github.com/filecoin-project/lotus/chain/beacon/drand" "github.com/filecoin-project/lotus/chain/consensus" "github.com/filecoin-project/lotus/chain/consensus/filcns" proofsffi "github.com/filecoin-project/lotus/chain/proofs/ffi" + "github.com/filecoin-project/lotus/chain/state" "github.com/filecoin-project/lotus/chain/stmgr" "github.com/filecoin-project/lotus/chain/store" "github.com/filecoin-project/lotus/chain/types" @@ -40,14 +48,9 @@ var gasTraceCmd = &cli.Command{ Name: "trace-gas", Description: "replay a message on the specified stateRoot and network version to get an execution trace", ArgsUsage: "[migratedStateRootCid networkVersion messageCid]", - Flags: []cli.Flag{ - &cli.StringFlag{ - Name: "repo", - Value: "~/.lotus", - }, - }, + Flags: []cli.Flag{}, Action: func(cctx *cli.Context) error { - ctx := context.TODO() + ctx := lcli.ReqContext(cctx) if cctx.NArg() != 3 { return lcli.IncorrectNumArgs(cctx) @@ -55,85 +58,87 @@ var gasTraceCmd = &cli.Command{ stateRootCid, err := cid.Decode(cctx.Args().Get(0)) if err != nil { - return fmt.Errorf("failed to parse input: %w", err) + return xerrors.Errorf("failed to parse input: %w", err) } nv, err := strconv.ParseInt(cctx.Args().Get(1), 10, 32) if err != nil { - return fmt.Errorf("failed to parse input: %w", err) + return xerrors.Errorf("failed to parse input: %w", err) } messageCid, err := cid.Decode(cctx.Args().Get(2)) if err != nil { - return fmt.Errorf("failed to parse input: %w", err) + return xerrors.Errorf("failed to parse input: %w", err) } - fsrepo, err := repo.NewFS(cctx.String("repo")) + client, closer, err := lcli.GetFullNodeAPI(cctx) if err != nil { - return err + return xerrors.Errorf("connect to full node: %w", err) } + defer closer() - lkrepo, err := fsrepo.Lock(repo.FullNode) + bs := blockstore.NewAPIBlockstore(client) + mds := datastore.NewMapDatastore() + + genesis, err := client.ChainGetGenesis(ctx) if err != nil { - return err + return xerrors.Errorf("failed to get genesis: %w", err) } - defer lkrepo.Close() //nolint:errcheck + cs := store.NewChainStore(bs, bs, mds, filcns.Weight, nil) + defer cs.Close() //nolint:errcheck - bs, err := lkrepo.Blockstore(ctx, repo.UniversalBlockstore) - if err != nil { - return fmt.Errorf("failed to open blockstore: %w", err) + // setup our local chainstore so it has enough data to execute a tipset, since we're not using + // a live repo datastore + gen := genesis.Blocks()[0] + if err := mds.Put(ctx, datastore.NewKey("0"), gen.Cid().Bytes()); err != nil { + return xerrors.Errorf("failed to put genesis: %w", err) } - defer func() { - if c, ok := bs.(io.Closer); ok { - if err := c.Close(); err != nil { - log.Warnf("failed to close blockstore: %s", err) - } - } - }() - - mds, err := lkrepo.Datastore(context.Background(), "/metadata") + head, err := client.ChainHead(ctx) if err != nil { - return err + return xerrors.Errorf("failed to get chain head: %w", err) + } + if err := cs.ForceHeadSilent(ctx, head); err != nil { + return xerrors.Errorf("failed to set head: %w", err) + } + if err = cs.Load(ctx); err != nil { + return xerrors.Errorf("failed to load chainstore: %w", err) } - shd, err := drand.BeaconScheduleFromDrandSchedule(buildconstants.DrandConfigSchedule(), MAINNET_GENESIS_TIME, nil) + shd, err := drand.BeaconScheduleFromDrandSchedule(buildconstants.DrandConfigSchedule(), genesis.Blocks()[0].Timestamp, nil) if err != nil { - return err + return xerrors.Errorf("failed to create beacon schedule: %w", err) } - cs := store.NewChainStore(bs, bs, mds, filcns.Weight, nil) - defer cs.Close() //nolint:errcheck - - sm, err := stmgr.NewStateManager(cs, consensus.NewTipSetExecutor(filcns.RewardFunc), vm.Syscalls(proofsffi.ProofVerifier), filcns.DefaultUpgradeSchedule(), - shd, mds, nil) + sm, err := stmgr.NewStateManager( + cs, + consensus.NewTipSetExecutor(filcns.RewardFunc), + vm.Syscalls(proofsffi.ProofVerifier), + filcns.DefaultUpgradeSchedule(), + shd, + mds, + nil, + ) if err != nil { - return err + return xerrors.Errorf("failed to create state manager: %w", err) } msg, err := cs.GetMessage(ctx, messageCid) if err != nil { - return err + return xerrors.Errorf("failed to get message: %w", err) } // Set to block limit so message will not run out of gas msg.GasLimit = buildconstants.BlockGasLimit - err = cs.Load(ctx) - if err != nil { - return err - } - - tw := tabwriter.NewWriter(os.Stdout, 8, 2, 2, ' ', tabwriter.AlignRight) res, err := sm.CallAtStateAndVersion(ctx, msg, stateRootCid, network.Version(nv)) if err != nil { - return err + return xerrors.Errorf("failed to call with gas: %w", err) } - fmt.Println("Total gas used: ", res.MsgRct.GasUsed) - printInternalExecutions(0, []types.ExecutionTrace{res.ExecutionTrace}, tw) + _, _ = fmt.Fprintf(cctx.App.Writer, "Result: %s (%s)\n", res.MsgRct.ExitCode, res.Error) - return tw.Flush() + return printGasStats(cctx.App.Writer, res.ExecutionTrace) }, } @@ -160,7 +165,7 @@ var replayOfflineCmd = &cli.Command{ messageCid, err := cid.Decode(cctx.Args().Get(0)) if err != nil { - return fmt.Errorf("failed to parse input: %w", err) + return xerrors.Errorf("failed to parse input: %w", err) } lookbackLimit := cctx.Int("lookback-limit") @@ -179,7 +184,7 @@ var replayOfflineCmd = &cli.Command{ bs, err := lkrepo.Blockstore(ctx, repo.UniversalBlockstore) if err != nil { - return fmt.Errorf("failed to open blockstore: %w", err) + return xerrors.Errorf("failed to open blockstore: %w", err) } defer func() { @@ -214,8 +219,7 @@ var replayOfflineCmd = &cli.Command{ return err } - err = cs.Load(ctx) - if err != nil { + if err = cs.Load(ctx); err != nil { return err } @@ -231,43 +235,255 @@ var replayOfflineCmd = &cli.Command{ return err } - tw := tabwriter.NewWriter(os.Stdout, 8, 2, 2, ' ', tabwriter.AlignRight) res, err := sm.CallWithGas(ctx, msg, []types.ChainMsg{}, executionTs, true) if err != nil { return err } - fmt.Println("Total gas used: ", res.MsgRct.GasUsed) - printInternalExecutions(0, []types.ExecutionTrace{res.ExecutionTrace}, tw) - - return tw.Flush() + return printGasStats(cctx.App.Writer, res.ExecutionTrace) }, } -func printInternalExecutions(depth int, trace []types.ExecutionTrace, tw *tabwriter.Writer) { - if depth == 0 { - _, _ = fmt.Fprintf(tw, "Depth\tFrom\tTo\tMethod\tTotalGas\tComputeGas\tStorageGas\t\tExitCode\n") - } - for _, im := range trace { - sumGas := im.SumGas() - _, _ = fmt.Fprintf(tw, "%d\t%s\t%s\t%d\t%d\t%d\t%d\t\t%d\n", depth, truncateString(im.Msg.From.String(), 10), truncateString(im.Msg.To.String(), 10), im.Msg.Method, sumGas.TotalGas, sumGas.ComputeGas, sumGas.StorageGas, im.MsgRct.ExitCode) - printInternalExecutions(depth+1, im.Subcalls, tw) - } +var gasSimCmd = &cli.Command{ + Name: "gas-sim", + Description: "simulate some variations that could affect gas usage", + Subcommands: []*cli.Command{compareCompactSectorsCmd}, } -func truncateString(str string, length int) string { - if len(str) <= length { - return str - } +var compareCompactSectorsCmd = &cli.Command{ + Name: "compact-sectors", + Description: "replay a miner message to compare gas stats with the same message preceded by CompactPartitions", + ArgsUsage: "[minerMessageCid]", + Flags: []cli.Flag{ + &cli.StringFlag{ + Name: "lookback-limit", + Value: "10000", + }, + }, + Action: func(cctx *cli.Context) error { + ctx := lcli.ReqContext(cctx) - truncated := "" - count := 0 - for _, char := range str { - truncated += string(char) - count++ - if count >= length { - break + if cctx.NArg() != 1 { + return lcli.IncorrectNumArgs(cctx) } + + messageCid, err := cid.Decode(cctx.Args().First()) + if err != nil { + return xerrors.Errorf("failed to parse input: %w", err) + } + + client, closer, err := lcli.GetFullNodeAPI(cctx) + if err != nil { + return xerrors.Errorf("connect to full node: %w", err) + } + defer closer() + + bs := blockstore.NewAPIBlockstore(client) + mds := datastore.NewMapDatastore() + + genesis, err := client.ChainGetGenesis(ctx) + if err != nil { + return xerrors.Errorf("failed to get genesis: %w", err) + } + + cs := store.NewChainStore(bs, bs, mds, filcns.Weight, nil) + defer cs.Close() //nolint:errcheck + + // setup our local chainstore so it has enough data to execute a tipset, since we're not using + // a live repo datastore + gen := genesis.Blocks()[0] + if err := mds.Put(ctx, datastore.NewKey("0"), gen.Cid().Bytes()); err != nil { + return xerrors.Errorf("failed to put genesis: %w", err) + } + + head, err := client.ChainHead(ctx) + if err != nil { + return xerrors.Errorf("failed to get chain head: %w", err) + } + if err := cs.ForceHeadSilent(ctx, head); err != nil { + return xerrors.Errorf("failed to set head: %w", err) + } + if err = cs.Load(ctx); err != nil { + return xerrors.Errorf("failed to load chainstore: %w", err) + } + + shd, err := drand.BeaconScheduleFromDrandSchedule(buildconstants.DrandConfigSchedule(), genesis.Blocks()[0].Timestamp, nil) + if err != nil { + return xerrors.Errorf("failed to create beacon schedule: %w", err) + } + + sm, err := stmgr.NewStateManager( + cs, + consensus.NewTipSetExecutor(filcns.RewardFunc), + vm.Syscalls(proofsffi.ProofVerifier), + filcns.DefaultUpgradeSchedule(), + shd, + mds, + nil, + ) + if err != nil { + return xerrors.Errorf("failed to create state manager: %w", err) + } + + lookbackLimit := cctx.Int("lookback-limit") + ts, _, mcid, err := sm.SearchForMessage(ctx, head, messageCid, abi.ChainEpoch(lookbackLimit), true) + if err != nil { + return xerrors.Errorf("failed to search for message: %w", err) + } + cmsg, err := cs.GetCMessage(ctx, mcid) + if err != nil { + return xerrors.Errorf("failed to get message (%s): %w", mcid, err) + } + msg := cmsg.VMMessage() + pts, err := cs.LoadTipSet(ctx, ts.Parents()) + if err != nil { + return xerrors.Errorf("failed to load parent tipset: %w", err) + } + + stTree, err := state.LoadStateTree(cbor.NewCborStore(bs), pts.ParentState()) + if err != nil { + return xerrors.Errorf("failed to load state tree: %w", err) + } + toActor, err := stTree.GetActor(msg.To) + if err != nil { + return xerrors.Errorf("failed to get from actor: %w", err) + } + if name, _, ok := actors.GetActorMetaByCode(toActor.Code); !ok { + return xerrors.Errorf("failed to get actor meta: %w", err) + } else if name != "storageminer" { + return xerrors.Errorf("message is not a miner message (%s)", name) + } + + fromActor, err := stTree.GetActor(msg.From) + if err != nil { + return xerrors.Errorf("failed to get from actor: %w", err) + } + + _, _ = fmt.Fprintf(cctx.App.Writer, "Message from %s to %s:%d at height %d\n", msg.From, msg.To, msg.Method, pts.Height()) + + priorMsgs := make([]types.ChainMsg, 0) + + tsMsgs, err := cs.MessagesForTipset(ctx, pts) + if err != nil { + return xerrors.Errorf("failed to get messages for tipset: %w", err) + } + for _, tsMsg := range tsMsgs { + if tsMsg.VMMessage().From == msg.VMMessage().From && tsMsg.VMMessage().Cid() != msg.VMMessage().Cid() { + priorMsgs = append(priorMsgs, tsMsg) + _, _ = fmt.Fprintf(cctx.App.Writer, "Found previous message to replay (%s) from %s to %s:%d\n", tsMsg.VMMessage().Cid(), tsMsg.VMMessage().From, tsMsg.VMMessage().To, tsMsg.VMMessage().Method) + } + } + + // Set to block limit so message will not run out of gas + msg.GasLimit = buildconstants.BlockGasLimit + + _, _ = fmt.Fprintf(cctx.App.Writer, "\nReplaying %d other messages prior to miner message\n", len(priorMsgs)) + origRes, err := sm.ApplyOnStateWithGas(ctx, pts.ParentState(), msg, priorMsgs, pts) + if err != nil { + return xerrors.Errorf("failed to call with gas: %w", err) + } + _, _ = fmt.Fprintf(cctx.App.Writer, "Result (%s):\n", origRes.MsgRct.ExitCode) + + if err := printTotalGasChargesPerCall(cctx.App.Writer, origRes.ExecutionTrace); err != nil { + return xerrors.Errorf("failed to print gas stats: %w", err) + } + + // 48 CompactPartition messages, many will fail due to partition modification rules + nonce := fromActor.Nonce + for i := 0; i < 48; i++ { + partitions := bitfield.New() + partitions.Set(0) // optimistically only doing the first partition, there may be more for this deadline, however + cpparams := &miner.CompactPartitionsParams{ + Deadline: uint64(i), + Partitions: partitions, + } + cp, err := actors.SerializeParams(cpparams) + if err != nil { + return xerrors.Errorf("serializing params: %w", err) + } + priorMsgs = append(priorMsgs, &types.Message{ + Version: 0, + Value: abi.NewTokenAmount(0), + To: msg.To, + From: msg.From, + Method: 19, // CompactPartitions + Params: cp, + GasLimit: math.MaxInt64 / 2, + Nonce: nonce, + }) + nonce++ + } + + _, _ = fmt.Fprintf(cctx.App.Writer, "\nReplaying %d CompactPartitions (and other) messages prior to miner message\n", len(priorMsgs)) + cmpRes, err := sm.ApplyOnStateWithGas(ctx, pts.ParentState(), msg, priorMsgs, pts) + if err != nil { + return xerrors.Errorf("failed to call with gas: %w", err) + } + _, _ = fmt.Fprintf(cctx.App.Writer, "Result after CompactSectors (%s):\n", cmpRes.MsgRct.ExitCode) + + if err := printTotalGasChargesPerCall(cctx.App.Writer, cmpRes.ExecutionTrace); err != nil { + return xerrors.Errorf("failed to print gas stats: %w", err) + } + + fmt.Println("\n" + strings.Repeat("─", 120)) + + origTotals := &gasTally{} + origCharges := make(map[string]*gasTally) + accumGasTallies(origCharges, origTotals, origRes.ExecutionTrace, false) + + cmpTotals := &gasTally{} + cmpCharges := make(map[string]*gasTally) + accumGasTallies(cmpCharges, cmpTotals, cmpRes.ExecutionTrace, false) + + diffCharges := make(map[string]*gasTally) // only those that differ + for k, v := range origCharges { + if c, ok := cmpCharges[k]; ok { + if !v.Equal(*c) { + diffCharges[k] = &gasTally{ + totalGas: v.totalGas - cmpCharges[k].totalGas, + storageGas: v.storageGas - cmpCharges[k].storageGas, + computeGas: v.computeGas - cmpCharges[k].computeGas, + count: v.count - cmpCharges[k].count, + } + } + } else { + diffCharges[k] = v + } + } + diffTotals := &gasTally{ + totalGas: origTotals.totalGas - cmpTotals.totalGas, + storageGas: origTotals.storageGas - cmpTotals.storageGas, + computeGas: origTotals.computeGas - cmpTotals.computeGas, + count: origTotals.count - cmpTotals.count, + } + + _, _ = fmt.Fprintln(cctx.App.Writer) + _, _ = fmt.Fprintln(cctx.App.Writer, color.New(color.Bold).Sprint("Difference in gas charges for miner msg (without subcalls):")) + if err := statsTableForCharges(cctx.App.Writer, diffCharges, diffTotals); err != nil { + return xerrors.Errorf("failed to print gas stats: %w", err) + } + + _, _ = fmt.Fprintln(cctx.App.Writer, "\n"+color.New(color.Bold).Sprint("CompactPartitions prior to message resulted in:")) + _, _ = fmt.Fprintf(cctx.App.Writer, " • %s total gas charges\n", posNegStr(diffTotals.count, "fewer", "more")) + _, _ = fmt.Fprintf(cctx.App.Writer, " • %s compute gas (%.2f%%)\n", posNegStr(int(diffTotals.computeGas), "less", "more"), (1-(float64(cmpTotals.computeGas)/float64(origTotals.computeGas)))*100) + _, _ = fmt.Fprintf(cctx.App.Writer, " • %s storage gas (%.2f%%)\n", posNegStr(int(diffTotals.storageGas), "less", "more"), (1-(float64(cmpTotals.storageGas)/float64(origTotals.storageGas)))*100) + _, _ = fmt.Fprintf(cctx.App.Writer, " • %s total gas (%.2f%%)\n", posNegStr(int(diffTotals.totalGas), "less", "more"), (1-(float64(cmpTotals.totalGas)/float64(origTotals.totalGas)))*100) + var reads int + if v, ok := diffCharges["OnBlockOpen"]; ok { + reads = v.count + } + var writes int + if v, ok := diffCharges["OnBlockLink"]; ok { + writes = v.count + } + _, _ = fmt.Fprintf(cctx.App.Writer, " • %s reads and %s writes\n", posNegStr(reads, "fewer", "more"), posNegStr(writes, "fewer", "more")) + + return nil + }, +} + +func posNegStr(i int, pos, neg string) string { + if i >= 0 { + return fmt.Sprintf("%d %s", i, pos) } - truncated += "..." - return truncated + return fmt.Sprintf("%d %s", -i, neg) } diff --git a/cmd/lotus-shed/main.go b/cmd/lotus-shed/main.go index 32b575894e9..04c85bb5d36 100644 --- a/cmd/lotus-shed/main.go +++ b/cmd/lotus-shed/main.go @@ -16,10 +16,12 @@ import ( var log = logging.Logger("lotus-shed") func main() { - _ = logging.SetLogLevel("*", "INFO") - _ = logging.SetLogLevelRegex("badger*", "ERROR") - _ = logging.SetLogLevel("drand", "ERROR") - _ = logging.SetLogLevel("chainstore", "ERROR") + if _, set := os.LookupEnv("GOLOG_LOG_LEVEL"); !set { + _ = logging.SetLogLevel("*", "INFO") + _ = logging.SetLogLevelRegex("badger*", "ERROR") + _ = logging.SetLogLevel("drand", "ERROR") + _ = logging.SetLogLevel("chainstore", "ERROR") + } local := []*cli.Command{ addressCmd, @@ -91,6 +93,7 @@ func main() { blockCmd, adlCmd, f3Cmd, + gasSimCmd, } app := &cli.App{ diff --git a/cmd/lotus-shed/msg.go b/cmd/lotus-shed/msg.go index 4de7789a85c..b9c9a31f8ae 100644 --- a/cmd/lotus-shed/msg.go +++ b/cmd/lotus-shed/msg.go @@ -96,40 +96,9 @@ var msgCmd = &cli.Command{ } if cctx.Bool("gas-stats") { - var printTrace func(descPfx string, trace types.ExecutionTrace) error - printTrace = func(descPfx string, trace types.ExecutionTrace) error { - typ := "Message" - if descPfx != "" { - typ = "Subcall" - } - _, _ = fmt.Fprintln(cctx.App.Writer, color.New(color.Bold).Sprint(fmt.Sprintf("%s (%s%s) gas charges:", typ, descPfx, trace.Msg.To))) - if err := statsTable(cctx.App.Writer, trace, false); err != nil { - return err - } - for _, subtrace := range trace.Subcalls { - _, _ = fmt.Fprintln(cctx.App.Writer) - if err := printTrace(descPfx+trace.Msg.To.String()+"➜", subtrace); err != nil { - return err - } - } - return nil - } - if err := printTrace("", res.ExecutionTrace); err != nil { + if err := printGasStats(cctx.App.Writer, res.ExecutionTrace); err != nil { return err } - if len(res.ExecutionTrace.Subcalls) > 0 { - _, _ = fmt.Fprintln(cctx.App.Writer) - _, _ = fmt.Fprintln(cctx.App.Writer, color.New(color.Bold).Sprint("Total gas charges:")) - if err := statsTable(cctx.App.Writer, res.ExecutionTrace, true); err != nil { - return err - } - perCallTrace := gasTracesPerCall(res.ExecutionTrace) - _, _ = fmt.Fprintln(cctx.App.Writer) - _, _ = fmt.Fprintln(cctx.App.Writer, color.New(color.Bold).Sprint("Gas charges per call:")) - if err := statsTable(cctx.App.Writer, perCallTrace, false); err != nil { - return err - } - } } } @@ -229,6 +198,7 @@ func printMessage(cctx *cli.Context, msg *types.Message) error { fmt.Println("---") color.Green("Message Details:") + fmt.Println("Version:", msg.Version) fmt.Println("Value:", types.FIL(msg.Value)) fmt.Println("Max Fees:", types.FIL(msg.RequiredFunds())) fmt.Println("Max Total Cost:", types.FIL(big.Add(msg.RequiredFunds(), msg.Value))) @@ -396,9 +366,14 @@ func messageFromCID(cctx *cli.Context, c cid.Cid) (types.ChainMsg, error) { type gasTally struct { storageGas int64 computeGas int64 + totalGas int64 // not necessarily C+S, for some reason? count int } +func (g gasTally) Equal(other gasTally) bool { + return g.storageGas == other.storageGas && g.computeGas == other.computeGas && g.totalGas == other.totalGas && g.count == other.count +} + func accumGasTallies(charges map[string]*gasTally, totals *gasTally, trace types.ExecutionTrace, recurse bool) { for _, charge := range trace.GasCharges { name := charge.Name @@ -407,9 +382,11 @@ func accumGasTallies(charges map[string]*gasTally, totals *gasTally, trace types } charges[name].computeGas += charge.ComputeGas charges[name].storageGas += charge.StorageGas + charges[name].totalGas += charge.TotalGas charges[name].count++ totals.computeGas += charge.ComputeGas totals.storageGas += charge.StorageGas + totals.totalGas += charge.TotalGas totals.count++ } if recurse { @@ -420,6 +397,13 @@ func accumGasTallies(charges map[string]*gasTally, totals *gasTally, trace types } func statsTable(out io.Writer, trace types.ExecutionTrace, recurse bool) error { + totals := &gasTally{} + charges := make(map[string]*gasTally) + accumGasTallies(charges, totals, trace, recurse) + return statsTableForCharges(out, charges, totals) +} + +func statsTableForCharges(out io.Writer, charges map[string]*gasTally, totals *gasTally) error { tw := tablewriter.New( tablewriter.Col("Type"), tablewriter.Col("Count", tablewriter.RightAlign()), @@ -431,10 +415,6 @@ func statsTable(out io.Writer, trace types.ExecutionTrace, recurse bool) error { tablewriter.Col("T%", tablewriter.RightAlign()), ) - totals := &gasTally{} - charges := make(map[string]*gasTally) - accumGasTallies(charges, totals, trace, recurse) - // Sort by name names := make([]string, 0, len(charges)) for name := range charges { @@ -451,8 +431,8 @@ func statsTable(out io.Writer, trace types.ExecutionTrace, recurse bool) error { "S%": fmt.Sprintf("%.2f", float64(charge.storageGas)/float64(totals.storageGas)*100), "Compute Gas": charge.computeGas, "C%": fmt.Sprintf("%.2f", float64(charge.computeGas)/float64(totals.computeGas)*100), - "Total Gas": charge.storageGas + charge.computeGas, - "T%": fmt.Sprintf("%.2f", float64(charge.storageGas+charge.computeGas)/float64(totals.storageGas+totals.computeGas)*100), + "Total Gas": charge.totalGas, + "T%": fmt.Sprintf("%.2f", float64(charge.totalGas)/float64(totals.totalGas)*100), }) } tw.Write(map[string]interface{}{ @@ -462,7 +442,7 @@ func statsTable(out io.Writer, trace types.ExecutionTrace, recurse bool) error { "S%": "100.00", "Compute Gas": totals.computeGas, "C%": "100.00", - "Total Gas": totals.storageGas + totals.computeGas, + "Total Gas": totals.totalGas, "T%": "100.00", }) return tw.Flush(out, tablewriter.WithBorders()) @@ -485,12 +465,72 @@ func gasTracesPerCall(inTrace types.ExecutionTrace) types.ExecutionTrace { Name: fmt.Sprintf("#%d %s", count, name), ComputeGas: totals.computeGas, StorageGas: totals.storageGas, + TotalGas: totals.totalGas, }) count++ for _, subtrace := range trace.Subcalls { - accum(name+"➜"+subtrace.Msg.To.String(), subtrace) + accum(fmt.Sprintf("%s➜%s:%d", name, truncateString(subtrace.Msg.To.String(), 12), subtrace.Msg.Method), subtrace) } } - accum(inTrace.Msg.To.String(), inTrace) + accum(truncateString(inTrace.Msg.To.String(), 12), inTrace) return outTrace } + +func printGasStats(out io.Writer, trace types.ExecutionTrace) error { + if err := printItemisedGasChargesPerCall(out, trace); err != nil { + return err + } + if len(trace.Subcalls) > 0 { + if err := printTotalItemisedGasCharges(out, trace); err != nil { + return err + } + if err := printTotalGasChargesPerCall(out, trace); err != nil { + return err + } + } + return nil +} + +func printItemisedGasChargesPerCall(out io.Writer, trace types.ExecutionTrace) error { + var printTrace func(descPfx string, trace types.ExecutionTrace) error + printTrace = func(descPfx string, trace types.ExecutionTrace) error { + typ := "Message" + if descPfx != "" { + typ = "Subcall" + } + _, _ = fmt.Fprintln(out, color.New(color.Bold).Sprint( + fmt.Sprintf("%s (%s%s:%d) gas charges:", typ, descPfx, truncateString(trace.Msg.To.String(), 12), trace.Msg.Method)), + ) + if err := statsTable(out, trace, false); err != nil { + return err + } + for _, subtrace := range trace.Subcalls { + _, _ = fmt.Fprintln(out) + if err := printTrace(descPfx+truncateString(trace.Msg.To.String(), 12)+"➜", subtrace); err != nil { + return err + } + } + return nil + } + return printTrace("", trace) +} + +func printTotalItemisedGasCharges(out io.Writer, trace types.ExecutionTrace) error { + _, _ = fmt.Fprintln(out) + _, _ = fmt.Fprintln(out, color.New(color.Bold).Sprint("Total gas charges:")) + return statsTable(out, trace, true) +} + +func printTotalGasChargesPerCall(out io.Writer, trace types.ExecutionTrace) error { + perCallTrace := gasTracesPerCall(trace) + _, _ = fmt.Fprintln(out) + _, _ = fmt.Fprintln(out, color.New(color.Bold).Sprint("Gas charges per call:")) + return statsTable(out, perCallTrace, false) +} + +func truncateString(str string, length int) string { + if len(str) <= length { + return str + } + return str[:length] + "…" +} diff --git a/itests/kit/init.go b/itests/kit/init.go index 9397c53a218..5fb844cf1bf 100644 --- a/itests/kit/init.go +++ b/itests/kit/init.go @@ -14,7 +14,9 @@ import ( ) func init() { - _ = logging.SetLogLevel("*", "INFO") + if _, set := os.LookupEnv("GOLOG_LOG_LEVEL"); !set { + _ = logging.SetLogLevel("*", "INFO") + } // These values mimic the values set in the builtin-actors when configured to use the "testing" network. Specifically: // - All proof types. diff --git a/node/impl/eth/api.go b/node/impl/eth/api.go index b9a5159a3e9..e0b49cf96f5 100644 --- a/node/impl/eth/api.go +++ b/node/impl/eth/api.go @@ -71,7 +71,7 @@ type StateManager interface { ExecutionTrace(ctx context.Context, ts *types.TipSet) (cid.Cid, []*api.InvocResult, error) Call(ctx context.Context, msg *types.Message, ts *types.TipSet) (*api.InvocResult, error) CallWithGas(ctx context.Context, msg *types.Message, priorMsgs []types.ChainMsg, ts *types.TipSet, applyTsMessages bool) (*api.InvocResult, error) - ApplyOnStateWithGas(ctx context.Context, stateCid cid.Cid, msg *types.Message, ts *types.TipSet) (*api.InvocResult, error) + ApplyOnStateWithGas(ctx context.Context, stateCid cid.Cid, msg *types.Message, priorMsgs []types.ChainMsg, ts *types.TipSet) (*api.InvocResult, error) HasExpensiveForkBetween(parent, height abi.ChainEpoch) bool } diff --git a/node/impl/eth/gas.go b/node/impl/eth/gas.go index db0c848f8b9..1af120555e1 100644 --- a/node/impl/eth/gas.go +++ b/node/impl/eth/gas.go @@ -282,7 +282,7 @@ func (e *ethGas) applyMessage(ctx context.Context, msg *types.Message, tsk types if err != nil { return nil, xerrors.Errorf("cannot get tipset state: %w", err) } - res, err = e.stateManager.ApplyOnStateWithGas(ctx, st, msg, ts) + res, err = e.stateManager.ApplyOnStateWithGas(ctx, st, msg, nil, ts) if err != nil { return nil, xerrors.Errorf("ApplyWithGasOnState failed: %w", err) }