comparison src/core/xmpp.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 3a22c011fdbd
children 6e975c6b0faf
comparison
equal deleted inserted replaced
992:f51a1895275c 993:301b342c697a
20 from sat.core.i18n import _ 20 from sat.core.i18n import _
21 from sat.core.constants import Const as C 21 from sat.core.constants import Const as C
22 from twisted.internet import task, defer 22 from twisted.internet import task, defer
23 from twisted.words.protocols.jabber import jid, xmlstream 23 from twisted.words.protocols.jabber import jid, xmlstream
24 from wokkel import client, disco, xmppim, generic, compat, delay, iwokkel 24 from wokkel import client, disco, xmppim, generic, compat, delay, iwokkel
25 from logging import debug, info, warning, error 25 from sat.core.log import getLogger
26 log = getLogger(__name__)
26 from sat.core import exceptions 27 from sat.core import exceptions
27 from calendar import timegm 28 from calendar import timegm
28 from zope.interface import implements 29 from zope.interface import implements
29 try: 30 try:
30 from twisted.words.protocols.xmlstream import XMPPHandler 31 from twisted.words.protocols.xmlstream import XMPPHandler
52 def _authd(self, xmlstream): 53 def _authd(self, xmlstream):
53 if not self.host_app.trigger.point("XML Initialized", xmlstream, self.profile): 54 if not self.host_app.trigger.point("XML Initialized", xmlstream, self.profile):
54 return 55 return
55 client.XMPPClient._authd(self, xmlstream) 56 client.XMPPClient._authd(self, xmlstream)
56 self.__connected = True 57 self.__connected = True
57 info(_("********** [%s] CONNECTED **********") % self.profile) 58 log.info(_("********** [%s] CONNECTED **********") % self.profile)
58 self.streamInitialized() 59 self.streamInitialized()
59 self.host_app.bridge.connected(self.profile) # we send the signal to the clients 60 self.host_app.bridge.connected(self.profile) # we send the signal to the clients
60 61
61 def streamInitialized(self): 62 def streamInitialized(self):
62 """Called after _authd""" 63 """Called after _authd"""
63 debug(_("XML stream is initialized")) 64 log.debug(_("XML stream is initialized"))
64 self.keep_alife = task.LoopingCall(self.xmlstream.send, " ") # Needed to avoid disconnection (specially with openfire) 65 self.keep_alife = task.LoopingCall(self.xmlstream.send, " ") # Needed to avoid disconnection (specially with openfire)
65 self.keep_alife.start(180) 66 self.keep_alife.start(180)
66 67
67 self.disco = SatDiscoProtocol(self) 68 self.disco = SatDiscoProtocol(self)
68 self.disco.setHandlerParent(self) 69 self.disco.setHandlerParent(self)
79 self.conn_deferred.callback(None) 80 self.conn_deferred.callback(None)
80 81
81 disco_d.addCallback(finish_connection) 82 disco_d.addCallback(finish_connection)
82 83
83 def initializationFailed(self, reason): 84 def initializationFailed(self, reason):
84 error(_("ERROR: XMPP connection failed for profile '%(profile)s': %(reason)s" % {'profile': self.profile, 'reason': reason})) 85 log.error(_("ERROR: XMPP connection failed for profile '%(profile)s': %(reason)s" % {'profile': self.profile, 'reason': reason}))
85 self.host_app.bridge.connectionError("AUTH_ERROR", self.profile) 86 self.host_app.bridge.connectionError("AUTH_ERROR", self.profile)
86 try: 87 try:
87 client.XMPPClient.initializationFailed(self, reason) 88 client.XMPPClient.initializationFailed(self, reason)
88 except: 89 except:
89 # we already send an error signal, no need to raise an exception 90 # we already send an error signal, no need to raise an exception
93 def isConnected(self): 94 def isConnected(self):
94 return self.__connected 95 return self.__connected
95 96
96 def connectionLost(self, connector, unused_reason): 97 def connectionLost(self, connector, unused_reason):
97 self.__connected = False 98 self.__connected = False
98 info(_("********** [%s] DISCONNECTED **********") % self.profile) 99 log.info(_("********** [%s] DISCONNECTED **********") % self.profile)
99 try: 100 try:
100 self.keep_alife.stop() 101 self.keep_alife.stop()
101 except AttributeError: 102 except AttributeError:
102 debug(_("No keep_alife")) 103 log.debug(_("No keep_alife"))
103 self.host_app.bridge.disconnected(self.profile) # we send the signal to the clients 104 self.host_app.bridge.disconnected(self.profile) # we send the signal to the clients
104 self.host_app.purgeClient(self.profile) # and we remove references to this client 105 self.host_app.purgeClient(self.profile) # and we remove references to this client
105 106
106 107
107 class SatMessageProtocol(xmppim.MessageProtocol): 108 class SatMessageProtocol(xmppim.MessageProtocol):
109 def __init__(self, host): 110 def __init__(self, host):
110 xmppim.MessageProtocol.__init__(self) 111 xmppim.MessageProtocol.__init__(self)
111 self.host = host 112 self.host = host
112 113
113 def onMessage(self, message): 114 def onMessage(self, message):
114 debug(_(u"got message from: %s"), message["from"]) 115 log.debug(_(u"got message from: %s") % message["from"])
115 post_treat = defer.Deferred() # XXX: plugin can add their treatments to this deferred 116 post_treat = defer.Deferred() # XXX: plugin can add their treatments to this deferred
116 117
117 if not self.host.trigger.point("MessageReceived", message, post_treat, profile=self.parent.profile): 118 if not self.host.trigger.point("MessageReceived", message, post_treat, profile=self.parent.profile):
118 return 119 return
119 120
161 for raw_jid, item in roster.iteritems(): 162 for raw_jid, item in roster.iteritems():
162 self.onRosterSet(item) 163 self.onRosterSet(item)
163 164
164 def requestRoster(self): 165 def requestRoster(self):
165 """ ask the server for Roster list """ 166 """ ask the server for Roster list """
166 debug("requestRoster") 167 log.debug("requestRoster")
167 d = self.getRoster().addCallback(self.rosterCb) 168 d = self.getRoster().addCallback(self.rosterCb)
168 d.chainDeferred(self.got_roster) 169 d.chainDeferred(self.got_roster)
169 170
170 def removeItem(self, to_jid): 171 def removeItem(self, to_jid):
171 """Remove a contact from roster list 172 """Remove a contact from roster list
215 #XXX: current behaviour: we don't want contact in our roster list 216 #XXX: current behaviour: we don't want contact in our roster list
216 # if there is no presence subscription 217 # if there is no presence subscription
217 # may change in the future 218 # may change in the future
218 self.removeItem(item.jid) 219 self.removeItem(item.jid)
219 return 220 return
220 info(_("new contact in roster list: %s"), item.jid.full()) 221 log.info(_("new contact in roster list: %s") % item.jid.full())
221 if not item.subscriptionTo: 222 if not item.subscriptionTo:
222 warning(_("You are not subscribed to this contact !")) 223 log.warning(_("You are not subscribed to this contact !"))
223 if not item.subscriptionFrom: 224 if not item.subscriptionFrom:
224 warning(_("This contact is not subscribed to you !")) 225 log.warning(_("This contact is not subscribed to you !"))
225 #self.host.memory.addContact(item.jid, item_attr, item.groups, self.parent.profile) 226 #self.host.memory.addContact(item.jid, item_attr, item.groups, self.parent.profile)
226 227
227 bare_jid = item.jid.userhostJID() 228 bare_jid = item.jid.userhostJID()
228 self._jids[bare_jid] = item 229 self._jids[bare_jid] = item
229 for group in item.groups: 230 for group in item.groups:
237 238
238 # we first remove item from local cache (self._groups and self._jids) 239 # we first remove item from local cache (self._groups and self._jids)
239 try: 240 try:
240 item = self._jids.pop(bare_jid) 241 item = self._jids.pop(bare_jid)
241 except KeyError: 242 except KeyError:
242 warning("Received a roster remove event for an item not in cache") 243 log.warning("Received a roster remove event for an item not in cache")
243 return 244 return
244 for group in item.groups: 245 for group in item.groups:
245 try: 246 try:
246 jids_set = self._groups[group] 247 jids_set = self._groups[group]
247 jids_set.remove(bare_jid) 248 jids_set.remove(bare_jid)
248 if not jids_set: 249 if not jids_set:
249 del self._groups[group] 250 del self._groups[group]
250 except KeyError: 251 except KeyError:
251 warning("there is not cache for the group [%(groups)s] of the removed roster item [%(jid)s]" % 252 log.warning("there is not cache for the group [%(groups)s] of the removed roster item [%(jid)s]" %
252 {"group": group, "jid": bare_jid}) 253 {"group": group, "jid": bare_jid})
253 254
254 # then we send the bridge signal 255 # then we send the bridge signal
255 self.host.bridge.contactDeleted(entity.userhost(), self.parent.profile) 256 self.host.bridge.contactDeleted(entity.userhost(), self.parent.profile)
256 257
293 if not self.host.trigger.point("Presence send", self.parent, obj): 294 if not self.host.trigger.point("Presence send", self.parent, obj):
294 return 295 return
295 super(SatPresenceProtocol, self).send(obj) 296 super(SatPresenceProtocol, self).send(obj)
296 297
297 def availableReceived(self, entity, show=None, statuses=None, priority=0): 298 def availableReceived(self, entity, show=None, statuses=None, priority=0):
298 debug(_("presence update for [%(entity)s] (available, show=%(show)s statuses=%(statuses)s priority=%(priority)d)") % {'entity': entity, 'show': show, 'statuses': statuses, 'priority': priority}) 299 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})
299 300
300 if not statuses: 301 if not statuses:
301 statuses = {} 302 statuses = {}
302 303
303 if None in statuses: # we only want string keys 304 if None in statuses: # we only want string keys
312 self.host.bridge.presenceUpdate(entity.full(), show or "", 313 self.host.bridge.presenceUpdate(entity.full(), show or "",
313 int(priority), statuses, 314 int(priority), statuses,
314 self.parent.profile) 315 self.parent.profile)
315 316
316 def unavailableReceived(self, entity, statuses=None): 317 def unavailableReceived(self, entity, statuses=None):
317 debug(_("presence update for [%(entity)s] (unavailable, statuses=%(statuses)s)") % {'entity': entity, 'statuses': statuses}) 318 log.debug(_("presence update for [%(entity)s] (unavailable, statuses=%(statuses)s)") % {'entity': entity, 'statuses': statuses})
318 319
319 if not statuses: 320 if not statuses:
320 statuses = {} 321 statuses = {}
321 322
322 if None in statuses: # we only want string keys 323 if None in statuses: # we only want string keys
356 def subscribed(self, entity): 357 def subscribed(self, entity):
357 xmppim.PresenceClientProtocol.subscribed(self, entity) 358 xmppim.PresenceClientProtocol.subscribed(self, entity)
358 self.host.memory.delWaitingSub(entity.userhost(), self.parent.profile) 359 self.host.memory.delWaitingSub(entity.userhost(), self.parent.profile)
359 item = self.parent.roster.getItem(entity) 360 item = self.parent.roster.getItem(entity)
360 if not item or not item.subscriptionTo: # we automatically subscribe to 'to' presence 361 if not item or not item.subscriptionTo: # we automatically subscribe to 'to' presence
361 debug(_('sending automatic "from" subscription request')) 362 log.debug(_('sending automatic "from" subscription request'))
362 self.subscribe(entity) 363 self.subscribe(entity)
363 364
364 def unsubscribed(self, entity): 365 def unsubscribed(self, entity):
365 xmppim.PresenceClientProtocol.unsubscribed(self, entity) 366 xmppim.PresenceClientProtocol.unsubscribed(self, entity)
366 self.host.memory.delWaitingSub(entity.userhost(), self.parent.profile) 367 self.host.memory.delWaitingSub(entity.userhost(), self.parent.profile)
367 368
368 def subscribedReceived(self, entity): 369 def subscribedReceived(self, entity):
369 debug(_("subscription approved for [%s]") % entity.userhost()) 370 log.debug(_("subscription approved for [%s]") % entity.userhost())
370 self.host.bridge.subscribe('subscribed', entity.userhost(), self.parent.profile) 371 self.host.bridge.subscribe('subscribed', entity.userhost(), self.parent.profile)
371 372
372 def unsubscribedReceived(self, entity): 373 def unsubscribedReceived(self, entity):
373 debug(_("unsubscription confirmed for [%s]") % entity.userhost()) 374 log.debug(_("unsubscription confirmed for [%s]") % entity.userhost())
374 self.host.bridge.subscribe('unsubscribed', entity.userhost(), self.parent.profile) 375 self.host.bridge.subscribe('unsubscribed', entity.userhost(), self.parent.profile)
375 376
376 def subscribeReceived(self, entity): 377 def subscribeReceived(self, entity):
377 debug(_("subscription request from [%s]") % entity.userhost()) 378 log.debug(_("subscription request from [%s]") % entity.userhost())
378 item = self.parent.roster.getItem(entity) 379 item = self.parent.roster.getItem(entity)
379 if item and item.subscriptionTo: 380 if item and item.subscriptionTo:
380 # We automatically accept subscription if we are already subscribed to contact presence 381 # We automatically accept subscription if we are already subscribed to contact presence
381 debug(_('sending automatic subscription acceptance')) 382 log.debug(_('sending automatic subscription acceptance'))
382 self.subscribed(entity) 383 self.subscribed(entity)
383 else: 384 else:
384 self.host.memory.addWaitingSub('subscribe', entity.userhost(), self.parent.profile) 385 self.host.memory.addWaitingSub('subscribe', entity.userhost(), self.parent.profile)
385 self.host.bridge.subscribe('subscribe', entity.userhost(), self.parent.profile) 386 self.host.bridge.subscribe('subscribe', entity.userhost(), self.parent.profile)
386 387
387 def unsubscribeReceived(self, entity): 388 def unsubscribeReceived(self, entity):
388 debug(_("unsubscription asked for [%s]") % entity.userhost()) 389 log.debug(_("unsubscription asked for [%s]") % entity.userhost())
389 item = self.parent.roster.getItem(entity) 390 item = self.parent.roster.getItem(entity)
390 if item and item.subscriptionFrom: # we automatically remove contact 391 if item and item.subscriptionFrom: # we automatically remove contact
391 debug(_('automatic contact deletion')) 392 log.debug(_('automatic contact deletion'))
392 self.host.delContact(entity, self.parent.profile) 393 self.host.delContact(entity, self.parent.profile)
393 self.host.bridge.subscribe('unsubscribe', entity.userhost(), self.parent.profile) 394 self.host.bridge.subscribe('unsubscribe', entity.userhost(), self.parent.profile)
394 395
395 396
396 class SatDiscoProtocol(disco.DiscoClientProtocol): 397 class SatDiscoProtocol(disco.DiscoClientProtocol):
403 generic.FallbackHandler.__init__(self) 404 generic.FallbackHandler.__init__(self)
404 405
405 def iqFallback(self, iq): 406 def iqFallback(self, iq):
406 if iq.handled is True: 407 if iq.handled is True:
407 return 408 return
408 debug(u"iqFallback: xml = [%s]" % (iq.toXml())) 409 log.debug(u"iqFallback: xml = [%s]" % (iq.toXml()))
409 generic.FallbackHandler.iqFallback(self, iq) 410 generic.FallbackHandler.iqFallback(self, iq)
410 411
411 412
412 class RegisteringAuthenticator(xmlstream.ConnectAuthenticator): 413 class RegisteringAuthenticator(xmlstream.ConnectAuthenticator):
413 414
439 _email = query.addElement('email') 440 _email = query.addElement('email')
440 _email.addContent(self.user_email) 441 _email.addContent(self.user_email)
441 iq.send(self.jabber_host).addCallbacks(self.registrationAnswer, self.registrationFailure) 442 iq.send(self.jabber_host).addCallbacks(self.registrationAnswer, self.registrationFailure)
442 443
443 def registrationAnswer(self, answer): 444 def registrationAnswer(self, answer):
444 debug(_("registration answer: %s") % answer.toXml()) 445 log.debug(_("registration answer: %s") % answer.toXml())
445 answer_type = "SUCCESS" 446 answer_type = "SUCCESS"
446 answer_data = {"message": _("Registration successfull")} 447 answer_data = {"message": _("Registration successfull")}
447 self.host.bridge.actionResult(answer_type, self.answer_id, answer_data, self.profile) 448 self.host.bridge.actionResult(answer_type, self.answer_id, answer_data, self.profile)
448 self.xmlstream.sendFooter() 449 self.xmlstream.sendFooter()
449 450
450 def registrationFailure(self, failure): 451 def registrationFailure(self, failure):
451 info(_("Registration failure: %s") % str(failure.value)) 452 log.info(_("Registration failure: %s") % str(failure.value))
452 answer_type = "ERROR" 453 answer_type = "ERROR"
453 answer_data = {} 454 answer_data = {}
454 if failure.value.condition == 'conflict': 455 if failure.value.condition == 'conflict':
455 answer_data['reason'] = 'conflict' 456 answer_data['reason'] = 'conflict'
456 answer_data = {"message": _("Username already exists, please choose an other one")} 457 answer_data = {"message": _("Username already exists, please choose an other one")}