From 0ef99cd33b4b450712e105e8ab448c2dab7081d2 Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Thu, 1 Mar 2012 17:46:44 -0500 Subject: Add LLLeap class, initial implementation, initial unit tests. Instantiating LLLeap with a command to execute a particular child process sets up machinery to speak LLSD Event API Plugin protocol with that child process. LLLeap is an LLInstanceTracker subclass, so the code that instantiates need not hold the pointer. LLLeap monitors child-process termination and deletes itself when done. --- indra/llcommon/tests/llleap_test.cpp | 261 +++++++++++++++++++++++++++++++++++ 1 file changed, 261 insertions(+) create mode 100644 indra/llcommon/tests/llleap_test.cpp (limited to 'indra/llcommon/tests/llleap_test.cpp') diff --git a/indra/llcommon/tests/llleap_test.cpp b/indra/llcommon/tests/llleap_test.cpp new file mode 100644 index 0000000000..0264442437 --- /dev/null +++ b/indra/llcommon/tests/llleap_test.cpp @@ -0,0 +1,261 @@ +/** + * @file llleap_test.cpp + * @author Nat Goodspeed + * @date 2012-02-21 + * @brief Test for llleap. + * + * $LicenseInfo:firstyear=2012&license=viewerlgpl$ + * Copyright (c) 2012, Linden Research, Inc. + * $/LicenseInfo$ + */ + +// Precompiled header +#include "linden_common.h" +// associated header +#include "llleap.h" +// STL headers +// std headers +// external library headers +#include +#include +#include +// other Linden headers +#include "../test/lltut.h" +#include "../test/namedtempfile.h" +#include "../test/manageapr.h" +#include "../test/catch_and_store_what_in.h" +#include "wrapllerrs.h" +#include "llevents.h" +#include "llprocess.h" +#include "stringize.h" +#include "StringVec.h" + +using boost::assign::list_of; + +static ManageAPR manager; + +StringVec sv(const StringVec& listof) { return listof; } + +#if defined(LL_WINDOWS) +#define sleep(secs) _sleep((secs) * 1000) +#endif + +void waitfor(const std::vector& instances) +{ + int i, timeout = 60; + for (i = 0; i < timeout; ++i) + { + // Every iteration, test whether any of the passed LLLeap instances + // still exist (are still running). + std::vector::const_iterator vli(instances.begin()), vlend(instances.end()); + for ( ; vli != vlend; ++vli) + { + // getInstance() returns NULL if it's terminated/gone, non-NULL if + // it's still running + if (LLLeap::getInstance(*vli)) + break; + } + // If we made it through all of 'instances' without finding one that's + // still running, we're done. + if (vli == vlend) + return; + // Found an instance that's still running. Wait and pump LLProcess. + sleep(1); + LLEventPumps::instance().obtain("mainloop").post(LLSD()); + } + tut::ensure("timed out without terminating", i < timeout); +} + +void waitfor(LLLeap* instance) +{ + std::vector instances; + instances.push_back(instance); + waitfor(instances); +} + +/***************************************************************************** +* TUT +*****************************************************************************/ +namespace tut +{ + struct llleap_data + { + llleap_data(): + reader(".py", + // This logic is adapted from vita.viewerclient.receiveEvent() + "import sys\n" + "LEFTOVER = ''\n" + "class ProtocolError(Exception):\n" + " pass\n" + "def get():\n" + " global LEFTOVER\n" + " hdr = LEFTOVER\n" + " if ':' not in hdr:\n" + " hdr += sys.stdin.read(20)\n" + " if not hdr:\n" + " sys.exit(0)\n" + " parts = hdr.split(':', 1)\n" + " if len(parts) != 2:\n" + " raise ProtocolError('Expected len:data, got %r' % hdr)\n" + " try:\n" + " length = int(parts[0])\n" + " except ValueError:\n" + " raise ProtocolError('Non-numeric len %r' % parts[0])\n" + " del parts[0]\n" + " received = len(parts[0])\n" + " while received < length:\n" + " parts.append(sys.stdin.read(length - received))\n" + " received += len(parts[-1])\n" + " if received > length:\n" + " excess = length - received\n" + " LEFTOVER = parts[-1][excess:]\n" + " parts[-1] = parts[-1][:excess]\n" + " data = ''.join(parts)\n" + " assert len(data) == length\n" + " return data\n"), + // Get the actual pathname of the NamedExtTempFile and trim off + // the ".py" extension. (We could cache reader.getName() in a + // separate member variable, but I happen to know getName() just + // returns a NamedExtTempFile member rather than performing any + // computation, so I don't mind calling it twice.) Then take the + // basename. + reader_module(LLProcess::basename( + reader.getName().substr(0, reader.getName().length()-3))), + pPYTHON(getenv("PYTHON")), + PYTHON(pPYTHON? pPYTHON : "") + { + ensure("Set PYTHON to interpreter pathname", pPYTHON); + } + NamedExtTempFile reader; + const std::string reader_module; + const char* pPYTHON; + const std::string PYTHON; + }; + typedef test_group llleap_group; + typedef llleap_group::object object; + llleap_group llleapgrp("llleap"); + + template<> template<> + void object::test<1>() + { + set_test_name("multiple LLLeap instances"); + NamedTempFile script("py", + "import time\n" + "time.sleep(1)\n"); + std::vector instances; + instances.push_back(LLLeap::create(get_test_name(), + sv(list_of(PYTHON)(script.getName())))); + instances.push_back(LLLeap::create(get_test_name(), + sv(list_of(PYTHON)(script.getName())))); + // In this case we're simply establishing that two LLLeap instances + // can coexist without throwing exceptions or bombing in any other + // way. Wait for them to terminate. + waitfor(instances); + } + + template<> template<> + void object::test<2>() + { + set_test_name("stderr to log"); + NamedTempFile script("py", + "import sys\n" + "sys.stderr.write('''Hello from Python!\n" + "note partial line''')\n"); + CaptureLog log(LLError::LEVEL_INFO); + waitfor(LLLeap::create(get_test_name(), + sv(list_of(PYTHON)(script.getName())))); + log.messageWith("Hello from Python!"); + log.messageWith("note partial line"); + } + + template<> template<> + void object::test<3>() + { + set_test_name("empty plugin vector"); + std::string threw; + try + { + LLLeap::create("empty", StringVec()); + } + CATCH_AND_STORE_WHAT_IN(threw, LLLeap::Error) + ensure_contains("LLLeap::Error", threw, "no plugin"); + // try the suppress-exception variant + ensure("bad launch returned non-NULL", ! LLLeap::create("empty", StringVec(), false)); + } + + template<> template<> + void object::test<4>() + { + set_test_name("bad launch"); + // Synthesize bogus executable name + std::string BADPYTHON(PYTHON.substr(0, PYTHON.length()-1) + "x"); + CaptureLog log; + std::string threw; + try + { + LLLeap::create("bad exe", BADPYTHON); + } + CATCH_AND_STORE_WHAT_IN(threw, LLLeap::Error) + ensure_contains("LLLeap::create() didn't throw", threw, "failed"); + log.messageWith("failed"); + log.messageWith(BADPYTHON); + // try the suppress-exception variant + ensure("bad launch returned non-NULL", ! LLLeap::create("bad exe", BADPYTHON, false)); + } + + // Mimic a dummy little LLEventAPI that merely sends a reply back to its + // requester on the "reply" pump. + struct API + { + API(): + mPump("API", true) + { + mPump.listen("API", boost::bind(&API::entry, this, _1)); + } + + bool entry(const LLSD& request) + { + LLEventPumps::instance().obtain(request["reply"]).post("ack"); + return false; + } + + LLEventStream mPump; + }; + + template<> template<> + void object::test<5>() + { + set_test_name("round trip"); + API api; + NamedTempFile script("py", + boost::lambda::_1 << + "import re\n" + "import sys\n" + "from " << reader_module << " import get\n" + // this will throw if the initial write to stdin + // doesn't follow len:data protocol + "initial = get()\n" + "match = re.search(r\"'pump':'(.*?)'\", initial)\n" + // this will throw if we couldn't find + // 'pump':'etc.' in the initial write + "reply = match.group(1)\n" + "req = '''\\\n" + "{'pump':'" << api.mPump.getName() << "','data':{'reply':'%s'}}\\\n" + "''' % reply\n" + // make a request on our little API + "sys.stdout.write(':'.join((str(len(req)), req)))\n" + "sys.stdout.flush()\n" + // wait for its response + "resp = get()\n" + // it would be cleverer to be order-insensitive + // about 'data' and 'pump'; hopefully the C++ + // serializer doesn't change its rules soon + "result = 'good' if (resp == \"{'data':'ack','pump':'%s'}\" % reply)\\\n" + " else 'bad: ' + resp\n" + // write 'good' or 'bad' to the log so we can observe + "sys.stderr.write(result)\n"); + CaptureLog log(LLError::LEVEL_INFO); + waitfor(LLLeap::create(get_test_name(), sv(list_of(PYTHON)(script.getName())))); + log.messageWith("good"); + } +} // namespace tut -- cgit v1.2.3 From 9b5fcb78e7692c82328bd4ff6d178b68b4b47636 Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Thu, 1 Mar 2012 23:01:37 -0500 Subject: Refactor llleap_test.cpp to streamline adding more unit tests. Migrate logic from specific test to common reader module, notably parsing the wakeup message containing the reply-pump name. Make test script post to Result struct to communicate success/failure to C++ TUT test, rather than just writing to log. Make test script insensitive to key order in serialized LLSD::Map. --- indra/llcommon/tests/llleap_test.cpp | 118 ++++++++++++++++++++++++++--------- 1 file changed, 87 insertions(+), 31 deletions(-) (limited to 'indra/llcommon/tests/llleap_test.cpp') diff --git a/indra/llcommon/tests/llleap_test.cpp b/indra/llcommon/tests/llleap_test.cpp index 0264442437..0ca8c9b684 100644 --- a/indra/llcommon/tests/llleap_test.cpp +++ b/indra/llcommon/tests/llleap_test.cpp @@ -83,6 +83,7 @@ namespace tut llleap_data(): reader(".py", // This logic is adapted from vita.viewerclient.receiveEvent() + "import re\n" "import sys\n" "LEFTOVER = ''\n" "class ProtocolError(Exception):\n" @@ -112,7 +113,29 @@ namespace tut " parts[-1] = parts[-1][:excess]\n" " data = ''.join(parts)\n" " assert len(data) == length\n" - " return data\n"), + " return data\n" + "\n" + "def put(req):\n" + " sys.stdout.write(':'.join((str(len(req)), req)))\n" + " sys.stdout.flush()\n" + "\n" + "# deal with initial stdin message\n" + // this will throw if the initial write to stdin + // doesn't follow len:data protocol + "_initial = get()\n" + "_match = re.search(r\"'pump':'(.*?)'\", _initial)\n" + // this will throw if we couldn't find + // 'pump':'etc.' in the initial write + "_reply = _match.group(1)\n" + "\n" + "def replypump():\n" + " return _reply\n" + "\n" + "def escape(str):\n" + " return ''.join(('\\\\'+c if c in r\"\\'\" else c) for c in str)\n" + "\n" + "def quote(str):\n" + " return \"'%s'\" % escape(str)\n"), // Get the actual pathname of the NamedExtTempFile and trim off // the ".py" extension. (We could cache reader.getName() in a // separate member variable, but I happen to know getName() just @@ -203,23 +226,64 @@ namespace tut ensure("bad launch returned non-NULL", ! LLLeap::create("bad exe", BADPYTHON, false)); } + // Generic self-contained listener: derive from this and override its + // call() method, then tell somebody to post on the pump named getName(). + // Control will reach your call() override. + struct ListenerBase + { + // Pass the pump name you want; will tweak for uniqueness. + ListenerBase(const std::string& name): + mPump(name, true) + { + mPump.listen(name, boost::bind(&ListenerBase::call, this, _1)); + } + + virtual bool call(const LLSD& request) + { + return false; + } + + LLEventPump& getPump() { return mPump; } + const LLEventPump& getPump() const { return mPump; } + + std::string getName() const { return mPump.getName(); } + void post(const LLSD& data) { mPump.post(data); } + + LLEventStream mPump; + }; + // Mimic a dummy little LLEventAPI that merely sends a reply back to its // requester on the "reply" pump. - struct API + struct API: public ListenerBase { - API(): - mPump("API", true) + API(): ListenerBase("API") {} + + virtual bool call(const LLSD& request) { - mPump.listen("API", boost::bind(&API::entry, this, _1)); + LLEventPumps::instance().obtain(request["reply"]).post("ack"); + return false; } + }; + + // Give LLLeap script a way to post success/failure. + struct Result: public ListenerBase + { + Result(): ListenerBase("Result") {} - bool entry(const LLSD& request) + virtual bool call(const LLSD& request) { - LLEventPumps::instance().obtain(request["reply"]).post("ack"); + mData = request; return false; } - LLEventStream mPump; + void ensure() const + { + tut::ensure(std::string("never posted to ") + getName(), mData.isDefined()); + // Post an empty string for success, non-empty string is failure message. + tut::ensure(mData, mData.asString().empty()); + } + + LLSD mData; }; template<> template<> @@ -227,35 +291,27 @@ namespace tut { set_test_name("round trip"); API api; + Result result; NamedTempFile script("py", boost::lambda::_1 << - "import re\n" "import sys\n" - "from " << reader_module << " import get\n" - // this will throw if the initial write to stdin - // doesn't follow len:data protocol - "initial = get()\n" - "match = re.search(r\"'pump':'(.*?)'\", initial)\n" - // this will throw if we couldn't find - // 'pump':'etc.' in the initial write - "reply = match.group(1)\n" - "req = '''\\\n" - "{'pump':'" << api.mPump.getName() << "','data':{'reply':'%s'}}\\\n" - "''' % reply\n" + "from " << reader_module << " import *\n" // make a request on our little API - "sys.stdout.write(':'.join((str(len(req)), req)))\n" - "sys.stdout.flush()\n" + "put(\"{'pump':'" << api.getName() << "','data':{'reply':'%s'}}\" %\n" + " replypump())\n" // wait for its response "resp = get()\n" - // it would be cleverer to be order-insensitive - // about 'data' and 'pump'; hopefully the C++ - // serializer doesn't change its rules soon - "result = 'good' if (resp == \"{'data':'ack','pump':'%s'}\" % reply)\\\n" - " else 'bad: ' + resp\n" - // write 'good' or 'bad' to the log so we can observe - "sys.stderr.write(result)\n"); - CaptureLog log(LLError::LEVEL_INFO); + // We expect "{'data':'ack','pump':'%s'}", but + // don't depend on the order of the keys. + "result = 'bad: ' + resp\n" + "if resp.startswith('{') and resp.endswith('}'):\n" + " expect = set((\"'data':'ack'\", \"'pump':'%s'\" % replypump()))\n" + " actual = set(resp[1:-1].split(','))\n" + " if actual == expect:\n" + " result = ''\n" + "put(\"{'pump':'" << result.getName() << "','data':%s}\" %\n" + " quote(result))\n"); waitfor(LLLeap::create(get_test_name(), sv(list_of(PYTHON)(script.getName())))); - log.messageWith("good"); + result.ensure(); } } // namespace tut -- cgit v1.2.3 From d16ce6bf0422f46e3a2d9966cd4210f4f4e35a83 Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Fri, 2 Mar 2012 09:47:27 -0500 Subject: Drag in Python llsd module, which greatly simplifies tests. It only took a few examples of trying to wrangle notation LLSD as string data to illustrate how clumsy that is. I'd forgotten that a couple other TUT tests already invoke Python code that depends on the llsd module. The trick is to recognize that at least as of now, there's still an obsolete version of the module in the viewer's own source tree. Python code is careful to try importing llbase.llsd before indra.base.llsd, so that if/when we finally do clear indra/lib/python from the viewer repo, we need only require that llbase be installed on every build machine. --- indra/llcommon/tests/llleap_test.cpp | 67 ++++++++++++++++++++---------------- 1 file changed, 38 insertions(+), 29 deletions(-) (limited to 'indra/llcommon/tests/llleap_test.cpp') diff --git a/indra/llcommon/tests/llleap_test.cpp b/indra/llcommon/tests/llleap_test.cpp index 0ca8c9b684..bef3bf1543 100644 --- a/indra/llcommon/tests/llleap_test.cpp +++ b/indra/llcommon/tests/llleap_test.cpp @@ -83,8 +83,21 @@ namespace tut llleap_data(): reader(".py", // This logic is adapted from vita.viewerclient.receiveEvent() - "import re\n" + boost::lambda::_1 << + "import os\n" "import sys\n" + // Don't forget that this Python script is written to some + // temp directory somewhere! Its __file__ is useless in + // finding indra/lib/python. Use our __FILE__, with + // raw-string syntax to deal with Windows pathnames. + "mydir = os.path.dirname(r'" << __FILE__ << "')\n" + "try:\n" + " from llbase import llsd\n" + "except ImportError:\n" + // We expect mydir to be .../indra/llcommon/tests. + " sys.path.insert(0,\n" + " os.path.join(mydir, os.pardir, os.pardir, 'lib', 'python'))\n" + " from indra.base import llsd\n" "LEFTOVER = ''\n" "class ProtocolError(Exception):\n" " pass\n" @@ -113,29 +126,28 @@ namespace tut " parts[-1] = parts[-1][:excess]\n" " data = ''.join(parts)\n" " assert len(data) == length\n" - " return data\n" - "\n" - "def put(req):\n" - " sys.stdout.write(':'.join((str(len(req)), req)))\n" - " sys.stdout.flush()\n" + " return llsd.parse(data)\n" "\n" "# deal with initial stdin message\n" - // this will throw if the initial write to stdin - // doesn't follow len:data protocol - "_initial = get()\n" - "_match = re.search(r\"'pump':'(.*?)'\", _initial)\n" - // this will throw if we couldn't find - // 'pump':'etc.' in the initial write - "_reply = _match.group(1)\n" + // this will throw if the initial write to stdin doesn't + // follow len:data protocol, or if we couldn't find 'pump' + // in the dict + "_reply = get()['pump']\n" "\n" "def replypump():\n" " return _reply\n" "\n" - "def escape(str):\n" - " return ''.join(('\\\\'+c if c in r\"\\'\" else c) for c in str)\n" + "def put(req):\n" + " sys.stdout.write(':'.join((str(len(req)), req)))\n" + " sys.stdout.flush()\n" + "\n" + "def send(pump, data):\n" + " put(llsd.format_notation(dict(pump=pump, data=data)))\n" "\n" - "def quote(str):\n" - " return \"'%s'\" % escape(str)\n"), + "def request(pump, data):\n" + " # we expect 'data' is a dict\n" + " data['reply'] = _reply\n" + " send(pump, data)\n"), // Get the actual pathname of the NamedExtTempFile and trim off // the ".py" extension. (We could cache reader.getName() in a // separate member variable, but I happen to know getName() just @@ -297,21 +309,18 @@ namespace tut "import sys\n" "from " << reader_module << " import *\n" // make a request on our little API - "put(\"{'pump':'" << api.getName() << "','data':{'reply':'%s'}}\" %\n" - " replypump())\n" + "request(pump='" << api.getName() << "', data={})\n" // wait for its response "resp = get()\n" - // We expect "{'data':'ack','pump':'%s'}", but - // don't depend on the order of the keys. - "result = 'bad: ' + resp\n" - "if resp.startswith('{') and resp.endswith('}'):\n" - " expect = set((\"'data':'ack'\", \"'pump':'%s'\" % replypump()))\n" - " actual = set(resp[1:-1].split(','))\n" - " if actual == expect:\n" - " result = ''\n" - "put(\"{'pump':'" << result.getName() << "','data':%s}\" %\n" - " quote(result))\n"); + "result = '' if resp == dict(pump=replypump(), data='ack')\\\n" + " else 'bad: ' + str(resp)\n" + "send(pump='" << result.getName() << "', data=result)\n"); waitfor(LLLeap::create(get_test_name(), sv(list_of(PYTHON)(script.getName())))); result.ensure(); } + + // TODO: + // many many small messages buffered in both directions + // very large message in both directions (md5) + } // namespace tut -- cgit v1.2.3 From c6c7cabd1daad23898edc9f352349a028888f8ee Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Fri, 2 Mar 2012 12:00:38 -0500 Subject: Add "load test" LLLeap unit tests: many small messages, one large. These tests rule out corruption as we cross buffer boundaries in OS pipes and the LLLeap implementation itself. --- indra/llcommon/tests/llleap_test.cpp | 120 ++++++++++++++++++++++++++++++++--- 1 file changed, 110 insertions(+), 10 deletions(-) (limited to 'indra/llcommon/tests/llleap_test.cpp') diff --git a/indra/llcommon/tests/llleap_test.cpp b/indra/llcommon/tests/llleap_test.cpp index bef3bf1543..652a95ac6b 100644 --- a/indra/llcommon/tests/llleap_test.cpp +++ b/indra/llcommon/tests/llleap_test.cpp @@ -40,9 +40,11 @@ StringVec sv(const StringVec& listof) { return listof; } #define sleep(secs) _sleep((secs) * 1000) #endif -void waitfor(const std::vector& instances) +const size_t BUFFERED_LENGTH = 1024*1024; // try wrangling a megabyte of data + +void waitfor(const std::vector& instances, int timeout=60) { - int i, timeout = 60; + int i; for (i = 0; i < timeout; ++i) { // Every iteration, test whether any of the passed LLLeap instances @@ -66,11 +68,11 @@ void waitfor(const std::vector& instances) tut::ensure("timed out without terminating", i < timeout); } -void waitfor(LLLeap* instance) +void waitfor(LLLeap* instance, int timeout=60) { std::vector instances; instances.push_back(instance); - waitfor(instances); + waitfor(instances, timeout); } /***************************************************************************** @@ -266,9 +268,9 @@ namespace tut // Mimic a dummy little LLEventAPI that merely sends a reply back to its // requester on the "reply" pump. - struct API: public ListenerBase + struct AckAPI: public ListenerBase { - API(): ListenerBase("API") {} + AckAPI(): ListenerBase("AckAPI") {} virtual bool call(const LLSD& request) { @@ -302,11 +304,10 @@ namespace tut void object::test<5>() { set_test_name("round trip"); - API api; + AckAPI api; Result result; NamedTempFile script("py", boost::lambda::_1 << - "import sys\n" "from " << reader_module << " import *\n" // make a request on our little API "request(pump='" << api.getName() << "', data={})\n" @@ -319,8 +320,107 @@ namespace tut result.ensure(); } + struct ReqIDAPI: public ListenerBase + { + ReqIDAPI(): ListenerBase("ReqIDAPI") {} + + virtual bool call(const LLSD& request) + { + // free function from llevents.h + sendReply(LLSD(), request); + return false; + } + }; + + template<> template<> + void object::test<6>() + { + set_test_name("many small messages"); + // It's not clear to me whether there's value in iterating many times + // over a send/receive loop -- I don't think that will exercise any + // interesting corner cases. This test first sends a large number of + // messages, then receives all the responses. The intent is to ensure + // that some of that data stream crosses buffer boundaries, loop + // iterations etc. in OS pipes and the LLLeap/LLProcess implementation. + ReqIDAPI api; + Result result; + NamedTempFile script("py", + boost::lambda::_1 << + "import sys\n" + "from " << reader_module << " import *\n" + // Note that since reader imports llsd, this + // 'import *' gets us llsd too. + "sample = llsd.format_notation(dict(pump='" << + api.getName() << "', data=dict(reqid=999999, reply=replypump())))\n" + // The whole packet has length prefix too: "len:data" + "samplen = len(str(len(sample))) + 1 + len(sample)\n" + // guess how many messages it will take to + // accumulate BUFFERED_LENGTH + "count = int(" << BUFFERED_LENGTH << "/samplen)\n" + "print >>sys.stderr, 'Sending %s requests' % count\n" + "for i in xrange(count):\n" + " request('" << api.getName() << "', dict(reqid=i))\n" + // The assumption in this specific test that + // replies will arrive in the same order as + // requests is ONLY valid because the API we're + // invoking sends replies instantly. If the API + // had to wait for some external event before + // sending its reply, replies could arrive in + // arbitrary order, and we'd have to tick them + // off from a set. + "result = ''\n" + "for i in xrange(count):\n" + " resp = get()\n" + " if resp['data']['reqid'] != i:\n" + " result = 'expected reqid=%s in %s' % (i, resp)\n" + " break\n" + "send(pump='" << result.getName() << "', data=result)\n"); + waitfor(LLLeap::create(get_test_name(), sv(list_of(PYTHON)(script.getName()))), + 300); // needs more realtime than most tests + result.ensure(); + } + + template<> template<> + void object::test<7>() + { + set_test_name("very large message"); + ReqIDAPI api; + Result result; + NamedTempFile script("py", + boost::lambda::_1 << + "import sys\n" + "from " << reader_module << " import *\n" + // Generate a very large string value. + "desired = int(sys.argv[1])\n" + // 7 chars per item: 6 digits, 1 comma + "count = int((desired - 50)/7)\n" + "large = ''.join('%06d,' % i for i in xrange(count))\n" + // Pass 'large' as reqid because we know the API + // will echo reqid, and we want to receive it back. + "request('" << api.getName() << "', dict(reqid=large))\n" + "resp = get()\n" + "echoed = resp['data']['reqid']\n" + "if echoed == large:\n" + " send('" << result.getName() << "', '')\n" + " sys.exit(0)\n" + // Here we know echoed did NOT match; try to find where + "for i in xrange(count):\n" + " start = 7*i\n" + " end = 7*(i+1)\n" + " if end > len(echoed)\\\n" + " or echoed[start:end] != large[start:end]:\n" + " send('" << result.getName() << "',\n" + " 'at offset %s, expected %r but got %r' %\n" + " (start, large[start:end], echoed[start:end]))\n" + "sys.exit(1)\n"); + waitfor(LLLeap::create(get_test_name(), + sv(list_of + (PYTHON) + (script.getName()) + (stringize(BUFFERED_LENGTH))))); + result.ensure(); + } + // TODO: - // many many small messages buffered in both directions - // very large message in both directions (md5) } // namespace tut -- cgit v1.2.3 From d09d4e1a7e64b01fa1d9f3015de819a2e7069ac4 Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Fri, 2 Mar 2012 13:43:13 -0500 Subject: Add LLLeap unit tests for strange data on child stdout. --- indra/llcommon/tests/llleap_test.cpp | 36 ++++++++++++++++++++++++++++++++---- 1 file changed, 32 insertions(+), 4 deletions(-) (limited to 'indra/llcommon/tests/llleap_test.cpp') diff --git a/indra/llcommon/tests/llleap_test.cpp b/indra/llcommon/tests/llleap_test.cpp index 652a95ac6b..053a6cea80 100644 --- a/indra/llcommon/tests/llleap_test.cpp +++ b/indra/llcommon/tests/llleap_test.cpp @@ -207,6 +207,34 @@ namespace tut template<> template<> void object::test<3>() + { + set_test_name("bad stdout protocol"); + NamedTempFile script("py", + "print 'Hello from Python!'\n"); + CaptureLog log(LLError::LEVEL_WARN); + waitfor(LLLeap::create(get_test_name(), + sv(list_of(PYTHON)(script.getName())))); + ensure_contains("error log line", + log.messageWith("invalid protocol"), "Hello from Python!"); + } + + template<> template<> + void object::test<4>() + { + set_test_name("leftover stdout"); + NamedTempFile script("py", + "import sys\n" + // note lack of newline + "sys.stdout.write('Hello from Python!')\n"); + CaptureLog log(LLError::LEVEL_WARN); + waitfor(LLLeap::create(get_test_name(), + sv(list_of(PYTHON)(script.getName())))); + ensure_contains("error log line", + log.messageWith("Discarding"), "Hello from Python!"); + } + + template<> template<> + void object::test<5>() { set_test_name("empty plugin vector"); std::string threw; @@ -221,7 +249,7 @@ namespace tut } template<> template<> - void object::test<4>() + void object::test<6>() { set_test_name("bad launch"); // Synthesize bogus executable name @@ -301,7 +329,7 @@ namespace tut }; template<> template<> - void object::test<5>() + void object::test<7>() { set_test_name("round trip"); AckAPI api; @@ -333,7 +361,7 @@ namespace tut }; template<> template<> - void object::test<6>() + void object::test<8>() { set_test_name("many small messages"); // It's not clear to me whether there's value in iterating many times @@ -381,7 +409,7 @@ namespace tut } template<> template<> - void object::test<7>() + void object::test<9>() { set_test_name("very large message"); ReqIDAPI api; -- cgit v1.2.3 From 674f9fb111919f9dffaddf8c0732267f6dbfdf2a Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Fri, 2 Mar 2012 14:56:00 -0500 Subject: Add LLLeap unit test for invalid length prefix from child stdout. --- indra/llcommon/tests/llleap_test.cpp | 22 ++++++++++++++++++---- 1 file changed, 18 insertions(+), 4 deletions(-) (limited to 'indra/llcommon/tests/llleap_test.cpp') diff --git a/indra/llcommon/tests/llleap_test.cpp b/indra/llcommon/tests/llleap_test.cpp index 053a6cea80..328b9c3562 100644 --- a/indra/llcommon/tests/llleap_test.cpp +++ b/indra/llcommon/tests/llleap_test.cpp @@ -235,6 +235,20 @@ namespace tut template<> template<> void object::test<5>() + { + set_test_name("bad stdout len prefix"); + NamedTempFile script("py", + "import sys\n" + "sys.stdout.write('5a2:something')\n"); + CaptureLog log(LLError::LEVEL_WARN); + waitfor(LLLeap::create(get_test_name(), + sv(list_of(PYTHON)(script.getName())))); + ensure_contains("error log line", + log.messageWith("invalid protocol"), "5a2:"); + } + + template<> template<> + void object::test<6>() { set_test_name("empty plugin vector"); std::string threw; @@ -249,7 +263,7 @@ namespace tut } template<> template<> - void object::test<6>() + void object::test<7>() { set_test_name("bad launch"); // Synthesize bogus executable name @@ -329,7 +343,7 @@ namespace tut }; template<> template<> - void object::test<7>() + void object::test<8>() { set_test_name("round trip"); AckAPI api; @@ -361,7 +375,7 @@ namespace tut }; template<> template<> - void object::test<8>() + void object::test<9>() { set_test_name("many small messages"); // It's not clear to me whether there's value in iterating many times @@ -409,7 +423,7 @@ namespace tut } template<> template<> - void object::test<9>() + void object::test<10>() { set_test_name("very large message"); ReqIDAPI api; -- cgit v1.2.3 From d72d9f73b6ff93f11e9bc4360d4c7bf2e76d1eec Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Sat, 3 Mar 2012 06:37:05 -0500 Subject: Add debugging output in case LLLeap writes corrupt data to plugin. New llleap_test.cpp load testing turned up Windows issue in which plugin process received corrupt packet, producing LLSDParseError. Add code to dump the bad packet in that case -- but if LLSDParseError is willing to state the offset of the problem, not ALL of the packet. Quiet MSVC warning about little internal base class needing virtual destructor. --- indra/llcommon/tests/llleap_test.cpp | 31 ++++++++++++++++++++++++++++++- 1 file changed, 30 insertions(+), 1 deletion(-) (limited to 'indra/llcommon/tests/llleap_test.cpp') diff --git a/indra/llcommon/tests/llleap_test.cpp b/indra/llcommon/tests/llleap_test.cpp index 328b9c3562..4fb80df788 100644 --- a/indra/llcommon/tests/llleap_test.cpp +++ b/indra/llcommon/tests/llleap_test.cpp @@ -86,6 +86,7 @@ namespace tut reader(".py", // This logic is adapted from vita.viewerclient.receiveEvent() boost::lambda::_1 << + "import re\n" "import os\n" "import sys\n" // Don't forget that this Python script is written to some @@ -128,7 +129,33 @@ namespace tut " parts[-1] = parts[-1][:excess]\n" " data = ''.join(parts)\n" " assert len(data) == length\n" - " return llsd.parse(data)\n" + " try:\n" + " return llsd.parse(data)\n" + " except llsd.LLSDParseError, e:\n" + " print >>sys.stderr, 'Bad received packet (%s), %s bytes:' % \\\n" + " (e, len(data))\n" + " showmax = 40\n" + // We've observed failures with very large packets; + // dumping the entire packet wastes time and space. + // But if the error states a particular byte offset, + // truncate to (near) that offset when dumping data. + " location = re.search(r' at byte ([0-9]+)', str(e))\n" + " if not location:\n" + " # didn't find offset, dump whole thing, no ellipsis\n" + " ellipsis = ''\n" + " else:\n" + " # found offset within error message\n" + " trunc = int(location.group(1)) + showmax\n" + " data = data[:trunc]\n" + " ellipsis = '... (%s more)' % (length - trunc)\n" + " offset = -showmax\n" + " for offset in xrange(0, len(data)-showmax, showmax):\n" + " print >>sys.stderr, '%04d: %r +' % \\\n" + " (offset, data[offset:offset+showmax])\n" + " offset += showmax\n" + " print >>sys.stderr, '%04d: %r%s' % \\\n" + " (offset, data[offset:], ellipsis)\n" + " raise\n" "\n" "# deal with initial stdin message\n" // this will throw if the initial write to stdin doesn't @@ -294,6 +321,8 @@ namespace tut mPump.listen(name, boost::bind(&ListenerBase::call, this, _1)); } + virtual ~ListenerBase() {} // pacify MSVC + virtual bool call(const LLSD& request) { return false; -- cgit v1.2.3 From ca703b2b9cd9469ad86539f2b95dbf1162b786f2 Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Sun, 4 Mar 2012 16:59:48 -0500 Subject: Make llleap_test.cpp avoid hard limit on MSVC std::ostringstream max. In load testing, we have observed intermittent failures on Windows in which LLSDNotationStreamer into std::ostringstream seems to bump into a hard limit of 1048590 bytes. ostringstream reports that much buffered data and returns that much -- even though, on examination, the notation-serialized stream is incomplete at that point. It's our intention to load-test LLLeap and LLProcess, not the local iostream implementation; we hope that this kind of data volume is comfortably greater than actual usage. Back off the load-testing max size a bit. --- indra/llcommon/tests/llleap_test.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'indra/llcommon/tests/llleap_test.cpp') diff --git a/indra/llcommon/tests/llleap_test.cpp b/indra/llcommon/tests/llleap_test.cpp index 4fb80df788..677f4830ea 100644 --- a/indra/llcommon/tests/llleap_test.cpp +++ b/indra/llcommon/tests/llleap_test.cpp @@ -40,7 +40,7 @@ StringVec sv(const StringVec& listof) { return listof; } #define sleep(secs) _sleep((secs) * 1000) #endif -const size_t BUFFERED_LENGTH = 1024*1024; // try wrangling a megabyte of data +const size_t BUFFERED_LENGTH = 1024*1023; // try wrangling just under a megabyte of data void waitfor(const std::vector& instances, int timeout=60) { @@ -139,13 +139,13 @@ namespace tut // dumping the entire packet wastes time and space. // But if the error states a particular byte offset, // truncate to (near) that offset when dumping data. - " location = re.search(r' at byte ([0-9]+)', str(e))\n" + " location = re.search(r' at (byte|index) ([0-9]+)', str(e))\n" " if not location:\n" " # didn't find offset, dump whole thing, no ellipsis\n" " ellipsis = ''\n" " else:\n" " # found offset within error message\n" - " trunc = int(location.group(1)) + showmax\n" + " trunc = int(location.group(2)) + showmax\n" " data = data[:trunc]\n" " ellipsis = '... (%s more)' % (length - trunc)\n" " offset = -showmax\n" -- cgit v1.2.3 From 30e8e23d7cf666c406901d85a59d16401dca67ab Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Sun, 4 Mar 2012 21:27:42 -0500 Subject: Simplify llleap_test.cpp plugin by reading individual characters. While we're accumulating the 'length:' prefix, the present socket-based logic reads 20 characters, then reads 'length' more, then discards any excess (in case the whole 'length:data' packet ends up being less than 20 characters). That's probably a bug: whatever characters follow that packet, however short it may be, are probably the 'length:' prefix of the next packet. We probably only get away with it because we probably never send packets that short. Earlier llleap_test.cpp plugin logic still read 20 characters, then, if there were any left after the present packet, cached them as the start of the next packet. This is probably more correct, but complicated. Easier just to read individual characters until we've seen 'length:', then try for exactly the specified length over however many reads that requires. --- indra/llcommon/tests/llleap_test.cpp | 23 ++++++++--------------- 1 file changed, 8 insertions(+), 15 deletions(-) (limited to 'indra/llcommon/tests/llleap_test.cpp') diff --git a/indra/llcommon/tests/llleap_test.cpp b/indra/llcommon/tests/llleap_test.cpp index 677f4830ea..73d7217608 100644 --- a/indra/llcommon/tests/llleap_test.cpp +++ b/indra/llcommon/tests/llleap_test.cpp @@ -101,32 +101,25 @@ namespace tut " sys.path.insert(0,\n" " os.path.join(mydir, os.pardir, os.pardir, 'lib', 'python'))\n" " from indra.base import llsd\n" - "LEFTOVER = ''\n" "class ProtocolError(Exception):\n" " pass\n" "def get():\n" - " global LEFTOVER\n" - " hdr = LEFTOVER\n" - " if ':' not in hdr:\n" - " hdr += sys.stdin.read(20)\n" + " hdr = ''\n" + " while ':' not in hdr and len(hdr) < 20:\n" + " hdr += sys.stdin.read(1)\n" " if not hdr:\n" " sys.exit(0)\n" - " parts = hdr.split(':', 1)\n" - " if len(parts) != 2:\n" + " if not hdr.endswith(':'):\n" " raise ProtocolError('Expected len:data, got %r' % hdr)\n" " try:\n" - " length = int(parts[0])\n" + " length = int(hdr[:-1])\n" " except ValueError:\n" - " raise ProtocolError('Non-numeric len %r' % parts[0])\n" - " del parts[0]\n" - " received = len(parts[0])\n" + " raise ProtocolError('Non-numeric len %r' % hdr[:-1])\n" + " parts = []\n" + " received = 0\n" " while received < length:\n" " parts.append(sys.stdin.read(length - received))\n" " received += len(parts[-1])\n" - " if received > length:\n" - " excess = length - received\n" - " LEFTOVER = parts[-1][excess:]\n" - " parts[-1] = parts[-1][:excess]\n" " data = ''.join(parts)\n" " assert len(data) == length\n" " try:\n" -- cgit v1.2.3 From 2491e2bda53ac3a1f2f021e425e7c7c4859e68ad Mon Sep 17 00:00:00 2001 From: Nat Goodspeed Date: Mon, 5 Mar 2012 18:55:48 -0500 Subject: Additional diagnostic code to track down strange Windows pipe error. It seems that under certain circumstances, write logic was duplicating a chunk of the data being streamed down our pipe. But as this condition is only driven with a very large data stream, eyeballing that data stream is tedious. Add code to compare the raw received data with the expected stream, reporting where and how they first differ. --- indra/llcommon/tests/llleap_test.cpp | 51 +++++++++++++++++++++++++++++++----- 1 file changed, 44 insertions(+), 7 deletions(-) (limited to 'indra/llcommon/tests/llleap_test.cpp') diff --git a/indra/llcommon/tests/llleap_test.cpp b/indra/llcommon/tests/llleap_test.cpp index 73d7217608..f1309c5e32 100644 --- a/indra/llcommon/tests/llleap_test.cpp +++ b/indra/llcommon/tests/llleap_test.cpp @@ -89,6 +89,7 @@ namespace tut "import re\n" "import os\n" "import sys\n" + "\n" // Don't forget that this Python script is written to some // temp directory somewhere! Its __file__ is useless in // finding indra/lib/python. Use our __FILE__, with @@ -101,8 +102,15 @@ namespace tut " sys.path.insert(0,\n" " os.path.join(mydir, os.pardir, os.pardir, 'lib', 'python'))\n" " from indra.base import llsd\n" + "\n" "class ProtocolError(Exception):\n" + " def __init__(self, msg, data):\n" + " Exception.__init__(self, msg)\n" + " self.data = data\n" + "\n" + "class ParseError(ProtocolError):\n" " pass\n" + "\n" "def get():\n" " hdr = ''\n" " while ':' not in hdr and len(hdr) < 20:\n" @@ -110,11 +118,11 @@ namespace tut " if not hdr:\n" " sys.exit(0)\n" " if not hdr.endswith(':'):\n" - " raise ProtocolError('Expected len:data, got %r' % hdr)\n" + " raise ProtocolError('Expected len:data, got %r' % hdr, hdr)\n" " try:\n" " length = int(hdr[:-1])\n" " except ValueError:\n" - " raise ProtocolError('Non-numeric len %r' % hdr[:-1])\n" + " raise ProtocolError('Non-numeric len %r' % hdr[:-1], hdr[:-1])\n" " parts = []\n" " received = 0\n" " while received < length:\n" @@ -124,9 +132,12 @@ namespace tut " assert len(data) == length\n" " try:\n" " return llsd.parse(data)\n" - " except llsd.LLSDParseError, e:\n" - " print >>sys.stderr, 'Bad received packet (%s), %s bytes:' % \\\n" - " (e, len(data))\n" + // Seems the old indra.base.llsd module didn't properly + // convert IndexError (from running off end of string) to + // LLSDParseError. + " except (IndexError, llsd.LLSDParseError), e:\n" + " msg = 'Bad received packet (%s)' % e\n" + " print >>sys.stderr, '%s, %s bytes:' % (msg, len(data))\n" " showmax = 40\n" // We've observed failures with very large packets; // dumping the entire packet wastes time and space. @@ -148,7 +159,7 @@ namespace tut " offset += showmax\n" " print >>sys.stderr, '%04d: %r%s' % \\\n" " (offset, data[offset:], ellipsis)\n" - " raise\n" + " raise ParseError(msg, data)\n" "\n" "# deal with initial stdin message\n" // this will throw if the initial write to stdin doesn't @@ -462,7 +473,33 @@ namespace tut // Pass 'large' as reqid because we know the API // will echo reqid, and we want to receive it back. "request('" << api.getName() << "', dict(reqid=large))\n" - "resp = get()\n" + "try:\n" + " resp = get()\n" + "except ParseError, e:\n" + " # try to find where e.data diverges from expectation\n" + // Normally we'd expect a 'pump' key in there, + // too, with value replypump(). But Python + // serializes keys in a different order than C++, + // so incoming data start with 'data'. + // Truthfully, though, if we get as far as 'pump' + // before we find a difference, something's very + // strange. + " expect = llsd.format_notation(dict(data=dict(reqid=large)))\n" + " chunk = 40\n" + " for offset in xrange(0, max(len(e.data), len(expect)), chunk):\n" + " if e.data[offset:offset+chunk] != \\\n" + " expect[offset:offset+chunk]:\n" + " print >>sys.stderr, 'Offset %06d: expect %r,\\n'\\\n" + " ' get %r' %\\\n" + " (offset,\n" + " expect[offset:offset+chunk],\n" + " e.data[offset:offset+chunk])\n" + " break\n" + " else:\n" + " print >>sys.stderr, 'incoming data matches expect?!'\n" + " send('" << result.getName() << "', '%s: %s' % (e.__class__.__name__, e))\n" + " sys.exit(1)\n" + "\n" "echoed = resp['data']['reqid']\n" "if echoed == large:\n" " send('" << result.getName() << "', '')\n" -- cgit v1.2.3