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.

Sign up for GitHub

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

log: Adjust masternode staking output to fix issue #648 #1006

Merged
merged 11 commits into from
Mar 18, 2022
Merged

log: Adjust masternode staking output to fix issue #648 #1006

Show file tree
Hide file tree
Changes from 3 commits
Commits
Show all changes
11 commits
Select commit Hold shift + click to select a range
824a95c
Correct loglevel for ThreadStaker (#648)
chrizog Dec 28, 2021
3d2ca99
No debug level for MakeStake kernel found (#648)
chrizog Dec 28, 2021
4bdd206
Merge branch 'master' into feature/masternode-debug-log-output
prasannavl Dec 30, 2021
0b2fb14
Time throttled logging for staker (#648)
chrizog Jan 2, 2022
9ba2dbc
Merge branch 'master' into feature/masternode-debug-log-output
chrizog Jan 3, 2022
36b39c2
Merge branch 'master' into feature/masternode-debug-log-output
Jouzo Jan 5, 2022
1bb9436
Reverse logic in log time throttle filter
chrizog Jan 6, 2022
88e4b01
Simplify throttled logging
chrizog Feb 12, 2022
93cc358
Minor refactors
prasannavl Mar 18, 2022
a23ce82
Merge branch 'master' into feature/masternode-debug-log-output
prasannavl Mar 18, 2022
2a00b18
Merge branch 'master' into feature/masternode-debug-log-output
prasannavl Mar 18, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
18 changes: 9 additions & 9 deletions src/miner.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -793,7 +793,7 @@ namespace pos {
{
if (shouldIgnoreMint(ctxState.subNode, blockHeight, creationHeight, subNodesBlockTime, chainparams))
break;
LogPrint(BCLog::STAKING, "MakeStake: kernel found\n");
LogPrintf("MakeStake: kernel found\n");
Copy link
Member

Choose a reason for hiding this comment

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

How about we leave this to staking log, but instead tweak the other (LogPrint(BCLog::STAKING, "ThreadStaker: (%s) minted a block!\n", operatorName);) one to always print since that's more informative?


found = true;
break;
Expand All @@ -818,7 +818,7 @@ namespace pos {
{
if (shouldIgnoreMint(ctxState.subNode, blockHeight, creationHeight, subNodesBlockTime, chainparams))
break;
LogPrint(BCLog::STAKING, "MakeStake: kernel found\n");
LogPrintf("MakeStake: kernel found\n");
Copy link
Member

Choose a reason for hiding this comment

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

Same as above.


found = true;
break;
Expand Down Expand Up @@ -917,22 +917,22 @@ void ThreadStaker::operator()(std::vector<ThreadStaker::Args> args, CChainParams
}
static std::atomic<uint64_t> time{0};
if (GetSystemTimeInSeconds() - time > 120) {
LogPrintf("ThreadStaker: unlock wallet to start minting...\n");
LogPrint(BCLog::STAKING, "ThreadStaker: unlock wallet to start minting...\n");
Copy link
Member

Choose a reason for hiding this comment

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

I don't think we want to do this, as this is a user actionable item. If this log is being displayed, it's to prompt to user to either unlock, or remove gen=1 if the intent is not to stake.

time = GetSystemTimeInSeconds();
}
std::this_thread::sleep_for(std::chrono::milliseconds(100));
}
}

LogPrintf("ThreadStaker: started.\n");
LogPrint(BCLog::STAKING, "ThreadStaker: started.\n");
Copy link
Member

Choose a reason for hiding this comment

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

This is a single log message per staker. Better to leave an auditable log point.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Will change it back


while (!args.empty()) {
boost::this_thread::interruption_point();

while (fImporting || fReindex) {
boost::this_thread::interruption_point();

LogPrintf("ThreadStaker: waiting reindex...\n");
LogPrint(BCLog::STAKING, "ThreadStaker: waiting reindex...\n");
Copy link
Member

Choose a reason for hiding this comment

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

A better approach here would be use a throttled logger method for staking log, that throttles psuedo actionable info, like waiting reindex, waiting init.


std::this_thread::sleep_for(std::chrono::milliseconds(900));
}
Expand All @@ -951,23 +951,23 @@ void ThreadStaker::operator()(std::vector<ThreadStaker::Args> args, CChainParams
status = staker.stake(chainparams, arg);
}
if (status == Staker::Status::error) {
LogPrintf("ThreadStaker: (%s) terminated due to a staking error!\n", operatorName);
LogPrint(BCLog::STAKING, "ThreadStaker: (%s) terminated due to a staking error!\n", operatorName);
it = args.erase(it);
continue;
}
else if (status == Staker::Status::minted) {
LogPrintf("ThreadStaker: (%s) minted a block!\n", operatorName);
LogPrint(BCLog::STAKING, "ThreadStaker: (%s) minted a block!\n", operatorName);
nMinted[arg.operatorID]++;
}
else if (status == Staker::Status::initWaiting) {
LogPrintf("ThreadStaker: (%s) waiting init...\n", operatorName);
LogPrint(BCLog::STAKING, "ThreadStaker: (%s) waiting init...\n", operatorName);
Copy link
Member

Choose a reason for hiding this comment

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

How about instead, we keep the first 2 unchanged. However, for the waiting init throttle the log message so there's only one every few mins for waiting init if staking log isn't enabled.

}
else if (status == Staker::Status::stakeWaiting) {
LogPrint(BCLog::STAKING, "ThreadStaker: (%s) Staked, but no kernel found yet.\n", operatorName);
}
}
catch (const std::runtime_error &e) {
LogPrintf("ThreadStaker: (%s) runtime error: %s\n", e.what(), operatorName);
LogPrint(BCLog::STAKING, "ThreadStaker: (%s) runtime error: %s\n", e.what(), operatorName);
Copy link
Member

Choose a reason for hiding this comment

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

Again, I believe both of these should be clearly auditable points to verify what happened, either if orphaned txs are used somewhere prematurely or if there was an error.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Will change them back to LogPrintf as before 👍


// Could be failed TX in mempool, wipe mempool and allow loop to continue.
LOCK(cs_main);
Expand Down
2 changes: 1 addition & 1 deletion src/pos.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -204,7 +204,7 @@ boost::optional<std::string> CheckSignedBlock(const std::shared_ptr<CBlock>& pbl
if (!CheckProofOfStake(*(CBlockHeader*)pblock.get(), pindexPrev, chainparams.GetConsensus(), pcustomcsview.get()))
return {std::string{} + "proof-of-stake checking failed"};

LogPrint(BCLog::STAKING, "new proof-of-stake block found hash: %s\n", hashBlock.GetHex());
LogPrintf("New proof-of-stake block found hash: %s\n", hashBlock.GetHex());

// Found a solution
if (pblock->hashPrevBlock != pindexPrev->GetBlockHash())
Expand Down