comparison src/core/sat_main.py @ 993:301b342c697a

core: use of the new core.log module: /!\ this is a massive refactoring and was largely automated, it probably did bring some bugs /!\
author Goffi <goffi@goffi.org>
date Sat, 19 Apr 2014 19:19:19 +0200
parents 05e02f8b7eb4
children c37a24922f27
comparison
equal deleted inserted replaced
992:f51a1895275c 993:301b342c697a
23 from twisted.words.protocols.jabber import jid, xmlstream 23 from twisted.words.protocols.jabber import jid, xmlstream
24 from twisted.words.xish import domish 24 from twisted.words.xish import domish
25 from twisted.internet import reactor 25 from twisted.internet import reactor
26 from wokkel.xmppim import RosterItem 26 from wokkel.xmppim import RosterItem
27 from sat.bridge.DBus import DBusBridge 27 from sat.bridge.DBus import DBusBridge
28 import logging
29 from logging import debug, info, warning, error
30
31 import sys
32 import os.path
33
34 from sat.core import xmpp 28 from sat.core import xmpp
35 from sat.core import exceptions 29 from sat.core import exceptions
30 from sat.core.log import getLogger
31 log = getLogger(__name__)
36 from sat.core.constants import Const as C 32 from sat.core.constants import Const as C
37 from sat.memory.memory import Memory 33 from sat.memory.memory import Memory
38 from sat.tools.misc import TriggerManager 34 from sat.tools.misc import TriggerManager
39 from sat.stdui import ui_contact_list 35 from sat.stdui import ui_contact_list
40 from glob import glob 36 from glob import glob
41 from uuid import uuid4 37 from uuid import uuid4
38 import sys
39 import os.path
42 40
43 try: 41 try:
44 from collections import OrderedDict # only available from python 2.7 42 from collections import OrderedDict # only available from python 2.7
45 except ImportError: 43 except ImportError:
46 from ordereddict import OrderedDict 44 from ordereddict import OrderedDict
91 self.trigger = TriggerManager() # trigger are used to change SàT behaviour 89 self.trigger = TriggerManager() # trigger are used to change SàT behaviour
92 90
93 try: 91 try:
94 self.bridge = DBusBridge() 92 self.bridge = DBusBridge()
95 except exceptions.BridgeInitError: 93 except exceptions.BridgeInitError:
96 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 94 log.error(u"Bridge can't be initialised, can't start SàT core")
97 sys.exit(1) 95 sys.exit(1)
98 self.bridge.register("getVersion", lambda: C.APP_VERSION) 96 self.bridge.register("getVersion", lambda: C.APP_VERSION)
99 self.bridge.register("getProfileName", self.memory.getProfileName) 97 self.bridge.register("getProfileName", self.memory.getProfileName)
100 self.bridge.register("getProfilesList", self.memory.getProfilesList) 98 self.bridge.register("getProfilesList", self.memory.getProfilesList)
101 self.bridge.register("getEntityData", lambda _jid, keys, profile: self.memory.getEntityData(jid.JID(_jid), keys, profile)) 99 self.bridge.register("getEntityData", lambda _jid, keys, profile: self.memory.getEntityData(jid.JID(_jid), keys, profile))
138 136
139 self.memory.initialized.addCallback(self._postMemoryInit) 137 self.memory.initialized.addCallback(self._postMemoryInit)
140 138
141 def _postMemoryInit(self, ignore): 139 def _postMemoryInit(self, ignore):
142 """Method called after memory initialization is done""" 140 """Method called after memory initialization is done"""
143 info(_("Memory initialised")) 141 log.info(_("Memory initialised"))
144 self._import_plugins() 142 self._import_plugins()
145 ui_contact_list.ContactList(self) 143 ui_contact_list.ContactList(self)
146 144
147 def _import_plugins(self): 145 def _import_plugins(self):
148 """Import all plugins found in plugins directory""" 146 """Import all plugins found in plugins directory"""
167 @param import_name: name of the plugin to import as found in PLUGIN_INFO['import_name'] 165 @param import_name: name of the plugin to import as found in PLUGIN_INFO['import_name']
168 @param optional: if False and plugin is not found, an ImportError exception is raised 166 @param optional: if False and plugin is not found, an ImportError exception is raised
169 167
170 """ 168 """
171 if import_name in self.plugins: 169 if import_name in self.plugins:
172 debug('Plugin [%s] already imported, passing' % import_name) 170 log.debug('Plugin [%s] already imported, passing' % import_name)
173 return 171 return
174 if not import_name: 172 if not import_name:
175 import_name, (plugin_path, mod, plugin_info) = plugins_to_import.popitem() 173 import_name, (plugin_path, mod, plugin_info) = plugins_to_import.popitem()
176 else: 174 else:
177 if not import_name in plugins_to_import: 175 if not import_name in plugins_to_import:
178 if optional: 176 if optional:
179 warning(_("Recommended plugin not found: %s") % import_name) 177 log.warning(_("Recommended plugin not found: %s") % import_name)
180 return 178 return
181 error(_("Dependency not found: %s") % import_name) 179 log.error(_("Dependency not found: %s") % import_name)
182 raise ImportError(_('Dependency plugin not found: [%s]') % import_name) 180 raise ImportError(_('Dependency plugin not found: [%s]') % import_name)
183 plugin_path, mod, plugin_info = plugins_to_import.pop(import_name) 181 plugin_path, mod, plugin_info = plugins_to_import.pop(import_name)
184 dependencies = plugin_info.setdefault("dependencies", []) 182 dependencies = plugin_info.setdefault("dependencies", [])
185 recommendations = plugin_info.setdefault("recommendations", []) 183 recommendations = plugin_info.setdefault("recommendations", [])
186 for to_import in dependencies + recommendations: 184 for to_import in dependencies + recommendations:
187 if to_import not in self.plugins: 185 if to_import not in self.plugins:
188 debug('Recursively import dependency of [%s]: [%s]' % (import_name, to_import)) 186 log.debug('Recursively import dependency of [%s]: [%s]' % (import_name, to_import))
189 self._import_plugins_from_dict(plugins_to_import, to_import, to_import not in dependencies) 187 self._import_plugins_from_dict(plugins_to_import, to_import, to_import not in dependencies)
190 info(_("importing plugin: %s"), plugin_info['name']) 188 log.info(_("importing plugin: %s") % plugin_info['name'])
191 self.plugins[import_name] = getattr(mod, plugin_info['main'])(self) 189 self.plugins[import_name] = getattr(mod, plugin_info['main'])(self)
192 if 'handler' in plugin_info and plugin_info['handler'] == 'yes': 190 if 'handler' in plugin_info and plugin_info['handler'] == 'yes':
193 self.plugins[import_name].is_handler = True 191 self.plugins[import_name].is_handler = True
194 else: 192 else:
195 self.plugins[import_name].is_handler = False 193 self.plugins[import_name].is_handler = False
203 """Connect to jabber server with asynchronous reply 201 """Connect to jabber server with asynchronous reply
204 @param profile_key: %(doc_profile)s 202 @param profile_key: %(doc_profile)s
205 """ 203 """
206 profile = self.memory.getProfileName(profile_key) 204 profile = self.memory.getProfileName(profile_key)
207 if not profile: 205 if not profile:
208 error(_('Trying to connect a non-exsitant profile')) 206 log.error(_('Trying to connect a non-exsitant profile'))
209 raise exceptions.ProfileUnknownError(profile_key) 207 raise exceptions.ProfileUnknownError(profile_key)
210 208
211 if self.isConnected(profile): 209 if self.isConnected(profile):
212 info(_("already connected !")) 210 log.info(_("already connected !"))
213 return defer.succeed("None") 211 return defer.succeed("None")
214 212
215 def afterMemoryInit(ignore): 213 def afterMemoryInit(ignore):
216 """This part must be called when we have loaded individual parameters from memory""" 214 """This part must be called when we have loaded individual parameters from memory"""
217 try: 215 try:
218 port = int(self.memory.getParamA("Port", "Connection", profile_key=profile)) 216 port = int(self.memory.getParamA("Port", "Connection", profile_key=profile))
219 except ValueError: 217 except ValueError:
220 error(_("Can't parse port value, using default value")) 218 log.error(_("Can't parse port value, using default value"))
221 port = 5222 219 port = 5222
222 current = self.profiles[profile] = xmpp.SatXMPPClient( 220 current = self.profiles[profile] = xmpp.SatXMPPClient(
223 self, profile, 221 self, profile,
224 jid.JID(self.memory.getParamA("JabberID", "Connection", profile_key=profile), profile), 222 jid.JID(self.memory.getParamA("JabberID", "Connection", profile_key=profile), profile),
225 self.memory.getParamA("Password", "Connection", profile_key=profile), 223 self.memory.getParamA("Password", "Connection", profile_key=profile),
243 current.versionHandler.setHandlerParent(current) 241 current.versionHandler.setHandlerParent(current)
244 242
245 current.identityHandler = xmpp.SatIdentityHandler() 243 current.identityHandler = xmpp.SatIdentityHandler()
246 current.identityHandler.setHandlerParent(current) 244 current.identityHandler.setHandlerParent(current)
247 245
248 debug(_("setting plugins parents")) 246 log.debug(_("setting plugins parents"))
249 247
250 plugin_conn_cb = [] 248 plugin_conn_cb = []
251 for plugin in self.plugins.iteritems(): 249 for plugin in self.plugins.iteritems():
252 if plugin[1].is_handler: 250 if plugin[1].is_handler:
253 plugin[1].getHandler(profile).setHandlerParent(current) 251 plugin[1].getHandler(profile).setHandlerParent(current)
268 list_d = defer.DeferredList(conn_cb_list) 266 list_d = defer.DeferredList(conn_cb_list)
269 267
270 def logPluginResults(results): 268 def logPluginResults(results):
271 all_succeed = all([success for success, result in results]) 269 all_succeed = all([success for success, result in results])
272 if not all_succeed: 270 if not all_succeed:
273 error(_("Plugins initialisation error")) 271 log.error(_("Plugins initialisation error"))
274 for idx, (success, result) in enumerate(results): 272 for idx, (success, result) in enumerate(results):
275 if not success: 273 if not success:
276 error("Error (plugin %(name)s): %(failure)s" % {'name': plugin_conn_cb[idx][0], 274 log.error("error (plugin %(name)s): %(failure)s" % {'name': plugin_conn_cb[idx][0],
277 'failure': result}) 275 'failure': result})
278 276
279 list_d.addCallback(logPluginResults) 277 list_d.addCallback(logPluginResults)
280 return list_d 278 return list_d
281 279
287 return self.memory.loadIndividualParams(profile).addCallback(afterMemoryInit) 285 return self.memory.loadIndividualParams(profile).addCallback(afterMemoryInit)
288 286
289 def disconnect(self, profile_key): 287 def disconnect(self, profile_key):
290 """disconnect from jabber server""" 288 """disconnect from jabber server"""
291 if not self.isConnected(profile_key): 289 if not self.isConnected(profile_key):
292 info(_("not connected !")) 290 log.info(_("not connected !"))
293 return 291 return
294 profile = self.memory.getProfileName(profile_key) 292 profile = self.memory.getProfileName(profile_key)
295 info(_("Disconnecting...")) 293 log.info(_("Disconnecting..."))
296 self.profiles[profile].stopService() 294 self.profiles[profile].stopService()
297 for plugin in self.plugins.iteritems(): 295 for plugin in self.plugins.iteritems():
298 disconnected_cb = getattr(plugin[1], "profileDisconnected", None) 296 disconnected_cb = getattr(plugin[1], "profileDisconnected", None)
299 if disconnected_cb: 297 if disconnected_cb:
300 disconnected_cb(profile) 298 disconnected_cb(profile)
316 """Remove reference to a profile client and purge cache 314 """Remove reference to a profile client and purge cache
317 the garbage collector can then free the memory""" 315 the garbage collector can then free the memory"""
318 try: 316 try:
319 del self.profiles[profile] 317 del self.profiles[profile]
320 except KeyError: 318 except KeyError:
321 error(_("Trying to remove reference to a client not referenced")) 319 log.error(_("Trying to remove reference to a client not referenced"))
322 self.memory.purgeProfileSession(profile) 320 self.memory.purgeProfileSession(profile)
323 321
324 def startService(self): 322 def startService(self):
325 info("Salut à toi ô mon frère !") 323 log.info(u"Salut à toi ô mon frère !")
326 #TODO: manage autoconnect 324 #TODO: manage autoconnect
327 #self.connect() 325 #self.connect()
328 326
329 def stopService(self): 327 def stopService(self):
330 info("Salut aussi à Rantanplan") 328 log.info("Salut aussi à Rantanplan")
331 329
332 def run(self): 330 def run(self):
333 debug(_("running app")) 331 log.debug(_("running app"))
334 reactor.run() 332 reactor.run()
335 333
336 def stop(self): 334 def stop(self):
337 debug(_("stopping app")) 335 log.debug(_("stopping app"))
338 reactor.stop() 336 reactor.stop()
339 337
340 ## Misc methods ## 338 ## Misc methods ##
341 339
342 def getJidNStream(self, profile_key): 340 def getJidNStream(self, profile_key):
413 411
414 ## Client management ## 412 ## Client management ##
415 413
416 def setParam(self, name, value, category, security_limit, profile_key): 414 def setParam(self, name, value, category, security_limit, profile_key):
417 """set wanted paramater and notice observers""" 415 """set wanted paramater and notice observers"""
418 info(_("setting param: %(name)s=%(value)s in category %(category)s") % {'name': name, 'value': value, 'category': category}) 416 log.info(_("setting param: %(name)s=%(value)s in category %(category)s") % {'name': name, 'value': value, 'category': category})
419 self.memory.setParam(name, value, category, security_limit, profile_key) 417 self.memory.setParam(name, value, category, security_limit, profile_key)
420 418
421 def isConnected(self, profile_key): 419 def isConnected(self, profile_key):
422 """Return connection status of profile 420 """Return connection status of profile
423 @param profile_key: key_word or profile name to determine profile name 421 @param profile_key: key_word or profile name to determine profile name
424 @return True if connected 422 @return True if connected
425 """ 423 """
426 profile = self.memory.getProfileName(profile_key) 424 profile = self.memory.getProfileName(profile_key)
427 if not profile: 425 if not profile:
428 error(_('asking connection status for a non-existant profile')) 426 log.error(_('asking connection status for a non-existant profile'))
429 return 427 return
430 if profile not in self.profiles: 428 if profile not in self.profiles:
431 return False 429 return False
432 return self.profiles[profile].isConnected() 430 return self.profiles[profile].isConnected()
433 431
488 486
489 if not no_trigger: 487 if not no_trigger:
490 if not self.trigger.point("sendMessage", mess_data, pre_xml_treatments, post_xml_treatments, profile): 488 if not self.trigger.point("sendMessage", mess_data, pre_xml_treatments, post_xml_treatments, profile):
491 return defer.succeed(None) 489 return defer.succeed(None)
492 490
493 debug(_("Sending jabber message of type [%(type)s] to %(to)s...") % {"type": mess_data["type"], "to": to_jid.full()}) 491 log.debug(_("Sending jabber message of type [%(type)s] to %(to)s...") % {"type": mess_data["type"], "to": to_jid.full()})
494 492
495 def generateXML(mess_data): 493 def generateXML(mess_data):
496 mess_data['xml'] = domish.Element((None, 'message')) 494 mess_data['xml'] = domish.Element((None, 'message'))
497 mess_data['xml']["to"] = mess_data["to"].full() 495 mess_data['xml']["to"] = mess_data["to"].full()
498 mess_data['xml']["from"] = current_jid.full() 496 mess_data['xml']["from"] = current_jid.full()
505 return mess_data 503 return mess_data
506 504
507 def sendErrback(e): 505 def sendErrback(e):
508 text = '%s: %s' % (e.value.__class__.__name__, e.getErrorMessage()) 506 text = '%s: %s' % (e.value.__class__.__name__, e.getErrorMessage())
509 if e.check(MessageSentAndStored): 507 if e.check(MessageSentAndStored):
510 debug(text) 508 log.debug(text)
511 elif e.check(AbortSendMessage): 509 elif e.check(AbortSendMessage):
512 warning(text) 510 log.warning(text)
513 return e 511 return e
514 else: 512 else:
515 error("Unmanaged exception: %s" % text) 513 log.error("Unmanaged exception: %s" % text)
516 return e 514 return e
517 pre_xml_treatments.addCallback(generateXML) 515 pre_xml_treatments.addCallback(generateXML)
518 pre_xml_treatments.chainDeferred(post_xml_treatments) 516 pre_xml_treatments.chainDeferred(post_xml_treatments)
519 post_xml_treatments.addCallback(self.sendAndStoreMessage, False, profile) 517 post_xml_treatments.addCallback(self.sendAndStoreMessage, False, profile)
520 post_xml_treatments.addErrback(sendErrback) 518 post_xml_treatments.addErrback(sendErrback)
530 @param profile: profile 528 @param profile: profile
531 """ 529 """
532 try: 530 try:
533 client = self.profiles[profile] 531 client = self.profiles[profile]
534 except KeyError: 532 except KeyError:
535 error(_("Trying to send a message with no profile")) 533 log.error(_("Trying to send a message with no profile"))
536 return 534 return
537 current_jid = client.jid 535 current_jid = client.jid
538 if not skip_send: 536 if not skip_send:
539 client.xmlstream.send(mess_data['xml']) 537 client.xmlstream.send(mess_data['xml'])
540 if mess_data["type"] != "groupchat": 538 if mess_data["type"] != "groupchat":
578 @param raw_jid: unicode entity's jid 576 @param raw_jid: unicode entity's jid
579 @param profile_key: profile""" 577 @param profile_key: profile"""
580 profile = self.memory.getProfileName(profile_key) 578 profile = self.memory.getProfileName(profile_key)
581 assert(profile) 579 assert(profile)
582 to_jid = jid.JID(raw_jid) 580 to_jid = jid.JID(raw_jid)
583 debug(_('subsciption request [%(subs_type)s] for %(jid)s') % {'subs_type': subs_type, 'jid': to_jid.full()}) 581 log.debug(_('subsciption request [%(subs_type)s] for %(jid)s') % {'subs_type': subs_type, 'jid': to_jid.full()})
584 if subs_type == "subscribe": 582 if subs_type == "subscribe":
585 self.profiles[profile].presence.subscribe(to_jid) 583 self.profiles[profile].presence.subscribe(to_jid)
586 elif subs_type == "subscribed": 584 elif subs_type == "subscribed":
587 self.profiles[profile].presence.subscribed(to_jid) 585 self.profiles[profile].presence.subscribed(to_jid)
588 elif subs_type == "unsubscribe": 586 elif subs_type == "unsubscribe":
662 @param action_id: same action_id used with action 660 @param action_id: same action_id used with action
663 @param action_type: result action_type /!\ only "DICT_DICT" for this method 661 @param action_type: result action_type /!\ only "DICT_DICT" for this method
664 @param data: dictionary of dictionaries 662 @param data: dictionary of dictionaries
665 """ 663 """
666 if action_type != "DICT_DICT": 664 if action_type != "DICT_DICT":
667 error(_("action_type for actionResultExt must be DICT_DICT, fixing it")) 665 log.error(_("action_type for actionResultExt must be DICT_DICT, fixing it"))
668 action_type = "DICT_DICT" 666 action_type = "DICT_DICT"
669 self.bridge.actionResultExt(action_type, action_id, data, profile) 667 self.bridge.actionResultExt(action_type, action_id, data, profile)
670 668
671 def askConfirmation(self, conf_id, conf_type, data, cb, profile): 669 def askConfirmation(self, conf_id, conf_type, data, cb, profile):
672 """Add a confirmation callback 670 """Add a confirmation callback
676 @param cb: callback called with the answer 674 @param cb: callback called with the answer
677 """ 675 """
678 # FIXME: use XMLUI and *callback methods for dialog 676 # FIXME: use XMLUI and *callback methods for dialog
679 client = self.getClient(profile) 677 client = self.getClient(profile)
680 if conf_id in client._waiting_conf: 678 if conf_id in client._waiting_conf:
681 error(_("Attempt to register two callbacks for the same confirmation")) 679 log.error(_("Attempt to register two callbacks for the same confirmation"))
682 else: 680 else:
683 client._waiting_conf[conf_id] = (conf_type, data, cb) 681 client._waiting_conf[conf_id] = (conf_type, data, cb)
684 self.bridge.askConfirmation(conf_id, conf_type, data, profile) 682 self.bridge.askConfirmation(conf_id, conf_type, data, profile)
685 683
686 def confirmationAnswer(self, conf_id, accepted, data, profile): 684 def confirmationAnswer(self, conf_id, accepted, data, profile):
687 """Called by frontends to answer confirmation requests""" 685 """Called by frontends to answer confirmation requests"""
688 client = self.getClient(profile) 686 client = self.getClient(profile)
689 debug(_("Received confirmation answer for conf_id [%(conf_id)s]: %(success)s") % {'conf_id': conf_id, 'success': _("accepted") if accepted else _("refused")}) 687 log.debug(_("Received confirmation answer for conf_id [%(conf_id)s]: %(success)s") % {'conf_id': conf_id, 'success': _("accepted") if accepted else _("refused")})
690 if conf_id not in client._waiting_conf: 688 if conf_id not in client._waiting_conf:
691 error(_("Received an unknown confirmation (%(id)s for %(profile)s)") % {'id': conf_id, 'profile': profile}) 689 log.error(_("Received an unknown confirmation (%(id)s for %(profile)s)") % {'id': conf_id, 'profile': profile})
692 else: 690 else:
693 cb = client._waiting_conf[conf_id][-1] 691 cb = client._waiting_conf[conf_id][-1]
694 del client._waiting_conf[conf_id] 692 del client._waiting_conf[conf_id]
695 cb(conf_id, accepted, data, profile) 693 cb(conf_id, accepted, data, profile)
696 694
701 699
702 def removeProgressCB(self, progress_id, profile): 700 def removeProgressCB(self, progress_id, profile):
703 """Remove a progress callback""" 701 """Remove a progress callback"""
704 client = self.getClient(profile) 702 client = self.getClient(profile)
705 if progress_id not in client._progress_cb_map: 703 if progress_id not in client._progress_cb_map:
706 error(_("Trying to remove an unknow progress callback")) 704 log.error(_("Trying to remove an unknow progress callback"))
707 else: 705 else:
708 del client._progress_cb_map[progress_id] 706 del client._progress_cb_map[progress_id]
709 707
710 def getProgress(self, progress_id, profile): 708 def getProgress(self, progress_id, profile):
711 """Return a dict with progress information 709 """Return a dict with progress information
716 data = {} 714 data = {}
717 try: 715 try:
718 client._progress_cb_map[progress_id](progress_id, data, profile) 716 client._progress_cb_map[progress_id](progress_id, data, profile)
719 except KeyError: 717 except KeyError:
720 pass 718 pass
721 #debug("Requested progress for unknown progress_id") 719 #log.debug("Requested progress for unknown progress_id")
722 return data 720 return data
723 721
724 def registerCallback(self, callback, *args, **kwargs): 722 def registerCallback(self, callback, *args, **kwargs):
725 """ Register a callback. 723 """ Register a callback.
726 Use with_data=True in kwargs if the callback use the optional data dict 724 Use with_data=True in kwargs if the callback use the optional data dict
748 return callback_id 746 return callback_id
749 747
750 def removeCallback(self, callback_id): 748 def removeCallback(self, callback_id):
751 """ Remove a previously registered callback 749 """ Remove a previously registered callback
752 @param callback_id: id returned by [registerCallback] """ 750 @param callback_id: id returned by [registerCallback] """
753 debug("Removing callback [%s]" % callback_id) 751 log.debug("Removing callback [%s]" % callback_id)
754 del self._cb_map[callback_id] 752 del self._cb_map[callback_id]
755 753
756 def launchCallback(self, callback_id, data=None, profile_key=C.PROF_KEY_NONE): 754 def launchCallback(self, callback_id, data=None, profile_key=C.PROF_KEY_NONE):
757 """Launch a specific callback 755 """Launch a specific callback
758 @param callback_id: id of the action (callback) to launch 756 @param callback_id: id of the action (callback) to launch