Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: Compiler-Enforced Logging of All Miner Transaction Outcomes #2821

Closed
wants to merge 18 commits into from

Conversation

gregorycoppola
Copy link
Contributor

@gregorycoppola gregorycoppola commented Aug 25, 2021

Description

The goal of this PR is to provide more robust logging for the miner, so that:

  1. all outcomes for mining a transaction are logged, and
  2. we make it as "hard as possible" to neglect to log an outcome

To do this, we use the type system. MemPoolDB::iterate_candidates will now require to be given a new kind of object called TransactionResult.

There are three kinds of TransactionResult: TransactionSuccess, TransactionError and TransactionSkipped.

In order to create one of these types, the user should use a factory function, which will do the logging as a side-effect.

The logs look like this:

# Error
WARN [1629921614.330687] [src/chainstate/stacks/db/queryable_logging.rs:31] [relayer] Transaction outcome for tx=491493d01fc8c0f21f0891ad7c378bfb9c7b83142524f3320ea609e6b5cffa90: failed with error: Bad nonce: origin account SP3WV3VC6GM1WF215SDHP0MESQ3BNXHB1N6TPB70S nonce of tx 491493d01fc8c0f21f0891ad7c378bfb9c7b83142524f3320ea609e6b5cffa90 is 9656 (expected 9680)

# Success
INFO [1629921614.162689] [src/chainstate/stacks/db/queryable_logging.rs:25] [relayer] Transaction outcome for tx=d2fa7f52421891a6e0f0c5c1a6a7db71e812637b4b12ae1e49524c8656c48b89: successfully processed.

Also, the different kinds of events are collected, and can be used for further logging later.

Testing

I am running this in a local mock miner and observing the logs. We will also run this on Hiro's mock miner.

It doesn't really admit of unit tests right now, I think.

Limitations

It is currently still possible to create a TransactionResult without using the factory methods, and that would mean that nothing gets logged. I'm not sure if it's technically possible to force the user to use the factory methods the first time an object is created, while also allowing them to decompose and reassemble objects in match blocks in Rust.

@gregorycoppola gregorycoppola changed the base branch from master to develop August 25, 2021 19:15
@gregorycoppola
Copy link
Contributor Author

@jcnelson @kantai This code can use an architecture review of the API used and overall design.

Note that many old tests are failing. That's because I didn't change them yet. If we resolve the API issues, I can update the tests.

where
F: FnMut(Vec<MemPoolTxInfo>) -> Result<(), E>,
F: FnMut(MemPoolTxInfo) -> TransactionResult,
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note: iterate_candidate requires one TransactionResult at a time.

@gregorycoppola gregorycoppola changed the title feat: Compiler-Enforced Logging feat: Compiler-Enforced Logging of All Miner Transaction Outcomes Aug 25, 2021
@gregorycoppola gregorycoppola removed the request for review from zone117x August 25, 2021 20:53
mined_origin_nonces: &mut HashMap<StacksAddress, u64>,
mined_sponsor_nonces: &mut HashMap<StacksAddress, u64>,
invalidated_txs: &mut Vec<Txid>,
block_limit_hit: &mut BlockLimitFunction,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The fact that you have to pass so many &mut references to this method from the caller's scope suggests to me that this is not the right way factor this.

let transaction_result = StacksChainState::process_transaction(clarity_tx, tx, quiet);
match transaction_result {
TransactionResult::Success(TransactionSuccess { tx, fee, receipt }) => {
info!("Include tx";
Copy link
Member

@jcnelson jcnelson Sep 2, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why isn't this logging code in the queryable_logging.rs file? Same for the other long-winded structured logging calls below.

@@ -292,21 +304,37 @@ impl<'a> StacksMicroblockBuilder<'a> {
}

/// Mine the next transaction into a microblock.
/// Returns true/false if the transaction was/was not mined into this microblock.
///
/// This is a wrapper around `StacksChainState::process_transaction` that also checks certain
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

"Wrapper" is not really the right word here. The mine_next_transaction method creates a block by processing a sequence of transactions it pulls from the mempool. The inner call to StacksChainState::process_transaction is used to faithfully create the MARF trie for this block and calculate the MARF state root for the block header. This is not the same as being a wrapper, since mine_next_transaction is not meant to be used to process blocks.

Copy link
Member

@jcnelson jcnelson left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There are a couple of problems with this PR, but they're easily fixed.

First, it doesn't seem to actually be logging anything in a queryable way, beyond just grepping the log file. It does seem to send the structured transaction-mining results to the event observer either. Do you intend to add either of these things? If not -- if the point of this PR is just to change what the miner prints out -- then a lot of this PR can be dropped and consolidated into src/chainstate/stacks/miner.rs as simply a set of structured types to represent each of the miner's decisions for a transaction.

Second, all of the transaction outcomes we're interested in are the concern of the miner, not the block database. The files in src/chainstate/stacks/db should not be touched by this PR at all, since they are not related to deciding which transactions to include and which to skip. The miner, which uses the block database to produce blocks, should instead interpret the result of processing each transaction it considers for mining on its own before deciding how to record the outcome of considering it.

Copy link
Contributor Author

@gregorycoppola gregorycoppola left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm leaving some responses to the reviewers.

This PR has some bugs that I will leave comments on in the a new round.

src/chainstate/stacks/events.rs Show resolved Hide resolved
src/chainstate/stacks/db/queryable_logging.rs Show resolved Hide resolved
src/chainstate/stacks/db/transactions.rs Outdated Show resolved Hide resolved
src/chainstate/stacks/db/transactions.rs Outdated Show resolved Hide resolved
src/chainstate/stacks/events.rs Outdated Show resolved Hide resolved
@jcnelson jcnelson marked this pull request as draft October 4, 2021 15:15
@gregorycoppola
Copy link
Contributor Author

Closed for #2975

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants