diff --git a/src/HashedObject.cpp b/src/HashedObject.cpp index 8c9ef0ac7c..9dc7e6e92c 100644 --- a/src/HashedObject.cpp +++ b/src/HashedObject.cpp @@ -37,7 +37,6 @@ bool HashedObjectStore::store(HashedObjectType type, uint32 index, t.detach(); } } - Log(lsTRACE) << "HOS: " << hash.GetHex() << " store: deferred"; return true; } diff --git a/src/LedgerAcquire.cpp b/src/LedgerAcquire.cpp index 16cc1abe4f..bc065606ef 100644 --- a/src/LedgerAcquire.cpp +++ b/src/LedgerAcquire.cpp @@ -147,27 +147,22 @@ void LedgerAcquire::trigger(Peer::pointer peer) #ifdef LA_DEBUG if(peer) Log(lsTRACE) << "Trigger acquiring ledger " << mHash.GetHex() << " from " << peer->getIP(); else Log(lsTRACE) << "Trigger acquiring ledger " << mHash.GetHex(); - Log(lsTRACE) << "complete=" << mComplete << " failed=" << mFailed; - Log(lsTRACE) << "base=" << mHaveBase << " tx=" << mHaveTransactions << " as=" << mHaveState; + if (mComplete || mFailed) + Log(lsTRACE) << "complete=" << mComplete << " failed=" << mFailed; + else + Log(lsTRACE) << "base=" << mHaveBase << " tx=" << mHaveTransactions << " as=" << mHaveState; #endif if (!mHaveBase) { -#ifdef LA_DEBUG - Log(lsTRACE) << "need base"; -#endif newcoin::TMGetLedger tmGL; tmGL.set_ledgerhash(mHash.begin(), mHash.size()); tmGL.set_itype(newcoin::liBASE); *(tmGL.add_nodeids()) = SHAMapNode().getRawString(); - if (peer) - { - sendRequest(tmGL, peer); - return; - } - else sendRequest(tmGL); + sendRequest(tmGL, peer); + return; // Cannot go on without base } - if (mHaveBase && !mHaveTransactions) + if (!mHaveTransactions) { #ifdef LA_DEBUG Log(lsTRACE) << "need tx"; @@ -180,12 +175,7 @@ void LedgerAcquire::trigger(Peer::pointer peer) tmGL.set_ledgerseq(mLedger->getLedgerSeq()); tmGL.set_itype(newcoin::liTX_NODE); *(tmGL.add_nodeids()) = SHAMapNode().getRawString(); - if (peer) - { - sendRequest(tmGL, peer); - return; - } - sendRequest(tmGL); + sendRequest(tmGL, peer); } else { @@ -199,7 +189,8 @@ void LedgerAcquire::trigger(Peer::pointer peer) else { mHaveTransactions = true; - if (mHaveState) mComplete = true; + if (mHaveState) + mComplete = true; } } else @@ -210,17 +201,12 @@ void LedgerAcquire::trigger(Peer::pointer peer) tmGL.set_itype(newcoin::liTX_NODE); for (std::vector::iterator it = nodeIDs.begin(); it != nodeIDs.end(); ++it) *(tmGL.add_nodeids()) = it->getRawString(); - if (peer) - { - sendRequest(tmGL, peer); - return; - } - sendRequest(tmGL); + sendRequest(tmGL, peer); } } } - if (mHaveBase && !mHaveState) + if (!mHaveState) { #ifdef LA_DEBUG Log(lsTRACE) << "need as"; @@ -233,12 +219,7 @@ void LedgerAcquire::trigger(Peer::pointer peer) tmGL.set_ledgerseq(mLedger->getLedgerSeq()); tmGL.set_itype(newcoin::liAS_NODE); *(tmGL.add_nodeids()) = SHAMapNode().getRawString(); - if (peer) - { - sendRequest(tmGL, peer); - return; - } - sendRequest(tmGL); + sendRequest(tmGL, peer); } else { @@ -252,7 +233,8 @@ void LedgerAcquire::trigger(Peer::pointer peer) else { mHaveState = true; - if (mHaveTransactions) mComplete = true; + if (mHaveTransactions) + mComplete = true; } } else @@ -263,12 +245,7 @@ void LedgerAcquire::trigger(Peer::pointer peer) tmGL.set_itype(newcoin::liAS_NODE); for (std::vector::iterator it = nodeIDs.begin(); it != nodeIDs.end(); ++it) *(tmGL.add_nodeids()) = it->getRawString(); - if (peer) - { - sendRequest(tmGL, peer); - return; - } - sendRequest(tmGL); + sendRequest(tmGL, peer); } } } @@ -281,7 +258,10 @@ void LedgerAcquire::trigger(Peer::pointer peer) void PeerSet::sendRequest(const newcoin::TMGetLedger& tmGL, Peer::pointer peer) { - peer->sendPacket(boost::make_shared(tmGL, newcoin::mtGET_LEDGER)); + if (!peer) + sendRequest(tmGL); + else + peer->sendPacket(boost::make_shared(tmGL, newcoin::mtGET_LEDGER)); } void PeerSet::sendRequest(const newcoin::TMGetLedger& tmGL) diff --git a/src/LedgerConsensus.cpp b/src/LedgerConsensus.cpp index 0d53af7b83..440be88eeb 100644 --- a/src/LedgerConsensus.cpp +++ b/src/LedgerConsensus.cpp @@ -427,9 +427,10 @@ void LedgerConsensus::stateEstablish() updateOurPositions(); if (!mHaveCloseTimeConsensus) { - Log(lsINFO) << "No close time consensus"; + if (haveConsensus()) + Log(lsINFO) << "We have TX consensus but not CT consensus"; } - else if (haveConsensus()) + if (haveConsensus()) { Log(lsINFO) << "Converge cutoff"; mState = lcsFINISHED; @@ -455,11 +456,10 @@ void LedgerConsensus::timerEntry() if (!mHaveCorrectLCL) { checkLCL(); - Log(lsINFO) << "Checking for consensus ledger " << mPrevLedgerHash.GetHex(); Ledger::pointer consensus = theApp->getMasterLedger().getLedgerByHash(mPrevLedgerHash); if (consensus) { - Log(lsINFO) << "We have acquired the consensus ledger"; + Log(lsINFO) << "Acquired the consensus ledger " << mPrevLedgerHash.GetHex(); if (theApp->getMasterLedger().getClosedLedger()->getHash() != mPrevLedgerHash) theApp->getOPs().switchLastClosedLedger(consensus, true); mPreviousLedger = consensus; @@ -468,7 +468,8 @@ void LedgerConsensus::timerEntry() mPreviousLedger->getCloseResolution(), mPreviousLedger->getCloseAgree(), mPreviousLedger->getLedgerSeq() + 1); } - else Log(lsINFO) << "We still don't have it"; + else + Log(lsINFO) << "Need consensus ledger " << mPrevLedgerHash.GetHex(); } mCurrentMSeconds = (mCloseTime == 0) ? 0 : @@ -487,7 +488,6 @@ void LedgerConsensus::timerEntry() void LedgerConsensus::updateOurPositions() { - Log(lsINFO) << "Updating our positions"; bool changes = false; SHAMap::pointer ourPosition; std::vector addedTx, removedTx; @@ -566,8 +566,7 @@ void LedgerConsensus::updateOurPositions() mOurPosition->changePosition(newHash, closeTime); if (mProposing) propose(addedTx, removedTx); mapComplete(newHash, ourPosition, false); - Log(lsINFO) << "We change our position to " << newHash.GetHex(); - Log(lsINFO) << " Close time " << closeTime; + Log(lsINFO) << "Position change: CTime " << closeTime << ", tx " << newHash.GetHex(); } } diff --git a/src/SNTPClient.cpp b/src/SNTPClient.cpp index d84cfa3c57..ffd2eecbe9 100644 --- a/src/SNTPClient.cpp +++ b/src/SNTPClient.cpp @@ -8,6 +8,8 @@ #include "utils.h" #include "Log.h" +// #define SNTP_DEBUG + static uint8_t SNTPQueryData[48] = { 0x1B,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0, 0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0 @@ -86,21 +88,24 @@ void SNTPClient::receivePacket(const boost::system::error_code& error, std::size if (!error) { boost::mutex::scoped_lock sl(mLock); +#ifdef SNTP_DEBUG Log(lsTRACE) << "SNTP: Packet from " << mReceiveEndpoint; +#endif std::map::iterator query = mQueries.find(mReceiveEndpoint); if (query == mQueries.end()) - Log(lsDEBUG) << "SNTP: Reply found without matching query"; + Log(lsDEBUG) << "SNTP: Reply from " << mReceiveEndpoint << " found without matching query"; else if (query->second.mReceivedReply) - Log(lsDEBUG) << "SNTP: Duplicate response to query"; + Log(lsDEBUG) << "SNTP: Duplicate response from " << mReceiveEndpoint; else { query->second.mReceivedReply = true; if (time(NULL) > (query->second.mLocalTimeSent + 1)) - Log(lsWARNING) << "SNTP: Late response"; + Log(lsWARNING) << "SNTP: Late response from " << mReceiveEndpoint; else if (bytes_xferd < 48) - Log(lsWARNING) << "SNTP: Short reply (" << bytes_xferd << ") " << mReceiveBuffer.size(); + Log(lsWARNING) << "SNTP: Short reply from " << mReceiveEndpoint + << " (" << bytes_xferd << ") " << mReceiveBuffer.size(); else if (reinterpret_cast(&mReceiveBuffer[0])[NTP_OFF_ORGTS_FRAC] != query->second.mQueryNonce) - Log(lsWARNING) << "SNTP: Reply had wrong nonce"; + Log(lsWARNING) << "SNTP: Reply from " << mReceiveEndpoint << "had wrong nonce"; else processReply(); } @@ -128,12 +133,12 @@ void SNTPClient::processReply() if ((info >> 30) == 3) { - Log(lsINFO) << "SNTP: Alarm condition"; + Log(lsINFO) << "SNTP: Alarm condition " << mReceiveEndpoint; return; } if ((stratum == 0) || (stratum > 14)) { - Log(lsINFO) << "SNTP: Unreasonable stratum"; + Log(lsINFO) << "SNTP: Unreasonable stratum (" << stratum << ") from " << mReceiveEndpoint; return; } @@ -161,7 +166,8 @@ void SNTPClient::processReply() if ((mOffset == -1) || (mOffset == 1)) // small corrections likely do more harm than good mOffset = 0; - Log(lsTRACE) << "SNTP: Offset is " << timev << ", new system offset is " << mOffset; + if (timev || mOffset) + Log(lsTRACE) << "SNTP: Offset is " << timev << ", new system offset is " << mOffset; } void SNTPClient::timerEntry(const boost::system::error_code& error) @@ -234,6 +240,8 @@ bool SNTPClient::doQuery() mResolver.async_resolve(query, boost::bind(&SNTPClient::resolveComplete, this, boost::asio::placeholders::error, boost::asio::placeholders::iterator)); +#ifdef SNTP_DEBUG Log(lsTRACE) << "SNTP: Resolve pending for " << best->first; +#endif return true; }