Use a logger

This commit is contained in:
nemunaire 2014-08-14 12:49:38 +02:00
parent 3839455f42
commit d0b1336d07
14 changed files with 118 additions and 77 deletions

1
.gitignore vendored
View File

@ -1,5 +1,6 @@
*#
*~
*.log
TAGS
*.py[cod]
__pycache__

39
bot.py
View File

@ -18,6 +18,7 @@
from datetime import datetime
from datetime import timedelta
import logging
from queue import Queue
import threading
import time
@ -31,6 +32,8 @@ from server.IRC import IRCServer
from server.DCC import DCC
import response
logger = logging.getLogger(__name__)
ID_letters = "abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ"
class Bot:
@ -38,6 +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)
# Save various informations
self.ip = ip
@ -87,6 +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))
def _ctcp_clientinfo(self, srv, msg):
"""Response to CLIENTINFO CTCP message"""
@ -101,7 +106,7 @@ class Bot:
srv.dcc_clients[conn.sender] = conn
conn.send_dcc("Hello %s!" % conn.nick)
else:
print ("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):
@ -132,10 +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))
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))
if len(self.events) > 0 and id == self.events[0].id:
self.events.remove(self.events[0])
self.update_timer()
@ -158,8 +165,8 @@ class Bot:
if self.event_timer is not None:
self.event_timer.cancel()
if len(self.events) > 0:
#print ("Update timer, next in", self.events[0].time_left.seconds,
# "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:
time.sleep(0.6)
@ -168,13 +175,13 @@ class Bot:
self.event_timer = threading.Timer(
self.events[0].time_left.seconds + 1, self.end_timer)
self.event_timer.start()
#else:
# print ("Update timer: no timer left")
else:
logger.debug("Update timer: no timer left")
def end_timer(self):
"""Function called at the end of the timer"""
#print ("end timer")
while len(self.events)>0 and datetime.now() >= self.events[0].current:
while len(self.events) > 0 and datetime.now() >= self.events[0].current:
#print ("end timer: while")
evt = self.events.pop(0)
self.cnsr_queue.put_nowait(consumer.EventConsumer(evt))
@ -225,7 +232,7 @@ class Bot:
return False
def unload_module(self, name, verb=False):
def unload_module(self, name):
"""Unload a module"""
if name in self.modules:
self.modules[name].print_debug("Unloading module %s" % name)
@ -240,7 +247,7 @@ class Bot:
self.del_event(e)
# Remove from the dict
del self.modules[name]
print(" Module `%s' successfully unloaded." % name)
logger.info("Module `%s' successfully unloaded." % name)
return True
return False
@ -274,18 +281,18 @@ class Bot:
if self.network[bot].srv == srv:
self.network[bot].send_cmd(cmd, data)
def quit(self, verb=False):
def quit(self):
"""Save and unload modules and disconnect servers"""
if self.event_timer is not None:
if verb: print ("Stop the event timer...")
logger.info("Stop the event timer...")
self.event_timer.cancel()
if verb: print ("Save and unload all modules...")
logger.info("Save and unload all modules...")
k = list(self.modules.keys())
for mod in k:
self.unload_module(mod, verb)
self.unload_module(mod)
if verb: print ("Close all servers connection...")
logger.info("Close all servers connection...")
k = list(self.servers.keys())
for srv in k:
self.servers[srv].disconnect()
@ -436,13 +443,13 @@ class Bot:
return srv.moremessages[msg.channel]
elif msg.cmds[0] == "dcc":
print("dcctest for", msg.sender)
logger.debug("dcctest for " + msg.sender)
srv.send_dcc("Hello %s!" % msg.nick, msg.sender)
elif msg.cmds[0] == "pvdcctest":
print("dcctest")
logger.debug("dcctest")
return Response(msg.sender, message="Test DCC")
elif msg.cmds[0] == "dccsendtest":
print("dccsendtest")
logger.debug("dccsendtest")
conn = DCC(srv, msg.sender)
conn.send_file("bot_sample.xml")

View File

@ -41,7 +41,7 @@ class Channel:
def join(self, nick, level = 0):
"""Someone join the channel"""
#print ("%s arrive sur %s" % (nick, self.name))
logger.debug("%s join %s" % (nick, self.name))
self.people[nick] = level
def chtopic(self, newtopic):
@ -52,7 +52,7 @@ class Channel:
def nick(self, oldnick, newnick):
"""Someone change his nick"""
if oldnick in self.people:
#print ("%s change de nom pour %s sur %s" % (oldnick, newnick, self.name))
logger.debug("%s switch nick to %s on %s" % (oldnick, newnick, self.name))
lvl = self.people[oldnick]
del self.people[oldnick]
self.people[newnick] = lvl
@ -60,7 +60,7 @@ class Channel:
def part(self, nick):
"""Someone leave the channel"""
if nick in self.people:
#print ("%s vient de quitter %s" % (nick, self.name))
logger.debug("%s has left %s" % (nick, self.name))
del self.people[nick]
def mode(self, msg):

View File

@ -16,6 +16,7 @@
# You should have received a copy of the GNU Affero General Public License
# along with this program. If not, see <http://www.gnu.org/licenses/>.
import logging
import queue
import re
import threading
@ -28,6 +29,8 @@ from message import Message
import response
import server
logger = logging.getLogger(__name__)
class MessageConsumer:
"""Store a message before treating"""
def __init__(self, srv, raw, time, prvt, data):
@ -63,8 +66,8 @@ class MessageConsumer:
res.server = context.servers[res.server]
if (res.server is not None and
not isinstance(res.server, server.Server)):
print ("\033[1;35mWarning:\033[0m the server defined in this "
"response doesn't exist: %s" % (res.server))
logger.error("The server defined in this response doesn't "
"exist: %s" % res.server)
res.server = None
if res.server is None:
res.server = self.srv
@ -77,8 +80,7 @@ class MessageConsumer:
context.hooks.add_hook(res.type, res.hook, res.src)
elif res is not None:
print ("\033[1;35mWarning:\033[0m unrecognized response type "
": %s" % res)
logger.error("Unrecognized response type: %s" % res)
def run(self, context):
"""Create, parse and treat the message"""
@ -90,11 +92,12 @@ class MessageConsumer:
msg.private = msg.private or msg.channel == self.srv.nick
res = self.treat_in(context, msg)
except:
print ("\033[1;31mERROR:\033[0m occurred during the "
"processing of the message: %s" % self.raw)
logger.error("Error occurred during the processing of the message:"
" %s" % self.raw)
exc_type, exc_value, exc_traceback = sys.exc_info()
traceback.print_exception(exc_type, exc_value,
exc_traceback)
logger.debug(traceback.format_exception(exc_type,
exc_value,
exc_traceback))
return
# Send message
@ -116,10 +119,11 @@ class EventConsumer:
try:
self.evt.launch_check()
except:
print ("\033[1;31mError:\033[0m during event end")
logger.error("Error during event end")
exc_type, exc_value, exc_traceback = sys.exc_info()
traceback.print_exception(exc_type, exc_value,
exc_traceback)
logger.debug(traceback.format_exception(exc_type,
exc_value,
exc_traceback))
if self.evt.next is not None:
context.add_event(self.evt, self.evt.id)

View File

@ -16,11 +16,14 @@
# You should have received a copy of the GNU Affero General Public License
# along with this program. If not, see <http://www.gnu.org/licenses/>.
import logging
import re
from response import Response
from exception import IRCException
logger = logging.getLogger(__name__)
class MessagesHook:
def __init__(self, context, bot):
self.context = context
@ -51,16 +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))
if module_src is None:
print ("\033[1;35mWarning:\033[0m No source module was passed to "
"add_hook function, please fix it in order to be "
"compatible with unload feature")
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)
del self.context.hooks_cache[store]
if not hasattr(self, store):
print ("\033[1;35mWarning:\033[0m unrecognized hook store")
# TODO: raise custom exception, this is a user problem, not internal one!
logger.error("Unrecognized hook store: " + store)
return
attr = getattr(self, store)
@ -75,7 +81,7 @@ class MessagesHook:
elif isinstance(attr, list):
attr.append(hook)
else:
print ("\033[1;32mWarning:\033[0m unrecognized hook store type")
logger.critical("Unrecognized hook store type: " + type(attr))
return
if module_src is not None and hasattr(module_src, "REGISTERED_HOOKS"):
module_src.REGISTERED_HOOKS.append((store, hook))
@ -147,7 +153,7 @@ class MessagesHook:
del self.context.hooks_cache[store]
if not hasattr(self, store):
print ("Warning: unrecognized hook store type")
logger.warn("unrecognized hook store type")
return
attr = getattr(self, store)

View File

@ -19,6 +19,7 @@
from importlib.abc import Finder
from importlib.abc import SourceLoader
import imp
import logging
import os
import sys
@ -28,6 +29,8 @@ import hooks
import response
import xmlparser
logger = logging.getLogger(__name__)
class ModuleFinder(Finder):
def __init__(self, context, prompt):
self.context = context
@ -143,22 +146,26 @@ class ModuleLoader(SourceLoader):
# Set module common functions and datas
module.__LOADED__ = True
module.logger = logging.getLogger("module/" + fullname)
def prnt(*args):
print("[%s]" % module.name, *args)
module.logger.info(*args)
def prnt_dbg(*args):
if module.DEBUG:
print("{%s}" % module.name, *args)
module.logger.debug(*args)
def mod_save():
module.print_debug("Saving DATAS...")
module.DATAS.save(self.context.datas_path + "/" + module.name + ".xml")
fpath = self.context.datas_path + "/" + module.name + ".xml"
module.print_debug("Saving DATAS to " + fpath)
module.DATAS.save(fpath)
def send_response(server, res):
if server in self.context.servers:
return self.context.servers[server].send_response(res, None)
else:
print("\033[1;35mWarning:\033[0m 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):
@ -210,9 +217,9 @@ class ModuleLoader(SourceLoader):
mod.MODS[md.name] = md
break
if depend["name"] not in module.MODS:
print ("\033[1;31mERROR:\033[0m in module `%s', module "
"`%s' require by this module but is not loaded."
% (module.name, depend["name"]))
logger.error("In module `%s', module `%s' require by this "
"module but is not loaded." % (module.name,
depend["name"]))
return
# Add the module to the global modules list
@ -225,8 +232,9 @@ class ModuleLoader(SourceLoader):
# Register hooks
register_hooks(module, self.context, self.prompt)
print (" 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)
raise ImportError("An error occurs while importing `%s'."
% module.name)
return module
@ -236,7 +244,7 @@ def add_cap_hook(prompt, module, cmd):
if hasattr(module, cmd["call"]):
prompt.add_cap_hook(cmd["name"], getattr(module, cmd["call"]))
else:
print ("Warning: In module `%s', no function `%s' defined for `%s' "
logger.warn("In module `%s', no function `%s' defined for `%s' "
"command hook." % (module.name, cmd["call"], cmd["name"]))
def register_hooks(module, context, prompt):

View File

@ -76,10 +76,8 @@ class Message:
self.channel = words[3]
self.content = self.pickWords(words[4:])
else:
#print (line)
self.content = self.pickWords(words[3:])
else:
print (line)
if self.cmd == 'PRIVMSG':
self.channel = words[2].decode()
self.content = b' '.join(words[3:])
@ -247,7 +245,6 @@ class Message:
minute = result.group(9)
second = result.group(11)
print ("Chaîne reconnue : %s/%s/%s %s:%s:%s"%(day, month, year, hour, minute, second))
if year == None:
year = date.today().year
if hour == None:

View File

@ -17,9 +17,10 @@
# You should have received a copy of the GNU Affero General Public License
# along with this program. If not, see <http://www.gnu.org/licenses/>.
import sys
import os
import imp
import logging
import os
import sys
import traceback
import bot
@ -28,6 +29,11 @@ from prompt.builtins import load_file
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__)
# Create bot context
context = bot.Bot(0, "FIXME")

View File

@ -67,7 +67,7 @@ class Prompt:
(f,d) = self.HOOKS_CAPS[toks[0]]
return f(d, toks, context, self)
else:
print ("Unknown command: `%s'" % toks[0])
print("Unknown command: `%s'" % toks[0])
return ""
def getPS1(self):
@ -88,7 +88,7 @@ class Prompt:
line = sys.stdin.readline()
if len(line) <= 0:
line = "quit"
print ("quit")
print("quit")
cmds = self.lex_cmd(line.strip())
for toks in cmds:
try:
@ -97,7 +97,7 @@ class Prompt:
exc_type, exc_value, exc_traceback = sys.exc_info()
traceback.print_exception(exc_type, exc_value, exc_traceback)
except KeyboardInterrupt:
print ("")
print("")
return ret != "quit"

View File

@ -16,9 +16,12 @@
# You should have received a copy of the GNU Affero General Public License
# along with this program. If not, see <http://www.gnu.org/licenses/>.
import logging
import os
import xmlparser
logger = logging.getLogger(__name__)
def end(toks, context, prompt):
"""Quit the prompt for reload or exit"""
if toks[0] == "refresh":
@ -66,10 +69,10 @@ def load_file(filename, context):
if context.addServer(server, config["nick"],
config["owner"], config["realname"],
server.hasAttribute("ssl")):
print (" Server `%s:%s' successfully added."
logger.info("Server `%s:%s' successfully added."
% (server["server"], server["port"]))
else:
print (" Server `%s:%s' already added, skiped."
logger.warn("Server `%s:%s' already added, skiped."
% (server["server"], server["port"]))
# Load files asked by the configuration file

View File

@ -16,9 +16,12 @@
# You should have received a copy of the GNU Affero General Public License
# along with this program. If not, see <http://www.gnu.org/licenses/>.
import logging
import traceback
import sys
logger = logging.getLogger(__name__)
class Response:
def __init__(self, sender, message=None, channel=None, nick=None, server=None,
nomore="No more message", title=None, more="(suite) ", count=None,
@ -54,7 +57,9 @@ class Response:
if sender is None or sender.find("!") < 0:
if sender is not None:
exc_type, exc_value, exc_traceback = sys.exc_info()
traceback.print_exception(exc_type, "\033[1;35mWarning:\033[0m bad sender provided in Response, it will be ignored.", exc_traceback)
logger.warn(traceback.format_exception(exc_type,
"Bad sender provided in Response, it will be ignored.",
exc_traceback))
self.sender = None
else:
self.sender = sender

View File

@ -55,7 +55,7 @@ class DCC(server.Server):
self.port = self.foundPort()
if self.port is None:
print ("No more available slot for DCC connection")
self.logger.critical("No more available slot for DCC connection")
self.setError("Il n'y a plus de place disponible sur le serveur"
" pour initialiser une session DCC.")
@ -81,7 +81,7 @@ class DCC(server.Server):
self.s = socket.socket()
try:
self.s.connect((host, port))
print ('Accepted user from', host, port, "for", 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
print ('Listen on', self.port, "for", 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()
print ('Connected by', 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:
print("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]
print ("Closing connection with", self.nick)
self.logger.info("Closing connection with " + self.nick)
self.stopping.set()
if self.closing_event is not None:
self.closing_event()

View File

@ -43,10 +43,10 @@ class IRCServer(server.Server):
realname -- string used as realname on this server
ssl -- require SSL?
"""
server.Server.__init__(self)
self.node = node
server.Server.__init__(self)
self.nick = nick
self.owner = owner
self.realname = realname
@ -173,7 +173,7 @@ class IRCServer(server.Server):
self.s.connect((self.host, self.port)) #Connect to server
except socket.error as e:
self.s = None
print ("\033[1;31mError:\033[0m Unable to connect to %s:%d: %s"
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:
print ("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
print ("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()
print ("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,17 @@ class IRCServer(server.Server):
"""Send a message without checks or format"""
#TODO: add something for post message treatment here
if channel == self.nick:
print ("\033[1;35mWarning:\033[0m Nemubot talks to himself: %s" % msg)
traceback.print_stack()
self.logger.warn("Nemubot talks to himself: %s" % msg)
self.logger.debug(traceback.print_stack())
if line is not None and channel is not None:
if self.s is None:
print ("\033[1;35mWarning:\033[0m Attempt to send message on a non connected server: %s: %s" % (self.id, line))
traceback.print_stack()
self.logger.warn("Attempt to send message on a non connected server: %s: %s" % (self.id, line))
self.logger.debug(traceback.format_stack())
elif len(line) < 442:
self.s.send (("%s %s :%s%s" % (cmd, channel, line, endl)).encode ())
self.s.send(("%s %s :%s%s" % (cmd, channel, line, endl)).encode ())
else:
print ("\033[1;35mWarning:\033[0m Message truncated due to size (%d ; max : 442) : %s" % (len(line), line))
traceback.print_stack()
self.logger.warn("Message truncated due to size (%d ; max : 442) : %s" % (len(line), line))
self.logger.debug(traceback.format_stack())
self.s.send (("%s %s :%s%s" % (cmd, channel, line[0:442]+"<…>", endl)).encode ())
def send_msg_usr(self, user, msg):

View File

@ -16,6 +16,7 @@
# You should have received a copy of the GNU Affero General Public License
# along with this program. If not, see <http://www.gnu.org/licenses/>.
import logging
import socket
import threading
@ -29,6 +30,8 @@ class Server(threading.Thread):
self.moremessages = dict()
self.logger = logging.getLogger(__name__ + "/" + self.id)
threading.Thread.__init__(self)
def isDCC(self, to=None):
@ -142,7 +145,7 @@ class Server(threading.Thread):
self.connected = False
#Send a message in order to close the socket
try:
self.s.send(("Bye!\r\n" % self.nick).encode ())
self.s.send(("Bye!\r\n").encode ())
except:
pass
self.stopping.wait()
@ -155,6 +158,7 @@ class Server(threading.Thread):
self._receive_action = receive_action
if not self.connected:
self.stop = False
self.logger.info("Entering main loop for server")
try:
self.start()
except RuntimeError: