diff --git a/bot.py b/bot.py index 3e60b8c..1e24087 100644 --- a/bot.py +++ b/bot.py @@ -32,7 +32,7 @@ from server.IRC import IRCServer from server.DCC import DCC import response -logger = logging.getLogger(__name__) +logger = logging.getLogger("nemubot.bot") ID_letters = "abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ" @@ -41,7 +41,7 @@ class Bot: # Bot general informations self.version = 3.4 self.version_txt = "3.4-dev" - logger.info("Initiate nemubot v%s" % self.version_txt) + logger.info("Initiate nemubot v%s", self.version_txt) # Save various informations self.ip = ip @@ -91,7 +91,7 @@ class Bot: msg.sender, "USERINFO %s" % self.realname) self.ctcp_capabilities["VERSION"] = lambda srv, msg: _ctcp_response( msg.sender, "VERSION nemubot v%s" % self.version_txt) - logger.debug("CTCP capabilities setup: %s" % ", ".join(self.ctcp_capabilities)) + logger.debug("CTCP capabilities setup: %s", ", ".join(self.ctcp_capabilities)) def _ctcp_clientinfo(self, srv, msg): """Response to CLIENTINFO CTCP message""" @@ -106,7 +106,7 @@ class Bot: srv.dcc_clients[conn.sender] = conn conn.send_dcc("Hello %s!" % conn.nick) else: - logger.error("DCC: unable to connect to %s:%s" % (ip, msg.cmds[4])) + logger.error("DCC: unable to connect to %s:%s", ip, msg.cmds[4]) def add_event(self, evt, eid=None, module_src=None): @@ -137,12 +137,12 @@ class Bot: if module_src is not None: module_src.REGISTERED_EVENTS.append(evt.id) - logger.info("New event registered: %s -> %s" % (evt.id, evt)) + logger.info("New event registered: %s -> %s", evt.id, evt) return evt.id def del_event(self, id, module_src=None): """Find and remove an event from list""" - logger.info("Removing event: %s from %s" % (id, module_src)) + logger.info("Removing event: %s from %s", id, module_src) if len(self.events) > 0 and id == self.events[0].id: self.events.remove(self.events[0]) self.update_timer() @@ -165,7 +165,7 @@ class Bot: if self.event_timer is not None: self.event_timer.cancel() if len(self.events) > 0: - logger.debug("Update timer: next event in %d seconds" % + logger.debug("Update timer: next event in %d seconds", self.events[0].time_left.seconds) if datetime.now() + timedelta(seconds=5) >= self.events[0].current: while datetime.now() < self.events[0].current: @@ -247,7 +247,7 @@ class Bot: self.del_event(e) # Remove from the dict del self.modules[name] - logger.info("Module `%s' successfully unloaded." % name) + logger.info("Module `%s' successfully unloaded.", name) return True return False @@ -443,7 +443,7 @@ class Bot: return srv.moremessages[msg.channel] elif msg.cmds[0] == "dcc": - logger.debug("dcctest for " + msg.sender) + logger.debug("dcctest for %s", msg.sender) srv.send_dcc("Hello %s!" % msg.nick, msg.sender) elif msg.cmds[0] == "pvdcctest": logger.debug("dcctest") diff --git a/channel.py b/channel.py index 974713f..c6266e8 100644 --- a/channel.py +++ b/channel.py @@ -16,12 +16,15 @@ # You should have received a copy of the GNU Affero General Public License # along with this program. If not, see . +import logging + class Channel: def __init__(self, name, password=None): self.name = name self.password = password self.people = dict() self.topic = "" + self.logger = logging.getLogger("nemubot.channel." + name) def treat(self, cmd, msg): if cmd == "353": @@ -41,7 +44,7 @@ class Channel: def join(self, nick, level = 0): """Someone join the channel""" - logger.debug("%s join %s" % (nick, self.name)) + self.logger.debug("%s join", nick) self.people[nick] = level def chtopic(self, newtopic): @@ -52,7 +55,7 @@ class Channel: def nick(self, oldnick, newnick): """Someone change his nick""" if oldnick in self.people: - logger.debug("%s switch nick to %s on %s" % (oldnick, newnick, self.name)) + self.logger.debug("%s switch nick to %s on", oldnick, newnick) lvl = self.people[oldnick] del self.people[oldnick] self.people[newnick] = lvl @@ -60,7 +63,7 @@ class Channel: def part(self, nick): """Someone leave the channel""" if nick in self.people: - logger.debug("%s has left %s" % (nick, self.name)) + self.logger.debug("%s has left", nick) del self.people[nick] def mode(self, msg): diff --git a/consumer.py b/consumer.py index ea63e1c..0efe37b 100644 --- a/consumer.py +++ b/consumer.py @@ -29,7 +29,7 @@ from message import Message import response import server -logger = logging.getLogger(__name__) +logger = logging.getLogger("nemubot.consumer") class MessageConsumer: """Store a message before treating""" @@ -67,7 +67,7 @@ class MessageConsumer: if (res.server is not None and not isinstance(res.server, server.Server)): logger.error("The server defined in this response doesn't " - "exist: %s" % res.server) + "exist: %s", res.server) res.server = None if res.server is None: res.server = self.srv @@ -80,7 +80,7 @@ class MessageConsumer: context.hooks.add_hook(res.type, res.hook, res.src) elif res is not None: - logger.error("Unrecognized response type: %s" % res) + logger.error("Unrecognized response type: %s", res) def run(self, context): """Create, parse and treat the message""" @@ -92,12 +92,7 @@ class MessageConsumer: msg.private = msg.private or msg.channel == self.srv.nick res = self.treat_in(context, msg) except: - logger.error("Error occurred during the processing of the message:" - " %s" % self.raw) - exc_type, exc_value, exc_traceback = sys.exc_info() - logger.debug(traceback.format_exception(exc_type, - exc_value, - exc_traceback)) + logger.exception("Error occurred during the processing of the message: %s", self.raw) return # Send message @@ -119,11 +114,7 @@ class EventConsumer: try: self.evt.launch_check() except: - logger.error("Error during event end") - exc_type, exc_value, exc_traceback = sys.exc_info() - logger.debug(traceback.format_exception(exc_type, - exc_value, - exc_traceback)) + logger.exception("Error during event end") if self.evt.next is not None: context.add_event(self.evt, self.evt.id) diff --git a/hooks.py b/hooks.py index 48c47ac..25f1019 100644 --- a/hooks.py +++ b/hooks.py @@ -22,7 +22,7 @@ import re from response import Response from exception import IRCException -logger = logging.getLogger(__name__) +logger = logging.getLogger("nemubot.hooks") class MessagesHook: def __init__(self, context, bot): @@ -54,19 +54,19 @@ class MessagesHook: def add_hook(self, store, hook, module_src=None): """Insert in the right place a hook into the given store""" - logger.info("Adding hook '%s' to store '%s' from module '%s'" % (hook, store, module_src)) + logger.info("Adding hook '%s' to store '%s' from module '%s'", hook, store, module_src) if module_src is None: logger.warn("No source module was passed to add_hook function, " "please fix it in order to be compatible with unload " "feature") if store in self.context.hooks_cache: - logger.debug("Cleaning hooks cache for " + store) + logger.debug("Cleaning hooks cache for %s", store) del self.context.hooks_cache[store] if not hasattr(self, store): # TODO: raise custom exception, this is a user problem, not internal one! - logger.error("Unrecognized hook store: " + store) + logger.error("Unrecognized hook store: %s", store) return attr = getattr(self, store) @@ -81,7 +81,7 @@ class MessagesHook: elif isinstance(attr, list): attr.append(hook) else: - logger.critical("Unrecognized hook store type: " + type(attr)) + logger.critical("Unrecognized hook store type: %s", type(attr)) return if module_src is not None and hasattr(module_src, "REGISTERED_HOOKS"): module_src.REGISTERED_HOOKS.append((store, hook)) diff --git a/importer.py b/importer.py index 4b435dc..7795547 100644 --- a/importer.py +++ b/importer.py @@ -29,7 +29,7 @@ import hooks import response import xmlparser -logger = logging.getLogger(__name__) +logger = logging.getLogger("nemubot.importer") class ModuleFinder(Finder): def __init__(self, context, prompt): @@ -146,7 +146,7 @@ class ModuleLoader(SourceLoader): # Set module common functions and datas module.__LOADED__ = True - module.logger = logging.getLogger("module/" + fullname) + module.logger = logging.getLogger("nemubot.module." + fullname) def prnt(*args): print("[%s]" % module.name, *args) @@ -165,7 +165,7 @@ class ModuleLoader(SourceLoader): if server in self.context.servers: return self.context.servers[server].send_response(res, None) else: - module.logger.error("Try to send a message to the unknown server: %s" % server) + module.logger.error("Try to send a message to the unknown server: %s", server) return False def add_hook(store, hook): @@ -218,8 +218,8 @@ class ModuleLoader(SourceLoader): break if depend["name"] not in module.MODS: logger.error("In module `%s', module `%s' require by this " - "module but is not loaded." % (module.name, - depend["name"])) + "module but is not loaded.", module.name, + depend["name"]) return # Add the module to the global modules list @@ -232,9 +232,9 @@ class ModuleLoader(SourceLoader): # Register hooks register_hooks(module, self.context, self.prompt) - logger.info("Module '%s' successfully loaded." % module.name) + logger.info("Module '%s' successfully loaded.", module.name) else: - logger.error("An error occurs while importing `%s'." % module.name) + logger.error("An error occurs while importing `%s'.", module.name) raise ImportError("An error occurs while importing `%s'." % module.name) return module @@ -245,7 +245,7 @@ def add_cap_hook(prompt, module, cmd): prompt.add_cap_hook(cmd["name"], getattr(module, cmd["call"])) else: logger.warn("In module `%s', no function `%s' defined for `%s' " - "command hook." % (module.name, cmd["call"], cmd["name"])) + "command hook.", module.name, cmd["call"], cmd["name"]) def register_hooks(module, context, prompt): """Register all available hooks""" diff --git a/nemubot.py b/nemubot.py index 66fc396..997d6c2 100755 --- a/nemubot.py +++ b/nemubot.py @@ -30,9 +30,19 @@ import importer if __name__ == "__main__": # Setup loggin interface - logging.basicConfig(filename='nemubot.log', level=logging.DEBUG) - logging.Formatter('%(asctime)s %(name)s %(levelname)s %(message)s') - logger = logging.getLogger(__name__) + logger = logging.getLogger("nemubot") + + formatter = logging.Formatter('%(asctime)s %(name)s %(levelname)s %(message)s') + + ch = logging.StreamHandler() + ch.setFormatter(formatter) + ch.setLevel(logging.INFO) + logger.addHandler(ch) + + fh = logging.FileHandler('./nemubot.log') + fh.setFormatter(formatter) + fh.setLevel(logging.DEBUG) + logger.addHandler(fh) # Create bot context context = bot.Bot(0, "FIXME") @@ -68,14 +78,11 @@ if __name__ == "__main__": prmpt = prompt.hotswap(prmpt) # Reload all other modules bot.reload() - print ("\033[1;32mContext reloaded\033[0m, now in Nemubot %s" % - context.version_txt) + print("\033[1;32mContext reloaded\033[0m, now in Nemubot %s" % + context.version_txt) except: - print ("\033[1;31mUnable to reload the prompt due to errors.\033[0" - "m Fix them before trying to reload the prompt.") - exc_type, exc_value, exc_traceback = sys.exc_info() - sys.stderr.write (traceback.format_exception_only(exc_type, - exc_value)[0]) + logger.exception("\033[1;31mUnable to reload the prompt due to errors.\033[0" + "m Fix them before trying to reload the prompt.") print ("\nWaiting for other threads shuts down...") diff --git a/prompt/builtins.py b/prompt/builtins.py index 4e0b0d7..ac6ab64 100644 --- a/prompt/builtins.py +++ b/prompt/builtins.py @@ -20,7 +20,7 @@ import logging import os import xmlparser -logger = logging.getLogger(__name__) +logger = logging.getLogger("nemubot.prompt.builtins") def end(toks, context, prompt): """Quit the prompt for reload or exit""" @@ -69,11 +69,11 @@ def load_file(filename, context): if context.addServer(server, config["nick"], config["owner"], config["realname"], server.hasAttribute("ssl")): - logger.info("Server `%s:%s' successfully added." - % (server["server"], server["port"])) + logger.info("Server `%s:%s' successfully added.", + server["server"], server["port"]) else: - logger.warn("Server `%s:%s' already added, skiped." - % (server["server"], server["port"])) + logger.warn("Server `%s:%s' already added, skiped.", + server["server"], server["port"]) # Load files asked by the configuration file for load in config.getNodes("load"): diff --git a/response.py b/response.py index 0716180..cd44405 100644 --- a/response.py +++ b/response.py @@ -20,7 +20,7 @@ import logging import traceback import sys -logger = logging.getLogger(__name__) +logger = logging.getLogger("nemubot.response") class Response: def __init__(self, sender, message=None, channel=None, nick=None, server=None, @@ -56,10 +56,7 @@ class Response: def set_sender(self, sender): if sender is None or sender.find("!") < 0: if sender is not None: - exc_type, exc_value, exc_traceback = sys.exc_info() - logger.warn(traceback.format_exception(exc_type, - "Bad sender provided in Response, it will be ignored.", - exc_traceback)) + logger.warn("Bad sender provided in Response, it will be ignored.", stack_info=True) self.sender = None else: self.sender = sender diff --git a/server/DCC.py b/server/DCC.py index 2a0b741..c5f8798 100644 --- a/server/DCC.py +++ b/server/DCC.py @@ -81,7 +81,7 @@ class DCC(server.Server): self.s = socket.socket() try: self.s.connect((host, port)) - self.logger.info("Accepted user from %s:%d for %s" % (host, port, self.sender)) + self.logger.info("Accepted user from %s:%d for %s", host, port, self.sender) self.connected = True self.stop = False except: @@ -106,7 +106,7 @@ class DCC(server.Server): self.setError("Une erreur s'est produite durant la tentative" " d'ouverture d'une session DCC.") return False - self.logger.info("Listening on %d for %s" % (self.port, self.sender)) + self.logger.info("Listening on %d for %s", self.port, self.sender) #Send CTCP request for DCC self.srv.send_ctcp(self.sender, @@ -117,7 +117,7 @@ class DCC(server.Server): s.listen(1) #Waiting for the client (self.s, addr) = s.accept() - self.logger.info("Connected by %d" % addr) + self.logger.info("Connected by %d", addr) self.connected = True return True @@ -151,7 +151,7 @@ class DCC(server.Server): except RuntimeError: pass else: - self.logger.error("File not found `%s'" % filename) + self.logger.error("File not found `%s'", filename) def run(self): self.stopping.clear() @@ -204,7 +204,7 @@ class DCC(server.Server): if self.realname in self.srv.dcc_clients: del self.srv.dcc_clients[self.realname] - self.logger.info("Closing connection with " + self.nick) + self.logger.info("Closing connection with %s", self.nick) self.stopping.set() if self.closing_event is not None: self.closing_event() diff --git a/server/IRC.py b/server/IRC.py index 2029340..f42ecc6 100644 --- a/server/IRC.py +++ b/server/IRC.py @@ -173,8 +173,8 @@ class IRCServer(server.Server): self.s.connect((self.host, self.port)) #Connect to server except socket.error as e: self.s = None - self.logger.critical("Unable to connect to %s:%d: %s" - % (self.host, self.port, os.strerror(e.errno))) + self.logger.critical("Unable to connect to %s:%d: %s", + self.host, self.port, os.strerror(e.errno)) return self.stopping.clear() @@ -185,10 +185,10 @@ class IRCServer(server.Server): self.realname)).encode()) raw = self.s.recv(1024) if not raw: - self.logger.critical("Unable to connect to %s:%d" % (self.host, self.port)) + self.logger.critical("Unable to connect to %s:%d", self.host, self.port) return self.connected = True - self.logger.info("Connection to %s:%d completed" % (self.host, self.port)) + self.logger.info("Connection to %s:%d completed", self.host, self.port) if len(self.channels) > 0: for chn in self.channels.keys(): @@ -214,7 +214,7 @@ class IRCServer(server.Server): self.connected = False if self.closing_event is not None: self.closing_event() - self.logger.info("Server `%s' successfully stopped." % self.id) + self.logger.info("Server `%s' successfully stopped.", self.id) self.stopping.set() # Rearm Thread threading.Thread.__init__(self) @@ -255,17 +255,14 @@ class IRCServer(server.Server): """Send a message without checks or format""" #TODO: add something for post message treatment here if channel == self.nick: - self.logger.warn("Nemubot talks to himself: %s" % msg) - self.logger.debug(traceback.print_stack()) + self.logger.warn("Nemubot talks to himself: %s", msg, stack_info=True) if line is not None and channel is not None: if self.s is None: - self.logger.warn("Attempt to send message on a non connected server: %s: %s" % (self.id, line)) - self.logger.debug(traceback.format_stack()) + self.logger.warn("Attempt to send message on a non connected server: %s: %s", self.id, line, stack_info=True) elif len(line) < 442: self.s.send(("%s %s :%s%s" % (cmd, channel, line, endl)).encode ()) else: - self.logger.warn("Message truncated due to size (%d ; max : 442) : %s" % (len(line), line)) - self.logger.debug(traceback.format_stack()) + self.logger.warn("Message truncated due to size (%d ; max : 442) : %s", len(line), line, stack_info=True) self.s.send (("%s %s :%s%s" % (cmd, channel, line[0:442]+"<…>", endl)).encode ()) def send_msg_usr(self, user, msg): diff --git a/server/__init__.py b/server/__init__.py index 590a194..a1ac635 100644 --- a/server/__init__.py +++ b/server/__init__.py @@ -30,7 +30,7 @@ class Server(threading.Thread): self.moremessages = dict() - self.logger = logging.getLogger(__name__ + "/" + self.id) + self.logger = logging.getLogger("nemubot.server." + self.id) threading.Thread.__init__(self) diff --git a/xmlparser/node.py b/xmlparser/node.py index 254dc31..1203cb6 100644 --- a/xmlparser/node.py +++ b/xmlparser/node.py @@ -3,10 +3,13 @@ import xml.sax from datetime import datetime from datetime import date +import logging import sys import time import traceback +logger = logging.getLogger("nemubot.xmlparser.node") + class ModuleState: """Tiny tree representation of an XML file""" @@ -192,10 +195,7 @@ class ModuleState: gen.endElement(self.name) except: - print ("\033[1;31mERROR:\033[0m occurred when saving the " - "following XML node: %s with %s" % (self.name, attrs)) - exc_type, exc_value, exc_traceback = sys.exc_info() - traceback.print_exception(exc_type, exc_value, exc_traceback) + logger.exception("Error occured when saving the following XML node: %s with %s", self.name, attrs) def save(self, filename): """Save the current node as root node in a XML file"""