From c9fc4349b7d4ab1f5a7bfc0125014a96a07e51a3 Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Tue, 11 May 2021 21:42:14 -0400 Subject: SL-10297: Move LL_ERRS crash location into the LL_ERRS macro itself. Introduce Oz's LLERROR_CRASH macro analogous to the old LLError::crashAndLoop() function. Change LL_ENDL macro so that, after calling flush(), if the CallSite is for LEVEL_ERROR, we invoke LLERROR_CRASH right there. Change the meaning of LLError::FatalFunction. It used to be responsible for the actual crash (hence crashAndLoop()). Now, instead, its role is to disrupt control flow in some other way if you DON'T want to crash: throw an exception, or call exit() or some such. Any FatalFunction that returns normally will fall into the new crash in LL_ENDL. Accordingly, the new default FatalFunction is a no-op lambda. This eliminates the need to test for empty (not set) FatalFunction in Log::flush(). Remove LLError::crashAndLoop() because the official LL_ERRS crash is now in LL_ENDL. One of the two common use cases for setFatalFunction() used to be to intercept control in the last moments before crashing -- not to crash or to avoid crashing, but to capture the LL_ERRS message in some way. Especially when that's temporary, though (e.g. LLLeap), saving and restoring the previous FatalFunction only works when the lifespans of the relevant objects are strictly LIFO. Either way, that's a misuse of FatalFunction. Fortunately the Recorder mechanism exactly addresses that case. Introduce a GenericRecorder template subclass, with LLError::addGenericRecorder(callable) that accepts a callable with suitable (level, message) signature, instantiates a GenericRecorder, adds it to the logging machinery and returns the RecorderPtr for possible later use with removeRecorder(). Change llappviewer.cpp's errorCallback() to an addGenericRecorder() callable. Its role was simply to update gDebugInfo["FatalMessage"] with the LL_ERRS message, then call writeDebugInfo(), before calling crashAndLoop() to finish crashing. Remove the crashAndLoop() call, retaining the gDebugInfo logic. Pass errorCallback() to LLError::addGenericRecorder() instead of setFatalFunction(). Oddly, errorCallback()'s crashAndLoop() call was conditional on a compile-time SHADER_CRASH_NONFATAL symbol. The new mechanism provides no way to support SHADER_CRASH_NONFATAL -- it is a Bad Idea to return normally from any LL_ERRS invocation! Rename LLLeapImpl::fatalFunction() to onError(). Instead of passing it to LLError::setFatalFunction(), pass it to addGenericRecorder(). Capture the returned RecorderPtr in mRecorder, replacing mPrevFatalFunction. Then ~LLLeapImpl() calls removeRecorder(mRecorder) instead of restoring mPrevFatalFunction (which, as noted above, was order-sensitive). Of course, every enabled Recorder is called with every log message. onError() and errorCallback() must specifically test for calls with LEVEL_ERROR. LLSingletonBase::logerrs() used to call LLError::getFatalFunction(), check the return and call it if non-empty, else call LLError::crashAndLoop(). Replace all that with LLERROR_CRASH. Remove from llappviewer.cpp the watchdog_llerrs_callback() and watchdog_killer_callback() functions. watchdog_killer_callback(), passed to Watchdog::init(), used to setFatalFunction(watchdog_llerrs_callback) and then invoke LL_ERRS() -- which seems a bit roundabout. watchdog_llerrs_callback(), in turn, replicated much of the logic in the primary errorCallback() function before replicating the crash from llwatchdog.cpp's default_killer_callback(). Instead, pass LLWatchdog::init() a lambda that invokes the LL_ERRS() message formerly found in watchdog_killer_callback(). It no longer needs to override FatalFunction with watchdog_llerrs_callback() because errorCallback() will still be called as a Recorder, obviating watchdog_llerrs_callback()'s first half; and LL_ENDL will handle the crash, obviating the second half. Remove from llappviewer.cpp the static fast_exit() function, which was simply an alias for _exit() acceptable to boost::bind(). Use a lambda directly calling _exit() instead of using boost::bind() at all. In the CaptureLog class in llcommon/tests/wrapllerrs.h, instead of statically referencing the wouldHaveCrashed() function from test.cpp, simply save and restore the current FatalFunction across the LLError::saveAndResetSettings() call. llerror_test.cpp calls setFatalFunction(fatalCall), where fatalCall() was a function that simply set a fatalWasCalled bool rather than actually crashing in any way. Of course, that implementation would now lead to crashing the test program. Make fatalCall() throw a new FatalWasCalled exception. Introduce a CATCH(LL_ERRS("tag"), "message") macro that expands to: LL_ERRS("tag") << "message" << LL_ENDL; within a try/catch block that catches FatalWasCalled and sets the same bool. Change all existing LL_ERRS() in llerror_test.cpp to corresponding CATCH() calls. In fact there's also an LL_DEBUGS(bad tag) invocation that exercises an LL_ERRS internal to llerror.cpp; wrap that too. --- indra/llcommon/llerror.cpp | 37 +++------------------- indra/llcommon/llerror.h | 22 ++++++++++--- indra/llcommon/llerrorcontrol.h | 57 +++++++++++++++++++++++++++------- indra/llcommon/llleap.cpp | 48 ++++++++++++++--------------- indra/llcommon/llsingleton.cpp | 15 +-------- indra/llcommon/tests/llerror_test.cpp | 58 +++++++++++++++++++++++------------ indra/llcommon/tests/wrapllerrs.h | 22 ++++++------- 7 files changed, 142 insertions(+), 117 deletions(-) (limited to 'indra/llcommon') diff --git a/indra/llcommon/llerror.cpp b/indra/llcommon/llerror.cpp index f876b8ee4a..9d775dcef3 100644 --- a/indra/llcommon/llerror.cpp +++ b/indra/llcommon/llerror.cpp @@ -549,7 +549,7 @@ namespace LLError mFileLevelMap(), mTagLevelMap(), mUniqueLogMessages(), - mCrashFunction(NULL), + mCrashFunction([](const std::string&){}), mTimeFunction(NULL), mRecorders(), mShouldLogCallCounter(0) @@ -728,7 +728,6 @@ namespace LLError::setDefaultLevel(LLError::LEVEL_INFO); LLError::setAlwaysFlush(true); LLError::setEnabledLogTypesMask(0xFFFFFFFF); - LLError::setFatalFunction(LLError::crashAndLoop); LLError::setTimeFunction(LLError::utcTime); // log_to_stderr is only false in the unit and integration tests to keep builds quieter @@ -1436,7 +1435,7 @@ namespace LLError if (site.mPrintOnce) { - std::ostringstream message_stream; + std::ostringstream message_stream; std::map::iterator messageIter = s->mUniqueLogMessages.find(message); if (messageIter != s->mUniqueLogMessages.end()) @@ -1457,8 +1456,8 @@ namespace LLError message_stream << "ONCE: "; s->mUniqueLogMessages[message] = 1; } - message_stream << message; - message = message_stream.str(); + message_stream << message; + message = message_stream.str(); } writeToRecorders(site, message); @@ -1466,10 +1465,7 @@ namespace LLError if (site.mLevel == LEVEL_ERROR) { g->mFatalMessage = message; - if (s->mCrashFunction) - { - s->mCrashFunction(message); - } + s->mCrashFunction(message); } } } @@ -1533,29 +1529,6 @@ namespace LLError return s->mShouldLogCallCounter; } -#if LL_WINDOWS - // VC80 was optimizing the error away. - #pragma optimize("", off) -#endif - void crashAndLoop(const std::string& message) - { - // Now, we go kaboom! - int* make_me_crash = NULL; - - *make_me_crash = 0; - - while(true) - { - // Loop forever, in case the crash didn't work? - } - - // this is an attempt to let Coverity and other semantic scanners know that this function won't be returning ever. - exit(EXIT_FAILURE); - } -#if LL_WINDOWS - #pragma optimize("", on) -#endif - std::string utcTime() { time_t now = time(NULL); diff --git a/indra/llcommon/llerror.h b/indra/llcommon/llerror.h index ffaa464d77..f8c0d03aea 100644 --- a/indra/llcommon/llerror.h +++ b/indra/llcommon/llerror.h @@ -382,11 +382,23 @@ typedef LLError::NoClassInfo _LL_CLASS_TO_LOG; #define LL_NEWLINE '\n' -#define LL_ENDL \ - LLError::End(); \ - LLError::Log::flush(_out, _site); \ - } \ - } while(0) +// Use this only in LL_ERRS or in a place that LL_ERRS may not be used +#define LLERROR_CRASH \ +{ \ + int* make_me_crash = NULL;\ + *make_me_crash = 0; \ + exit(*make_me_crash); \ +} + +#define LL_ENDL \ + LLError::End(); \ + LLError::Log::flush(_out, _site); \ + if (_site.mLevel == LLError::LEVEL_ERROR) \ + { \ + LLERROR_CRASH \ + } \ + } \ + } while(0) // NEW Macros for debugging, allow the passing of a string tag diff --git a/indra/llcommon/llerrorcontrol.h b/indra/llcommon/llerrorcontrol.h index 25786d5457..e87bb7bf35 100644 --- a/indra/llcommon/llerrorcontrol.h +++ b/indra/llcommon/llerrorcontrol.h @@ -94,14 +94,16 @@ namespace LLError */ typedef boost::function FatalFunction; - LL_COMMON_API void crashAndLoop(const std::string& message); - // Default fatal function: access null pointer and loops forever LL_COMMON_API void setFatalFunction(const FatalFunction&); - // The fatal function will be called when an message of LEVEL_ERROR + // The fatal function will be called after an message of LEVEL_ERROR // is logged. Note: supressing a LEVEL_ERROR message from being logged // (by, for example, setting a class level to LEVEL_NONE), will keep - // the that message from causing the fatal funciton to be invoked. + // that message from causing the fatal function to be invoked. + // The passed FatalFunction will be the LAST log function called + // before LL_ERRS crashes its caller. A FatalFunction can throw an + // exception, or call exit(), to bypass the crash. It MUST disrupt the + // flow of control because no caller expects LL_ERRS to return. LL_COMMON_API FatalFunction getFatalFunction(); // Retrieve the previously-set FatalFunction @@ -147,14 +149,14 @@ namespace LLError virtual void recordMessage(LLError::ELevel, const std::string& message) = 0; // use the level for better display, not for filtering - virtual bool enabled() { return true; } + virtual bool enabled() { return true; } bool wantsTime(); bool wantsTags(); bool wantsLevel(); bool wantsLocation(); bool wantsFunctionName(); - bool wantsMultiline(); + bool wantsMultiline(); void showTime(bool show); void showTags(bool show); @@ -165,15 +167,35 @@ namespace LLError protected: bool mWantsTime; - bool mWantsTags; - bool mWantsLevel; - bool mWantsLocation; - bool mWantsFunctionName; - bool mWantsMultiline; + bool mWantsTags; + bool mWantsLevel; + bool mWantsLocation; + bool mWantsFunctionName; + bool mWantsMultiline; }; typedef boost::shared_ptr RecorderPtr; + /** + * Instantiate GenericRecorder with a callable(level, message) to get + * control on every log message without having to code an explicit + * Recorder subclass. + */ + template + class GenericRecorder: public Recorder + { + public: + GenericRecorder(const CALLABLE& callable): + mCallable(callable) + {} + void recordMessage(LLError::ELevel level, const std::string& message) override + { + mCallable(level, message); + } + private: + CALLABLE mCallable; + }; + /** * @NOTE: addRecorder() and removeRecorder() uses the boost::shared_ptr to allow for shared ownership * while still ensuring that the allocated memory is eventually freed @@ -181,6 +203,19 @@ namespace LLError LL_COMMON_API void addRecorder(RecorderPtr); LL_COMMON_API void removeRecorder(RecorderPtr); // each error message is passed to each recorder via recordMessage() + /** + * Call addGenericRecorder() with a callable(level, message) to get + * control on every log message without having to code an explicit + * Recorder subclass. Save the returned RecorderPtr if you later want to + * call removeRecorder(). + */ + template + RecorderPtr addGenericRecorder(const CALLABLE& callable) + { + RecorderPtr ptr{ new GenericRecorder(callable) }; + addRecorder(ptr); + return ptr; + } LL_COMMON_API void logToFile(const std::string& filename); LL_COMMON_API void logToStderr(); diff --git a/indra/llcommon/llleap.cpp b/indra/llcommon/llleap.cpp index cf8f8cc6a5..e8ea0ab398 100644 --- a/indra/llcommon/llleap.cpp +++ b/indra/llcommon/llleap.cpp @@ -59,7 +59,6 @@ public: // pump name -- so it should NOT need tweaking for uniqueness. mReplyPump(LLUUID::generateNewID().asString()), mExpect(0), - mPrevFatalFunction(LLError::getFatalFunction()), // Instantiate a distinct LLLeapListener for this plugin. (Every // plugin will want its own collection of managed listeners, etc.) // Pass it a callback to our connect() method, so it can send events @@ -146,7 +145,9 @@ public: .listen("LLLeap", boost::bind(&LLLeapImpl::rstderr, this, _1)); // For our lifespan, intercept any LL_ERRS so we can notify plugin - LLError::setFatalFunction(boost::bind(&LLLeapImpl::fatalFunction, this, _1)); + mRecorder = LLError::addGenericRecorder( + [this](LLError::ELevel level, const std::string& message) + { onError(level, message); }); // Send child a preliminary event reporting our own reply-pump name -- // which would otherwise be pretty tricky to guess! @@ -162,8 +163,7 @@ public: virtual ~LLLeapImpl() { LL_DEBUGS("LLLeap") << "destroying LLLeap(\"" << mDesc << "\")" << LL_ENDL; - // Restore original FatalFunction - LLError::setFatalFunction(mPrevFatalFunction); + LLError::removeRecorder(mRecorder); } // Listener for failed launch attempt @@ -377,28 +377,28 @@ public: return false; } - void fatalFunction(const std::string& error) + void onError(LLError::ELevel level, const std::string& error) { - // Notify plugin - LLSD event; - event["type"] = "error"; - event["error"] = error; - mReplyPump.post(event); - - // All the above really accomplished was to buffer the serialized - // event in our WritePipe. Have to pump mainloop a couple times to - // really write it out there... but time out in case we can't write. - LLProcess::WritePipe& childin(mChild->getWritePipe(LLProcess::STDIN)); - LLEventPump& mainloop(LLEventPumps::instance().obtain("mainloop")); - LLSD nop; - F64 until = (LLTimer::getElapsedSeconds() + 2).value(); - while (childin.size() && LLTimer::getElapsedSeconds() < until) + if (level == LLError::LEVEL_ERROR) { - mainloop.post(nop); + // Notify plugin + LLSD event; + event["type"] = "error"; + event["error"] = error; + mReplyPump.post(event); + + // All the above really accomplished was to buffer the serialized + // event in our WritePipe. Have to pump mainloop a couple times to + // really write it out there... but time out in case we can't write. + LLProcess::WritePipe& childin(mChild->getWritePipe(LLProcess::STDIN)); + LLEventPump& mainloop(LLEventPumps::instance().obtain("mainloop")); + LLSD nop; + F64 until = (LLTimer::getElapsedSeconds() + 2).value(); + while (childin.size() && LLTimer::getElapsedSeconds() < until) + { + mainloop.post(nop); + } } - - // forward the call to the previous FatalFunction - mPrevFatalFunction(error); } private: @@ -421,7 +421,7 @@ private: mStdinConnection, mStdoutConnection, mStdoutDataConnection, mStderrConnection; boost::scoped_ptr mBlocker; LLProcess::ReadPipe::size_type mExpect; - LLError::FatalFunction mPrevFatalFunction; + LLError::RecorderPtr mRecorder; boost::scoped_ptr mListener; }; diff --git a/indra/llcommon/llsingleton.cpp b/indra/llcommon/llsingleton.cpp index d0dcd463ff..4b1666563e 100644 --- a/indra/llcommon/llsingleton.cpp +++ b/indra/llcommon/llsingleton.cpp @@ -486,20 +486,7 @@ void LLSingletonBase::logerrs(std::initializer_list args) log(LLError::LEVEL_ERROR, args); // The other important side effect of LL_ERRS() is // https://www.youtube.com/watch?v=OMG7paGJqhQ (emphasis on OMG) - std::ostringstream out; - for (auto arg : args) - { - out << arg; - } - auto crash = LLError::getFatalFunction(); - if (crash) - { - crash(out.str()); - } - else - { - LLError::crashAndLoop(out.str()); - } + LLERROR_CRASH; } std::string LLSingletonBase::demangle(const char* mangled) diff --git a/indra/llcommon/tests/llerror_test.cpp b/indra/llcommon/tests/llerror_test.cpp index 8e1f4c14ac..148c18aabe 100644 --- a/indra/llcommon/tests/llerror_test.cpp +++ b/indra/llcommon/tests/llerror_test.cpp @@ -26,6 +26,7 @@ */ #include +#include #include "linden_common.h" @@ -69,21 +70,41 @@ namespace namespace { - static bool fatalWasCalled; - void fatalCall(const std::string&) { fatalWasCalled = true; } + static bool fatalWasCalled = false; + struct FatalWasCalled: public std::runtime_error + { + FatalWasCalled(const std::string& what): std::runtime_error(what) {} + }; + void fatalCall(const std::string& msg) { throw FatalWasCalled(msg); } } +// Because we use LLError::setFatalFunction(fatalCall), any LL_ERRS call we +// issue will throw FatalWasCalled. But we want the test program to continue. +// So instead of writing: +// LL_ERRS("tag") << "some message" << LL_ENDL; +// write: +// CATCH(LL_ERRS("tag"), "some message"); +#define CATCH(logcall, expr) \ + try \ + { \ + logcall << expr << LL_ENDL; \ + } \ + catch (const FatalWasCalled&) \ + { \ + fatalWasCalled = true; \ + } + namespace tut { class TestRecorder : public LLError::Recorder { public: TestRecorder() - { - showTime(false); - } + { + showTime(false); + } virtual ~TestRecorder() - {} + {} virtual void recordMessage(LLError::ELevel level, const std::string& message) @@ -252,7 +273,7 @@ namespace LL_DEBUGS("WriteTag","AnotherTag") << "one" << LL_ENDL; LL_INFOS("WriteTag") << "two" << LL_ENDL; LL_WARNS("WriteTag") << "three" << LL_ENDL; - LL_ERRS("WriteTag") << "four" << LL_ENDL; + CATCH(LL_ERRS("WriteTag"), "four"); } }; @@ -380,7 +401,7 @@ namespace std::string errorReturningLocation() { - LL_ERRS() << "die" << LL_ENDL; int this_line = __LINE__; + int this_line = __LINE__; CATCH(LL_ERRS(), "die"); return locationString(this_line); } } @@ -701,7 +722,7 @@ public: static void doDebug() { LL_DEBUGS() << "add dice" << LL_ENDL; } static void doInfo() { LL_INFOS() << "any idea" << LL_ENDL; } static void doWarn() { LL_WARNS() << "aim west" << LL_ENDL; } - static void doError() { LL_ERRS() << "ate eels" << LL_ENDL; } + static void doError() { CATCH(LL_ERRS(), "ate eels"); } static void doAll() { doDebug(); doInfo(); doWarn(); doError(); } }; @@ -712,7 +733,7 @@ public: static void doDebug() { LL_DEBUGS() << "bed down" << LL_ENDL; } static void doInfo() { LL_INFOS() << "buy iron" << LL_ENDL; } static void doWarn() { LL_WARNS() << "bad word" << LL_ENDL; } - static void doError() { LL_ERRS() << "big easy" << LL_ENDL; } + static void doError() { CATCH(LL_ERRS(), "big easy"); } static void doAll() { doDebug(); doInfo(); doWarn(); doError(); } }; @@ -874,13 +895,10 @@ namespace tut namespace { std::string writeTagWithSpaceReturningLocation() - { - LL_DEBUGS("Write Tag") << "not allowed" << LL_ENDL; int this_line = __LINE__; - - std::ostringstream location; - location << LLError::abbreviateFile(__FILE__).c_str() << "(" << this_line << ")"; - return location.str(); - } + { + int this_line = __LINE__; CATCH(LL_DEBUGS("Write Tag"), "not allowed"); + return locationString(this_line); + } }; namespace tut @@ -894,9 +912,9 @@ namespace tut std::string location = writeTagWithSpaceReturningLocation(); std::string expected = "Space is not allowed in a log tag at " + location; - ensure_message_field_equals(0, LEVEL_FIELD, "ERROR"); - ensure_message_field_equals(0, MSG_FIELD, expected); - ensure("fatal callback called", fatalWasCalled); + ensure_message_field_equals(0, LEVEL_FIELD, "ERROR"); + ensure_message_field_equals(0, MSG_FIELD, expected); + ensure("fatal callback called", fatalWasCalled); } } diff --git a/indra/llcommon/tests/wrapllerrs.h b/indra/llcommon/tests/wrapllerrs.h index b07d5afbd8..3779fb41bc 100644 --- a/indra/llcommon/tests/wrapllerrs.h +++ b/indra/llcommon/tests/wrapllerrs.h @@ -44,10 +44,6 @@ #include #include -// statically reference the function in test.cpp... it's short, we could -// replicate, but better to reuse -extern void wouldHaveCrashed(const std::string& message); - struct WrapLLErrs { WrapLLErrs(): @@ -59,7 +55,8 @@ struct WrapLLErrs mPriorFatal(LLError::getFatalFunction()) { // Make LL_ERRS call our own operator() method - LLError::setFatalFunction(boost::bind(&WrapLLErrs::operator(), this, _1)); + LLError::setFatalFunction( + [this](const std::string& message){ (*this)(message); }); } ~WrapLLErrs() @@ -199,11 +196,13 @@ public: // with that output. If it turns out that saveAndResetSettings() has // some bad effect, give up and just let the DEBUG level log messages // display. - : boost::noncopyable(), + : boost::noncopyable(), + mFatalFunction(LLError::getFatalFunction()), mOldSettings(LLError::saveAndResetSettings()), - mRecorder(new CaptureLogRecorder()) + mRecorder(new CaptureLogRecorder()) { - LLError::setFatalFunction(wouldHaveCrashed); + // reinstate the FatalFunction we just reset + LLError::setFatalFunction(mFatalFunction); LLError::setDefaultLevel(level); LLError::addRecorder(mRecorder); } @@ -219,17 +218,18 @@ public: /// for the sought string. std::string messageWith(const std::string& search, bool required=true) { - return boost::dynamic_pointer_cast(mRecorder)->messageWith(search, required); + return boost::dynamic_pointer_cast(mRecorder)->messageWith(search, required); } std::ostream& streamto(std::ostream& out) const { - return boost::dynamic_pointer_cast(mRecorder)->streamto(out); + return boost::dynamic_pointer_cast(mRecorder)->streamto(out); } private: + LLError::FatalFunction mFatalFunction; LLError::SettingsStoragePtr mOldSettings; - LLError::RecorderPtr mRecorder; + LLError::RecorderPtr mRecorder; }; #endif /* ! defined(LL_WRAPLLERRS_H) */ -- cgit v1.2.3