From d733d3a200a1d2a5aef697960badc02f1198d334 Mon Sep 17 00:00:00 2001 From: Daniel Silverstone Date: Sun, 12 Aug 2012 17:11:06 +0100 Subject: SUPPLE: Lots of diagnosis stuff --- Makefile | 2 +- example/simple-example.lua | 102 +++++++++++++++++++++++++++++++++------------ lib/supple.lua | 2 + lib/supple/capi.c | 2 +- lib/supple/comms.lua | 29 +++++++++++-- lib/supple/host.lua | 7 +++- lib/supple/objects.lua | 35 +++++++++++++++- lib/supple/sandbox.lua | 2 + lib/supple/track.lua | 57 +++++++++++++++++++++++++ test/test-supple.track.lua | 51 +++++++++++++++++++++++ 10 files changed, 254 insertions(+), 35 deletions(-) create mode 100644 lib/supple/track.lua create mode 100644 test/test-supple.track.lua diff --git a/Makefile b/Makefile index 2228776..639aaae 100644 --- a/Makefile +++ b/Makefile @@ -1,7 +1,7 @@ all: test LMODULES := supple supple.request supple.objects supple.sandbox \ - supple.host supple.comms + supple.host supple.comms supple.track CMODULES := supple.capi MODULES := $(LMODULES) $(CMODULES) LUA_VER := 5.1 diff --git a/example/simple-example.lua b/example/simple-example.lua index 1d82944..6f35400 100644 --- a/example/simple-example.lua +++ b/example/simple-example.lua @@ -41,39 +41,55 @@ local mt = { setmetatable(tab, mt) -local function lprint(...) +local tests, passed = 0, 0 + +local function lprint(expect, result, ...) + tests = tests + 1 + luxio.write(1, ("[%d]\r"):format(tests)) local foo = {n=select("#",...),...} - if foo[1] then - print "Function ran OK:" - else - print "Error encountered:" + if expect and not result then + print "Want OK, got FAIL" + elseif (not expect) and result then + print "Want FAIL, got OK" end - for i = 2, foo.n do - if type(foo[i]) == "table" then - print("{") - for k, v in pairs(foo[i]) do - print("",k,v) + if expect ~= result then + for i = 1, foo.n do + if type(foo[i]) == "table" then + print("{") + for k, v in pairs(foo[i]) do + print("",k,v) + end + print("}") + else + print(foo[i]) end - print("}") - else - print(foo[i]) end + print() + else + passed = passed + 1 end - print() +end + +local function lprint_ok(...) + return lprint(true, ...) +end + +local function lprint_fail(...) + return lprint(false, ...) end -- Finally, run the subcode -lprint(supple.host.run(subcode, "@test-code", tab)) +lprint_ok(supple.host.run(subcode, "@test-code", tab)) assert(tab.tot == 24) -- Now run a supple command which we expect to error out. -lprint(supple.host.run("unknown()", "@test-code")) +lprint_fail(supple.host.run("unknown()", "@test-code")) -- And now, one where we pass an error from host to sandbox and back -lprint(supple.host.run("local f = ... f()", "@test-code", function() unknown() end)) +lprint_fail(supple.host.run("local f = ... f()", "@test-code", function() unknown() end)) -- And now, one where we pass an error from sandbox to host to sandbox and back -lprint(supple.host.run("local f = ... f(function() unknown() end)", "@test-code", function(ff) ff() end)) +lprint_fail(supple.host.run("local f = ... f(function() unknown() end)", "@test-code", function(ff) ff() end)) -- Next , a reasonable traceback via named functions on each end... @@ -99,7 +115,7 @@ function loopback(f) f(loopback) end -lprint(supple.host.run(errsrc, "@error-code", loopback)) +lprint_fail(supple.host.run(errsrc, "@error-code", loopback)) -- Now we try the sandboxing limits @@ -112,9 +128,9 @@ local long_run = [[ ]] supple.host.set_limits { count = 100 } -lprint(supple.host.run(long_run, "@long-code")) +lprint_fail(supple.host.run(long_run, "@long-code")) supple.host.set_limits { memory = 1000 } -lprint(supple.host.run(long_run, "@big-code")) +lprint_fail(supple.host.run(long_run, "@big-code")) -- next we demonstrate that ipairs works on proxied tables @@ -128,7 +144,7 @@ local summing = [[ return tot ]] -lprint(supple.host.run(summing, "@summing", { 10, 14, 3 })) +lprint_ok(supple.host.run(summing, "@summing", { 10, 14, 3 })) -- next we demonstrate that next works on proxied tables @@ -137,8 +153,8 @@ local isempty = [[ return next(t) == nil ]] -lprint(supple.host.run(isempty, "@isempty", {})) -lprint(supple.host.run(isempty, "@isempty", {"bar"})) +lprint_ok(supple.host.run(isempty, "@isempty", {})) +lprint_ok(supple.host.run(isempty, "@isempty", {"bar"})) -- And now that pairs works on proxied tables @@ -152,7 +168,7 @@ local keys = [[ return ret ]] -lprint(supple.host.run(keys, "@keys", { foo="bar", baz="meta" })) +lprint_ok(supple.host.run(keys, "@keys", { foo="bar", baz="meta" })) -- Next demonstrate that using supple.host.loadstring works to allow -- globals set in the parent to be seen/changed @@ -168,4 +184,38 @@ local getname = [[ ]] -- Expect to see 'PRINT' -lprint(supple.host.run(getname, "@getname", loader)) +lprint_ok(supple.host.run(getname, "@getname", loader)) + +-- Attempt to do a test which shows the same issue as seen with gitano-web + +local updates = { + ["refs/heads/master"] = { + oldsha = "0123456789abcdef0123456789abcdef01234567", + newsha = "76543210fedcba9876543210fedcba9876543210", + } +} + +local update_code = [[ + local repo, updates = ... + local hadmaster = false + local foundrefs = {} + if updates["refs/heads/master"] then + hadmaster = true + end + for ref, data in pairs(updates) do + foundrefs[ref] = { data.oldsha, data.newsha } + end + return hadmaster, foundrefs +]] + +for i = 1, 1000 do + lprint_ok(supple.host.run(update_code, "@update-hook", "REPO", updates)) + if passed ~= tests then + os.exit(1) + end +end + +print(("[%d/%d OK]"):format(passed, tests)) + +-- Dump the final trace, just for edification +--print(supple.track.stop()) diff --git a/lib/supple.lua b/lib/supple.lua index 9cb2d8a..513d3ac 100644 --- a/lib/supple.lua +++ b/lib/supple.lua @@ -13,6 +13,7 @@ local objects = require 'supple.objects' local comms = require 'supple.comms' local sandbox = require 'supple.sandbox' local host = require 'supple.host' +local track = require 'supple.track' local _VERSION = 1 local _ABI = 1 @@ -26,6 +27,7 @@ return { comms = comms, sandbox = sandbox, host = host, + track = track, _VERSION = _VERSION, VERSION = VERSION, _ABI = _ABI, diff --git a/lib/supple/capi.c b/lib/supple/capi.c index 38c4f27..34e6169 100644 --- a/lib/supple/capi.c +++ b/lib/supple/capi.c @@ -181,7 +181,7 @@ supple_capi_lockdown(lua_State *L) char *tempdir; struct rlimit lim; lua_settop(L, 0); /* Discard any arguments */ - + /* Prepare a copy of the tempdir template ready */ tempdir = lua_newuserdata(L, strlen(TEMPDIR_NAME)); strcpy(tempdir, TEMPDIR_NAME); diff --git a/lib/supple/comms.lua b/lib/supple/comms.lua index e72f8f1..ae2779c 100644 --- a/lib/supple/comms.lua +++ b/lib/supple/comms.lua @@ -14,6 +14,7 @@ local luxio = require "luxio" local capi = require "supple.capi" local request = require "supple.request" local objects = require "supple.objects" +local track = require "supple.track" local unpack = unpack local tonumber = tonumber @@ -34,6 +35,7 @@ local function send_msg(msg) error("Message too long") end local msglen = ("%05d"):format(#msg) + track.record("XMIT", msg) luxio.write(fd, msglen .. msg) end @@ -53,6 +55,7 @@ local function recv_msg() if type(str) ~= "string" or #str ~= len then error("Unable to read " .. tostring(len) .. " bytes of msg") end + track.record("RECV", str) return str end @@ -64,7 +67,8 @@ local function captcha(msg) return info.short_src:match("/supple/[^%.]+%.lua$") end while info and info.func ~= xpcall do - if info.currentline > 0 and not in_supple() then +-- if info.currentline > 0 and not in_supple() then + if true then local ttype, tag = objects.find_tag(info.func) if ttype then info.name = tag @@ -78,7 +82,7 @@ local function captcha(msg) level = level + 1 info = getinfo(level, "Snlf") end - return {msg, concat(traceback, "\n") or ""} + return {msg, (concat(traceback, "\n") or "") .. "\nComms track:\n" .. track.stop()} end local limits = {} @@ -111,7 +115,23 @@ end local function wait_for_response() repeat + -- We *MUST* disable GC for the duration of receiving and parsing the + -- message, lest we send a __gc transaction between the first and second + -- read operations. Or indeed if we GC and object between receiving the + -- message and deserialising and thus anchoring the object. If we error + -- out here, we don't really care about restarting gc since we won't + -- survive long anyhow. + gc "stop" + -- Also anchor all the objects just in case + local anchor = objects.get_object_anchor() + -- Now receive and deserialise (thus anchoring relevant objects) local back = request.deserialise(recv_msg()) + -- Now that the request is anchored, release the extra anchor and + -- re-allow GC + anchor = nil + gc "restart" + -- And get on with parsing the message we received.. + -- back could be three things -- an error (raise it) if back.error then @@ -182,9 +202,12 @@ local function wait_for_response() end local function make_call(object, method, ...) + track.enter("make_call", object, method) local req = request.request(object, method, ...) send_msg(req) - return wait_for_response() + local ret = {wait_for_response()} + track.leave("make_call", object, method) + return unpack(ret) end local function set_limits(newlimits) diff --git a/lib/supple/host.lua b/lib/supple/host.lua index 617b365..596fba1 100644 --- a/lib/supple/host.lua +++ b/lib/supple/host.lua @@ -15,6 +15,7 @@ local subprocess = require 'luxio.subprocess' local comms = require 'supple.comms' local objects = require 'supple.objects' local capi = require 'supple.capi' +local track = require 'supple.track' local hostname = "host" local counter = 0 @@ -80,6 +81,8 @@ local function run_sandbox(codestr, codename, ...) objects.set_name(("host[%d,%%d]"):format(counter)) comms._set_fd(commsfd) objects.set_proc_call(comms.call) + + track.start() local func, env = comms.call("supple:loadstring", "__call", codestr, codename) if not func then @@ -120,12 +123,12 @@ local function run_sandbox(codestr, codename, ...) objects.clean_down(true) comms._set_fd(-1) - luxio.kill(child.pid, luxio.SIGKILL) + luxio.close(commsfd) child:wait() if ok then return ok, unpack(ret) else - return ok, err + return ok, err .. "\n\nHost comms track:\n" .. track.stop() end end diff --git a/lib/supple/objects.lua b/lib/supple/objects.lua index 5a5dfca..72eaf9a 100644 --- a/lib/supple/objects.lua +++ b/lib/supple/objects.lua @@ -12,6 +12,7 @@ local gc = collectgarbage local capi = require 'supple.capi' +local track = require 'supple.track' local my_objects_by_obj = {} local my_objects_by_tag = {} @@ -24,6 +25,9 @@ local proc_call = nil local type = capi.rawtype local function clean_down(call_other_end) + track.enter("clean_down") + setmetatable(their_objects_by_tag, { __mode="v" }) + setmetatable(their_objects_by_obj, { __mode="k" }) -- And force a full GC gc "collect" gc "collect" @@ -35,6 +39,7 @@ local function clean_down(call_other_end) -- And forget all our local objects my_objects_by_obj = {} my_objects_by_tag = {} + track.leave("clean_down") end local function set_name(newname) @@ -76,14 +81,17 @@ local function give(obj, special_tag) end -- If the passed object is one of their objects then "unwrap" it by -- returning their tag. + track.enter("give", tostring(obj), tostring(special_tag)) local tag = their_objects_by_obj[obj]; if tag then + track.leave("give", "theirs", tag) return { tag = tag } end -- If it's one of our objects which has already been wrapped, return our -- tag local tag = my_objects_by_obj[obj] if tag then + track.leave("give", "ours", tag) return { tag = tag } end -- otherwise wrap it freshly for us and return that. @@ -91,6 +99,7 @@ local function give(obj, special_tag) local expn = capi.explain(obj, tag) my_objects_by_obj[obj] = tag my_objects_by_tag[tag] = obj + track.leave("give", "ours, new", tag) return expn end @@ -103,18 +112,21 @@ local function receive(obj) assert(type(obj) == "table") assert(type(obj.tag) == "string") local tag = obj.tag + track.enter("receive", tag) -- First up, is it one of our objects? local ret = my_objects_by_tag[tag] if ret then + track.leave("receive", "ours", tostring(ret)) return ret end -- Now is it a known one of their objects? ret = their_objects_by_tag[tag] if ret then + track.leave("receive", "theirs", tostring(ret)) return ret end -- Okay, prepare a proxy? - assert(type(obj.type) == "string") + assert(type(obj.type) == "string", "Type string expected, got " .. type(obj.type) .. " preparing proxy for " .. obj.tag) local proxy, mt = capi.new_proxy(obj.type) assert(capi.type(proxy) == obj.type) their_objects_by_tag[tag] = proxy @@ -133,18 +145,25 @@ local function receive(obj) end for _, name in ipairs(obj.methods or {}) do local function meta_func(mobj, ...) - return proc_call(tag, name, ...) + track.enter("meta_func", tostring(mobj), tag, name) + local ret = {proc_call(tag, name, ...)} + track.leave("meta_func", tostring(mobj), tag, name) + return unpack(ret) end mt[name] = meta_func end -- And return the proxy object + track.leave("receive", "theirs, new", tostring(proxy)) return proxy end local function forget_mine(tag) + track.enter("forget_mine", tag) local obj = my_objects_by_tag[tag] + assert(obj, "Trying to forget nil object: " .. tag) my_objects_by_tag[tag] = nil my_objects_by_obj[obj] = nil + track.leave("forget_mine", tag) end local function find_tag(obj) @@ -156,6 +175,17 @@ local function find_tag(obj) end end +local function get_object_anchor() + local ret = {} + for obj in pairs(their_objects_by_obj) do + ret[obj] = true + end + for obj in pairs(my_objects_by_obj) do + ret[obj] = true + end + return ret +end + return { set_name = set_name, get_name = get_name, @@ -165,4 +195,5 @@ return { clean_down = clean_down, forget_mine = forget_mine, find_tag = find_tag, + get_object_anchor = get_object_anchor, } diff --git a/lib/supple/sandbox.lua b/lib/supple/sandbox.lua index cc1bc6c..bcb2cb8 100644 --- a/lib/supple/sandbox.lua +++ b/lib/supple/sandbox.lua @@ -24,6 +24,7 @@ local objects = require 'supple.objects' local comms = require 'supple.comms' local luxio = require 'luxio' local sio = require 'luxio.simple' +local track = require 'supple.track' local loadstring = loadstring local load = load @@ -152,6 +153,7 @@ local function run() -- Pretend we've "given" the host an object called 'supple:loadstring' -- which is the loadstring/load function + track.start() objects.give(set_limits, "supple:set_limits") objects.give(wrappered_load, "supple:loadstring") objects.give(objects.clean_down, "supple:clean_down") diff --git a/lib/supple/track.lua b/lib/supple/track.lua new file mode 100644 index 0000000..c652281 --- /dev/null +++ b/lib/supple/track.lua @@ -0,0 +1,57 @@ +-- lib/supple/track.lua +-- +-- Sandbox (for) Untrusted Procedure Partitioning (in) Lua Engine +-- +-- Tracking and logging for debug porpoises. +-- +-- Copyright 2012 Daniel Silverstone +-- +-- For licence terms, see COPYING +-- + +local depth +local track + +local function record(...) + if depth then + track[#track+1] = { depth, ... } + end +end + +local function enter(...) + if depth then + record(">>>", ...) + depth = depth + 1 + end +end + +local function leave(...) + if depth then + depth = depth - 1 + record("<<<", ...) + end +end + +local function start_tracking() + depth, track = 0, {} +end + +local function stop_tracking() + local ret = {} + for i = 1, #track do + local ent = track[i] + local pfx = (" "):rep(ent[1]) + table.remove(ent, 1) + ret[#ret+1] = pfx .. table.concat(ent, " ") + end + depth, track = nil, {} + return table.concat(ret, "\n") +end + +return { + start = start_tracking, + stop = stop_tracking, + enter = enter, + leave = leave, + record = record, +} \ No newline at end of file diff --git a/test/test-supple.track.lua b/test/test-supple.track.lua new file mode 100644 index 0000000..b9cc136 --- /dev/null +++ b/test/test-supple.track.lua @@ -0,0 +1,51 @@ +-- test/test-supple.track.lua +-- +-- Supple - Tests for the track module +-- +-- Copyright 2012 Daniel Silverstone +-- +-- For Licence terms, see COPYING +-- + +-- Step one, start coverage + +local luacov = require 'luacov' + +local track = 'supple.track' + +local testnames = {} + +local real_assert = assert +local total_asserts = 0 +local function assert(...) + local retval = real_assert(...) + total_asserts = total_asserts + 1 + return retval +end + +local function add_test(suite, name, value) + rawset(suite, name, value) + testnames[#testnames+1] = name +end + +local suite = setmetatable({}, {__newindex = add_test}) + +function suite:starts() + track.start() +end + +local count_ok = 0 +for _, testname in ipairs(testnames) do +-- print("Run: " .. testname) + local ok, err = xpcall(suite[testname], debug.traceback) + if not ok then + print(err) + print() + else + count_ok = count_ok + 1 + end +end + +print(tostring(count_ok) .. "/" .. tostring(#testnames) .. " [" .. tostring(total_asserts) .. "] OK") + +os.exit(count_ok == #testnames and 0 or 1) -- cgit v1.2.1