From 370ef290d12697c347b649148c3ae0c4132c97a4 Mon Sep 17 00:00:00 2001 From: Matthew Wild Date: Thu, 30 Apr 2009 01:36:46 +0100 Subject: modulemanager: Update logger when a module becomes global --- core/modulemanager.lua | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/core/modulemanager.lua b/core/modulemanager.lua index a1d3bef3..cc48c2f6 100644 --- a/core/modulemanager.lua +++ b/core/modulemanager.lua @@ -123,6 +123,10 @@ function load(host, module_name, config) -- Use modified host, if the module set one modulemap[api_instance.host][module_name] = pluginenv; + if api_instance.host == "*" and host ~= "*" then + api_instance:set_global(); + end + return true; end @@ -260,6 +264,10 @@ end function api:set_global() self.host = "*"; + -- Update the logger + local _log = logger.init("mod_"..self.name); + self.log = function (self, ...) return _log(...); end; + self._log = _log; end local function _add_handler(module, origin_type, tag, xmlns, handler) -- cgit v1.2.3 From daf13d7b6b2de7184b1912753eade90dff79b607 Mon Sep 17 00:00:00 2001 From: Matthew Wild Date: Thu, 30 Apr 2009 01:37:52 +0100 Subject: mod_dialback: Use module logger instead of creating a new one --- plugins/mod_dialback.lua | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/plugins/mod_dialback.lua b/plugins/mod_dialback.lua index fe65d394..855df9eb 100644 --- a/plugins/mod_dialback.lua +++ b/plugins/mod_dialback.lua @@ -13,9 +13,9 @@ local s2s_make_authenticated = require "core.s2smanager".make_authenticated; local s2s_verify_dialback = require "core.s2smanager".verify_dialback; local s2s_destroy_session = require "core.s2smanager".destroy_session; -local st = require "util.stanza"; +local log = module._log; -local log = require "util.logger".init("mod_dialback"); +local st = require "util.stanza"; local xmlns_dialback = "jabber:server:dialback"; -- cgit v1.2.3 From b29f3b94b8f7283cd7f72d915d3c139ce58f55e5 Mon Sep 17 00:00:00 2001 From: Matthew Wild Date: Thu, 30 Apr 2009 01:38:52 +0100 Subject: mod_saslauth: Use module logger instead of creating a new one --- plugins/mod_saslauth.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/plugins/mod_saslauth.lua b/plugins/mod_saslauth.lua index f7b30aab..81d34eaa 100644 --- a/plugins/mod_saslauth.lua +++ b/plugins/mod_saslauth.lua @@ -21,7 +21,7 @@ local jid_split = require "util.jid".split local md5 = require "util.hashes".md5; local config = require "core.configmanager"; -local log = require "util.logger".init("mod_saslauth"); +local log = module._log; local xmlns_sasl ='urn:ietf:params:xml:ns:xmpp-sasl'; local xmlns_bind ='urn:ietf:params:xml:ns:xmpp-bind'; -- cgit v1.2.3 From a2b3659dd8e3141800d3f348e14417f9e9fefdc1 Mon Sep 17 00:00:00 2001 From: Matthew Wild Date: Thu, 30 Apr 2009 01:39:39 +0100 Subject: mod_saslauth: Various logging fixes --- plugins/mod_saslauth.lua | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/plugins/mod_saslauth.lua b/plugins/mod_saslauth.lua index 81d34eaa..9a7c4f97 100644 --- a/plugins/mod_saslauth.lua +++ b/plugins/mod_saslauth.lua @@ -32,13 +32,13 @@ local new_sasl = require "util.sasl".new; local function build_reply(status, ret, err_msg) local reply = st.stanza(status, {xmlns = xmlns_sasl}); if status == "challenge" then - log("debug", ret or ""); + log("debug", "%s", ret or ""); reply:text(base64.encode(ret or "")); elseif status == "failure" then reply:tag(ret):up(); if err_msg then reply:tag("text"):text(err_msg); end elseif status == "success" then - log("debug", ret or ""); + log("debug", "%s", ret or ""); reply:text(base64.encode(ret or "")); else error("Unknown sasl status: "..status); @@ -89,7 +89,7 @@ local function sasl_handler(session, stanza) local text = stanza[1]; if text then text = base64.decode(text); - log("debug", text); + log("debug", "%s", text); if not text then session.sasl_handler = nil; session.send(build_reply("failure", "incorrect-encoding")); @@ -99,7 +99,7 @@ local function sasl_handler(session, stanza) local status, ret, err_msg = session.sasl_handler:feed(text); handle_status(session, status); local s = build_reply(status, ret, err_msg); - log("debug", "sasl reply: "..tostring(s)); + log("debug", "sasl reply: %s", tostring(s)); session.send(s); end @@ -130,7 +130,7 @@ module:add_event_hook("stream-features", module:add_iq_handler("c2s", "urn:ietf:params:xml:ns:xmpp-bind", function (session, stanza) - log("debug", "Client tried to bind to a resource"); + log("debug", "Client requesting a resource bind"); local resource; if stanza.attr.type == "set" then local bind = stanza.tags[1]; @@ -153,6 +153,6 @@ module:add_iq_handler("c2s", "urn:ietf:params:xml:ns:xmpp-bind", module:add_iq_handler("c2s", "urn:ietf:params:xml:ns:xmpp-session", function (session, stanza) - log("debug", "Client tried to bind to a resource"); + log("debug", "Client requesting a session"); session.send(st.reply(stanza)); end); -- cgit v1.2.3 From 5095f23e5d2b9b9c2d8a021376e75c57d52d37c0 Mon Sep 17 00:00:00 2001 From: Matthew Wild Date: Thu, 30 Apr 2009 01:46:36 +0100 Subject: mod_saslauth: Remove 2 instances of raising errors and replacing with more graceful handling --- plugins/mod_saslauth.lua | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/plugins/mod_saslauth.lua b/plugins/mod_saslauth.lua index 9a7c4f97..f27d8060 100644 --- a/plugins/mod_saslauth.lua +++ b/plugins/mod_saslauth.lua @@ -41,7 +41,7 @@ local function build_reply(status, ret, err_msg) log("debug", "%s", ret or ""); reply:text(base64.encode(ret or "")); else - error("Unknown sasl status: "..status); + module:log("error", "Unknown sasl status: %s", status); end return reply; end @@ -50,7 +50,12 @@ local function handle_status(session, status) if status == "failure" then session.sasl_handler = nil; elseif status == "success" then - if not session.sasl_handler.username then error("SASL succeeded but we didn't get a username!"); end -- TODO move this to sessionmanager + if not session.sasl_handler.username then -- TODO move this to sessionmanager + module:log("warn", "SASL succeeded but we didn't get a username!"); + session.sasl_handler = nil; + session:reset_stream(); + return; + end sm_make_authenticated(session, session.sasl_handler.username); session.sasl_handler = nil; session:reset_stream(); -- cgit v1.2.3 From eb68ccd978b7e69b13e391af74e912108ca525f6 Mon Sep 17 00:00:00 2001 From: Matthew Wild Date: Thu, 30 Apr 2009 02:30:03 +0100 Subject: presencemanager: Lower log level of a message --- core/presencemanager.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/core/presencemanager.lua b/core/presencemanager.lua index db6bbf9a..ae73d676 100644 --- a/core/presencemanager.lua +++ b/core/presencemanager.lua @@ -144,7 +144,7 @@ function send_presence_of_available_resources(user, host, jid, recipient_session end end end - log("info", "broadcasted presence of "..count.." resources from "..user.."@"..host.." to "..jid); + log("debug", "broadcasted presence of "..count.." resources from "..user.."@"..host.." to "..jid); return count; end -- cgit v1.2.3 From 8f3b27b822765c096a3ea5fca77d521a89e5e71d Mon Sep 17 00:00:00 2001 From: Matthew Wild Date: Thu, 30 Apr 2009 02:43:12 +0100 Subject: s2smanager: Miscellaneous logging improvements, changing levels, improving messages and using session loggers where possible --- core/s2smanager.lua | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/core/s2smanager.lua b/core/s2smanager.lua index a16f8b02..b14f0e96 100644 --- a/core/s2smanager.lua +++ b/core/s2smanager.lua @@ -48,7 +48,7 @@ local function compare_srv_priorities(a,b) return a.priority < b.priority or a.w local function bounce_sendq(session) local sendq = session.sendq; if sendq then - session.log("debug", "sending error replies for "..#sendq.." queued stanzas because of failed outgoing connection to "..tostring(session.to_host)); + session.log("info", "sending error replies for "..#sendq.." queued stanzas because of failed outgoing connection to "..tostring(session.to_host)); local dummy = { type = "s2sin"; send = function(s) @@ -199,9 +199,9 @@ function attempt_connection(host_session, err) host_session.srv_choice = host_session.srv_choice + 1; local srv_choice = host_session.srv_hosts[host_session.srv_choice]; connect_host, connect_port = srv_choice.target or to_host, srv_choice.port or connect_port; - host_session.log("debug", "Connection failed (%s). Attempt #%d: This time to %s:%d", tostring(err), host_session.srv_choice, connect_host, connect_port); + host_session.log("info", "Connection failed (%s). Attempt #%d: This time to %s:%d", tostring(err), host_session.srv_choice, connect_host, connect_port); else - host_session.log("debug", "Out of connection options, can't connect to %s", tostring(host_session.to_host)); + host_session.log("info", "Out of connection options, can't connect to %s", tostring(host_session.to_host)); -- We're out of options return false; end @@ -216,7 +216,7 @@ function attempt_connection(host_session, err) end function try_connect(host_session, connect_host, connect_port) - log("debug", "Beginning new connection attempt to %s (%s:%d)", host_session.to_host, connect_host, connect_port); + host_session.log("info", "Beginning new connection attempt to %s (%s:%d)", host_session.to_host, connect_host, connect_port); -- Ok, we're going to try to connect local from_host, to_host = host_session.from_host, host_session.to_host; @@ -338,7 +338,7 @@ function make_authenticated(session, host) else return false; end - session.log("info", "connection is now authenticated"); + session.log("debug", "connection %s->%s is now authenticated", session.from_host or "(unknown)", session.to_host or "(unknown)"); mark_connected(session); @@ -350,7 +350,7 @@ function mark_connected(session) local from, to = session.from_host, session.to_host; - session.log("debug", session.direction.." s2s connection "..from.."->"..to.." is now complete"); + session.log("info", session.direction.." s2s connection "..from.."->"..to.." complete"); local send_to_host = send_to_host; function session.send(data) send_to_host(to, from, data); end -- cgit v1.2.3 From 18b7e2867c44c13cb21e849387fcca6dda62e2eb Mon Sep 17 00:00:00 2001 From: Matthew Wild Date: Thu, 30 Apr 2009 02:45:10 +0100 Subject: sessionmanager: Miscellaneous logging improvements, changing levels, improving messages and using session loggers where possible --- core/sessionmanager.lua | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/core/sessionmanager.lua b/core/sessionmanager.lua index 52e418cc..68493d87 100644 --- a/core/sessionmanager.lua +++ b/core/sessionmanager.lua @@ -45,7 +45,7 @@ function new_session(conn) getmetatable(session.trace).__gc = function () open_sessions = open_sessions - 1; end; end open_sessions = open_sessions + 1; - log("info", "open sessions now: ".. open_sessions); + log("debug", "open sessions now: ".. open_sessions); local w = conn.write; session.send = function (t) w(tostring(t)); end session.ip = conn.ip(); @@ -53,7 +53,7 @@ function new_session(conn) end function destroy_session(session, err) - (session.log or log)("info", "Destroying session"); + (session.log or log)("info", "Destroying session for %s (%s@%s)", session.full_jid or "(unknown)", session.username or "(unknown)", session.host or "(unknown)"); -- Send unavailable presence if session.presence then @@ -94,6 +94,7 @@ function make_authenticated(session, username) if session.type == "c2s_unauthed" then session.type = "c2s"; end + session.log("info", "Authenticated as %s@%s", username or "(unknown)", session.host or "(unknown)"); return true; end @@ -176,7 +177,7 @@ function streamopened(session, attr) send(features); - (session.log or log)("info", "Sent reply to client"); + (session.log or log)("debug", "Sent reply to client"); session.notopen = nil; end -- cgit v1.2.3 From 26e6087e32a55fc04c9678caddb2313ba0f1700c Mon Sep 17 00:00:00 2001 From: Matthew Wild Date: Thu, 30 Apr 2009 02:45:33 +0100 Subject: mod_dialback: Miscellaneous logging improvements, changing levels, improving messages and using session loggers where possible --- plugins/mod_dialback.lua | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/plugins/mod_dialback.lua b/plugins/mod_dialback.lua index 855df9eb..b1bc3ae3 100644 --- a/plugins/mod_dialback.lua +++ b/plugins/mod_dialback.lua @@ -24,7 +24,7 @@ local dialback_requests = setmetatable({}, { __mode = 'v' }); module:add_handler({"s2sin_unauthed", "s2sin"}, "verify", xmlns_dialback, function (origin, stanza) -- We are being asked to verify the key, to ensure it was generated by us - log("debug", "verifying dialback key..."); + origin.log("debug", "verifying that dialback key is ours..."); local attr = stanza.attr; -- FIXME: Grr, ejabberd breaks this one too?? it is black and white in XEP-220 example 34 --if attr.from ~= origin.to_host then error("invalid-from"); end @@ -33,9 +33,9 @@ module:add_handler({"s2sin_unauthed", "s2sin"}, "verify", xmlns_dialback, type = "valid" else type = "invalid" - log("warn", "Asked to verify a dialback key that was incorrect. An imposter is claiming to be %s?", attr.to); + origin.log("warn", "Asked to verify a dialback key that was incorrect. An imposter is claiming to be %s?", attr.to); end - log("debug", "verified dialback key... it is %s", type); + origin.log("debug", "verified dialback key... it is %s", type); origin.sends2s(st.stanza("db:verify", { from = attr.to, to = attr.from, id = attr.id, type = type }):text(stanza[1])); end); @@ -48,7 +48,7 @@ module:add_handler({ "s2sin_unauthed", "s2sin" }, "result", xmlns_dialback, if not hosts[attr.to] then -- Not a host that we serve - log("info", "%s tried to connect to %s, which we don't serve", attr.from, attr.to); + origin.log("info", "%s tried to connect to %s, which we don't serve", attr.from, attr.to); origin:close("host-unknown"); return; end @@ -64,7 +64,7 @@ module:add_handler({ "s2sin_unauthed", "s2sin" }, "result", xmlns_dialback, origin.to_host = attr.to; end - log("debug", "asking %s if key %s belongs to them", attr.from, stanza[1]); + origin.log("debug", "asking %s if key %s belongs to them", attr.from, stanza[1]); send_s2s(attr.to, attr.from, st.stanza("db:verify", { from = attr.to, to = attr.from, id = origin.streamid }):text(stanza[1])); end); -- cgit v1.2.3 From a1a1fd2213c069994ddbb9b03e8ae39281deb6d5 Mon Sep 17 00:00:00 2001 From: Matthew Wild Date: Thu, 30 Apr 2009 03:05:26 +0100 Subject: loggingmanager: Support prepending timestamps in file/console/stdout log sinks --- core/loggingmanager.lua | 31 +++++++++++++++++++++++++++++-- 1 file changed, 29 insertions(+), 2 deletions(-) diff --git a/core/loggingmanager.lua b/core/loggingmanager.lua index 5dff6a34..13b091cc 100644 --- a/core/loggingmanager.lua +++ b/core/loggingmanager.lua @@ -6,7 +6,7 @@ local tostring, setmetatable, rawset, pairs, ipairs, type = tostring, setmetatable, rawset, pairs, ipairs, type; local io_open, io_write = io.open, io.write; local math_max, rep = math.max, string.rep; -local os_getenv = os.getenv; +local os_date, os_getenv = os.date, os.getenv; local getstyle, getstring = require "util.termcolours".getstyle, require "util.termcolours".getstring; local config = require "core.configmanager"; @@ -20,7 +20,7 @@ module "loggingmanager" -- The log config used if none specified in the config file local default_logging = { { to = "console" } }; local default_file_logging = { { to = "file", levels = { min = "info" } } }; - +local default_timestamp = "%b %d %T"; -- The actual config loggingmanager is using local logging_config = config.get("*", "core", "log") or default_logging; @@ -130,9 +130,18 @@ end local sourcewidth = 20; function log_sink_types.stdout() + local timestamps = config.timestamps; + + if timestamps == true then + timestamps = default_timestamp; -- Default format + end + return function (name, level, message, ...) sourcewidth = math_max(#name+2, sourcewidth); local namelen = #name; + if timestamps then + io_write(os_date(timestamps), " "); + end if ... then io_write(name, rep(" ", sourcewidth-namelen), level, "\t", format(message, ...), "\n"); else @@ -156,9 +165,18 @@ do return log_sink_types.stdout(config); end + local timestamps = config.timestamps; + + if timestamps == true then + timestamps = default_timestamp; -- Default format + end + return function (name, level, message, ...) sourcewidth = math_max(#name+2, sourcewidth); local namelen = #name; + if timestamps then + io_write(os_date(timestamps), " "); + end if ... then io_write(name, rep(" ", sourcewidth-namelen), getstring(logstyles[level], level), "\t", format(message, ...), "\n"); else @@ -175,8 +193,17 @@ function log_sink_types.file(config) return function () end end + local timestamps = config.timestamps; + + if timestamps == true then + timestamps = default_timestamp; -- Default format + end + local write, format, flush = logfile.write, format, logfile.flush; return function (name, level, message, ...) + if timestamps then + write(logfile, os_date(timestamps), " "); + end if ... then write(logfile, name, "\t", level, "\t", format(message, ...), "\n"); else -- cgit v1.2.3