diff options
| -rw-r--r-- | src/init.cpp | 9 | ||||
| -rw-r--r-- | src/main.cpp | 14 | ||||
| -rw-r--r-- | src/net.cpp | 4 | ||||
| -rw-r--r-- | src/sync.cpp | 49 | ||||
| -rw-r--r-- | src/sync.h | 8 | ||||
| -rw-r--r-- | src/util.cpp | 105 | ||||
| -rw-r--r-- | src/util.h | 1 | ||||
| -rw-r--r-- | src/wallet/rpcwallet.cpp | 1 |
8 files changed, 139 insertions, 52 deletions
diff --git a/src/init.cpp b/src/init.cpp index 4addc663c8..ecf05d95b4 100644 --- a/src/init.cpp +++ b/src/init.cpp @@ -668,6 +668,9 @@ bool AppInit2(boost::thread_group& threadGroup, CScheduler& scheduler) fLogTimestamps = GetBoolArg("-logtimestamps", true); fLogIPs = GetBoolArg("-logips", false); + LogPrintf("\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n"); + LogPrintf("Bitcoin version %s (%s)\n", FormatFullVersion(), CLIENT_DATE); + // when specifying an explicit binding address, you want to listen on it // even when -connect or -proxy is specified if (mapArgs.count("-bind")) { @@ -941,8 +944,10 @@ bool AppInit2(boost::thread_group& threadGroup, CScheduler& scheduler) #endif if (GetBoolArg("-shrinkdebugfile", !fDebug)) ShrinkDebugFile(); - LogPrintf("\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n"); - LogPrintf("Bitcoin version %s (%s)\n", FormatFullVersion(), CLIENT_DATE); + + if (fPrintToDebugLog) + OpenDebugLog(); + LogPrintf("Using OpenSSL version %s\n", SSLeay_version(SSLEAY_VERSION)); #ifdef ENABLE_WALLET LogPrintf("Using BerkeleyDB version %s\n", DbEnv::version(0, 0, 0)); diff --git a/src/main.cpp b/src/main.cpp index fb90d7578c..54f9f89c4d 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -75,9 +75,9 @@ struct COrphanTx { CTransaction tx; NodeId fromPeer; }; -map<uint256, COrphanTx> mapOrphanTransactions; -map<uint256, set<uint256> > mapOrphanTransactionsByPrev; -void EraseOrphansFor(NodeId peer); +map<uint256, COrphanTx> mapOrphanTransactions GUARDED_BY(cs_main);; +map<uint256, set<uint256> > mapOrphanTransactionsByPrev GUARDED_BY(cs_main);; +void EraseOrphansFor(NodeId peer) EXCLUSIVE_LOCKS_REQUIRED(cs_main); /** * Returns true if there are nRequired or more blocks of minVersion or above @@ -527,7 +527,7 @@ CBlockTreeDB *pblocktree = NULL; // mapOrphanTransactions // -bool AddOrphanTx(const CTransaction& tx, NodeId peer) +bool AddOrphanTx(const CTransaction& tx, NodeId peer) EXCLUSIVE_LOCKS_REQUIRED(cs_main) { uint256 hash = tx.GetHash(); if (mapOrphanTransactions.count(hash)) @@ -557,7 +557,7 @@ bool AddOrphanTx(const CTransaction& tx, NodeId peer) return true; } -void static EraseOrphanTx(uint256 hash) +void static EraseOrphanTx(uint256 hash) EXCLUSIVE_LOCKS_REQUIRED(cs_main) { map<uint256, COrphanTx>::iterator it = mapOrphanTransactions.find(hash); if (it == mapOrphanTransactions.end()) @@ -591,7 +591,7 @@ void EraseOrphansFor(NodeId peer) } -unsigned int LimitOrphanTxSize(unsigned int nMaxOrphans) +unsigned int LimitOrphanTxSize(unsigned int nMaxOrphans) EXCLUSIVE_LOCKS_REQUIRED(cs_main) { unsigned int nEvicted = 0; while (mapOrphanTransactions.size() > nMaxOrphans) @@ -3649,7 +3649,7 @@ std::string GetWarnings(const std::string& strFor) // -bool static AlreadyHave(const CInv& inv) +bool static AlreadyHave(const CInv& inv) EXCLUSIVE_LOCKS_REQUIRED(cs_main) { switch (inv.type) { diff --git a/src/net.cpp b/src/net.cpp index 3d369c7dd1..5cb6527c9b 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -2183,8 +2183,10 @@ void CNode::EndMessage() UNLOCK_FUNCTION(cs_vSend) Fuzz(GetArg("-fuzzmessagestest", 10)); if (ssSend.size() == 0) + { + LEAVE_CRITICAL_SECTION(cs_vSend); return; - + } // Set the size unsigned int nSize = ssSend.size() - CMessageHeader::HEADER_SIZE; WriteLE32((uint8_t*)&ssSend[CMessageHeader::MESSAGE_SIZE_OFFSET], nSize); diff --git a/src/sync.cpp b/src/sync.cpp index a422939964..1837e8d53d 100644 --- a/src/sync.cpp +++ b/src/sync.cpp @@ -33,20 +33,22 @@ void PrintLockContention(const char* pszName, const char* pszFile, int nLine) // struct CLockLocation { - CLockLocation(const char* pszName, const char* pszFile, int nLine) + CLockLocation(const char* pszName, const char* pszFile, int nLine, bool fTryIn) { mutexName = pszName; sourceFile = pszFile; sourceLine = nLine; + fTry = fTryIn; } std::string ToString() const { - return mutexName + " " + sourceFile + ":" + itostr(sourceLine); + return mutexName + " " + sourceFile + ":" + itostr(sourceLine) + (fTry ? " (TRY)" : ""); } std::string MutexName() const { return mutexName; } + bool fTry; private: std::string mutexName; std::string sourceFile; @@ -62,23 +64,52 @@ static boost::thread_specific_ptr<LockStack> lockstack; static void potential_deadlock_detected(const std::pair<void*, void*>& mismatch, const LockStack& s1, const LockStack& s2) { + // We attempt to not assert on probably-not deadlocks by assuming that + // a try lock will immediately have otherwise bailed if it had + // failed to get the lock + // We do this by, for the locks which triggered the potential deadlock, + // in either lockorder, checking that the second of the two which is locked + // is only a TRY_LOCK, ignoring locks if they are reentrant. + bool firstLocked = false; + bool secondLocked = false; + bool onlyMaybeDeadlock = false; + LogPrintf("POTENTIAL DEADLOCK DETECTED\n"); LogPrintf("Previous lock order was:\n"); BOOST_FOREACH (const PAIRTYPE(void*, CLockLocation) & i, s2) { - if (i.first == mismatch.first) + if (i.first == mismatch.first) { LogPrintf(" (1)"); - if (i.first == mismatch.second) + if (!firstLocked && secondLocked && i.second.fTry) + onlyMaybeDeadlock = true; + firstLocked = true; + } + if (i.first == mismatch.second) { LogPrintf(" (2)"); + if (!secondLocked && firstLocked && i.second.fTry) + onlyMaybeDeadlock = true; + secondLocked = true; + } LogPrintf(" %s\n", i.second.ToString()); } + firstLocked = false; + secondLocked = false; LogPrintf("Current lock order is:\n"); BOOST_FOREACH (const PAIRTYPE(void*, CLockLocation) & i, s1) { - if (i.first == mismatch.first) + if (i.first == mismatch.first) { LogPrintf(" (1)"); - if (i.first == mismatch.second) + if (!firstLocked && secondLocked && i.second.fTry) + onlyMaybeDeadlock = true; + firstLocked = true; + } + if (i.first == mismatch.second) { LogPrintf(" (2)"); + if (!secondLocked && firstLocked && i.second.fTry) + onlyMaybeDeadlock = true; + secondLocked = true; + } LogPrintf(" %s\n", i.second.ToString()); } + assert(onlyMaybeDeadlock); } static void push_lock(void* c, const CLockLocation& locklocation, bool fTry) @@ -101,10 +132,8 @@ static void push_lock(void* c, const CLockLocation& locklocation, bool fTry) lockorders[p1] = (*lockstack); std::pair<void*, void*> p2 = std::make_pair(c, i.first); - if (lockorders.count(p2)) { + if (lockorders.count(p2)) potential_deadlock_detected(p1, lockorders[p2], lockorders[p1]); - break; - } } } dd_mutex.unlock(); @@ -119,7 +148,7 @@ static void pop_lock() void EnterCritical(const char* pszName, const char* pszFile, int nLine, void* cs, bool fTry) { - push_lock(cs, CLockLocation(pszName, pszFile, nLine), fTry); + push_lock(cs, CLockLocation(pszName, pszFile, nLine, fTry), fTry); } void LeaveCritical() diff --git a/src/sync.h b/src/sync.h index 78b9043477..705647e4a5 100644 --- a/src/sync.h +++ b/src/sync.h @@ -101,7 +101,7 @@ void PrintLockContention(const char* pszName, const char* pszFile, int nLine); /** Wrapper around boost::unique_lock<Mutex> */ template <typename Mutex> -class CMutexLock +class SCOPED_LOCKABLE CMutexLock { private: boost::unique_lock<Mutex> lock; @@ -129,7 +129,7 @@ private: } public: - CMutexLock(Mutex& mutexIn, const char* pszName, const char* pszFile, int nLine, bool fTry = false) : lock(mutexIn, boost::defer_lock) + CMutexLock(Mutex& mutexIn, const char* pszName, const char* pszFile, int nLine, bool fTry = false) EXCLUSIVE_LOCK_FUNCTION(mutexIn) : lock(mutexIn, boost::defer_lock) { if (fTry) TryEnter(pszName, pszFile, nLine); @@ -137,7 +137,7 @@ public: Enter(pszName, pszFile, nLine); } - CMutexLock(Mutex* pmutexIn, const char* pszName, const char* pszFile, int nLine, bool fTry = false) + CMutexLock(Mutex* pmutexIn, const char* pszName, const char* pszFile, int nLine, bool fTry = false) EXCLUSIVE_LOCK_FUNCTION(pmutexIn) { if (!pmutexIn) return; @@ -148,7 +148,7 @@ public: Enter(pszName, pszFile, nLine); } - ~CMutexLock() + ~CMutexLock() UNLOCK_FUNCTION() { if (lock.owns_lock()) LeaveCritical(); diff --git a/src/util.cpp b/src/util.cpp index 00d0f3a00d..37d52037c0 100644 --- a/src/util.cpp +++ b/src/util.cpp @@ -114,7 +114,7 @@ CTranslationInterface translationInterface; /** Init OpenSSL library multithreading support */ static CCriticalSection** ppmutexOpenSSL; -void locking_callback(int mode, int i, const char* file, int line) +void locking_callback(int mode, int i, const char* file, int line) NO_THREAD_SAFETY_ANALYSIS { if (mode & CRYPTO_LOCK) { ENTER_CRITICAL_SECTION(*ppmutexOpenSSL[i]); @@ -175,23 +175,51 @@ instance_of_cinit; */ static boost::once_flag debugPrintInitFlag = BOOST_ONCE_INIT; + /** - * We use boost::call_once() to make sure these are initialized - * in a thread-safe manner the first time called: + * We use boost::call_once() to make sure mutexDebugLog and + * vMsgsBeforeOpenLog are initialized in a thread-safe manner. + * + * NOTE: fileout, mutexDebugLog and sometimes vMsgsBeforeOpenLog + * are leaked on exit. This is ugly, but will be cleaned up by + * the OS/libc. When the shutdown sequence is fully audited and + * tested, explicit destruction of these objects can be implemented. */ static FILE* fileout = NULL; static boost::mutex* mutexDebugLog = NULL; +static list<string> *vMsgsBeforeOpenLog; + +static int FileWriteStr(const std::string &str, FILE *fp) +{ + return fwrite(str.data(), 1, str.size(), fp); +} static void DebugPrintInit() { - assert(fileout == NULL); assert(mutexDebugLog == NULL); + mutexDebugLog = new boost::mutex(); + vMsgsBeforeOpenLog = new list<string>; +} + +void OpenDebugLog() +{ + boost::call_once(&DebugPrintInit, debugPrintInitFlag); + boost::mutex::scoped_lock scoped_lock(*mutexDebugLog); + assert(fileout == NULL); + assert(vMsgsBeforeOpenLog); boost::filesystem::path pathDebug = GetDataDir() / "debug.log"; fileout = fopen(pathDebug.string().c_str(), "a"); if (fileout) setbuf(fileout, NULL); // unbuffered - mutexDebugLog = new boost::mutex(); + // dump buffered messages from before we opened the log + while (!vMsgsBeforeOpenLog->empty()) { + FileWriteStr(vMsgsBeforeOpenLog->front(), fileout); + vMsgsBeforeOpenLog->pop_front(); + } + + delete vMsgsBeforeOpenLog; + vMsgsBeforeOpenLog = NULL; } bool LogAcceptCategory(const char* category) @@ -223,44 +251,67 @@ bool LogAcceptCategory(const char* category) return true; } +/** + * fStartedNewLine is a state variable held by the calling context that will + * suppress printing of the timestamp when multiple calls are made that don't + * end in a newline. Initialize it to true, and hold it, in the calling context. + */ +static std::string LogTimestampStr(const std::string &str, bool *fStartedNewLine) +{ + string strStamped; + + if (!fLogTimestamps) + return str; + + if (*fStartedNewLine) + strStamped = DateTimeStrFormat("%Y-%m-%d %H:%M:%S", GetTime()) + ' ' + str; + else + strStamped = str; + + if (!str.empty() && str[str.size()-1] == '\n') + *fStartedNewLine = true; + else + *fStartedNewLine = false; + + return strStamped; +} + int LogPrintStr(const std::string &str) { int ret = 0; // Returns total number of characters written + static bool fStartedNewLine = true; if (fPrintToConsole) { // print to console ret = fwrite(str.data(), 1, str.size(), stdout); fflush(stdout); } - else if (fPrintToDebugLog && AreBaseParamsConfigured()) + else if (fPrintToDebugLog) { - static bool fStartedNewLine = true; boost::call_once(&DebugPrintInit, debugPrintInitFlag); - - if (fileout == NULL) - return ret; - boost::mutex::scoped_lock scoped_lock(*mutexDebugLog); - // reopen the log file, if requested - if (fReopenDebugLog) { - fReopenDebugLog = false; - boost::filesystem::path pathDebug = GetDataDir() / "debug.log"; - if (freopen(pathDebug.string().c_str(),"a",fileout) != NULL) - setbuf(fileout, NULL); // unbuffered - } + string strTimestamped = LogTimestampStr(str, &fStartedNewLine); - // Debug print useful for profiling - if (fLogTimestamps && fStartedNewLine) - ret += fprintf(fileout, "%s ", DateTimeStrFormat("%Y-%m-%d %H:%M:%S", GetTime()).c_str()); - if (!str.empty() && str[str.size()-1] == '\n') - fStartedNewLine = true; + // buffer if we haven't opened the log yet + if (fileout == NULL) { + assert(vMsgsBeforeOpenLog); + ret = strTimestamped.length(); + vMsgsBeforeOpenLog->push_back(strTimestamped); + } else - fStartedNewLine = false; - - ret = fwrite(str.data(), 1, str.size(), fileout); + { + // reopen the log file, if requested + if (fReopenDebugLog) { + fReopenDebugLog = false; + boost::filesystem::path pathDebug = GetDataDir() / "debug.log"; + if (freopen(pathDebug.string().c_str(),"a",fileout) != NULL) + setbuf(fileout, NULL); // unbuffered + } + + ret = FileWriteStr(strTimestamped, fileout); + } } - return ret; } diff --git a/src/util.h b/src/util.h index 6019e25015..afc9a378bb 100644 --- a/src/util.h +++ b/src/util.h @@ -125,6 +125,7 @@ void ReadConfigFile(std::map<std::string, std::string>& mapSettingsRet, std::map boost::filesystem::path GetSpecialFolderPath(int nFolder, bool fCreate = true); #endif boost::filesystem::path GetTempPath(); +void OpenDebugLog(); void ShrinkDebugFile(); void runCommand(const std::string& strCommand); diff --git a/src/wallet/rpcwallet.cpp b/src/wallet/rpcwallet.cpp index 8d88933878..f6ca8cbb76 100644 --- a/src/wallet/rpcwallet.cpp +++ b/src/wallet/rpcwallet.cpp @@ -476,7 +476,6 @@ UniValue listaddressgroupings(const UniValue& params, bool fHelp) addressInfo.push_back(CBitcoinAddress(address).ToString()); addressInfo.push_back(ValueFromAmount(balances[address])); { - LOCK(pwalletMain->cs_wallet); if (pwalletMain->mapAddressBook.find(CBitcoinAddress(address).Get()) != pwalletMain->mapAddressBook.end()) addressInfo.push_back(pwalletMain->mapAddressBook.find(CBitcoinAddress(address).Get())->second.name); } |