Assign each path finding request an ID and track its lifecycle.

src/ripple_app/paths/PathRequest.cpp

@@ -23,6 +23,7 @@ SETUP_LOG (PathRequest)
 // VFALCO TODO Move these globals into a PathRequests collection inteface
 PathRequest::StaticLockType PathRequest::sLock ("PathRequest", __FILE__, __LINE__);
 std::set <PathRequest::wptr> PathRequest::sRequests;
+Atomic<int> PathRequest::siLastIdentifier(0);
 
 PathRequest::PathRequest (const boost::shared_ptr<InfoSub>& subscriber)
     : mLock (this, "PathRequest", __FILE__, __LINE__)
@@ -32,7 +33,14 @@ PathRequest::PathRequest (const boost::shared_ptr<InfoSub>& subscriber)
     , bNew (true)
     , iLastLevel (0)
     , bLastSuccess (false)
+    , iIdentifier (++siLastIdentifier)
 {
+    WriteLog (lsINFO, PathRequest) << iIdentifier << " created";
+}
+
+PathRequest::~PathRequest()
+{
+    WriteLog (lsINFO, PathRequest) << iIdentifier << " destroyed";
 }
 
 bool PathRequest::isValid ()
@@ -130,13 +138,15 @@ Json::Value PathRequest::doCreate (Ledger::ref lrLedger, const Json::Value& valu
 
     if (mValid)
     {
-        WriteLog (lsINFO, PathRequest) << "Request created: " << raSrcAccount.humanAccountID () <<
+        WriteLog (lsINFO, PathRequest) << iIdentifier << " valid: " << raSrcAccount.humanAccountID () <<
                                        " -> " << raDstAccount.humanAccountID ();
-        WriteLog (lsINFO, PathRequest) << "Deliver: " << saDstAmount.getFullText ();
+        WriteLog (lsINFO, PathRequest) << iIdentifier << "Deliver: " << saDstAmount.getFullText ();
 
         StaticScopedLockType sl (sLock, __FILE__, __LINE__);
         sRequests.insert (shared_from_this ());
     }
+    else
+        WriteLog (lsINFO, PathRequest) << iIdentifier << " invalid";
 
     return status;
 }
@@ -235,6 +245,7 @@ int PathRequest::parseJson (const Json::Value& jvParams, bool complete)
 }
 Json::Value PathRequest::doClose (const Json::Value&)
 {
+    WriteLog (lsDEBUG, PathRequest) << iIdentifier << " closed";
     ScopedLockType sl (mLock, __FILE__, __LINE__);
     return jvStatus;
 }
@@ -247,6 +258,7 @@ Json::Value PathRequest::doStatus (const Json::Value&)
 
 bool PathRequest::doUpdate (RippleLineCache::ref cache, bool fast)
 {
+    WriteLog (lsDEBUG, PathRequest) << iIdentifier << " update " << (fast ? "fast" : "normal");
     ScopedLockType sl (mLock, __FILE__, __LINE__);
     jvStatus = Json::objectValue;
 
@@ -319,19 +331,21 @@ bool PathRequest::doUpdate (RippleLineCache::ref cache, bool fast)
             --iLevel;
     }
 
+    WriteLog (lsDEBUG, PathRequest) << iIdentifier << " processing at level " << iLevel;
+
     bool found = false;
 
     BOOST_FOREACH (const currIssuer_t & currIssuer, sourceCurrencies)
     {
         {
             STAmount test (currIssuer.first, currIssuer.second, 1);
-            WriteLog (lsDEBUG, PathRequest) << "Trying to find paths: " << test.getFullText ();
+            WriteLog (lsDEBUG, PathRequest) << iIdentifier << "Trying to find paths: " << test.getFullText ();
         }
         bool valid;
         STPathSet& spsPaths = mContext[currIssuer];
         Pathfinder pf (cache, raSrcAccount, raDstAccount,
                        currIssuer.first, currIssuer.second, saDstAmount, valid);
-        CondLog (!valid, lsINFO, PathRequest) << "PF request not valid";
+        CondLog (!valid, lsINFO, PathRequest) << iIdentifier << "PF request not valid";
 
         STPath extraPath;
         if (valid && pf.findPaths (iLevel, 4, spsPaths, extraPath))
@@ -344,7 +358,7 @@ bool PathRequest::doUpdate (RippleLineCache::ref cache, bool fast)
                     currIssuer.second.isNonZero () ? currIssuer.second :
                     (currIssuer.first.isZero () ? ACCOUNT_XRP : raSrcAccount.getAccountID ()), 1);
             saMaxAmount.negate ();
-            WriteLog (lsDEBUG, PathRequest) << "Paths found, calling rippleCalc";
+            WriteLog (lsDEBUG, PathRequest) << iIdentifier << "Paths found, calling rippleCalc";
             TER terResult = RippleCalc::rippleCalc (lesSandbox, saMaxAmountAct, saDstAmountAct,
                                                     vpsExpanded, saMaxAmount, saDstAmount,
                                                     raDstAccount.getAccountID (), raSrcAccount.getAccountID (),
@@ -353,14 +367,14 @@ bool PathRequest::doUpdate (RippleLineCache::ref cache, bool fast)
 
             if ((extraPath.size() > 0) && ((terResult == terNO_LINE) || (terResult == tecPATH_PARTIAL)))
             {
-                WriteLog (lsDEBUG, PathRequest) << "Trying with an extra path element";
+                WriteLog (lsDEBUG, PathRequest) << iIdentifier << "Trying with an extra path element";
                 spsPaths.addPath(extraPath);
                 vpsExpanded.clear ();
                 terResult = RippleCalc::rippleCalc (lesSandbox, saMaxAmountAct, saDstAmountAct,
                                                     vpsExpanded, saMaxAmount, saDstAmount,
                                                     raDstAccount.getAccountID (), raSrcAccount.getAccountID (),
                                                     spsPaths, false, false, false, true);
-                WriteLog (lsDEBUG, PathRequest) << "Extra path element gives " << transHuman (terResult);
+                WriteLog (lsDEBUG, PathRequest) << iIdentifier << "Extra path element gives " << transHuman (terResult);
             }
 
             if (terResult == tesSUCCESS)
@@ -373,12 +387,12 @@ bool PathRequest::doUpdate (RippleLineCache::ref cache, bool fast)
             }
             else
             {
-                WriteLog (lsINFO, PathRequest) << "rippleCalc returns " << transHuman (terResult);
+                WriteLog (lsINFO, PathRequest) << iIdentifier << "rippleCalc returns " << transHuman (terResult);
             }
         }
         else
         {
-            WriteLog (lsINFO, PathRequest) << "No paths found";
+            WriteLog (lsINFO, PathRequest) << iIdentifier << "No paths found";
         }
     }
 
@@ -391,6 +405,8 @@ bool PathRequest::doUpdate (RippleLineCache::ref cache, bool fast)
 
 void PathRequest::updateAll (Ledger::ref ledger, bool newOnly, CancelCallback shouldCancel)
 {
+    WriteLog (lsDEBUG, PathRequest) << "updateAll seq=" << ledger->getLedgerSeq() <<
+        (newOnly ? " newOnly" : " all");
     std::set<wptr> requests;
 
     LoadEvent::autoptr event (getApp().getJobQueue().getLoadEventAP(jtPATH_FIND, "PathRequest::updateAll"));
@@ -403,6 +419,7 @@ void PathRequest::updateAll (Ledger::ref ledger, bool newOnly, CancelCallback sh
     if (requests.empty ())
         return;
 
+    int processed = 0, removed = 0;
     RippleLineCache::pointer cache = boost::make_shared<RippleLineCache> (ledger);
 
     BOOST_FOREACH (wref wRequest, requests)
@@ -432,16 +449,20 @@ void PathRequest::updateAll (Ledger::ref ledger, bool newOnly, CancelCallback sh
                     update["type"] = "path_find";
                     ipSub->send (update, false);
                     remove = false;
+                    ++processed;
                 }
             }
         }
 
         if (remove)
         {
+            ++removed;
             StaticScopedLockType sl (sLock, __FILE__, __LINE__);
             sRequests.erase (wRequest);
         }
     }
+    WriteLog (lsDEBUG, PathRequest) << "updateAll complete " << processed << " process and " <<
+        removed << " removed";
 }
 
 // vim:ts=4

src/ripple_app/paths/PathRequest.h

@@ -46,6 +46,7 @@ public:
 public:
     // VFALCO TODO Break the cyclic dependency on InfoSub
     explicit PathRequest (boost::shared_ptr <InfoSub> const& subscriber);
+    ~PathRequest ();
 
     bool        isValid (const boost::shared_ptr<Ledger>&);
     bool        isValid ();
@@ -86,6 +87,9 @@ private:
     int                             iLastLevel;
     bool                            bLastSuccess;
 
+    int                             iIdentifier;
+    static Atomic<int>              siLastIdentifier;
+
     // Track all requests
     static std::set<wptr>           sRequests;