# HG changeset patch # User Goffi # Date 1397927959 -7200 # Node ID 301b342c697a4390f745f8abe449ec0b59653422 # Parent f51a1895275c3dcc268eb885ed815258ff35785f core: use of the new core.log module: /!\ this is a massive refactoring and was largely automated, it probably did bring some bugs /!\ diff -r f51a1895275c -r 301b342c697a frontends/src/bridge/DBus.py --- a/frontends/src/bridge/DBus.py Sat Apr 19 16:48:26 2014 +0200 +++ b/frontends/src/bridge/DBus.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/bridge/DBus.py --- a/src/bridge/DBus.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/bridge/DBus.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/bridge/bridge.py --- a/src/bridge/bridge.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/bridge/bridge.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 -r f51a1895275c -r 301b342c697a src/bridge/bridge_constructor/dbus_core_template.py --- a/src/bridge/bridge_constructor/dbus_core_template.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/bridge/bridge_constructor/dbus_core_template.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/bridge/bridge_constructor/dbus_frontend_template.py --- a/src/bridge/bridge_constructor/dbus_frontend_template.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/bridge/bridge_constructor/dbus_frontend_template.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/core/sat_main.py --- a/src/core/sat_main.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/core/sat_main.py Sat Apr 19 19:19:19 2014 +0200 @@ -25,20 +25,18 @@ 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 @@ 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 @@ 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 @@ """ 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 @@ """ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ """ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ @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 @@ # 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 @@ 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 @@ """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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/core/xmpp.py --- a/src/core/xmpp.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/core/xmpp.py Sat Apr 19 19:19:19 2014 +0200 @@ -22,7 +22,8 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ # 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/memory/disco.py --- a/src/memory/disco.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/memory/disco.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ # 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/memory/memory.py --- a/src/memory/memory.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/memory/memory.py Sat Apr 19 19:19:19 2014 +0200 @@ -24,7 +24,8 @@ 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 @@ 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 @@ 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 @@ """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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ """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 -r f51a1895275c -r 301b342c697a src/memory/params.py --- a/src/memory/params.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/memory/params.py Sat Apr 19 19:19:19 2014 +0200 @@ -22,7 +22,8 @@ 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 @@ 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 @@ 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 @@ @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 @@ @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 @@ 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 @@ 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 @@ @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 @@ """ #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 @@ #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 @@ 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 @@ @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 @@ 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 @@ """ 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 @@ """ 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 @@ #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 @@ 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 -r f51a1895275c -r 301b342c697a src/memory/persistent.py --- a/src/memory/persistent.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/memory/persistent.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ """@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 -r f51a1895275c -r 301b342c697a src/memory/sqlite.py --- a/src/memory/sqlite.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/memory/sqlite.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ # 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 @@ 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 @@ @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 @@ 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 @@ 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 @@ 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 @@ @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 @@ @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 @@ 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 @@ 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 @@ 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 @@ @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 @@ @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 @@ @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 @@ @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 @@ 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 @@ 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 @@ @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 @@ @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 @@ @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 @@ @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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/deprecated_misc_cs.py --- a/src/plugins/deprecated_misc_cs.py Sat Apr 19 16:48:26 2014 +0200 +++ /dev/null Thu Jan 01 00:00:00 1970 +0000 @@ -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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_adhoc_dbus.py --- a/src/plugins/plugin_adhoc_dbus.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_adhoc_dbus.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ @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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_exp_command_export.py --- a/src/plugins/plugin_exp_command_export.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_exp_command_export.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 @@ # 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 @@ 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 @@ """ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_exp_parrot.py --- a/src/plugins/plugin_exp_parrot.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_exp_parrot.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ # /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 @@ # 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 @@ 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 @@ _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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_exp_pipe.py --- a/src/plugins/plugin_exp_pipe.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_exp_pipe.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ """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 @@ 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 @@ @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 @@ 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 @@ 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 @@ 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 @@ 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 @@ @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 @@ @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 @@ 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 @@ """ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_misc_account.py --- a/src/plugins/plugin_misc_account.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_misc_account.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ # 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_misc_groupblog.py --- a/src/plugins/plugin_misc_groupblog.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_misc_groupblog.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ """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 @@ #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 @@ 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 @@ 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 @@ 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 @@ 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 @@ # 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_misc_imap.py --- a/src/plugins/plugin_misc_imap.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_misc_imap.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ """ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ @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 @@ 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 @@ 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 @@ @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 @@ 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 @@ @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 @@ @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 @@ 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 @@ @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 @@ 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 @@ 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 @@ 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 @@ #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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_misc_maildir.py --- a/src/plugins/plugin_misc_maildir.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_misc_maildir.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 MaildirBox(object): def __init__(self, host): - info(_("Plugin Maildir initialization")) + log.info(_("Plugin Maildir initialization")) self.host = host self.__observed = {} @@ -126,7 +127,7 @@ @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 @@ 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 @@ @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 @@ @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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_misc_quiz.py --- a/src/plugins/plugin_misc_quiz.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_misc_quiz.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ """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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_misc_radiocol.py --- a/src/plugins/plugin_misc_radiocol.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_misc_radiocol.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ # ==> 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 @@ 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 @@ # 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_misc_room_game.py --- a/src/plugins/plugin_misc_room_game.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_misc_room_game.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 @@ (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 @@ @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 @@ # 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 @@ """ 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 @@ @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 @@ """ 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 @@ - 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 @@ @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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_misc_smtp.py --- a/src/plugins/plugin_misc_smtp.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_misc_smtp.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 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 @@ """ 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 @@ 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_misc_tarot.py --- a/src/plugins/plugin_misc_tarot.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_misc_tarot.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ """ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_misc_text_commands.py --- a/src/plugins/plugin_misc_text_commands.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_misc_text_commands.py Sat Apr 19 19:19:19 2014 +0200 @@ -23,7 +23,8 @@ 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 @@ # 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 @@ 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_misc_text_syntaxes.py --- a/src/plugins/plugin_misc_text_syntaxes.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_misc_text_syntaxes.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ } 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_misc_xmllog.py --- a/src/plugins/plugin_misc_xmllog.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_misc_xmllog.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ """ % {"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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_tmp_demo_directory.py --- a/src/plugins/plugin_tmp_demo_directory.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_tmp_demo_directory.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ } 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 @@ """ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0020.py --- a/src/plugins/plugin_xep_0020.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0020.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0033.py --- a/src/plugins/plugin_xep_0033.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0033.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0045.py --- a/src/plugins/plugin_xep_0045.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0045.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ # 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 @@ 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 @@ @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 @@ #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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ #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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0047.py --- a/src/plugins/plugin_xep_0047.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0047.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ @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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0048.py --- a/src/plugins/plugin_xep_0048.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0048.py Sat Apr 19 19:19:19 2014 +0200 @@ -22,7 +22,8 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ @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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0049.py --- a/src/plugins/plugin_xep_0049.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0049.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0050.py --- a/src/plugins/plugin_xep_0050.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0050.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ @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 @@ ('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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0054.py --- a/src/plugins/plugin_xep_0054.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0054.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ # - 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 @@ """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 @@ 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 @@ 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 @@ @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 @@ """ 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 @@ _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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0055.py --- a/src/plugins/plugin_xep_0055.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0055.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0060.py --- a/src/plugins/plugin_xep_0060.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0060.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 @@ def deleteReceived(self, event): #TODO: manage delete event - debug(_("Publish node deleted")) + log.debug(_("Publish node deleted")) # def purgeReceived(self, event): diff -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0065.py --- a/src/plugins/plugin_xep_0065.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0065.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ """ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ """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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0071.py --- a/src/plugins/plugin_xep_0071.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0071.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0077.py --- a/src/plugins/plugin_xep_0077.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0077.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0085.py --- a/src/plugins/plugin_xep_0085.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0085.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ } 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0092.py --- a/src/plugins/plugin_xep_0092.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0092.py Sat Apr 19 19:19:19 2014 +0200 @@ -23,7 +23,8 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0095.py --- a/src/plugins/plugin_xep_0095.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0095.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ """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 @@ @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 @@ @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 @@ @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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0096.py --- a/src/plugins/plugin_xep_0096.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0096.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 @@ @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 @@ 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 @@ 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 @@ 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 @@ 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 @@ 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 @@ @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 @@ @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 @@ 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 @@ 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 @@ """ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0100.py --- a/src/plugins/plugin_xep_0100.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0100.py Sat Apr 19 19:19:19 2014 +0200 @@ -21,7 +21,8 @@ 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 @@ 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 @@ 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 @@ """ 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 @@ 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 @@ 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 @@ """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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0115.py --- a/src/plugins/plugin_xep_0115.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0115.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0163.py --- a/src/plugins/plugin_xep_0163.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0163.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ """ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0249.py --- a/src/plugins/plugin_xep_0249.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0249.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ } 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 @@ """ 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 @@ """ 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 @@ """ 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 -r f51a1895275c -r 301b342c697a src/plugins/plugin_xep_0277.py --- a/src/plugins/plugin_xep_0277.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/plugins/plugin_xep_0277.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 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 @@ 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 @@ 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 @@ 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 @@ @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 @@ 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 @@ _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 -r f51a1895275c -r 301b342c697a src/test/test_plugin_misc_radiocol.py --- a/src/test/test_plugin_misc_radiocol.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/test/test_plugin_misc_radiocol.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 -r f51a1895275c -r 301b342c697a src/test/test_plugin_misc_room_game.py --- a/src/test/test_plugin_misc_room_game.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/test/test_plugin_misc_room_game.py Sat Apr 19 19:19:19 2014 +0200 @@ -26,7 +26,6 @@ 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 @@ 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 -r f51a1895275c -r 301b342c697a src/test/test_plugin_xep_0033.py --- a/src/test/test_plugin_xep_0033.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/test/test_plugin_xep_0033.py Sat Apr 19 19:19:19 2014 +0200 @@ -111,7 +111,7 @@ 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 @@ """ 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 -r f51a1895275c -r 301b342c697a src/tools/misc.py --- a/src/tools/misc.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/tools/misc.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 -r f51a1895275c -r 301b342c697a src/tools/xml_tools.py --- a/src/tools/xml_tools.py Sat Apr 19 16:48:26 2014 +0200 +++ b/src/tools/xml_tools.py Sat Apr 19 19:19:19 2014 +0200 @@ -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 @@ 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 @@ 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 @@ 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 @@ 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)