main.lua

Mon, 10 Sep 2018 13:47:34 +0100

author
Matthew Wild <mwild1@gmail.com>
date
Mon, 10 Sep 2018 13:47:34 +0100
changeset 113
f5c1ccc58b48
parent 110
d58403c8615e
child 114
48aab6c9e9d3
permissions
-rwxr-xr-x

main: Include script filename in "script" log event

#!/usr/bin/env luajit

local json = require "cjson";
local time = require "socket".gettime;
local sleep = require "socket".sleep;

local is_scansion_error = require "scansion.error".is;

local result_log_filename = nil;
local server_log_reader = nil;
local test_metadata = {};
local server_log_wait_time = 0.2;
local skip_server_startup_log = false;
local action_timeout = 5;
local verse_log_levels = { "warn", "error" };
local quiet = false;

local property_rules = {};

local function apply_object_properties(class, name, object)
	for _, rule in ipairs(property_rules) do
		if (not(rule.class) or tostring(rule.class):lower() == tostring(class):lower())
		and (not(rule.name) or tostring(rule.name):lower() == tostring(name):lower()) then
			for prop_key, prop_value in pairs(rule.properties) do
				object[prop_key] = prop_value;
			end
		end
	end
end

local function process_options()
	local function get_value()
		return (assert(table.remove(arg, 1), "unexpected end of command-line options"));
	end
	while arg[1] and arg[1]:sub(1,1) == "-" do
		local opt = arg[1];
		if opt == "--" then
			table.remove(arg, 1);
			break;
		end
		table.remove(arg, 1);
		if opt == "--port" or opt == "-p" then
			local port = assert(tonumber(get_value()), "port number must be a number");
			table.insert(property_rules, { class = "client", properties = { connect_port = port } });
		elseif opt == "--host" or opt == "-h" then
			local host = get_value();
			table.insert(property_rules, { class = "client", properties = { connect_host = host } });
		elseif opt == "--out" or opt == "-o" then
			result_log_filename = get_value();
		elseif opt == "--server-log" or opt == "-s" then
			local server_log = assert(io.open(get_value(), "r"));
			function server_log_reader()
				local new_lines = {};
				local last_line_time = time();
				while time() - last_line_time < server_log_wait_time do
					sleep(0.05);
					for line in server_log:lines() do
						table.insert(new_lines, line);
						last_line_time = time();
					end
				end
				return new_lines;
			end
		elseif opt == "--skip-server-startup-log" then
			skip_server_startup_log = true;
		elseif opt == "--step-timeout" then
			action_timeout = assert(tonumber(get_value()), "number expected for --step-timeout");
		elseif opt == "--tag" then
			local tag = get_value();
			local key, value = tag:match("^([^=]+):(.+)$");
			if key and value then
				test_metadata[key] = value;
			else
				error("Unable to parse tag: "..tag);
			end
		elseif opt == "--verbose" or opt == "-v" then
			verse_log_levels = { "debug", "info", "warn", "error" };
			quiet = false;
		elseif opt == "--quiet" or opt == "-q" then
			verse_log_levels = { "error" };
			quiet = true;
		else
			error("Unhandled command-line option: "..opt);
		end
	end
	assert(#arg > 0, "No test script provided");
end

local function read_script(script_name)
	io.input(script_name);
	return io.read("*a");
end

local function parse_script(data)
	local parser = require "scansion.parser";
	return assert(parser.parse(data));
end

local function initialize_script(script)
	local c = 0;
	for name, object in pairs(script.objects) do --luacheck: ignore name
		local o = require("scansion.objects."..object.type);
		object.handler = o;
		object.script = script;
		apply_object_properties(object.type, object.name, object);
		if object.type == "client" and not object.stanza_timeout then
			object.stanza_timeout = action_timeout - 1;
		end
		o._validate(object);
		c = c + 1;
	end

	--print("Script defines "..c.." objects, and "..#script.actions.." actions");
	return script;
end

local function initialize_verse(errcb)
	local verse = require "verse";

	verse.set_log_handler(verse._default_log_handler, verse_log_levels);

	local function error_handler(err)
		-- Only log actual errors. Those reported by Scansion will be handled gracefully higher up.
		if not is_scansion_error(err) then
			verse.log("error", "Error: %s", err);
			verse.log("error", "Traceback: %s", debug.traceback());
		end
		errcb(err);
	end
	verse.set_error_handler(error_handler);
	return verse;
end

local function main(log_data, script_name)

	local ok, err = true;

	local script = initialize_script(parse_script(read_script(script_name)));

	log_data("script", { title = script.title, summary = script.summary, tags = script.tags, filename = script_name });

	if server_log_reader then
		if skip_server_startup_log then
			server_log_reader();
		else
			log_data("server", { lines = server_log_reader() });
		end
	end

	local verse = initialize_verse(function (_err) ok, err = false, _err end);
	local async = require "scansion.async";

	local runner = async.runner(function ()
		for i, action in ipairs(script.actions) do
			local object = script.objects[action.object_name];
			local handler = object.handler;
			assert(handler[action.action], "Objects of type '"..object.type.."' do not support action '"..action.action.."'");
			if not quiet then
				print("");
			end
			if server_log_reader then
				log_data("server", { lines = server_log_reader() });
			end
			log_data("action", {
				action = action.action;
				object = object.name;
				object_type = object.type;
				extra = action.extra;
				annotation = action.annotation;
			});
			if not quiet then
				if action.annotation then
					print(action.annotation);
				end
				print(object.name.." "..action.action);
			end
			if action_timeout and action_timeout > 0 then
				local action_number = i;
				verse.add_task(action_timeout, function ()
					if i == action_number then
						error("Timeout waiting for response from server");
					end
				end);
			end
			do
				--luacheck: ignore ok err
				local ok, err = pcall(handler[action.action], object, action.extra);
				if server_log_reader then
					log_data("server", { lines = server_log_reader() });
				end
				if not ok then
					log_data("error", { message = err });
					error(err);
				end
			end
		end
		script.finished = true;
		verse.log("info", "Completed script!");
		verse.quit();
	end, {
		error = function (runner, _err) --luacheck: ignore runner
			verse.log("error", "Runner caught error: %s", _err);
			ok, err = false, _err;
			verse.quit();
		end;
	});

	runner:run(true);
	verse.log("debug", "runner paused")

	verse.loop();

	if server_log_reader then
		log_data("server", { lines = server_log_reader() });
	end

	return ok, err;
end

-- Process command-line options
process_options();

-- Dummy logging function, used if no log file set
local log_data = function () end;

local result_log;
if result_log_filename then
	result_log = assert(io.open(result_log_filename, "w+"));
	result_log:write("[\n");
	function log_data(type, data)
		local entry = { type = type, data = data, time = time() };
		result_log:write("  ", json.encode(entry), ",\n");
		result_log:flush();
	end
end

local function run_test_script(script_name)

	log_data("start", { metadata = test_metadata });
	local ok, result, err = pcall(main, log_data, script_name);

	local exit_code = 0;
	if not ok then
		print("TEST ERROR:", result);
		exit_code = 2;
		log_data("test-error", { error = result });
	elseif not result then
		print("TEST FAILED", err);
		exit_code = 1;
		log_data("test-failed", { error = err });
	elseif not quiet then
		print("TEST PASSED");
		log_data("test-passed");
	end
	return exit_code;
end

local exit_code = 0;
for i = 1, #arg do
	local ret = run_test_script(arg[i]);
	if ret > exit_code then
		exit_code = ret;
	end
end

if result_log then
	result_log:write([[  {"type": "end", "time": ]]..time().."}\n]\n");
	result_log:close();
end

os.exit(exit_code);

mercurial