From 90ba675da4416a7f75f59340633e2c007b6cc029 Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Fri, 3 Feb 2012 13:09:20 -0500 Subject: Escape all strings embedded in TeamCity service messages. TeamCity requires that certain characters (notably "'") must be escaped when embedded in service messages: http://confluence.jetbrains.net/display/TCD65/Build+Script+Interaction+with+TeamCity#BuildScriptInteractionwithTeamCity-ServiceMessages TUT frequently outputs messages containing "'", e.g. from ensure_equals() failure. We've seen TC output nesting get confused when it fails to process service messages properly due to parsing unescaped messages. Along with test number, report test name (from set_test_name()) when available. Eliminate horsing around to produce normal output on both std::cout and possible output file. When output file is specified, use boost::iostreams::tee_device to do fanout for us. Improve placement (and possibly reliability) of service messages. Clean up a startling amount of redundancy in service-message production. --- indra/test/test.cpp | 183 ++++++++++++++++++++++++++++++++-------------------- 1 file changed, 112 insertions(+), 71 deletions(-) (limited to 'indra/test/test.cpp') diff --git a/indra/test/test.cpp b/indra/test/test.cpp index ffdb0cb976..3e7be29b39 100644 --- a/indra/test/test.cpp +++ b/indra/test/test.cpp @@ -37,6 +37,7 @@ #include "linden_common.h" #include "llerrorcontrol.h" #include "lltut.h" +#include "stringize.h" #include "apr_pools.h" #include "apr_getopt.h" @@ -53,6 +54,13 @@ #include #endif +#include +#include +#include +#include +#include +#include + namespace tut { std::string sSourceDir; @@ -69,8 +77,24 @@ public: mPassedTests(0), mFailedTests(0), mSkippedTests(0), - mStream(stream) + // 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::cout, boost::lambda::_1)) { + if (stream) + { + // We want a boost::iostreams::tee_device that will stream to two + // std::ostreams. + typedef boost::iostreams::tee_device TeeDevice; + // More than that, though, we want an actual stream using that + // device. + typedef boost::iostreams::stream TeeStream; + // Allocate and assign in two separate steps, per Herb Sutter. + // (Until we turn on C++11 support, have to wrap *stream with + // boost::ref() due to lack of perfect forwarding.) + boost::shared_ptr pstream(new TeeStream(std::cout, boost::ref(*stream))); + mStream = pstream; + } } ~LLTestCallback() @@ -94,7 +118,10 @@ public: { ++mTotalTests; std::ostringstream out; - out << "[" << tr.group << ", " << tr.test << "] "; + out << "[" << tr.group << ", " << tr.test; + if (! tr.name.empty()) + out << ": " << tr.name; + out << "] "; switch(tr.result) { case tut::test_result::ok: @@ -123,56 +150,43 @@ public: break; default: ++mFailedTests; - out << "unknown"; + out << "unknown (tr.result == " << tr.result << ")"; } if(mVerboseMode || (tr.result != tut::test_result::ok)) { + *mStream << out.str(); if(!tr.message.empty()) { - out << ": '" << tr.message << "'"; + *mStream << ": '" << tr.message << "'"; } - if (mStream) - { - *mStream << out.str() << std::endl; - } - - std::cout << out.str() << std::endl; - } - } - - virtual void run_completed() - { - if (mStream) - { - run_completed_(*mStream); + *mStream << std::endl; } - run_completed_(std::cout); } virtual int getFailedTests() const { return mFailedTests; } - virtual void run_completed_(std::ostream &stream) + virtual void run_completed() { - stream << "\tTotal Tests:\t" << mTotalTests << std::endl; - stream << "\tPassed Tests:\t" << mPassedTests; + *mStream << "\tTotal Tests:\t" << mTotalTests << std::endl; + *mStream << "\tPassed Tests:\t" << mPassedTests; if (mPassedTests == mTotalTests) { - stream << "\tYAY!! \\o/"; + *mStream << "\tYAY!! \\o/"; } - stream << std::endl; + *mStream << std::endl; if (mSkippedTests > 0) { - stream << "\tSkipped known failures:\t" << mSkippedTests + *mStream << "\tSkipped known failures:\t" << mSkippedTests << std::endl; } if(mFailedTests > 0) { - stream << "*********************************" << std::endl; - stream << "Failed Tests:\t" << mFailedTests << std::endl; - stream << "Please report or fix the problem." << std::endl; - stream << "*********************************" << std::endl; + *mStream << "*********************************" << std::endl; + *mStream << "Failed Tests:\t" << mFailedTests << std::endl; + *mStream << "Please report or fix the problem." << std::endl; + *mStream << "*********************************" << std::endl; } } @@ -182,7 +196,7 @@ protected: int mPassedTests; int mFailedTests; int mSkippedTests; - std::ostream *mStream; + boost::shared_ptr mStream; }; // TeamCity specific class which emits service messages @@ -192,84 +206,111 @@ class LLTCTestCallback : public LLTestCallback { public: LLTCTestCallback(bool verbose_mode, std::ostream *stream) : - LLTestCallback(verbose_mode, stream), - mTCStream() + LLTestCallback(verbose_mode, stream) { } ~LLTCTestCallback() { - } + } virtual void group_started(const std::string& name) { LLTestCallback::group_started(name); - mTCStream << "\n##teamcity[testSuiteStarted name='" << name << "']" << std::endl; + std::cout << "\n##teamcity[testSuiteStarted name='" << escape(name) << "']" << std::endl; } virtual void group_completed(const std::string& name) { LLTestCallback::group_completed(name); - mTCStream << "##teamcity[testSuiteFinished name='" << name << "']" << std::endl; + std::cout << "##teamcity[testSuiteFinished name='" << escape(name) << "']" << std::endl; } virtual void test_completed(const tut::test_result& tr) { + std::string testname(STRINGIZE(tr.group << "." << tr.test)); + if (! tr.name.empty()) + { + testname.append(":"); + testname.append(tr.name); + } + testname = escape(testname); + + // Sadly, tut::callback doesn't give us control at test start; have to + // backfill start message into TC output. + std::cout << "##teamcity[testStarted name='" << testname << "']" << std::endl; + + // now forward call to base class so any output produced there is in + // the right TC context LLTestCallback::test_completed(tr); switch(tr.result) { case tut::test_result::ok: - mTCStream << "##teamcity[testStarted name='" << tr.group << "." << tr.test << "']" << std::endl; - mTCStream << "##teamcity[testFinished name='" << tr.group << "." << tr.test << "']" << std::endl; break; + case tut::test_result::fail: - mTCStream << "##teamcity[testStarted name='" << tr.group << "." << tr.test << "']" << std::endl; - mTCStream << "##teamcity[testFailed name='" << tr.group << "." << tr.test << "' message='" << tr.message << "']" << std::endl; - mTCStream << "##teamcity[testFinished name='" << tr.group << "." << tr.test << "']" << std::endl; - break; case tut::test_result::ex: - mTCStream << "##teamcity[testStarted name='" << tr.group << "." << tr.test << "']" << std::endl; - mTCStream << "##teamcity[testFailed name='" << tr.group << "." << tr.test << "' message='" << tr.message << "']" << std::endl; - mTCStream << "##teamcity[testFinished name='" << tr.group << "." << tr.test << "']" << std::endl; - break; case tut::test_result::warn: - mTCStream << "##teamcity[testStarted name='" << tr.group << "." << tr.test << "']" << std::endl; - mTCStream << "##teamcity[testFailed name='" << tr.group << "." << tr.test << "' message='" << tr.message << "']" << std::endl; - mTCStream << "##teamcity[testFinished name='" << tr.group << "." << tr.test << "']" << std::endl; - break; case tut::test_result::term: - mTCStream << "##teamcity[testStarted name='" << tr.group << "." << tr.test << "']" << std::endl; - mTCStream << "##teamcity[testFailed name='" << tr.group << "." << tr.test << "' message='" << tr.message << "']" << std::endl; - mTCStream << "##teamcity[testFinished name='" << tr.group << "." << tr.test << "']" << std::endl; + std::cout << "##teamcity[testFailed name='" << testname + << "' message='" << escape(tr.message) << "']" << std::endl; break; + case tut::test_result::skip: - mTCStream << "##teamcity[testStarted name='" << tr.group << "." << tr.test << "']" << std::endl; - mTCStream << "##teamcity[testIgnored name='" << tr.group << "." << tr.test << "']" << std::endl; - mTCStream << "##teamcity[testFinished name='" << tr.group << "." << tr.test << "']" << std::endl; + std::cout << "##teamcity[testIgnored name='" << testname << "']" << std::endl; break; + default: break; } + std::cout << "##teamcity[testFinished name='" << testname << "']" << std::endl; } - virtual void run_completed() - { - LLTestCallback::run_completed(); - - // dump the TC reporting results to cout - tc_run_completed_(std::cout); - } - - virtual void tc_run_completed_(std::ostream &stream) + static std::string escape(const std::string& str) { - - // dump the TC reporting results to cout - stream << mTCStream.str() << std::endl; + // Per http://confluence.jetbrains.net/display/TCD65/Build+Script+Interaction+with+TeamCity#BuildScriptInteractionwithTeamCity-ServiceMessages + std::string result; + BOOST_FOREACH(char c, str) + { + switch (c) + { + case '\'': + result.append("|'"); + break; + case '\n': + result.append("|n"); + break; + case '\r': + result.append("|r"); + break; +/*==========================================================================*| + // These are not possible 'char' values from a std::string. + case '\u0085': // next line + result.append("|x"); + break; + case '\u2028': // line separator + result.append("|l"); + break; + case '\u2029': // paragraph separator + result.append("|p"); + break; +|*==========================================================================*/ + case '|': + result.append("||"); + break; + case '[': + result.append("|["); + break; + case ']': + result.append("|]"); + break; + default: + result.push_back(c); + break; + } + } + return result; } - -protected: - std::ostringstream mTCStream; - }; -- cgit v1.2.3 From 33a42b32ca72031a79edca821966f6ebbdcddc93 Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Tue, 7 Feb 2012 13:06:38 -0500 Subject: Disable MSVC warning C4702 (unreachable code) in Boost headers. --- indra/test/test.cpp | 8 ++++++++ 1 file changed, 8 insertions(+) (limited to 'indra/test/test.cpp') diff --git a/indra/test/test.cpp b/indra/test/test.cpp index 3e7be29b39..1adcfb6f45 100644 --- a/indra/test/test.cpp +++ b/indra/test/test.cpp @@ -54,8 +54,16 @@ #include #endif +#if LL_MSVC +#pragma warning (push) +#pragma warning (disable : 4702) // warning C4702: unreachable code +#endif #include #include +#if LL_MSVC +#pragma warning (pop) +#endif + #include #include #include -- cgit v1.2.3 From f02ded46fe6f166a07673d97301bf169eb0b9ba8 Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Mon, 5 Mar 2012 13:07:14 -0500 Subject: Make test.cpp support LOGFAIL env var: only failed tests show log. Set LOGFAIL= one of ALL, DEBUG, INFO, WARN, ERROR, NONE. A passing test will run silently, as now; but a failing test will replay log output at the specified level or higher. While at it, support LOGTEST environment variable, same values. This is like setting --debug (or -d), but allows specifying an arbitrary level -- and, unlike --debug, can be set for a TeamCity build config without modifying any scripts or code. Publish LLError::decodeLevel(std::string), previously private to llerror.cpp. --- indra/test/test.cpp | 126 +++++++++++++++++++++++++++++++++++++++++++++++----- 1 file changed, 114 insertions(+), 12 deletions(-) (limited to 'indra/test/test.cpp') diff --git a/indra/test/test.cpp b/indra/test/test.cpp index 1adcfb6f45..128d84e428 100644 --- a/indra/test/test.cpp +++ b/indra/test/test.cpp @@ -38,6 +38,7 @@ #include "llerrorcontrol.h" #include "lltut.h" #include "stringize.h" +#include "namedtempfile.h" #include "apr_pools.h" #include "apr_getopt.h" @@ -69,17 +70,79 @@ #include #include +#include + +void wouldHaveCrashed(const std::string& message); + namespace tut { std::string sSourceDir; - - test_runner_singleton runner; + + test_runner_singleton runner; } +class LLReplayLog +{ +public: + LLReplayLog() {} + virtual ~LLReplayLog() {} + + virtual void reset() {} + virtual void replay(std::ostream&) {} +}; + +class LLReplayLogReal: public LLReplayLog, public LLError::Recorder +{ +public: + LLReplayLogReal(LLError::ELevel level, apr_pool_t* pool): + mOldSettings(LLError::saveAndResetSettings()), + mTempFile("log", "", pool), // create file + mFile(mTempFile.getName().c_str()) // open it + { + LLError::setFatalFunction(wouldHaveCrashed); + LLError::setDefaultLevel(level); + LLError::addRecorder(this); + } + + virtual ~LLReplayLogReal() + { + LLError::removeRecorder(this); + LLError::restoreSettings(mOldSettings); + } + + virtual void recordMessage(LLError::ELevel level, const std::string& message) + { + mFile << message << std::endl; + } + + virtual void reset() + { + mFile.close(); + mFile.open(mTempFile.getName().c_str()); + } + + virtual void replay(std::ostream& out) + { + mFile.close(); + std::ifstream inf(mTempFile.getName().c_str()); + std::string line; + while (std::getline(inf, line)) + { + out << line << std::endl; + } + } + +private: + LLError::Settings* mOldSettings; + NamedTempFile mTempFile; + std::ofstream mFile; +}; + class LLTestCallback : public tut::callback { public: - LLTestCallback(bool verbose_mode, std::ostream *stream) : + LLTestCallback(bool verbose_mode, std::ostream *stream, + boost::shared_ptr replayer) : mVerboseMode(verbose_mode), mTotalTests(0), mPassedTests(0), @@ -87,7 +150,8 @@ 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::cout, boost::lambda::_1)) + mStream(boost::shared_ptr(&std::cout, boost::lambda::_1)), + mReplayer(replayer) { if (stream) { @@ -125,6 +189,16 @@ public: virtual void test_completed(const tut::test_result& tr) { ++mTotalTests; + + // If this test failed, dump requested log messages BEFORE stating the + // test result. + if (tr.result != tut::test_result::ok && tr.result != tut::test_result::skip) + { + mReplayer->replay(*mStream); + } + // Either way, clear stored messages in preparation for next test. + mReplayer->reset(); + std::ostringstream out; out << "[" << tr.group << ", " << tr.test; if (! tr.name.empty()) @@ -205,6 +279,7 @@ protected: int mFailedTests; int mSkippedTests; boost::shared_ptr mStream; + boost::shared_ptr mReplayer; }; // TeamCity specific class which emits service messages @@ -213,8 +288,9 @@ protected: class LLTCTestCallback : public LLTestCallback { public: - LLTCTestCallback(bool verbose_mode, std::ostream *stream) : - LLTestCallback(verbose_mode, stream) + LLTCTestCallback(bool verbose_mode, std::ostream *stream, + boost::shared_ptr replayer) : + LLTestCallback(verbose_mode, stream, replayer) { } @@ -355,6 +431,14 @@ void stream_usage(std::ostream& s, const char* app) ++option; } + s << app << " is also sensitive to environment variables:\n" + << "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"; + s << "Examples:" << std::endl; s << " " << app << " --verbose" << std::endl; s << "\tRun all the tests and report all results." << std::endl; @@ -391,8 +475,14 @@ int main(int argc, char **argv) LLError::initForApplication("."); LLError::setFatalFunction(wouldHaveCrashed); LLError::setDefaultLevel(LLError::LEVEL_ERROR); - //< *TODO: should come from error config file. Note that we - // have a command line option that sets this to debug. + // ^ possibly overridden by --debug, LOGTEST or LOGFAIL + + // LOGTEST overrides default, but can be overridden by --debug or LOGFAIL. + const char* LOGTEST = getenv("LOGTEST"); + if (LOGTEST) + { + LLError::setDefaultLevel(LLError::decodeLevel(LOGTEST)); + } #ifdef CTYPE_WORKAROUND ctype_workaround(); @@ -467,8 +557,6 @@ int main(int argc, char **argv) wait_at_exit = true; break; case 'd': - // *TODO: should come from error config file. We set it to - // ERROR by default, so this allows full debug levels. LLError::setDefaultLevel(LLError::LEVEL_DEBUG); break; case 'x': @@ -483,14 +571,28 @@ int main(int argc, char **argv) // run the tests + const char* LOGFAIL = getenv("LOGFAIL"); + boost::shared_ptr replayer; + // As described in stream_usage(), LOGFAIL overrides both --debug and + // LOGTEST. + if (LOGFAIL) + { + LLError::ELevel level = LLError::decodeLevel(LOGFAIL); + replayer.reset(new LLReplayLogReal(level, pool)); + } + else + { + replayer.reset(new LLReplayLog()); + } + LLTestCallback* mycallback; if (getenv("TEAMCITY_PROJECT_NAME")) { - mycallback = new LLTCTestCallback(verbose_mode, output); + mycallback = new LLTCTestCallback(verbose_mode, output, replayer); } else { - mycallback = new LLTestCallback(verbose_mode, output); + mycallback = new LLTestCallback(verbose_mode, output, replayer); } tut::runner.get().set_callback(mycallback); -- cgit v1.2.3