From 501bc92528a9ed04b9790cd4977d14e3ccd93726 Mon Sep 17 00:00:00 2001 From: Goffi Date: Sat, 19 Apr 2014 19:19:19 +0200 Subject: [PATCH] core: use of the new core.log module: /!\ this is a massive refactoring and was largely automated, it probably did bring some bugs /!\ --- frontends/src/bridge/DBus.py | 7 +- src/bridge/DBus.py | 22 +- src/bridge/bridge.py | 5 +- .../bridge_constructor/dbus_core_template.py | 22 +- .../dbus_frontend_template.py | 7 +- src/core/sat_main.py | 80 +++--- src/core/xmpp.py | 51 ++-- src/memory/disco.py | 11 +- src/memory/memory.py | 39 +-- src/memory/params.py | 57 ++-- src/memory/persistent.py | 5 +- src/memory/sqlite.py | 77 ++--- src/plugins/deprecated_misc_cs.py | 271 ------------------ src/plugins/plugin_adhoc_dbus.py | 17 +- src/plugins/plugin_exp_command_export.py | 17 +- src/plugins/plugin_exp_parrot.py | 17 +- src/plugins/plugin_exp_pipe.py | 55 ++-- src/plugins/plugin_misc_account.py | 15 +- src/plugins/plugin_misc_groupblog.py | 39 +-- src/plugins/plugin_misc_imap.py | 83 +++--- src/plugins/plugin_misc_maildir.py | 25 +- src/plugins/plugin_misc_quiz.py | 15 +- src/plugins/plugin_misc_radiocol.py | 13 +- src/plugins/plugin_misc_room_game.py | 33 +-- src/plugins/plugin_misc_smtp.py | 20 +- src/plugins/plugin_misc_tarot.py | 44 +-- src/plugins/plugin_misc_text_commands.py | 17 +- src/plugins/plugin_misc_text_syntaxes.py | 9 +- src/plugins/plugin_misc_xmllog.py | 9 +- src/plugins/plugin_tmp_demo_directory.py | 11 +- src/plugins/plugin_xep_0020.py | 7 +- src/plugins/plugin_xep_0033.py | 13 +- src/plugins/plugin_xep_0045.py | 51 ++-- src/plugins/plugin_xep_0047.py | 31 +- src/plugins/plugin_xep_0048.py | 29 +- src/plugins/plugin_xep_0049.py | 5 +- src/plugins/plugin_xep_0050.py | 13 +- src/plugins/plugin_xep_0054.py | 31 +- src/plugins/plugin_xep_0055.py | 20 +- src/plugins/plugin_xep_0060.py | 11 +- src/plugins/plugin_xep_0065.py | 93 +++--- src/plugins/plugin_xep_0071.py | 9 +- src/plugins/plugin_xep_0077.py | 15 +- src/plugins/plugin_xep_0085.py | 5 +- src/plugins/plugin_xep_0092.py | 7 +- src/plugins/plugin_xep_0095.py | 15 +- src/plugins/plugin_xep_0096.py | 61 ++-- src/plugins/plugin_xep_0100.py | 21 +- src/plugins/plugin_xep_0115.py | 21 +- src/plugins/plugin_xep_0163.py | 23 +- src/plugins/plugin_xep_0249.py | 23 +- src/plugins/plugin_xep_0277.py | 23 +- src/test/test_plugin_misc_radiocol.py | 3 +- src/test/test_plugin_misc_room_game.py | 3 +- src/test/test_plugin_xep_0033.py | 4 +- src/tools/misc.py | 7 +- src/tools/xml_tools.py | 11 +- 57 files changed, 707 insertions(+), 941 deletions(-) delete mode 100755 src/plugins/deprecated_misc_cs.py diff --git a/frontends/src/bridge/DBus.py b/frontends/src/bridge/DBus.py index 33f3d643..b685ab69 100644 --- a/frontends/src/bridge/DBus.py +++ b/frontends/src/bridge/DBus.py @@ -20,7 +20,8 @@ from sat.core.i18n import _ from bridge_frontend import BridgeFrontend import dbus -from logging import debug, error +from sat.core.log import getLogger +log = getLogger(__name__) from sat.core.exceptions import BridgeExceptionNoService, BridgeInitError from dbus.mainloop.glib import DBusGMainLoop @@ -47,7 +48,7 @@ class DBusBridgeFrontend(BridgeFrontend): if e._dbus_error_name == 'org.freedesktop.DBus.Error.ServiceUnknown': raise BridgeExceptionNoService elif e._dbus_error_name == 'org.freedesktop.DBus.Error.NotSupported': - print u"D-Bus is not launched, please see README to see instructions on how to launch it" + log.error(_(u"D-Bus is not launched, please see README to see instructions on how to launch it")) raise BridgeInitError else: raise e @@ -59,7 +60,7 @@ class DBusBridgeFrontend(BridgeFrontend): elif iface == "plugin": self.db_plugin_iface.connect_to_signal(functionName, handler) else: - error(_('Unknown interface')) + log.error(_('Unknown interface')) def __getattribute__(self, name): """ usual __getattribute__ if the method exists, else try to find a plugin method """ diff --git a/src/bridge/DBus.py b/src/bridge/DBus.py index 871bea59..166f1187 100755 --- a/src/bridge/DBus.py +++ b/src/bridge/DBus.py @@ -17,12 +17,14 @@ # You should have received a copy of the GNU Affero General Public License # along with this program. If not, see . +from sat.core.i18n import _ from bridge import Bridge import dbus import dbus.service import dbus.mainloop.glib import inspect -from logging import debug, info, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.internet.defer import Deferred from sat.core.exceptions import BridgeInitError @@ -69,7 +71,7 @@ class DbusObject(dbus.service.Object): def __init__(self, bus, path): dbus.service.Object.__init__(self, bus, path) - debug("Init DbusObject...") + log.debug("Init DbusObject...") self.cb = {} def register(self, name, cb): @@ -84,7 +86,7 @@ class DbusObject(dbus.service.Object): if "callback" in kwargs: #we must have errback too if not "errback" in kwargs: - error("errback is missing in method call [%s]" % name) + log.error("errback is missing in method call [%s]" % name) raise InternalError callback = kwargs.pop("callback") errback = kwargs.pop("errback") @@ -94,13 +96,13 @@ class DbusObject(dbus.service.Object): result = self.cb[name](*args, **kwargs) if async: if not isinstance(result, Deferred): - error("Asynchronous method [%s] does not return a Deferred." % name) + log.error("Asynchronous method [%s] does not return a Deferred." % name) raise AsyncNotDeferred result.addCallback(lambda result: callback() if result is None else callback(result)) result.addErrback(lambda err: errback(GenericException(err))) else: if isinstance(result, Deferred): - error("Synchronous method [%s] return a Deferred." % name) + log.error("Synchronous method [%s] return a Deferred." % name) raise DeferredNotAsync return result ### signals ### @@ -502,7 +504,7 @@ class DbusObject(dbus.service.Object): attributes = ', '.join(self.__attributes(signature)) #TODO: use doc parameter to name attributes - #code = compile ('def '+name+' (self,'+attributes+'): debug ("'+name+' signal")', '','exec') #XXX: the debug is too annoying with xmllog + #code = compile ('def '+name+' (self,'+attributes+'): log.debug ("'+name+' signal")', '','exec') #XXX: the log.debug is too annoying with xmllog code = compile('def ' + name + ' (self,' + attributes + '): pass', '', 'exec') exec (code) signal = locals()[name] @@ -517,12 +519,12 @@ class DBusBridge(Bridge): def __init__(self): dbus.mainloop.glib.DBusGMainLoop(set_as_default=True) Bridge.__init__(self) - info("Init DBus...") + log.info("Init DBus...") try: self.session_bus = dbus.SessionBus() except dbus.DBusException as e: if e._dbus_error_name == 'org.freedesktop.DBus.Error.NotSupported': - print u"D-Bus is not launched, please see README to see instructions on how to launch it" + log.error(_(u"D-Bus is not launched, please see README to see instructions on how to launch it")) raise BridgeInitError self.dbus_name = dbus.service.BusName(const_INT_PREFIX, self.session_bus) self.dbus_bridge = DbusObject(self.session_bus, const_OBJ_PATH) @@ -570,13 +572,13 @@ class DBusBridge(Bridge): self.dbus_bridge.subscribe(sub_type, entity_jid, profile) def register(self, name, callback): - debug("registering DBus bridge method [%s]", name) + log.debug("registering DBus bridge method [%s]" % name) self.dbus_bridge.register(name, callback) def addMethod(self, name, int_suffix, in_sign, out_sign, method, async=False, doc={}): """Dynamically add a method to Dbus Bridge""" #FIXME: doc parameter is kept only temporary, the time to remove it from calls - print ("Adding method [%s] to DBus bridge" % name) + log.debug("Adding method [%s] to DBus bridge" % name) self.dbus_bridge.addMethod(name, int_suffix, in_sign, out_sign, method, async) self.register(name, method) diff --git a/src/bridge/bridge.py b/src/bridge/bridge.py index 85092852..9c5f364d 100755 --- a/src/bridge/bridge.py +++ b/src/bridge/bridge.py @@ -17,9 +17,10 @@ # You should have received a copy of the GNU Affero General Public License # along with this program. If not, see . -from logging import debug, info, error +from sat.core.log import getLogger +log = getLogger(__name__) class Bridge(object): def __init__(self): - info("Bridge initialization") + log.info("Bridge initialization") diff --git a/src/bridge/bridge_constructor/dbus_core_template.py b/src/bridge/bridge_constructor/dbus_core_template.py index 679fc8ee..51c1336e 100644 --- a/src/bridge/bridge_constructor/dbus_core_template.py +++ b/src/bridge/bridge_constructor/dbus_core_template.py @@ -17,12 +17,14 @@ # You should have received a copy of the GNU Affero General Public License # along with this program. If not, see . +from sat.core.i18n import _ from bridge import Bridge import dbus import dbus.service import dbus.mainloop.glib import inspect -from logging import debug, info, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.internet.defer import Deferred from sat.core.exceptions import BridgeInitError @@ -69,7 +71,7 @@ class DbusObject(dbus.service.Object): def __init__(self, bus, path): dbus.service.Object.__init__(self, bus, path) - debug("Init DbusObject...") + log.debug("Init DbusObject...") self.cb = {} def register(self, name, cb): @@ -84,7 +86,7 @@ class DbusObject(dbus.service.Object): if "callback" in kwargs: #we must have errback too if not "errback" in kwargs: - error("errback is missing in method call [%s]" % name) + log.error("errback is missing in method call [%s]" % name) raise InternalError callback = kwargs.pop("callback") errback = kwargs.pop("errback") @@ -94,13 +96,13 @@ class DbusObject(dbus.service.Object): result = self.cb[name](*args, **kwargs) if async: if not isinstance(result, Deferred): - error("Asynchronous method [%s] does not return a Deferred." % name) + log.error("Asynchronous method [%s] does not return a Deferred." % name) raise AsyncNotDeferred result.addCallback(lambda result: callback() if result is None else callback(result)) result.addErrback(lambda err: errback(GenericException(err))) else: if isinstance(result, Deferred): - error("Synchronous method [%s] return a Deferred." % name) + log.error("Synchronous method [%s] return a Deferred." % name) raise DeferredNotAsync return result ### signals ### @@ -194,7 +196,7 @@ class DbusObject(dbus.service.Object): attributes = ', '.join(self.__attributes(signature)) #TODO: use doc parameter to name attributes - #code = compile ('def '+name+' (self,'+attributes+'): debug ("'+name+' signal")', '','exec') #XXX: the debug is too annoying with xmllog + #code = compile ('def '+name+' (self,'+attributes+'): log.debug ("'+name+' signal")', '','exec') #XXX: the log.debug is too annoying with xmllog code = compile('def ' + name + ' (self,' + attributes + '): pass', '', 'exec') exec (code) signal = locals()[name] @@ -209,25 +211,25 @@ class DBusBridge(Bridge): def __init__(self): dbus.mainloop.glib.DBusGMainLoop(set_as_default=True) Bridge.__init__(self) - info("Init DBus...") + log.info("Init DBus...") try: self.session_bus = dbus.SessionBus() except dbus.DBusException as e: if e._dbus_error_name == 'org.freedesktop.DBus.Error.NotSupported': - print u"D-Bus is not launched, please see README to see instructions on how to launch it" + log.error(_(u"D-Bus is not launched, please see README to see instructions on how to launch it")) raise BridgeInitError self.dbus_name = dbus.service.BusName(const_INT_PREFIX, self.session_bus) self.dbus_bridge = DbusObject(self.session_bus, const_OBJ_PATH) ##DIRECT_CALLS## def register(self, name, callback): - debug("registering DBus bridge method [%s]", name) + log.debug("registering DBus bridge method [%s]" % name) self.dbus_bridge.register(name, callback) def addMethod(self, name, int_suffix, in_sign, out_sign, method, async=False, doc={}): """Dynamically add a method to Dbus Bridge""" #FIXME: doc parameter is kept only temporary, the time to remove it from calls - print ("Adding method [%s] to DBus bridge" % name) + log.debug("Adding method [%s] to DBus bridge" % name) self.dbus_bridge.addMethod(name, int_suffix, in_sign, out_sign, method, async) self.register(name, method) diff --git a/src/bridge/bridge_constructor/dbus_frontend_template.py b/src/bridge/bridge_constructor/dbus_frontend_template.py index 58d85399..b0b1579f 100644 --- a/src/bridge/bridge_constructor/dbus_frontend_template.py +++ b/src/bridge/bridge_constructor/dbus_frontend_template.py @@ -20,7 +20,8 @@ from sat.core.i18n import _ from bridge_frontend import BridgeFrontend import dbus -from logging import debug, error +from sat.core.log import getLogger +log = getLogger(__name__) from sat.core.exceptions import BridgeExceptionNoService, BridgeInitError from dbus.mainloop.glib import DBusGMainLoop @@ -47,7 +48,7 @@ class DBusBridgeFrontend(BridgeFrontend): if e._dbus_error_name == 'org.freedesktop.DBus.Error.ServiceUnknown': raise BridgeExceptionNoService elif e._dbus_error_name == 'org.freedesktop.DBus.Error.NotSupported': - print u"D-Bus is not launched, please see README to see instructions on how to launch it" + log.error(_(u"D-Bus is not launched, please see README to see instructions on how to launch it")) raise BridgeInitError else: raise e @@ -59,7 +60,7 @@ class DBusBridgeFrontend(BridgeFrontend): elif iface == "plugin": self.db_plugin_iface.connect_to_signal(functionName, handler) else: - error(_('Unknown interface')) + log.error(_('Unknown interface')) def __getattribute__(self, name): """ usual __getattribute__ if the method exists, else try to find a plugin method """ diff --git a/src/core/sat_main.py b/src/core/sat_main.py index 5056a226..9ad6ed0c 100644 --- a/src/core/sat_main.py +++ b/src/core/sat_main.py @@ -25,20 +25,18 @@ from twisted.words.xish import domish from twisted.internet import reactor from wokkel.xmppim import RosterItem from sat.bridge.DBus import DBusBridge -import logging -from logging import debug, info, warning, error - -import sys -import os.path - from sat.core import xmpp from sat.core import exceptions +from sat.core.log import getLogger +log = getLogger(__name__) from sat.core.constants import Const as C from sat.memory.memory import Memory from sat.tools.misc import TriggerManager from sat.stdui import ui_contact_list from glob import glob from uuid import uuid4 +import sys +import os.path try: from collections import OrderedDict # only available from python 2.7 @@ -93,7 +91,7 @@ class SAT(service.Service): try: self.bridge = DBusBridge() except exceptions.BridgeInitError: - print (u"Bridge can't be initialised, can't start SàT core") # reactor is not launched yet, so we can't use error log + log.error(u"Bridge can't be initialised, can't start SàT core") sys.exit(1) self.bridge.register("getVersion", lambda: C.APP_VERSION) self.bridge.register("getProfileName", self.memory.getProfileName) @@ -140,7 +138,7 @@ class SAT(service.Service): def _postMemoryInit(self, ignore): """Method called after memory initialization is done""" - info(_("Memory initialised")) + log.info(_("Memory initialised")) self._import_plugins() ui_contact_list.ContactList(self) @@ -169,25 +167,25 @@ class SAT(service.Service): """ if import_name in self.plugins: - debug('Plugin [%s] already imported, passing' % import_name) + log.debug('Plugin [%s] already imported, passing' % import_name) return if not import_name: import_name, (plugin_path, mod, plugin_info) = plugins_to_import.popitem() else: if not import_name in plugins_to_import: if optional: - warning(_("Recommended plugin not found: %s") % import_name) + log.warning(_("Recommended plugin not found: %s") % import_name) return - error(_("Dependency not found: %s") % import_name) + log.error(_("Dependency not found: %s") % import_name) raise ImportError(_('Dependency plugin not found: [%s]') % import_name) plugin_path, mod, plugin_info = plugins_to_import.pop(import_name) dependencies = plugin_info.setdefault("dependencies", []) recommendations = plugin_info.setdefault("recommendations", []) for to_import in dependencies + recommendations: if to_import not in self.plugins: - debug('Recursively import dependency of [%s]: [%s]' % (import_name, to_import)) + log.debug('Recursively import dependency of [%s]: [%s]' % (import_name, to_import)) self._import_plugins_from_dict(plugins_to_import, to_import, to_import not in dependencies) - info(_("importing plugin: %s"), plugin_info['name']) + log.info(_("importing plugin: %s") % plugin_info['name']) self.plugins[import_name] = getattr(mod, plugin_info['main'])(self) if 'handler' in plugin_info and plugin_info['handler'] == 'yes': self.plugins[import_name].is_handler = True @@ -205,11 +203,11 @@ class SAT(service.Service): """ profile = self.memory.getProfileName(profile_key) if not profile: - error(_('Trying to connect a non-exsitant profile')) + log.error(_('Trying to connect a non-exsitant profile')) raise exceptions.ProfileUnknownError(profile_key) if self.isConnected(profile): - info(_("already connected !")) + log.info(_("already connected !")) return defer.succeed("None") def afterMemoryInit(ignore): @@ -217,7 +215,7 @@ class SAT(service.Service): try: port = int(self.memory.getParamA("Port", "Connection", profile_key=profile)) except ValueError: - error(_("Can't parse port value, using default value")) + log.error(_("Can't parse port value, using default value")) port = 5222 current = self.profiles[profile] = xmpp.SatXMPPClient( self, profile, @@ -245,7 +243,7 @@ class SAT(service.Service): current.identityHandler = xmpp.SatIdentityHandler() current.identityHandler.setHandlerParent(current) - debug(_("setting plugins parents")) + log.debug(_("setting plugins parents")) plugin_conn_cb = [] for plugin in self.plugins.iteritems(): @@ -270,10 +268,10 @@ class SAT(service.Service): def logPluginResults(results): all_succeed = all([success for success, result in results]) if not all_succeed: - error(_("Plugins initialisation error")) + log.error(_("Plugins initialisation error")) for idx, (success, result) in enumerate(results): if not success: - error("Error (plugin %(name)s): %(failure)s" % {'name': plugin_conn_cb[idx][0], + log.error("error (plugin %(name)s): %(failure)s" % {'name': plugin_conn_cb[idx][0], 'failure': result}) list_d.addCallback(logPluginResults) @@ -289,10 +287,10 @@ class SAT(service.Service): def disconnect(self, profile_key): """disconnect from jabber server""" if not self.isConnected(profile_key): - info(_("not connected !")) + log.info(_("not connected !")) return profile = self.memory.getProfileName(profile_key) - info(_("Disconnecting...")) + log.info(_("Disconnecting...")) self.profiles[profile].stopService() for plugin in self.plugins.iteritems(): disconnected_cb = getattr(plugin[1], "profileDisconnected", None) @@ -318,23 +316,23 @@ class SAT(service.Service): try: del self.profiles[profile] except KeyError: - error(_("Trying to remove reference to a client not referenced")) + log.error(_("Trying to remove reference to a client not referenced")) self.memory.purgeProfileSession(profile) def startService(self): - info("Salut à toi ô mon frère !") + log.info(u"Salut à toi ô mon frère !") #TODO: manage autoconnect #self.connect() def stopService(self): - info("Salut aussi à Rantanplan") + log.info("Salut aussi à Rantanplan") def run(self): - debug(_("running app")) + log.debug(_("running app")) reactor.run() def stop(self): - debug(_("stopping app")) + log.debug(_("stopping app")) reactor.stop() ## Misc methods ## @@ -415,7 +413,7 @@ class SAT(service.Service): def setParam(self, name, value, category, security_limit, profile_key): """set wanted paramater and notice observers""" - info(_("setting param: %(name)s=%(value)s in category %(category)s") % {'name': name, 'value': value, 'category': category}) + log.info(_("setting param: %(name)s=%(value)s in category %(category)s") % {'name': name, 'value': value, 'category': category}) self.memory.setParam(name, value, category, security_limit, profile_key) def isConnected(self, profile_key): @@ -425,7 +423,7 @@ class SAT(service.Service): """ profile = self.memory.getProfileName(profile_key) if not profile: - error(_('asking connection status for a non-existant profile')) + log.error(_('asking connection status for a non-existant profile')) return if profile not in self.profiles: return False @@ -490,7 +488,7 @@ class SAT(service.Service): if not self.trigger.point("sendMessage", mess_data, pre_xml_treatments, post_xml_treatments, profile): return defer.succeed(None) - debug(_("Sending jabber message of type [%(type)s] to %(to)s...") % {"type": mess_data["type"], "to": to_jid.full()}) + log.debug(_("Sending jabber message of type [%(type)s] to %(to)s...") % {"type": mess_data["type"], "to": to_jid.full()}) def generateXML(mess_data): mess_data['xml'] = domish.Element((None, 'message')) @@ -507,12 +505,12 @@ class SAT(service.Service): def sendErrback(e): text = '%s: %s' % (e.value.__class__.__name__, e.getErrorMessage()) if e.check(MessageSentAndStored): - debug(text) + log.debug(text) elif e.check(AbortSendMessage): - warning(text) + log.warning(text) return e else: - error("Unmanaged exception: %s" % text) + log.error("Unmanaged exception: %s" % text) return e pre_xml_treatments.addCallback(generateXML) pre_xml_treatments.chainDeferred(post_xml_treatments) @@ -532,7 +530,7 @@ class SAT(service.Service): try: client = self.profiles[profile] except KeyError: - error(_("Trying to send a message with no profile")) + log.error(_("Trying to send a message with no profile")) return current_jid = client.jid if not skip_send: @@ -580,7 +578,7 @@ class SAT(service.Service): profile = self.memory.getProfileName(profile_key) assert(profile) to_jid = jid.JID(raw_jid) - debug(_('subsciption request [%(subs_type)s] for %(jid)s') % {'subs_type': subs_type, 'jid': to_jid.full()}) + log.debug(_('subsciption request [%(subs_type)s] for %(jid)s') % {'subs_type': subs_type, 'jid': to_jid.full()}) if subs_type == "subscribe": self.profiles[profile].presence.subscribe(to_jid) elif subs_type == "subscribed": @@ -664,7 +662,7 @@ class SAT(service.Service): @param data: dictionary of dictionaries """ if action_type != "DICT_DICT": - error(_("action_type for actionResultExt must be DICT_DICT, fixing it")) + log.error(_("action_type for actionResultExt must be DICT_DICT, fixing it")) action_type = "DICT_DICT" self.bridge.actionResultExt(action_type, action_id, data, profile) @@ -678,7 +676,7 @@ class SAT(service.Service): # FIXME: use XMLUI and *callback methods for dialog client = self.getClient(profile) if conf_id in client._waiting_conf: - error(_("Attempt to register two callbacks for the same confirmation")) + log.error(_("Attempt to register two callbacks for the same confirmation")) else: client._waiting_conf[conf_id] = (conf_type, data, cb) self.bridge.askConfirmation(conf_id, conf_type, data, profile) @@ -686,9 +684,9 @@ class SAT(service.Service): def confirmationAnswer(self, conf_id, accepted, data, profile): """Called by frontends to answer confirmation requests""" client = self.getClient(profile) - debug(_("Received confirmation answer for conf_id [%(conf_id)s]: %(success)s") % {'conf_id': conf_id, 'success': _("accepted") if accepted else _("refused")}) + log.debug(_("Received confirmation answer for conf_id [%(conf_id)s]: %(success)s") % {'conf_id': conf_id, 'success': _("accepted") if accepted else _("refused")}) if conf_id not in client._waiting_conf: - error(_("Received an unknown confirmation (%(id)s for %(profile)s)") % {'id': conf_id, 'profile': profile}) + log.error(_("Received an unknown confirmation (%(id)s for %(profile)s)") % {'id': conf_id, 'profile': profile}) else: cb = client._waiting_conf[conf_id][-1] del client._waiting_conf[conf_id] @@ -703,7 +701,7 @@ class SAT(service.Service): """Remove a progress callback""" client = self.getClient(profile) if progress_id not in client._progress_cb_map: - error(_("Trying to remove an unknow progress callback")) + log.error(_("Trying to remove an unknow progress callback")) else: del client._progress_cb_map[progress_id] @@ -718,7 +716,7 @@ class SAT(service.Service): client._progress_cb_map[progress_id](progress_id, data, profile) except KeyError: pass - #debug("Requested progress for unknown progress_id") + #log.debug("Requested progress for unknown progress_id") return data def registerCallback(self, callback, *args, **kwargs): @@ -750,7 +748,7 @@ class SAT(service.Service): def removeCallback(self, callback_id): """ Remove a previously registered callback @param callback_id: id returned by [registerCallback] """ - debug("Removing callback [%s]" % callback_id) + log.debug("Removing callback [%s]" % callback_id) del self._cb_map[callback_id] def launchCallback(self, callback_id, data=None, profile_key=C.PROF_KEY_NONE): diff --git a/src/core/xmpp.py b/src/core/xmpp.py index 3264724f..059d9a95 100644 --- a/src/core/xmpp.py +++ b/src/core/xmpp.py @@ -22,7 +22,8 @@ from sat.core.constants import Const as C from twisted.internet import task, defer from twisted.words.protocols.jabber import jid, xmlstream from wokkel import client, disco, xmppim, generic, compat, delay, iwokkel -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from sat.core import exceptions from calendar import timegm from zope.interface import implements @@ -54,13 +55,13 @@ class SatXMPPClient(client.XMPPClient): return client.XMPPClient._authd(self, xmlstream) self.__connected = True - info(_("********** [%s] CONNECTED **********") % self.profile) + log.info(_("********** [%s] CONNECTED **********") % self.profile) self.streamInitialized() self.host_app.bridge.connected(self.profile) # we send the signal to the clients def streamInitialized(self): """Called after _authd""" - debug(_("XML stream is initialized")) + log.debug(_("XML stream is initialized")) self.keep_alife = task.LoopingCall(self.xmlstream.send, " ") # Needed to avoid disconnection (specially with openfire) self.keep_alife.start(180) @@ -81,7 +82,7 @@ class SatXMPPClient(client.XMPPClient): disco_d.addCallback(finish_connection) def initializationFailed(self, reason): - error(_("ERROR: XMPP connection failed for profile '%(profile)s': %(reason)s" % {'profile': self.profile, 'reason': reason})) + log.error(_("ERROR: XMPP connection failed for profile '%(profile)s': %(reason)s" % {'profile': self.profile, 'reason': reason})) self.host_app.bridge.connectionError("AUTH_ERROR", self.profile) try: client.XMPPClient.initializationFailed(self, reason) @@ -95,11 +96,11 @@ class SatXMPPClient(client.XMPPClient): def connectionLost(self, connector, unused_reason): self.__connected = False - info(_("********** [%s] DISCONNECTED **********") % self.profile) + log.info(_("********** [%s] DISCONNECTED **********") % self.profile) try: self.keep_alife.stop() except AttributeError: - debug(_("No keep_alife")) + log.debug(_("No keep_alife")) self.host_app.bridge.disconnected(self.profile) # we send the signal to the clients self.host_app.purgeClient(self.profile) # and we remove references to this client @@ -111,7 +112,7 @@ class SatMessageProtocol(xmppim.MessageProtocol): self.host = host def onMessage(self, message): - debug(_(u"got message from: %s"), message["from"]) + log.debug(_(u"got message from: %s") % message["from"]) post_treat = defer.Deferred() # XXX: plugin can add their treatments to this deferred if not self.host.trigger.point("MessageReceived", message, post_treat, profile=self.parent.profile): @@ -163,7 +164,7 @@ class SatRosterProtocol(xmppim.RosterClientProtocol): def requestRoster(self): """ ask the server for Roster list """ - debug("requestRoster") + log.debug("requestRoster") d = self.getRoster().addCallback(self.rosterCb) d.chainDeferred(self.got_roster) @@ -217,11 +218,11 @@ class SatRosterProtocol(xmppim.RosterClientProtocol): # may change in the future self.removeItem(item.jid) return - info(_("new contact in roster list: %s"), item.jid.full()) + log.info(_("new contact in roster list: %s") % item.jid.full()) if not item.subscriptionTo: - warning(_("You are not subscribed to this contact !")) + log.warning(_("You are not subscribed to this contact !")) if not item.subscriptionFrom: - warning(_("This contact is not subscribed to you !")) + log.warning(_("This contact is not subscribed to you !")) #self.host.memory.addContact(item.jid, item_attr, item.groups, self.parent.profile) bare_jid = item.jid.userhostJID() @@ -239,7 +240,7 @@ class SatRosterProtocol(xmppim.RosterClientProtocol): try: item = self._jids.pop(bare_jid) except KeyError: - warning("Received a roster remove event for an item not in cache") + log.warning("Received a roster remove event for an item not in cache") return for group in item.groups: try: @@ -248,7 +249,7 @@ class SatRosterProtocol(xmppim.RosterClientProtocol): if not jids_set: del self._groups[group] except KeyError: - warning("there is not cache for the group [%(groups)s] of the removed roster item [%(jid)s]" % + log.warning("there is not cache for the group [%(groups)s] of the removed roster item [%(jid)s]" % {"group": group, "jid": bare_jid}) # then we send the bridge signal @@ -295,7 +296,7 @@ class SatPresenceProtocol(xmppim.PresenceClientProtocol): super(SatPresenceProtocol, self).send(obj) def availableReceived(self, entity, show=None, statuses=None, priority=0): - debug(_("presence update for [%(entity)s] (available, show=%(show)s statuses=%(statuses)s priority=%(priority)d)") % {'entity': entity, 'show': show, 'statuses': statuses, 'priority': priority}) + log.debug(_("presence update for [%(entity)s] (available, show=%(show)s statuses=%(statuses)s priority=%(priority)d)") % {'entity': entity, 'show': show, 'statuses': statuses, 'priority': priority}) if not statuses: statuses = {} @@ -314,7 +315,7 @@ class SatPresenceProtocol(xmppim.PresenceClientProtocol): self.parent.profile) def unavailableReceived(self, entity, statuses=None): - debug(_("presence update for [%(entity)s] (unavailable, statuses=%(statuses)s)") % {'entity': entity, 'statuses': statuses}) + log.debug(_("presence update for [%(entity)s] (unavailable, statuses=%(statuses)s)") % {'entity': entity, 'statuses': statuses}) if not statuses: statuses = {} @@ -358,7 +359,7 @@ class SatPresenceProtocol(xmppim.PresenceClientProtocol): self.host.memory.delWaitingSub(entity.userhost(), self.parent.profile) item = self.parent.roster.getItem(entity) if not item or not item.subscriptionTo: # we automatically subscribe to 'to' presence - debug(_('sending automatic "from" subscription request')) + log.debug(_('sending automatic "from" subscription request')) self.subscribe(entity) def unsubscribed(self, entity): @@ -366,29 +367,29 @@ class SatPresenceProtocol(xmppim.PresenceClientProtocol): self.host.memory.delWaitingSub(entity.userhost(), self.parent.profile) def subscribedReceived(self, entity): - debug(_("subscription approved for [%s]") % entity.userhost()) + log.debug(_("subscription approved for [%s]") % entity.userhost()) self.host.bridge.subscribe('subscribed', entity.userhost(), self.parent.profile) def unsubscribedReceived(self, entity): - debug(_("unsubscription confirmed for [%s]") % entity.userhost()) + log.debug(_("unsubscription confirmed for [%s]") % entity.userhost()) self.host.bridge.subscribe('unsubscribed', entity.userhost(), self.parent.profile) def subscribeReceived(self, entity): - debug(_("subscription request from [%s]") % entity.userhost()) + log.debug(_("subscription request from [%s]") % entity.userhost()) item = self.parent.roster.getItem(entity) if item and item.subscriptionTo: # We automatically accept subscription if we are already subscribed to contact presence - debug(_('sending automatic subscription acceptance')) + log.debug(_('sending automatic subscription acceptance')) self.subscribed(entity) else: self.host.memory.addWaitingSub('subscribe', entity.userhost(), self.parent.profile) self.host.bridge.subscribe('subscribe', entity.userhost(), self.parent.profile) def unsubscribeReceived(self, entity): - debug(_("unsubscription asked for [%s]") % entity.userhost()) + log.debug(_("unsubscription asked for [%s]") % entity.userhost()) item = self.parent.roster.getItem(entity) if item and item.subscriptionFrom: # we automatically remove contact - debug(_('automatic contact deletion')) + log.debug(_('automatic contact deletion')) self.host.delContact(entity, self.parent.profile) self.host.bridge.subscribe('unsubscribe', entity.userhost(), self.parent.profile) @@ -405,7 +406,7 @@ class SatFallbackHandler(generic.FallbackHandler): def iqFallback(self, iq): if iq.handled is True: return - debug(u"iqFallback: xml = [%s]" % (iq.toXml())) + log.debug(u"iqFallback: xml = [%s]" % (iq.toXml())) generic.FallbackHandler.iqFallback(self, iq) @@ -441,14 +442,14 @@ class RegisteringAuthenticator(xmlstream.ConnectAuthenticator): iq.send(self.jabber_host).addCallbacks(self.registrationAnswer, self.registrationFailure) def registrationAnswer(self, answer): - debug(_("registration answer: %s") % answer.toXml()) + log.debug(_("registration answer: %s") % answer.toXml()) answer_type = "SUCCESS" answer_data = {"message": _("Registration successfull")} self.host.bridge.actionResult(answer_type, self.answer_id, answer_data, self.profile) self.xmlstream.sendFooter() def registrationFailure(self, failure): - info(_("Registration failure: %s") % str(failure.value)) + log.info(_("Registration failure: %s") % str(failure.value)) answer_type = "ERROR" answer_data = {} if failure.value.condition == 'conflict': diff --git a/src/memory/disco.py b/src/memory/disco.py index 011fde6b..c8e905ef 100755 --- a/src/memory/disco.py +++ b/src/memory/disco.py @@ -19,7 +19,8 @@ from sat.core.i18n import _ from sat.core import exceptions -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.protocols.jabber import jid from twisted.words.protocols.jabber.error import StanzaError from twisted.internet import defer @@ -126,9 +127,9 @@ class Discovery(object): # we cache items only for our own server try: items = self.host.memory.getEntityData(jid_, ["DISCO_ITEMS"], client.profile)["DISCO_ITEMS"] - debug("[%s] disco items are in cache" % jid_.full()) + log.debug("[%s] disco items are in cache" % jid_.full()) except KeyError: - debug("Caching [%s] disco items" % jid_.full()) + log.debug("Caching [%s] disco items" % jid_.full()) items = yield client.disco.requestItems(jid_) self.host.memory.updateEntityData(jid_, "DISCO_ITEMS", items, client.profile) else: @@ -139,7 +140,7 @@ class Discovery(object): def _infosEb(self, failure, entity_jid): failure.trap(StanzaError) - warning(_("Error while requesting [%(jid)s]: %(error)s") % {'jid': entity_jid.full(), + log.warning(_("Error while requesting [%(jid)s]: %(error)s") % {'jid': entity_jid.full(), 'error': failure.getErrorMessage()}) def findServiceEntities(self, category, type_, jid_=None, profile_key=C.PROF_KEY_NONE): @@ -236,7 +237,7 @@ class Discovery(object): s.append('<') #TODO: manage XEP-0128 data form here cap_hash = b64encode(sha1(''.join(s)).digest()) - debug(_('Capability hash generated: [%s]') % cap_hash) + log.debug(_('Capability hash generated: [%s]') % cap_hash) return cap_hash @defer.inlineCallbacks diff --git a/src/memory/memory.py b/src/memory/memory.py index c7d5fad9..80335a53 100644 --- a/src/memory/memory.py +++ b/src/memory/memory.py @@ -24,7 +24,8 @@ import csv from xdg import BaseDirectory from ConfigParser import SafeConfigParser, NoOptionError, NoSectionError from uuid import uuid4 -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.internet import defer, reactor from twisted.words.protocols.jabber import jid from sat.core import exceptions @@ -61,7 +62,7 @@ class Sessions(object): def _purgeSession(self, session_id): del self._sessions[session_id] - debug("Session [%s] purged" % session_id) + log.debug("Session [%s] purged" % session_id) def __len__(self): return len(self._sessions) @@ -97,7 +98,7 @@ class Sessions(object): timer.cancel() self._purgeSession(session_id) except KeyError: - debug ("Session [%s] doesn't exists, timeout expired ?" % session_id) + log.debug ("Session [%s] doesn't exists, timeout expired ?" % session_id) def keys(self): return self._sessions.keys() @@ -110,7 +111,7 @@ class Memory(object): """This class manage all persistent informations""" def __init__(self, host): - info(_("Memory manager init")) + log.info(_("Memory manager init")) self.initialized = defer.Deferred() self.host = host self._entities_cache = {} # XXX: keep presence/last resource/other data in cache @@ -123,7 +124,7 @@ class Memory(object): self.storage = SqliteStorage(database_file, host.__version__) PersistentDict.storage = self.storage self.params = Params(host, self.storage) - info(_("Loading default params template")) + log.info(_("Loading default params template")) self.params.load_default_params() d = self.storage.initialized.addCallback(lambda ignore: self.load()) self.memory_data = PersistentDict("memory") @@ -136,7 +137,7 @@ class Memory(object): try: config.read(C.CONFIG_FILES) except: - error(_("Can't read main config !")) + log.error(_("Can't read main config !")) return config # XXX: tmp update code, will be removed in the future @@ -148,7 +149,7 @@ class Memory(object): return # nothing to do old_default = '~/.sat' if os.path.isfile(os.path.expanduser(old_default) + '/' + C.SAVEFILE_DATABASE): - warning(_("A database has been found in the default local_dir for previous versions (< 0.5)")) + log.warning(_("A database has been found in the default local_dir for previous versions (< 0.5)")) config = SafeConfigParser() target_file = None for file_ in C.CONFIG_FILES[::-1]: @@ -164,7 +165,7 @@ class Memory(object): config.set('', 'local_dir', old_default) with open(target_file, 'wb') as configfile: config.write(configfile) # for the next time that user launches sat - warning(_("Auto-update: local_dir set to %(path)s in the file %(config_file)s") % {'path': old_default, 'config_file': file_}) + log.warning(_("Auto-update: local_dir set to %(path)s in the file %(config_file)s") % {'path': old_default, 'config_file': file_}) default = old_default else: # use the new default local_dir default = C.DEFAULT_LOCAL_DIR @@ -200,10 +201,10 @@ class Memory(object): if os.path.exists(filename): try: self.params.load_xml(filename) - debug(_("Parameters loaded from file: %s") % filename) + log.debug(_("Parameters loaded from file: %s") % filename) return True except Exception as e: - error(_("Can't load parameters from file: %s") % e) + log.error(_("Can't load parameters from file: %s") % e) return False def load(self): @@ -219,18 +220,18 @@ class Memory(object): def startProfileSession(self, profile): """"Iniatialise session for a profile @param profile: %(doc_profile)s""" - info(_("[%s] Profile session started" % profile)) + log.info(_("[%s] Profile session started" % profile)) self._entities_cache[profile] = {} def purgeProfileSession(self, profile): """Delete cache of data of profile @param profile: %(doc_profile)s""" - info(_("[%s] Profile session purge" % profile)) + log.info(_("[%s] Profile session purge" % profile)) self.params.purgeProfile(profile) try: del self._entities_cache[profile] except KeyError: - error(_("Trying to purge roster status cache for a profile not in memory: [%s]") % profile) + log.error(_("Trying to purge roster status cache for a profile not in memory: [%s]") % profile) def save_xml(self, filename=None): """Save parameters template to xml file""" @@ -240,10 +241,10 @@ class Memory(object): filename = os.path.expanduser(filename) try: self.params.save_xml(filename) - debug(_("Parameters saved to file: %s") % filename) + log.debug(_("Parameters saved to file: %s") % filename) return True except Exception as e: - error(_("Can't save parameters to file: %s") % e) + log.error(_("Can't save parameters to file: %s") % e) return False def getProfilesList(self): @@ -312,7 +313,7 @@ class Memory(object): if "presence" in self._entities_cache[profile][entity]: entities_presence[entity] = self._entities_cache[profile][entity]["presence"] - debug("Memory getPresenceStatus (%s)", entities_presence) + log.debug("Memory getPresenceStatus (%s)", entities_presence) return entities_presence def setPresenceStatus(self, entity_jid, show, priority, statuses, profile_key): @@ -393,7 +394,7 @@ class Memory(object): try: del entity_data[key] except KeyError: - debug("Key [%s] doesn't exist for [%s] in entities_cache" % (key, entity_jid.full())) + log.debug("Key [%s] doesn't exist for [%s] in entities_cache" % (key, entity_jid.full())) def getEntityData(self, entity_jid, keys_list, profile_key): """Get a list of cached values for entity @@ -454,7 +455,7 @@ class Memory(object): try: del self._entities_cache[profile][entity] except KeyError: - debug("Can't delete entity [%s]: not in cache" % entity.full()) + log.debug("Can't delete entity [%s]: not in cache" % entity.full()) def addWaitingSub(self, type_, entity_jid, profile_key): """Called when a subcription request is received""" @@ -475,7 +476,7 @@ class Memory(object): """Called to get a list of currently waiting subscription requests""" profile = self.getProfileName(profile_key) if not profile: - error(_('Asking waiting subscriptions for a non-existant profile')) + log.error(_('Asking waiting subscriptions for a non-existant profile')) return {} if profile not in self.subscriptions: return {} diff --git a/src/memory/params.py b/src/memory/params.py index e0ce122e..0a94945d 100644 --- a/src/memory/params.py +++ b/src/memory/params.py @@ -22,7 +22,8 @@ from sat.core.i18n import _ from sat.core import exceptions from sat.core.constants import Const as C from xml.dom import minidom, NotFoundErr -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.internet import defer from twisted.python.failure import Failure from sat.tools.xml_tools import paramsXML2XMLUI @@ -115,7 +116,7 @@ class Params(object): try: del self.params[profile] except KeyError: - error(_("Trying to purge cache of a profile not in memory: [%s]") % profile) + log.error(_("Trying to purge cache of a profile not in memory: [%s]") % profile) def save_xml(self, filename): """Save parameters template to xml file""" @@ -123,7 +124,7 @@ class Params(object): xml_file.write(self.dom.toxml('utf-8')) def __init__(self, host, storage): - debug("Parameters init") + log.debug("Parameters init") self.host = host self.storage = storage self.default_profile = None @@ -138,7 +139,7 @@ class Params(object): @return: a Deferred instance """ if self.storage.hasProfile(profile): - info(_('The profile name already exists')) + log.info(_('The profile name already exists')) return defer.fail(Failure(exceptions.ConflictError)) if not self.host.trigger.point("ProfileCreation", profile): return defer.fail(Failure(exceptions.CancelError)) @@ -153,13 +154,13 @@ class Params(object): @return: a Deferred instance """ if not self.storage.hasProfile(profile): - info(_('Trying to delete an unknown profile')) + log.info(_('Trying to delete an unknown profile')) return defer.fail(Failure(exceptions.ProfileUnknownError)) if self.host.isConnected(profile): if force: self.host.disconnect(profile) else: - info(_("Trying to delete a connected profile")) + log.info(_("Trying to delete a connected profile")) return defer.fail(Failure(exceptions.ConnectedProfileError)) return self.storage.deleteProfile(profile) @@ -174,11 +175,11 @@ class Params(object): if profile_key == '@DEFAULT@': default = self.host.memory.memory_data.get('Profile_default') if not default: - info(_('No default profile, returning first one')) # TODO: manage real default profile + log.info(_('No default profile, returning first one')) # TODO: manage real default profile try: default = self.host.memory.memory_data['Profile_default'] = self.storage.getProfilesList()[0] except IndexError: - info(_('No profile exist yet')) + log.info(_('No profile exist yet')) return "" return default # FIXME: temporary, must use real default value, and fallback to first one if it doesn't exists elif profile_key == C.PROF_KEY_NONE: @@ -186,7 +187,7 @@ class Params(object): elif return_profile_keys and profile_key in ["@ALL@"]: return profile_key # this value must be managed by the caller if not self.storage.hasProfile(profile_key): - info(_('Trying to access an unknown profile')) + log.info(_('Trying to access an unknown profile')) return "" # FIXME: raise exceptions.ProfileUnknownError here (must be well checked, this method is used in lot of places) return profile_key @@ -267,23 +268,23 @@ class Params(object): @param app: name of the frontend registering the parameters """ if not app: - warning(_("Trying to register frontends parameters with no specified app: aborted")) + log.warning(_("Trying to register frontends parameters with no specified app: aborted")) return if not hasattr(self, "frontends_cache"): self.frontends_cache = [] if app in self.frontends_cache: - debug(_("Trying to register twice frontends parameters for %(app)s: aborted" % {"app": app})) + log.debug(_("Trying to register twice frontends parameters for %(app)s: aborted" % {"app": app})) return self.frontends_cache.append(app) self.updateParams(xml, security_limit, app) - debug("Frontends parameters registered for %(app)s" % {'app': app}) + log.debug("Frontends parameters registered for %(app)s" % {'app': app}) def __default_ok(self, value, name, category): #FIXME: will not work with individual parameters self.setParam(name, value, category) def __default_ko(self, failure, name, category): - error(_("Can't determine default value for [%(category)s/%(name)s]: %(reason)s") % {'category': category, 'name': name, 'reason': str(failure.value)}) + log.error(_("Can't determine default value for [%(category)s/%(name)s]: %(reason)s") % {'category': category, 'name': name, 'reason': str(failure.value)}) def setDefault(self, name, category, callback, errback=None): """Set default value of parameter @@ -295,17 +296,17 @@ class Params(object): """ #TODO: send signal param update if value changed #TODO: manage individual paramaters - debug ("setDefault called for %(category)s/%(name)s" % {"category": category, "name": name}) + log.debug ("setDefault called for %(category)s/%(name)s" % {"category": category, "name": name}) node = self._getParamNode(name, category, '@ALL@') if not node: - error(_("Requested param [%(name)s] in category [%(category)s] doesn't exist !") % {'name': name, 'category': category}) + log.error(_("Requested param [%(name)s] in category [%(category)s] doesn't exist !") % {'name': name, 'category': category}) return if node[1].getAttribute('default_cb') == 'yes': # del node[1].attributes['default_cb'] # default_cb is not used anymore as a flag to know if we have to set the default value, # and we can still use it later e.g. to call a generic setDefault method value = self._getParam(category, name, C.GENERAL) if value is None: # no value set by the user: we have the default value - debug ("Default value to set, using callback") + log.debug ("Default value to set, using callback") d = defer.maybeDeferred(callback) d.addCallback(self.__default_ok, name, category) d.addErrback(errback or self.__default_ko, name, category) @@ -343,7 +344,7 @@ class Params(object): #FIXME: looks really dirty and buggy, need to be reviewed/refactored node = self._getParamNode(name, category) if not node: - error(_("Requested param [%(name)s] in category [%(category)s] doesn't exist !") % {'name': name, 'category': category}) + log.error(_("Requested param [%(name)s] in category [%(category)s] doesn't exist !") % {'name': name, 'category': category}) raise exceptions.NotFound if node[0] == C.GENERAL: @@ -354,11 +355,11 @@ class Params(object): profile = self.getProfileName(profile_key) if not profile: - error(_('Requesting a param for an non-existant profile')) + log.error(_('Requesting a param for an non-existant profile')) raise exceptions.ProfileUnknownError if profile not in self.params: - error(_('Requesting synchronous param for not connected profile')) + log.error(_('Requesting synchronous param for not connected profile')) raise exceptions.NotConnectedProfileError(profile) if attr == "value": @@ -378,11 +379,11 @@ class Params(object): @param profile: owner of the param (@ALL@ for everyone)""" node = self._getParamNode(name, category) if not node: - error(_("Requested param [%(name)s] in category [%(category)s] doesn't exist !") % {'name': name, 'category': category}) + log.error(_("Requested param [%(name)s] in category [%(category)s] doesn't exist !") % {'name': name, 'category': category}) return None if not self.checkSecurityLimit(node[1], security_limit): - warning(_("Trying to get parameter '%(param)s' in category '%(cat)s' without authorization!!!" + log.warning(_("Trying to get parameter '%(param)s' in category '%(cat)s' without authorization!!!" % {'param': name, 'cat': category})) return None @@ -394,7 +395,7 @@ class Params(object): profile = self.getProfileName(profile_key) if not profile: - error(_('Requesting a param for a non-existant profile')) + log.error(_('Requesting a param for a non-existant profile')) return defer.fail() if attr != "value": @@ -538,7 +539,7 @@ class Params(object): """ profile = self.getProfileName(profile_key) if not profile: - error(_("Asking params for inexistant profile")) + log.error(_("Asking params for inexistant profile")) return "" d = self.getParams(security_limit, app, profile) return d.addCallback(lambda param_xml: paramsXML2XMLUI(param_xml)) @@ -554,7 +555,7 @@ class Params(object): """ profile = self.getProfileName(profile_key) if not profile: - error(_("Asking params for inexistant profile")) + log.error(_("Asking params for inexistant profile")) return defer.succeed("") def returnXML(prof_xml): @@ -577,7 +578,7 @@ class Params(object): #TODO: manage category of general type (without existant profile) profile = self.getProfileName(profile_key) if not profile: - error(_("Asking params for inexistant profile")) + log.error(_("Asking params for inexistant profile")) return "" def returnCategoryXml(prof_xml): @@ -629,17 +630,17 @@ class Params(object): if profile_key != C.PROF_KEY_NONE: profile = self.getProfileName(profile_key) if not profile: - error(_('Trying to set parameter for an unknown profile')) + log.error(_('Trying to set parameter for an unknown profile')) return # TODO: throw an error node = self._getParamNode(name, category, '@ALL@') if not node: - error(_('Requesting an unknown parameter (%(category)s/%(name)s)') + log.error(_('Requesting an unknown parameter (%(category)s/%(name)s)') % {'category': category, 'name': name}) return if not self.checkSecurityLimit(node[1], security_limit): - warning(_("Trying to set parameter '%(param)s' in category '%(cat)s' without authorization!!!" + log.warning(_("Trying to set parameter '%(param)s' in category '%(cat)s' without authorization!!!" % {'param': name, 'cat': category})) return diff --git a/src/memory/persistent.py b/src/memory/persistent.py index 4b5668b8..c29ec894 100644 --- a/src/memory/persistent.py +++ b/src/memory/persistent.py @@ -18,7 +18,8 @@ # along with this program. If not, see . from sat.core.i18n import _ -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) class MemoryNotInitializedError(Exception): @@ -35,7 +36,7 @@ class PersistentDict(object): """@param namespace: unique namespace for this dictionary @param profile: profile which *MUST* exists, or None for general values""" if not self.storage: - error(_("PersistentDict can't be used before memory initialisation")) + log.error(_("PersistentDict can't be used before memory initialisation")) raise MemoryNotInitializedError self._cache = {} self.namespace = namespace diff --git a/src/memory/sqlite.py b/src/memory/sqlite.py index 0a006d17..8c7773a4 100644 --- a/src/memory/sqlite.py +++ b/src/memory/sqlite.py @@ -19,7 +19,8 @@ from sat.core.i18n import _ from sat.core import exceptions -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.enterprise import adbapi from twisted.internet import defer from collections import OrderedDict @@ -80,7 +81,7 @@ class SqliteStorage(object): self.initialized = defer.Deferred() # triggered when memory is fully initialised and ready self.profiles = {} # we keep cache for the profiles (key: profile name, value: profile id) - info(_("Connecting database")) + log.info(_("Connecting database")) new_base = not os.path.exists(db_filename) # do we have to create the database ? if new_base: # the dir may not exist if it's not the XDG recommended one dir_ = os.path.dirname(db_filename) @@ -92,10 +93,10 @@ class SqliteStorage(object): # XXX: foreign_keys activation doesn't seem to work, probably because of the multi-threading # All the requests that need to use this feature should be run with runInteraction instead, # so you can set the PRAGMA as it is done in self.deleteProfile - init_defer = self.dbpool.runOperation("PRAGMA foreign_keys = ON").addErrback(lambda x: error(_("Can't activate foreign keys"))) + init_defer = self.dbpool.runOperation("PRAGMA foreign_keys = ON").addErrback(lambda x: log.error(_("Can't activate foreign keys"))) def getNewBaseSql(): - info(_("The database is new, creating the tables")) + log.info(_("The database is new, creating the tables")) database_creation = ["PRAGMA user_version=%d" % CURRENT_DB_VERSION] database_creation.extend(Updater.createData2Raw(DATABASE_SCHEMAS['current']['CREATE'])) database_creation.extend(Updater.insertData2Raw(DATABASE_SCHEMAS['current']['INSERT'])) @@ -109,7 +110,7 @@ class SqliteStorage(object): if statements is None: return defer.succeed(None) - debug("===== COMMITING STATEMENTS =====\n%s\n============\n\n" % '\n'.join(statements)) + log.debug("===== COMMITING STATEMENTS =====\n%s\n============\n\n" % '\n'.join(statements)) d = self.dbpool.runInteraction(self._updateDb, tuple(statements)) return d @@ -166,7 +167,7 @@ class SqliteStorage(object): @param name: name of the profile @return: deferred triggered once profile is actually deleted""" def deletionError(failure): - error(_("Can't delete profile [%s]") % name) + log.error(_("Can't delete profile [%s]") % name) return failure def delete(txn): @@ -176,7 +177,7 @@ class SqliteStorage(object): return None d = self.dbpool.runInteraction(delete) - d.addCallback(lambda ignore: info(_("Profile [%s] deleted") % name)) + d.addCallback(lambda ignore: log.info(_("Profile [%s] deleted") % name)) d.addErrback(deletionError) return d @@ -190,7 +191,7 @@ class SqliteStorage(object): for param in result: category, name, value = param params_gen[(category, name)] = value - debug(_("loading general parameters from database")) + log.debug(_("loading general parameters from database")) return self.dbpool.runQuery("SELECT category,name,value FROM param_gen").addCallback(fillParams) def loadIndParams(self, params_ind, profile): @@ -203,7 +204,7 @@ class SqliteStorage(object): for param in result: category, name, value = param params_ind[(category, name)] = value - debug(_("loading individual parameters from database")) + log.debug(_("loading individual parameters from database")) d = self.dbpool.runQuery("SELECT category,name,value FROM param_ind WHERE profile_id=?", (self.profiles[profile], )) d.addCallback(fillParams) return d @@ -225,7 +226,7 @@ class SqliteStorage(object): @param value: value to set @return: deferred""" d = self.dbpool.runQuery("REPLACE INTO param_gen(category,name,value) VALUES (?,?,?)", (category, name, value)) - d.addErrback(lambda ignore: error(_("Can't set general parameter (%(category)s/%(name)s) in database" % {"category": category, "name": name}))) + d.addErrback(lambda ignore: log.error(_("Can't set general parameter (%(category)s/%(name)s) in database" % {"category": category, "name": name}))) return d def setIndParam(self, category, name, value, profile): @@ -236,7 +237,7 @@ class SqliteStorage(object): @param profile: a profile which *must* exist @return: deferred""" d = self.dbpool.runQuery("REPLACE INTO param_ind(category,name,profile_id,value) VALUES (?,?,?,?)", (category, name, self.profiles[profile], value)) - d.addErrback(lambda ignore: error(_("Can't set individual parameter (%(category)s/%(name)s) for [%(profile)s] in database" % {"category": category, "name": name, "profile": profile}))) + d.addErrback(lambda ignore: log.error(_("Can't set individual parameter (%(category)s/%(name)s) for [%(profile)s] in database" % {"category": category, "name": name, "profile": profile}))) return d #History @@ -256,7 +257,7 @@ class SqliteStorage(object): d = self.dbpool.runQuery("INSERT INTO history(source, source_res, dest, dest_res, timestamp, message, type, extra, profile_id) VALUES (?,?,?,?,?,?,?,?,?)", (from_jid.userhost(), from_jid.resource, to_jid.userhost(), to_jid.resource, timestamp or time(), message, _type, extra_, self.profiles[profile])) - d.addErrback(lambda ignore: error(_("Can't save following message in history: from [%(from_jid)s] to [%(to_jid)s] ==> [%(message)s]" % + d.addErrback(lambda ignore: log.error(_("Can't save following message in history: from [%(from_jid)s] to [%(to_jid)s] ==> [%(message)s]" % {"from_jid": from_jid.full(), "to_jid": to_jid.full(), "message": message}))) return d @@ -321,9 +322,9 @@ class SqliteStorage(object): for private in result: key, value = private private_gen[key] = value - debug(_("loading general private values [namespace: %s] from database") % (namespace, )) + log.debug(_("loading general private values [namespace: %s] from database") % (namespace, )) d = self.dbpool.runQuery("SELECT key,value FROM private_gen WHERE namespace=?", (namespace, )).addCallback(fillPrivates) - return d.addErrback(lambda x: debug(_("No data present in database for namespace %s") % namespace)) + return d.addErrback(lambda x: log.debug(_("No data present in database for namespace %s") % namespace)) def loadIndPrivates(self, private_ind, namespace, profile): """Load individual private values @@ -336,10 +337,10 @@ class SqliteStorage(object): for private in result: key, value = private private_ind[key] = value - debug(_("loading individual private values [namespace: %s] from database") % (namespace, )) + log.debug(_("loading individual private values [namespace: %s] from database") % (namespace, )) d = self.dbpool.runQuery("SELECT key,value FROM private_ind WHERE namespace=? AND profile_id=?", (namespace, self.profiles[profile])) d.addCallback(fillPrivates) - return d.addErrback(lambda x: debug(_("No data present in database for namespace %s") % namespace)) + return d.addErrback(lambda x: log.debug(_("No data present in database for namespace %s") % namespace)) def setGenPrivate(self, namespace, key, value): """Save the general private value in database @@ -348,7 +349,7 @@ class SqliteStorage(object): @param value: value to set @return: deferred""" d = self.dbpool.runQuery("REPLACE INTO private_gen(namespace,key,value) VALUES (?,?,?)", (namespace, key, value)) - d.addErrback(lambda ignore: error(_("Can't set general private value (%(key)s) [namespace:%(namespace)s] in database" % + d.addErrback(lambda ignore: log.error(_("Can't set general private value (%(key)s) [namespace:%(namespace)s] in database" % {"namespace": namespace, "key": key}))) return d @@ -360,7 +361,7 @@ class SqliteStorage(object): @param profile: a profile which *must* exist @return: deferred""" d = self.dbpool.runQuery("REPLACE INTO private_ind(namespace,key,profile_id,value) VALUES (?,?,?,?)", (namespace, key, self.profiles[profile], value)) - d.addErrback(lambda ignore: error(_("Can't set individual private value (%(key)s) [namespace: %(namespace)s] for [%(profile)s] in database" % + d.addErrback(lambda ignore: log.error(_("Can't set individual private value (%(key)s) [namespace: %(namespace)s] for [%(profile)s] in database" % {"namespace": namespace, "key": key, "profile": profile}))) return d @@ -370,7 +371,7 @@ class SqliteStorage(object): @param key: key of the private value @return: deferred""" d = self.dbpool.runQuery("DELETE FROM private_gen WHERE namespace=? AND key=?", (namespace, key)) - d.addErrback(lambda ignore: error(_("Can't delete general private value (%(key)s) [namespace:%(namespace)s] in database" % + d.addErrback(lambda ignore: log.error(_("Can't delete general private value (%(key)s) [namespace:%(namespace)s] in database" % {"namespace": namespace, "key": key}))) return d @@ -381,7 +382,7 @@ class SqliteStorage(object): @param profile: a profile which *must* exist @return: deferred""" d = self.dbpool.runQuery("DELETE FROM private_ind WHERE namespace=? AND key=? AND profile=?)", (namespace, key, self.profiles[profile])) - d.addErrback(lambda ignore: error(_("Can't delete individual private value (%(key)s) [namespace: %(namespace)s] for [%(profile)s] in database" % + d.addErrback(lambda ignore: log.error(_("Can't delete individual private value (%(key)s) [namespace: %(namespace)s] for [%(profile)s] in database" % {"namespace": namespace, "key": key, "profile": profile}))) return d @@ -395,9 +396,9 @@ class SqliteStorage(object): for private in result: key, value = private private_gen[key] = pickle.loads(str(value)) - debug(_("loading general private binary values [namespace: %s] from database") % (namespace, )) + log.debug(_("loading general private binary values [namespace: %s] from database") % (namespace, )) d = self.dbpool.runQuery("SELECT key,value FROM private_gen_bin WHERE namespace=?", (namespace, )).addCallback(fillPrivates) - return d.addErrback(lambda x: debug(_("No binary data present in database for namespace %s") % namespace)) + return d.addErrback(lambda x: log.debug(_("No binary data present in database for namespace %s") % namespace)) def loadIndPrivatesBinary(self, private_ind, namespace, profile): """Load individual private binary values @@ -410,10 +411,10 @@ class SqliteStorage(object): for private in result: key, value = private private_ind[key] = pickle.loads(str(value)) - debug(_("loading individual private binary values [namespace: %s] from database") % (namespace, )) + log.debug(_("loading individual private binary values [namespace: %s] from database") % (namespace, )) d = self.dbpool.runQuery("SELECT key,value FROM private_ind_bin WHERE namespace=? AND profile_id=?", (namespace, self.profiles[profile])) d.addCallback(fillPrivates) - return d.addErrback(lambda x: debug(_("No binary data present in database for namespace %s") % namespace)) + return d.addErrback(lambda x: log.debug(_("No binary data present in database for namespace %s") % namespace)) def setGenPrivateBinary(self, namespace, key, value): """Save the general private binary value in database @@ -422,7 +423,7 @@ class SqliteStorage(object): @param value: value to set @return: deferred""" d = self.dbpool.runQuery("REPLACE INTO private_gen_bin(namespace,key,value) VALUES (?,?,?)", (namespace, key, pickle.dumps(value, 0))) - d.addErrback(lambda ignore: error(_("Can't set general private binary value (%(key)s) [namespace:%(namespace)s] in database" % + d.addErrback(lambda ignore: log.error(_("Can't set general private binary value (%(key)s) [namespace:%(namespace)s] in database" % {"namespace": namespace, "key": key}))) return d @@ -434,7 +435,7 @@ class SqliteStorage(object): @param profile: a profile which *must* exist @return: deferred""" d = self.dbpool.runQuery("REPLACE INTO private_ind_bin(namespace,key,profile_id,value) VALUES (?,?,?,?)", (namespace, key, self.profiles[profile], pickle.dumps(value, 0))) - d.addErrback(lambda ignore: error(_("Can't set individual binary private value (%(key)s) [namespace: %(namespace)s] for [%(profile)s] in database" % + d.addErrback(lambda ignore: log.error(_("Can't set individual binary private value (%(key)s) [namespace: %(namespace)s] for [%(profile)s] in database" % {"namespace": namespace, "key": key, "profile": profile}))) return d @@ -444,7 +445,7 @@ class SqliteStorage(object): @param key: key of the private value @return: deferred""" d = self.dbpool.runQuery("DELETE FROM private_gen_bin WHERE namespace=? AND key=?", (namespace, key)) - d.addErrback(lambda ignore: error(_("Can't delete general private binary value (%(key)s) [namespace:%(namespace)s] in database" % + d.addErrback(lambda ignore: log.error(_("Can't delete general private binary value (%(key)s) [namespace:%(namespace)s] in database" % {"namespace": namespace, "key": key}))) return d @@ -455,7 +456,7 @@ class SqliteStorage(object): @param profile: a profile which *must* exist @return: deferred""" d = self.dbpool.runQuery("DELETE FROM private_ind_bin WHERE namespace=? AND key=? AND profile=?)", (namespace, key, self.profiles[profile])) - d.addErrback(lambda ignore: error(_("Can't delete individual private binary value (%(key)s) [namespace: %(namespace)s] for [%(profile)s] in database" % + d.addErrback(lambda ignore: log.error(_("Can't delete individual private binary value (%(key)s) [namespace: %(namespace)s] for [%(profile)s] in database" % {"namespace": namespace, "key": key, "profile": profile}))) return d ##Helper methods## @@ -521,7 +522,7 @@ class Updater(object): if local_hash == current_hash: if local_version != CURRENT_DB_VERSION: - warning(_("Your local schema is up-to-date, but database versions mismatch, fixing it...")) + log.warning(_("Your local schema is up-to-date, but database versions mismatch, fixing it...")) yield self._setLocalVersion(CURRENT_DB_VERSION) else: # an update is needed @@ -531,17 +532,17 @@ class Updater(object): if self._sat_version.endswith('D'): # we are in a development version update_data = self.generateUpdateData(local_sch, current_sch, False) - warning(_("There is a schema mismatch, but as we are on a dev version, database will be updated")) + log.warning(_("There is a schema mismatch, but as we are on a dev version, database will be updated")) update_raw = self.update2raw(update_data, True) defer.returnValue(update_raw) else: - error(_(u"schema version is up-to-date, but local schema differ from expected current schema")) + log.error(_(u"schema version is up-to-date, but local schema differ from expected current schema")) update_data = self.generateUpdateData(local_sch, current_sch, True) - warning(_(u"Here are the commands that should fix the situation, use at your own risk (do a backup before modifying database), you can go to SàT's MUC room at sat@chat.jabberfr.org for help\n### SQL###\n%s\n### END SQL ###\n") % u'\n'.join(("%s;" % statement for statement in self.update2raw(update_data)))) + log.warning(_(u"Here are the commands that should fix the situation, use at your own risk (do a backup before modifying database), you can go to SàT's MUC room at sat@chat.jabberfr.org for help\n### SQL###\n%s\n### END SQL ###\n") % u'\n'.join(("%s;" % statement for statement in self.update2raw(update_data)))) raise exceptions.DatabaseError("Database mismatch") else: # Database is not up-to-date, we'll do the update - info(_("Database schema has changed, local database will be updated")) + log.info(_("Database schema has changed, local database will be updated")) update_raw = [] for version in xrange(local_version+1, CURRENT_DB_VERSION+1): try: @@ -612,12 +613,12 @@ class Updater(object): schema_dict = {} for create_statement in raw_statements: if not create_statement.startswith("CREATE TABLE "): - warning("Unexpected statement, ignoring it") + log.warning("Unexpected statement, ignoring it") continue _create_statement = create_statement[13:] table, raw_col_stats = _create_statement.split(' ',1) if raw_col_stats[0] != '(' or raw_col_stats[-1] != ')': - warning("Unexpected statement structure, ignoring it") + log.warning("Unexpected statement structure, ignoring it") continue col_stats = [stmt.strip() for stmt in self.stmnt_regex.findall(raw_col_stats[1:-1])] col_defs = [] @@ -668,7 +669,7 @@ class Updater(object): new_col_defs, new_constraints = new_data[table] for obj in old_col_defs, old_constraints, new_col_defs, new_constraints: if not isinstance(obj, tuple): - raise InternalError("Columns definitions must be tuples") + raise exceptions.InternalError("Columns definitions must be tuples") defs_create, defs_delete, ignore = getChanges(set(old_col_defs), set(new_col_defs)) constraints_create, constraints_delete, ignore = getChanges(set(old_constraints), set(new_constraints)) created_col_names = set([name.split(' ',1)[0] for name in defs_create]) @@ -706,7 +707,7 @@ class Updater(object): drop.append(self.DROP_SQL % table) if dev_version: if drop: - info("Dev version, SQL NOT EXECUTED:\n--\n%s\n--\n" % "\n".join(drop)) + log.info("Dev version, SQL NOT EXECUTED:\n--\n%s\n--\n" % "\n".join(drop)) else: ret.extend(drop) @@ -717,7 +718,7 @@ class Updater(object): cols_delete = update.get('cols delete', {}) for table in cols_delete: - info("Following columns in table [%s] are not needed anymore, but are kept for dev version: %s" % (table, ", ".join(cols_delete[table]))) + log.info("Following columns in table [%s] are not needed anymore, but are kept for dev version: %s" % (table, ", ".join(cols_delete[table]))) cols_modify = update.get('cols modify', {}) for table in cols_modify: diff --git a/src/plugins/deprecated_misc_cs.py b/src/plugins/deprecated_misc_cs.py deleted file mode 100755 index 0baff699..00000000 --- a/src/plugins/deprecated_misc_cs.py +++ /dev/null @@ -1,271 +0,0 @@ -#!/usr/bin/python -# -*- coding: utf-8 -*- - -# SAT plugin for managing xep-0045 -# Copyright (C) 2009, 2010, 2011, 2012, 2013, 2014 Jérôme Poisson (goffi@goffi.org) - -# This program is free software: you can redistribute it and/or modify -# it under the terms of the GNU Affero General Public License as published by -# the Free Software Foundation, either version 3 of the License, or -# (at your option) any later version. - -# This program is distributed in the hope that it will be useful, -# but WITHOUT ANY WARRANTY; without even the implied warranty of -# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the -# GNU Affero General Public License for more details. - -# You should have received a copy of the GNU Affero General Public License -# along with this program. If not, see . - -from sat.core.i18n import _ -from logging import debug, info, warning, error -from twisted.words.xish import domish -from twisted.internet import protocol, defer, threads, reactor -from twisted.words.protocols.jabber import client, jid, xmlstream -from twisted.words.protocols.jabber import error as jab_error -from twisted.words.protocols.jabber.xmlstream import IQ -from twisted.web.client import getPage -from sat.memory.persistent import PersistentBinaryDict -import os.path -import pdb - -from zope.interface import implements - -from wokkel import disco, iwokkel, data_form -from sat.tools.xml_tools import XMLUI -import urllib -import webbrowser - -from BeautifulSoup import BeautifulSoup -import re - -PLUGIN_INFO = { - "name": "CouchSurfing plugin", - "import_name": "CS", - "type": "Misc", - "protocols": [], - "dependencies": [], - "main": "CS_Plugin", - "handler": "no", - "description": _(u"""This plugin allow to manage your CouchSurfing account throught your SàT frontend""") -} - -AGENT = 'Salut à Toi XMPP/CS Plugin' - - -class CS_Plugin(object): - - params = """ - - - - - - - - - """ - - def __init__(self, host): - info(_("Plugin CS initialization")) - self.host = host - #parameters - host.memory.updateParams(CS_Plugin.params) - #menu - host.importMenu(_("Plugin"), "CouchSurfing", self.menuSelected, help_string=_("Launch CoushSurfing management interface")) - self.data = {} # TODO: delete cookies/data after a while - self.host.registerGeneralCB("plugin_CS_sendMessage", self.sendMessage) - self.host.registerGeneralCB("plugin_CS_showUnreadMessages", self.showUnreadMessages) - - def profileConnected(self, profile): - self.data[profile] = PersistentBinaryDict("plugin_CS", profile) - - def dataLoaded(ignore): - if not self.data[profile]: - self.data[profile] = {'cookies': {}} - - self.data[profile].load().addCallback(dataLoaded) - - def profileDisconnected(self, profile): - del self.data[profile] - - def erroCB(self, e, id): - """Called when something is going wrong when contacting CS website""" - #pdb.set_trace() - message_data = {"reason": "connection error", "message": _(u"Impossible to contact CS website, please check your login/password, connection or try again later")} - self.host.bridge.actionResult("ERROR", id, message_data) - - def menuSelected(self, id, profile): - """Called when the couchsurfing menu item is selected""" - login = self.host.memory.getParamA("Login", "CouchSurfing", profile_key=profile) - password = self.host.memory.getParamA("Password", "CouchSurfing", profile_key=profile) - if not login or not password: - message_data = {"reason": "uncomplete", "message": _(u"You have to fill your CouchSurfing login & password in parameters before using this interface")} - self.host.bridge.actionResult("ERROR", id, message_data) - return - - post_data = urllib.urlencode({'auth_login[un]': login, 'auth_login[pw]': password, 'auth_login[action]': 'Login...'}) - - self.data[profile]['cookies'] = {} - - d = getPage('http://www.couchsurfing.org/login.html', method='POST', postdata=post_data, headers={'Content-Type': 'application/x-www-form-urlencoded'}, agent=AGENT, cookies=self.data[profile]['cookies']) - d.addCallback(self.__connectionCB, id, profile) - d.addErrback(self.erroCB, id) - - #self.host.bridge.actionResult("SUPPRESS", id, {}) - -#pages parsing callbacks - - def savePage(self, name, html): - f = open('/tmp/CS_' + name + '.html', 'w') - f.write(html) - f.close() - print "page [%s] sauvee" % name - #pdb.set_trace() - - def __connectionCB(self, html, id, profile): - print 'Response received' - #self.savePage('principale',html) - soup = BeautifulSoup(html) - self.data[profile]['user_nick'] = soup.find('a', 'item_link', href='/home.html').contents[0] - self.data[profile]['user_name'] = soup.html.head.title.string.split(' - ')[1] - #unread messages - try: - self.data[profile]['unread_messages'] = int(soup.find(lambda tag: tag.name == 'div' and ('class', 'item_bubble') in tag.attrs and tag.find('a', href="/messages.html?message_status=inbox")).find(text=True)) - except: - self.data[profile]['unread_messages'] = 0 - #unread couchrequest messages - try: - self.data[profile]['unread_CR_messages'] = int(soup.find(lambda tag: tag.name == 'div' and ('class', 'item_bubble') in tag.attrs and tag.find('a', href="/couchmanager")).find(text=True)) - except: - self.data[profile]['unread_CR_messages'] = 0 - - #if we have already the list of friend, no need to make new requests - if 'friends' not in self.data[profile]: - self.data[profile]['friends'] = {} - d = getPage('http://www.couchsurfing.org/connections.html?type=myfriends&show=10000', agent=AGENT, cookies=self.data[profile]['cookies']) - d.addCallback(self.__friendsPageCB, id=id, profile=profile) - d.addErrback(self.erroCB, id) - else: - self.host.bridge.actionResult("XMLUI", id, {"type": "window", "xml": self.__buildUI(self.data[profile])}) - - def __buildUI(self, data): - """Build the XML UI of the plugin - @param data: data store for the profile""" - user_nick = data['user_nick'] - user_name = data['user_name'] - unread_mess = data['unread_messages'] - unread_CR_mess = data['unread_CR_messages'] - friends_list = data['friends'].keys() - friends_list.sort() - interface = XMLUI('window', 'tabs', title='CouchSurfing management') - interface.addCategory(_("Messages"), "vertical") - interface.addText(_("G'day %(name)s, you have %(nb_message)i unread message%(plural_mess)s and %(unread_CR_mess)s unread couch request message%(plural_CR)s\nIf you want to send a message, select the recipient(s) in the list below") % {'name': user_name, 'nb_message': unread_mess, 'plural_mess': 's' if unread_mess > 1 else '', 'unread_CR_mess': unread_CR_mess, 'plural_CR': 's' if unread_CR_mess > 1 else ''}) - if unread_mess: - interface.addButton('plugin_CS_showUnreadMessages', 'showUnreadMessages', _('Show unread message%(plural)s in external web browser') % {'plural': 's' if unread_mess > 1 else ''}) - interface.addList(friends_list, 'friends', None, style=['multi']) - interface.changeLayout('pairs') - interface.addLabel(_("Subject")) - interface.addString('subject') - interface.changeLayout('vertical') - interface.addLabel(_("Message")) - interface.addText("(use %name% for contact name and %firstname% for guessed first name)") - interface.addTextBox('message') - interface.addButton('plugin_CS_sendMessage', 'sendMessage', _('send'), fields_back=['friends', 'subject', 'message']) - #interface.addCategory(_("Events"), "vertical") #TODO: coming soon, hopefuly :) - #interface.addCategory(_("Couch search"), "vertical") - return interface.toXml() - - def __meetingPageCB(self, html): - """Called when the meeting page has been received""" - - def __friendsPageCB(self, html, id, profile): - """Called when the friends list page has been received""" - self.savePage('friends', html) - soup = BeautifulSoup(html.replace('"formtable width="400', '"formtable" width="400"')) # CS html fix #TODO: report the bug to CS dev team - friends = self.data[profile]['friends'] - for _tr in soup.findAll('tr', {'class': re.compile("^msgRow*")}): # we parse the row with friends infos - _nobr = _tr.find('nobr') # contain the friend name - friend_name = unicode(_nobr.string) - friend_link = u'http://www.couchsurfing.org' + _nobr.parent['href'] - regex_href = re.compile(r'/connections\.html\?id=([^&]+)') - a_tag = _tr.find('a', href=regex_href) - friend_id = regex_href.search(unicode(a_tag)).groups()[0] - - debug(_("CS friend found: %(friend_name)s (id: %(friend_id)s, link: %(friend_link)s)") % {'friend_name': friend_name, 'friend_id': friend_id, 'friend_link': friend_link}) - friends[friend_name] = {'link': friend_link, 'id': friend_id} - a = soup.find('td', 'barmiddle next').a # is there several pages ? - if a: - #yes, we parse the next page - d = getPage('http://www.couchsurfing.org/' + str(a['href']), agent=AGENT, cookies=self.data[profile]['cookies']) - d.addCallback(self.__friendsPageCB, id=id, profile=profile) - d.addErrback(self.erroCB, id) - else: - #no, we show the result - self.host.bridge.actionResult("XMLUI", id, {"type": "window", "xml": self.__buildUI(self.data[profile])}) - - def __sendMessage(self, answer, subject, message, data, recipient_list, id, profile): - """Send actually the message - @param subject: subject of the message - @param message: body of the message - @param data: data of the profile - @param recipient_list: list of friends names, names are removed once message is sent - @param id: id of the action - @param profile: profile who launched the action - """ - if answer: - if not 'Here is a copy of the email that was sent' in answer: - error(_("INTERNAL ERROR: no confirmation of message sent by CS, maybe the site has been modified ?")) - #TODO: throw a warning to the frontend, saying that maybe the message has not been sent and to contact dev of this plugin - #debug(_('HTML answer: %s') % answer) - if recipient_list: - recipient = recipient_list.pop() - try: - friend_id = data['friends'][recipient]['id'] - except KeyError: - error('INTERNAL ERROR: unknown friend') - return # send an error to the frontend - mess = message.replace('%name%', recipient).replace('%firstname%', recipient.split(' ')[0]) - info(_('Sending message to %s') % recipient) - debug(_("\nsubject: %(subject)s\nmessage: \n---\n%(message)s\n---\n\n") % {'subject': subject, 'message': mess}) - post_data = urllib.urlencode({'email[subject]': subject.encode('utf-8'), 'email[body]': mess.encode('utf-8'), 'email[id]': friend_id, 'email[action]': 'Send Message', 'email[replied_id]': '', 'email[couchsurf]': '', 'email[directions_to_add]': ''}) - d = getPage("http://www.couchsurfing.org/send_message.html", method='POST', postdata=post_data, headers={'Content-Type': 'application/x-www-form-urlencoded'}, agent=AGENT, cookies=data['cookies']) - d.addCallback(self.__sendMessage, subject, message, data, recipient_list, id, profile) - d.addErrback(self.erroCB, id) - else: - interface = XMLUI('window', title=_('Message sent')) # TODO: create particular actionResult for alerts ? - interface.addText(_('The message has been sent to every recipients')) - self.host.bridge.actionResult("XMLUI", id, {"type": "window", "xml": interface.toXml()}) - - def sendMessage(self, id, data, profile): - """Called to send a message to a friend - @param data: dict with the following keys: - friend: name of the recipient - subject: subject of the message - message: body of the message, with the following special keywords: - - %name%: name of the friend - - %firstname%: guessed first name of the friend (currently the first part of the name) - """ - if not data['friends']: - message_data = {"reason": "bad data", "message": _(u"There is not recipient selected for this message !")} - self.host.bridge.actionResult("ERROR", id, message_data) - return - friends = data['friends'].split('\t') - subject = data['subject'] - message = data['message'] - info(_("sending message to %(friends)s with subject [%(subject)s]" % {'friends': friends, 'subject': subject})) - self.__sendMessage(None, subject, message, self.data[profile], friends, id, profile) - - def __showUnreadMessages2(self, html, id, profile): - """Called when the inbox page has been received""" - #FIXME: that's really too fragile, only works if the unread messages are in the first page, and it would be too resources consuming for the website to DL each time all pages. In addition, the show attribute doesn't work as expected. - soup = BeautifulSoup(html) - for tag in soup.findAll(lambda tag: tag.name == 'strong' and tag.a and tag.a['href'].startswith('messages.html?message_status=inbox')): - link = "http://www.couchsurfing.org/" + str(tag.a['href']) - webbrowser.open_new_tab(link) # TODO: the web browser need to already have CS cookies (i.e. already be opened & logged on CS, or be permanently loggued), a warning to the user should be sent/or a balloon-tip - - def showUnreadMessages(self, id, data, profile): - """Called when user want to see all unread messages in the external browser""" - d = getPage("http://www.couchsurfing.org/messages.html?message_status=inbox&show=10000", agent=AGENT, cookies=self.data[profile]['cookies']) - d.addCallback(self.__showUnreadMessages2, id, profile) - d.addErrback(self.erroCB, id) diff --git a/src/plugins/plugin_adhoc_dbus.py b/src/plugins/plugin_adhoc_dbus.py index eb5892f5..fd1c16df 100644 --- a/src/plugins/plugin_adhoc_dbus.py +++ b/src/plugins/plugin_adhoc_dbus.py @@ -19,7 +19,8 @@ from sat.core.i18n import _, D_ from sat.core.constants import Const as C -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.protocols.jabber import jid from twisted.internet import defer, reactor from wokkel import data_form @@ -53,7 +54,7 @@ PLUGIN_INFO = { class AdHocDBus(object): def __init__(self, host): - info(_("plugin Ad-Hoc D-Bus initialization")) + log.info(_("plugin Ad-Hoc D-Bus initialization")) self.host = host host.bridge.addMethod("adHocDBusAddAuto", ".plugin", in_sign='sasasasasasass', out_sign='(sa(sss))', method=self._adHocDBusAddAuto, @@ -97,7 +98,7 @@ class AdHocDBus(object): @defer.inlineCallbacks def _introspect(self, methods, bus_name, proxy): - debug("introspecting path [%s]" % proxy.object_path) + log.debug("introspecting path [%s]" % proxy.object_path) introspect_xml = yield self._DBusIntrospect(proxy) el = etree.fromstring(introspect_xml) for node in el.iterchildren('node', 'interface'): @@ -108,13 +109,13 @@ class AdHocDBus(object): elif node.tag == 'interface': name = node.get('name') if any(name.startswith(ignored) for ignored in IGNORED_IFACES_START): - debug('interface [%s] is ignored' % name) + log.debug('interface [%s] is ignored' % name) continue - debug("introspecting interface [%s]" % name) + log.debug("introspecting interface [%s]" % name) for method in node.iterchildren('method'): if self._acceptMethod(method): method_name = method.get('name') - debug("method accepted: [%s]" % method_name) + log.debug("method accepted: [%s]" % method_name) methods.add((proxy.object_path, name, method_name)) def _adHocDBusAddAuto(self, prog_name, allowed_jids, allowed_groups, allowed_magics, forbidden_jids, forbidden_groups, flags, profile_key): @@ -125,13 +126,13 @@ class AdHocDBus(object): bus_names = yield self._DBusListNames() bus_names = [bus_name for bus_name in bus_names if '.' + prog_name in bus_name] if not bus_names: - info("Can't find any bus for [%s]" % prog_name) + log.info("Can't find any bus for [%s]" % prog_name) return bus_names.sort() for bus_name in bus_names: if bus_name.endswith(prog_name): break - info("bus name found: [%s]" % bus_name) + log.info("bus name found: [%s]" % bus_name) proxy = self.session_bus.get_object(bus_name, '/', introspect=False) methods = set() diff --git a/src/plugins/plugin_exp_command_export.py b/src/plugins/plugin_exp_command_export.py index d1f4f44a..9c948a29 100755 --- a/src/plugins/plugin_exp_command_export.py +++ b/src/plugins/plugin_exp_command_export.py @@ -18,7 +18,8 @@ # along with this program. If not, see . from sat.core.i18n import _ -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.protocols.jabber import jid from twisted.internet import reactor, protocol @@ -47,13 +48,13 @@ class ExportCommandProtocol(protocol.ProcessProtocol): def _clean(self, data): if not data: - error ("data should not be empty !") + log.error ("data should not be empty !") return u"" decoded = data.decode('utf-8', 'ignore')[:-1 if data[-1] == '\n' else None] return clean_ustr(decoded) def connectionMade(self): - info("connectionMade :)") + log.info("connectionMade :)") def outReceived(self, data): self.parent.host.sendMessage(self.target, self._clean(data), no_trigger=True, profile_key=self.profile) @@ -62,7 +63,7 @@ class ExportCommandProtocol(protocol.ProcessProtocol): self.parent.host.sendMessage(self.target, self._clean(data), no_trigger=True, profile_key=self.profile) def processEnded(self, reason): - info (u"process finished: %d" % (reason.value.exitCode,)) + log.info (u"process finished: %d" % (reason.value.exitCode,)) self.parent.removeProcess(self.target, self) def write(self, message): @@ -83,7 +84,7 @@ class CommandExport(object): # this is specially true if we have other triggers. def __init__(self, host): - info(_("Plugin command export initialization")) + log.info(_("Plugin command export initialization")) self.host = host self.spawned = {} # key = entity host.trigger.add("MessageReceived", self.MessageReceivedTrigger, priority=10000) @@ -109,7 +110,7 @@ class CommandExport(object): body = [e for e in message.elements() if e.name == 'body'][0] except IndexError: # do not block message without body (chat state notification...) - warning("No body element found in message, following normal behaviour") + log.warning("No body element found in message, following normal behaviour") return True mess_data = unicode(body) + '\n' @@ -141,7 +142,7 @@ class CommandExport(object): """ profile = self.host.memory.getProfileName(profile_key) if not profile: - warning("Unknown profile [%s]" % (profile,)) + log.warning("Unknown profile [%s]" % (profile,)) return for target in targets: @@ -151,7 +152,7 @@ class CommandExport(object): raise jid.InvalidFormat _jid = _jid.userhostJID() except (jid.InvalidFormat, RuntimeError): - info(u"invalid target ignored: %s" % (target,)) + log.info(u"invalid target ignored: %s" % (target,)) continue process_prot = ExportCommandProtocol(self, _jid, options, profile) self.spawned.setdefault((_jid, profile),set()).add(process_prot) diff --git a/src/plugins/plugin_exp_parrot.py b/src/plugins/plugin_exp_parrot.py index 14302c00..ca8c3f47 100755 --- a/src/plugins/plugin_exp_parrot.py +++ b/src/plugins/plugin_exp_parrot.py @@ -19,7 +19,8 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.protocols.jabber import jid from sat.core.exceptions import UnknownEntityError @@ -46,14 +47,14 @@ class Exp_Parrot(object): # /unparrot command in text commands plugin. def __init__(self, host): - info(_("Plugin Parrot initialization")) + log.info(_("Plugin Parrot initialization")) self.host = host host.trigger.add("MessageReceived", self.MessageReceivedTrigger, priority=100) #host.trigger.add("sendMessage", self.sendMessageTrigger, priority=100) try: self.host.plugins[C.TEXT_CMDS].registerTextCommands(self) except KeyError: - info(_("Text commands not available")) + log.info(_("Text commands not available")) #def sendMessageTrigger(self, mess_data, treatments, profile): # """ Deactivate other triggers if recipient is in parrot links """ @@ -64,7 +65,7 @@ class Exp_Parrot(object): # return True # # if mess_data['to'].userhostJID() in _links.values(): - # debug("Parrot link detected, skipping other triggers") + # log.debug("Parrot link detected, skipping other triggers") # raise SkipOtherTriggers def MessageReceivedTrigger(self, message, post_treat, profile): @@ -101,7 +102,7 @@ class Exp_Parrot(object): self.host.sendMessage(jid.JID(unicode(linked)), msg, None, "auto", no_trigger=True, profile_key=profile) else: - warning("No body element found in message, following normal behaviour") + log.warning("No body element found in message, following normal behaviour") return True @@ -117,7 +118,7 @@ class Exp_Parrot(object): _links = client.parrot_links = {} _links[source_jid.userhostJID()] = dest_jid - info("Parrot mode: %s will be repeated to %s" % (source_jid.userhost(), unicode(dest_jid))) + log.info("Parrot mode: %s will be repeated to %s" % (source_jid.userhost(), unicode(dest_jid))) def removeParrot(self, source_jid, profile): """Remove parrot link @@ -131,7 +132,7 @@ class Exp_Parrot(object): def cmd_parrot(self, mess_data, profile): """activate Parrot mode between 2 entities, in both directions.""" - debug("Catched parrot command") + log.debug("Catched parrot command") txt_cmd = self.host.plugins[C.TEXT_CMDS] try: @@ -153,7 +154,7 @@ class Exp_Parrot(object): def cmd_unparrot(self, mess_data, profile): """remove Parrot mode between 2 entities, in both directions.""" - debug("Catched unparrot command") + log.debug("Catched unparrot command") txt_cmd = self.host.plugins[C.TEXT_CMDS] try: diff --git a/src/plugins/plugin_exp_pipe.py b/src/plugins/plugin_exp_pipe.py index d47ce1f4..5c43e6cf 100755 --- a/src/plugins/plugin_exp_pipe.py +++ b/src/plugins/plugin_exp_pipe.py @@ -19,10 +19,11 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.xish import domish from twisted.words.protocols.jabber import jid -from twisted.words.protocols.jabber import error as jab_error +from twisted.words.protocols import jabber from twisted.internet import reactor from wokkel import data_form @@ -47,7 +48,7 @@ class Exp_Pipe(object): """This is a modified version of XEP-0096 to work with named pipes instead of files""" def __init__(self, host): - info(_("Plugin Pipe initialization")) + log.info(_("Plugin Pipe initialization")) self.host = host self.managed_stream_m = [self.host.plugins["XEP-0065"].NAMESPACE, self.host.plugins["XEP-0047"].NAMESPACE] # Stream methods managed @@ -62,12 +63,12 @@ class Exp_Pipe(object): def _kill_id(self, approval_id, profile): """Delete a waiting_for_approval id, called after timeout @param approval_id: id of _pipe_waiting_for_approval""" - info(_("SI Pipe Transfer: TimeOut reached for id %s") % approval_id) + log.info(_("SI Pipe Transfer: TimeOut reached for id %s") % approval_id) try: client = self.host.getClient(profile) del client._pipe_waiting_for_approval[approval_id] except KeyError: - warning(_("kill id called on a non existant approval id")) + log.warning(_("kill id called on a non existant approval id")) def transferRequest(self, iq_id, from_jid, si_id, si_mime_type, si_el, profile): """Called when a pipe transfer is requested @@ -77,14 +78,14 @@ class Exp_Pipe(object): @param si_mime_type: Mime type of the pipe (or default "application/octet-stream" if unknown) @param si_el: domish.Element of the request @param profile: %(doc_profile)s""" - info(_("EXP-PIPE file transfer requested")) - debug(si_el.toXml()) + log.info(_("EXP-PIPE file transfer requested")) + log.debug(si_el.toXml()) client = self.host.getClient(profile) pipe_elts = filter(lambda elt: elt.name == 'pipe', si_el.elements()) feature_elts = self.host.plugins["XEP-0020"].getFeatureElt(si_el) if not pipe_elts: - warning(_("No pipe element found")) + log.warning(_("No pipe element found")) self.host.plugins["XEP-0095"].sendBadRequestError(iq_id, from_jid, profile) return @@ -94,15 +95,15 @@ class Exp_Pipe(object): try: stream_method = self.host.plugins["XEP-0020"].negociate(feature_el, 'stream-method', self.managed_stream_m) except KeyError: - warning(_("No stream method found")) + log.warning(_("No stream method found")) self.host.plugins["XEP-0095"].sendBadRequestError(iq_id, from_jid, profile) return if not stream_method: - warning(_("Can't find a valid stream method")) + log.warning(_("Can't find a valid stream method")) self.host.plugins["XEP-0095"].sendFailedError(iq_id, from_jid, profile) return else: - warning(_("No feature element found")) + log.warning(_("No feature element found")) self.host.plugins["XEP-0095"].sendBadRequestError(iq_id, from_jid, profile) return @@ -125,7 +126,7 @@ class Exp_Pipe(object): try: dest_path = frontend_data['dest_path'] except KeyError: - error(_('dest path not found in frontend_data')) + log.error(_('dest path not found in frontend_data')) del(client._pipe_waiting_for_approval[sid]) return if stream_method == self.host.plugins["XEP-0065"].NAMESPACE: @@ -135,7 +136,7 @@ class Exp_Pipe(object): file_obj = open(dest_path, 'w+') self.host.plugins["XEP-0047"].prepareToReceive(jid.JID(data['from']), sid, file_obj, None, self._transferSucceeded, self._transferFailed, profile) else: - error(_("Unknown stream method, this should not happen at this stage, cancelling transfer")) + log.error(_("Unknown stream method, this should not happen at this stage, cancelling transfer")) del(client._pipe_waiting_for_approval[sid]) return @@ -145,7 +146,7 @@ class Exp_Pipe(object): misc_elts.append(domish.Element((PROFILE, "file"))) self.host.plugins["XEP-0095"].acceptStream(data["id"], data['from'], feature_elt, misc_elts, profile) else: - debug(_("Transfer [%s] refused"), sid) + log.debug(_("Transfer [%s] refused"), sid) self.host.plugins["XEP-0095"].sendRejectedError(data["id"], data['from'], profile=profile) del(client._pipe_waiting_for_approval[sid]) @@ -154,7 +155,7 @@ class Exp_Pipe(object): @param id: stream id""" client = self.host.getClient(profile) file_obj.close() - info(_('Transfer %s successfuly finished') % sid) + log.info(_('Transfer %s successfuly finished') % sid) del(client._pipe_waiting_for_approval[sid]) def _transferFailed(self, sid, file_obj, stream_method, reason, profile): @@ -163,41 +164,41 @@ class Exp_Pipe(object): @param reason: can be TIMEOUT, IO_ERROR, PROTOCOL_ERROR""" client = self.host.getClient(profile) data, timeout, stream_method, failed_methods, profile = client._pipe_waiting_for_approval[sid] - warning(_('Transfer %(id)s failed with stream method %(s_method)s') % {'id': sid, + log.warning(_('Transfer %(id)s failed with stream method %(s_method)s') % {'id': sid, 's_method': stream_method}) # filepath = file_obj.name file_obj.close() #TODO: session remenber (within a time limit) when a stream method fail, and avoid that stream method with full jid for the rest of the session - warning(_("All stream methods failed, can't transfer the file")) + log.warning(_("All stream methods failed, can't transfer the file")) del(client._pipe_waiting_for_approval[sid]) def pipeCb(self, filepath, sid, profile, IQ): if IQ['type'] == "error": - stanza_err = jab_error.exceptionFromStanza(IQ) + stanza_err = jabber.error.exceptionFromStanza(IQ) if stanza_err.code == '403' and stanza_err.condition == 'forbidden': - debug(_("Pipe transfer refused by %s") % IQ['from']) + log.debug(_("Pipe transfer refused by %s") % IQ['from']) self.host.bridge.newAlert(_("The contact %s refused your pipe stream") % IQ['from'], _("Pipe stream refused"), "INFO", profile) else: - warning(_("Error during pipe stream transfer with %s") % IQ['from']) + log.warning(_("Error during pipe stream transfer with %s") % IQ['from']) self.host.bridge.newAlert(_("Something went wrong during the pipe stream session intialisation with %s") % IQ['from'], _("Pipe stream error"), "ERROR", profile) return si_elt = IQ.firstChildElement() if IQ['type'] != "result" or not si_elt or si_elt.name != "si": - error(_("Protocol error during file transfer")) + log.error(_("Protocol error during file transfer")) return feature_elts = self.host.plugins["XEP-0020"].getFeatureElt(si_elt) if not feature_elts: - warning(_("No feature element")) + log.warning(_("No feature element")) return choosed_options = self.host.plugins["XEP-0020"].getChoosedOptions(feature_elts[0]) try: stream_method = choosed_options["stream-method"] except KeyError: - warning(_("No stream method choosed")) + log.warning(_("No stream method choosed")) return if stream_method == self.host.plugins["XEP-0065"].NAMESPACE: @@ -211,7 +212,7 @@ class Exp_Pipe(object): file_obj = open(filepath, 'r') # XXX: we have to be sure that filepath is well opened, as reading can block it self.host.plugins["XEP-0047"].startStream(file_obj, jid.JID(IQ['from']), sid, None, self.sendSuccessCb, self.sendFailureCb, None, profile) else: - warning(_("Invalid stream method received")) + log.warning(_("Invalid stream method received")) def pipeOut(self, to_jid, filepath, data={}, profile_key=C.PROF_KEY_NONE): """send a file using EXP-PIPE @@ -223,7 +224,7 @@ class Exp_Pipe(object): """ profile = self.host.memory.getProfileName(profile_key) if not profile: - warning(_("Trying to send a file from an unknown profile")) + log.warning(_("Trying to send a file from an unknown profile")) return "" feature_elt = self.host.plugins["XEP-0020"].proposeFeatures({'stream-method': self.managed_stream_m}) @@ -237,9 +238,9 @@ class Exp_Pipe(object): return sid def sendSuccessCb(self, sid, file_obj, stream_method, profile): - info(_('Transfer %s successfuly finished') % sid) + log.info(_('Transfer %s successfuly finished') % sid) file_obj.close() def sendFailureCb(self, sid, file_obj, stream_method, reason, profile): file_obj.close() - warning(_('Transfer %(id)s failed with stream method %(s_method)s %(profile)s') % {'id': sid, "s_method": stream_method, "profile": profile}) + log.warning(_('Transfer %(id)s failed with stream method %(s_method)s %(profile)s') % {'id': sid, "s_method": stream_method, "profile": profile}) diff --git a/src/plugins/plugin_misc_account.py b/src/plugins/plugin_misc_account.py index 951c781f..12722617 100755 --- a/src/plugins/plugin_misc_account.py +++ b/src/plugins/plugin_misc_account.py @@ -18,7 +18,8 @@ # along with this program. If not, see . from sat.core.i18n import _, D_ -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from sat.core import exceptions from twisted.internet import reactor, defer, protocol from os.path import join, dirname @@ -88,10 +89,10 @@ class ProsodyRegisterProtocol(protocol.ProcessProtocol): def processEnded(self, reason): if (reason.value.exitCode == 0): - info(_('Prosody command succeed')) + log.info(_('Prosody command succeed')) self.deferred.callback(None) else: - error(_(u"Can't complete Prosody command (error code: %(code)d): %(message)s") % {'code': reason.value.exitCode, 'message': self.data}) + log.error(_(u"Can't complete Prosody command (error code: %(code)d): %(message)s") % {'code': reason.value.exitCode, 'message': self.data}) self.deferred.errback(Failure(exceptions.InternalError)) @classmethod @@ -117,7 +118,7 @@ class MiscAccount(object): # only focused on Prosody) is planed def __init__(self, host): - info(_(u"Plugin Account initialization")) + log.info(_(u"Plugin Account initialization")) self.host = host host.bridge.addMethod("registerSatAccount", ".plugin", in_sign='sss', out_sign='', method=self._registerAccount, async=True) host.bridge.addMethod("getNewAccountDomain", ".plugin", in_sign='', out_sign='s', method=self.getNewAccountDomain, async=False) @@ -126,10 +127,10 @@ class MiscAccount(object): if self._prosody_path is None: paths = which(self.getConfig('prosodyctl')) if not paths: - error(_("Can't find %s") % (self.getConfig('prosodyctl'), )) + log.error(_("Can't find %s") % (self.getConfig('prosodyctl'), )) else: self._prosody_path = dirname(paths[0]) - info(_('Prosody path found: %s') % (self._prosody_path, )) + log.info(_('Prosody path found: %s') % (self._prosody_path, )) self.__account_cb_id = host.registerCallback(self._accountDialogCb, with_data=True) self.__delete_account_id = host.registerCallback(self.__deleteAccountCb, with_data=True) @@ -193,7 +194,7 @@ class MiscAccount(object): def email_ko(ignore): #TODO: return error code to user - error("Failed to send email to %s" % email) + log.error("Failed to send email to %s" % email) body = (u"""Welcome to Libervia, a Salut à Toi project part diff --git a/src/plugins/plugin_misc_groupblog.py b/src/plugins/plugin_misc_groupblog.py index a7ec4128..8d004778 100755 --- a/src/plugins/plugin_misc_groupblog.py +++ b/src/plugins/plugin_misc_groupblog.py @@ -19,7 +19,8 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.internet import defer from twisted.words.protocols.jabber import jid from twisted.words.xish.domish import Element, generateElementsNamed @@ -83,7 +84,7 @@ class GroupBlog(object): """This class use a SàT PubSub Service to manage access on microblog""" def __init__(self, host): - info(_("Group blog plugin initialization")) + log.info(_("Group blog plugin initialization")) self.host = host host.bridge.addMethod("sendGroupBlog", ".plugin", in_sign='sassa{ss}s', out_sign='', @@ -157,18 +158,18 @@ class GroupBlog(object): #we first check that we have a item-access pubsub server if not hasattr(client, "item_access_pubsub"): - debug(_('Looking for item-access powered pubsub server')) + log.debug(_('Looking for item-access powered pubsub server')) #we don't have any pubsub server featuring item access yet item_access_pubsubs = yield self.host.findFeaturesSet((NS_PUBSUB_AUTO_CREATE, NS_PUBSUB_CREATOR_JID_CHECK), "pubsub", "service", profile_key=profile) # item_access_pubsubs = yield self.host.findFeaturesSet((NS_PUBSUB_ITEM_ACCESS, NS_PUBSUB_AUTO_CREATE, NS_PUBSUB_CREATOR_JID_CHECK), "pubsub", "service", profile_key=profile) try: client.item_access_pubsub = item_access_pubsubs.pop() - info(_("item-access powered pubsub service found: [%s]") % client.item_access_pubsub.full()) + log.info(_("item-access powered pubsub service found: [%s]") % client.item_access_pubsub.full()) except KeyError: client.item_access_pubsub = None if not client.item_access_pubsub: - error(_("No item-access powered pubsub server found, can't use group blog")) + log.error(_("No item-access powered pubsub server found, can't use group blog")) raise NoCompatiblePubSubServerFound defer.returnValue((profile, client)) @@ -186,7 +187,7 @@ class GroupBlog(object): if (not (origin_host) or len(event_host) < len(origin_host) or event_host[-len(origin_host):] != origin_host): - warning("Host incoherence between %s and %s (hack attempt ?)" % (unicode(event.sender), + log.warning("Host incoherence between %s and %s (hack attempt ?)" % (unicode(event.sender), unicode(publisher))) return False @@ -243,7 +244,7 @@ class GroupBlog(object): try: microblog_data["groups"] = '\n'.join(form.fields[P.OPT_ROSTER_GROUPS_ALLOWED].values) except KeyError: - warning("No group found for roster access-model") + log.warning("No group found for roster access-model") microblog_data["groups"] = '' break @@ -317,7 +318,7 @@ class GroupBlog(object): elif access_type == "JID": raise NotImplementedError else: - error(_("Unknown access_type")) + log.error(_("Unknown access_type")) raise BadAccessTypeError defer_blog = self.host.plugins["XEP-0060"].publish(service, node_name, items=[mblog_item], profile_key=client.profile) @@ -373,7 +374,7 @@ class GroupBlog(object): elif access_type == "JID": raise NotImplementedError else: - error(_("Unknown access type")) + log.error(_("Unknown access type")) raise BadAccessTypeError return self._initialise(profile_key).addCallback(initialised) @@ -395,10 +396,10 @@ class GroupBlog(object): # remove the associated comments node comments_service, comments_node = self.host.plugins["XEP-0277"].parseCommentUrl(comments) d = self.host.plugins["XEP-0060"].deleteNode(comments_service, comments_node, profile_key=profile) - d.addErrback(lambda failure: error("Deletion of node %s failed: %s" % (comments_node, failure.getErrorMessage()))) + d.addErrback(lambda failure: log.error("Deletion of node %s failed: %s" % (comments_node, failure.getErrorMessage()))) # remove the item itself d = self.host.plugins["XEP-0060"].retractItems(service_jid, node, [item_id], profile_key=profile) - d.addErrback(lambda failure: error("Deletion of item %s from %s failed: %s" % (item_id, node, failure.getErrorMessage()))) + d.addErrback(lambda failure: log.error("Deletion of item %s from %s failed: %s" % (item_id, node, failure.getErrorMessage()))) return d def notify(d): @@ -447,7 +448,7 @@ class GroupBlog(object): self.__fillCommentsElement(mblog_data, entry_id, node, service_jid) entry_d = self.host.plugins["XEP-0277"].data2entry(mblog_data, profile) entry_d.addCallback(lambda mblog_item: self.host.plugins["XEP-0060"].publish(service_jid, node, items=[mblog_item], profile_key=profile)) - entry_d.addErrback(lambda failure: error("Modification of %s failed: %s" % (pub_data, failure.getErrorMessage()))) + entry_d.addErrback(lambda failure: log.error("Modification of %s failed: %s" % (pub_data, failure.getErrorMessage()))) return entry_d return self._initialise(profile_key).addCallback(initialised) @@ -501,7 +502,7 @@ class GroupBlog(object): self.host.plugins["XEP-0060"].subscribe(jid.JID(gbdata["comments_service"]), gbdata["comments_node"], profile_key=client.profile) except KeyError: - warning("Missing key for comments") + log.warning("Missing key for comments") defer.returnValue(ret) def __getGroupBlogs(self, pub_jid_s, max_items=10, item_ids=None, profile_key=C.PROF_KEY_NONE): @@ -775,8 +776,8 @@ class GroupBlog(object): main_node = self.getNodeName(jid_) d = self.host.plugins["XEP-0060"].deleteNode(service, main_node, profile_key=profile) - d.addCallback(lambda dummy: info(_("All microblog's main items from %s have been deleted!") % jid_.userhost())) - d.addErrback(lambda failure: error(_("Deletion of node %(node)s failed: %(message)s") % + d.addCallback(lambda dummy: log.info(_("All microblog's main items from %s have been deleted!") % jid_.userhost())) + d.addErrback(lambda failure: log.error(_("Deletion of node %(node)s failed: %(message)s") % {'node': main_node, 'message': failure.getErrorMessage()})) return d @@ -799,7 +800,7 @@ class GroupBlog(object): main_node = self.getNodeName(jid_) d = self.host.plugins["XEP-0060"].getItems(service, main_node, profile_key=profile) d.addCallback(getComments, client) - d.addErrback(lambda failure, main_node: error(_("Retrieval of items for node %(node)s failed: %(message)s") % + d.addErrback(lambda failure, main_node: log.error(_("Retrieval of items for node %(node)s failed: %(message)s") % {'node': main_node, 'message': failure.getErrorMessage()}), main_node) blogs.append(d) @@ -822,7 +823,7 @@ class GroupBlog(object): service, node = self.host.plugins['XEP-0277'].parseCommentUrl(href) d = self.host.plugins["XEP-0060"].getItems(service, node, profile_key=profile_key) d.addCallback(lambda items, service, node: (service, node, items), service, node) - d.addErrback(lambda failure, node: error(_("Retrieval of comments for node %(node)s failed: %(message)s") % + d.addErrback(lambda failure, node: log.error(_("Retrieval of comments for node %(node)s failed: %(message)s") % {'node': node, 'message': failure.getErrorMessage()}), node) comments.append(d) dlist = defer.DeferredList(comments) @@ -854,9 +855,9 @@ class GroupBlog(object): deletions = [] if item_ids: # remove the comments of the user on the given post d = self.host.plugins['XEP-0060'].retractItems(service, node_id, item_ids, profile_key=profile_key) - d.addCallback(lambda dummy, node_id: debug(_('Comments of user %(user)s in node %(node)s have been retracted') % + d.addCallback(lambda dummy, node_id: log.debug(_('Comments of user %(user)s in node %(node)s have been retracted') % {'user': user_jid_s, 'node': node_id}), node_id) - d.addErrback(lambda failure, node_id: error(_("Retraction of comments from %(user)s in node %(node)s failed: %(message)s") % + d.addErrback(lambda failure, node_id: log.error(_("Retraction of comments from %(user)s in node %(node)s failed: %(message)s") % {'user': user_jid_s, 'node': node_id, 'message': failure.getErrorMessage()}), node_id) deletions.append(d) return defer.DeferredList(deletions) diff --git a/src/plugins/plugin_misc_imap.py b/src/plugins/plugin_misc_imap.py index 05d5f964..09438465 100755 --- a/src/plugins/plugin_misc_imap.py +++ b/src/plugins/plugin_misc_imap.py @@ -18,20 +18,17 @@ # along with this program. If not, see . from sat.core.i18n import _ -from logging import debug, info, error -import warnings +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.internet import protocol, defer -from twisted.words.protocols.jabber import error as jab_error from twisted.cred import portal, checkers, credentials from twisted.cred import error as cred_error from twisted.mail import imap4 from twisted.python import failure from email.parser import Parser -import email.message import os from cStringIO import StringIO from twisted.internet import reactor -import pdb from zope.interface import implements @@ -61,14 +58,14 @@ class IMAP_server(object): """ def __init__(self, host): - info(_("Plugin Imap Server initialization")) + log.info(_("Plugin Imap Server initialization")) self.host = host #parameters host.memory.updateParams(self.params) port = int(self.host.memory.getParamA("IMAP Port", "Mail Server")) - info(_("Launching IMAP server on port %d"), port) + log.info(_("Launching IMAP server on port %d") % port) self.server_factory = ImapServerFactory(self.host) reactor.listenTCP(port, self.server_factory) @@ -78,7 +75,7 @@ class Message(object): implements(imap4.IMessage) def __init__(self, uid, flags, mess_fp): - debug('Message Init') + log.debug('Message Init') self.uid = uid self.flags = flags self.mess_fp = mess_fp @@ -87,21 +84,21 @@ class Message(object): def getUID(self): """Retrieve the unique identifier associated with this message. """ - debug('getUID (message)') + log.debug('getUID (message)') return self.uid def getFlags(self): """Retrieve the flags associated with this message. @return: The flags, represented as strings. """ - debug('getFlags') + log.debug('getFlags') return self.flags def getInternalDate(self): """Retrieve the date internally associated with this message. @return: An RFC822-formatted date string. """ - debug('getInternalDate') + log.debug('getInternalDate') return self.message['Date'] def getHeaders(self, negate, *names): @@ -111,7 +108,7 @@ class Message(object): should be omitted from the return value, rather than included. @return: A mapping of header field names to header field values """ - debug('getHeaders %s - %s' % (negate, names)) + log.debug('getHeaders %s - %s' % (negate, names)) final_dict = {} to_check = [name.lower() for name in names] for header in self.message.keys(): @@ -123,20 +120,20 @@ class Message(object): def getBodyFile(self): """Retrieve a file object containing only the body of this message. """ - debug('getBodyFile') + log.debug('getBodyFile') return StringIO(self.message.get_payload()) def getSize(self): """Retrieve the total size, in octets, of this message. """ - debug('getSize') + log.debug('getSize') self.mess_fp.seek(0, os.SEEK_END) return self.mess_fp.tell() def isMultipart(self): """Indicate whether this message has subparts. """ - debug('isMultipart') + log.debug('isMultipart') return False def getSubPart(self, part): @@ -144,7 +141,7 @@ class Message(object): @param part: The number of the part to retrieve, indexed from 0. @return: The specified sub-part. """ - debug('getSubPart') + log.debug('getSubPart') return TypeError @@ -154,14 +151,14 @@ class SatMailbox(object): def __init__(self, host, name, profile): self.host = host self.listeners = set() - debug('Mailbox init (%s)', name) + log.debug('Mailbox init (%s)', name) if name != "INBOX": raise imap4.MailboxException("Only INBOX is managed for the moment") self.mailbox = self.host.plugins["Maildir"].accessMessageBox(name, self.newMessage, profile) def newMessage(self): """Called when a new message is in the mailbox""" - debug("newMessage signal received") + log.debug("newMessage signal received") nb_messages = self.getMessageCount() for listener in self.listeners: listener.newMessages(nb_messages, None) @@ -169,13 +166,13 @@ class SatMailbox(object): def getUIDValidity(self): """Return the unique validity identifier for this mailbox. """ - debug('getUIDValidity') + log.debug('getUIDValidity') return 0 def getUIDNext(self): """Return the likely UID for the next message added to this mailbox. """ - debug('getUIDNext') + log.debug('getUIDNext') return self.mailbox.getNextUid() def getUID(self, message): @@ -183,41 +180,41 @@ class SatMailbox(object): @param message: The message sequence number @return: The UID of the message. """ - debug('getUID (%i)' % message) + log.debug('getUID (%i)' % message) #return self.mailbox.getUid(message-1) #XXX: it seems that this method get uid and not message sequence number return message def getMessageCount(self): """Return the number of messages in this mailbox. """ - debug('getMessageCount') + log.debug('getMessageCount') ret = self.mailbox.getMessageCount() - debug("count = %i" % ret) + log.debug("count = %i" % ret) return ret def getRecentCount(self): """Return the number of messages with the 'Recent' flag. """ - debug('getRecentCount') + log.debug('getRecentCount') return len(self.mailbox.getMessageIdsWithFlag('\\Recent')) def getUnseenCount(self): """Return the number of messages with the 'Unseen' flag. """ - debug('getUnseenCount') + log.debug('getUnseenCount') return self.getMessageCount() - len(self.mailbox.getMessageIdsWithFlag('\\SEEN')) def isWriteable(self): """Get the read/write status of the mailbox. @return: A true value if write permission is allowed, a false value otherwise. """ - debug('isWriteable') + log.debug('isWriteable') return True def destroy(self): """Called before this mailbox is deleted, permanently. """ - debug('destroy') + log.debug('destroy') def requestStatus(self, names): """Return status information about this mailbox. @@ -229,7 +226,7 @@ class SatMailbox(object): information up would be costly, a deferred whose callback will eventually be passed this dictionary is returned instead. """ - debug('requestStatus') + log.debug('requestStatus') return imap4.statusRequestHelper(self, names) def addListener(self, listener): @@ -239,7 +236,7 @@ class SatMailbox(object): @param listener: An object to add to the set of those which will be notified when the contents of this mailbox change. """ - debug('addListener %s' % listener) + log.debug('addListener %s' % listener) self.listeners.add(listener) def removeListener(self, listener): @@ -252,7 +249,7 @@ class SatMailbox(object): @raise ValueError: Raised when the given object is not a listener for this mailbox. """ - debug('removeListener') + log.debug('removeListener') if listener in self.listeners: self.listeners.remove(listener) else: @@ -267,7 +264,7 @@ class SatMailbox(object): id if the message is added successfully and whose errback is invoked otherwise. """ - debug('addMessage') + log.debug('addMessage') raise imap4.MailboxException("Client message addition not implemented yet") def expunge(self): @@ -275,7 +272,7 @@ class SatMailbox(object): @return: The list of message sequence numbers which were deleted, or a Deferred whose callback will be invoked with such a list. """ - debug('expunge') + log.debug('expunge') self.mailbox.removeDeleted() def fetch(self, messages, uid): @@ -284,13 +281,13 @@ class SatMailbox(object): about @param uid: If true, the IDs specified in the query are UIDs; """ - debug('fetch (%s, %s)' % (messages, uid)) + log.debug('fetch (%s, %s)' % (messages, uid)) if uid: messages.last = self.mailbox.getMaxUid() messages.getnext = self.mailbox.getNextExistingUid for mess_uid in messages: if mess_uid is None: - debug('stopping iteration') + log.debug('stopping iteration') raise StopIteration try: yield (mess_uid, Message(mess_uid, self.mailbox.getFlagsUid(mess_uid), self.mailbox.getMessageUid(mess_uid))) @@ -318,7 +315,7 @@ class SatMailbox(object): been performed, or a Deferred whose callback will be invoked with such a dict. """ - debug('store') + log.debug('store') flags = [flag.upper() for flag in flags] @@ -361,13 +358,13 @@ class SatMailbox(object): Flags with the \\ prefix are reserved for use as system flags. @return: A list of the flags that can be set on messages in this mailbox. """ - debug('getFlags') + log.debug('getFlags') return ['\\SEEN', '\\ANSWERED', '\\FLAGGED', '\\DELETED', '\\DRAFT'] # TODO: add '\\RECENT' def getHierarchicalDelimiter(self): """Get the character which delimits namespaces for in this mailbox. """ - debug('getHierarchicalDelimiter') + log.debug('getHierarchicalDelimiter') return '.' @@ -375,12 +372,12 @@ class ImapSatAccount(imap4.MemoryAccount): #implements(imap4.IAccount) def __init__(self, host, profile): - debug("ImapAccount init") + log.debug("ImapAccount init") self.host = host self.profile = profile imap4.MemoryAccount.__init__(self, profile) self.addMailbox("Inbox") # We only manage Inbox for the moment - debug('INBOX added') + log.debug('INBOX added') def _emptyMailbox(self, name, id): return SatMailbox(self.host, name, self.profile) @@ -393,7 +390,7 @@ class ImapRealm(object): self.host = host def requestAvatar(self, avatarID, mind, *interfaces): - debug('requestAvatar') + log.debug('requestAvatar') profile = avatarID.decode('utf-8') if imap4.IAccount not in interfaces: raise NotImplementedError @@ -436,13 +433,13 @@ class ImapServerFactory(protocol.ServerFactory): self.host = host def startedConnecting(self, connector): - debug(_("IMAP server connection started")) + log.debug(_("IMAP server connection started")) def clientConnectionLost(self, connector, reason): - debug(_("IMAP server connection lost (reason: %s)"), reason) + log.debug(_("IMAP server connection lost (reason: %s)"), reason) def buildProtocol(self, addr): - debug("Building protocol") + log.debug("Building protocol") prot = protocol.ServerFactory.buildProtocol(self, addr) prot.portal = portal.Portal(ImapRealm(self.host)) prot.portal.registerChecker(SatProfileCredentialChecker(self.host)) diff --git a/src/plugins/plugin_misc_maildir.py b/src/plugins/plugin_misc_maildir.py index 01cd8e3f..69df2e88 100755 --- a/src/plugins/plugin_misc_maildir.py +++ b/src/plugins/plugin_misc_maildir.py @@ -19,11 +19,12 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, error +from sat.core.log import getLogger +log = getLogger(__name__) import warnings warnings.filterwarnings('ignore', 'the MimeWriter', DeprecationWarning, 'twisted') # FIXME: to be removed, see http://twistedmatrix.com/trac/ticket/4038 from twisted.internet import protocol -from twisted.words.protocols.jabber import error as jab_error +from twisted.words.protocols import jabber from twisted.cred import portal, checkers from twisted.mail import imap4, maildir from email.parser import Parser @@ -58,7 +59,7 @@ class MaildirError(Exception): class MaildirBox(object): def __init__(self, host): - info(_("Plugin Maildir initialization")) + log.info(_("Plugin Maildir initialization")) self.host = host self.__observed = {} @@ -126,7 +127,7 @@ class MaildirBox(object): @param mailboxUser: MailboxUser instance""" if boxname not in self.__mailboxes: err_msg = _("Trying to remove an mailboxUser not referenced") - error(_("INTERNAL ERROR: ") + err_msg) + log.error(_("INTERNAL ERROR: ") + err_msg) raise MaildirError(err_msg) assert self.__mailboxes[profile][boxname] == mailboxUser del self.__mailboxes[profile][boxname] @@ -145,7 +146,7 @@ class MaildirBox(object): return self.data[profile][boxname] # the boxname MUST exist in the data except KeyError: err_msg = _("Boxname doesn't exist in internal data") - error(_("INTERNAL ERROR: ") + err_msg) + log.error(_("INTERNAL ERROR: ") + err_msg) raise MaildirError(err_msg) def getUid(self, boxname, message_id, profile): @@ -284,21 +285,21 @@ class MaildirBox(object): @param signal: which signal was observed by the caller""" if (profile, boxname) not in self.__observed: err_msg = _("Trying to remove an observer for an inexistant mailbox") - error(_("INTERNAL ERROR: ") + err_msg) + log.error(_("INTERNAL ERROR: ") + err_msg) raise MaildirError(err_msg) if signal not in self.__observed[(profile, boxname)]: err_msg = _("Trying to remove an inexistant observer, no observer for this signal") - error(_("INTERNAL ERROR: ") + err_msg) + log.error(_("INTERNAL ERROR: ") + err_msg) raise MaildirError(err_msg) if not callback in self.__observed[(profile, boxname)][signal]: err_msg = _("Trying to remove an inexistant observer") - error(_("INTERNAL ERROR: ") + err_msg) + log.error(_("INTERNAL ERROR: ") + err_msg) raise MaildirError(err_msg) self.__observed[(profile, boxname)][signal].remove(callback) def emitSignal(self, profile, boxname, signal_name): """Emit the signal to observer""" - debug('emitSignal %s %s %s' % (profile, boxname, signal_name)) + log.debug('emitSignal %s %s %s' % (profile, boxname, signal_name)) try: for observer_cb in self.__observed[(profile, boxname)][signal_name]: observer_cb() @@ -334,7 +335,7 @@ class MailboxUser(object): @param profile: real profile (ie not a profile_key) THIS OBJECT MUST NOT BE USED DIRECTLY: use MaildirBox.accessMessageBox instead""" if _maildir._checkBoxReference(name, profile): - error("INTERNAL ERROR: MailboxUser MUST NOT be instancied directly") + log.error("INTERNAL ERROR: MailboxUser MUST NOT be instancied directly") raise MaildirError('double MailboxUser instanciation') if name != "INBOX": raise NotImplementedError @@ -352,7 +353,7 @@ class MailboxUser(object): self.__uid_table_update() if observer: - debug("adding observer for %s (%s)" % (name, profile)) + log.debug("adding observer for %s (%s)" % (name, profile)) self.maildir.addObserver(observer, profile, name, "NEW_MESSAGE") def __uid_table_update(self): @@ -365,7 +366,7 @@ class MailboxUser(object): def __del__(self): if self.observer: - debug("removing observer for %s" % self.name) + log.debug("removing observer for %s" % self.name) self._maildir.removeObserver(self.observer, self.name, "NEW_MESSAGE") self.maildir._removeBoxAccess(self.name, self, profile=self.profile) diff --git a/src/plugins/plugin_misc_quiz.py b/src/plugins/plugin_misc_quiz.py index e554db41..ea462c69 100755 --- a/src/plugins/plugin_misc_quiz.py +++ b/src/plugins/plugin_misc_quiz.py @@ -19,11 +19,12 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.xish import domish from twisted.internet import protocol, defer, threads, reactor from twisted.words.protocols.jabber import client, jid, xmlstream -from twisted.words.protocols.jabber import error as jab_error +from twisted.words.protocols import jabber from twisted.words.protocols.jabber.xmlstream import IQ import random @@ -54,7 +55,7 @@ class Quiz(object): self.__class__ = type(self.__class__.__name__, (self.__class__, RoomGame, object), {}) def __init__(self, host): - info(_("Plugin Quiz initialization")) + log.info(_("Plugin Quiz initialization")) self.inheritFromRoomGame(host) RoomGame._init_(self, host, PLUGIN_INFO, (NS_QG, QG_TAG), game_init={'stage': None}, player_init={'score': 0}) host.bridge.addMethod("quizGameLaunch", ".plugin", in_sign='asss', out_sign='', method=self.prepareRoom) # args: players, room_jid, profile @@ -180,9 +181,9 @@ class Quiz(object): """Called when a player give an answer""" profile = self.host.memory.getProfileName(profile_key) if not profile: - error(_("profile %s is unknown") % profile_key) + log.error(_("profile %s is unknown") % profile_key) return - debug('new player answer (%(profile)s): %(answer)s' % {'profile': profile, 'answer': answer}) + log.debug('new player answer (%(profile)s): %(answer)s' % {'profile': profile, 'answer': answer}) mess = self.createGameElt(jid.JID(referee)) answer_elt = mess.firstChildElement().addElement('player_answer') answer_elt['player'] = player @@ -280,7 +281,7 @@ Attention, tu es prêt ?""")} status = self.games[room_jid.userhost()]['status'] nb_players = len(self.games[room_jid.userhost()]['players']) status[player] = 'ready' - debug(_('Player %(player)s is ready to start [status: %(status)s]') % {'player': player, 'status': status}) + log.debug(_('Player %(player)s is ready to start [status: %(status)s]') % {'player': player, 'status': status}) if status.values().count('ready') == nb_players: # everybody is ready, we can start the game self.newGame(room_jid, profile) @@ -328,4 +329,4 @@ Attention, tu es prêt ?""")} self.host.bridge.quizGameTimerRestarted(room_jid.userhost(), int(elt['time_left']), profile) else: - error(_('Unmanaged game element: %s') % elt.name) + log.error(_('Unmanaged game element: %s') % elt.name) diff --git a/src/plugins/plugin_misc_radiocol.py b/src/plugins/plugin_misc_radiocol.py index acf76253..38d236e0 100755 --- a/src/plugins/plugin_misc_radiocol.py +++ b/src/plugins/plugin_misc_radiocol.py @@ -18,7 +18,8 @@ # along with this program. If not, see . from sat.core.i18n import _, D_ -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.xish import domish from twisted.internet import reactor from twisted.words.protocols.jabber import jid @@ -63,7 +64,7 @@ class Radiocol(object): self.__class__ = type(self.__class__.__name__, (self.__class__, RoomGame, object), {}) def __init__(self, host): - info(_("Radio collective initialization")) + log.info(_("Radio collective initialization")) self.inheritFromRoomGame(host) RoomGame._init_(self, host, PLUGIN_INFO, (NC_RADIOCOL, RADIOC_TAG), game_init={'queue': [], 'upload': True, 'playing': None, 'playing_time': 0, 'to_delete': {}}) @@ -135,7 +136,7 @@ class Radiocol(object): # ==> unlink done the Q&D way with the same host trick (see above) radio_data = self.games[room_jid.userhost()] if len(radio_data['players']) == 0: - debug(_('No more participants in the radiocol: cleaning data')) + log.debug(_('No more participants in the radiocol: cleaning data')) radio_data['queue'] = [] for filename in radio_data['to_delete']: self.deleteFile(filename, radio_data) @@ -171,14 +172,14 @@ class Radiocol(object): try: file_to_delete = radio_data['to_delete'][filename] except KeyError: - error(_("INTERNAL ERROR: can't find full path of the song to delete")) + log.error(_("INTERNAL ERROR: can't find full path of the song to delete")) return False else: file_to_delete = filename try: unlink(file_to_delete) except OSError: - error(_("INTERNAL ERROR: can't find %s on the file system" % file_to_delete)) + log.error(_("INTERNAL ERROR: can't find %s on the file system" % file_to_delete)) return False return True @@ -241,7 +242,7 @@ class Radiocol(object): # songs in queue. We can now start the party :) self.playNext(room_jid, profile) else: - error(_('Unmanaged game element: %s') % elt.name) + log.error(_('Unmanaged game element: %s') % elt.name) def getSyncDataForPlayer(self, room_jid_s, nick): game_data = self.games[room_jid_s] diff --git a/src/plugins/plugin_misc_room_game.py b/src/plugins/plugin_misc_room_game.py index 9b36cea2..3c276bcd 100644 --- a/src/plugins/plugin_misc_room_game.py +++ b/src/plugins/plugin_misc_room_game.py @@ -19,7 +19,8 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.protocols.jabber.jid import JID from twisted.words.xish import domish from twisted.internet import defer @@ -199,7 +200,7 @@ class RoomGame(object): break if not auth and (verbose or _DEBUG): - debug(_("%(user)s not allowed to join the game %(game)s in %(room)s") % {'user': user_jid_s or nick, 'game': self.name, 'room': room_jid_s}) + log.debug(_("%(user)s not allowed to join the game %(game)s in %(room)s") % {'user': user_jid_s or nick, 'game': self.name, 'room': room_jid_s}) return auth def _updatePlayers(self, room_jid_s, nicks, sync, profile): @@ -335,7 +336,7 @@ class RoomGame(object): elif self.invite_mode == self.FROM_PLAYERS: auth = self.isPlayer(room_jid_s, nick) if not auth and (verbose or _DEBUG): - debug(_("%(user)s not allowed to invite for the game %(game)s in %(room)s") % {'user': nick, 'game': self.name, 'room': room_jid_s}) + log.debug(_("%(user)s not allowed to invite for the game %(game)s in %(room)s") % {'user': nick, 'game': self.name, 'room': room_jid_s}) return auth def isReferee(self, room_jid_s, nick): @@ -381,7 +382,7 @@ class RoomGame(object): (nicks, missing) = self.host.plugins["XEP-0045"].getRoomNicksOfUsers(room, other_players, secure=False) result = (len(nicks) == len(other_players), nicks, missing) if not result[0] and (verbose or _DEBUG): - debug(_("Still waiting for %(users)s before starting the game %(game)s in %(room)s") % {'users': result[2], 'game': self.name, 'room': room.occupantJID.userhost()}) + log.debug(_("Still waiting for %(users)s before starting the game %(game)s in %(room)s") % {'users': result[2], 'game': self.name, 'room': room.occupantJID.userhost()}) return result def getUniqueName(self, muc_service=None, profile_key=C.PROF_KEY_NONE): @@ -402,10 +403,10 @@ class RoomGame(object): @param room_jid_s: JID userhost of the room, or None to generate a unique name @param profile_key """ - debug(_('Preparing room for %s game') % self.name) + log.debug(_('Preparing room for %s game') % self.name) profile = self.host.memory.getProfileName(profile_key) if not profile: - error(_("Unknown profile")) + log.error(_("Unknown profile")) return if other_players is None: other_players = [] @@ -446,7 +447,7 @@ class RoomGame(object): # considering the last batch of invitations batch = len(self.invitations[room_jid_s]) - 1 if batch < 0: - error("Invitations from %s to play %s in %s have been lost!" % (profile_nick, self.name, room_jid_s)) + log.error("Invitations from %s to play %s in %s have been lost!" % (profile_nick, self.name, room_jid_s)) return True other_players = self.invitations[room_jid_s][batch][1] (auth, nicks, dummy) = self._checkWaitAuth(room, other_players) @@ -500,15 +501,15 @@ class RoomGame(object): """ user_nick = self.host.plugins["XEP-0045"].getRoomNick(room_jid_s, profile) if not user_nick: - error('Internal error: profile %s has not joined the room %s' % (profile, room_jid_s)) + log.error('Internal error: profile %s has not joined the room %s' % (profile, room_jid_s)) return False, False if self._gameExists(room_jid_s): is_referee = self.isReferee(room_jid_s, user_nick) if self._gameExists(room_jid_s, started=True): - warning(_("%(game)s game already created in room %(room)s") % {'game': self.name, 'room': room_jid_s}) + log.warning(_("%(game)s game already created in room %(room)s") % {'game': self.name, 'room': room_jid_s}) return False, is_referee elif not is_referee: - warning(_("%(game)s game in room %(room)s can only be created by %(user)s") % {'game': self.name, 'room': room_jid_s, 'user': user_nick}) + log.warning(_("%(game)s game in room %(room)s can only be created by %(user)s") % {'game': self.name, 'room': room_jid_s, 'user': user_nick}) return False, False else: self._initGame(room_jid_s, user_nick) @@ -523,10 +524,10 @@ class RoomGame(object): @param nicks: list of players nicks in the room (referee included, in first position) @param profile_key: %(doc_profile_key)s """ - debug(_("Creating %(game)s game in room %(room)s") % {'game': self.name, 'room': room_jid_s}) + log.debug(_("Creating %(game)s game in room %(room)s") % {'game': self.name, 'room': room_jid_s}) profile = self.host.memory.getProfileName(profile_key) if not profile: - error(_("profile %s is unknown") % profile_key) + log.error(_("profile %s is unknown") % profile_key) return (create, sync) = self._checkCreateGameAndInit(room_jid_s, profile) if nicks is None: @@ -552,9 +553,9 @@ class RoomGame(object): """ profile = self.host.memory.getProfileName(profile_key) if not profile: - error(_("profile %s is unknown") % profile_key) + log.error(_("profile %s is unknown") % profile_key) return - debug('new player ready: %s' % profile) + log.debug('new player ready: %s' % profile) # TODO: we probably need to add the game and room names in the sent message self.send(JID(referee), 'player_ready', {'player': player}, profile=profile) @@ -567,7 +568,7 @@ class RoomGame(object): - msg_elts: dict to map each user to his specific initialization message @param profile """ - debug(_('new round for %s game') % self.name) + log.debug(_('new round for %s game') % self.name) game_data = self.games[room_jid.userhost()] players = game_data['players'] players_data = game_data['players_data'] @@ -635,7 +636,7 @@ class RoomGame(object): @return: a Deferred instance """ if profile is None: - error(_("Message can not be sent without a sender profile")) + log.error(_("Message can not be sent without a sender profile")) return defer.fail(None) msg = self._createGameElt(to_jid) for elem, attrs, content in data: diff --git a/src/plugins/plugin_misc_smtp.py b/src/plugins/plugin_misc_smtp.py index c5a90f59..b49736d4 100755 --- a/src/plugins/plugin_misc_smtp.py +++ b/src/plugins/plugin_misc_smtp.py @@ -18,10 +18,9 @@ # along with this program. If not, see . from sat.core.i18n import _ -from logging import debug, info, error -import warnings -from twisted.internet import protocol, defer -from twisted.words.protocols.jabber import error as jab_error +from sat.core.log import getLogger +log = getLogger(__name__) +from twisted.internet import defer from twisted.cred import portal, checkers, credentials from twisted.cred import error as cred_error from twisted.mail import smtp @@ -29,7 +28,6 @@ from twisted.python import failure from email.parser import Parser from email.utils import parseaddr from twisted.mail.imap4 import LOGINCredentials, PLAINCredentials -import os from twisted.internet import reactor import sys @@ -60,14 +58,14 @@ class SMTP_server(object): """ def __init__(self, host): - info(_("Plugin SMTP Server initialization")) + log.info(_("Plugin SMTP Server initialization")) self.host = host #parameters host.memory.updateParams(self.params) port = int(self.host.memory.getParamA("SMTP Port", "Mail Server")) - info(_("Launching SMTP server on port %d"), port) + log.info(_("Launching SMTP server on port %d") % port) self.server_factory = SmtpServerFactory(self.host) reactor.listenTCP(port, self.server_factory) @@ -93,7 +91,7 @@ class SatSmtpMessage(object): subject=mail['subject'].decode('utf-8', 'replace'), mess_type='normal', profile_key=self.profile) except: exc_type, exc_value, exc_traceback = sys.exc_info() - error(_("Can't send message: %s") % exc_value) # The email is invalid or incorreclty parsed + log.error(_("Can't send message: %s") % exc_value) # The email is invalid or incorreclty parsed return defer.fail() self.message = None return defer.succeed(None) @@ -152,7 +150,7 @@ class SmtpRealm(object): self.host = host def requestAvatar(self, avatarID, mind, *interfaces): - debug('requestAvatar') + log.debug('requestAvatar') profile = avatarID.decode('utf-8') if smtp.IMessageDelivery not in interfaces: raise NotImplementedError @@ -198,11 +196,11 @@ class SmtpServerFactory(smtp.SMTPFactory): smtp.SMTPFactory.__init__(self, _portal) def startedConnecting(self, connector): - debug(_("SMTP server connection started")) + log.debug(_("SMTP server connection started")) smtp.SMTPFactory.startedConnecting(self, connector) def clientConnectionLost(self, connector, reason): - debug(_("SMTP server connection lost (reason: %s)"), reason) + log.debug(_("SMTP server connection lost (reason: %s)"), reason) smtp.SMTPFactory.clientConnectionLost(self, connector, reason) def buildProtocol(self, addr): diff --git a/src/plugins/plugin_misc_tarot.py b/src/plugins/plugin_misc_tarot.py index d5bd2d40..452c6850 100755 --- a/src/plugins/plugin_misc_tarot.py +++ b/src/plugins/plugin_misc_tarot.py @@ -19,7 +19,8 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.xish import domish from twisted.words.protocols.jabber import jid from twisted.internet import defer @@ -28,7 +29,6 @@ from wokkel import data_form from sat.memory import memory from sat.tools import xml_tools from sat_frontends.tools.games import TarotCard -from time import time import random @@ -55,7 +55,7 @@ class Tarot(object): self.__class__ = type(self.__class__.__name__, (self.__class__, RoomGame, object), {}) def __init__(self, host): - info(_("Plugin Tarot initialization")) + log.info(_("Plugin Tarot initialization")) self._sessions = memory.Sessions() self.inheritFromRoomGame(host) RoomGame._init_(self, host, PLUGIN_INFO, (NS_CG, CG_TAG), @@ -199,7 +199,7 @@ class Tarot(object): pl_waiting = players_data[player]['wait_for_low'] played.remove(card) players_data[pl_waiting]['levees'].append(card) - debug(_('Player %(excuse_owner)s give %(card_waited)s to %(player_waiting)s for Excuse compensation') % {"excuse_owner": player, "card_waited": card, "player_waiting": pl_waiting}) + log.debug(_('Player %(excuse_owner)s give %(card_waited)s to %(player_waiting)s for Excuse compensation') % {"excuse_owner": player, "card_waited": card, "player_waiting": pl_waiting}) return return @@ -230,12 +230,12 @@ class Tarot(object): low_card = owner_levees[card_idx] del owner_levees[card_idx] players_data[winner]['levees'].append(low_card) - debug(_('Player %(excuse_owner)s give %(card_waited)s to %(player_waiting)s for Excuse compensation') % {"excuse_owner": excuse_player, "card_waited": low_card, "player_waiting": winner}) + log.debug(_('Player %(excuse_owner)s give %(card_waited)s to %(player_waiting)s for Excuse compensation') % {"excuse_owner": excuse_player, "card_waited": low_card, "player_waiting": winner}) break if not low_card: # The player has no low card yet #TODO: manage case when player never win a trick with low card players_data[excuse_player]['wait_for_low'] = winner - debug(_("%(excuse_owner)s keep the Excuse but has not card to give, %(winner)s is waiting for one") % {'excuse_owner': excuse_player, 'winner': winner}) + log.debug(_("%(excuse_owner)s keep the Excuse but has not card to give, %(winner)s is waiting for one") % {'excuse_owner': excuse_player, 'winner': winner}) def __draw_game(self, game_data): """The game is draw, no score change @@ -246,7 +246,7 @@ class Tarot(object): scores_str += '\n' for player in game_data['players']: scores_str += _("\n--\n%(player)s:\nscore for this game ==> %(score_game)i\ntotal score ==> %(total_score)i") % {'player': player, 'score_game': 0, 'total_score': players_data[player]['score']} - debug(scores_str) + log.debug(scores_str) return (scores_str, [], []) @@ -295,7 +295,7 @@ class Tarot(object): elif game_data['contrat'] == 'Garde Contre': contrat_mult = 6 else: - error(_('INTERNAL ERROR: contrat not managed (mispelled ?)')) + log.error(_('INTERNAL ERROR: contrat not managed (mispelled ?)')) assert(False) victory = (score >= point_limit) @@ -318,7 +318,7 @@ class Tarot(object): scores_str += '\n' for player in game_data['players']: scores_str += _("\n--\n%(player)s:\nscore for this game ==> %(score_game)i\ntotal score ==> %(total_score)i") % {'player': player, 'score_game': player_score[player], 'total_score': players_data[player]['score']} - debug(scores_str) + log.debug(scores_str) return (scores_str, winners, loosers) @@ -375,7 +375,7 @@ class Tarot(object): if card.suit == "atout" and card < biggest_atout and biggest_hand_atout > biggest_atout and card.value != "excuse": forbidden_cards.append(card) else: - error(_('Internal error: unmanaged game stage')) + log.error(_('Internal error: unmanaged game stage')) return forbidden_cards def __start_play(self, room_jid, game_data, profile): @@ -394,7 +394,7 @@ class Tarot(object): try: session_data = self._sessions.profileGet(raw_data["session_id"], profile) except KeyError: - warning(_("session id doesn't exist, session has probably expired")) + log.warning(_("session id doesn't exist, session has probably expired")) # TODO: send error dialog return defer.succeed({}) @@ -403,7 +403,7 @@ class Tarot(object): player = self.host.plugins["XEP-0045"].getRoomNick(room_jid_s, profile) data = xml_tools.XMLUIResult2DataFormResult(raw_data) contrat = data['contrat'] - debug(_('contrat [%(contrat)s] choosed by %(profile)s') % {'contrat': contrat, 'profile': profile}) + log.debug(_('contrat [%(contrat)s] choosed by %(profile)s') % {'contrat': contrat, 'profile': profile}) d = self.send(jid.JID(referee), ('', 'contrat_choosed'), {'player': player}, content=contrat, profile=profile) d.addCallback(lambda ignore: {}) del self._sessions[raw_data["session_id"]] @@ -417,7 +417,7 @@ class Tarot(object): try: session_data = self._sessions.profileGet(raw_data["session_id"], profile) except KeyError: - warning(_("session id doesn't exist, session has probably expired")) + log.warning(_("session id doesn't exist, session has probably expired")) # TODO: send error dialog return defer.succeed({}) @@ -436,9 +436,9 @@ class Tarot(object): """ profile = self.host.memory.getProfileName(profile_key) if not profile: - error(_("profile %s is unknown") % profile_key) + log.error(_("profile %s is unknown") % profile_key) return - debug(_('Cards played by %(profile)s: [%(cards)s]') % {'profile': profile, 'cards': cards}) + log.debug(_('Cards played by %(profile)s: [%(cards)s]') % {'profile': profile, 'cards': cards}) elem = self.__card_list_to_xml(TarotCard.from_tuples(cards), 'cards_played') self.send(jid.JID(referee), elem, {'player': player}, profile=profile) @@ -504,7 +504,7 @@ class Tarot(object): status = self.games[room_jid.userhost()]['status'] nb_players = len(self.games[room_jid.userhost()]['players']) status[player] = 'ready' - debug(_('Player %(player)s is ready to start [status: %(status)s]') % {'player': player, 'status': status}) + log.debug(_('Player %(player)s is ready to start [status: %(status)s]') % {'player': player, 'status': status}) if status.values().count('ready') == nb_players: # everybody is ready, we can start the game self.newRound(room_jid, profile) @@ -539,14 +539,14 @@ class Tarot(object): best_contrat[0] = player best_contrat[1] = contrat if best_contrat[1] == "Passe": - debug(_("Everybody is passing, round ended")) + log.debug(_("Everybody is passing, round ended")) to_jid = jid.JID(room_jid.userhost()) self.send(to_jid, self.__give_scores(*self.__draw_game(game_data)), profile=profile) game_data['init_player'] = (game_data['init_player'] + 1) % len(game_data['players']) # we change the dealer for player in game_data['players']: game_data['status'][player] = "init" return - debug(_("%(player)s win the bid with %(contrat)s") % {'player': best_contrat[0], 'contrat': best_contrat[1]}) + log.debug(_("%(player)s win the bid with %(contrat)s") % {'player': best_contrat[0], 'contrat': best_contrat[1]}) game_data['contrat'] = best_contrat[1] if game_data['contrat'] == "Garde Sans" or game_data['contrat'] == "Garde Contre": @@ -567,7 +567,7 @@ class Tarot(object): del game_data['chien'][:] elif elt.name == 'chien': # we have received the chien - debug(_("tarot: chien received")) + log.debug(_("tarot: chien received")) data = {"attaquant": elt['attaquant']} game_data['stage'] = "ecart" game_data['attaquant'] = elt['attaquant'] @@ -618,7 +618,7 @@ class Tarot(object): if all(played): #everybody has played winner = self.__winner(game_data) - debug(_('The winner of this trick is %s') % winner) + log.debug(_('The winner of this trick is %s') % winner) #the winner win the trick self.__excuse_hack(game_data, played, winner) players_data[elt['player']]['levees'].extend(played) @@ -664,9 +664,9 @@ class Tarot(object): invalid_cards = self.__xml_to_list(elt.elements(name='invalid', uri=NS_CG).next()) self.host.bridge.tarotGameInvalidCards(room_jid.userhost(), elt['phase'], played_cards, invalid_cards, profile) else: - error(_('Unmanaged error type: %s') % elt['type']) + log.error(_('Unmanaged error type: %s') % elt['type']) else: - error(_('Unmanaged card game element: %s') % elt.name) + log.error(_('Unmanaged card game element: %s') % elt.name) def getSyncDataForPlayer(self, room_jid_s, nick): return [] diff --git a/src/plugins/plugin_misc_text_commands.py b/src/plugins/plugin_misc_text_commands.py index 273bd268..7fea3137 100755 --- a/src/plugins/plugin_misc_text_commands.py +++ b/src/plugins/plugin_misc_text_commands.py @@ -23,7 +23,8 @@ from sat.core.sat_main import MessageSentAndStored from twisted.words.protocols.jabber import jid from twisted.internet import defer from twisted.python.failure import Failure -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) PLUGIN_INFO = { "name": "Text commands", @@ -43,7 +44,7 @@ class TextCommands(object): # should be downloadable independently) def __init__(self, host): - info(_("Text commands initialization")) + log.info(_("Text commands initialization")) self.host = host host.trigger.add("sendMessage", self.sendMessageTrigger) self._commands = {} @@ -59,20 +60,20 @@ class TextCommands(object): if attr.startswith('cmd_'): cmd = getattr(instance, attr) if not callable(cmd): - warning(_("Skipping not callable [%s] attribute") % attr) + log.warning(_("Skipping not callable [%s] attribute") % attr) continue cmd_name = attr[4:] if not cmd_name: - warning(_("Skipping cmd_ method")) + log.warning(_("Skipping cmd_ method")) if cmd_name in self._commands: suff=2 while (cmd_name + str(suff)) in self._commands: suff+=1 new_name = cmd_name + str(suff) - warning(_("Conflict for command [%(old_name)s], renaming it to [%(new_name)s]") % {'old_name': cmd_name, 'new_name': new_name}) + log.warning(_("Conflict for command [%(old_name)s], renaming it to [%(new_name)s]") % {'old_name': cmd_name, 'new_name': new_name}) cmd_name = new_name self._commands[cmd_name] = cmd - info(_("Registered text command [%s]") % cmd_name) + log.info(_("Registered text command [%s]") % cmd_name) def addWhoIsCb(self, callback, priority=0): """Add a callback which give information to the /whois command @@ -160,7 +161,7 @@ class TextCommands(object): def cmd_whois(self, mess_data, profile): """show informations on entity""" - debug("Catched whois command") + log.debug("Catched whois command") entity = mess_data["unparsed"].strip() @@ -170,7 +171,7 @@ class TextCommands(object): if self.host.plugins["XEP-0045"].isNickInRoom(room, entity, profile): entity = u"%s/%s" % (room, entity) except KeyError: - warning("plugin XEP-0045 is not present") + log.warning("plugin XEP-0045 is not present") if not entity: target_jid = mess_data["to"] diff --git a/src/plugins/plugin_misc_text_syntaxes.py b/src/plugins/plugin_misc_text_syntaxes.py index 12f21e2d..fc0358e6 100755 --- a/src/plugins/plugin_misc_text_syntaxes.py +++ b/src/plugins/plugin_misc_text_syntaxes.py @@ -18,7 +18,8 @@ # along with this program. If not, see . from sat.core.i18n import _, D_ -from logging import debug, info, error, warning +from sat.core.log import getLogger +log = getLogger(__name__) from wokkel import disco, pubsub from twisted.internet import defer @@ -94,7 +95,7 @@ class TextSyntaxes(object): } def __init__(self, host): - info(_("Text syntaxes plugin initialization")) + log.info(_("Text syntaxes plugin initialization")) self.host = host self.syntaxes = {} self.addSyntax(self.SYNTAX_XHTML, lambda xhtml: defer.succeed(xhtml), lambda xhtml: defer.succeed(xhtml), @@ -109,7 +110,7 @@ class TextSyntaxes(object): return h.handle(html) self.addSyntax(self.SYNTAX_MARKDOWN, markdown.markdown, _html2text, [TextSyntaxes.OPT_DEFAULT]) except ImportError: - warning("markdown or html2text not found, can't use Markdown syntax") + log.warning("markdown or html2text not found, can't use Markdown syntax") host.bridge.addMethod("syntaxConvert", ".plugin", in_sign='sssbs', out_sign='s', async=True, method=self.convert) @@ -173,7 +174,7 @@ class TextSyntaxes(object): elif isinstance(xhtml, html.HtmlElement): xhtml_elt = xhtml else: - error("Only strings and HtmlElements can be cleaned") + log.error("Only strings and HtmlElements can be cleaned") raise exceptions.DataError cleaner = clean.Cleaner(style=False, add_nofollow=False, diff --git a/src/plugins/plugin_misc_xmllog.py b/src/plugins/plugin_misc_xmllog.py index becaac76..054460fb 100755 --- a/src/plugins/plugin_misc_xmllog.py +++ b/src/plugins/plugin_misc_xmllog.py @@ -18,7 +18,8 @@ # along with this program. If not, see . from sat.core.i18n import _ -from logging import debug, info, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.protocols.jabber.xmlstream import XmlStream from twisted.words.xish import domish @@ -43,7 +44,7 @@ class LoggingXmlStream(XmlStream): elif isinstance(obj, domish.Element): log = obj.toXml() else: - error(_('INTERNAL ERROR: Unmanaged XML type')) + log.error(_('INTERNAL ERROR: Unmanaged XML type')) self._host.bridge.xmlLog("OUT", log, self._profile) return XmlStream.send(self, obj) @@ -65,7 +66,7 @@ class XmlLog(object): """ % {"label_xmllog": _("Activate XML log")} def __init__(self, host): - info(_("Plugin XML Log initialization")) + log.info(_("Plugin XML Log initialization")) self.host = host #parameters @@ -76,7 +77,7 @@ class XmlLog(object): do_log = self.host.memory.getParamA("Xml log", "Debug") if do_log: - info(_("XML log activated")) + log.info(_("XML log activated")) host.trigger.add("XML Initialized", self.logXml) def logXml(self, xmlstream, profile): diff --git a/src/plugins/plugin_tmp_demo_directory.py b/src/plugins/plugin_tmp_demo_directory.py index c5838a62..dd20c5f3 100755 --- a/src/plugins/plugin_tmp_demo_directory.py +++ b/src/plugins/plugin_tmp_demo_directory.py @@ -18,7 +18,8 @@ # along with this program. If not, see . from sat.core.i18n import _, D_ -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.internet import defer from twisted.words.protocols.jabber.xmlstream import IQ from twisted.words.protocols.jabber import jid @@ -74,10 +75,10 @@ class DemoDirectory(object): } def __init__(self, host): - info(_(u"Plugin demo directory initialization")) + log.info(_(u"Plugin demo directory initialization")) activate = host.memory.getConfig(CONFIG_SECTION, CONFIG_ACTIVATE) or 'false' if not activate.lower() in ('true', 'yes', '1'): - info("not activated") + log.info("not activated") return service_str = host.memory.getConfig(CONFIG_SECTION, CONFIG_SERVICE) or 'salut.libervia.org' self.service = jid.JID(service_str) @@ -95,7 +96,7 @@ class DemoDirectory(object): """ client = self.host.getClient(profile) if not subscribe: - info ("Unsubscribing [%s] from directory" % profile) + log.info ("Unsubscribing [%s] from directory" % profile) unsub_req = IQ(client.xmlstream, 'set') unsub_req['from'] = client.jid.full() unsub_req['to'] = self.service.userhost() @@ -104,7 +105,7 @@ class DemoDirectory(object): command_elt['action'] = 'execute' yield unsub_req.send(self.service.userhost()) else: - info ("Subscribing [%s] to directory" % profile) + log.info ("Subscribing [%s] to directory" % profile) sub_req = IQ(client.xmlstream, 'set') sub_req['from'] = client.jid.full() sub_req['to'] = self.service.userhost() diff --git a/src/plugins/plugin_xep_0020.py b/src/plugins/plugin_xep_0020.py index b324c16f..e9326f04 100755 --- a/src/plugins/plugin_xep_0020.py +++ b/src/plugins/plugin_xep_0020.py @@ -18,7 +18,8 @@ # along with this program. If not, see . from sat.core.i18n import _ -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.protocols.jabber import client, jid from twisted.words.xish import domish @@ -47,7 +48,7 @@ PLUGIN_INFO = { class XEP_0020(object): def __init__(self, host): - info(_("Plugin XEP_0020 initialization")) + log.info(_("Plugin XEP_0020 initialization")) def getHandler(self, profile): return XEP_0020_handler() @@ -68,7 +69,7 @@ class XEP_0020(object): values = form.fields[field].values result[field] = values[0] if values else None if len(values) > 1: - warning(_("More than one value choosed for %s, keeping the first one") % field) + log.warning(_("More than one value choosed for %s, keeping the first one") % field) return result def negociate(self, feature_elt, form_type, negociable_values): diff --git a/src/plugins/plugin_xep_0033.py b/src/plugins/plugin_xep_0033.py index c8e004a5..9e7cc8a0 100644 --- a/src/plugins/plugin_xep_0033.py +++ b/src/plugins/plugin_xep_0033.py @@ -18,8 +18,8 @@ # along with this program. If not, see . from sat.core.i18n import _ -import logging -from sat.core import exceptions +from sat.core.log import getLogger +log = getLogger(__name__) from wokkel import disco, iwokkel from zope.interface import implements from twisted.words.protocols.jabber.jid import JID @@ -29,9 +29,8 @@ try: from twisted.words.protocols.xmlstream import XMPPHandler except ImportError: from wokkel.subprotocols import XMPPHandler -from threading import Timer from twisted.words.xish import domish -from twisted.internet import defer, threads +from twisted.internet import defer from sat.core.sat_main import MessageSentAndStored, AbortSendMessage from sat.tools.misc import TriggerManager @@ -70,7 +69,7 @@ class XEP_0033(object): Implementation for XEP 0033 """ def __init__(self, host): - logging.info(_("Extended Stanza Addressing plugin initialization")) + log.info(_("Extended Stanza Addressing plugin initialization")) self.host = host self.internal_data = {} host.trigger.add("sendMessage", self.sendMessageTrigger, TriggerManager.MIN_PRIORITY) @@ -87,8 +86,8 @@ class XEP_0033(object): if entity is None: return Failure(AbortSendMessage(_("XEP-0033 is being used but the server doesn't support it!"))) if mess_data["to"] != entity: - logging.warning(_("Stanzas using XEP-0033 should be addressed to %(expected)s, not %(current)s!") % {'expected': entity, 'current': mess_data["to"]}) - logging.warning(_("TODO: addressing has be fixed by the backend... fix it in the frontend!")) + log.warning(_("Stanzas using XEP-0033 should be addressed to %(expected)s, not %(current)s!") % {'expected': entity, 'current': mess_data["to"]}) + log.warning(_("TODO: addressing has be fixed by the backend... fix it in the frontend!")) mess_data["to"] = entity element = mess_data['xml'].addElement('addresses', NS_ADDRESS) entries = [entry.split(':') for entry in mess_data['extra']['address'].split('\n') if entry != ''] diff --git a/src/plugins/plugin_xep_0045.py b/src/plugins/plugin_xep_0045.py index 3f7b82a7..d6493bf2 100755 --- a/src/plugins/plugin_xep_0045.py +++ b/src/plugins/plugin_xep_0045.py @@ -19,7 +19,8 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.internet import defer from twisted.words.protocols.jabber import jid @@ -55,7 +56,7 @@ class XEP_0045(object): # TODO: this plugin is messy, need a big cleanup/refactoring def __init__(self, host): - info(_("Plugin XEP_0045 initialization")) + log.info(_("Plugin XEP_0045 initialization")) self.host = host self.clients = {} self._sessions = memory.Sessions() @@ -77,7 +78,7 @@ class XEP_0045(object): self.host.plugins[C.TEXT_CMDS].registerTextCommands(self) self.host.plugins[C.TEXT_CMDS].addWhoIsCb(self._whois, 100) except KeyError: - info(_("Text commands not available")) + log.info(_("Text commands not available")) def profileConnected(self, profile): def assign_service(service): @@ -92,7 +93,7 @@ class XEP_0045(object): @param profile: profile to check @return: True if the profile is known and connected, else False""" if not profile or profile not in self.clients or not self.host.isConnected(profile): - error(_('Unknown or disconnected profile (%s)') % profile) + log.error(_('Unknown or disconnected profile (%s)') % profile) if profile in self.clients: del self.clients[profile] return False @@ -112,7 +113,7 @@ class XEP_0045(object): #and send the signal only when the room is unlocked #a proper configuration management should be done print "room locked !" - self.clients[profile].configure(room.roomJID, {}).addCallbacks(_sendBridgeSignal, lambda x: error(_('Error while configuring the room'))) + self.clients[profile].configure(room.roomJID, {}).addCallbacks(_sendBridgeSignal, lambda x: log.error(_('Error while configuring the room'))) else: _sendBridgeSignal() return room @@ -124,7 +125,7 @@ class XEP_0045(object): nick += '_' return self.clients[profile].join(room_jid, nick, history_options, password).addCallbacks(self.__room_joined, self.__err_joining_room, callbackKeywords={'profile': profile}, errbackArgs=[room_jid, nick, history_options, password, profile]) mess = _("Error while joining the room %s" % room_jid.userhost()) - error(mess) + log.error(mess) self.host.bridge.newAlert(mess, _("Group chat error"), "ERROR", profile) raise failure @@ -224,7 +225,7 @@ class XEP_0045(object): try: session_data = self._sessions.profileGet(raw_data["session_id"], profile) except KeyError: - warning ("session id doesn't exist, session has probably expired") + log.warning ("session id doesn't exist, session has probably expired") # TODO: send error dialog return defer.succeed({}) @@ -286,7 +287,7 @@ class XEP_0045(object): except AttributeError: raise NotReadyYet("Main server MUC service has not been checked yet") if muc_service is None: - warning(_("No MUC service found on main server")) + log.warning(_("No MUC service found on main server")) raise exceptions.FeatureNotFound muc_service = muc_service.userhost() @@ -302,9 +303,9 @@ class XEP_0045(object): if not self.__check_profile(profile): return _errDeferred() if room_jid.userhost() in self.clients[profile].joined_rooms: - warning(_('%(profile)s is already in room %(room_jid)s') % {'profile': profile, 'room_jid': room_jid.userhost()}) + log.warning(_('%(profile)s is already in room %(room_jid)s') % {'profile': profile, 'room_jid': room_jid.userhost()}) return _errDeferred() - info(_("[%(profile)s] is joining room %(room)s with nick %(nick)s") % {'profile': profile, 'room': room_jid.userhost(), 'nick': nick}) + log.info(_("[%(profile)s] is joining room %(room)s with nick %(nick)s") % {'profile': profile, 'room': room_jid.userhost(), 'nick': nick}) history_options = options["history"] == "True" if "history" in options else None password = options["password"] if "password" in options else None @@ -328,7 +329,7 @@ class XEP_0045(object): room_jid = jid.JID(room_jid_s) except: mess = _("Invalid room jid: %s") % room_jid_s - warning(mess) + log.warning(mess) self.host.bridge.newAlert(mess, _("Group chat error"), "ERROR", profile) return self.join(room_jid, nick, options, profile) @@ -375,11 +376,11 @@ class XEP_0045(object): def cmd_nick(self, mess_data, profile): """change nickname""" - debug("Catched nick command") + log.debug("Catched nick command") if mess_data['type'] != "groupchat": #/nick command does nothing if we are not on a group chat - info("Ignoring /nick command on a non groupchat message") + log.info("Ignoring /nick command on a non groupchat message") return True @@ -392,11 +393,11 @@ class XEP_0045(object): def cmd_join(self, mess_data, profile): """join a new room (on the same service if full jid is not specified)""" - debug("Catched join command") + log.debug("Catched join command") if mess_data['type'] != "groupchat": #/leave command does nothing if we are not on a group chat - info("Ignoring /join command on a non groupchat message") + log.info("Ignoring /join command on a non groupchat message") return True if mess_data["unparsed"].strip(): @@ -409,11 +410,11 @@ class XEP_0045(object): def cmd_leave(self, mess_data, profile): """quit a room""" - debug("Catched leave command") + log.debug("Catched leave command") if mess_data['type'] != "groupchat": #/leave command does nothing if we are not on a group chat - info("Ignoring /leave command on a non groupchat message") + log.info("Ignoring /leave command on a non groupchat message") return True if mess_data["unparsed"].strip(): @@ -431,11 +432,11 @@ class XEP_0045(object): def cmd_title(self, mess_data, profile): """change room's subject""" - debug("Catched title command") + log.debug("Catched title command") if mess_data['type'] != "groupchat": #/leave command does nothing if we are not on a group chat - info("Ignoring /title command on a non groupchat message") + log.info("Ignoring /title command on a non groupchat message") return True subject = mess_data["unparsed"].strip() @@ -455,7 +456,7 @@ class XEP_0045(object): if mess_data['type'] != "groupchat": return if target_jid.userhost() not in self.clients[profile].joined_rooms: - warning(_("This room has not been joined")) + log.warning(_("This room has not been joined")) return user = self.clients[profile].joined_rooms[target_jid.userhost()].getUser(target_jid.resource) whois_msg.append(_("Nickname: %s") % user.nick) @@ -511,13 +512,13 @@ class SatMUCClient (muc.MUCClient): self.userLeftRoom(room, user) def receivedGroupChat(self, room, user, body): - debug('receivedGroupChat: room=%s user=%s body=%s', room, user, body) + log.debug('receivedGroupChat: room=%s user=%s body=%s', room, user, body) def userJoinedRoom(self, room, user): if user.nick in self.__changing_nicks: self.__changing_nicks.remove(user.nick) else: - debug(_("user %(nick)s has joined room (%(room_id)s)") % {'nick': user.nick, 'room_id': room.occupantJID.userhost()}) + log.debug(_("user %(nick)s has joined room (%(room_id)s)") % {'nick': user.nick, 'room_id': room.occupantJID.userhost()}) if not self.host.trigger.point("MUC user joined", room, user, self.parent.profile): return user_data = {'entity': user.entity.full() if user.entity else '', 'affiliation': user.affiliation, 'role': user.role} @@ -529,13 +530,13 @@ class SatMUCClient (muc.MUCClient): if user.nick == room.nick: # we left the room room_jid_s = room.roomJID.userhost() - info(_("Room [%(room)s] left (%(profile)s))") % {"room": room_jid_s, + log.info(_("Room [%(room)s] left (%(profile)s))") % {"room": room_jid_s, "profile": self.parent.profile}) self.host.memory.delEntityCache(room.roomJID, self.parent.profile) del self.plugin_parent.clients[self.parent.profile].joined_rooms[room_jid_s] self.host.bridge.roomLeft(room.roomJID.userhost(), self.parent.profile) else: - debug(_("user %(nick)s left room (%(room_id)s)") % {'nick': user.nick, 'room_id': room.occupantJID.userhost()}) + log.debug(_("user %(nick)s left room (%(room_id)s)") % {'nick': user.nick, 'room_id': room.occupantJID.userhost()}) user_data = {'entity': user.entity.full() if user.entity else '', 'affiliation': user.affiliation, 'role': user.role} self.host.bridge.roomUserLeft(room.roomJID.userhost(), user.nick, user_data, self.parent.profile) @@ -547,6 +548,6 @@ class SatMUCClient (muc.MUCClient): #FIXME: def receivedSubject(self, room, user, subject): - debug(_("New subject for room (%(room_id)s): %(subject)s") % {'room_id': room.roomJID.full(), 'subject': subject}) + log.debug(_("New subject for room (%(room_id)s): %(subject)s") % {'room_id': room.roomJID.full(), 'subject': subject}) self.rec_subjects[room.roomJID.userhost()] = (room.roomJID.userhost(), subject) self.host.bridge.roomNewSubject(room.roomJID.userhost(), subject, self.parent.profile) diff --git a/src/plugins/plugin_xep_0047.py b/src/plugins/plugin_xep_0047.py index 0089078d..408b8161 100644 --- a/src/plugins/plugin_xep_0047.py +++ b/src/plugins/plugin_xep_0047.py @@ -18,7 +18,8 @@ # along with this program. If not, see . from sat.core.i18n import _ -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.protocols.jabber import client as jabber_client, jid from twisted.words.xish import domish from twisted.internet import reactor @@ -59,7 +60,7 @@ class XEP_0047(object): NAMESPACE = NS_IBB def __init__(self, host): - info(_("In-Band Bytestreams plugin initialization")) + log.info(_("In-Band Bytestreams plugin initialization")) self.host = host def getHandler(self, profile): @@ -72,7 +73,7 @@ class XEP_0047(object): def _timeOut(self, sid, profile): """Delecte current_stream id, called after timeout @param id: id of client.xep_0047_current_stream""" - info(_("In-Band Bytestream: TimeOut reached for id %(sid)s [%(profile)s]") + log.info(_("In-Band Bytestream: TimeOut reached for id %(sid)s [%(profile)s]") % {"sid": sid, "profile": profile}) self._killId(sid, False, "TIMEOUT", profile) @@ -82,7 +83,7 @@ class XEP_0047(object): assert(profile) client = self.host.getClient(profile) if sid not in client.xep_0047_current_stream: - warning(_("kill id called on a non existant id")) + log.warning(_("kill id called on a non existant id")) return if "observer_cb" in client.xep_0047_current_stream[sid]: client.xmlstream.removeObserver(client.xep_0047_current_stream[sid]["event_data"], client.xep_0047_current_stream[sid]["observer_cb"]) @@ -134,7 +135,7 @@ class XEP_0047(object): data["failure_cb"] = failure_cb def streamOpening(self, IQ, profile): - debug(_("IBB stream opening")) + log.debug(_("IBB stream opening")) IQ.handled = True client = self.host.getClient(profile) open_elt = IQ.firstChildElement() @@ -142,15 +143,15 @@ class XEP_0047(object): sid = open_elt.getAttribute('sid') stanza = open_elt.getAttribute('stanza', 'iq') if not sid or not block_size or int(block_size) > 65535: - warning(_("malformed IBB transfer: %s" % IQ['id'])) + log.warning(_("malformed IBB transfer: %s" % IQ['id'])) self.sendNotAcceptableError(IQ['id'], IQ['from'], client.xmlstream) return if not sid in client.xep_0047_current_stream: - warning(_("Ignoring unexpected IBB transfer: %s" % sid)) + log.warning(_("Ignoring unexpected IBB transfer: %s" % sid)) self.sendNotAcceptableError(IQ['id'], IQ['from'], client.xmlstream) return if client.xep_0047_current_stream[sid]["from"] != jid.JID(IQ['from']): - warning(_("sended jid inconsistency (man in the middle attack attempt ?)")) + log.warning(_("sended jid inconsistency (man in the middle attack attempt ?)")) self.sendNotAcceptableError(IQ['id'], IQ['from'], client.xmlstream) self._killId(sid, False, "PROTOCOL_ERROR", profile=profile) return @@ -177,7 +178,7 @@ class XEP_0047(object): def streamClosing(self, IQ, profile): IQ.handled = True client = self.host.getClient(profile) - debug(_("IBB stream closing")) + log.debug(_("IBB stream closing")) data_elt = IQ.firstChildElement() sid = data_elt.getAttribute('sid') result = domish.Element((None, 'iq')) @@ -212,21 +213,21 @@ class XEP_0047(object): client = self.host.getClient(profile) sid = data_elt.getAttribute('sid') if sid not in client.xep_0047_current_stream: - error(_("Received data for an unknown session id")) + log.error(_("Received data for an unknown session id")) return False from_jid = client.xep_0047_current_stream[sid]["from"] file_obj = client.xep_0047_current_stream[sid]["file_obj"] if stanza_from_jid != from_jid: - warning(_("sended jid inconsistency (man in the middle attack attempt ?)")) + log.warning(_("sended jid inconsistency (man in the middle attack attempt ?)")) if stanza == 'iq': self.sendNotAcceptableError(sid, from_jid, client.xmlstream) return False client.xep_0047_current_stream[sid]["seq"] += 1 if int(data_elt.getAttribute("seq", -1)) != client.xep_0047_current_stream[sid]["seq"]: - warning(_("Sequence error")) + log.warning(_("Sequence error")) if stanza == 'iq': self.sendNotAcceptableError(data_elt["id"], from_jid, client.xmlstream) return False @@ -239,7 +240,7 @@ class XEP_0047(object): file_obj.write(base64.b64decode(str(data_elt))) except TypeError: #The base64 data is invalid - warning(_("Invalid base64 data")) + log.warning(_("Invalid base64 data")) if stanza == 'iq': self.sendNotAcceptableError(data_elt["id"], from_jid, client.xmlstream) return False @@ -270,7 +271,7 @@ class XEP_0047(object): @param profile: %(doc_profile)s""" client = self.host.getClient(profile) if length is not None: - error(_('stream length not managed yet')) + log.error(_('stream length not managed yet')) return data = client.xep_0047_current_stream[sid] = {} data["timer"] = reactor.callLater(TIMEOUT, self._timeOut, sid) @@ -297,7 +298,7 @@ class XEP_0047(object): client = self.host.getClient(profile) data = client.xep_0047_current_stream[sid] if iq_elt["type"] == "error": - warning(_("Transfer failed")) + log.warning(_("Transfer failed")) self.terminateStream(sid, "IQ_ERROR") return diff --git a/src/plugins/plugin_xep_0048.py b/src/plugins/plugin_xep_0048.py index 01e95cf4..bc748af8 100644 --- a/src/plugins/plugin_xep_0048.py +++ b/src/plugins/plugin_xep_0048.py @@ -22,7 +22,8 @@ from sat.core import exceptions from sat.core.constants import Const as C from sat.memory.persistent import PersistentBinaryDict from sat.tools import xml_tools -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.xish import domish from twisted.words.protocols.jabber import jid from twisted.words.protocols.jabber.error import StanzaError @@ -53,7 +54,7 @@ class XEP_0048(object): URL_ATTRS = ('name',) def __init__(self, host): - info(_("Bookmarks plugin initialization")) + log.info(_("Bookmarks plugin initialization")) self.host = host # self.__menu_id = host.registerCallback(self._bookmarksMenu, with_data=True) self.__bm_save_id = host.registerCallback(self._bookmarksSaveCb, with_data=True) @@ -69,7 +70,7 @@ class XEP_0048(object): try: self.host.plugins[C.TEXT_CMDS].registerTextCommands(self) except KeyError: - info(_("Text commands not available")) + log.info(_("Text commands not available")) @defer.inlineCallbacks def profileConnected(self, profile): @@ -106,7 +107,7 @@ class XEP_0048(object): bookmarks_private_xml = yield self.private_plg.privateXMLGet('storage', NS_BOOKMARKS, profile) data = client.bookmarks_private = self._bookmarkElt2Dict(bookmarks_private_xml) except (StanzaError, AttributeError): - info(_("Private XML storage not available")) + log.info(_("Private XML storage not available")) data = client.bookmarks_private = None elif storage_type == 'pubsub': raise NotImplementedError @@ -147,7 +148,7 @@ class XEP_0048(object): try: room_jid = jid.JID(conference_elt[XEP_0048.MUC_KEY]) except KeyError: - warning ("invalid bookmark found, igoring it:\n%s" % conference_elt.toXml()) + log.warning ("invalid bookmark found, igoring it:\n%s" % conference_elt.toXml()) continue data = conf_data[room_jid] = {} @@ -166,7 +167,7 @@ class XEP_0048(object): try: url = url_elt[XEP_0048.URL_KEY] except KeyError: - warning ("invalid bookmark found, igoring it:\n%s" % url_elt.toXml()) + log.warning ("invalid bookmark found, igoring it:\n%s" % url_elt.toXml()) continue data = url_data[url] = {} for attr in XEP_0048.URL_ATTRS: @@ -215,12 +216,12 @@ class XEP_0048(object): room_jid_s, nick = data['index'].split(' ', 1) room_jid = jid.JID(room_jid_s) except (KeyError, RuntimeError): - warning(_("No room jid selected")) + log.warning(_("No room jid selected")) return {} d = self.host.plugins['XEP-0045'].join(room_jid, nick, {}, profile_key=profile) def join_eb(failure): - warning("Error while trying to join room: %s" % failure) + log.warning("Error while trying to join room: %s" % failure) # FIXME: failure are badly managed in plugin XEP-0045. Plugin XEP-0045 need to be fixed before managing errors correctly here return {} d.addCallbacks(lambda dummy: {}, join_eb) @@ -303,8 +304,8 @@ class XEP_0048(object): storage_type = 'private' else: storage_type = 'local' - warning(_("Bookmarks will be local only")) - info(_('Type selected for "auto" storage: %s') % storage_type) + log.warning(_("Bookmarks will be local only")) + log.info(_('Type selected for "auto" storage: %s') % storage_type) if storage_type == 'local': client.bookmarks_local[type_][location] = data @@ -338,7 +339,7 @@ class XEP_0048(object): del client.bookmarks_local[type_][location] yield client.bookmarks_local.force(type_) except KeyError: - debug("Bookmark is not present in local storage") + log.debug("Bookmark is not present in local storage") if storage_type in ('all', 'private'): bookmarks = yield self._getServerBookmarks('private', client.profile) @@ -347,7 +348,7 @@ class XEP_0048(object): bookmark_elt = self._dict2BookmarkElt(type_, bookmarks) yield self._setServerBookmarks('private', bookmark_elt, client.profile) except KeyError: - debug("Bookmark is not present in private storage") + log.debug("Bookmark is not present in private storage") if storage_type == 'pubsub': raise NotImplementedError @@ -422,13 +423,13 @@ class XEP_0048(object): @command (group): [autojoin | remove] - autojoin: join room automatically on connection """ - debug("Catched bookmark command") + log.debug("Catched bookmark command") client = self.host.getClient(profile) txt_cmd = self.host.plugins[C.TEXT_CMDS] if mess_data['type'] != "groupchat": #/bookmark command does nothing if we are not on a group chat - info("Ignoring /bookmark command on a non groupchat message") + log.info("Ignoring /bookmark command on a non groupchat message") return True options = mess_data["unparsed"].strip().split() diff --git a/src/plugins/plugin_xep_0049.py b/src/plugins/plugin_xep_0049.py index 18d88972..460548e5 100755 --- a/src/plugins/plugin_xep_0049.py +++ b/src/plugins/plugin_xep_0049.py @@ -18,7 +18,8 @@ # along with this program. If not, see . from sat.core.i18n import _ -from logging import debug, info, error, warning +from sat.core.log import getLogger +log = getLogger(__name__) from wokkel import compat from twisted.words.xish import domish @@ -40,7 +41,7 @@ class XEP_0049(object): NS_PRIVATE = 'jabber:iq:private' def __init__(self, host): - info(_("Plugin XEP-0049 initialization")) + log.info(_("Plugin XEP-0049 initialization")) self.host = host def privateXMLStore(self, element, profile_key): diff --git a/src/plugins/plugin_xep_0050.py b/src/plugins/plugin_xep_0050.py index 60dacbfc..06a7429d 100644 --- a/src/plugins/plugin_xep_0050.py +++ b/src/plugins/plugin_xep_0050.py @@ -19,9 +19,10 @@ from sat.core.i18n import _, D_ from sat.core.constants import Const as C -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.protocols.jabber import jid -from twisted.words.protocols.jabber import error as xmpp_error +from twisted.words.protocols import jabber from twisted.words.xish import domish from twisted.internet import defer from wokkel import disco, iwokkel, data_form, compat @@ -106,7 +107,7 @@ class AdHocCommand(XMPPHandler): try: allowed.update(self.client.roster.getJidsFromGroup(group)) except exceptions.UnknownGroupError: - warning(_("The groups [%(group)s] is unknown for profile [%(profile)s])" % {'group':group, 'profile':self.client.profile})) + log.warning(_("The groups [%(group)s] is unknown for profile [%(profile)s])" % {'group':group, 'profile':self.client.profile})) if requestor.userhostJID() in allowed: return True return False @@ -169,7 +170,7 @@ class AdHocCommand(XMPPHandler): @param request: original request (domish.Element) """ xmpp_condition, cmd_condition = error_constant - iq_elt = xmpp_error.StanzaError(xmpp_condition).toResponse(request) + iq_elt = jabber.error.StanzaError(xmpp_condition).toResponse(request) if cmd_condition: error_elt = iq_elt.elements(None, "error").next() error_elt.addElement(cmd_condition, NS_COMMANDS) @@ -208,7 +209,7 @@ class XEP_0050(object): ('item-not-found', None), ('feature-not-implemented', None), ('internal-server-error', None)) # XEP-0050 §4.4 Table 5 def __init__(self, host): - info(_("plugin XEP-0050 initialization")) + log.info(_("plugin XEP-0050 initialization")) self.host = host self.requesting = Sessions() self.answering = {} @@ -290,7 +291,7 @@ class XEP_0050(object): try: session_data = self.requesting.profileGet(data["session_id"], profile) except KeyError: - warning ("session id doesn't exist, session has probably expired") + log.warning ("session id doesn't exist, session has probably expired") # TODO: send error dialog return defer.succeed({}) session_id = data["session_id"] diff --git a/src/plugins/plugin_xep_0054.py b/src/plugins/plugin_xep_0054.py index 7c5842cd..c1fd34a5 100755 --- a/src/plugins/plugin_xep_0054.py +++ b/src/plugins/plugin_xep_0054.py @@ -20,7 +20,8 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.internet import threads, defer from twisted.words.protocols.jabber import jid from twisted.words.protocols.jabber.xmlstream import IQ @@ -72,7 +73,7 @@ class XEP_0054(object): # - get missing values def __init__(self, host): - info(_("Plugin XEP_0054 initialization")) + log.info(_("Plugin XEP_0054 initialization")) self.host = host self.avatar_path = os.path.join(self.host.memory.getConfig('', 'local_dir'), AVATAR_PATH) if not os.path.exists(self.avatar_path): @@ -141,24 +142,24 @@ class XEP_0054(object): """Parse a elem and save the picture""" for elem in photo_xml.elements(): if elem.name == 'TYPE': - info(_('Photo of type [%s] found') % str(elem)) + log.info(_('Photo of type [%s] found') % str(elem)) if elem.name == 'BINVAL': - debug(_('Decoding binary')) + log.debug(_('Decoding binary')) decoded = b64decode(str(elem)) image_hash = sha1(decoded).hexdigest() filename = self.avatar_path + '/' + image_hash if not os.path.exists(filename): with open(filename, 'wb') as file: file.write(decoded) - debug(_("file saved to %s") % image_hash) + log.debug(_("file saved to %s") % image_hash) else: - debug(_("file [%s] already in cache") % image_hash) + log.debug(_("file [%s] already in cache") % image_hash) return image_hash @defer.inlineCallbacks def vCard2Dict(self, vcard, target, profile): """Convert a VCard to a dict, and save binaries""" - debug(_("parsing vcard")) + log.debug(_("parsing vcard")) dictionary = {} for elem in vcard.elements(): @@ -180,13 +181,13 @@ class XEP_0054(object): else: self.update_cache(target, 'avatar', dictionary['avatar'], profile) else: - info(_('FIXME: [%s] VCard tag is not managed yet') % elem.name) + log.info(_('FIXME: [%s] VCard tag is not managed yet') % elem.name) defer.returnValue(dictionary) def vcard_ok(self, answer, profile): """Called after the first get IQ""" - debug(_("VCard found")) + log.debug(_("VCard found")) if answer.firstChildElement().name == "vCard": _jid, steam = self.host.getJidNStream(profile) @@ -197,13 +198,13 @@ class XEP_0054(object): d = self.vCard2Dict(answer.firstChildElement(), from_jid, profile) d.addCallback(lambda data: self.host.bridge.actionResult("RESULT", answer['id'], data, profile)) else: - error(_("FIXME: vCard not found as first child element")) + log.error(_("FIXME: vCard not found as first child element")) self.host.bridge.actionResult("SUPPRESS", answer['id'], {}, profile) # FIXME: maybe an error message would be better def vcard_err(self, failure, profile): """Called when something is wrong with registration""" if failure.value.stanza.hasAttribute("from"): - error(_("Can't find VCard of %s") % failure.value.stanza['from']) + log.error(_("Can't find VCard of %s") % failure.value.stanza['from']) self.host.bridge.actionResult("SUPPRESS", failure.value.stanza['id'], {}, profile) # FIXME: maybe an error message would be better def getCard(self, target_s, profile_key=C.PROF_KEY_NONE): @@ -212,11 +213,11 @@ class XEP_0054(object): @result: id to retrieve the profile""" current_jid, xmlstream = self.host.getJidNStream(profile_key) if not xmlstream: - error(_('Asking vcard for a non-existant or not connected profile')) + log.error(_('Asking vcard for a non-existant or not connected profile')) return "" profile = self.host.memory.getProfileName(profile_key) to_jid = jid.JID(target_s) - debug(_("Asking for %s's VCard") % to_jid.userhost()) + log.debug(_("Asking for %s's VCard") % to_jid.userhost()) reg_request = IQ(xmlstream, 'get') reg_request["from"] = current_jid.full() reg_request["to"] = to_jid.userhost() @@ -231,7 +232,7 @@ class XEP_0054(object): """ filename = self.avatar_path + '/' + avatar_hash if not os.path.exists(filename): - error(_("Asking for an uncached avatar [%s]") % avatar_hash) + log.error(_("Asking for an uncached avatar [%s]") % avatar_hash) return "" return filename @@ -303,5 +304,5 @@ class XEP_0054_handler(XMPPHandler): _hash = str(elem) old_avatar = self.plugin_parent.get_cache(from_jid, 'avatar', self.parent.profile) if not old_avatar or old_avatar != _hash: - debug(_('New avatar found, requesting vcard')) + log.debug(_('New avatar found, requesting vcard')) self.plugin_parent.getCard(from_jid.userhost(), self.parent.profile) diff --git a/src/plugins/plugin_xep_0055.py b/src/plugins/plugin_xep_0055.py index 4cec04b9..91f53278 100644 --- a/src/plugins/plugin_xep_0055.py +++ b/src/plugins/plugin_xep_0055.py @@ -18,9 +18,11 @@ # along with this program. If not, see . from sat.core.i18n import _, D_ -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.protocols.jabber.xmlstream import IQ from twisted.words.protocols.jabber import jid +from twisted.internet import defer from wokkel import data_form from sat.core.exceptions import DataError from sat.memory.memory import Sessions @@ -42,7 +44,7 @@ PLUGIN_INFO = { class XEP_0055(object): def __init__(self, host): - info(_("Jabber search plugin initialization")) + log.info(_("Jabber search plugin initialization")) self.host = host host.bridge.addMethod("getSearchUI", ".plugin", in_sign='ss', out_sign='s', method=self._getSearchUI, @@ -105,26 +107,26 @@ class XEP_0055(object): try: query_elts = answer.elements('jabber:iq:search', 'query').next() except StopIteration: - info(_("No query element found")) + log.info(_("No query element found")) raise DataError # FIXME: StanzaError is probably more appropriate, check the RFC try: form_elt = query_elts.elements(data_form.NS_X_DATA, 'x').next() except StopIteration: - info(_("No data form found")) + log.info(_("No data form found")) raise NotImplementedError("Only search through data form is implemented so far") parsed_form = data_form.Form.fromElement(form_elt) return xml_tools.dataForm2XMLUI(parsed_form, "") def _fieldsErr(self, failure, profile): """ Called when something is wrong with fields request """ - info(_("Fields request failure: %s") % str(failure.value)) + log.info(_("Fields request failure: %s") % str(failure.value)) return failure def _xmluiSearchRequest(self, raw_data, profile): try: session_data = self._sessions.profileGet(raw_data["session_id"], profile) except KeyError: - warning ("session id doesn't exist, session has probably expired") + log.warning ("session id doesn't exist, session has probably expired") # TODO: send error dialog return defer.succeed({}) @@ -163,16 +165,16 @@ class XEP_0055(object): try: query_elts = answer.elements('jabber:iq:search', 'query').next() except StopIteration: - info(_("No query element found")) + log.info(_("No query element found")) raise DataError # FIXME: StanzaError is probably more appropriate, check the RFC try: form_elt = query_elts.elements(data_form.NS_X_DATA, 'x').next() except StopIteration: - info(_("No data form found")) + log.info(_("No data form found")) raise NotImplementedError("Only search through data form is implemented so far") return xml_tools.dataFormResult2XMLUI(form_elt) def _searchErr(self, failure, profile): """ Called when something is wrong with search request """ - info(_("Search request failure: %s") % str(failure.value)) + log.info(_("Search request failure: %s") % str(failure.value)) return failure diff --git a/src/plugins/plugin_xep_0060.py b/src/plugins/plugin_xep_0060.py index 7d624efe..27b54e2c 100755 --- a/src/plugins/plugin_xep_0060.py +++ b/src/plugins/plugin_xep_0060.py @@ -19,7 +19,8 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, error +from sat.core.log import getLogger +log = getLogger(__name__) from wokkel.pubsub import PubSubRequest from wokkel import disco, pubsub from zope.interface import implements @@ -49,7 +50,7 @@ class XEP_0060(object): OPT_PUBLISH_MODEL = 'pubsub#publish_model' def __init__(self, host): - info(_("PubSub plugin initialization")) + log.info(_("PubSub plugin initialization")) self.host = host self.managedNodes = [] self.clients = {} @@ -86,13 +87,13 @@ class XEP_0060(object): err_mess = _('Trying to %(action)s with an unknown profile key [%(profile_key)s]') % { 'action': action, 'profile_key': profile_key} - error(err_mess) + log.error(err_mess) raise Exception(err_mess) try: client = self.clients[profile] except KeyError: err_mess = _('INTERNAL ERROR: no handler for required profile') - error(err_mess) + log.error(err_mess) raise Exception(err_mess) return profile, client @@ -215,7 +216,7 @@ class SatPubSubClient(pubsub.PubSubClient): def deleteReceived(self, event): #TODO: manage delete event - debug(_("Publish node deleted")) + log.debug(_("Publish node deleted")) # def purgeReceived(self, event): diff --git a/src/plugins/plugin_xep_0065.py b/src/plugins/plugin_xep_0065.py index c05cd3ea..6bec6e13 100755 --- a/src/plugins/plugin_xep_0065.py +++ b/src/plugins/plugin_xep_0065.py @@ -55,9 +55,10 @@ # THE SOFTWARE. from sat.core.i18n import _ -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.internet import protocol, reactor -from twisted.internet import error as jab_error +from twisted.internet import error from twisted.words.protocols.jabber import jid, client as jabber_client from twisted.protocols.basic import FileSender from twisted.words.xish import domish @@ -139,7 +140,7 @@ def calculateHash(from_jid, to_jid, sid): class SOCKSv5(protocol.Protocol, FileSender): def __init__(self): - debug(_("Protocol init")) + log.debug(_("Protocol init")) self.state = STATE_INITIAL self.buf = "" self.supportedAuthMechs = [AUTHMECH_ANON] @@ -150,12 +151,12 @@ class SOCKSv5(protocol.Protocol, FileSender): self.requestType = 0 def _startNegotiation(self): - debug("_startNegotiation") + log.debug("_startNegotiation") self.state = STATE_TARGET_AUTH self.transport.write(struct.pack('!3B', SOCKS5_VER, 1, AUTHMECH_ANON)) def _parseNegotiation(self): - debug("_parseNegotiation") + log.debug("_parseNegotiation") try: # Parse out data ver, nmethod = struct.unpack('!BB', self.buf[:2]) @@ -189,7 +190,7 @@ class SOCKSv5(protocol.Protocol, FileSender): pass def _parseUserPass(self): - debug("_parseUserPass") + log.debug("_parseUserPass") try: # Parse out data ver, ulen = struct.unpack('BB', self.buf[:2]) @@ -211,14 +212,14 @@ class SOCKSv5(protocol.Protocol, FileSender): pass def sendErrorReply(self, errorcode): - debug("sendErrorReply") + log.debug("sendErrorReply") # Any other address types are not supported result = struct.pack('!BBBBIH', SOCKS5_VER, errorcode, 0, 1, 0, 0) self.transport.write(result) self.transport.loseConnection() def _parseRequest(self): - debug("_parseRequest") + log.debug("_parseRequest") try: # Parse out data and trim buffer accordingly ver, cmd, rsvd, self.addressType = struct.unpack('!BBBB', self.buf[:4]) @@ -260,14 +261,14 @@ class SOCKSv5(protocol.Protocol, FileSender): return None def _makeRequest(self): - debug("_makeRequest") + log.debug("_makeRequest") self.state = STATE_TARGET_REQUEST sha1 = calculateHash(self.data["from"], self.data["to"], self.sid) request = struct.pack('!5B%dsH' % len(sha1), SOCKS5_VER, CMD_CONNECT, 0, ADDR_DOMAINNAME, len(sha1), sha1, 0) self.transport.write(request) def _parseRequestReply(self): - debug("_parseRequestReply") + log.debug("_parseRequestReply") try: ver, rep, rsvd, self.addressType = struct.unpack('!BBBB', self.buf[:4]) # Ensure we actually support the requested address type @@ -304,7 +305,7 @@ class SOCKSv5(protocol.Protocol, FileSender): return None def connectionMade(self): - debug("connectionMade (mode = %s)" % "requester" if isinstance(self.factory, Socks5ServerFactory) else "target") + log.debug("connectionMade (mode = %s)" % "requester" if isinstance(self.factory, Socks5ServerFactory) else "target") if isinstance(self.factory, Socks5ClientFactory): self.sid = self.factory.sid @@ -314,7 +315,7 @@ class SOCKSv5(protocol.Protocol, FileSender): self._startNegotiation() def connectRequested(self, addr, port): - debug("connectRequested") + log.debug("connectRequested") # Check that this session is expected if addr not in self.factory.hash_sid_map: @@ -333,12 +334,12 @@ class SOCKSv5(protocol.Protocol, FileSender): d.addCallback(self.fileTransfered) def fileTransfered(self, d): - info(_("File transfer completed, closing connection")) + log.info(_("File transfer completed, closing connection")) self.transport.loseConnection() self.factory.finishedCb(self.sid, True, self.profile) def connectCompleted(self, remotehost, remoteport): - debug("connectCompleted") + log.debug("connectCompleted") if self.addressType == ADDR_IPV4: result = struct.pack('!BBBBIH', SOCKS5_VER, REPLY_SUCCESS, 0, 1, remotehost, remoteport) elif self.addressType == ADDR_DOMAINNAME: @@ -351,7 +352,7 @@ class SOCKSv5(protocol.Protocol, FileSender): pass def authenticateUserPass(self, user, passwd): - debug("User/pass: %s/%s", user, passwd) + log.debug("User/pass: %s/%s", user, passwd) return True def dataReceived(self, buf): @@ -377,11 +378,11 @@ class SOCKSv5(protocol.Protocol, FileSender): self._parseRequestReply() def clientConnectionLost(self, reason): - debug("clientConnectionLost") + log.debug("clientConnectionLost") self.transport.loseConnection() def connectionLost(self, reason): - debug("connectionLost") + log.debug("connectionLost") if self.state != STATE_CONNECT_PENDING: self.transport.unregisterProducer() if self.peersock is not None: @@ -399,10 +400,10 @@ class Socks5ServerFactory(protocol.ServerFactory): self.finishedCb = finishedCb def startedConnecting(self, connector): - debug(_("Socks 5 server connection started")) + log.debug(_("Socks 5 server connection started")) def clientConnectionLost(self, connector, reason): - debug(_("Socks 5 server connection lost (reason: %s)"), reason) + log.debug(_("Socks 5 server connection lost (reason: %s)"), reason) class Socks5ClientFactory(protocol.ClientFactory): @@ -427,11 +428,11 @@ class Socks5ClientFactory(protocol.ClientFactory): self.profile = profile def startedConnecting(self, connector): - debug(_("Socks 5 client connection started")) + log.debug(_("Socks 5 client connection started")) def clientConnectionLost(self, connector, reason): - debug(_("Socks 5 client connection lost (reason: %s)"), reason) - self.finishedCb(self.sid, reason.type == jab_error.ConnectionDone, self.profile) # TODO: really check if the state is actually successful + log.debug(_("Socks 5 client connection lost (reason: %s)"), reason) + self.finishedCb(self.sid, reason.type == error.ConnectionDone, self.profile) # TODO: really check if the state is actually successful class XEP_0065(object): @@ -457,13 +458,13 @@ class XEP_0065(object): """ def __init__(self, host): - info(_("Plugin XEP_0065 initialization")) + log.info(_("Plugin XEP_0065 initialization")) #session data self.hash_sid_map = {} # key: hash of the transfer session, value: (session id, profile) self.host = host - debug(_("registering")) + log.debug(_("registering")) self.server_factory = Socks5ServerFactory(host, self.hash_sid_map, lambda sid, success, profile: self._killId(sid, success, profile=profile)) #parameters @@ -471,7 +472,7 @@ class XEP_0065(object): host.memory.setDefault("IP", "File Transfer", self.getExternalIP) port = int(self.host.memory.getParamA("Port", "File Transfer")) - info(_("Launching Socks5 Stream server on port %d"), port) + log.info(_("Launching Socks5 Stream server on port %d") % port) reactor.listenTCP(port, self.server_factory) def getHandler(self, profile): @@ -498,7 +499,7 @@ class XEP_0065(object): def _timeOut(self, sid, profile): """Delecte current_stream id, called after timeout @param id: id of client.xep_0065_current_stream""" - info(_("Socks5 Bytestream: TimeOut reached for id %(sid)s [%(profile)s]") + log.info(_("Socks5 Bytestream: TimeOut reached for id %(sid)s [%(profile)s]") % {"sid": sid, "profile": profile}) self._killId(sid, False, "TIMEOUT", profile) @@ -508,7 +509,7 @@ class XEP_0065(object): assert(profile) client = self.host.getClient(profile) if sid not in client.xep_0065_current_stream: - warning(_("kill id called on a non existant id")) + log.warning(_("kill id called on a non existant id")) return if "observer_cb" in client.xep_0065_current_stream[sid]: xmlstream = client.xep_0065_current_stream[sid]["xmlstream"] @@ -546,7 +547,7 @@ class XEP_0065(object): client = self.host.getClient(profile) if length is not None: - error(_('stream length not managed yet')) + log.error(_('stream length not managed yet')) return profile_jid = client.jid @@ -589,7 +590,7 @@ class XEP_0065(object): def iqResult(self, sid, profile, iq_elt): """Called when the result of open iq is received""" if iq_elt["type"] == "error": - warning(_("Transfer failed")) + log.warning(_("Transfer failed")) return client = self.host.getClient(profile) try: @@ -597,7 +598,7 @@ class XEP_0065(object): file_obj = data["file_obj"] timer = data["timer"] except KeyError: - error(_("Internal error, can't do transfer")) + log.error(_("Internal error, can't do transfer")) return if timer.active(): @@ -607,17 +608,17 @@ class XEP_0065(object): query_elt = iq_elt.firstChildElement() streamhost_elts = filter(lambda elt: elt.name == 'streamhost-used', query_elt.elements()) if not streamhost_elts: - warning(_("No streamhost found in stream query")) + log.warning(_("No streamhost found in stream query")) return streamhost_jid = streamhost_elts[0]['jid'] if streamhost_jid != profile_jid.full(): - debug(_("A proxy server is used")) + log.debug(_("A proxy server is used")) proxy_host = self.host.memory.getParamA("Proxy host", "File Transfer", profile_key=profile) proxy_port = self.host.memory.getParamA("Proxy port", "File Transfer", profile_key=profile) proxy_jid = self.host.memory.getParamA("Proxy", "File Transfer", profile_key=profile) if proxy_jid != streamhost_jid: - warning(_("Proxy jid is not the same as in parameters, this should not happen")) + log.warning(_("Proxy jid is not the same as in parameters, this should not happen")) return factory = Socks5ClientFactory(client.xep_0065_current_stream, sid, None, self.activateProxyStream, lambda sid, success, profile: self._killId(sid, success, profile=profile), True, profile) reactor.connectTCP(proxy_host, int(proxy_port), factory) @@ -625,7 +626,7 @@ class XEP_0065(object): data["start_transfer_cb"](file_obj) # We now activate the stream def activateProxyStream(self, sid, iq_id, start_transfer_cb, profile): - debug(_("activating stream")) + log.debug(_("activating stream")) client = self.host.getClient(profile) data = client.xep_0065_current_stream[sid] profile_jid, xmlstream = self.host.getJidNStream(profile) @@ -641,7 +642,7 @@ class XEP_0065(object): def proxyResult(self, sid, start_transfer_cb, file_obj, iq_elt): if iq_elt['type'] == 'error': - warning(_("Can't activate the proxy stream")) + log.warning(_("Can't activate the proxy stream")) return else: start_transfer_cb(file_obj) @@ -669,7 +670,7 @@ class XEP_0065(object): def streamQuery(self, iq_elt, profile): """Get file using byte stream""" - debug(_("BS stream query")) + log.debug(_("BS stream query")) client = self.host.getClient(profile) if not client: @@ -683,7 +684,7 @@ class XEP_0065(object): streamhost_elts = filter(lambda elt: elt.name == 'streamhost', query_elt.elements()) if not sid in client.xep_0065_current_stream: - warning(_("Ignoring unexpected BS transfer: %s" % sid)) + log.warning(_("Ignoring unexpected BS transfer: %s" % sid)) self.sendNotAcceptableError(iq_elt['id'], iq_elt['from'], xmlstream) return @@ -692,7 +693,7 @@ class XEP_0065(object): client.xep_0065_current_stream[sid]["xmlstream"] = xmlstream if not streamhost_elts: - warning(_("No streamhost found in stream query %s" % sid)) + log.warning(_("No streamhost found in stream query %s" % sid)) self.sendBadRequestError(iq_elt['id'], iq_elt['from'], xmlstream) return @@ -701,19 +702,19 @@ class XEP_0065(object): sh_port = streamhost_elt.getAttribute("port") sh_jid = streamhost_elt.getAttribute("jid") if not sh_host or not sh_port or not sh_jid: - warning(_("incomplete streamhost element")) + log.warning(_("incomplete streamhost element")) self.sendBadRequestError(iq_elt['id'], iq_elt['from'], xmlstream) return client.xep_0065_current_stream[sid]["streamhost"] = (sh_host, sh_port, sh_jid) - info(_("Stream proposed: host=[%(host)s] port=[%(port)s]") % {'host': sh_host, 'port': sh_port}) + log.info(_("Stream proposed: host=[%(host)s] port=[%(port)s]") % {'host': sh_host, 'port': sh_port}) factory = Socks5ClientFactory(client.xep_0065_current_stream, sid, iq_elt["id"], self.activateStream, lambda sid, success, profile: self._killId(sid, success, profile=profile), profile=profile) reactor.connectTCP(sh_host, int(sh_port), factory) def activateStream(self, sid, iq_id, profile): client = self.host.getClient(profile) - debug(_("activating stream")) + log.debug(_("activating stream")) result = domish.Element((None, 'iq')) data = client.xep_0065_current_stream[sid] result['type'] = 'result' @@ -766,18 +767,18 @@ class XEP_0065_handler(XMPPHandler): """Called with the informations about proxy according to XEP-0065 #4 Params should be filled with these infos""" if iq_elt["type"] == "error": - warning(_("Can't determine proxy informations")) + log.warning(_("Can't determine proxy informations")) return query_elt = iq_elt.firstChildElement() if query_elt.name != "query": - warning(_("Bad answer received from proxy")) + log.warning(_("Bad answer received from proxy")) return streamhost_elts = filter(lambda elt: elt.name == 'streamhost', query_elt.elements()) if not streamhost_elts: - warning(_("No streamhost found in stream query")) + log.warning(_("No streamhost found in stream query")) return if len(streamhost_elts) != 1: - warning(_("Multiple streamhost elements in proxy not managed, keeping only the first one")) + log.warning(_("Multiple streamhost elements in proxy not managed, keeping only the first one")) streamhost_elt = streamhost_elts[0] self.host.memory.setParam("Proxy", streamhost_elt.getAttribute("jid", ""), "File Transfer", profile_key=self.parent.profile) @@ -795,7 +796,7 @@ class XEP_0065_handler(XMPPHandler): try: proxy_ent = entities.pop() except KeyError: - info(_("No proxy found on this server")) + log.info(_("No proxy found on this server")) return iq_elt = jabber_client.IQ(self.parent.xmlstream, 'get') iq_elt["to"] = proxy_ent.full() diff --git a/src/plugins/plugin_xep_0071.py b/src/plugins/plugin_xep_0071.py index 5a1a9b63..26cee7e4 100644 --- a/src/plugins/plugin_xep_0071.py +++ b/src/plugins/plugin_xep_0071.py @@ -19,9 +19,10 @@ from sat.core.i18n import _ from sat.core import exceptions -from logging import debug, info, error +from sat.core.log import getLogger +log = getLogger(__name__) -from wokkel import disco, pubsub, iwokkel +from wokkel import disco, iwokkel from zope.interface import implements # from lxml import etree from lxml import html @@ -69,7 +70,7 @@ class XEP_0071(object): SYNTAX_XHTML_IM = "XHTML-IM" def __init__(self, host): - info(_("XHTML-IM plugin initialization")) + log.info(_("XHTML-IM plugin initialization")) self.host = host self.synt_plg = self.host.plugins["TEXT-SYNTAXES"] self.synt_plg.addSyntax(self.SYNTAX_XHTML_IM, lambda xhtml: xhtml, self.XHTML2XHTML_IM, [self.synt_plg.OPT_HIDDEN]) @@ -189,7 +190,7 @@ class XEP_0071(object): for elem in to_strip: if elem.tag in blacklist: #we need to remove the element and all descendants - debug(u"removing black listed tag: %s" % (elem.tag)) + log.debug(u"removing black listed tag: %s" % (elem.tag)) elem.drop_tree() else: elem.drop_tag() diff --git a/src/plugins/plugin_xep_0077.py b/src/plugins/plugin_xep_0077.py index a26ef28d..f917e0cd 100755 --- a/src/plugins/plugin_xep_0077.py +++ b/src/plugins/plugin_xep_0077.py @@ -20,7 +20,8 @@ from sat.core.i18n import _ from sat.core.constants import Const as C from sat.core import exceptions -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.protocols.jabber import jid from twisted.words.protocols.jabber.xmlstream import IQ from sat.tools import xml_tools @@ -43,7 +44,7 @@ PLUGIN_INFO = { class XEP_0077(object): def __init__(self, host): - info(_("Plugin XEP_0077 initialization")) + log.info(_("Plugin XEP_0077 initialization")) self.host = host self.triggers = {} # used by other protocol (e.g. XEP-0100) to finish registration. key = target_jid host.bridge.addMethod("inBandRegister", ".plugin", in_sign='ss', out_sign='s', @@ -61,7 +62,7 @@ class XEP_0077(object): x_elem = query_elt.elements(data_form.NS_X_DATA, 'x').next() except StopIteration: # XXX: it seems we have an old service which doesn't manage data forms - warning(_("Can't find data form")) + log.warning(_("Can't find data form")) raise exceptions.DataError(_("This gateway can't be managed by SàT, sorry :(")) def submitForm(data, profile): @@ -83,17 +84,17 @@ class XEP_0077(object): def _regErr(self, failure, client): """Called when something is wrong with registration""" - info(_("Registration failure: %s") % str(failure.value)) + log.info(_("Registration failure: %s") % str(failure.value)) raise failure def _regSuccess(self, answer, client, post_treat_cb): - debug(_("registration answer: %s") % answer.toXml()) + log.debug(_("registration answer: %s") % answer.toXml()) if post_treat_cb is not None: post_treat_cb(jid.JID(answer['from']), client.profile) return {} def _regFailure(self, failure, client): - info(_("Registration failure: %s") % str(failure.value)) + log.info(_("Registration failure: %s") % str(failure.value)) if failure.value.condition == 'conflict': raise exceptions.ConflictError( _("Username already exists, please choose an other one")) raise failure @@ -104,7 +105,7 @@ class XEP_0077(object): def inBandRegister(self, to_jid, post_treat_cb=None, profile_key=C.PROF_KEY_NONE): """register to a target JID""" client = self.host.getClient(profile_key) - debug(_("Asking registration for [%s]") % to_jid.full()) + log.debug(_("Asking registration for [%s]") % to_jid.full()) reg_request = IQ(client.xmlstream, 'get') reg_request["from"] = client.jid.full() reg_request["to"] = to_jid.full() diff --git a/src/plugins/plugin_xep_0085.py b/src/plugins/plugin_xep_0085.py index 8ef1c8b2..3525c27e 100755 --- a/src/plugins/plugin_xep_0085.py +++ b/src/plugins/plugin_xep_0085.py @@ -20,7 +20,8 @@ from sat.core.i18n import _ from sat.core.constants import Const as C from sat.core import exceptions -from logging import info +from sat.core.log import getLogger +log = getLogger(__name__) from wokkel import disco, iwokkel from zope.interface import implements from twisted.words.protocols.jabber.jid import JID @@ -91,7 +92,7 @@ class XEP_0085(object): } def __init__(self, host): - info(_("Chat State Notifications plugin initialization")) + log.info(_("Chat State Notifications plugin initialization")) self.host = host # parameter value is retrieved before each use diff --git a/src/plugins/plugin_xep_0092.py b/src/plugins/plugin_xep_0092.py index fd03bd8d..2673f622 100644 --- a/src/plugins/plugin_xep_0092.py +++ b/src/plugins/plugin_xep_0092.py @@ -23,7 +23,8 @@ from twisted.internet import reactor, defer from twisted.words.protocols.jabber import jid from wokkel import compat from sat.core import exceptions -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) NS_VERSION = "jabber:iq:version" TIMEOUT = 10 @@ -44,13 +45,13 @@ PLUGIN_INFO = { class XEP_0092(object): def __init__(self, host): - info(_("Plugin XEP_0092 initialization")) + log.info(_("Plugin XEP_0092 initialization")) self.host = host host.bridge.addMethod("getSoftwareVersion", ".plugin", in_sign='ss', out_sign='(sss)', method=self._getVersion, async=True) try: self.host.plugins[C.TEXT_CMDS].addWhoIsCb(self._whois, 50) except KeyError: - info(_("Text commands not available")) + log.info(_("Text commands not available")) def _getVersion(self, entity_jid_s, profile_key): def prepareForBridge(data): diff --git a/src/plugins/plugin_xep_0095.py b/src/plugins/plugin_xep_0095.py index 459df5e9..0f942cf4 100644 --- a/src/plugins/plugin_xep_0095.py +++ b/src/plugins/plugin_xep_0095.py @@ -19,7 +19,8 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.xish import domish from twisted.words.protocols.jabber import client import uuid @@ -52,7 +53,7 @@ PLUGIN_INFO = { class XEP_0095(object): def __init__(self, host): - info(_("Plugin XEP_0095 initialization")) + log.info(_("Plugin XEP_0095 initialization")) self.host = host self.si_profiles = {} # key: SI profile, value: callback @@ -69,7 +70,7 @@ class XEP_0095(object): """This method is called on stream initiation (XEP-0095 #3.2) @param iq_el: IQ element @param profile: %(doc_profile)s""" - info(_("XEP-0095 Stream initiation")) + log.info(_("XEP-0095 Stream initiation")) iq_el.handled = True si_el = iq_el.firstChildElement() si_id = si_el.getAttribute('id') @@ -110,7 +111,7 @@ class XEP_0095(object): @param iq_id: IQ id @param to_jid: recipient @param profile: %(doc_profile)s""" - self.sendError(iq_id, to_jid, 500, 'cancel', {'custom': 'failed'}, profile=profile) # as there is no error code for failed transfer, we use 500 (undefined-condition) + self.sendError(iq_id, to_jid, 500, 'cancel', {'custom': 'failed'}, profile=profile) # as there is no lerror code for failed transfer, we use 500 (undefined-condition) def sendError(self, iq_id, to_jid, err_code, err_type='cancel', data={}, profile=C.PROF_KEY_NONE): """Send IQ error as a result @@ -154,7 +155,7 @@ class XEP_0095(object): @param profile: %(doc_profile)s""" _client = self.host.getClient(profile) assert(_client) - info(_("sending stream initiation accept answer")) + log.info(_("sending stream initiation accept answer")) result = domish.Element((None, 'iq')) result['type'] = 'result' result['id'] = iq_id @@ -176,12 +177,12 @@ class XEP_0095(object): @return: session id, offer""" current_jid, xmlstream = self.host.getJidNStream(profile_key) if not xmlstream: - error(_('Asking for an non-existant or not connected profile')) + log.error(_('Asking for an non-existant or not connected profile')) return "" offer = client.IQ(xmlstream, 'set') sid = str(uuid.uuid4()) - debug(_("Stream Session ID: %s") % offer["id"]) + log.debug(_("Stream Session ID: %s") % offer["id"]) offer["from"] = current_jid.full() offer["to"] = to_jid.full() diff --git a/src/plugins/plugin_xep_0096.py b/src/plugins/plugin_xep_0096.py index d8c8ff20..9e8acd8a 100755 --- a/src/plugins/plugin_xep_0096.py +++ b/src/plugins/plugin_xep_0096.py @@ -19,10 +19,11 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.xish import domish from twisted.words.protocols.jabber import jid -from twisted.words.protocols.jabber import error as jab_error +from twisted.words.protocols import jabber import os from twisted.internet import reactor @@ -47,7 +48,7 @@ PLUGIN_INFO = { class XEP_0096(object): def __init__(self, host): - info(_("Plugin XEP_0096 initialization")) + log.info(_("Plugin XEP_0096 initialization")) self.host = host self.managed_stream_m = [self.host.plugins["XEP-0065"].NAMESPACE, self.host.plugins["XEP-0047"].NAMESPACE] # Stream methods managed @@ -62,12 +63,12 @@ class XEP_0096(object): def _kill_id(self, approval_id, profile): """Delete a waiting_for_approval id, called after timeout @param approval_id: id of _xep_0096_waiting_for_approval""" - info(_("SI File Transfer: TimeOut reached for id %s") % approval_id) + log.info(_("SI File Transfer: TimeOut reached for id %s") % approval_id) try: client = self.host.getClient(profile) del client._xep_0096_waiting_for_approval[approval_id] except KeyError: - warning(_("kill id called on a non existant approval id")) + log.warning(_("kill id called on a non existant approval id")) def transferRequest(self, iq_id, from_jid, si_id, si_mime_type, si_el, profile): """Called when a file transfer is requested @@ -77,8 +78,8 @@ class XEP_0096(object): @param si_mime_type: Mime type of the file (or default "application/octet-stream" if unknown) @param si_el: domish.Element of the request @param profile: %(doc_profile)s""" - info(_("XEP-0096 file transfer requested")) - debug(si_el.toXml()) + log.info(_("XEP-0096 file transfer requested")) + log.debug(si_el.toXml()) client = self.host.getClient(profile) filename = "" file_size = "" @@ -95,14 +96,14 @@ class XEP_0096(object): file_size = file_el["size"] file_date = file_el.getAttribute("date", "") file_hash = file_el.getAttribute("hash", "") - info(_("File proposed: name=[%(name)s] size=%(size)s") % {'name': filename, 'size': file_size}) + log.info(_("File proposed: name=[%(name)s] size=%(size)s") % {'name': filename, 'size': file_size}) for file_child_el in file_el.elements(): if file_child_el.name == "desc": file_desc = unicode(file_child_el) elif file_child_el.name == "range": can_range = True else: - warning(_("No file element found")) + log.warning(_("No file element found")) self.host.plugins["XEP-0095"].sendBadRequestError(iq_id, from_jid, profile) return @@ -112,15 +113,15 @@ class XEP_0096(object): try: stream_method = self.host.plugins["XEP-0020"].negociate(feature_el, 'stream-method', self.managed_stream_m) except KeyError: - warning(_("No stream method found")) + log.warning(_("No stream method found")) self.host.plugins["XEP-0095"].sendBadRequestError(iq_id, from_jid, profile) return if not stream_method: - warning(_("Can't find a valid stream method")) + log.warning(_("Can't find a valid stream method")) self.host.plugins["XEP-0095"].sendFailedError(iq_id, from_jid, profile) return else: - warning(_("No feature element found")) + log.warning(_("No feature element found")) self.host.plugins["XEP-0095"].sendBadRequestError(iq_id, from_jid, profile) return @@ -152,7 +153,7 @@ class XEP_0096(object): try: dest_path = frontend_data['dest_path'] except KeyError: - error(_('dest path not found in frontend_data')) + log.error(_('dest path not found in frontend_data')) del(client._xep_0096_waiting_for_approval[sid]) return if stream_method == self.host.plugins["XEP-0065"].NAMESPACE: @@ -164,7 +165,7 @@ class XEP_0096(object): range_offset = file_obj.tell() self.host.plugins["XEP-0047"].prepareToReceive(jid.JID(data['from']), sid, file_obj, int(data["size"]), self._transferSucceeded, self._transferFailed, profile) else: - error(_("Unknown stream method, this should not happen at this stage, cancelling transfer")) + log.error(_("Unknown stream method, this should not happen at this stage, cancelling transfer")) del(client._xep_0096_waiting_for_approval[sid]) return @@ -179,7 +180,7 @@ class XEP_0096(object): misc_elts.append(range_elt) self.host.plugins["XEP-0095"].acceptStream(data["id"], data['from'], feature_elt, misc_elts, profile) else: - debug(_("Transfer [%s] refused"), sid) + log.debug(_("Transfer [%s] refused"), sid) self.host.plugins["XEP-0095"].sendRejectedError(data["id"], data['from'], profile=profile) del(client._xep_0096_waiting_for_approval[sid]) @@ -188,7 +189,7 @@ class XEP_0096(object): @param id: stream id""" client = self.host.getClient(profile) file_obj.close() - info(_('Transfer %s successfuly finished') % sid) + log.info(_('Transfer %s successfuly finished') % sid) del(client._xep_0096_waiting_for_approval[sid]) def _transferFailed(self, sid, file_obj, stream_method, reason, profile): @@ -197,7 +198,7 @@ class XEP_0096(object): @param reason: can be TIMEOUT, IO_ERROR, PROTOCOL_ERROR""" client = self.host.getClient(profile) data, timeout, stream_method, failed_methods = client._xep_0096_waiting_for_approval[sid] - warning(_('Transfer %(id)s failed with stream method %(s_method)s: %(reason)s') % { + log.warning(_('Transfer %(id)s failed with stream method %(s_method)s: %(reason)s') % { 'id': sid, 's_method': stream_method, 'reason': reason}) @@ -205,36 +206,36 @@ class XEP_0096(object): file_obj.close() os.remove(filepath) #TODO: session remenber (within a time limit) when a stream method fail, and avoid that stream method with full jid for the rest of the session - warning(_("All stream methods failed, can't transfer the file")) + log.warning(_("All stream methods failed, can't transfer the file")) del(client._xep_0096_waiting_for_approval[sid]) def fileCb(self, filepath, sid, size, profile, IQ): if IQ['type'] == "error": - stanza_err = jab_error.exceptionFromStanza(IQ) + stanza_err = jabber.error.exceptionFromStanza(IQ) if stanza_err.code == '403' and stanza_err.condition == 'forbidden': - debug(_("File transfer refused by %s") % IQ['from']) + log.debug(_("File transfer refused by %s") % IQ['from']) self.host.bridge.newAlert(_("The contact %s refused your file") % IQ['from'], _("File refused"), "INFO", profile) else: - warning(_("Error during file transfer with %s") % IQ['from']) + log.warning(_("Error during file transfer with %s") % IQ['from']) self.host.bridge.newAlert(_("Something went wrong during the file transfer session intialisation with %s") % IQ['from'], _("File transfer error"), "ERROR", profile) return si_elt = IQ.firstChildElement() if IQ['type'] != "result" or not si_elt or si_elt.name != "si": - error(_("Protocol error during file transfer")) + log.error(_("Protocol error during file transfer")) return feature_elts = self.host.plugins["XEP-0020"].getFeatureElt(si_elt) if not feature_elts: - warning(_("No feature element")) + log.warning(_("No feature element")) return choosed_options = self.host.plugins["XEP-0020"].getChoosedOptions(feature_elts[0]) try: stream_method = choosed_options["stream-method"] except KeyError: - warning(_("No stream method choosed")) + log.warning(_("No stream method choosed")) return range_offset = 0 @@ -256,7 +257,7 @@ class XEP_0096(object): file_obj.seek(range_offset) self.host.plugins["XEP-0047"].startStream(file_obj, jid.JID(IQ['from']), sid, range_length, self.sendSuccessCb, self.sendFailureCb, size, profile) else: - warning(_("Invalid stream method received")) + log.warning(_("Invalid stream method received")) def sendFile(self, to_jid, filepath, data={}, profile_key=C.PROF_KEY_NONE): """send a file using XEP-0096 @@ -269,16 +270,16 @@ class XEP_0096(object): """ profile = self.host.memory.getProfileName(profile_key) if not profile: - warning(_("Trying to send a file from an unknown profile")) + log.warning(_("Trying to send a file from an unknown profile")) return "" feature_elt = self.host.plugins["XEP-0020"].proposeFeatures({'stream-method': self.managed_stream_m}) file_transfer_elts = [] - statinfo = os.stat(filepath) + statlog.info = os.stat(filepath) file_elt = domish.Element((PROFILE, 'file')) file_elt['name'] = os.path.basename(filepath) - size = file_elt['size'] = str(statinfo.st_size) + size = file_elt['size'] = str(statlog.info.st_size) file_transfer_elts.append(file_elt) file_transfer_elts.append(domish.Element((None, 'range'))) @@ -288,10 +289,10 @@ class XEP_0096(object): return sid def sendSuccessCb(self, sid, file_obj, stream_method, profile): - info(_('Transfer %(sid)s successfuly finished [%(profile)s]') + log.info(_('Transfer %(sid)s successfuly finished [%(profile)s]') % {"sid": sid, "profile": profile}) file_obj.close() def sendFailureCb(self, sid, file_obj, stream_method, reason, profile): file_obj.close() - warning(_('Transfer %(id)s failed with stream method %(s_method)s: %(reason)s [%(profile)s]') % {'id': sid, "s_method": stream_method, 'reason': reason, 'profile': profile}) + log.warning(_('Transfer %(id)s failed with stream method %(s_method)s: %(reason)s [%(profile)s]') % {'id': sid, "s_method": stream_method, 'reason': reason, 'profile': profile}) diff --git a/src/plugins/plugin_xep_0100.py b/src/plugins/plugin_xep_0100.py index 124747a0..79928b2a 100755 --- a/src/plugins/plugin_xep_0100.py +++ b/src/plugins/plugin_xep_0100.py @@ -21,7 +21,8 @@ from sat.core.i18n import _, D_ from sat.core.constants import Const as C from sat.core import exceptions from sat.tools import xml_tools -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.protocols.jabber import jid from twisted.internet import reactor, defer @@ -55,7 +56,7 @@ TYPE_DESCRIPTIONS = { 'irc': D_("Internet Relay Chat"), class XEP_0100(object): def __init__(self, host): - info(_("Gateways plugin initialization")) + log.info(_("Gateways plugin initialization")) self.host = host self.__gateways = {} # dict used to construct the answer to findGateways. Key = target jid host.bridge.addMethod("findGateways", ".plugin", in_sign='ss', out_sign='s', method=self._findGateways) @@ -111,7 +112,7 @@ class XEP_0100(object): try: target_jid = jid.JID(data['index']) except (KeyError, RuntimeError): - warning(_("No gateway index selected")) + log.warning(_("No gateway index selected")) return {} d = self.gatewayRegister(target_jid, profile) @@ -125,7 +126,7 @@ class XEP_0100(object): """ category, type_ = identity if category != 'gateway': - error(_('INTERNAL ERROR: identity category should always be "gateway" in _getTypeString, got "%s"') % category) + log.error(_('INTERNAL ERROR: identity category should always be "gateway" in _getTypeString, got "%s"') % category) try: return _(TYPE_DESCRIPTIONS[type_]) except KeyError: @@ -133,7 +134,7 @@ class XEP_0100(object): def _registrationSuccessful(self, jid_, profile): """Called when in_band registration is ok, we must now follow the rest of procedure""" - debug(_("Registration successful, doing the rest")) + log.debug(_("Registration successful, doing the rest")) self.host.addContact(jid_, profile_key=profile) self.host.setPresence(jid_, profile_key=profile) @@ -167,22 +168,22 @@ class XEP_0100(object): entity = items[idx].entity gateways = [(identity, result.identities[identity]) for identity in result.identities if identity[0] == 'gateway'] if gateways: - info (_("Found gateway [%(jid)s]: %(identity_name)s") % {'jid': entity.full(), 'identity_name': ' - '.join([gateway[1] for gateway in gateways])}) + log.info (_("Found gateway [%(jid)s]: %(identity_name)s") % {'jid': entity.full(), 'identity_name': ' - '.join([gateway[1] for gateway in gateways])}) ret.append((success, (entity, gateways))) else: - info(_("Skipping [%(jid)s] which is not a gateway") % {'jid': entity.full()}) + log.info(_("Skipping [%(jid)s] which is not a gateway") % {'jid': entity.full()}) return ret def _itemsReceived(self, disco, target, client): """Look for items with disco protocol, and ask infos for each one""" if len(disco._items) == 0: - debug(_("No gateway found")) + log.debug(_("No gateway found")) return [] _defers = [] for item in disco._items: - debug(_("item found: %s"), item.entity) + log.debug(_("item found: %s"), item.entity) _defers.append(client.disco.requestInfo(item.entity)) dl = defer.DeferredList(_defers) dl.addCallback(self._infosReceived, items=disco._items, target=target, client=client) @@ -205,7 +206,7 @@ class XEP_0100(object): """Find gateways in the target JID, using discovery protocol """ client = self.host.getClient(profile) - debug(_("find gateways (target = %(target)s, profile = %(profile)s)") % {'target': target.full(), 'profile': profile}) + log.debug(_("find gateways (target = %(target)s, profile = %(profile)s)") % {'target': target.full(), 'profile': profile}) d = client.disco.requestItems(target) d.addCallback(self._itemsReceived , target=target, client=client) return d diff --git a/src/plugins/plugin_xep_0115.py b/src/plugins/plugin_xep_0115.py index 10933768..9ea0d50c 100755 --- a/src/plugins/plugin_xep_0115.py +++ b/src/plugins/plugin_xep_0115.py @@ -19,7 +19,8 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, error, warning +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.xish import domish from twisted.words.protocols.jabber import jid from twisted.internet import defer @@ -52,7 +53,7 @@ class XEP_0115(object): cap_hash = None # capabilities hash is class variable as it is common to all profiles def __init__(self, host): - info(_("Plugin XEP_0115 initialization")) + log.info(_("Plugin XEP_0115 initialization")) self.host = host host.trigger.add("Disco handled", self._checkHash) host.trigger.add("Presence send", self._presenceTrigger) @@ -69,10 +70,10 @@ class XEP_0115(object): def updateOptimize(optimize): client.caps_optimize = optimize if optimize: - info(_("Caps optimisation enabled")) + log.info(_("Caps optimisation enabled")) client.caps_sent = False else: - warning(_("Caps optimisation not available")) + log.warning(_("Caps optimisation not available")) disco_d.addCallback(updateOptimize) disco_d.addCallback(lambda dummy: self.recalculateHash(profile)) return True @@ -94,8 +95,8 @@ class XEP_0115(object): for item in _infos: disco_infos.append(item) cap_hash = self.host.memory.disco.generateHash(disco_infos) - info("Our capability hash has been generated: [%s]" % cap_hash) - debug("Generating capability domish.Element") + log.info("Our capability hash has been generated: [%s]" % cap_hash) + log.debug("Generating capability domish.Element") c_elt = domish.Element((NS_ENTITY_CAPABILITY, 'c')) c_elt['hash'] = 'sha-1' c_elt['node'] = C.APP_URL @@ -140,21 +141,21 @@ class XEP_0115_handler(XMPPHandler): c_hash = c_elem['hash'] c_node = c_elem['node'] except KeyError: - warning(_('Received invalid capabilities tag')) + log.warning(_('Received invalid capabilities tag')) return if c_ver in self.host.memory.disco.hashes: # we already know the hash, we update the jid entity - debug ("hash [%(hash)s] already in cache, updating entity [%(jid)s]" % {'hash': c_ver, 'jid': from_jid.full()}) + log.debug ("hash [%(hash)s] already in cache, updating entity [%(jid)s]" % {'hash': c_ver, 'jid': from_jid.full()}) self.host.memory.updateEntityData(from_jid, C.ENTITY_CAP_HASH, c_ver, self.profile) return yield self.host.getDiscoInfos(from_jid, self.profile) if c_hash != 'sha-1': #unknown hash method - warning(_('Unknown hash method for entity capabilities: [%(hash_method)s] (entity: %(jid)s, node: %(node)s)') % {'hash_method':c_hash, 'jid': from_jid, 'node': c_node}) + log.warning(_('Unknown hash method for entity capabilities: [%(hash_method)s] (entity: %(jid)s, node: %(node)s)') % {'hash_method':c_hash, 'jid': from_jid, 'node': c_node}) computed_hash = self.host.memory.getEntityDatum(from_jid, C.ENTITY_CAP_HASH, self.profile) if computed_hash != c_ver: - warning(_('Computed hash differ from given hash:\ngiven: [%(given_hash)s]\ncomputed: [%(computed_hash)s]\n(entity: %(jid)s, node: %(node)s)') % {'given_hash':c_ver, 'computed_hash': computed_hash, 'jid': from_jid, 'node': c_node}) + log.warning(_('Computed hash differ from given hash:\ngiven: [%(given_hash)s]\ncomputed: [%(computed_hash)s]\n(entity: %(jid)s, node: %(node)s)') % {'given_hash':c_ver, 'computed_hash': computed_hash, 'jid': from_jid, 'node': c_node}) # TODO: me must manage the full algorithm described at XEP-0115 #5.4 part 3 diff --git a/src/plugins/plugin_xep_0163.py b/src/plugins/plugin_xep_0163.py index 7e4028da..1b80baca 100755 --- a/src/plugins/plugin_xep_0163.py +++ b/src/plugins/plugin_xep_0163.py @@ -18,17 +18,14 @@ # along with this program. If not, see . from sat.core.i18n import _ +from sat.core import exceptions from sat.core.constants import Const as C -from logging import debug, info, error -from twisted.internet import protocol -from twisted.words.protocols.jabber import client, jid -from twisted.words.protocols.jabber import error as jab_error -import twisted.internet.error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.xish import domish from wokkel import disco, pubsub from wokkel.formats import Mood -from sat.core import exceptions NS_USER_MOOD = 'http://jabber.org/protocol/mood' @@ -47,7 +44,7 @@ PLUGIN_INFO = { class XEP_0163(object): def __init__(self, host): - info(_("PEP plugin initialization")) + log.info(_("PEP plugin initialization")) self.host = host self.pep_events = set() self.pep_out_cb = {} @@ -95,25 +92,25 @@ class XEP_0163(object): """ profile = self.host.memory.getProfileName(profile_key) if not profile: - error(_('Trying to send personal event with an unknown profile key [%s]') % profile_key) + log.error(_('Trying to send personal event with an unknown profile key [%s]') % profile_key) raise exceptions.ProfileUnknownError if not event_type in self.pep_out_cb.keys(): - error(_('Trying to send personal event for an unknown type')) - raise DataError('Type unknown') + log.error(_('Trying to send personal event for an unknown type')) + raise exceptions.DataError('Type unknown') return self.pep_out_cb[event_type](data, profile) def userMoodCB(self, itemsEvent, profile): if not itemsEvent.items: - debug(_("No item found")) + log.debug(_("No item found")) return try: mood_elt = [child for child in itemsEvent.items[0].elements() if child.name == "mood"][0] except IndexError: - error(_("Can't find mood element in mood event")) + log.error(_("Can't find mood element in mood event")) return mood = Mood.fromXml(mood_elt) if not mood: - debug(_("No mood found")) + log.debug(_("No mood found")) return self.host.bridge.personalEvent(itemsEvent.sender.full(), "MOOD", {"mood": mood.value or "", "text": mood.text or ""}, profile) diff --git a/src/plugins/plugin_xep_0249.py b/src/plugins/plugin_xep_0249.py index a966b642..271b700e 100755 --- a/src/plugins/plugin_xep_0249.py +++ b/src/plugins/plugin_xep_0249.py @@ -19,14 +19,14 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.xish import domish -from twisted.internet import protocol, defer -from twisted.words.protocols.jabber import client, jid, xmlstream +from twisted.words.protocols.jabber import jid from zope.interface import implements -from wokkel import disco, iwokkel, data_form +from wokkel import disco, iwokkel try: @@ -76,7 +76,7 @@ class XEP_0249(object): } def __init__(self, host): - info(_("Plugin XEP_0249 initialization")) + log.info(_("Plugin XEP_0249 initialization")) self.host = host host.memory.updateParams(self.params) host.bridge.addMethod("inviteMUC", ".plugin", in_sign='sssa{ss}s', out_sign='', method=self._invite) @@ -94,7 +94,7 @@ class XEP_0249(object): """ profile = self.host.memory.getProfileName(profile_key) if not profile: - error(_("Profile doesn't exists !")) + log.error(_("Profile doesn't exists !")) return message = domish.Element((None, 'message')) message["to"] = target.full() @@ -122,11 +122,12 @@ class XEP_0249(object): """ profile = self.host.memory.getProfileName(profile_key) if not profile: - error(_("Profile doesn't exists !")) + log.error(_("Profile doesn't exists !")) return - info(_('Invitation accepted for room %(room)s [%(profile)s]') % {'room': room, 'profile': profile}) + log.info(_('Invitation accepted for room %(room)s [%(profile)s]') % {'room': room, 'profile': profile}) _jid, xmlstream = self.host.getJidNStream(profile) d = self.host.plugins["XEP-0045"].join(jid.JID(room), _jid.user, {}, profile) + return d def onInvitation(self, message, profile): """ @@ -136,13 +137,13 @@ class XEP_0249(object): """ try: room = message.firstChildElement()['jid'] - info(_('Invitation received for room %(room)s [%(profile)s]') % {'room': room, 'profile': profile}) + log.info(_('Invitation received for room %(room)s [%(profile)s]') % {'room': room, 'profile': profile}) except: - error(_('Error while parsing invitation')) + log.error(_('Error while parsing invitation')) return from_ = message["from"] if room in self.host.plugins["XEP-0045"].clients[profile].joined_rooms: - info(_("Invitation silently discarded because user is already in the room.")) + log.info(_("Invitation silently discarded because user is already in the room.")) return autojoin = self.host.memory.getParamA(AUTOJOIN_NAME, AUTOJOIN_KEY, profile_key=profile) diff --git a/src/plugins/plugin_xep_0277.py b/src/plugins/plugin_xep_0277.py index 24a4bbed..2bbba8c9 100755 --- a/src/plugins/plugin_xep_0277.py +++ b/src/plugins/plugin_xep_0277.py @@ -19,7 +19,8 @@ from sat.core.i18n import _ from sat.core.constants import Const as C -from logging import debug, info, warning, error +from sat.core.log import getLogger +log = getLogger(__name__) from twisted.words.protocols.jabber import jid from twisted.internet import defer from sat.core import exceptions @@ -56,7 +57,7 @@ class NodeAccessChangeException(Exception): class XEP_0277(object): def __init__(self, host): - info(_("Microblogging plugin initialization")) + log.info(_("Microblogging plugin initialization")) self.host = host self.host.plugins["XEP-0163"].addPEPEvent("MICROBLOG", NS_MICROBLOG, self.microblogCB, self.sendMicroblog) host.bridge.addMethod("getLastMicroblogs", ".plugin", @@ -153,7 +154,7 @@ class XEP_0277(object): microblog_data['updated'] = date2float(entry_elt, 'updated') assert('title' in microblog_data) # has been processed already except IndexError: - error(_("Atom entry %s misses a required element") % item_elt.get('id', '')) + log.error(_("Atom entry %s misses a required element") % item_elt.get('id', '')) raise exceptions.DataError if 'content' not in microblog_data: # use the atom title data as the microblog body content @@ -179,7 +180,7 @@ class XEP_0277(object): microblog_data['comments_service'] = service.full() microblog_data['comments_node'] = node except (exceptions.DataError, RuntimeError, KeyError): - warning(_("Can't parse the link element of pubsub entry %s") % microblog_data['id']) + log.warning(_("Can't parse the link element of pubsub entry %s") % microblog_data['id']) except: pass try: @@ -188,7 +189,7 @@ class XEP_0277(object): try: # XXX: workaround for Jappix behaviour microblog_data['author'] = xpath(entry_elt, 'author/nick')[0].text except IndexError: - warning(_("Can't find author element in pubsub entry %s") % microblog_data['id']) + log.warning(_("Can't find author element in pubsub entry %s") % microblog_data['id']) defer.returnValue(microblog_data) @@ -300,11 +301,11 @@ class XEP_0277(object): @param data: must include content @param profile: profile which send the mood""" if 'content' not in data: - error(_("Microblog data must contain at least 'content' key")) + log.error(_("Microblog data must contain at least 'content' key")) raise exceptions.DataError('no "content" key found') content = data['content'] if not content: - error(_("Microblog data's content value must not be empty")) + log.error(_("Microblog data's content value must not be empty")) raise exceptions.DataError('empty content') item = yield self.data2entry(data, profile) ret = yield self.host.plugins["XEP-0060"].publish(None, NS_MICROBLOG, [item], profile_key=profile) @@ -322,7 +323,7 @@ class XEP_0277(object): if success: ret.append(value) else: - error('Error while getting last microblog') + log.error('Error while getting last microblog') return ret d = self.host.plugins["XEP-0060"].getItems(jid.JID(pub_jid), NS_MICROBLOG, max_items=max_items, profile_key=profile_key) @@ -338,18 +339,18 @@ class XEP_0277(object): _jid, xmlstream = self.host.getJidNStream(profile_key) if not _jid: - error(_("Can't find profile's jid")) + log.error(_("Can't find profile's jid")) return C = self.host.plugins["XEP-0060"] _options = {C.OPT_ACCESS_MODEL: access, C.OPT_PERSIST_ITEMS: 1, C.OPT_MAX_ITEMS: -1, C.OPT_DELIVER_PAYLOADS: 1, C.OPT_SEND_ITEM_SUBSCRIBE: 1} def cb(result): #Node is created with right permission - debug(_("Microblog node has now access %s") % access) + log.debug(_("Microblog node has now access %s") % access) def fatal_err(s_error): #Something went wrong - error(_("Can't set microblog access")) + log.error(_("Can't set microblog access")) raise NodeAccessChangeException() def err_cb(s_error): diff --git a/src/test/test_plugin_misc_radiocol.py b/src/test/test_plugin_misc_radiocol.py index 97d951e8..170b4725 100644 --- a/src/test/test_plugin_misc_radiocol.py +++ b/src/test/test_plugin_misc_radiocol.py @@ -20,7 +20,6 @@ """ Tests for the plugin radiocol """ -from sat.core.i18n import _ from sat.core import exceptions from sat.test import helpers, helpers_plugins from sat.plugins import plugin_misc_radiocol as plugin @@ -64,7 +63,7 @@ class RadiocolTest(helpers.SatTestCase): self.plugin_0249 = self.host.plugins['XEP-0249'] = helpers_plugins.FakeXEP_0249(self.host) logger = logging.getLogger() level = logger.getEffectiveLevel() - logger.setLevel(logging.WARNING) # remove info pollution + logger.setLevel(logging.WARNING) # remove log.info pollution for profile in Const.PROFILE: self.host.getClient(profile) # init self.host.profiles[profile] logger.setLevel(level) diff --git a/src/test/test_plugin_misc_room_game.py b/src/test/test_plugin_misc_room_game.py index cab4d49e..fb03fa27 100644 --- a/src/test/test_plugin_misc_room_game.py +++ b/src/test/test_plugin_misc_room_game.py @@ -26,7 +26,6 @@ from sat.test import helpers, helpers_plugins from sat.plugins import plugin_misc_room_game as plugin from twisted.words.protocols.jabber.jid import JID from wokkel.muc import User -import traceback import logging # Data used for test initialization @@ -61,7 +60,7 @@ class RoomGameTest(helpers.SatTestCase): self.plugin_0249 = self.host.plugins['XEP-0249'] = helpers_plugins.FakeXEP_0249(self.host) logger = logging.getLogger() level = logger.getEffectiveLevel() - logger.setLevel(logging.WARNING) # remove info pollution + logger.setLevel(logging.WARNING) # remove log.info pollution for profile in Const.PROFILE: self.host.getClient(profile) # init self.host.profiles[profile] logger.setLevel(level) diff --git a/src/test/test_plugin_xep_0033.py b/src/test/test_plugin_xep_0033.py index c9c3c0a9..7837aa0e 100644 --- a/src/test/test_plugin_xep_0033.py +++ b/src/test/test_plugin_xep_0033.py @@ -111,7 +111,7 @@ class XEP_0033Test(helpers.SatTestCase): host = JID(to_jid.host) logger = logging.getLogger() level = logger.getEffectiveLevel() - logger.setLevel(logging.ERROR) # remove warning pollution + logger.setLevel(logging.ERROR) # remove log.warning pollution if self.host.memory.hasServerFeature(plugin.NS_ADDRESS, host, Const.PROFILE[0]): if host not in cache: sent.append(host) @@ -136,7 +136,7 @@ class XEP_0033Test(helpers.SatTestCase): """ logger = logging.getLogger() level = logger.getEffectiveLevel() - logger.setLevel(logging.ERROR) # remove warning pollution + logger.setLevel(logging.ERROR) # remove log.warning pollution pre_treatments = defer.Deferred() post_treatments = defer.Deferred() self.plugin.sendMessageTrigger(data, pre_treatments, post_treatments, Const.PROFILE[0]) diff --git a/src/tools/misc.py b/src/tools/misc.py index b35c1e32..1a6f6b43 100644 --- a/src/tools/misc.py +++ b/src/tools/misc.py @@ -21,7 +21,8 @@ from sat.core.i18n import _ import sys -from logging import debug, warning +from sat.core.log import getLogger +log = getLogger(__name__) class TriggerException(Exception): @@ -55,9 +56,9 @@ class TriggerManager(object): self.__triggers[point_name] = [] if priority != 0 and priority in [trigger_tuple[0] for trigger_tuple in self.__triggers[point_name]]: if priority in (self.MIN_PRIORITY, self.MAX_PRIORITY): - warning(_("There is already a bound priority [%s]") % point_name) + log.warning(_("There is already a bound priority [%s]") % point_name) else: - debug(_("There is already a trigger with the same priority [%s]") % point_name) + log.debug(_("There is already a trigger with the same priority [%s]") % point_name) self.__triggers[point_name].append((priority, callback)) self.__triggers[point_name].sort(key=lambda trigger_tuple: trigger_tuple[0], reverse=True) diff --git a/src/tools/xml_tools.py b/src/tools/xml_tools.py index 1da5bc89..30732293 100644 --- a/src/tools/xml_tools.py +++ b/src/tools/xml_tools.py @@ -18,7 +18,8 @@ # along with this program. If not, see . from sat.core.i18n import _ -from logging import debug, info, error, warning +from sat.core.log import getLogger +log = getLogger(__name__) from xml.dom import minidom, NotFoundErr from wokkel import data_form from twisted.words.xish import domish @@ -46,7 +47,7 @@ def _dataFormField2XMLUIData(field): widget_type = 'text' if field.value is None: if field.label is None: - warning(_("Fixed field has neither value nor label, ignoring it")) + log.warning(_("Fixed field has neither value nor label, ignoring it")) field.value = "" else: field.value = field.label @@ -65,7 +66,7 @@ def _dataFormField2XMLUIData(field): del widget_args[0] widget_kwargs["options"] = [(option.value, option.label or option.value) for option in field.options] else: - error(u"FIXME FIXME FIXME: Type [%s] is not managed yet by SàT" % field.fieldType) + log.error(u"FIXME FIXME FIXME: Type [%s] is not managed yet by SàT" % field.fieldType) widget_type = "string" if field.var: @@ -131,7 +132,7 @@ def dataFormResult2AdvancedList(xmlui, form_xml): for item_elt in item_elts: for elt in item_elt.elements(): if elt.name != 'field': - warning("Unexpected tag (%s)" % elt.name) + log.warning("Unexpected tag (%s)" % elt.name) continue field = data_form.Field.fromElement(elt) @@ -699,7 +700,7 @@ class ListWidget(InputWidget): style = set() styles = set(style) if not options: - warning(_('empty "options" list')) + log.warning(_('empty "options" list')) if not styles.issubset(['multi']): raise exceptions.DataError(_("invalid styles")) super(ListWidget, self).__init__(xmlui, name, parent)