MAINT-5011: Catch unhandled exceptions in LLCoros coroutines.

Wrap coroutine call in try/catch in top-level coroutine wrapper function
LLCoros::toplevel(). Distinguish exception classes derived from
LLContinueError (log and continue) from all others (crash with LL_ERRS).

Enhance CRASH_ON_UNHANDLED_EXCEPTIONS() and LOG_UNHANDLED_EXCEPTIONS() macros
to accept a context string to supplement the log message. This lets us replace
many places that called boost::current_exception_diagnostic_information() with
LOG_UNHANDLED_EXCEPTIONS() instead, since the explicit calls were mostly to
log supplemental information.

Provide supplemental information (coroutine name, function parameters) for
some of the previous LOG_UNHANDLED_EXCEPTIONS() calls. This information
duplicates LL_DEBUGS() information at the top of these functions, but in a
typical log file we wouldn't see the LL_DEBUGS() message.

Eliminate a few catch (std::exception e) clauses: the information we get from
boost::current_exception_diagnostic_information() in a catch (...) clause
makes it unnecessary to distinguish.

In a few cases, add a final 'throw;' to a catch (...) clause: having logged
the local context info, propagate the exception to be caught by higher-level
try/catch.

In a couple places, couldn't resist reconciling indentation within a
particular function: tabs where the rest of the function uses tabs, spaces
where the rest of the function uses spaces.

In LLLogin::Impl::loginCoro(), eliminate some confusing comments about an
array of rewritten URIs that date back to a long-deleted implementation.
master
Nat Goodspeed 2016-08-18 17:33:44 -04:00
parent c7bf8af637
commit 4d10172d8b
10 changed files with 124 additions and 113 deletions

View File

@ -38,6 +38,7 @@
#include "llevents.h"
#include "llerror.h"
#include "stringize.h"
#include "llexception.h"
// do nothing, when we need nothing done
void LLCoros::no_cleanup(CoroData*) {}
@ -235,7 +236,18 @@ void LLCoros::toplevel(coro::self& self, CoroData* data, const callable_t& calla
// capture the 'self' param in CoroData
data->mSelf = &self;
// run the code the caller actually wants in the coroutine
callable();
try
{
callable();
}
catch (const LLContinueError& e)
{
LOG_UNHANDLED_EXCEPTION(STRINGIZE("coroutine " << data->mName));
}
catch (...)
{
CRASH_ON_UNHANDLED_EXCEPTION(STRINGIZE("coroutine " << data->mName));
}
// This cleanup isn't perfectly symmetrical with the way we initially set
// data->mPrev, but this is our last chance to reset mCurrentCoro.
sCurrentCoro.reset(data->mPrev);

View File

@ -24,25 +24,32 @@
namespace {
// used by crash_on_unhandled_exception_() and log_unhandled_exception_()
void log_unhandled_exception_(LLError::ELevel level,
const char* file, int line, const char* pretty_function)
const char* file, int line, const char* pretty_function,
const std::string& context)
{
// log same message but allow caller-specified severity level
// lllog() is the macro underlying LL_ERRS(), LL_WARNS() et al.
lllog(level, false) << file << "(" << line << "): Unhandled exception caught in "
<< pretty_function
<< ":\n" << boost::current_exception_diagnostic_information() << LL_ENDL;
<< pretty_function;
if (! context.empty())
{
LL_CONT << ": " << context;
}
LL_CONT << ":\n" << boost::current_exception_diagnostic_information() << LL_ENDL;
}
}
void crash_on_unhandled_exception_(const char* file, int line, const char* pretty_function)
void crash_on_unhandled_exception_(const char* file, int line, const char* pretty_function,
const std::string& context)
{
// LL_ERRS() terminates and propagates message into crash dump.
log_unhandled_exception_(LLError::LEVEL_ERROR, file, line, pretty_function);
log_unhandled_exception_(LLError::LEVEL_ERROR, file, line, pretty_function, context);
}
void log_unhandled_exception_(const char* file, int line, const char* pretty_function)
void log_unhandled_exception_(const char* file, int line, const char* pretty_function,
const std::string& context)
{
// Use LL_WARNS() because we seriously do not expect this to happen
// routinely, but we DO expect to return from this function.
log_unhandled_exception_(LLError::LEVEL_WARN, file, line, pretty_function);
log_unhandled_exception_(LLError::LEVEL_WARN, file, line, pretty_function, context);
}

View File

@ -31,6 +31,7 @@
* boost::current_exception_diagnostic_information() is quite wonderful: if
* all we need to do with an exception is log it, in most places we should
* catch (...) and log boost::current_exception_diagnostic_information().
* See CRASH_ON_UNHANDLED_EXCEPTION() and LOG_UNHANDLED_EXCEPTION() below.
*
* There may be circumstances in which it would be valuable to distinguish an
* exception explicitly thrown by viewer code from an exception thrown by
@ -71,14 +72,14 @@ struct LLContinueError: public LLException
#define LLTHROW(x) BOOST_THROW_EXCEPTION(x)
/// Call this macro from a catch (...) clause
#define CRASH_ON_UNHANDLED_EXCEPTION() \
crash_on_unhandled_exception_(__FILE__, __LINE__, BOOST_CURRENT_FUNCTION)
void crash_on_unhandled_exception_(const char*, int, const char*);
#define CRASH_ON_UNHANDLED_EXCEPTION(CONTEXT) \
crash_on_unhandled_exception_(__FILE__, __LINE__, BOOST_CURRENT_FUNCTION, CONTEXT)
void crash_on_unhandled_exception_(const char*, int, const char*, const std::string&);
/// Call this from a catch (const LLContinueError&) clause, or from a catch
/// (...) clause in which you do NOT want the viewer to crash.
#define LOG_UNHANDLED_EXCEPTION() \
log_unhandled_exception_(__FILE__, __LINE__, BOOST_CURRENT_FUNCTION)
void log_unhandled_exception_(const char*, int, const char*);
#define LOG_UNHANDLED_EXCEPTION(CONTEXT) \
log_unhandled_exception_(__FILE__, __LINE__, BOOST_CURRENT_FUNCTION, CONTEXT)
void log_unhandled_exception_(const char*, int, const char*, const std::string&);
#endif /* ! defined(LL_LLEXCEPTION_H) */

View File

@ -44,6 +44,7 @@
#include "lleventcoro.h"
#include "llcorehttputil.h"
#include "llexception.h"
#include "stringize.h"
#include <map>
#include <set>
@ -232,13 +233,12 @@ void LLAvatarNameCache::requestAvatarNameCache_(std::string url, std::vector<LLU
LLAvatarNameCache::handleAvNameCacheSuccess(results, httpResults);
}
catch (std::exception e)
{
LL_WARNS() << "Caught exception '" << e.what() << "'" << LL_ENDL;
}
catch (...)
{
LOG_UNHANDLED_EXCEPTION();
LOG_UNHANDLED_EXCEPTION(STRINGIZE("coroutine " << LLCoros::instance().getName()
<< "('" << url << "', " << agentIds.size()
<< " Agent Ids)"));
throw;
}
}

View File

@ -27,8 +27,9 @@
#include "linden_common.h"
#include "llcoproceduremanager.h"
#include "llexception.h"
#include "stringize.h"
#include <boost/assign.hpp>
#include <boost/exception/diagnostic_information.hpp>
//=========================================================================
// Map of pool sizes for known pools
@ -389,15 +390,14 @@ void LLCoprocedurePool::coprocedureInvokerCoro(LLCoreHttpUtil::HttpCoroutineAdap
{
coproc->mProc(httpAdapter, coproc->mId);
}
catch (std::exception &e)
{
LL_WARNS() << "Coprocedure(" << coproc->mName << ") id=" << coproc->mId.asString() <<
" threw an exception! Message=\"" << e.what() << "\"" << LL_ENDL;
}
catch (...)
{
LL_WARNS() << "A non std::exception was thrown from " << coproc->mName << " with id=" << coproc->mId << "." << " in pool \"" << mPoolName << "\"\n"
<< boost::current_exception_diagnostic_information() << LL_ENDL;
LOG_UNHANDLED_EXCEPTION(STRINGIZE("Coprocedure('" << coproc->mName
<< "', id=" << coproc->mId.asString()
<< ") in pool '" << mPoolName << "'"));
// must NOT omit this or we deplete the pool
mActiveCoprocs.erase(itActive);
throw;
}
LL_INFOS() << "Finished coprocedure(" << coproc->mName << ")" << " in pool \"" << mPoolName << "\"" << LL_ENDL;

View File

@ -32,6 +32,7 @@
#include "lleventcoro.h"
#include "llcorehttputil.h"
#include "llexception.h"
#include "stringize.h"
#include <algorithm>
#include <iterator>
@ -155,13 +156,11 @@ void LLAccountingCostManager::accountingCostCoro(std::string url,
} while (false);
}
catch (std::exception e)
{
LL_WARNS() << "Caught exception '" << e.what() << "'" << LL_ENDL;
}
catch (...)
{
LOG_UNHANDLED_EXCEPTION();
LOG_UNHANDLED_EXCEPTION(STRINGIZE("coroutine " << LLCoros::instance().getName()
<< "('" << url << "')"));
throw;
}
mPendingObjectQuota.clear();

View File

@ -31,6 +31,7 @@
#include "llappviewer.h"
#include "llviewercontrol.h"
#include "llexception.h"
#include "stringize.h"
#include <openssl/x509_vfy.h>
#include <openssl/ssl.h>
@ -552,7 +553,7 @@ LLCore::HttpStatus LLAppCoreHttp::sslVerify(const std::string &url,
}
catch (...)
{
LOG_UNHANDLED_EXCEPTION();
LOG_UNHANDLED_EXCEPTION(STRINGIZE("('" << url << "')"));
// any other odd error, we just handle as a connect error.
result = LLCore::HttpStatus(LLCore::HttpStatus::EXT_CURL_EASY, CURLE_SSL_CONNECT_ERROR);
}

View File

@ -30,6 +30,7 @@
#include "llsecapi.h"
#include "llsechandler_basic.h"
#include "llexception.h"
#include "stringize.h"
#include <openssl/evp.h>
#include <openssl/err.h>
#include <map>
@ -102,6 +103,7 @@ std::ostream& operator <<(std::ostream& s, const LLCredential& cred)
LLSD LLCredential::getLoginParams()
{
LLSD result = LLSD::emptyMap();
std::string username;
try
{
if (mIdentifier["type"].asString() == "agent")
@ -110,18 +112,19 @@ LLSD LLCredential::getLoginParams()
result["passwd"] = "$1$" + mAuthenticator["secret"].asString();
result["first"] = mIdentifier["first_name"];
result["last"] = mIdentifier["last_name"];
username = result["first"].asString() + " " + result["last"].asString();
}
else if (mIdentifier["type"].asString() == "account")
{
result["username"] = mIdentifier["account_name"];
result["passwd"] = mAuthenticator["secret"];
username = result["username"].asString();
}
}
catch (...)
{
LOG_UNHANDLED_EXCEPTION();
// nat 2016-08-18: not clear what exceptions the above COULD throw?!
LOG_UNHANDLED_EXCEPTION(STRINGIZE("for '" << username << "'"));
// we could have corrupt data, so simply return a null login param if so
LL_WARNS("AppInit") << "Invalid credential" << LL_ENDL;
}

View File

@ -36,9 +36,9 @@
#include "lldir.h"
#include "llviewercontrol.h"
#include "llexception.h"
#include "stringize.h"
#include <vector>
#include <ios>
#include <boost/exception/diagnostic_information.hpp>
#include <openssl/ossl_typ.h>
#include <openssl/x509.h>
#include <openssl/x509v3.h>
@ -619,8 +619,7 @@ void LLBasicCertificateStore::load_from_file(const std::string& filename)
}
catch (...)
{
LL_WARNS("SECAPI") << "Failure creating certificate from the certificate store file: "
<< boost::current_exception_diagnostic_information() << LL_ENDL;
LOG_UNHANDLED_EXCEPTION("creating certificate from the certificate store file");
}
X509_free(cert_x509);
cert_x509 = NULL;
@ -1367,8 +1366,7 @@ void LLSecAPIBasicHandler::_writeProtectedData()
}
catch (...)
{
LL_WARNS() << "LLProtectedDataException(Error writing Protected Data Store): "
<< boost::current_exception_diagnostic_information() << LL_ENDL;
LOG_UNHANDLED_EXCEPTION("LLProtectedDataException(Error writing Protected Data Store)");
// it's good practice to clean up any secure information on error
// (even though this file isn't really secure. Perhaps in the future
// it may be, however.
@ -1379,29 +1377,28 @@ void LLSecAPIBasicHandler::_writeProtectedData()
//LLTHROW(LLProtectedDataException("Error writing Protected Data Store"));
}
try
{
// move the temporary file to the specified file location.
if((( (LLFile::isfile(mProtectedDataFilename) != 0)
&& (LLFile::remove(mProtectedDataFilename) != 0)))
|| (LLFile::rename(tmp_filename, mProtectedDataFilename)))
{
LL_WARNS() << "LLProtectedDataException(Could not overwrite protected data store)" << LL_ENDL;
LLFile::remove(tmp_filename);
try
{
// move the temporary file to the specified file location.
if((( (LLFile::isfile(mProtectedDataFilename) != 0)
&& (LLFile::remove(mProtectedDataFilename) != 0)))
|| (LLFile::rename(tmp_filename, mProtectedDataFilename)))
{
LL_WARNS() << "LLProtectedDataException(Could not overwrite protected data store)" << LL_ENDL;
LLFile::remove(tmp_filename);
// EXP-1825 crash in LLSecAPIBasicHandler::_writeProtectedData()
// Decided throwing an exception here was overkill until we figure out why this happens
//LLTHROW(LLProtectedDataException("Could not overwrite protected data store"));
}
// EXP-1825 crash in LLSecAPIBasicHandler::_writeProtectedData()
// Decided throwing an exception here was overkill until we figure out why this happens
//LLTHROW(LLProtectedDataException("Could not overwrite protected data store"));
}
}
catch (...)
{
LL_WARNS() << "LLProtectedDataException(Error renaming '" << tmp_filename
<< "' to '" << mProtectedDataFilename << "'): "
<< boost::current_exception_diagnostic_information() << LL_ENDL;
LOG_UNHANDLED_EXCEPTION(STRINGIZE("renaming '" << tmp_filename << "' to '"
<< mProtectedDataFilename << "'"));
// it's good practice to clean up any secure information on error
// (even though this file isn't really secure. Perhaps in the future
// it may be, however.
// it may be, however).
LLFile::remove(tmp_filename);
//crash in LLSecAPIBasicHandler::_writeProtectedData()
@ -1409,7 +1406,7 @@ void LLSecAPIBasicHandler::_writeProtectedData()
//LLTHROW(LLProtectedDataException("Error writing Protected Data Store"));
}
}
// instantiate a certificate from a pem string
LLPointer<LLCertificate> LLSecAPIBasicHandler::getCertificate(const std::string& pem_cert)
{

View File

@ -43,6 +43,7 @@
#include "lleventfilter.h"
#include "lleventcoro.h"
#include "llexception.h"
#include "stringize.h"
//*********************
// LLLogin
@ -129,30 +130,23 @@ void LLLogin::Impl::connect(const std::string& uri, const LLSD& login_params)
void LLLogin::Impl::loginCoro(std::string uri, LLSD login_params)
{
try
{
LLSD printable_params = login_params;
//if(printable_params.has("params")
// && printable_params["params"].has("passwd"))
//{
// printable_params["params"]["passwd"] = "*******";
//}
LL_DEBUGS("LLLogin") << "Entering coroutine " << LLCoros::instance().getName()
LLSD printable_params = login_params;
if (printable_params.has("params")
&& printable_params["params"].has("passwd"))
{
printable_params["params"]["passwd"] = "*******";
}
try
{
LL_DEBUGS("LLLogin") << "Entering coroutine " << LLCoros::instance().getName()
<< " with uri '" << uri << "', parameters " << printable_params << LL_ENDL;
// Arriving in SRVRequest state
LLEventStream replyPump("SRVreply", true);
// Should be an array of one or more uri strings.
LLEventPump& xmlrpcPump(LLEventPumps::instance().obtain("LLXMLRPCTransaction"));
// EXT-4193: use a DIFFERENT reply pump than for the SRV request. We used
// to share them -- but the EXT-3934 fix made it possible for an abandoned
// SRV response to arrive just as we were expecting the XMLRPC response.
LLEventStream loginReplyPump("loginreply", true);
// Loop through the rewrittenURIs, counting attempts along the way.
// Because of possible redirect responses, we may make more than one
// attempt per rewrittenURIs entry.
LLSD::Integer attempts = 0;
LLSD request(login_params);
@ -168,11 +162,11 @@ void LLLogin::Impl::loginCoro(std::string uri, LLSD login_params)
LLSD progress_data;
progress_data["attempt"] = attempts;
progress_data["request"] = request;
if(progress_data["request"].has("params")
&& progress_data["request"]["params"].has("passwd"))
{
progress_data["request"]["params"]["passwd"] = "*******";
}
if (progress_data["request"].has("params")
&& progress_data["request"]["params"].has("passwd"))
{
progress_data["request"]["params"]["passwd"] = "*******";
}
sendProgressEvent("offline", "authenticating", progress_data);
// We expect zero or more "Downloading" status events, followed by
@ -190,8 +184,8 @@ void LLLogin::Impl::loginCoro(std::string uri, LLSD login_params)
// Still Downloading -- send progress update.
sendProgressEvent("offline", "downloading");
}
LL_DEBUGS("LLLogin") << "Auth Response: " << mAuthResponse << LL_ENDL;
LL_DEBUGS("LLLogin") << "Auth Response: " << mAuthResponse << LL_ENDL;
status = mAuthResponse["status"].asString();
// Okay, we've received our final status event for this
@ -203,7 +197,7 @@ void LLLogin::Impl::loginCoro(std::string uri, LLSD login_params)
break;
}
sendProgressEvent("offline", "indeterminate", mAuthResponse["responses"]);
sendProgressEvent("offline", "indeterminate", mAuthResponse["responses"]);
// Here the login service at the current URI is redirecting us
// to some other URI ("indeterminate" -- why not "redirect"?).
@ -213,8 +207,7 @@ void LLLogin::Impl::loginCoro(std::string uri, LLSD login_params)
request["method"] = mAuthResponse["responses"]["next_method"].asString();
} // loop back to try the redirected URI
// Here we're done with redirects for the current rewrittenURIs
// entry.
// Here we're done with redirects.
if (status == "Complete")
{
// StatusComplete does not imply auth success. Check the
@ -231,14 +224,14 @@ void LLLogin::Impl::loginCoro(std::string uri, LLSD login_params)
return; // Done!
}
// /* Sometimes we end with "Started" here. Slightly slow server?
// * Seems to be ok to just skip it. Otherwise we'd error out and crash in the if below.
// */
// if( status == "Started")
// {
// LL_DEBUGS("LLLogin") << mAuthResponse << LL_ENDL;
// continue;
// }
// /* Sometimes we end with "Started" here. Slightly slow server?
// * Seems to be ok to just skip it. Otherwise we'd error out and crash in the if below.
// */
// if( status == "Started")
// {
// LL_DEBUGS("LLLogin") << mAuthResponse << LL_ENDL;
// continue;
// }
// If we don't recognize status at all, trouble
if (! (status == "CURLError"
@ -251,27 +244,25 @@ void LLLogin::Impl::loginCoro(std::string uri, LLSD login_params)
}
// Here status IS one of the errors tested above.
// Tell caller this didn't work out so well.
// Here we got through all the rewrittenURIs without succeeding. Tell
// caller this didn't work out so well. Of course, the only failure data
// we can reasonably show are from the last of the rewrittenURIs.
// *NOTE: The response from LLXMLRPCListener's Poller::poll method returns an
// llsd with no "responses" node. To make the output from an incomplete login symmetrical
// to success, add a data/message and data/reason fields.
LLSD error_response;
error_response["reason"] = mAuthResponse["status"];
error_response["errorcode"] = mAuthResponse["errorcode"];
error_response["message"] = mAuthResponse["error"];
if(mAuthResponse.has("certificate"))
{
error_response["certificate"] = mAuthResponse["certificate"];
}
sendProgressEvent("offline", "fail.login", error_response);
}
catch (...) {
CRASH_ON_UNHANDLED_EXCEPTION();
}
// *NOTE: The response from LLXMLRPCListener's Poller::poll method returns an
// llsd with no "responses" node. To make the output from an incomplete login symmetrical
// to success, add a data/message and data/reason fields.
LLSD error_response;
error_response["reason"] = mAuthResponse["status"];
error_response["errorcode"] = mAuthResponse["errorcode"];
error_response["message"] = mAuthResponse["error"];
if(mAuthResponse.has("certificate"))
{
error_response["certificate"] = mAuthResponse["certificate"];
}
sendProgressEvent("offline", "fail.login", error_response);
}
catch (...) {
CRASH_ON_UNHANDLED_EXCEPTION(STRINGIZE("coroutine " << LLCoros::instance().getName()
<< "('" << uri << "', " << printable_params << ")"));
}
}
void LLLogin::Impl::disconnect()