github/SleekXMPP
1
0
Fork 0
mirror of https://github.com/correl/SleekXMPP.git synced 2024-11-23 11:09:54 +00:00
Code Issues Projects Releases Packages Wiki Activity

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.

Browse source 
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
This commit is contained in:
Vijay Pandurangan 2011-11-20 03:30:44 +08:00 committed by Lance Stout
parent 1baf139ca4
commit deb52ad350
23 changed files with 69 additions and 72 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

6
conn_tests/test_pubsubjobs.py
View file

@ -122,14 +122,14 @@ if __name__ == '__main__':
logging.basicConfig(level=opts.loglevel, format='%(levelname)-8s %(message)s')
#load xml config
logging.info("Loading config file: %s" % opts.configfile)
logging.info("Loading config file: %s" , opts.configfile)
config = configparser.RawConfigParser()
config.read(opts.configfile)
#init
logging.info("Account 1 is %s" % config.get('account1', 'jid'))
logging.info("Account 1 is %s" , config.get('account1', 'jid'))
xmpp1 = TestClient(config.get('account1','jid'), config.get('account1','pass'))
logging.info("Account 2 is %s" % config.get('account2', 'jid'))
logging.info("Account 2 is %s" , config.get('account2', 'jid'))
xmpp2 = TestClient(config.get('account2','jid'), config.get('account2','pass'))
xmpp1.registerPlugin('xep_0004')

6
conn_tests/test_pubsubserver.py
View file

@ -186,14 +186,14 @@ if __name__ == '__main__':
logging.basicConfig(level=opts.loglevel, format='%(levelname)-8s %(message)s')
#load xml config
logging.info("Loading config file: %s" % opts.configfile)
logging.info("Loading config file: %s" , opts.configfile)
config = configparser.RawConfigParser()
config.read(opts.configfile)
#init
logging.info("Account 1 is %s" % config.get('account1', 'jid'))
logging.info("Account 1 is %s" , config.get('account1', 'jid'))
xmpp1 = TestClient(config.get('account1','jid'), config.get('account1','pass'))
logging.info("Account 2 is %s" % config.get('account2', 'jid'))
logging.info("Account 2 is %s" , config.get('account2', 'jid'))
xmpp2 = TestClient(config.get('account2','jid'), config.get('account2','pass'))
xmpp1.registerPlugin('xep_0004')

4
conn_tests/testpubsub.py
View file

@ -329,11 +329,11 @@ if __name__ == '__main__':
logging.basicConfig(level=opts.loglevel, format='%(levelname)-8s %(message)s')
#load xml config
logging.info("Loading config file: %s" % opts.configfile)
logging.info("Loading config file: %s" , opts.configfile)
config = ET.parse(os.path.expanduser(opts.configfile)).find('auth')
#init
logging.info("Logging in as %s" % config.attrib['jid'])
logging.info("Logging in as %s" , config.attrib['jid'])
plugin_config = {}

2
examples/ping.py
View file

@ -72,7 +72,7 @@ class PingTest(sleekxmpp.ClientXMPP):
self.disconnect()
sys.exit(1)
else:
logging.info("Success! RTT: %s" % str(result))
logging.info("Success! RTT: %s" , str(result))
self.disconnect()

8
sleekxmpp/basexmpp.py
View file

@ -246,7 +246,7 @@ class BaseXMPP(XMLStream):
spec = "(RFC-%s) " % self.plugin[plugin].rfc
desc = (spec, self.plugin[plugin].description)
log.debug("Loaded Plugin %s%s" % desc)
log.debug("Loaded Plugin %s%s" , desc)
except:
log.exception("Unable to load plugin: %s", plugin)
@ -282,7 +282,7 @@ class BaseXMPP(XMLStream):
if key in self.plugin:
return self.plugin[key]
else:
log.warning("""Plugin "%s" is not loaded.""" % key)
log.warning("""Plugin "%s" is not loaded.""" , key)
return False
def get(self, key, default):
@ -679,7 +679,7 @@ class BaseXMPP(XMLStream):
def set_jid(self, jid):
"""Rip a JID apart and claim it as our own."""
log.debug("setting jid to %s" % jid)
log.debug("setting jid to %s" , jid)
self.boundjid.full = jid
def getjidresource(self, fulljid):
@ -795,7 +795,7 @@ class BaseXMPP(XMLStream):
log.warning('You should catch IqError exceptions')
elif isinstance(exception, IqTimeout):
iq = exception.iq
log.error('Request timed out: %s' % iq)
log.error('Request timed out: %s' , iq)
log.warning('You should catch IqTimeout exceptions')
else:
log.exception(exception)

2
sleekxmpp/clientxmpp.py
View file

@ -164,7 +164,7 @@ class ClientXMPP(BaseXMPP):
address = (answer.target.to_text()[:-1], answer.port)
answers.append((address, answer.priority, answer.weight))
except (dns.resolver.NXDOMAIN, dns.resolver.NoAnswer):
log.warning("No SRV records for %s" % domain)
log.warning("No SRV records for %s" , domain)
answers = super(ClientXMPP, self).get_dns_records(domain, port)
except dns.exception.Timeout:
log.warning("DNS resolution timed out " + \

4
sleekxmpp/features/feature_bind/bind.py
View file

@ -42,7 +42,7 @@ class feature_bind(base_plugin):
Arguments:
features -- The stream features stanza.
"""
log.debug("Requesting resource: %s" % self.xmpp.boundjid.resource)
log.debug("Requesting resource: %s" , self.xmpp.boundjid.resource)
iq = self.xmpp.Iq()
iq['type'] = 'set'
iq.enable('bind')
@ -55,7 +55,7 @@ class feature_bind(base_plugin):
self.xmpp.features.add('bind')
log.info("Node set to: %s" % self.xmpp.boundjid.full)
log.info("Node set to: %s" , self.xmpp.boundjid.full)
if 'session' not in features['features']:
log.debug("Established Session")

2
sleekxmpp/features/feature_mechanisms/mechanisms.py
View file

@ -123,7 +123,7 @@ class feature_mechanisms(base_plugin):
def _handle_fail(self, stanza):
"""SASL authentication failed. Disconnect and shutdown."""
log.info("Authentication failed: %s" % stanza['condition'])
log.info("Authentication failed: %s" , stanza['condition'])
self.xmpp.event("failed_auth", stanza, direct=True)
self.xmpp.disconnect()
return True

4
sleekxmpp/plugins/gmail_notify.py
View file

@ -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

2
sleekxmpp/plugins/jobs.py
View file

@ -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

16
sleekxmpp/plugins/xep_0009/remote.py
View file

@ -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()

8
sleekxmpp/plugins/xep_0009/rpc.py
View file

@ -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):

4
sleekxmpp/plugins/xep_0012.py
View file

@ -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):

4
sleekxmpp/plugins/xep_0045.py
View file

@ -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:

3
sleekxmpp/plugins/xep_0050/adhoc.py
View file

@ -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'],

4
sleekxmpp/plugins/xep_0078/legacyauth.py
View file

@ -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

2
sleekxmpp/plugins/xep_0085/chat_states.py
View file

@ -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)

6
sleekxmpp/plugins/xep_0199/ping.py
View file

@ -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

2
sleekxmpp/plugins/xep_0224/attention.py
View file

@ -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)

3
sleekxmpp/stanza/rootstanza.py
View file

@ -80,8 +80,7 @@ class RootStanza(StanzaBase):
self['error']['type'] = 'cancel'
self.send()
# log the error
log.exception('Error handling {%s}%s stanza' %
(self.namespace, self.name))
log.exception('Error handling {%s}%s stanza' , self.namespace, self.name)
# Finally raise the exception to a global exception handler
self.stream.exception(e)

2
sleekxmpp/xmlstream/handler/waiter.py
View file

@ -91,7 +91,7 @@ class Waiter(BaseHandler):
stanza = self._payload.get(True, timeout)
except queue.Empty:
stanza = False
log.warning("Timed out waiting for %s" % self.name)
log.warning("Timed out waiting for %s" , self.name)
self.stream().remove_handler(self.name)
return stanza

3
sleekxmpp/xmlstream/matcher/xmlmask.py
View file

@ -102,8 +102,7 @@ class MatchXMLMask(MatcherBase):
try:
mask = ET.fromstring(mask)
except ExpatError:
log.warning("Expat error: %s\nIn parsing: %s" % ('', mask))
log.warning("Expat error: %s\nIn parsing: %s" , '', mask)
if not use_ns:
# Compare the element without using namespaces.
source_tag = source.tag.split('}', 1)[-1]

44
sleekxmpp/xmlstream/xmlstream.py
View file

@ -362,7 +362,7 @@ class XMLStream(object):
else:
delay = min(self.reconnect_delay * 2, self.reconnect_max_delay)
delay = random.normalvariate(delay, delay * 0.1)
log.debug('Waiting %s seconds before connecting.' % delay)
log.debug('Waiting %s seconds before connecting.' , delay)
time.sleep(delay)
if self.use_proxy:
@ -391,7 +391,7 @@ class XMLStream(object):
try:
if not self.use_proxy:
log.debug("Connecting to %s:%s" % self.address)
log.debug("Connecting to %s:%s" , self.address)
self.socket.connect(self.address)
self.set_socket(self.socket, ignore=True)
@ -435,18 +435,18 @@ class XMLStream(object):
headers = '\r\n'.join(headers) + '\r\n\r\n'
try:
log.debug("Connecting to proxy: %s:%s" % address)
log.debug("Connecting to proxy: %s:%s" , address)
self.socket.connect(address)
self.send_raw(headers, now=True)
resp = ''
while '\r\n\r\n' not in resp:
resp += self.socket.recv(1024).decode('utf-8')
log.debug('RECV: %s' % resp)
log.debug('RECV: %s' , resp)
lines = resp.split('\r\n')
if '200' not in lines[0]:
self.event('proxy_error', resp)
log.error('Proxy Error: %s' % lines[0])
log.error('Proxy Error: %s' , lines[0])
return False
# Proxy connection established, continue connecting
@ -510,7 +510,7 @@ class XMLStream(object):
# Wait for confirmation that the stream was
# closed in the other direction.
self.auto_reconnect = reconnect
log.debug('Waiting for %s from server' % self.stream_footer)
log.debug('Waiting for %s from server' , self.stream_footer)
self.stream_end_event.wait(4)
if not self.auto_reconnect:
self.stop.set()
@ -601,7 +601,7 @@ class XMLStream(object):
"""
if self.ssl_support:
log.info("Negotiating TLS")
log.info("Using SSL version: %s" % str(self.ssl_version))
log.info("Using SSL version: %s" , str(self.ssl_version))
if self.ca_certs is None:
cert_policy = ssl.CERT_NONE
else:
@ -759,7 +759,7 @@ class XMLStream(object):
try:
answers = resolver.query(domain, dns.rdatatype.A)
except (dns.resolver.NXDOMAIN, dns.resolver.NoAnswer):
log.warning("No A records for %s" % domain)
log.warning("No A records for %s" , domain)
return [((domain, port), 0, 0)]
except dns.exception.Timeout:
log.warning("DNS resolution timed out " + \
@ -808,7 +808,7 @@ class XMLStream(object):
if self.dns_answers[0] == address:
break
self.dns_answers.pop(idx)
log.debug("Trying to connect to %s:%s" % address)
log.debug("Trying to connect to %s:%s" , address)
return address
def add_event_handler(self, name, pointer,
@ -879,7 +879,7 @@ class XMLStream(object):
handler[0](copy.copy(data))
except Exception as e:
error_msg = 'Error processing event handler: %s'
log.exception(error_msg % str(handler[0]))
log.exception(error_msg , str(handler[0]))
if hasattr(data, 'exception'):
data.exception(e)
else:
@ -994,7 +994,7 @@ class XMLStream(object):
Defaults to self.auto_reconnect.
"""
if now:
log.debug("SEND (IMMED): %s" % data)
log.debug("SEND (IMMED): %s" , data)
try:
data = data.encode('utf-8')
total = len(data)
@ -1004,10 +1004,10 @@ class XMLStream(object):
sent += self.socket.send(data[sent:])
count += 1
if count > 1:
log.debug('SENT: %d chunks' % count)
log.debug('SENT: %d chunks' , count)
except Socket.error as serr:
self.event('socket_error', serr)
log.warning("Failed to send %s" % data)
log.warning("Failed to send %s" , data)
if reconnect is None:
reconnect = self.auto_reconnect
self.disconnect(reconnect)
@ -1187,7 +1187,7 @@ class XMLStream(object):
Arguments:
xml -- The XML stanza to analyze.
"""
log.debug("RECV: %s" % tostring(xml,
log.debug("RECV: %s" , tostring(xml,
xmlns=self.default_ns,
stream=self))
# Apply any preprocessing filters.
@ -1232,7 +1232,7 @@ class XMLStream(object):
func(*args)
except Exception as e:
error_msg = 'Error processing event handler: %s'
log.exception(error_msg % str(func))
log.exception(error_msg , str(func))
if hasattr(orig, 'exception'):
orig.exception(e)
else:
@ -1267,12 +1267,12 @@ class XMLStream(object):
handler.run(args[0])
except Exception as e:
error_msg = 'Error processing stream handler: %s'
log.exception(error_msg % handler.name)
log.exception(error_msg , handler.name)
orig.exception(e)
elif etype == 'schedule':
name = args[1]
try:
log.debug('Scheduled event: %s: %s' % (name, args[0]))
log.debug('Scheduled event: %s: %s' , name, args[0])
handler(*args[0])
except Exception as e:
log.exception('Error processing scheduled task')
@ -1291,7 +1291,7 @@ class XMLStream(object):
func(*args)
except Exception as e:
error_msg = 'Error processing event handler: %s'
log.exception(error_msg % str(func))
log.exception(error_msg , str(func))
if hasattr(orig, 'exception'):
orig.exception(e)
else:
@ -1324,7 +1324,7 @@ class XMLStream(object):
data = self.send_queue.get(True, 1)
except queue.Empty:
continue
log.debug("SEND: %s" % data)
log.debug("SEND: %s" , data)
try:
enc_data = data.encode('utf-8')
total = len(enc_data)
@ -1334,15 +1334,15 @@ class XMLStream(object):
sent += self.socket.send(enc_data[sent:])
count += 1
if count > 1:
log.debug('SENT: %d chunks' % count)
log.debug('SENT: %d chunks' , count)
self.send_queue.task_done()
except Socket.error as serr:
self.event('socket_error', serr)
log.warning("Failed to send %s" % data)
log.warning("Failed to send %s" , data)
self.__failed_send_stanza = data
self.disconnect(self.auto_reconnect)
except Exception as ex:
log.exception('Unexpected error in send thread: %s' % ex)
log.exception('Unexpected error in send thread: %s' , ex)
self.exception(ex)
if not self.stop.is_set():
self.disconnect(self.auto_reconnect)