From 8f280f3466e9edcdc5bba5324f287ad3f21522b8 Mon Sep 17 00:00:00 2001 From: Alexander Block Date: Mon, 25 Mar 2019 05:48:18 +0100 Subject: [PATCH] Split "llmq" debug category into "llmq", "llmq-dkg" and "llmq-sigs" (#2799) * Use llmq-sig log category for CSigSharesManager * Use llmq-dkg log category for DKG related logging --- src/init.cpp | 2 +- src/llmq/quorums_dkgsession.cpp | 2 +- src/llmq/quorums_dkgsessionhandler.cpp | 6 ++-- src/llmq/quorums_signing_shares.cpp | 40 +++++++++++++------------- src/util.cpp | 2 ++ 5 files changed, 27 insertions(+), 25 deletions(-) diff --git a/src/init.cpp b/src/init.cpp index aead7ccae8133..e5929bd727f2e 100644 --- a/src/init.cpp +++ b/src/init.cpp @@ -553,7 +553,7 @@ std::string HelpMessage(HelpMessageMode mode) strUsage += HelpMessageOpt("-watchquorums=", strprintf("Watch and validate quorum communication (default: %u)", llmq::DEFAULT_WATCH_QUORUMS)); } std::string debugCategories = "addrman, alert, bench, cmpctblock, coindb, db, http, leveldb, libevent, lock, mempool, mempoolrej, net, proxy, prune, rand, reindex, rpc, selectcoins, tor, zmq, " - "dash (or specifically: chainlocks, gobject, instantsend, keepass, llmq, masternode, mnpayments, mnsync, privatesend, spork)"; // Don't translate these and qt below + "dash (or specifically: chainlocks, gobject, instantsend, keepass, llmq, llmq-dkg, llmq-sigs, masternode, mnpayments, mnsync, privatesend, spork)"; // Don't translate these and qt below if (mode == HMM_BITCOIN_QT) debugCategories += ", qt"; strUsage += HelpMessageOpt("-debug=", strprintf(_("Output debugging information (default: %u, supplying is optional)"), 0) + ". " + diff --git a/src/llmq/quorums_dkgsession.cpp b/src/llmq/quorums_dkgsession.cpp index d439485307965..58a56adec04d8 100644 --- a/src/llmq/quorums_dkgsession.cpp +++ b/src/llmq/quorums_dkgsession.cpp @@ -39,7 +39,7 @@ CDKGLogger::CDKGLogger(const CDKGSession& _quorumDkg, const std::string& _func) } CDKGLogger::CDKGLogger(Consensus::LLMQType _llmqType, const uint256& _quorumHash, int _height, bool _areWeMember, const std::string& _func) : - CBatchedLogger("llmq", strprintf("QuorumDKG(type=%d, height=%d, member=%d, func=%s)", _llmqType, _height, _areWeMember, _func)) + CBatchedLogger("llmq-dkg", strprintf("QuorumDKG(type=%d, height=%d, member=%d, func=%s)", _llmqType, _height, _areWeMember, _func)) { } diff --git a/src/llmq/quorums_dkgsessionhandler.cpp b/src/llmq/quorums_dkgsessionhandler.cpp index 01163ce472278..4cd69f4b70451 100644 --- a/src/llmq/quorums_dkgsessionhandler.cpp +++ b/src/llmq/quorums_dkgsessionhandler.cpp @@ -45,7 +45,7 @@ void CDKGPendingMessages::PushPendingMessage(NodeId from, CDataStream& vRecv) LOCK2(cs_main, cs); if (!seenMessages.emplace(hash).second) { - LogPrint("llmq", "CDKGPendingMessages::%s -- already seen %s, peer=%d", __func__, from); + LogPrint("llmq-dkg", "CDKGPendingMessages::%s -- already seen %s, peer=%d", __func__, from); return; } @@ -482,7 +482,7 @@ void CDKGSessionHandler::HandleDKGRound() for (const auto& c : connections) { debugMsg += strprintf(" %s\n", c.first.ToString(false)); } - LogPrint("llmq", debugMsg); + LogPrint("llmq-dkg", debugMsg); g_connman->AddMasternodeQuorumNodes(params.type, curQuorumHash, connections); } } @@ -541,7 +541,7 @@ void CDKGSessionHandler::PhaseHandlerThread() status.aborted = true; return true; }); - LogPrint("llmq", "CDKGSessionHandler::%s -- aborted current DKG session for llmq=%s\n", __func__, params.name); + LogPrint("llmq-dkg", "CDKGSessionHandler::%s -- aborted current DKG session for llmq=%s\n", __func__, params.name); } } } diff --git a/src/llmq/quorums_signing_shares.cpp b/src/llmq/quorums_signing_shares.cpp index bb3fd2d863d44..73433d2105fcb 100644 --- a/src/llmq/quorums_signing_shares.cpp +++ b/src/llmq/quorums_signing_shares.cpp @@ -303,12 +303,12 @@ bool CSigSharesManager::ProcessMessageSigSesAnn(CNode* pfrom, const CSigSesAnn& return false; } - LogPrint("llmq", "CSigSharesManager::%s -- ann={%s}, node=%d\n", __func__, ann.ToString(), pfrom->id); + LogPrint("llmq-sigs", "CSigSharesManager::%s -- ann={%s}, node=%d\n", __func__, ann.ToString(), pfrom->id); auto quorum = quorumManager->GetQuorum(llmqType, ann.quorumHash); if (!quorum) { // TODO should we ban here? - LogPrint("llmq", "CSigSharesManager::%s -- quorum %s not found, node=%d\n", __func__, + LogPrint("llmq-sigs", "CSigSharesManager::%s -- quorum %s not found, node=%d\n", __func__, ann.quorumHash.ToString(), pfrom->id); return true; // let's still try other announcements from the same message } @@ -353,12 +353,12 @@ bool CSigSharesManager::ProcessMessageSigSharesInv(CNode* pfrom, const CSigShare return true; } - LogPrint("llmq", "CSigSharesManager::%s -- signHash=%s, inv={%s}, node=%d\n", __func__, + LogPrint("llmq-sigs", "CSigSharesManager::%s -- signHash=%s, inv={%s}, node=%d\n", __func__, sessionInfo.signHash.ToString(), inv.ToString(), pfrom->id); if (sessionInfo.quorum->quorumVvec == nullptr) { // TODO we should allow to ask other nodes for the quorum vvec if we missed it in the DKG - LogPrint("llmq", "CSigSharesManager::%s -- we don't have the quorum vvec for %s, not requesting sig shares. node=%d\n", __func__, + LogPrint("llmq-sigs", "CSigSharesManager::%s -- we don't have the quorum vvec for %s, not requesting sig shares. node=%d\n", __func__, sessionInfo.quorumHash.ToString(), pfrom->id); return true; } @@ -390,7 +390,7 @@ bool CSigSharesManager::ProcessMessageGetSigShares(CNode* pfrom, const CSigShare return true; } - LogPrint("llmq", "CSigSharesManager::%s -- signHash=%s, inv={%s}, node=%d\n", __func__, + LogPrint("llmq-sigs", "CSigSharesManager::%s -- signHash=%s, inv={%s}, node=%d\n", __func__, sessionInfo.signHash.ToString(), inv.ToString(), pfrom->id); LOCK(cs); @@ -444,7 +444,7 @@ bool CSigSharesManager::ProcessMessageBatchedSigShares(CNode* pfrom, const CBatc } } - LogPrint("llmq", "CSigSharesManager::%s -- signHash=%s, shares=%d, new=%d, inv={%s}, node=%d\n", __func__, + LogPrint("llmq-sigs", "CSigSharesManager::%s -- signHash=%s, shares=%d, new=%d, inv={%s}, node=%d\n", __func__, sessionInfo.signHash.ToString(), batchedSigShares.sigShares.size(), sigShares.size(), batchedSigShares.ToInvString(), pfrom->id); if (sigShares.empty()) { @@ -473,7 +473,7 @@ bool CSigSharesManager::PreVerifyBatchedSigShares(NodeId nodeId, const CSigShare } if (session.quorum->quorumVvec == nullptr) { // TODO we should allow to ask other nodes for the quorum vvec if we missed it in the DKG - LogPrint("llmq", "CSigSharesManager::%s -- we don't have the quorum vvec for %s, no verification possible. node=%d\n", __func__, + LogPrint("llmq-sigs", "CSigSharesManager::%s -- we don't have the quorum vvec for %s, no verification possible. node=%d\n", __func__, session.quorumHash.ToString(), nodeId); return false; } @@ -614,7 +614,7 @@ bool CSigSharesManager::ProcessPendingSigShares(CConnman& connman) batchVerifier.Verify(); verifyTimer.stop(); - LogPrint("llmq", "CSigSharesManager::%s -- verified sig shares. count=%d, vt=%d, nodes=%d\n", __func__, verifyCount, verifyTimer.count(), sigSharesByNodes.size()); + LogPrint("llmq-sigs", "CSigSharesManager::%s -- verified sig shares. count=%d, vt=%d, nodes=%d\n", __func__, verifyCount, verifyTimer.count(), sigSharesByNodes.size()); for (auto& p : sigSharesByNodes) { auto nodeId = p.first; @@ -649,7 +649,7 @@ void CSigSharesManager::ProcessPendingSigSharesFromNode(NodeId nodeId, } t.stop(); - LogPrint("llmq", "CSigSharesManager::%s -- processed sigShare batch. shares=%d, time=%d, node=%d\n", __func__, + LogPrint("llmq-sigs", "CSigSharesManager::%s -- processed sigShare batch. shares=%d, time=%d, node=%d\n", __func__, sigShares.size(), t.count(), nodeId); } @@ -754,7 +754,7 @@ void CSigSharesManager::TryRecoverSig(const CQuorumCPtr& quorum, const uint256& return; } - LogPrint("llmq", "CSigSharesManager::%s -- recovered signature. id=%s, msgHash=%s, time=%d\n", __func__, + LogPrint("llmq-sigs", "CSigSharesManager::%s -- recovered signature. id=%s, msgHash=%s, time=%d\n", __func__, id.ToString(), msgHash.ToString(), t.count()); CRecoveredSig rs; @@ -805,7 +805,7 @@ void CSigSharesManager::CollectSigSharesToRequest(std::unordered_map= SIG_SHARE_REQUEST_TIMEOUT) { // timeout while waiting for this one, so retry it with another node - LogPrint("llmq", "CSigSharesManager::CollectSigSharesToRequest -- timeout while waiting for %s-%d, node=%d\n", + LogPrint("llmq-sigs", "CSigSharesManager::CollectSigSharesToRequest -- timeout while waiting for %s-%d, node=%d\n", k.first.ToString(), k.second, nodeId); return true; } @@ -840,7 +840,7 @@ void CSigSharesManager::CollectSigSharesToRequest(std::unordered_mapsecond >= SIG_SHARE_REQUEST_TIMEOUT && nodeId != p->first) { // other node timed out, re-request from this node - LogPrint("llmq", "CSigSharesManager::%s -- other node timeout while waiting for %s-%d, re-request from=%d, node=%d\n", __func__, + LogPrint("llmq-sigs", "CSigSharesManager::%s -- other node timeout while waiting for %s-%d, re-request from=%d, node=%d\n", __func__, k.first.ToString(), k.second, nodeId, p->first); } else { continue; @@ -1043,7 +1043,7 @@ bool CSigSharesManager::SendMessages() std::vector msgs; msgs.reserve(it1->second.size()); for (auto& sigSesAnn : it1->second) { - LogPrint("llmq", "CSigSharesManager::SendMessages -- QSIGSESANN signHash=%s, sessionId=%d, node=%d\n", + LogPrint("llmq-sigs", "CSigSharesManager::SendMessages -- QSIGSESANN signHash=%s, sessionId=%d, node=%d\n", CLLMQUtils::BuildSignHash(sigSesAnn).ToString(), sigSesAnn.sessionId, pnode->id); msgs.emplace_back(sigSesAnn); if (msgs.size() == MAX_MSGS_CNT_QSIGSESANN) { @@ -1063,7 +1063,7 @@ bool CSigSharesManager::SendMessages() std::vector msgs; for (auto& p : it->second) { assert(p.second.CountSet() != 0); - LogPrint("llmq", "CSigSharesManager::SendMessages -- QGETSIGSHARES signHash=%s, inv={%s}, node=%d\n", + LogPrint("llmq-sigs", "CSigSharesManager::SendMessages -- QGETSIGSHARES signHash=%s, inv={%s}, node=%d\n", p.first.ToString(), p.second.ToString(), pnode->id); msgs.emplace_back(std::move(p.second)); if (msgs.size() == MAX_MSGS_CNT_QGETSIGSHARES) { @@ -1084,7 +1084,7 @@ bool CSigSharesManager::SendMessages() std::vector msgs; for (auto& p : jt->second) { assert(!p.second.sigShares.empty()); - LogPrint("llmq", "CSigSharesManager::SendMessages -- QBSIGSHARES signHash=%s, inv={%s}, node=%d\n", + LogPrint("llmq-sigs", "CSigSharesManager::SendMessages -- QBSIGSHARES signHash=%s, inv={%s}, node=%d\n", p.first.ToString(), p.second.ToInvString(), pnode->id); if (totalSigsCount + p.second.sigShares.size() > MAX_MSGS_TOTAL_BATCHED_SIGS) { g_connman->PushMessage(pnode, msgMaker.Make(NetMsgType::QBSIGSHARES, msgs), false); @@ -1107,7 +1107,7 @@ bool CSigSharesManager::SendMessages() std::vector msgs; for (auto& p : kt->second) { assert(p.second.CountSet() != 0); - LogPrint("llmq", "CSigSharesManager::SendMessages -- QSIGSHARESINV signHash=%s, inv={%s}, node=%d\n", + LogPrint("llmq-sigs", "CSigSharesManager::SendMessages -- QSIGSHARESINV signHash=%s, inv={%s}, node=%d\n", p.first.ToString(), p.second.ToString(), pnode->id); msgs.emplace_back(std::move(p.second)); if (msgs.size() == MAX_MSGS_CNT_QSIGSHARESINV) { @@ -1249,10 +1249,10 @@ void CSigSharesManager::Cleanup() } } - LogPrint("llmq", "CSigSharesManager::%s -- signing session timed out. signHash=%s, id=%s, msgHash=%s, sigShareCount=%d, missingMembers=%s\n", __func__, + LogPrint("llmq-sigs", "CSigSharesManager::%s -- signing session timed out. signHash=%s, id=%s, msgHash=%s, sigShareCount=%d, missingMembers=%s\n", __func__, signHash.ToString(), oneSigShare.id.ToString(), oneSigShare.msgHash.ToString(), count, strMissingMembers); } else { - LogPrint("llmq", "CSigSharesManager::%s -- signing session timed out. signHash=%s, sigShareCount=%d\n", __func__, + LogPrint("llmq-sigs", "CSigSharesManager::%s -- signing session timed out. signHash=%s, sigShareCount=%d\n", __func__, signHash.ToString(), count); } RemoveSigSharesForSession(signHash); @@ -1408,7 +1408,7 @@ void CSigSharesManager::Sign(const CQuorumCPtr& quorum, const uint256& id, const CBLSSecretKey skShare = quorum->GetSkShare(); if (!skShare.IsValid()) { - LogPrint("llmq", "CSigSharesManager::%s -- we don't have our skShare for quorum %s\n", __func__, quorum->quorumHash.ToString()); + LogPrint("llmq-sigs", "CSigSharesManager::%s -- we don't have our skShare for quorum %s\n", __func__, quorum->quorumHash.ToString()); return; } @@ -1435,7 +1435,7 @@ void CSigSharesManager::Sign(const CQuorumCPtr& quorum, const uint256& id, const sigShare.UpdateKey(); - LogPrint("llmq", "CSigSharesManager::%s -- signed sigShare. signHash=%s, id=%s, msgHash=%s, time=%s\n", __func__, + LogPrint("llmq-sigs", "CSigSharesManager::%s -- signed sigShare. signHash=%s, id=%s, msgHash=%s, time=%s\n", __func__, signHash.ToString(), sigShare.id.ToString(), sigShare.msgHash.ToString(), t.count()); ProcessSigShare(-1, sigShare, *g_connman, quorum); } diff --git a/src/util.cpp b/src/util.cpp index f9bb9f5575f8f..5977476252bf0 100644 --- a/src/util.cpp +++ b/src/util.cpp @@ -286,6 +286,8 @@ bool LogAcceptCategory(const char* category) ptrCategory->insert(std::string("instantsend")); ptrCategory->insert(std::string("keepass")); ptrCategory->insert(std::string("llmq")); + ptrCategory->insert(std::string("llmq-dkg")); + ptrCategory->insert(std::string("llmq-sigs")); ptrCategory->insert(std::string("masternode")); ptrCategory->insert(std::string("mnpayments")); ptrCategory->insert(std::string("mnsync"));