1 files changed, 68 insertions, 17 deletions

diff --git a/plugins/mod_muc_mam.lua b/plugins/mod_muc_mam.lua
index 5a01324d..7eeada6d 100644
--- a/plugins/mod_muc_mam.lua
+++ b/plugins/mod_muc_mam.lua
@@ -4,7 +4,7 @@
 -- This file is MIT/X11 licensed.
 
 if module:get_host_type() ~= "component" then
-	module:log("error", "mod_%s should be loaded only on a MUC component, not normal hosts", module.name);
+	module:log_status("error", "mod_%s should be loaded only on a MUC component, not normal hosts", module.name);
 	return;
 end
 
@@ -21,6 +21,7 @@ local jid_bare = require "util.jid".bare;
 local jid_split = require "util.jid".split;
 local jid_prep = require "util.jid".prep;
 local dataform = require "util.dataforms".new;
+local get_form_type = require "util.dataforms".get_type;
 
 local mod_muc = module:depends"muc";
 local get_room_from_jid = mod_muc.get_room_from_jid;
@@ -32,6 +33,9 @@ local m_min = math.min;
 local timestamp, timestamp_parse, datestamp = import( "util.datetime", "datetime", "parse", "date");
 local default_max_items, max_max_items = 20, module:get_option_number("max_archive_query_results", 50);
 
+local cleanup_after = module:get_option_string("muc_log_expires_after", "1w");
+local cleanup_interval = module:get_option_number("muc_log_cleanup_interval", 4 * 60 * 60);
+
 local default_history_length = 20;
 local max_history_length = module:get_option_number("max_history_messages", math.huge);
 
@@ -49,6 +53,8 @@ local log_by_default = module:get_option_boolean("muc_log_by_default", true);
 local archive_store = "muc_log";
 local archive = module:open_store(archive_store, "archive");
 
+local archive_item_limit = module:get_option_number("storage_archive_item_limit", archive.caps and archive.caps.quota or 1000);
+
 if archive.name == "null" or not archive.find then
 	if not archive.find then
 		module:log("error", "Attempt to open archive storage returned a driver without archive API support");
@@ -63,12 +69,15 @@ end
 
 local function archiving_enabled(room)
 	if log_all_rooms then
+		module:log("debug", "Archiving all rooms");
 		return true;
 	end
 	local enabled = room._data.archiving;
 	if enabled == nil then
+		module:log("debug", "Default is %s (for %s)", log_by_default, room.jid);
 		return log_by_default;
 	end
+	module:log("debug", "Logging in room %s is %s", room.jid, enabled);
 	return enabled;
 end
 
@@ -135,7 +144,14 @@ module:hook("iq-set/bare/"..xmlns_mam..":query", function(event)
 	local qstart, qend;
 	local form = query:get_child("x", "jabber:x:data");
 	if form then
-		local err;
+		local form_type, err = get_form_type(form);
+		if not form_type then
+			origin.send(st.error_reply(stanza, "modify", "bad-request", "Invalid dataform: "..err));
+			return true;
+		elseif form_type ~= xmlns_mam then
+			origin.send(st.error_reply(stanza, "modify", "bad-request", "Unexpected FORM_TYPE, expected '"..xmlns_mam.."'"));
+			return true;
+		end
 		form, err = query_form:data(form);
 		if err then
 			origin.send(st.error_reply(stanza, "modify", "bad-request", select(2, next(err))));
@@ -153,10 +169,11 @@ module:hook("iq-set/bare/"..xmlns_mam..":query", function(event)
 		qstart, qend = vstart, vend;
 	end
 
-	module:log("debug", "Archive query id %s from %s until %s)",
-		tostring(qid),
-		qstart and timestamp(qstart) or "the dawn of time",
-		qend and timestamp(qend) or "now");
+	module:log("debug", "Archive query by %s id=%s when=%s...%s",
+		origin.username,
+		qid or stanza.attr.id,
+		qstart and timestamp(qstart) or "",
+		qend and timestamp(qend) or "");
 
 	-- RSM stuff
 	local qset = rsm.get(query);
@@ -165,6 +182,9 @@ module:hook("iq-set/bare/"..xmlns_mam..":query", function(event)
 
 	local before, after = qset and qset.before, qset and qset.after;
 	if type(before) ~= "string" then before = nil; end
+	if qset then
+		module:log("debug", "Archive query id=%s rsm=%q", qid or stanza.attr.id, qset);
+	end
 
 	-- Load all the data!
 	local data, err = archive:find(room_node, {
@@ -176,7 +196,12 @@ module:hook("iq-set/bare/"..xmlns_mam..":query", function(event)
 	});
 
 	if not data then
-		origin.send(st.error_reply(stanza, "cancel", "internal-server-error"));
+		module:log("debug", "Archive query id=%s failed: %s", qid or stanza.attr.id, err);
+		if err == "item-not-found" then
+			origin.send(st.error_reply(stanza, "modify", "item-not-found"));
+		else
+			origin.send(st.error_reply(stanza, "cancel", "internal-server-error"));
+		end
 		return true;
 	end
 	local total = tonumber(err);
@@ -233,13 +258,14 @@ module:hook("iq-set/bare/"..xmlns_mam..":query", function(event)
 		first, last = last, first;
 	end
 
-	-- That's all folks!
-	module:log("debug", "Archive query %s completed", tostring(qid));
 
 	origin.send(st.reply(stanza)
 		:tag("fin", { xmlns = xmlns_mam, queryid = qid, complete = complete })
 			:add_child(rsm.generate {
 				first = first, last = last, count = total }));
+
+	-- That's all folks!
+	module:log("debug", "Archive query id=%s completed, %d items returned", qid or stanza.attr.id, complete and count or count - 1);
 	return true;
 end);
 
@@ -274,7 +300,7 @@ module:hook("muc-get-history", function (event)
 	local data, err = archive:find(jid_split(room_jid), query);
 
 	if not data then
-		module:log("error", "Could not fetch history: %s", tostring(err));
+		module:log("error", "Could not fetch history: %s", err);
 		return
 	end
 
@@ -300,7 +326,7 @@ module:hook("muc-get-history", function (event)
 			maxchars = maxchars - chars;
 		end
 		history[i], i = item, i+1;
-		-- module:log("debug", tostring(item));
+		-- module:log("debug", item);
 	end
 	function event.next_stanza()
 		i = i - 1;
@@ -328,7 +354,7 @@ end, 0);
 
 -- Handle messages
 local function save_to_history(self, stanza)
-	local room_node, room_host = jid_split(self.jid);
+	local room_node = jid_split(self.jid);
 
 	local stored_stanza = stanza;
 
@@ -355,7 +381,29 @@ local function save_to_history(self, stanza)
 	end
 
 	-- And stash it
-	local id, err = archive:append(room_node, nil, stored_stanza, time_now(), with);
+	local time = time_now();
+	local id, err = archive:append(room_node, nil, stored_stanza, time, with);
+
+	if not id and err == "quota-limit" then
+		if type(cleanup_after) == "number" then
+			module:log("debug", "Room '%s' over quota, cleaning archive", room_node);
+			local cleaned = archive:delete(room_node, {
+				["end"] = (os.time() - cleanup_after);
+			});
+			if cleaned then
+				id, err = archive:append(room_node, nil, stored_stanza, time, with);
+			end
+		end
+		if not id and (archive.caps and archive.caps.truncate) then
+			module:log("debug", "User '%s' over quota, truncating archive", room_node);
+			local truncated = archive:delete(room_node, {
+				truncate = archive_item_limit - 1;
+			});
+			if truncated then
+				id, err = archive:append(room_node, nil, stored_stanza, time, with);
+			end
+		end
+	end
 
 	if id then
 		schedule_cleanup(room_node);
@@ -394,14 +442,13 @@ end
 module:add_feature(xmlns_mam);
 
 module:hook("muc-disco#info", function(event)
-	event.reply:tag("feature", {var=xmlns_mam}):up();
+	if archiving_enabled(event.room) then
+		event.reply:tag("feature", {var=xmlns_mam}):up();
+	end
 end);
 
 -- Cleanup
 
-local cleanup_after = module:get_option_string("muc_log_expires_after", "1w");
-local cleanup_interval = module:get_option_number("muc_log_cleanup_interval", 4 * 60 * 60);
-
 if cleanup_after ~= "never" then
 	local cleanup_storage = module:open_store("muc_log_cleanup");
 	local cleanup_map = module:open_store("muc_log_cleanup", "map");
@@ -437,8 +484,11 @@ if cleanup_after ~= "never" then
 		end
 	end
 
+	local cleanup_time = module:measure("cleanup", "times");
+
 	local async = require "util.async";
 	cleanup_runner = async.runner(function ()
+		local cleanup_done = cleanup_time();
 		local rooms = {};
 		local cut_off = datestamp(os.time() - cleanup_after);
 		for date in cleanup_storage:users() do
@@ -472,6 +522,7 @@ if cleanup_after ~= "never" then
 			wait();
 		end
 		module:log("info", "Deleted %d expired messages for %d rooms", sum, num_rooms);
+		cleanup_done();
 	end);
 
 	cleanup_task = module:add_timer(1, function ()