From 7e322d837f7958eba62844583e2db55f6c69268f Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Mon, 23 May 2011 22:16:38 -0400 Subject: CHOP-661: Add information to try to zero in on remaining failures. Make testrunner.py module interpret $INTEGRATION_TEST_VERBOSE environment variable, setting module global VERBOSE. Enable/disable debug() output based on that variable, defaulting to VERBOSE True. Add debug() output to freeport(), including reporting exceptions. Add debug() output to test_llsdmessage_peer.py, including normal BaseHTTPRequestHandler output: when VERBOSE is set, don't suppress log_request() or log_error() output. Add C++ verbose() function to query $INTEGRATION_TEST_VERBOSE, broken out as two functions so we only have to interpret the value once. Default to 'true'. Move C++ commtest_data::getport(variable) function to global namespace, broken out as two functions to cache the value. Report value received when verbose() returns true. --- indra/llmessage/tests/commtest.h | 64 +++++++++++++-- indra/llmessage/tests/test_llsdmessage_peer.py | 32 +++++--- indra/llmessage/tests/testrunner.py | 103 ++++++++++++++----------- 3 files changed, 136 insertions(+), 63 deletions(-) (limited to 'indra/llmessage') diff --git a/indra/llmessage/tests/commtest.h b/indra/llmessage/tests/commtest.h index 0fef596df2..0d149b5258 100644 --- a/indra/llmessage/tests/commtest.h +++ b/indra/llmessage/tests/commtest.h @@ -34,6 +34,7 @@ #include "llsd.h" #include "llhost.h" #include "stringize.h" +#include #include #include #include @@ -43,6 +44,58 @@ struct CommtestError: public std::runtime_error CommtestError(const std::string& what): std::runtime_error(what) {} }; +static bool query_verbose() +{ + const char* cbose = getenv("INTEGRATION_TEST_VERBOSE"); + if (! cbose) + { + cbose = "1"; + } + std::string strbose(cbose); + return (! (strbose == "0" || strbose == "off" || + strbose == "false" || strbose == "quiet")); +} + +bool verbose() +{ + // This should only be initialized once. + static bool vflag = query_verbose(); + return vflag; +} + +static int query_port(const std::string& var) +{ + const char* cport = getenv(var.c_str()); + if (! cport) + { + throw CommtestError(STRINGIZE("missing environment variable" << var)); + } + // This will throw, too, if the value of PORT isn't numeric. + int port(boost::lexical_cast(cport)); + if (verbose()) + { + std::cout << "getport('" << var << "') = " << port << std::endl; + } + return port; +} + +static int getport(const std::string& var) +{ + typedef std::map portsmap; + static portsmap ports; + // We can do this with a single map lookup with map::insert(). Either it + // returns an existing entry and 'false' (not newly inserted), or it + // inserts the specified value and 'true'. + std::pair inserted(ports.insert(portsmap::value_type(var, 0))); + if (inserted.second) + { + // We haven't yet seen this var. Remember its value. + inserted.first->second = query_port(var); + } + // Return the (existing or new) iterator's value. + return inserted.first->second; +} + /** * This struct is shared by a couple of standalone comm tests (ADD_COMM_BUILD_TEST). */ @@ -71,13 +124,10 @@ struct commtest_data static int getport(const std::string& var) { - const char* port = getenv(var.c_str()); - if (! port) - { - throw CommtestError("missing $PORT environment variable"); - } - // This will throw, too, if the value of PORT isn't numeric. - return boost::lexical_cast(port); + // We have a couple consumers of commtest_data::getport(). But we've + // since moved it out to the global namespace. So this is just a + // facade. + return ::getport(var); } bool outcome(const LLSD& _result, bool _success) diff --git a/indra/llmessage/tests/test_llsdmessage_peer.py b/indra/llmessage/tests/test_llsdmessage_peer.py index cea5032111..9886d49ccc 100644 --- a/indra/llmessage/tests/test_llsdmessage_peer.py +++ b/indra/llmessage/tests/test_llsdmessage_peer.py @@ -38,7 +38,7 @@ mydir = os.path.dirname(__file__) # expected to be .../indra/llmessage/tes sys.path.insert(0, os.path.join(mydir, os.pardir, os.pardir, "lib", "python")) from indra.util.fastest_elementtree import parse as xml_parse from indra.base import llsd -from testrunner import freeport, run, debug +from testrunner import freeport, run, debug, VERBOSE class TestHTTPRequestHandler(BaseHTTPRequestHandler): """This subclass of BaseHTTPRequestHandler is to receive and echo @@ -72,10 +72,10 @@ class TestHTTPRequestHandler(BaseHTTPRequestHandler): ## # assuming that the underlying XML parser reads its input file ## # incrementally. Unfortunately I haven't been able to make it work. ## tree = xml_parse(self.rfile) -## debug("Finished raw parse\n") -## debug("parsed XML tree %s\n" % tree) -## debug("parsed root node %s\n" % tree.getroot()) -## debug("root node tag %s\n" % tree.getroot().tag) +## debug("Finished raw parse") +## debug("parsed XML tree %s", tree) +## debug("parsed root node %s", tree.getroot()) +## debug("root node tag %s", tree.getroot().tag) ## return llsd.to_python(tree.getroot()) def do_GET(self): @@ -88,8 +88,10 @@ class TestHTTPRequestHandler(BaseHTTPRequestHandler): self.answer(self.read_xml()) def answer(self, data): + debug("%s.answer(%s): self.path = %r", self.__class__.__name__, data, self.path) if "fail" not in self.path: response = llsd.format_xml(data.get("reply", llsd.LLSD("success"))) + debug("success: %s", response) self.send_response(200) self.send_header("Content-type", "application/llsd+xml") self.send_header("Content-Length", str(len(response))) @@ -106,16 +108,21 @@ class TestHTTPRequestHandler(BaseHTTPRequestHandler): ("fail requested", "Your request specified failure status %s " "without providing a reason" % status))[1]) + debug("fail requested: %s: %r", status, reason) self.send_error(status, reason) - def log_request(self, code, size=None): - # For present purposes, we don't want the request splattered onto - # stderr, as it would upset devs watching the test run - pass + if not VERBOSE: + # When VERBOSE is set, skip both these overrides because they exist to + # suppress output. - def log_error(self, format, *args): - # Suppress error output as well - pass + def log_request(self, code, size=None): + # For present purposes, we don't want the request splattered onto + # stderr, as it would upset devs watching the test run + pass + + def log_error(self, format, *args): + # Suppress error output as well + pass if __name__ == "__main__": # Instantiate an HTTPServer(TestHTTPRequestHandler) on the first free port @@ -130,4 +137,5 @@ if __name__ == "__main__": # command-line parsing -- and anyway, for C++ integration tests, that's # performed in TUT code rather than our own. os.environ["PORT"] = str(port) + debug("$PORT = %s", port) sys.exit(run(server=Thread(name="httpd", target=httpd.serve_forever), *sys.argv[1:])) diff --git a/indra/llmessage/tests/testrunner.py b/indra/llmessage/tests/testrunner.py index 8ff13e0426..f329ec2a0e 100644 --- a/indra/llmessage/tests/testrunner.py +++ b/indra/llmessage/tests/testrunner.py @@ -29,14 +29,21 @@ $/LicenseInfo$ import os import sys +import re import errno import socket -def debug(*args): - sys.stdout.writelines(args) - sys.stdout.flush() -# comment out the line below to enable debug output -debug = lambda *args: None +VERBOSE = os.environ.get("INTEGRATION_TEST_VERBOSE", "1") # default to verbose +# Support usage such as INTEGRATION_TEST_VERBOSE=off -- distressing to user if +# that construct actually turns on verbosity... +VERBOSE = not re.match(r"(0|off|false|quiet)$", VERBOSE, re.IGNORECASE) + +if VERBOSE: + def debug(fmt, *args): + print fmt % args + sys.stdout.flush() +else: + debug = lambda *args: None def freeport(portlist, expr): """ @@ -78,44 +85,53 @@ def freeport(portlist, expr): # pass 'port' to client code # call server.serve_forever() """ - # If portlist is completely empty, let StopIteration propagate: that's an - # error because we can't return meaningful values. We have no 'port', - # therefore no 'expr(port)'. - portiter = iter(portlist) - port = portiter.next() - - while True: - try: - # If this value of port works, return as promised. - return expr(port), port - - except socket.error, err: - # Anything other than 'Address already in use', propagate - if err.args[0] != errno.EADDRINUSE: - raise - - # Here we want the next port from portiter. But on StopIteration, - # we want to raise the original exception rather than - # StopIteration. So save the original exc_info(). - type, value, tb = sys.exc_info() + try: + # If portlist is completely empty, let StopIteration propagate: that's an + # error because we can't return meaningful values. We have no 'port', + # therefore no 'expr(port)'. + portiter = iter(portlist) + port = portiter.next() + + while True: try: + # If this value of port works, return as promised. + value = expr(port) + + except socket.error, err: + # Anything other than 'Address already in use', propagate + if err.args[0] != errno.EADDRINUSE: + raise + + # Here we want the next port from portiter. But on StopIteration, + # we want to raise the original exception rather than + # StopIteration. So save the original exc_info(). + type, value, tb = sys.exc_info() try: - port = portiter.next() - except StopIteration: - raise type, value, tb - finally: - # Clean up local traceback, see docs for sys.exc_info() - del tb - - # Recap of the control flow above: - # If expr(port) doesn't raise, return as promised. - # If expr(port) raises anything but EADDRINUSE, propagate that - # exception. - # If portiter.next() raises StopIteration -- that is, if the port - # value we just passed to expr(port) was the last available -- reraise - # the EADDRINUSE exception. - # If we've actually arrived at this point, portiter.next() delivered a - # new port value. Loop back to pass that to expr(port). + try: + port = portiter.next() + except StopIteration: + raise type, value, tb + finally: + # Clean up local traceback, see docs for sys.exc_info() + del tb + + else: + debug("freeport() returning %s on port %s", value, port) + return value, port + + # Recap of the control flow above: + # If expr(port) doesn't raise, return as promised. + # If expr(port) raises anything but EADDRINUSE, propagate that + # exception. + # If portiter.next() raises StopIteration -- that is, if the port + # value we just passed to expr(port) was the last available -- reraise + # the EADDRINUSE exception. + # If we've actually arrived at this point, portiter.next() delivered a + # new port value. Loop back to pass that to expr(port). + + except Exception, err: + debug("*** freeport() raising %s: %s", err.__class__.__name__, err) + raise def run(*args, **kwds): """All positional arguments collectively form a command line, executed as @@ -144,8 +160,7 @@ def run(*args, **kwds): # - [no p] don't use the PATH because we specifically want to invoke the # executable passed as our first arg, # - [no e] child should inherit this process's environment. - debug("Running %s...\n" % (" ".join(args))) - sys.stdout.flush() + debug("Running %s...", " ".join(args)) rc = os.spawnv(os.P_WAIT, args[0], args) - debug("%s returned %s\n" % (args[0], rc)) + debug("%s returned %s", args[0], rc) return rc -- cgit v1.2.3