Skip to content

Commit

Permalink
Distinguish held from waiting locks.
Browse files Browse the repository at this point in the history
  • Loading branch information
@mtrippled
mtrippled committed Aug 22, 2024
1 parent c6d0e44 commit 977b182
Show file tree
Hide file tree
Showing 7 changed files with 55 additions and 9 deletions.
8 changes: 8 additions & 0 deletions src/xrpld/app/ledger/detail/InboundLedger.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -106,6 +106,7 @@ InboundLedger::init(ScopedLockType& collectionLock)
{
JLOG(journal_.debug()) << "TimeoutCounter lock2 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked2 " << this;
collectionLock.unlock();
JLOG(journal_.debug()) << "InboundLedgers InboundLedger::init unlock";
tryDB(app_.getNodeFamily().db());
Expand Down Expand Up @@ -158,6 +159,7 @@ InboundLedger::update(std::uint32_t seq)
{
JLOG(journal_.debug()) << "TimeoutCounter lock3 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked3 " << this;

// If we didn't know the sequence number, but now do, save it
if ((seq != 0) && (mSeq == 0))
Expand All @@ -173,6 +175,7 @@ InboundLedger::checkLocal()
{
JLOG(journal_.debug()) << "TimeoutCounter lock4 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked4 " << this;
if (!isDone())
{
if (mLedger)
Expand Down Expand Up @@ -504,6 +507,7 @@ InboundLedger::trigger(std::shared_ptr<Peer> const& peer, TriggerReason reason)
JLOG(journal_.debug()) << "InboundLedger::trigger1 " << this;
JLOG(journal_.debug()) << "TimeoutCounter lock5-1 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked5-1 " << this;

if (isDone())
{
Expand Down Expand Up @@ -675,6 +679,7 @@ InboundLedger::trigger(std::shared_ptr<Peer> const& peer, TriggerReason reason)
JLOG(journal_.debug()) << "InboundLedger::trigger13 " << this;
JLOG(journal_.debug()) << "TimeoutCounter lock5-2 " << this;
sl.lock();
JLOG(journal_.debug()) << "TimeoutCounter locked5-2 " << this;

// Make sure nothing happened while we released the lock
if (!failed_ && !complete_ && !mHaveState)
Expand Down Expand Up @@ -1117,6 +1122,7 @@ InboundLedger::processData(

JLOG(journal_.debug()) << "TimeoutCounter lock6 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked6 " << this;

try
{
Expand Down Expand Up @@ -1177,6 +1183,7 @@ InboundLedger::processData(

JLOG(journal_.debug()) << "TimeoutCounter lock7 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked7 " << this;

// Verify node IDs and data are complete
for (auto const& node : packet.nodes())
Expand Down Expand Up @@ -1340,6 +1347,7 @@ InboundLedger::getJson(int)

JLOG(journal_.debug()) << "TimeoutCounter lock8 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked8 " << this;

ret[jss::hash] = to_string(hash_);

Expand Down
36 changes: 27 additions & 9 deletions src/xrpld/app/ledger/detail/InboundLedgers.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,7 @@
#include <xrpl/protocol/jss.h>
#include <memory>
#include <mutex>
#include <thread>
#include <vector>

namespace ripple {
Expand Down Expand Up @@ -68,33 +69,38 @@ class InboundLedgersImp : public InboundLedgers
std::uint32_t seq,
InboundLedger::Reason reason) override
{
JLOG(j_.debug()) << "InboundLedgers::acquire1 " << this;
static std::size_t instance = 0;
++instance;
JLOG(j_.debug()) << "InboundLedgers::acquire1 " << this << " " << std::this_thread::get_id() << " " << instance;
assert(hash.isNonZero());

// probably not the right rule
if (app_.getOPs().isNeedNetworkLedger() &&
(reason != InboundLedger::Reason::GENERIC) &&
(reason != InboundLedger::Reason::CONSENSUS))
{
JLOG(j_.debug()) << "InboundLedgers::acquire2 " << this;
JLOG(j_.debug()) << "InboundLedgers::acquire2 " << this << " " << std::this_thread::get_id() << " " << instance;
return {};
}

bool isNew = true;
std::shared_ptr<InboundLedger> inbound;
{
JLOG(j_.debug()) << "InboundLedgers::acquire3 " << this;
JLOG(j_.debug()) << "InboundLedgers::acquire3 " << this << " " << std::this_thread::get_id() << " " << instance;
JLOG(j_.debug()) << "InboundLedgers lock1";
ScopedLockType sl(mLock);
JLOG(j_.debug()) << "InboundLedgers::acquire4 " << this;
JLOG(j_.debug()) << "InboundLedgers locked1";
JLOG(j_.debug()) << "InboundLedgers::acquire4 " << this << " " << std::this_thread::get_id() << " " << instance;
if (stopping_)
{
JLOG(j_.debug()) << "InboundLedgers::acquire5 " << this;
JLOG(j_.debug()) << "InboundLedgers::acquire5 " << this << " " << std::this_thread::get_id() << " " << instance;
JLOG(j_.debug()) << "InboundLedgers unlock1-1";
return {};
}

JLOG(j_.debug()) << "InboundLedgers::acquire5.1 " << this << " " << std::this_thread::get_id() << " " << instance;
auto it = mLedgers.find(hash);
JLOG(j_.debug()) << "InboundLedgers::acquire5.2 " << this << " " << std::this_thread::get_id() << " " << instance;
if (it != mLedgers.end())
{
isNew = false;
Expand All @@ -113,28 +119,31 @@ class InboundLedgersImp : public InboundLedgers
inbound->init(sl);
++mCounter;
}
JLOG(j_.debug()) << "InboundLedgers::acquire5.3 " << this << " " << std::this_thread::get_id() << " " << instance;
}

if (inbound->isFailed())
{
JLOG(j_.debug()) << "InboundLedgers::acquire6 " << this;
JLOG(j_.debug()) << "InboundLedgers::acquire6 " << this << " " << std::this_thread::get_id() << " " << instance;
JLOG(j_.debug()) << "InboundLedgers unlock1-2 but I think init already unlocked";
return {};
}

if (!isNew)
{
JLOG(j_.debug()) << "InboundLedgers::acquire5.4 " << this << " " << std::this_thread::get_id() << " " << instance;
inbound->update(seq);
JLOG(j_.debug()) << "InboundLedgers::acquire5.5 " << this << " " << std::this_thread::get_id() << " " << instance;
}

if (!inbound->isComplete())
{
JLOG(j_.debug()) << "InboundLedgers::acquire7 " << this;
JLOG(j_.debug()) << "InboundLedgers::acquire7 " << this << " " << std::this_thread::get_id() << " " << instance;
JLOG(j_.debug()) << "InboundLedgers unlock1-3 but I think init already unlocked";
return {};
}

JLOG(j_.debug()) << "InboundLedgers::acquire8 " << this;
JLOG(j_.debug()) << "InboundLedgers::acquire8 " << this << " " << std::this_thread::get_id() << " " << instance;
JLOG(j_.debug()) << "InboundLedgers unlock1-4 but I think init already unlocked";
return inbound->getLedger();
}
Expand All @@ -149,6 +158,7 @@ class InboundLedgersImp : public InboundLedgers
{
JLOG(j_.debug()) << "InboundLedgers lock2";
ScopedLockType sl(mLock);
JLOG(j_.debug()) << "InboundLedgers locked2";

auto it = mLedgers.find(hash);
if (it != mLedgers.end())
Expand Down Expand Up @@ -222,6 +232,7 @@ class InboundLedgersImp : public InboundLedgers
{
JLOG(j_.debug()) << "InboundLedgers lock3";
ScopedLockType sl(mLock);
JLOG(j_.debug()) << "InboundLedgers locked3";

mRecentFailures.emplace(h, seq);
JLOG(j_.debug()) << "InboundLedgers unlock3";
Expand All @@ -234,6 +245,7 @@ class InboundLedgersImp : public InboundLedgers
JLOG(j_.debug()) << "InboundLedgers lock4";
{
ScopedLockType sl(mLock);
JLOG(j_.debug()) << "InboundLedgers locked4";

beast::expire(mRecentFailures, kReacquireInterval);
ret = mRecentFailures.find(h) != mRecentFailures.end();
Expand Down Expand Up @@ -285,6 +297,7 @@ class InboundLedgersImp : public InboundLedgers
{
JLOG(j_.debug()) << "InboundLedgers lock5";
ScopedLockType sl(mLock);
JLOG(j_.debug()) << "InboundLedgers locked5";

mRecentFailures.clear();
mLedgers.clear();
Expand Down Expand Up @@ -317,6 +330,7 @@ class InboundLedgersImp : public InboundLedgers
{
JLOG(j_.debug()) << "InboundLedgers lock6";
ScopedLockType sl(mLock);
JLOG(j_.debug()) << "InboundLedgers locked6";

acqs.reserve(mLedgers.size());
for (auto const& it : mLedgers)
Expand Down Expand Up @@ -354,6 +368,7 @@ class InboundLedgersImp : public InboundLedgers
{
JLOG(j_.debug()) << "InboundLedgers lock7";
ScopedLockType sl(mLock);
JLOG(j_.debug()) << "InboundLedgers locked7";

acquires.reserve(mLedgers.size());
for (auto const& it : mLedgers)
Expand All @@ -362,7 +377,7 @@ class InboundLedgersImp : public InboundLedgers
acquires.push_back(it.second);
}
}
JLOG(j_.debug()) << "InboundLedgers lock7";
JLOG(j_.debug()) << "InboundLedgers unlock7";

for (auto const& acquire : acquires)
{
Expand All @@ -382,6 +397,7 @@ class InboundLedgersImp : public InboundLedgers
{
JLOG(j_.debug()) << "InboundLedgers lock8";
ScopedLockType sl(mLock);
JLOG(j_.debug()) << "InboundLedgers locked8";
MapType::iterator it(mLedgers.begin());
total = mLedgers.size();

Expand Down Expand Up @@ -427,6 +443,7 @@ class InboundLedgersImp : public InboundLedgers
{
JLOG(j_.debug()) << "InboundLedgers lock9";
ScopedLockType lock(mLock);
JLOG(j_.debug()) << "InboundLedgers locked9";
stopping_ = true;
mLedgers.clear();
mRecentFailures.clear();
Expand All @@ -440,6 +457,7 @@ class InboundLedgersImp : public InboundLedgers
JLOG(j_.debug()) << "InboundLedgers lock10";
{
ScopedLockType lock(mLock);
JLOG(j_.debug()) << "InboundLedgers locked10";
ret = mLedgers.size();
}
JLOG(j_.debug()) << "InboundLedgers unlock10";
Expand Down
4 changes: 4 additions & 0 deletions src/xrpld/app/ledger/detail/LedgerDeltaAcquire.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -59,6 +59,7 @@ LedgerDeltaAcquire::init(int numPeers)
{
JLOG(journal_.debug()) << "TimeoutCounter lock9 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked9 " << this;
if (!isDone())
{
trigger(numPeers, sl);
Expand Down Expand Up @@ -144,6 +145,7 @@ LedgerDeltaAcquire::processData(
{
JLOG(journal_.debug()) << "TimeoutCounter lock10 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked10 " << this;
JLOG(journal_.trace()) << "got data for " << hash_;
if (isDone())
{
Expand Down Expand Up @@ -181,6 +183,7 @@ LedgerDeltaAcquire::addDataCallback(
{
JLOG(journal_.debug()) << "TimeoutCounter lock11 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked11 " << this;
dataReadyCallbacks_.emplace_back(std::move(cb));
if (reasons_.count(reason) == 0)
{
Expand All @@ -203,6 +206,7 @@ LedgerDeltaAcquire::tryBuild(std::shared_ptr<Ledger const> const& parent)
{
JLOG(journal_.debug()) << "TimeoutCounter lock12 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked12 " << this;

if (fullLedger_)
{
Expand Down
6 changes: 6 additions & 0 deletions src/xrpld/app/ledger/detail/LedgerReplayTask.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -136,6 +136,7 @@ LedgerReplayTask::init()

JLOG(journal_.debug()) << "TimeoutCounter lock13 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked13 " << this;
if (!isDone())
{
trigger(sl);
Expand Down Expand Up @@ -179,6 +180,7 @@ LedgerReplayTask::deltaReady(uint256 const& deltaHash)
<< hash_;
JLOG(journal_.debug()) << "TimeoutCounter lock14 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked14 " << this;
if (!isDone())
tryAdvance(sl);
JLOG(journal_.debug()) << "TimeoutCounter unlock14 " << this;
Expand Down Expand Up @@ -235,6 +237,7 @@ LedgerReplayTask::updateSkipList(
{
JLOG(journal_.debug()) << "TimeoutCounter lock15 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked15 " << this;
if (isDone())
{
JLOG(journal_.debug()) << "TimeoutCounter unlock15-1 " << this;
Expand All @@ -253,6 +256,7 @@ LedgerReplayTask::updateSkipList(
replayer_.createDeltas(shared_from_this());
JLOG(journal_.debug()) << "TimeoutCounter lock16 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked16 " << this;
if (!isDone())
trigger(sl);
JLOG(journal_.debug()) << "TimeoutCounter unlock16 " << this;
Expand Down Expand Up @@ -297,6 +301,7 @@ LedgerReplayTask::addDelta(std::shared_ptr<LedgerDeltaAcquire> const& delta)

JLOG(journal_.debug()) << "TimeoutCounter lock17 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked17 " << this;
if (!isDone())
{
JLOG(journal_.trace())
Expand All @@ -317,6 +322,7 @@ LedgerReplayTask::finished() const
JLOG(journal_.debug()) << "TimeoutCounter lock18 " << this;
{
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked18 " << this;
ret = isDone();
}
JLOG(journal_.debug()) << "TimeoutCounter unlock18 " << this;
Expand Down
4 changes: 4 additions & 0 deletions src/xrpld/app/ledger/detail/SkipListAcquire.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -55,6 +55,7 @@ SkipListAcquire::init(int numPeers)
{
JLOG(journal_.debug()) << "TimeoutCounter lock19 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked19 " << this;
if (!isDone())
{
trigger(numPeers, sl);
Expand Down Expand Up @@ -144,6 +145,7 @@ SkipListAcquire::processData(
assert(ledgerSeq != 0 && item);
JLOG(journal_.debug()) << "TimeoutCounter lock20 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked20 " << this;
if (isDone())
{
JLOG(journal_.debug()) << "TimeoutCounter unlock20-1 " << this;
Expand Down Expand Up @@ -180,6 +182,7 @@ SkipListAcquire::addDataCallback(OnSkipListDataCB&& cb)
{
JLOG(journal_.debug()) << "TimeoutCounter lock21 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked21 " << this;
dataReadyCallbacks_.emplace_back(std::move(cb));
if (isDone())
{
Expand All @@ -197,6 +200,7 @@ SkipListAcquire::getData() const
JLOG(journal_.debug()) << "TimeoutCounter lock22 " << this;
{
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked22 " << this;
ret = data_;
}
JLOG(journal_.debug()) << "TimeoutCounter unlock22 " << this;
Expand Down
3 changes: 3 additions & 0 deletions src/xrpld/app/ledger/detail/TimeoutCounter.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -61,6 +61,7 @@ TimeoutCounter::setTimer(ScopedLockType& sl)
{
JLOG(journal_.debug()) << "TimeoutCounter lock23 " << this;
ScopedLockType sl(ptr->mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked23 " << this;
ptr->queueJob(sl);
JLOG(journal_.debug()) << "TimeoutCounter unlock23 " << this;
}
Expand Down Expand Up @@ -98,6 +99,7 @@ TimeoutCounter::invokeOnTimer()
{
JLOG(journal_.debug()) << "TimeoutCounter lock24 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked24 " << this;
JLOG(journal_.debug()) << "TimeoutCounter::invokeOnTimer locked " << this;

if (isDone())
Expand Down Expand Up @@ -136,6 +138,7 @@ TimeoutCounter::cancel()
{
JLOG(journal_.debug()) << "TimeoutCounter lock25 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked25 " << this;
if (!isDone())
{
failed_ = true;
Expand Down
3 changes: 3 additions & 0 deletions src/xrpld/app/ledger/detail/TransactionAcquire.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -181,6 +181,7 @@ TransactionAcquire::takeNodes(
{
JLOG(journal_.debug()) << "TimeoutCounter lock26 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked26 " << this;

if (complete_)
{
Expand Down Expand Up @@ -259,6 +260,7 @@ TransactionAcquire::init(int numPeers)
{
JLOG(journal_.debug()) << "TimeoutCounter lock27 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked27 " << this;

addPeers(numPeers);

Expand All @@ -271,6 +273,7 @@ TransactionAcquire::stillNeed()
{
JLOG(journal_.debug()) << "TimeoutCounter lock28 " << this;
ScopedLockType sl(mtx_);
JLOG(journal_.debug()) << "TimeoutCounter locked28 " << this;

if (timeouts_ > NORM_TIMEOUTS)
timeouts_ = NORM_TIMEOUTS;
Expand Down

0 comments on commit 977b182

Please sign in to comment.