This change stops sleekxmpp from spending huge amounts of time unnecessarily computing logging data that may never be used. This is a HUGE performance improvement; in some of my test runs, unnecessary string creation was accounting for > 60% of all CPU time.

Note that using % in a string will _always_ perform the sting substitutions, because the strings are constructed before the function is called. So log.debug('%s' % expensiveoperation()) will take about the same CPU time whether or not the logging level is DEBUG or INFO. if you use , no substitutions are performed unless the string is actually logged

11 files changed, 27 insertions, 28 deletions

diff --git a/sleekxmpp/plugins/gmail_notify.py b/sleekxmpp/plugins/gmail_notify.py
index 9a94a413..f6391ac6 100644
--- a/sleekxmpp/plugins/gmail_notify.py
+++ b/sleekxmpp/plugins/gmail_notify.py
@@ -121,7 +121,7 @@ class gmail_notify(base.base_plugin):
     def handle_gmail(self, iq):
         mailbox = iq['mailbox']
         approx = ' approximately' if mailbox['estimated'] else ''
-        log.info('Gmail: Received%s %s emails' % (approx, mailbox['total-matched']))
+        log.info('Gmail: Received%s %s emails' , approx, mailbox['total-matched'])
         self.last_result_time = mailbox['result-time']
         self.xmpp.event('gmail_messages', iq)
 
@@ -140,7 +140,7 @@ class gmail_notify(base.base_plugin):
         if query is None:
             log.info("Gmail: Checking for new emails")
         else:
-            log.info('Gmail: Searching for emails matching: "%s"' % query)
+            log.info('Gmail: Searching for emails matching: "%s"' , query)
         iq = self.xmpp.Iq()
         iq['type'] = 'get'
         iq['to'] = self.xmpp.boundjid.bare
diff --git a/sleekxmpp/plugins/jobs.py b/sleekxmpp/plugins/jobs.py
index 0f1f7fb1..5ccfe271 100644
--- a/sleekxmpp/plugins/jobs.py
+++ b/sleekxmpp/plugins/jobs.py
@@ -43,7 +43,7 @@ class jobs(base.base_plugin):
 		iq['psstate']['payload'] = state
 		result = iq.send()
 		if result is None or type(result) == bool or result['type'] != 'result':
-			log.error("Unable to change %s:%s to %s" % (node, jobid, state))
+			log.error("Unable to change %s:%s to %s" , node, jobid, state)
 			return False
 		return True
 
diff --git a/sleekxmpp/plugins/xep_0009/remote.py b/sleekxmpp/plugins/xep_0009/remote.py
index 3cc0f520..6ca42d08 100644
--- a/sleekxmpp/plugins/xep_0009/remote.py
+++ b/sleekxmpp/plugins/xep_0009/remote.py
@@ -20,7 +20,7 @@ log = logging.getLogger(__name__)
 
 def _intercept(method, name, public):
     def _resolver(instance, *args, **kwargs):
-        log.debug("Locally calling %s.%s with arguments %s." % (instance.FQN(), method.__name__, args))
+        log.debug("Locally calling %s.%s with arguments %s." , instance.FQN(), method.__name__, args)
         try:
             value = method(instance, *args, **kwargs)
             if value == NotImplemented:
@@ -381,7 +381,7 @@ class Proxy(Endpoint):
                 try:
                     if attribute._rpc:
                         def _remote_call(*args, **kwargs):
-                            log.debug("Remotely calling '%s.%s' with arguments %s." % (self._endpoint.FQN(), attribute._rpc_name, args))
+                            log.debug("Remotely calling '%s.%s' with arguments %s." , self._endpoint.FQN(), attribute._rpc_name, args)
                             return self._endpoint.session._call_remote(self._endpoint.target_jid, "%s.%s" % (self._endpoint.FQN(), attribute._rpc_name), self._callback, *args, **kwargs)
                         return _remote_call
                 except:
@@ -449,7 +449,7 @@ class RemoteSession(object):
         self._event.wait()
 
     def _notify(self, event):
-        log.debug("RPC Session as %s started." % self._client.boundjid.full)
+        log.debug("RPC Session as %s started." , self._client.boundjid.full)
         self._client.sendPresence()
         self._event.set()
         pass
@@ -461,7 +461,7 @@ class RemoteSession(object):
         if name is None:
             name = method.__name__
         key = "%s.%s" % (endpoint, name)
-        log.debug("Registering call handler for %s (%s)." % (key, method))
+        log.debug("Registering call handler for %s (%s)." , key, method)
         with self._lock:
             if key in self._entries:
                 raise KeyError("A handler for %s has already been regisered!" % endpoint)
@@ -469,7 +469,7 @@ class RemoteSession(object):
         return key
 
     def _register_acl(self, endpoint, acl):
-        log.debug("Registering ACL %s for endpoint %s." % (repr(acl), endpoint))
+        log.debug("Registering ACL %s for endpoint %s." , repr(acl), endpoint)
         with self._lock:
             self._acls[endpoint] = acl
 
@@ -562,7 +562,7 @@ class RemoteSession(object):
             iq.send()
             return future.get_value(30)
         else:
-            log.debug("[RemoteSession] _call_remote %s" % callback)
+            log.debug("[RemoteSession] _call_remote %s" , callback)
             self._register_callback(pid, callback)
             iq.send()
 
@@ -601,11 +601,11 @@ class RemoteSession(object):
             error.send()
         except Exception as e:
             if isinstance(e, KeyError):
-                log.error("No handler available for %s!" % pmethod)
+                log.error("No handler available for %s!" , pmethod)
                 error = self._client.plugin['xep_0009']._item_not_found(iq)
             else:
                 traceback.print_exc(file=sys.stderr)
-                log.error("An unexpected problem occurred invoking method %s!" % pmethod)
+                log.error("An unexpected problem occurred invoking method %s!" , pmethod)
                 error = self._client.plugin['xep_0009']._undefined_condition(iq)
             #! print "[REMOTE.PY] _handle_remote_procedure_call AN ERROR SHOULD BE SENT NOW %s " % e
             error.send()
diff --git a/sleekxmpp/plugins/xep_0009/rpc.py b/sleekxmpp/plugins/xep_0009/rpc.py
index fc306d31..7f150511 100644
--- a/sleekxmpp/plugins/xep_0009/rpc.py
+++ b/sleekxmpp/plugins/xep_0009/rpc.py
@@ -128,22 +128,22 @@ class xep_0009(base.base_plugin):
     def _handle_method_call(self, iq):

         type = iq['type']

         if type == 'set':

-            log.debug("Incoming Jabber-RPC call from %s" % iq['from'])

+            log.debug("Incoming Jabber-RPC call from %s" , iq['from'])

             self.xmpp.event('jabber_rpc_method_call', iq)

         else:

             if type == 'error' and ['rpc_query'] is None:

                 self.handle_error(iq)

             else:

-                log.debug("Incoming Jabber-RPC error from %s" % iq['from'])

+                log.debug("Incoming Jabber-RPC error from %s" , iq['from'])

                 self.xmpp.event('jabber_rpc_error', iq)

 

     def _handle_method_response(self, iq):

         if iq['rpc_query']['method_response']['fault'] is not None:

-            log.debug("Incoming Jabber-RPC fault from %s" % iq['from'])

+            log.debug("Incoming Jabber-RPC fault from %s" , iq['from'])

             #self._on_jabber_rpc_method_fault(iq)

             self.xmpp.event('jabber_rpc_method_fault', iq)

         else:

-            log.debug("Incoming Jabber-RPC response from %s" % iq['from'])

+            log.debug("Incoming Jabber-RPC response from %s" , iq['from'])

             self.xmpp.event('jabber_rpc_method_response', iq)

 

     def _handle_error(self, iq):

diff --git a/sleekxmpp/plugins/xep_0012.py b/sleekxmpp/plugins/xep_0012.py
index 8fe818b8..e865cf19 100644
--- a/sleekxmpp/plugins/xep_0012.py
+++ b/sleekxmpp/plugins/xep_0012.py
@@ -71,10 +71,10 @@ class xep_0012(base.base_plugin):
 

     def handle_last_activity_query(self, iq):

         if iq['type'] == 'get':

-            log.debug("Last activity requested by %s" % iq['from'])

+            log.debug("Last activity requested by %s" , iq['from'])

             self.xmpp.event('last_activity_request', iq)

         elif iq['type'] == 'result':

-            log.debug("Last activity result from %s" % iq['from'])

+            log.debug("Last activity result from %s" , iq['from'])

             self.xmpp.event('last_activity', iq)

 

     def handle_last_activity(self, iq):

diff --git a/sleekxmpp/plugins/xep_0045.py b/sleekxmpp/plugins/xep_0045.py
index 45f16110..c037297e 100644
--- a/sleekxmpp/plugins/xep_0045.py
+++ b/sleekxmpp/plugins/xep_0045.py
@@ -127,7 +127,7 @@ class xep_0045(base.base_plugin):
     def handle_groupchat_invite(self, inv):
         """ Handle an invite into a muc.
         """
-        logging.debug("MUC invite to %s from %s: %s" % (inv['from'], inv["from"], inv))
+        logging.debug("MUC invite to %s from %s: %s" , inv['from'], inv["from"], inv)
         if inv['from'] not in self.rooms.keys():
             self.xmpp.event("groupchat_invite", inv)
 
@@ -149,7 +149,7 @@ class xep_0045(base.base_plugin):
             if entry['nick'] not in self.rooms[entry['room']]:
                 got_online = True
             self.rooms[entry['room']][entry['nick']] = entry
-        log.debug("MUC presence from %s/%s : %s" % (entry['room'],entry['nick'], entry))
+        log.debug("MUC presence from %s/%s : %s" , entry['room'],entry['nick'], entry)
         self.xmpp.event("groupchat_presence", pr)
         self.xmpp.event("muc::%s::presence" % entry['room'], pr)
         if got_offline:
diff --git a/sleekxmpp/plugins/xep_0050/adhoc.py b/sleekxmpp/plugins/xep_0050/adhoc.py
index 5095f874..7cfaa0e0 100644
--- a/sleekxmpp/plugins/xep_0050/adhoc.py
+++ b/sleekxmpp/plugins/xep_0050/adhoc.py
@@ -211,8 +211,7 @@ class xep_0050(base_plugin):
         key = (iq['to'].full, node)
         name, handler = self.commands.get(key, ('Not found', None))
         if not handler:
-            log.debug('Command not found: %s, %s' % (key, self.commands))
-
+            log.debug('Command not found: %s, %s' , key, self.commands)
         initial_session = {'id': sessionid,
                            'from': iq['from'],
                            'to': iq['to'],
diff --git a/sleekxmpp/plugins/xep_0078/legacyauth.py b/sleekxmpp/plugins/xep_0078/legacyauth.py
index edb8f314..49634462 100644
--- a/sleekxmpp/plugins/xep_0078/legacyauth.py
+++ b/sleekxmpp/plugins/xep_0078/legacyauth.py
@@ -60,12 +60,12 @@ class xep_0078(base_plugin):
         try:
             resp = iq.send(now=True)
         except IqError:
-            log.info("Authentication failed: %s" % resp['error']['condition'])
+            log.info("Authentication failed: %s" , resp['error']['condition'])
             self.xmpp.event('failed_auth', direct=True)
             self.xmpp.disconnect()
             return True
         except IqTimeout:
-            log.info("Authentication failed: %s" % 'timeout')
+            log.info("Authentication failed: %s" , 'timeout')
             self.xmpp.event('failed_auth', direct=True)
             self.xmpp.disconnect()
             return True
diff --git a/sleekxmpp/plugins/xep_0085/chat_states.py b/sleekxmpp/plugins/xep_0085/chat_states.py
index 4fb21ba0..d0a05cc9 100644
--- a/sleekxmpp/plugins/xep_0085/chat_states.py
+++ b/sleekxmpp/plugins/xep_0085/chat_states.py
@@ -45,5 +45,5 @@ class xep_0085(base_plugin):
 
     def _handle_chat_state(self, msg):
         state = msg['chat_state']
-        log.debug("Chat State: %s, %s" % (state, msg['from'].jid))
+        log.debug("Chat State: %s, %s" , state, msg['from'].jid)
         self.xmpp.event('chatstate_%s' % state, msg)
diff --git a/sleekxmpp/plugins/xep_0199/ping.py b/sleekxmpp/plugins/xep_0199/ping.py
index de7f5688..f8ae4018 100644
--- a/sleekxmpp/plugins/xep_0199/ping.py
+++ b/sleekxmpp/plugins/xep_0199/ping.py
@@ -118,7 +118,7 @@ class xep_0199(base_plugin):
         Arguments:
             iq -- The ping request.
         """
-        log.debug("Pinged by %s" % iq['from'])
+        log.debug("Pinged by %s" , iq['from'])
         iq.reply().send()
 
     def send_ping(self, jid, timeout=None, errorfalse=False,
@@ -141,7 +141,7 @@ class xep_0199(base_plugin):
                           is received. Useful in conjunction with
                           the option block=False.
         """
-        log.debug("Pinging %s" % jid)
+        log.debug("Pinging %s" , jid)
         if timeout is None:
             timeout = self.timeout
 
@@ -167,7 +167,7 @@ class xep_0199(base_plugin):
         if not block:
             return None
 
-        log.debug("Pong: %s %f" % (jid, delay))
+        log.debug("Pong: %s %f" , jid, delay)
         return delay
 
 
diff --git a/sleekxmpp/plugins/xep_0224/attention.py b/sleekxmpp/plugins/xep_0224/attention.py
index 41d7a0f1..4c03f6a5 100644
--- a/sleekxmpp/plugins/xep_0224/attention.py
+++ b/sleekxmpp/plugins/xep_0224/attention.py
@@ -68,5 +68,5 @@ class xep_0224(base_plugin):
         Arguments:
             msg -- A message stanza with an attention element.
         """
-        log.debug("Received attention request from: %s" % msg['from'])
+        log.debug("Received attention request from: %s" , msg['from'])
         self.xmpp.event('attention', msg)