Tidy up logging calls.

This commit is contained in:
Lance Stout 2011-11-19 12:07:57 -08:00
parent deb52ad350
commit 429c94d6a9
23 changed files with 80 additions and 81 deletions

View file

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

View file

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

View file

@ -164,11 +164,11 @@ class ClientXMPP(BaseXMPP):
address = (answer.target.to_text()[:-1], answer.port) address = (answer.target.to_text()[:-1], answer.port)
answers.append((address, answer.priority, answer.weight)) answers.append((address, answer.priority, answer.weight))
except (dns.resolver.NXDOMAIN, dns.resolver.NoAnswer): 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) answers = super(ClientXMPP, self).get_dns_records(domain, port)
except dns.exception.Timeout: except dns.exception.Timeout:
log.warning("DNS resolution timed out " + \ log.warning("DNS resolution timed out " + \
"for SRV record of %s" % domain) "for SRV record of %s", domain)
answers = super(ClientXMPP, self).get_dns_records(domain, port) answers = super(ClientXMPP, self).get_dns_records(domain, port)
return answers return answers
else: else:

View file

@ -87,8 +87,8 @@ class ComponentXMPP(BaseXMPP):
Overrides XMLStream.connect. Overrides XMLStream.connect.
""" """
log.debug("Connecting to %s:%s" % (self.server_host, log.debug("Connecting to %s:%s", self.server_host,
self.server_port)) self.server_port)
return XMLStream.connect(self, self.server_host, return XMLStream.connect(self, self.server_host,
self.server_port) self.server_port)

View file

@ -42,7 +42,7 @@ class feature_bind(base_plugin):
Arguments: Arguments:
features -- The stream features stanza. 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 = self.xmpp.Iq()
iq['type'] = 'set' iq['type'] = 'set'
iq.enable('bind') iq.enable('bind')
@ -55,7 +55,7 @@ class feature_bind(base_plugin):
self.xmpp.features.add('bind') 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']: if 'session' not in features['features']:
log.debug("Established Session") log.debug("Established Session")

View file

@ -123,7 +123,7 @@ class feature_mechanisms(base_plugin):
def _handle_fail(self, stanza): def _handle_fail(self, stanza):
"""SASL authentication failed. Disconnect and shutdown.""" """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.event("failed_auth", stanza, direct=True)
self.xmpp.disconnect() self.xmpp.disconnect()
return True return True

View file

@ -58,8 +58,8 @@ class feature_starttls(base_plugin):
self.xmpp.send(features['starttls'], now=True) self.xmpp.send(features['starttls'], now=True)
return True return True
else: else:
log.warning("The module tlslite is required to log in" +\ log.warning("The module tlslite is required to log in" + \
" to some servers, and has not been found.") " to some servers, and has not been found.")
return False return False
def _handle_starttls_proceed(self, proceed): def _handle_starttls_proceed(self, proceed):

View file

@ -121,7 +121,7 @@ class gmail_notify(base.base_plugin):
def handle_gmail(self, iq): def handle_gmail(self, iq):
mailbox = iq['mailbox'] mailbox = iq['mailbox']
approx = ' approximately' if mailbox['estimated'] else '' 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.last_result_time = mailbox['result-time']
self.xmpp.event('gmail_messages', iq) self.xmpp.event('gmail_messages', iq)
@ -140,7 +140,7 @@ class gmail_notify(base.base_plugin):
if query is None: if query is None:
log.info("Gmail: Checking for new emails") log.info("Gmail: Checking for new emails")
else: else:
log.info('Gmail: Searching for emails matching: "%s"' , query) log.info('Gmail: Searching for emails matching: "%s"', query)
iq = self.xmpp.Iq() iq = self.xmpp.Iq()
iq['type'] = 'get' iq['type'] = 'get'
iq['to'] = self.xmpp.boundjid.bare iq['to'] = self.xmpp.boundjid.bare

View file

@ -43,7 +43,7 @@ class jobs(base.base_plugin):
iq['psstate']['payload'] = state iq['psstate']['payload'] = state
result = iq.send() result = iq.send()
if result is None or type(result) == bool or result['type'] != 'result': 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 False
return True return True

View file

@ -20,7 +20,7 @@ log = logging.getLogger(__name__)
def _intercept(method, name, public): def _intercept(method, name, public):
def _resolver(instance, *args, **kwargs): 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: try:
value = method(instance, *args, **kwargs) value = method(instance, *args, **kwargs)
if value == NotImplemented: if value == NotImplemented:
@ -381,7 +381,7 @@ class Proxy(Endpoint):
try: try:
if attribute._rpc: if attribute._rpc:
def _remote_call(*args, **kwargs): 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 self._endpoint.session._call_remote(self._endpoint.target_jid, "%s.%s" % (self._endpoint.FQN(), attribute._rpc_name), self._callback, *args, **kwargs)
return _remote_call return _remote_call
except: except:
@ -449,7 +449,7 @@ class RemoteSession(object):
self._event.wait() self._event.wait()
def _notify(self, event): 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._client.sendPresence()
self._event.set() self._event.set()
pass pass
@ -461,7 +461,7 @@ class RemoteSession(object):
if name is None: if name is None:
name = method.__name__ name = method.__name__
key = "%s.%s" % (endpoint, 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: with self._lock:
if key in self._entries: if key in self._entries:
raise KeyError("A handler for %s has already been regisered!" % endpoint) raise KeyError("A handler for %s has already been regisered!" % endpoint)
@ -469,7 +469,7 @@ class RemoteSession(object):
return key return key
def _register_acl(self, endpoint, acl): 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: with self._lock:
self._acls[endpoint] = acl self._acls[endpoint] = acl
@ -562,7 +562,7 @@ class RemoteSession(object):
iq.send() iq.send()
return future.get_value(30) return future.get_value(30)
else: else:
log.debug("[RemoteSession] _call_remote %s" , callback) log.debug("[RemoteSession] _call_remote %s", callback)
self._register_callback(pid, callback) self._register_callback(pid, callback)
iq.send() iq.send()
@ -601,11 +601,11 @@ class RemoteSession(object):
error.send() error.send()
except Exception as e: except Exception as e:
if isinstance(e, KeyError): 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) error = self._client.plugin['xep_0009']._item_not_found(iq)
else: else:
traceback.print_exc(file=sys.stderr) 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) error = self._client.plugin['xep_0009']._undefined_condition(iq)
#! print "[REMOTE.PY] _handle_remote_procedure_call AN ERROR SHOULD BE SENT NOW %s " % e #! print "[REMOTE.PY] _handle_remote_procedure_call AN ERROR SHOULD BE SENT NOW %s " % e
error.send() error.send()

View file

@ -128,22 +128,22 @@ class xep_0009(base.base_plugin):
def _handle_method_call(self, iq): def _handle_method_call(self, iq):
type = iq['type'] type = iq['type']
if type == 'set': 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) self.xmpp.event('jabber_rpc_method_call', iq)
else: else:
if type == 'error' and ['rpc_query'] is None: if type == 'error' and ['rpc_query'] is None:
self.handle_error(iq) self.handle_error(iq)
else: 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) self.xmpp.event('jabber_rpc_error', iq)
def _handle_method_response(self, iq): def _handle_method_response(self, iq):
if iq['rpc_query']['method_response']['fault'] is not None: 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._on_jabber_rpc_method_fault(iq)
self.xmpp.event('jabber_rpc_method_fault', iq) self.xmpp.event('jabber_rpc_method_fault', iq)
else: 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) self.xmpp.event('jabber_rpc_method_response', iq)
def _handle_error(self, iq): def _handle_error(self, iq):

View file

@ -71,10 +71,10 @@ class xep_0012(base.base_plugin):
def handle_last_activity_query(self, iq): def handle_last_activity_query(self, iq):
if iq['type'] == 'get': 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) self.xmpp.event('last_activity_request', iq)
elif iq['type'] == 'result': 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) self.xmpp.event('last_activity', iq)
def handle_last_activity(self, iq): def handle_last_activity(self, iq):

View file

@ -268,7 +268,7 @@ class xep_0030(base_plugin):
""" """
if local or jid is None: if local or jid is None:
log.debug("Looking up local disco#info data " + \ log.debug("Looking up local disco#info data " + \
"for %s, node %s." % (jid, node)) "for %s, node %s.", jid, node)
info = self._run_node_handler('get_info', jid, node, kwargs) info = self._run_node_handler('get_info', jid, node, kwargs)
return self._fix_default_info(info) return self._fix_default_info(info)
@ -542,7 +542,7 @@ class xep_0030(base_plugin):
""" """
if iq['type'] == 'get': if iq['type'] == 'get':
log.debug("Received disco info query from " + \ log.debug("Received disco info query from " + \
"<%s> to <%s>." % (iq['from'], iq['to'])) "<%s> to <%s>.", iq['from'], iq['to'])
if self.xmpp.is_component: if self.xmpp.is_component:
jid = iq['to'].full jid = iq['to'].full
else: else:
@ -558,7 +558,7 @@ class xep_0030(base_plugin):
iq.send() iq.send()
elif iq['type'] == 'result': elif iq['type'] == 'result':
log.debug("Received disco info result from" + \ log.debug("Received disco info result from" + \
"%s to %s." % (iq['from'], iq['to'])) "%s to %s.", iq['from'], iq['to'])
self.xmpp.event('disco_info', iq) self.xmpp.event('disco_info', iq)
def _handle_disco_items(self, iq): def _handle_disco_items(self, iq):
@ -572,7 +572,7 @@ class xep_0030(base_plugin):
""" """
if iq['type'] == 'get': if iq['type'] == 'get':
log.debug("Received disco items query from " + \ log.debug("Received disco items query from " + \
"<%s> to <%s>." % (iq['from'], iq['to'])) "<%s> to <%s>.", iq['from'], iq['to'])
if self.xmpp.is_component: if self.xmpp.is_component:
jid = iq['to'].full jid = iq['to'].full
else: else:
@ -586,7 +586,7 @@ class xep_0030(base_plugin):
iq.send() iq.send()
elif iq['type'] == 'result': elif iq['type'] == 'result':
log.debug("Received disco items result from" + \ log.debug("Received disco items result from" + \
"%s to %s." % (iq['from'], iq['to'])) "%s to %s.", iq['from'], iq['to'])
self.xmpp.event('disco_items', iq) self.xmpp.event('disco_items', iq)
def _fix_default_info(self, info): def _fix_default_info(self, info):

View file

@ -127,7 +127,7 @@ class xep_0045(base.base_plugin):
def handle_groupchat_invite(self, inv): def handle_groupchat_invite(self, inv):
""" Handle an invite into a muc. """ 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(): if inv['from'] not in self.rooms.keys():
self.xmpp.event("groupchat_invite", inv) 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']]: if entry['nick'] not in self.rooms[entry['room']]:
got_online = True got_online = True
self.rooms[entry['room']][entry['nick']] = entry 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("groupchat_presence", pr)
self.xmpp.event("muc::%s::presence" % entry['room'], pr) self.xmpp.event("muc::%s::presence" % entry['room'], pr)
if got_offline: if got_offline:

View file

@ -211,7 +211,7 @@ class xep_0050(base_plugin):
key = (iq['to'].full, node) key = (iq['to'].full, node)
name, handler = self.commands.get(key, ('Not found', None)) name, handler = self.commands.get(key, ('Not found', None))
if not handler: 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, initial_session = {'id': sessionid,
'from': iq['from'], 'from': iq['from'],
'to': iq['to'], 'to': iq['to'],

View file

@ -60,12 +60,12 @@ class xep_0078(base_plugin):
try: try:
resp = iq.send(now=True) resp = iq.send(now=True)
except IqError: 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.event('failed_auth', direct=True)
self.xmpp.disconnect() self.xmpp.disconnect()
return True return True
except IqTimeout: except IqTimeout:
log.info("Authentication failed: %s" , 'timeout') log.info("Authentication failed: %s", 'timeout')
self.xmpp.event('failed_auth', direct=True) self.xmpp.event('failed_auth', direct=True)
self.xmpp.disconnect() self.xmpp.disconnect()
return True return True

View file

@ -45,5 +45,5 @@ class xep_0085(base_plugin):
def _handle_chat_state(self, msg): def _handle_chat_state(self, msg):
state = msg['chat_state'] 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) self.xmpp.event('chatstate_%s' % state, msg)

View file

@ -118,7 +118,7 @@ class xep_0199(base_plugin):
Arguments: Arguments:
iq -- The ping request. iq -- The ping request.
""" """
log.debug("Pinged by %s" , iq['from']) log.debug("Pinged by %s", iq['from'])
iq.reply().send() iq.reply().send()
def send_ping(self, jid, timeout=None, errorfalse=False, def send_ping(self, jid, timeout=None, errorfalse=False,
@ -141,7 +141,7 @@ class xep_0199(base_plugin):
is received. Useful in conjunction with is received. Useful in conjunction with
the option block=False. the option block=False.
""" """
log.debug("Pinging %s" , jid) log.debug("Pinging %s", jid)
if timeout is None: if timeout is None:
timeout = self.timeout timeout = self.timeout
@ -167,7 +167,7 @@ class xep_0199(base_plugin):
if not block: if not block:
return None return None
log.debug("Pong: %s %f" , jid, delay) log.debug("Pong: %s %f", jid, delay)
return delay return delay

View file

@ -68,5 +68,5 @@ class xep_0224(base_plugin):
Arguments: Arguments:
msg -- A message stanza with an attention element. 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) self.xmpp.event('attention', msg)

View file

@ -91,7 +91,7 @@ class Waiter(BaseHandler):
stanza = self._payload.get(True, timeout) stanza = self._payload.get(True, timeout)
except queue.Empty: except queue.Empty:
stanza = False 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) self.stream().remove_handler(self.name)
return stanza return stanza

View file

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

View file

@ -1261,8 +1261,8 @@ class StanzaBase(ElementBase):
Meant to be overridden. Meant to be overridden.
""" """
log.exception('Error handling {%s}%s stanza' % (self.namespace, log.exception('Error handling {%s}%s stanza', self.namespace,
self.name)) self.name)
def send(self, now=False): def send(self, now=False):
""" """

View file

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