Reduce log chattiness.

Acquire transaction and state trees in parallel.
This commit is contained in:
JoelKatz
2012-08-07 03:32:58 -07:00
parent 03e8104f62
commit 86b9597ddd
4 changed files with 43 additions and 57 deletions

View File

@@ -37,7 +37,6 @@ bool HashedObjectStore::store(HashedObjectType type, uint32 index,
t.detach();
}
}
Log(lsTRACE) << "HOS: " << hash.GetHex() << " store: deferred";
return true;
}

View File

@@ -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<SHAMapNode>::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<SHAMapNode>::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<PackedMessage>(tmGL, newcoin::mtGET_LEDGER));
if (!peer)
sendRequest(tmGL);
else
peer->sendPacket(boost::make_shared<PackedMessage>(tmGL, newcoin::mtGET_LEDGER));
}
void PeerSet::sendRequest(const newcoin::TMGetLedger& tmGL)

View File

@@ -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<uint256> 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();
}
}

View File

@@ -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<boost::asio::ip::udp::endpoint, SNTPQuery>::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<uint32*>(&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;
}