diff --git a/emulator/blockchain.go b/emulator/blockchain.go index c9ee2c5f..80bbedfc 100644 --- a/emulator/blockchain.go +++ b/emulator/blockchain.go @@ -1935,13 +1935,13 @@ func (b *Blockchain) executeScheduledTransactions(blockContext fvm.Context) ([]* return results, err } pendingExecutionEvents := filterPendingExecutionEvents(sdkEvents, serviceAddress) - executeTxs, err := executeScheduledTransactions(pendingExecutionEvents, serviceAddress, parentID) + executeTxs, scheduledIDs, err := executeScheduledTransactions(pendingExecutionEvents, serviceAddress, parentID) if err != nil { return results, err } // execute scheduled transactions out-of-band - for _, tx := range executeTxs { + for idx, tx := range executeTxs { execSnapshot, execOutput, err := b.vm.Run( ctx, fvm.Transaction(&tx, uint32(len(b.pendingBlock.Transactions()))), @@ -1950,6 +1950,18 @@ func (b *Blockchain) executeScheduledTransactions(blockContext fvm.Context) ([]* if err != nil { return results, err } + + // Print scheduled transaction result (labeled), including app-level scheduled tx id + schedResult, err := convert.VMTransactionResultToEmulator(tx.ID(), execOutput) + if err != nil { + return results, err + } + appScheduledID := "" + if idx < len(scheduledIDs) { + appScheduledID = scheduledIDs[idx] + } + utils.PrintScheduledTransactionResult(&b.conf.ServerLogger, schedResult, appScheduledID) + b.pendingBlock.events = append(b.pendingBlock.events, execOutput.Events...) if err := b.pendingBlock.ledgerState.Merge(execSnapshot); err != nil { return results, err diff --git a/emulator/scheduled_transactions.go b/emulator/scheduled_transactions.go index 55f12279..5f3289d2 100644 --- a/emulator/scheduled_transactions.go +++ b/emulator/scheduled_transactions.go @@ -86,8 +86,10 @@ func executeScheduledTransactions( pendingExecutionEvents []flowsdk.Event, serviceAddress flowgo.Address, parentID flowgo.Identifier, -) ([]flowgo.TransactionBody, error) { - var transactions []flowgo.TransactionBody +) (transactions []flowgo.TransactionBody, scheduledIDs []string, err error) { + transactions = make([]flowgo.TransactionBody, 0) + scheduledIDs = make([]string, 0) + env := templates.Environment{ FlowTransactionSchedulerAddress: serviceAddress.HexWithPrefix(), } @@ -97,7 +99,7 @@ func executeScheduledTransactions( for _, e := range pendingExecutionEvents { id, _, limit, _, err := parseSchedulerPendingExecutionEvent(e, serviceAddress) if err != nil { - return nil, err + return nil, nil, err } txBuilder := flowgo.NewTransactionBodyBuilder(). @@ -110,13 +112,14 @@ func executeScheduledTransactions( tx, err := txBuilder.Build() if err != nil { - return nil, err + return nil, nil, err } transactions = append(transactions, *tx) + scheduledIDs = append(scheduledIDs, string(id)) } - return transactions, nil + return transactions, scheduledIDs, nil } // parseSchedulerPendingExecutionEvent parses flow event that is emitted during scheduler diff --git a/utils/logging.go b/utils/logging.go index 805ca12b..ab03c6bd 100644 --- a/utils/logging.go +++ b/utils/logging.go @@ -88,6 +88,44 @@ func PrintTransactionResult(logger *zerolog.Logger, result *types.TransactionRes } } +// PrintScheduledTransactionResult prints a clearly labeled log entry for scheduled transactions +// execute transactions so they can be easily distinguished from user transactions. +func PrintScheduledTransactionResult(logger *zerolog.Logger, result *types.TransactionResult, scheduledTxID string) { + if result.Succeeded() { + logger.Debug(). + Str("systemTxId", result.TransactionID.String()). + Str("scheduledTxId", scheduledTxID). + Uint64("computationUsed", result.ComputationUsed). + Uint64("memoryEstimate", result.MemoryEstimate). + Str("kind", "scheduled"). + Msg("⏱️ Scheduled transaction executed") + } else { + logger.Warn(). + Str("systemTxId", result.TransactionID.String()). + Str("scheduledTxId", scheduledTxID). + Uint64("computationUsed", result.ComputationUsed). + Uint64("memoryEstimate", result.MemoryEstimate). + Str("kind", "scheduled"). + Msg("❗ Scheduled transaction reverted") + } + + for _, event := range result.Events { + logger.Debug().Msgf( + "%s %s", + logPrefix("EVT-SYS", result.TransactionID, aurora.GreenFg), + event, + ) + } + + if !result.Succeeded() { + logger.Warn().Msgf( + "%s %s", + logPrefix("ERR-SYS", result.TransactionID, aurora.RedFg), + result.Error.Error(), + ) + } +} + func logPrefix(prefix string, id flowsdk.Identifier, color aurora.Color) string { prefix = aurora.Colorize(prefix, color|aurora.BoldFm).String() shortID := fmt.Sprintf("[%s]", id.String()[:6])