livie
/
phoenix-firestorm
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

DRTVWR-476: Cherry-pick debug aids from commit 77b0c53 (fiber-mutex)

master
Nat Goodspeed 2020-04-03 10:38:53 -04:00
parent b793ab8619
commit dc07509f29
8 changed files with 320 additions and 109 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

15
indra/llcommon/llerror.h
View File

@ -191,9 +191,9 @@ namespace LLError
The classes CallSite and Log are used by the logging macros below.
They are not intended for general use.
*/
struct CallSite;
class LL_COMMON_API Log
{
public:
@ -202,8 +202,17 @@ namespace LLError
static void flush(std::ostringstream* out, char* message);
static void flush(std::ostringstream*, const CallSite&);
static std::string demangle(const char* mangled);
/// classname<TYPE>()
template <typename T>
static std::string classname() { return demangle(typeid(T).name()); }
/// classname(some_pointer)
template <typename T>
static std::string classname(const T* ptr) { return demangle(typeid(*ptr).name()); }
/// classname(some_reference)
template <typename T>
static std::string classname(const T& obj) { return demangle(typeid(obj).name()); }
};
struct LL_COMMON_API CallSite
{
// Represents a specific place in the code where a message is logged

2
indra/llcommon/llsingleton.h
View File

@ -120,6 +120,8 @@ protected:
static void logdebugs(const char* p1, const char* p2="",
const char* p3="", const char* p4="");
static std::string demangle(const char* mangled);
// these classname() declarations restate template functions declared in
// llerror.h because we avoid #including that here
template <typename T>
static std::string classname() { return demangle(typeid(T).name()); }
template <typename T>

119
indra/llcommon/tests/lleventdispatcher_test.cpp
View File

@ -23,6 +23,7 @@
#include "stringize.h"
#include "tests/wrapllerrs.h"
#include "../test/catch_and_store_what_in.h"
#include "../test/debug.h"
#include <map>
#include <string>
@ -45,15 +46,6 @@ using boost::lambda::var;
using namespace llsd;
/*****************************************************************************
* Output control
*****************************************************************************/
#ifdef DEBUG_ON
using std::cout;
#else
static std::ostringstream cout;
#endif
/*****************************************************************************
* Example data, functions, classes
*****************************************************************************/
@ -155,13 +147,13 @@ struct Vars
/*------------- no-args (non-const, const, static) methods -------------*/
void method0()
{
cout << "method0()\n";
debug()("method0()");
i = 17;
}
void cmethod0() const
{
cout << 'c';
debug()('c', NONL);
const_cast<Vars*>(this)->method0();
}
@ -170,13 +162,13 @@ struct Vars
/*------------ Callable (non-const, const, static) methods -------------*/
void method1(const LLSD& obj)
{
cout << "method1(" << obj << ")\n";
debug()("method1(", obj, ")");
llsd = obj;
}
void cmethod1(const LLSD& obj) const
{
cout << 'c';
debug()('c', NONL);
const_cast<Vars*>(this)->method1(obj);
}
@ -196,12 +188,12 @@ struct Vars
else
vcp = std::string("'") + cp + "'";
cout << "methodna(" << b
<< ", " << i
<< ", " << f
<< ", " << d
<< ", " << vcp
<< ")\n";
debug()("methodna(", b,
", ", i,
", ", f,
", ", d,
", ", vcp,
")");
this->b = b;
this->i = i;
@ -218,12 +210,12 @@ struct Vars
vbin << std::hex << std::setfill('0') << std::setw(2) << unsigned(byte);
}
cout << "methodnb(" << "'" << s << "'"
<< ", " << uuid
<< ", " << date
<< ", '" << uri << "'"
<< ", " << vbin.str()
<< ")\n";
debug()("methodnb(", "'", s, "'",
", ", uuid,
", ", date,
", '", uri, "'",
", ", vbin.str(),
")");
this->s = s;
this->uuid = uuid;
@ -234,18 +226,30 @@ struct Vars
void cmethodna(NPARAMSa) const
{
cout << 'c';
debug()('c', NONL);
const_cast<Vars*>(this)->methodna(NARGSa);
}
void cmethodnb(NPARAMSb) const
{
cout << 'c';
debug()('c', NONL);
const_cast<Vars*>(this)->methodnb(NARGSb);
}
static void smethodna(NPARAMSa);
static void smethodnb(NPARAMSb);
static Debug& debug()
{
// Lazily initialize this Debug instance so it can notice if main()
// has forcibly set LOGTEST. If it were simply a static member, it
// would already have examined the environment variable by the time
// main() gets around to checking command-line switches. Since we have
// a global static Vars instance, the same would be true of a plain
// non-static member.
static Debug sDebug("Vars");
return sDebug;
}
};
/*------- Global Vars instance for free functions and static methods -------*/
static Vars g;
@ -253,25 +257,25 @@ static Vars g;
/*------------ Static Vars method implementations reference 'g' ------------*/
void Vars::smethod0()
{
cout << "smethod0() -> ";
debug()("smethod0() -> ", NONL);
g.method0();
}
void Vars::smethod1(const LLSD& obj)
{
cout << "smethod1(" << obj << ") -> ";
debug()("smethod1(", obj, ") -> ", NONL);
g.method1(obj);
}
void Vars::smethodna(NPARAMSa)
{
cout << "smethodna(...) -> ";
debug()("smethodna(...) -> ", NONL);
g.methodna(NARGSa);
}
void Vars::smethodnb(NPARAMSb)
{
cout << "smethodnb(...) -> ";
debug()("smethodnb(...) -> ", NONL);
g.methodnb(NARGSb);
}
@ -284,25 +288,25 @@ void clear()
/*------------------- Free functions also reference 'g' --------------------*/
void free0()
{
cout << "free0() -> ";
g.debug()("free0() -> ", NONL);
g.method0();
}
void free1(const LLSD& obj)
{
cout << "free1(" << obj << ") -> ";
g.debug()("free1(", obj, ") -> ", NONL);
g.method1(obj);
}
void freena(NPARAMSa)
{
cout << "freena(...) -> ";
g.debug()("freena(...) -> ", NONL);
g.methodna(NARGSa);
}
void freenb(NPARAMSb)
{
cout << "freenb(...) -> ";
g.debug()("freenb(...) -> ", NONL);
g.methodnb(NARGSb);
}
@ -313,6 +317,7 @@ namespace tut
{
struct lleventdispatcher_data
{
Debug debug{"test"};
WrapLLErrs redirect;
Dispatcher work;
Vars v;
@ -431,7 +436,12 @@ namespace tut
// Same for freenb() et al.
params = LLSDMap("a", LLSDArray("b")("i")("f")("d")("cp"))
("b", LLSDArray("s")("uuid")("date")("uri")("bin"));
cout << "params:\n" << params << "\nparams[\"a\"]:\n" << params["a"] << "\nparams[\"b\"]:\n" << params["b"] << std::endl;
debug("params:\n",
params, "\n"
"params[\"a\"]:\n",
params["a"], "\n"
"params[\"b\"]:\n",
params["b"]);
// default LLSD::Binary value
std::vector<U8> binary;
for (size_t ix = 0, h = 0xaa; ix < 6; ++ix, h += 0x11)
@ -448,7 +458,8 @@ namespace tut
(LLDate::now())
(LLURI("http://www.ietf.org/rfc/rfc3986.txt"))
(binary));
cout << "dft_array_full:\n" << dft_array_full << std::endl;
debug("dft_array_full:\n",
dft_array_full);
// Partial defaults arrays.
foreach(LLSD::String a, ab)
{
@ -457,7 +468,8 @@ namespace tut
llsd_copy_array(dft_array_full[a].beginArray() + partition,
dft_array_full[a].endArray());
}
cout << "dft_array_partial:\n" << dft_array_partial << std::endl;
debug("dft_array_partial:\n",
dft_array_partial);
foreach(LLSD::String a, ab)
{
@ -473,7 +485,10 @@ namespace tut
dft_map_partial[a][params[a][ix].asString()] = dft_array_full[a][ix];
}
}
cout << "dft_map_full:\n" << dft_map_full << "\ndft_map_partial:\n" << dft_map_partial << '\n';
debug("dft_map_full:\n",
dft_map_full, "\n"
"dft_map_partial:\n",
dft_map_partial);
// (Free function | static method) with (no | arbitrary) params,
// map style, no (empty array) defaults
@ -918,7 +933,12 @@ namespace tut
params[a].endArray()),
dft_array_partial[a]);
}
cout << "allreq:\n" << allreq << "\nleftreq:\n" << leftreq << "\nrightdft:\n" << rightdft << std::endl;
debug("allreq:\n",
allreq, "\n"
"leftreq:\n",
leftreq, "\n"
"rightdft:\n",
rightdft);
// Generate maps containing parameter names not provided by the
// dft_map_partial maps.
@ -930,7 +950,8 @@ namespace tut
skipreq[a].erase(me.first);
}
}
cout << "skipreq:\n" << skipreq << std::endl;
debug("skipreq:\n",
skipreq);
LLSD groups(LLSDArray // array of groups
@ -975,7 +996,11 @@ namespace tut
LLSD names(grp[0]);
LLSD required(grp[1][0]);
LLSD optional(grp[1][1]);
cout << "For " << names << ",\n" << "required:\n" << required << "\noptional:\n" << optional << std::endl;
debug("For ", names, ",\n",
"required:\n",
required, "\n"
"optional:\n",
optional);
// Loop through 'names'
foreach(LLSD nm, inArray(names))
@ -1163,7 +1188,7 @@ namespace tut
}
// Adjust expect["a"]["cp"] for special Vars::cp treatment.
expect["a"]["cp"] = std::string("'") + expect["a"]["cp"].asString() + "'";
cout << "expect: " << expect << '\n';
debug("expect: ", expect);
// Use substantially the same logic for args and argsplus
LLSD argsarrays(LLSDArray(args)(argsplus));
@ -1218,7 +1243,8 @@ namespace tut
{
array_overfull[a].append("bogus");
}
cout << "array_full: " << array_full << "\narray_overfull: " << array_overfull << std::endl;
debug("array_full: ", array_full, "\n"
"array_overfull: ", array_overfull);
// We rather hope that LLDate::now() will generate a timestamp
// distinct from the one it generated in the constructor, moments ago.
ensure_not_equals("Timestamps too close",
@ -1233,7 +1259,8 @@ namespace tut
map_overfull[a] = map_full[a];
map_overfull[a]["extra"] = "ignore";
}
cout << "map_full: " << map_full << "\nmap_overfull: " << map_overfull << std::endl;
debug("map_full: ", map_full, "\n"
"map_overfull: ", map_overfull);
LLSD expect(map_full);
// Twiddle the const char* param.
expect["a"]["cp"] = std::string("'") + expect["a"]["cp"].asString() + "'";
@ -1248,7 +1275,7 @@ namespace tut
// so won't bother returning it. Predict that behavior to match the
// LLSD values.
expect["a"].erase("b");
cout << "expect: " << expect << std::endl;
debug("expect: ", expect);
// For this test, calling functions registered with different sets of
// parameter defaults should make NO DIFFERENCE WHATSOEVER. Every call
// should pass all params.

105
indra/test/chained_callback.h Normal file
View File

@ -0,0 +1,105 @@
/**
* @file chained_callback.h
* @author Nat Goodspeed
* @date 2020-01-03
* @brief Subclass of tut::callback used for chaining callbacks.
*
* $LicenseInfo:firstyear=2020&license=viewerlgpl$
* Copyright (c) 2020, Linden Research, Inc.
* $/LicenseInfo$
*/
#if ! defined(LL_CHAINED_CALLBACK_H)
#define LL_CHAINED_CALLBACK_H
/**
* Derive your TUT callback from chained_callback instead of tut::callback to
* ensure that multiple such callbacks can coexist in a given test executable.
* The relevant callback method will be called for each callback instance in
* reverse order of the instance's link() methods being called: the most
* recently link()ed callback will be called first, then the previous, and so
* forth.
*
* Obviously, for this to work, all relevant callbacks must be derived from
* chained_callback instead of tut::callback. Given that, control should reach
* each of them regardless of their construction order. The chain is
* guaranteed to stop because the first link() call will link to test_runner's
* default_callback, which is simply an instance of the callback() base class.
*
* The rule for deriving from chained_callback is that you may override any of
* its virtual methods, but your override must at some point call the
* corresponding chained_callback method.
*/
class chained_callback: public tut::callback
{
public:
/**
* Instead of calling tut::test_runner::set_callback(&your_callback), call
* your_callback.link();
* This uses the canonical instance of tut::test_runner.
*/
void link()
{
link(tut::runner.get());
}
/**
* If for some reason you have a different instance of test_runner...
*/
void link(tut::test_runner& runner)
{
// Since test_runner's constructor sets a default callback,
// get_callback() will always return a reference to a valid callback
// instance.
mPrev = &runner.get_callback();
runner.set_callback(this);
}
/**
* Called when new test run started.
*/
virtual void run_started()
{
mPrev->run_started();
}
/**
* Called when a group started
* @param name Name of the group
*/
virtual void group_started(const std::string& name)
{
mPrev->group_started(name);
}
/**
* Called when a test finished.
* @param tr Test results.
*/
virtual void test_completed(const tut::test_result& tr)
{
mPrev->test_completed(tr);
}
/**
* Called when a group is completed
* @param name Name of the group
*/
virtual void group_completed(const std::string& name)
{
mPrev->group_completed(name);
}
/**
* Called when all tests in run completed.
*/
virtual void run_completed()
{
mPrev->run_completed();
}
private:
tut::callback* mPrev;
};
#endif /* ! defined(LL_CHAINED_CALLBACK_H) */

40
indra/test/debug.h
View File

@ -29,37 +29,59 @@
#if ! defined(LL_DEBUG_H)
#define LL_DEBUG_H
#include <iostream>
#include "print.h"
/*****************************************************************************
* Debugging stuff
*****************************************************************************/
// This class is intended to illuminate entry to a given block, exit from the
// same block and checkpoints along the way. It also provides a convenient
// place to turn std::cout output on and off.
/**
* This class is intended to illuminate entry to a given block, exit from the
* same block and checkpoints along the way. It also provides a convenient
* place to turn std::cerr output on and off.
*
* If the environment variable LOGTEST is non-empty, each Debug instance will
* announce its construction and destruction, presumably at entry and exit to
* the block in which it's declared. Moreover, any arguments passed to its
* operator()() will be streamed to std::cerr, prefixed by the block
* description.
*
* The variable LOGTEST is used because that's the environment variable
* checked by test.cpp, our TUT main() program, to turn on LLError logging. It
* is expected that Debug is solely for use in test programs.
*/
class Debug
{
public:
Debug(const std::string& block):
mBlock(block)
mBlock(block),
mLOGTEST(getenv("LOGTEST")),
// debug output enabled when LOGTEST is set AND non-empty
mEnabled(mLOGTEST && *mLOGTEST)
{
(*this)("entry");
}
// non-copyable
Debug(const Debug&) = delete;
~Debug()
{
(*this)("exit");
}
void operator()(const std::string& status)
template <typename... ARGS>
void operator()(ARGS&&... args)
{
#if defined(DEBUG_ON)
std::cout << mBlock << ' ' << status << std::endl;
#endif
if (mEnabled)
{
print(mBlock, ' ', std::forward<ARGS>(args)...);
}
}
private:
const std::string mBlock;
const char* mLOGTEST;
bool mEnabled;
};
// It's often convenient to use the name of the enclosing function as the name

42
indra/test/print.h Normal file
View File

@ -0,0 +1,42 @@
/**
* @file print.h
* @author Nat Goodspeed
* @date 2020-01-02
* @brief print() function for debugging
*
* $LicenseInfo:firstyear=2020&license=viewerlgpl$
* Copyright (c) 2020, Linden Research, Inc.
* $/LicenseInfo$
*/
#if ! defined(LL_PRINT_H)
#define LL_PRINT_H
#include <iostream>
// print(..., NONL);
// leaves the output dangling, suppressing the normally appended std::endl
struct NONL_t {};
#define NONL (NONL_t())
// normal recursion end
inline
void print()
{
std::cerr << std::endl;
}
// print(NONL) is a no-op
inline
void print(NONL_t)
{
}
template <typename T, typename... ARGS>
void print(T&& first, ARGS&&... rest)
{
std::cerr << first;
print(std::forward<ARGS>(rest)...);
}
#endif /* ! defined(LL_PRINT_H) */

105
indra/test/test.cpp
View File

@ -37,6 +37,7 @@
#include "linden_common.h"
#include "llerrorcontrol.h"
#include "lltut.h"
#include "chained_callback.h"
#include "stringize.h"
#include "namedtempfile.h"
#include "lltrace.h"
@ -71,7 +72,6 @@
#include <boost/shared_ptr.hpp>
#include <boost/make_shared.hpp>
#include <boost/foreach.hpp>
#include <boost/lambda/lambda.hpp>
#include <fstream>
@ -172,8 +172,10 @@ private:
LLError::RecorderPtr mRecorder;
};
class LLTestCallback : public tut::callback
class LLTestCallback : public chained_callback
{
typedef chained_callback super;
public:
LLTestCallback(bool verbose_mode, std::ostream *stream,
boost::shared_ptr<LLReplayLog> replayer) :
@ -184,7 +186,7 @@ public:
mSkippedTests(0),
// By default, capture a shared_ptr to std::cout, with a no-op "deleter"
// so that destroying the shared_ptr makes no attempt to delete std::cout.
mStream(boost::shared_ptr<std::ostream>(&std::cout, boost::lambda::_1)),
mStream(boost::shared_ptr<std::ostream>(&std::cout, [](std::ostream*){})),
mReplayer(replayer)
{
if (stream)
@ -205,22 +207,25 @@ public:
~LLTestCallback()
{
}
}
virtual void run_started()
{
//std::cout << "run_started" << std::endl;
LL_INFOS("TestRunner")<<"Test Started"<< LL_ENDL;
super::run_started();
}
virtual void group_started(const std::string& name) {
LL_INFOS("TestRunner")<<"Unit test group_started name=" << name << LL_ENDL;
*mStream << "Unit test group_started name=" << name << std::endl;
super::group_started(name);
}
virtual void group_completed(const std::string& name) {
LL_INFOS("TestRunner")<<"Unit test group_completed name=" << name << LL_ENDL;
*mStream << "Unit test group_completed name=" << name << std::endl;
super::group_completed(name);
}
virtual void test_completed(const tut::test_result& tr)
@ -282,6 +287,7 @@ public:
*mStream << std::endl;
}
LL_INFOS("TestRunner")<<out.str()<<LL_ENDL;
super::test_completed(tr);
}
virtual int getFailedTests() const { return mFailedTests; }
@ -309,6 +315,7 @@ public:
*mStream << "Please report or fix the problem." << std::endl;
*mStream << "*********************************" << std::endl;
}
super::run_completed();
}
protected:
@ -474,9 +481,8 @@ void stream_usage(std::ostream& s, const char* app)
<< "LOGTEST=level : for all tests, emit log messages at level 'level'\n"
<< "LOGFAIL=level : only for failed tests, emit log messages at level 'level'\n"
<< "where 'level' is one of ALL, DEBUG, INFO, WARN, ERROR, NONE.\n"
<< "--debug is like LOGTEST=DEBUG, but --debug overrides LOGTEST.\n"
<< "Setting LOGFAIL overrides both LOGTEST and --debug: the only log\n"
<< "messages you will see will be for failed tests.\n\n";
<< "--debug is like LOGTEST=DEBUG, but --debug overrides LOGTEST,\n"
<< "while LOGTEST overrides LOGFAIL.\n\n";
s << "Examples:" << std::endl;
s << " " << app << " --verbose" << std::endl;
@ -520,35 +526,8 @@ int main(int argc, char **argv)
#ifndef LL_WINDOWS
::testing::InitGoogleMock(&argc, argv);
#endif
// LOGTEST overrides default, but can be overridden by --debug or LOGFAIL.
const char* LOGTEST = getenv("LOGTEST");
if (LOGTEST)
{
LLError::initForApplication(".", ".", true /* log to stderr */);
LLError::setDefaultLevel(LLError::decodeLevel(LOGTEST));
}
else
{
LLError::initForApplication(".", ".", false /* do not log to stderr */);
LLError::setDefaultLevel(LLError::LEVEL_DEBUG);
}
LLError::setFatalFunction(wouldHaveCrashed);
std::string test_app_name(argv[0]);
std::string test_log = test_app_name + ".log";
LLFile::remove(test_log);
LLError::logToFile(test_log);
#ifdef CTYPE_WORKAROUND
ctype_workaround();
#endif
ll_init_apr();
if (!sMasterThreadRecorder)
{
sMasterThreadRecorder = new LLTrace::ThreadRecorder();
LLTrace::set_master_thread_recorder(sMasterThreadRecorder);
}
apr_getopt_t* os = NULL;
if(APR_SUCCESS != apr_getopt_init(&os, gAPRPoolp, argc, argv))
{
@ -562,7 +541,13 @@ int main(int argc, char **argv)
std::string test_group;
std::string suite_name;
// values use for options parsing
// LOGTEST overrides default, but can be overridden by --debug.
const char* LOGTEST = getenv("LOGTEST");
// DELETE
LOGTEST = "DEBUG";
// values used for options parsing
apr_status_t apr_err;
const char* opt_arg = NULL;
int opt_id = 0;
@ -611,10 +596,7 @@ int main(int argc, char **argv)
wait_at_exit = true;
break;
case 'd':
// this is what LLError::initForApplication() does internally
// when you pass log_to_stderr=true
LLError::logToStderr();
LLError::setDefaultLevel(LLError::LEVEL_DEBUG);
LOGTEST = "DEBUG";
break;
case 'x':
suite_name.assign(opt_arg);
@ -626,22 +608,44 @@ int main(int argc, char **argv)
}
}
// run the tests
// set up logging
const char* LOGFAIL = getenv("LOGFAIL");
boost::shared_ptr<LLReplayLog> replayer;
// As described in stream_usage(), LOGFAIL overrides both --debug and
// LOGTEST. But allow user to set LOGFAIL empty to revert to LOGTEST
// and/or --debug.
if (LOGFAIL && *LOGFAIL)
boost::shared_ptr<LLReplayLog> replayer{boost::make_shared<LLReplayLog>()};
// Testing environment variables for both 'set' and 'not empty' allows a
// user to suppress a pre-existing environment variable by forcing empty.
if (LOGTEST && *LOGTEST)
{
LLError::ELevel level = LLError::decodeLevel(LOGFAIL);
replayer.reset(new LLReplayLogReal(level, gAPRPoolp));
LLError::initForApplication(".", ".", true /* log to stderr */);
LLError::setDefaultLevel(LLError::decodeLevel(LOGTEST));
}
else
{
replayer.reset(new LLReplayLog());
LLError::initForApplication(".", ".", false /* do not log to stderr */);
LLError::setDefaultLevel(LLError::LEVEL_DEBUG);
if (LOGFAIL && *LOGFAIL)
{
LLError::ELevel level = LLError::decodeLevel(LOGFAIL);
replayer.reset(new LLReplayLogReal(level, gAPRPoolp));
}
}
LLError::setFatalFunction(wouldHaveCrashed);
std::string test_app_name(argv[0]);
std::string test_log = test_app_name + ".log";
LLFile::remove(test_log);
LLError::logToFile(test_log);
#ifdef CTYPE_WORKAROUND
ctype_workaround();
#endif
if (!sMasterThreadRecorder)
{
sMasterThreadRecorder = new LLTrace::ThreadRecorder();
LLTrace::set_master_thread_recorder(sMasterThreadRecorder);
}
// run the tests
LLTestCallback* mycallback;
if (getenv("TEAMCITY_PROJECT_NAME"))
@ -653,7 +657,8 @@ int main(int argc, char **argv)
mycallback = new LLTestCallback(verbose_mode, output.get(), replayer);
}
tut::runner.get().set_callback(mycallback);
// a chained_callback subclass must be linked with previous
mycallback->link();
if(test_group.empty())
{

1
indra/viewer_components/login/tests/lllogin_test.cpp
View File

@ -43,7 +43,6 @@
#include "llsd.h"
#include "../../../test/lltut.h"
#include "../../../test/lltestapp.h"
//#define DEBUG_ON
#include "../../../test/debug.h"
#include "llevents.h"
#include "lleventcoro.h"