From c5ffc7bf5db448bb211c015a20ab763f72e098cb Mon Sep 17 00:00:00 2001 From: junglecow Date: Mon, 13 Nov 2006 14:24:41 +0000 Subject: [PATCH 01/13] - Added support for PyOpenSSL (with fallback to old library if not found) - Also added a wrapper for cleaner compatibility handling of old SSL library - Changed exception handling to be more precise. (Catching Exception. Ish.) - Added lots of debug printing You will need to install pyopenssl (Debian unstable: python-pyopenssl) to try this. --- src/common/xmpp/transports_nb.py | 321 ++++++++++++++++++++++++++++--- 1 file changed, 299 insertions(+), 22 deletions(-) diff --git a/src/common/xmpp/transports_nb.py b/src/common/xmpp/transports_nb.py index ad3456e6a..edab59ea5 100644 --- a/src/common/xmpp/transports_nb.py +++ b/src/common/xmpp/transports_nb.py @@ -25,6 +25,33 @@ import sys import os import errno +import traceback +import thread + +import logging +h = logging.StreamHandler() +f = logging.Formatter('%(asctime)s %(name)s: %(levelname)s: %(message)s') +h.setFormatter(f) +log = logging.getLogger('Gajim.transports') +log.addHandler(h) +log.setLevel(logging.DEBUG) +log.propagate = False +del h, f + +USE_PYOPENSSL = False + +try: + #raise ImportError("Manually disabled PyOpenSSL") + import OpenSSL.SSL + import OpenSSL.crypto + USE_PYOPENSSL = True + print "PyOpenSSL loaded." +except ImportError: + # FIXME: Remove these prints before release, replace with a warning dialog. + print "=" * 79 + print "PyOpenSSL not found, falling back to Python builtin SSL objects (insecure)." + print "=" * 79 + # timeout to connect to the server socket, it doesn't include auth CONNECT_TIMEOUT_SECONDS = 30 @@ -33,7 +60,120 @@ DISCONNECT_TIMEOUT_SECONDS = 10 # size of the buffer which reads data from server # if lower, more stanzas will be fragmented and processed twice -RECV_BUFSIZE = 1048576 +RECV_BUFSIZE = 32768 # 2x maximum size of ssl packet, should be plenty +#RECV_BUFSIZE = 16 # FIXME: (#2634) gajim breaks with this setting: it's inefficient but should work. + +def torf(cond, tv, fv): + if cond: return tv + return fv + +class SSLWrapper: + def __init__(this, sslobj): + this.sslobj = sslobj + print "init called with", sslobj + + # We can return None out of this function to signal that no data is + # available right now. Better than an exception, which differs + # depending on which SSL lib we're using. Unfortunately returning '' + # can indicate that the socket has been closed, so to be sure, we avoid + # this. + + def recv(this, data, flags=None): + raise NotImplementedException() + + def send(this, data, flags=None): + raise NotImplementedException() + +class PyOpenSSLWrapper(SSLWrapper): + '''Wrapper class for PyOpenSSL's recv() and send() methods''' + parent = SSLWrapper + + def __init__(this, *args): + this.parent.__init__(this, *args) + + def is_numtoolarge(this, e): + t = ('asn1 encoding routines', 'a2d_ASN1_OBJECT', 'first num too large') + return isinstance(e.args, (list, tuple)) and len(e.args) == 1 and \ + isinstance(e.args[0], (list, tuple)) and len(e.args[0]) == 2 and \ + e.args[0][0] == e.args[0][1] == t + + def recv(this, bufsize, flags=None): + retval = None + try: + #print "recv: thread id:", thread.get_ident() + if flags is None: retval = this.sslobj.recv(bufsize) + else: retval = this.sslobj.recv(bufsize, flags) + except (OpenSSL.SSL.WantReadError, OpenSSL.SSL.WantWriteError), e: + log.debug("Recv: " + repr(e)) + except OpenSSL.SSL.Error, e: + "Recv: Caught OpenSSL.SSL.Error:" + traceback.print_exc() + print "Current Stack:" + traceback.print_stack() + if this.is_numtoolarge(e): + # print an error but ignore this exception + log.warning("Recv: OpenSSL: asn1enc: first num too large (eaten)") + else: + raise + + return retval + + def send(this, data, flags=None): + try: + #print "send: thread id:", thread.get_ident() + if flags is None: return this.sslobj.send(data) + else: return this.sslobj.send(data, flags) + except (OpenSSL.SSL.WantReadError, OpenSSL.SSL.WantWriteError), e: + log.debug("Send: " + repr(e)) + except OpenSSL.SSL.Error, e: + print "Send: Caught OpenSSL.SSL.Error:" + traceback.print_exc() + print "Current Stack:" + traceback.print_stack() + if this.is_numtoolarge(e): + # warn, but ignore this exception + log.warning("Send: OpenSSL: asn1enc: first num too large (ignoring)") + else: + raise + return 0 + +class StdlibSSLWrapper(SSLWrapper): + '''Wrapper class for Python's socket.ssl read() and write() methods''' + parent = SSLWrapper + + def __init__(this, *args): + this.parent.__init__(this, *args) + + def recv(this, bufsize, flags=None): + # we simply ignore flags since ssl object doesn't support it + retval = None + try: + retval = this.sslobj.read(bufsize) + except socket.sslerror, e: + print "Got socket.sslerror" + print e, e.args + traceback.print_exc() + print "Current Stack:" + traceback.print_stack() + if e.args[0] not in (socket.SSL_ERROR_WANT_READ, socket.SSL_ERROR_WANT_WRITE): + raise + if retval is None: return '' + if retval == '': raise SSLWrapper.SocketShutdown('Connection Closed') + return retval + + def send(this, data, flags=None): + # we simply ignore flags since ssl object doesn't support it + try: + return this.sslobj.write(data) + except socket.sslerror, e: + print "Got socket.sslerror" + print e, e.args + traceback.print_exc() + print "Current Stack:" + traceback.print_stack() + if e.args[0] not in (socket.SSL_ERROR_WANT_READ, socket.SSL_ERROR_WANT_WRITE): + raise + return 0 class NonBlockingTcp(PlugIn, IdleObject): ''' This class can be used instead of transports.Tcp in threadless implementations ''' @@ -109,6 +249,7 @@ class NonBlockingTcp(PlugIn, IdleObject): self._sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM) self._sock.setblocking(False) except: + traceback.print_exc() sys.exc_clear() if self.on_connect_failure: self.on_connect_failure() @@ -161,6 +302,7 @@ class NonBlockingTcp(PlugIn, IdleObject): self._sock.shutdown(socket.SHUT_RDWR) self._sock.close() except: + traceback.print_exc() # socket is already closed sys.exc_clear() # socket descriptor cannot be (un)plugged anymore @@ -204,34 +346,56 @@ class NonBlockingTcp(PlugIn, IdleObject): def _do_receive(self): ''' Reads all pending incoming data. Calls owner's disconnected() method if appropriate.''' - received = '' + ERR_DISCONN = -2 # Misc error signifying that we got disconnected + ERR_OTHER = -1 # Other error + received = None errnum = 0 + errtxt = 'No Error Set' try: # get as many bites, as possible, but not more than RECV_BUFSIZE received = self._recv(RECV_BUFSIZE) - except Exception, e: - if len(e.args) > 0 and isinstance(e.args[0], int): - errnum = e[0] - sys.exc_clear() - # "received" will be empty anyhow - if errnum == socket.SSL_ERROR_WANT_READ: - pass - elif errnum in [errno.ECONNRESET, errno.ENOTCONN, errno.ESHUTDOWN]: + except (socket.error, socket.herror, socket.gaierror), e: + print "Got socket exception" + traceback.print_exc() + print "Current Stack:" + traceback.print_stack() + errnum = e[0] + errtxt = str(errnum) + ':' + e[1] + except socket.sslerror, e: + print "Got unknown socket.sslerror" + traceback.print_exc() + print "Current Stack:" + traceback.print_stack() + errnum = ERR_OTHER + errtxt = repr("socket.sslerror: " + e.args) + + # Should we really do this? In C, recv() will happily return 0 + # in nonblocking mode when there is no data waiting, and in + # some cases select() will mark the socket for reading when + # there is nothing to read, and the socket is still open. For + # example, this can happen when the remote sends a zero-length + # tcp packet. + if received is '': + errnum = ERR_DISCONN + errtxt = "Connection closed unexpectedly" + + if errnum in (ERR_DISCONN, errno.ECONNRESET, errno.ENOTCONN, errno.ESHUTDOWN): + self.DEBUG(errtxt, 'error') self.pollend() # don't proccess result, cas it will raise error return - elif not received : - if errnum != socket.SSL_ERROR_EOF: - # 8 EOF occurred in violation of protocol - self.DEBUG('Socket error while receiving data', 'error') - self.pollend() - if self.state >= 0: - self.disconnect() - return - + + if received is None: + if errnum != 0: + self.DEBUG(errtxt, 'error') + if self.state >= 0: + self.disconnect() + return + received = '' + if self.state < 0: return - + # we have received some bites, stop the timeout! self.renew_send_timeout() if self.on_receive: @@ -268,6 +432,7 @@ class NonBlockingTcp(PlugIn, IdleObject): self._plug_idle() self._on_send() except socket.error, e: + traceback.print_exc() sys.exc_clear() if e[0] == socket.SSL_ERROR_WANT_WRITE: return True @@ -287,6 +452,7 @@ class NonBlockingTcp(PlugIn, IdleObject): try: self._sock.connect(self._server) except socket.error, e: + traceback.print_exc() errnum = e[0] sys.exc_clear() # in progress, or would block @@ -361,6 +527,14 @@ class NonBlockingTcp(PlugIn, IdleObject): class NonBlockingTLS(PlugIn): ''' TLS connection used to encrypts already estabilished tcp connection.''' + + # from ssl.h (partial extract) + ssl_h_bits = { "SSL_ST_CONNECT": 0x1000, "SSL_ST_ACCEPT": 0x2000, + "SSL_CB_LOOP": 0x01, "SSL_CB_EXIT": 0x02, + "SSL_CB_READ": 0x04, "SSL_CB_WRITE": 0x08, + "SSL_CB_ALERT": 0x4000, + "SSL_CB_HANDSHAKE_START": 0x10, "SSL_CB_HANDSHAKE_DONE": 0x20} + def PlugIn(self, owner, now=0, on_tls_start = None): ''' If the 'now' argument is true then starts using encryption immidiatedly. If 'now' in false then starts encryption as soon as TLS feature is @@ -375,6 +549,7 @@ class NonBlockingTLS(PlugIn): try: res = self._startSSL() except Exception, e: + traceback.print_exc() self._owner.socket.pollend() return self.tls_start() @@ -416,18 +591,118 @@ class NonBlockingTLS(PlugIn): self.tls_start() raise NodeProcessed + def _dumpX509(this, cert): + print "Digest (SHA-1):", cert.digest("sha1") + print "Digest (MD5):", cert.digest("md5") + print "Serial #:", cert.get_serial_number() + print "Version:", cert.get_version() + print "Expired:", torf(cert.has_expired(), "Yes", "No") + print "Subject:" + this._dumpX509Name(cert.get_subject()) + print "Issuer:" + this._dumpX509Name(cert.get_issuer()) + this._dumpPKey(cert.get_pubkey()) + + def _dumpX509Name(this, name): + print "X509Name:", str(name) + + def _dumpPKey(this, pkey): + typedict = {OpenSSL.crypto.TYPE_RSA: "RSA", OpenSSL.crypto.TYPE_DSA: "DSA"} + print "PKey bits:", pkey.bits() + print "PKey type: %s (%d)" % (typedict.get(pkey.type(), "Unknown"), pkey.type()) + def _startSSL(self): ''' Immidiatedly switch socket to TLS mode. Used internally.''' + print "_startSSL called" + if USE_PYOPENSSL: return self._startSSL_pyOpenSSL() + return self._startSSL_stdlib() + + def _startSSL_pyOpenSSL(self): + print "_startSSL_pyOpenSSL called, thread id:", thread.get_ident() + tcpsock = self._owner.Connection + # FIXME: should method be configurable? + tcpsock._sslContext = OpenSSL.SSL.Context(OpenSSL.SSL.TLSv1_METHOD) + tcpsock._sslContext.set_info_callback(self._ssl_info_callback) + tcpsock._sslObj = OpenSSL.SSL.Connection(tcpsock._sslContext, tcpsock._sock) + tcpsock._sslObj.set_connect_state() # set to client mode + + wrapper = PyOpenSSLWrapper(tcpsock._sslObj) + tcpsock._recv = wrapper.recv + tcpsock._send = wrapper.send + + print "Initiating handshake..." + #tcpsock._sslObj.setblocking(True) + try: + self.starttls='in progress' + tcpsock._sslObj.do_handshake() + except (OpenSSL.SSL.WantReadError, OpenSSL.SSL.WantWriteError), e: + log.debug("do_handshake: " + str(e)) + #tcpsock._sslObj.setblocking(False) + #print "Done handshake" + print "Async handshake started..." + + def _on_ssl_handshake_done(self): + print "Handshake done!" + self.starttls='success' + + tcpsock = self._owner.Connection + cert = tcpsock._sslObj.get_peer_certificate() + peer = cert.get_subject() + issuer = cert.get_issuer() + tcpsock._sslIssuer = unicode(issuer) + tcpsock._sslServer = unicode(peer) + + # FIXME: remove debug prints + peercert = tcpsock._sslObj.get_peer_certificate() + ciphers = tcpsock._sslObj.get_cipher_list() + + print "Ciphers:", ciphers + print "Peer cert:", peercert + self._dumpX509(peercert) + + print OpenSSL.crypto.dump_certificate(OpenSSL.crypto.FILETYPE_PEM, peercert) + + def _startSSL_stdlib(self): + print "_startSSL_stdlib called" tcpsock=self._owner.Connection tcpsock._sock.setblocking(True) tcpsock._sslObj = socket.ssl(tcpsock._sock, None, None) tcpsock._sock.setblocking(False) tcpsock._sslIssuer = tcpsock._sslObj.issuer() tcpsock._sslServer = tcpsock._sslObj.server() - tcpsock._recv = tcpsock._sslObj.read - tcpsock._send = tcpsock._sslObj.write + wrapper = StdlibSSLWrapper(tcpsock._sslObj) + tcpsock._recv = wrapper.recv + tcpsock._send = wrapper.send self.starttls='success' + def _ssl_info_callback(this, sslconn, type, st): + # Exceptions can't propagate up through this callback, so print them here. + try: this._ssl_info_callback_guarded(sslconn, type, st) + except: traceback.print_exc() + + def _ssl_info_callback_guarded(this, sslconn, type, st): + b = this.ssl_h_bits + + #if type & b['SSL_CB_LOOP']: + # if type & SSL_ST_CONNECT: tls_state = "connect" + # elif type & SSL_ST_ACCEPT: tls_state = "accept" + # else: tls_state = "undefined" + # print "tls_state: %s: %s" % (tls_state, sslconn.state_string()) + + #if type & b['SSL_CB_ALERT']: + # if type & SSL_CB_READ: rdwr = "read" + # elif type & SSL_CB_WRITE: rdwr = "write" + # else: rdwr = "unknown" + # print "tls_alert: %s:%d: %s" % (rdwr, st, sslconn.state_string()) + + #mask = "" + #for k, v in b.iteritems(): + # if type & v: mask += " " + k + #print "mask:", mask, st + + if type & b['SSL_CB_HANDSHAKE_DONE']: + this._on_ssl_handshake_done() + def StartTLSHandler(self, conn, starttls): ''' Handle server reply if TLS is allowed to process. Behaves accordingly. Used internally.''' @@ -441,6 +716,7 @@ class NonBlockingTLS(PlugIn): try: self._startSSL() except Exception, e: + traceback.print_exc() self._owner.socket.pollend() return self._owner.Dispatcher.PlugOut() @@ -499,6 +775,7 @@ class NBHTTPPROXYsocket(NonBlockingTcp): try: proto, code, desc = reply.split('\n')[0].split(' ', 2) except: + traceback.print_exc() raise error('Invalid proxy reply') if code <> '200': self.DEBUG('Invalid proxy reply: %s %s %s' % (proto, code, desc),'error') From 9e3e14dd786bef425874d330d57d01998f76e529 Mon Sep 17 00:00:00 2001 From: junglecow Date: Mon, 13 Nov 2006 14:44:17 +0000 Subject: [PATCH 02/13] Fixed a bug in compatibility code --- src/common/xmpp/transports_nb.py | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/src/common/xmpp/transports_nb.py b/src/common/xmpp/transports_nb.py index edab59ea5..02a8d3236 100644 --- a/src/common/xmpp/transports_nb.py +++ b/src/common/xmpp/transports_nb.py @@ -157,8 +157,7 @@ class StdlibSSLWrapper(SSLWrapper): traceback.print_stack() if e.args[0] not in (socket.SSL_ERROR_WANT_READ, socket.SSL_ERROR_WANT_WRITE): raise - if retval is None: return '' - if retval == '': raise SSLWrapper.SocketShutdown('Connection Closed') + return retval def send(this, data, flags=None): From 4617618463aa5ac82c63f7b5b5caf7a6fe9a4007 Mon Sep 17 00:00:00 2001 From: junglecow Date: Mon, 13 Nov 2006 15:07:47 +0000 Subject: [PATCH 03/13] Removing all calls to sys.exc_clear(). This is only necessary in very rare circumstances, and if there is such a circumstance, it should be clearly documented in code. --- src/common/xmpp/dispatcher_nb.py | 1 - src/common/xmpp/transports_nb.py | 4 ---- src/common/zeroconf/client_zeroconf.py | 2 -- src/gajim-remote.py | 1 - 4 files changed, 8 deletions(-) diff --git a/src/common/xmpp/dispatcher_nb.py b/src/common/xmpp/dispatcher_nb.py index 732de220f..7fb064a80 100644 --- a/src/common/xmpp/dispatcher_nb.py +++ b/src/common/xmpp/dispatcher_nb.py @@ -135,7 +135,6 @@ class Dispatcher(PlugIn): self._owner.Connection.disconnect() return 0 except ExpatError: - sys.exc_clear() self.DEBUG('Invalid XML received from server. Forcing disconnect.', 'error') self._owner.Connection.pollend() return 0 diff --git a/src/common/xmpp/transports_nb.py b/src/common/xmpp/transports_nb.py index 02a8d3236..cba137c6e 100644 --- a/src/common/xmpp/transports_nb.py +++ b/src/common/xmpp/transports_nb.py @@ -249,7 +249,6 @@ class NonBlockingTcp(PlugIn, IdleObject): self._sock.setblocking(False) except: traceback.print_exc() - sys.exc_clear() if self.on_connect_failure: self.on_connect_failure() return False @@ -303,7 +302,6 @@ class NonBlockingTcp(PlugIn, IdleObject): except: traceback.print_exc() # socket is already closed - sys.exc_clear() # socket descriptor cannot be (un)plugged anymore self.fd = -1 if self.on_disconnect: @@ -432,7 +430,6 @@ class NonBlockingTcp(PlugIn, IdleObject): self._on_send() except socket.error, e: traceback.print_exc() - sys.exc_clear() if e[0] == socket.SSL_ERROR_WANT_WRITE: return True if self.state < 0: @@ -453,7 +450,6 @@ class NonBlockingTcp(PlugIn, IdleObject): except socket.error, e: traceback.print_exc() errnum = e[0] - sys.exc_clear() # in progress, or would block if errnum in (errno.EINPROGRESS, errno.EALREADY, errno.EWOULDBLOCK): return diff --git a/src/common/zeroconf/client_zeroconf.py b/src/common/zeroconf/client_zeroconf.py index da15b7ad5..04a975875 100644 --- a/src/common/zeroconf/client_zeroconf.py +++ b/src/common/zeroconf/client_zeroconf.py @@ -377,7 +377,6 @@ class P2PConnection(IdleObject, PlugIn): except Exception, e: if len(e.args) > 0 and isinstance(e.args[0], int): errnum = e[0] - sys.exc_clear() # "received" will be empty anyhow if errnum == socket.SSL_ERROR_WANT_READ: pass @@ -457,7 +456,6 @@ class P2PConnection(IdleObject, PlugIn): self._on_send() except socket.error, e: - sys.exc_clear() if e[0] == socket.SSL_ERROR_WANT_WRITE: return True if self.state < 0: diff --git a/src/gajim-remote.py b/src/gajim-remote.py index 5548b80aa..48a4335aa 100755 --- a/src/gajim-remote.py +++ b/src/gajim-remote.py @@ -27,7 +27,6 @@ from common import i18n try: PREFERRED_ENCODING = locale.getpreferredencoding() except: - sys.exc_clear() PREFERRED_ENCODING = 'UTF-8' def send_error(error_message): From be1b58aa79cd43e6dea65b75512909785c5602bc Mon Sep 17 00:00:00 2001 From: junglecow Date: Mon, 13 Nov 2006 22:17:16 +0000 Subject: [PATCH 04/13] Handle OpenSSL.SSL.SysCallError --- src/common/xmpp/transports_nb.py | 16 +++++++++++++++- 1 file changed, 15 insertions(+), 1 deletion(-) diff --git a/src/common/xmpp/transports_nb.py b/src/common/xmpp/transports_nb.py index cba137c6e..7fe2cac64 100644 --- a/src/common/xmpp/transports_nb.py +++ b/src/common/xmpp/transports_nb.py @@ -68,6 +68,11 @@ def torf(cond, tv, fv): return fv class SSLWrapper: + def Error(Exception): + parent = Exception + def __init__(this, *args): + this.parent.__init__(this, *args) + def __init__(this, sslobj): this.sslobj = sslobj print "init called with", sslobj @@ -105,6 +110,10 @@ class PyOpenSSLWrapper(SSLWrapper): else: retval = this.sslobj.recv(bufsize, flags) except (OpenSSL.SSL.WantReadError, OpenSSL.SSL.WantWriteError), e: log.debug("Recv: " + repr(e)) + except OpenSSL.SSL.SysCallError: + log.error("Got OpenSSL.SSL.SysCallError: " + repr(e)) + traceback.print_exc() + raise SSLWrapper.Error(('OpenSSL.SSL.SysCallError', e.args)) except OpenSSL.SSL.Error, e: "Recv: Caught OpenSSL.SSL.Error:" traceback.print_exc() @@ -365,6 +374,9 @@ class NonBlockingTcp(PlugIn, IdleObject): traceback.print_stack() errnum = ERR_OTHER errtxt = repr("socket.sslerror: " + e.args) + except SSLWrapper.Error: + errnum = ERR_OTHER + errtxt = repr(e.args) # Should we really do this? In C, recv() will happily return 0 # in nonblocking mode when there is no data waiting, and in @@ -378,6 +390,7 @@ class NonBlockingTcp(PlugIn, IdleObject): if errnum in (ERR_DISCONN, errno.ECONNRESET, errno.ENOTCONN, errno.ESHUTDOWN): self.DEBUG(errtxt, 'error') + log.error("Got Disconnected: " + errtxt) self.pollend() # don't proccess result, cas it will raise error return @@ -385,6 +398,7 @@ class NonBlockingTcp(PlugIn, IdleObject): if received is None: if errnum != 0: self.DEBUG(errtxt, 'error') + log.error("Error: " + errtxt) if self.state >= 0: self.disconnect() return @@ -631,7 +645,7 @@ class NonBlockingTLS(PlugIn): self.starttls='in progress' tcpsock._sslObj.do_handshake() except (OpenSSL.SSL.WantReadError, OpenSSL.SSL.WantWriteError), e: - log.debug("do_handshake: " + str(e)) + log.debug("do_handshake: " + repr(e)) #tcpsock._sslObj.setblocking(False) #print "Done handshake" print "Async handshake started..." From 321020751d263b88d8575ed3bf7795ee87277632 Mon Sep 17 00:00:00 2001 From: junglecow Date: Tue, 14 Nov 2006 06:39:08 +0000 Subject: [PATCH 05/13] Bugfix --- src/common/xmpp/transports_nb.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/common/xmpp/transports_nb.py b/src/common/xmpp/transports_nb.py index 7fe2cac64..29de0668e 100644 --- a/src/common/xmpp/transports_nb.py +++ b/src/common/xmpp/transports_nb.py @@ -110,7 +110,7 @@ class PyOpenSSLWrapper(SSLWrapper): else: retval = this.sslobj.recv(bufsize, flags) except (OpenSSL.SSL.WantReadError, OpenSSL.SSL.WantWriteError), e: log.debug("Recv: " + repr(e)) - except OpenSSL.SSL.SysCallError: + except OpenSSL.SSL.SysCallError, e: log.error("Got OpenSSL.SSL.SysCallError: " + repr(e)) traceback.print_exc() raise SSLWrapper.Error(('OpenSSL.SSL.SysCallError', e.args)) From 3c77ffd406075bdbfc53363633d54ef948053596 Mon Sep 17 00:00:00 2001 From: junglecow Date: Sat, 18 Nov 2006 15:09:40 +0000 Subject: [PATCH 06/13] [PyOpenSSL branch] - Close connection after creating account. Fixes #2676 - Handle normal connection close by server. Fixes #2671 - Do not disconnect if we haven't received starttag yet. Fixes #2668. Fixes unticketed bug causing account creation not to work with PyOpenSSL and asynchronous handshake (see also #2671). Behaviour of #2634 is also improved but now results in deadlock. --- src/common/xmpp/dispatcher_nb.py | 3 ++- src/common/xmpp/simplexml.py | 19 +++++++++++++++++-- src/common/xmpp/transports_nb.py | 5 ++++- 3 files changed, 23 insertions(+), 4 deletions(-) diff --git a/src/common/xmpp/dispatcher_nb.py b/src/common/xmpp/dispatcher_nb.py index 7fb064a80..9f05282f1 100644 --- a/src/common/xmpp/dispatcher_nb.py +++ b/src/common/xmpp/dispatcher_nb.py @@ -131,7 +131,7 @@ class Dispatcher(PlugIn): try: self.Stream.Parse(data) # end stream:stream tag received - if self.Stream and self.Stream._NodeBuilder__depth == 0: + if self.Stream and self.Stream.has_received_endtag(): self._owner.Connection.disconnect() return 0 except ExpatError: @@ -141,6 +141,7 @@ class Dispatcher(PlugIn): if len(self._pendingExceptions) > 0: _pendingException = self._pendingExceptions.pop() raise _pendingException[0], _pendingException[1], _pendingException[2] + if len(data) == 0: return '0' return len(data) def RegisterNamespace(self, xmlns, order='info'): diff --git a/src/common/xmpp/simplexml.py b/src/common/xmpp/simplexml.py index 76c70651f..5596aa165 100644 --- a/src/common/xmpp/simplexml.py +++ b/src/common/xmpp/simplexml.py @@ -290,6 +290,8 @@ class NodeBuilder: self.Parse = self._parser.Parse self.__depth = 0 + self.__last_depth = 0 + self.__max_depth = 0 self._dispatch_depth = 1 self._document_attrs = None self._mini_dom=initial_node @@ -326,7 +328,7 @@ class NodeBuilder: ns=attr[:sp] # attrs[self.namespaces[ns]+attr[sp+1:]]=attrs[attr] del attrs[attr] # - self.__depth += 1 + self._inc_depth() self.DEBUG(DBG_NODEBUILDER, "DEPTH -> %i , tag -> %s, attrs -> %s" % (self.__depth, tag, `attrs`), 'down') if self.__depth == self._dispatch_depth: if not self._mini_dom : @@ -354,7 +356,7 @@ class NodeBuilder: self._ptr = self._ptr.parent else: self.DEBUG(DBG_NODEBUILDER, "Got higher than dispatch level. Stream terminated?", 'stop') - self.__depth -= 1 + self._dec_depth() self.last_is_data = 0 if self.__depth == 0: self.stream_footer_received() @@ -387,6 +389,19 @@ class NodeBuilder: """ Method called when stream just closed. """ self.check_data_buffer() + def has_received_endtag(self, level=0): + """ Return True if at least one end tag was seen (at level) """ + return self.__depth <= level and self.__max_depth > level + + def _inc_depth(self): + self.__last_depth = self.__depth + self.__depth += 1 + self.__max_depth = max(self.__depth, self.__max_depth) + + def _dec_depth(self): + self.__last_depth = self.__depth + self.__depth -= 1 + def XML2Node(xml): """ Converts supplied textual string into XML node. Handy f.e. for reading configuration file. Raises xml.parser.expat.parsererror if provided string is not well-formed XML. """ diff --git a/src/common/xmpp/transports_nb.py b/src/common/xmpp/transports_nb.py index 29de0668e..4a8d270b2 100644 --- a/src/common/xmpp/transports_nb.py +++ b/src/common/xmpp/transports_nb.py @@ -650,9 +650,12 @@ class NonBlockingTLS(PlugIn): #print "Done handshake" print "Async handshake started..." + # fake it, for now + self.starttls='success' + def _on_ssl_handshake_done(self): print "Handshake done!" - self.starttls='success' + #self.starttls='success' tcpsock = self._owner.Connection cert = tcpsock._sslObj.get_peer_certificate() From 5cb241b8c0e8cdb491050c321706be957c17e042 Mon Sep 17 00:00:00 2001 From: junglecow Date: Tue, 28 Nov 2006 01:02:31 +0000 Subject: [PATCH 07/13] [trunk] - Typo [pyopenssl] - Better exception handling - Prevent 100% cpu usage when ssl handshake is slow --- src/common/xmpp/client_nb.py | 4 +- src/common/xmpp/transports_nb.py | 120 +++++++++++++++++++++---------- 2 files changed, 84 insertions(+), 40 deletions(-) diff --git a/src/common/xmpp/client_nb.py b/src/common/xmpp/client_nb.py index 40753ef4e..7db5a1eeb 100644 --- a/src/common/xmpp/client_nb.py +++ b/src/common/xmpp/client_nb.py @@ -74,10 +74,8 @@ class NBCommonClient(CommonClient): ''' Called on disconnection. Calls disconnect handlers and cleans things up. ''' self.connected='' self.DEBUG(self.DBG,'Disconnect detected','stop') - self.disconnect_handlers.reverse() - for i in self.disconnect_handlers: + for i in reversed(self.disconnect_handlers): i() - self.disconnect_handlers.reverse() if self.__dict__.has_key('NonBlockingRoster'): self.NonBlockingRoster.PlugOut() if self.__dict__.has_key('NonBlockingBind'): diff --git a/src/common/xmpp/transports_nb.py b/src/common/xmpp/transports_nb.py index 4a8d270b2..d5865db6e 100644 --- a/src/common/xmpp/transports_nb.py +++ b/src/common/xmpp/transports_nb.py @@ -24,6 +24,7 @@ from transports import * import sys import os import errno +import time import traceback import thread @@ -67,14 +68,55 @@ def torf(cond, tv, fv): if cond: return tv return fv -class SSLWrapper: - def Error(Exception): - parent = Exception - def __init__(this, *args): - this.parent.__init__(this, *args) +def gattr(obj, attr, default=None): + try: + return getattr(obj, attr) + except: + return default - def __init__(this, sslobj): +class SSLWrapper: + class Error(IOError): + def __init__(this, sock=None, exc=None, errno=None, strerror=None, peer=None): + this.parent = IOError + + this.exc = exc + + this.errno = errno or gattr(this.exc, 'errno', 0) + this.strerror = strerror or gattr(this.exc, 'strerror') or gattr(this.exc, 'args') + + this.parent.__init__(this, errno, strerror) + this.peer = peer + this.exc_name = None + + if this.exc is not None: + this.exc_name = str(this.exc.__class__) + this.exc_args = gattr(this.exc, 'args') + this.exc_str = str(this.exc) + this.exc_repr = repr(this.exc) + + if this.peer is None and sock is not None: + try: + ppeer = this.obj.getpeername() + if len(ppeer) == 2 and isinstance(ppeer[0], basestring) \ + and isinstance(ppeer[1], int): + this.peer = ppeer + except: pass + + def __str__(this): + s = str(this.__class__) + if this.peer: s += "for %s:%d" % this.peer + if this.errno is not None: s += ": [Errno: %d]" % this.errno + if this.strerror: s += " (%s)" % this.strerror + if this.exc_name: + s += ", Caused by %s" % this.exc_name + if this.exc_str: + if this.strerror: s += "(%s)" % this.exc_str + else: s += "(%s)" % this.exc_args + return s + + def __init__(this, sslobj, sock=None): this.sslobj = sslobj + this.sock = sock print "init called with", sslobj # We can return None out of this function to signal that no data is @@ -91,9 +133,9 @@ class SSLWrapper: class PyOpenSSLWrapper(SSLWrapper): '''Wrapper class for PyOpenSSL's recv() and send() methods''' - parent = SSLWrapper def __init__(this, *args): + this.parent = SSLWrapper this.parent.__init__(this, *args) def is_numtoolarge(this, e): @@ -111,20 +153,19 @@ class PyOpenSSLWrapper(SSLWrapper): except (OpenSSL.SSL.WantReadError, OpenSSL.SSL.WantWriteError), e: log.debug("Recv: " + repr(e)) except OpenSSL.SSL.SysCallError, e: - log.error("Got OpenSSL.SSL.SysCallError: " + repr(e)) + log.error("Recv: Got OpenSSL.SSL.SysCallError: " + repr(e)) traceback.print_exc() - raise SSLWrapper.Error(('OpenSSL.SSL.SysCallError', e.args)) + raise SSLWrapper.Error(this.sock or this.sslobj, e) except OpenSSL.SSL.Error, e: - "Recv: Caught OpenSSL.SSL.Error:" - traceback.print_exc() - print "Current Stack:" - traceback.print_stack() if this.is_numtoolarge(e): - # print an error but ignore this exception - log.warning("Recv: OpenSSL: asn1enc: first num too large (eaten)") + # warn, but ignore this exception + log.warning("Recv: OpenSSL: asn1enc: first num too large (ignored)") else: - raise - + log.warning("Recv: Caught OpenSSL.SSL.Error:") + traceback.print_exc() + print "Current Stack:" + traceback.print_stack() + raise SSLWrapper.Error(this.sock or this.sslobj, e) return retval def send(this, data, flags=None): @@ -134,23 +175,28 @@ class PyOpenSSLWrapper(SSLWrapper): else: return this.sslobj.send(data, flags) except (OpenSSL.SSL.WantReadError, OpenSSL.SSL.WantWriteError), e: log.debug("Send: " + repr(e)) - except OpenSSL.SSL.Error, e: - print "Send: Caught OpenSSL.SSL.Error:" + time.sleep(0.1) # prevent 100% CPU usage + except OpenSSL.SSL.SysCallError, e: + log.error("Recv: Got OpenSSL.SSL.SysCallError: " + repr(e)) traceback.print_exc() - print "Current Stack:" - traceback.print_stack() + raise SSLWrapper.Error(this.sock or this.sslobj, e) + except OpenSSL.SSL.Error, e: if this.is_numtoolarge(e): # warn, but ignore this exception - log.warning("Send: OpenSSL: asn1enc: first num too large (ignoring)") + log.warning("Send: OpenSSL: asn1enc: first num too large (ignored)") else: - raise + log.warning("Send: Caught OpenSSL.SSL.Error:") + traceback.print_exc() + print "Current Stack:" + traceback.print_stack() + raise SSLWrapper.Error(this.sock or this.sslobj, e) return 0 class StdlibSSLWrapper(SSLWrapper): '''Wrapper class for Python's socket.ssl read() and write() methods''' - parent = SSLWrapper def __init__(this, *args): + this.parent = SSLWrapper this.parent.__init__(this, *args) def recv(this, bufsize, flags=None): @@ -165,7 +211,7 @@ class StdlibSSLWrapper(SSLWrapper): print "Current Stack:" traceback.print_stack() if e.args[0] not in (socket.SSL_ERROR_WANT_READ, socket.SSL_ERROR_WANT_WRITE): - raise + raise SSLWrapper.Error(this.sock or this.sslobj, e) return retval @@ -180,7 +226,7 @@ class StdlibSSLWrapper(SSLWrapper): print "Current Stack:" traceback.print_stack() if e.args[0] not in (socket.SSL_ERROR_WANT_READ, socket.SSL_ERROR_WANT_WRITE): - raise + raise SSLWrapper.Error(this.sock or this.sslobj, e) return 0 class NonBlockingTcp(PlugIn, IdleObject): @@ -305,12 +351,10 @@ class NonBlockingTcp(PlugIn, IdleObject): self.remove_timeout() self._owner.disconnected() self.idlequeue.unplug_idle(self.fd) - try: - self._sock.shutdown(socket.SHUT_RDWR) - self._sock.close() - except: - traceback.print_exc() - # socket is already closed + try: self._sock.shutdown(socket.SHUT_RDWR) + except: traceback.print_exc() + try: self._sock.close() + except: traceback.print_exc() # socket descriptor cannot be (un)plugged anymore self.fd = -1 if self.on_disconnect: @@ -374,9 +418,11 @@ class NonBlockingTcp(PlugIn, IdleObject): traceback.print_stack() errnum = ERR_OTHER errtxt = repr("socket.sslerror: " + e.args) - except SSLWrapper.Error: - errnum = ERR_OTHER - errtxt = repr(e.args) + except SSLWrapper.Error, e: + print "caught " + str(e) + errnum = gattr(e, 'errno', ERR_OTHER) + if errnum == 0: errnum = ERR_OTHER # unset, but we must put a status + errtxt = gattr(e, 'strerror') or repr(e.args) # Should we really do this? In C, recv() will happily return 0 # in nonblocking mode when there is no data waiting, and in @@ -400,7 +446,7 @@ class NonBlockingTcp(PlugIn, IdleObject): self.DEBUG(errtxt, 'error') log.error("Error: " + errtxt) if self.state >= 0: - self.disconnect() + self.pollend() return received = '' @@ -682,7 +728,7 @@ class NonBlockingTLS(PlugIn): tcpsock._sock.setblocking(False) tcpsock._sslIssuer = tcpsock._sslObj.issuer() tcpsock._sslServer = tcpsock._sslObj.server() - wrapper = StdlibSSLWrapper(tcpsock._sslObj) + wrapper = StdlibSSLWrapper(tcpsock._sslObj, tcpsock._sock) tcpsock._recv = wrapper.recv tcpsock._send = wrapper.send self.starttls='success' From 236ed0463a566f41f7deb4491944b87fdd302df9 Mon Sep 17 00:00:00 2001 From: junglecow Date: Tue, 28 Nov 2006 22:12:03 +0000 Subject: [PATCH 08/13] [pyopenssl] More exception fixes --- src/common/xmpp/transports_nb.py | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/src/common/xmpp/transports_nb.py b/src/common/xmpp/transports_nb.py index d5865db6e..5d416efcc 100644 --- a/src/common/xmpp/transports_nb.py +++ b/src/common/xmpp/transports_nb.py @@ -81,10 +81,10 @@ class SSLWrapper: this.exc = exc - this.errno = errno or gattr(this.exc, 'errno', 0) - this.strerror = strerror or gattr(this.exc, 'strerror') or gattr(this.exc, 'args') + errno = errno or gattr(this.exc, 'errno', 0) + strerror = strerror or gattr(this.exc, 'strerror') or gattr(this.exc, 'args') - this.parent.__init__(this, errno, strerror) + this.parent.__init__(this, this.errno, this.strerror) this.peer = peer this.exc_name = None @@ -111,7 +111,7 @@ class SSLWrapper: s += ", Caused by %s" % this.exc_name if this.exc_str: if this.strerror: s += "(%s)" % this.exc_str - else: s += "(%s)" % this.exc_args + else: s += "(%s)" % str(this.exc_args) return s def __init__(this, sslobj, sock=None): @@ -177,7 +177,7 @@ class PyOpenSSLWrapper(SSLWrapper): log.debug("Send: " + repr(e)) time.sleep(0.1) # prevent 100% CPU usage except OpenSSL.SSL.SysCallError, e: - log.error("Recv: Got OpenSSL.SSL.SysCallError: " + repr(e)) + log.error("Send: Got OpenSSL.SSL.SysCallError: " + repr(e)) traceback.print_exc() raise SSLWrapper.Error(this.sock or this.sslobj, e) except OpenSSL.SSL.Error, e: From 4a58bc4797fcdc16fd5376b53854cd5223ddacb8 Mon Sep 17 00:00:00 2001 From: junglecow Date: Fri, 1 Dec 2006 22:23:45 +0000 Subject: [PATCH 09/13] [pyopenssl] Yet more exception fixes --- src/common/xmpp/transports_nb.py | 19 ++++++++++++------- 1 file changed, 12 insertions(+), 7 deletions(-) diff --git a/src/common/xmpp/transports_nb.py b/src/common/xmpp/transports_nb.py index 5d416efcc..a3af68b9a 100644 --- a/src/common/xmpp/transports_nb.py +++ b/src/common/xmpp/transports_nb.py @@ -79,14 +79,19 @@ class SSLWrapper: def __init__(this, sock=None, exc=None, errno=None, strerror=None, peer=None): this.parent = IOError + errno = errno or gattr(exc, 'errno', 0) + strerror = strerror or gattr(exc, 'strerror') or gattr(exc, 'args') + if not isinstance(strerror, basestring): strerror = repr(strerror) + + this.parent.__init__(this, errno, strerror) + + this.sock = sock this.exc = exc - - errno = errno or gattr(this.exc, 'errno', 0) - strerror = strerror or gattr(this.exc, 'strerror') or gattr(this.exc, 'args') - - this.parent.__init__(this, this.errno, this.strerror) this.peer = peer this.exc_name = None + this.exc_args = None + this.exc_str = None + this.exc_repr = None if this.exc is not None: this.exc_name = str(this.exc.__class__) @@ -96,7 +101,7 @@ class SSLWrapper: if this.peer is None and sock is not None: try: - ppeer = this.obj.getpeername() + ppeer = this.sock.getpeername() if len(ppeer) == 2 and isinstance(ppeer[0], basestring) \ and isinstance(ppeer[1], int): this.peer = ppeer @@ -104,7 +109,7 @@ class SSLWrapper: def __str__(this): s = str(this.__class__) - if this.peer: s += "for %s:%d" % this.peer + if this.peer: s += " for %s:%d" % this.peer if this.errno is not None: s += ": [Errno: %d]" % this.errno if this.strerror: s += " (%s)" % this.strerror if this.exc_name: From 7c0696093a0555a7b4d7931a26ecb5659049fc45 Mon Sep 17 00:00:00 2001 From: junglecow Date: Fri, 8 Dec 2006 21:19:01 +0000 Subject: [PATCH 10/13] - Trying to connect to server every 20 seconds forever is extremely rude to its owner. Let's be polite and do exponential back-off. (See #2411) - [PyOpenSSL] Ported [7443] to pyopenssl branch. --- src/common/xmpp/client_nb.py | 2 ++ src/common/xmpp/transports_nb.py | 10 +++++----- 2 files changed, 7 insertions(+), 5 deletions(-) diff --git a/src/common/xmpp/client_nb.py b/src/common/xmpp/client_nb.py index 7db5a1eeb..111416bb3 100644 --- a/src/common/xmpp/client_nb.py +++ b/src/common/xmpp/client_nb.py @@ -123,6 +123,8 @@ class NBCommonClient(CommonClient): self.on_connect_failure(retry) def _on_connected(self): + # connect succeeded, so no need of this callback anymore + self.on_connect_failure = None self.connected = 'tcp' if self._Ssl: transports_nb.NonBlockingTLS().PlugIn(self, now=1) diff --git a/src/common/xmpp/transports_nb.py b/src/common/xmpp/transports_nb.py index a3af68b9a..7da9bb6c9 100644 --- a/src/common/xmpp/transports_nb.py +++ b/src/common/xmpp/transports_nb.py @@ -342,11 +342,11 @@ class NonBlockingTcp(PlugIn, IdleObject): def pollin(self): self._do_receive() - def pollend(self): + def pollend(self, retry=False): conn_failure_cb = self.on_connect_failure self.disconnect() if conn_failure_cb: - conn_failure_cb() + conn_failure_cb(retry) def disconnect(self): if self.state == -2: # already disconnected @@ -442,8 +442,8 @@ class NonBlockingTcp(PlugIn, IdleObject): if errnum in (ERR_DISCONN, errno.ECONNRESET, errno.ENOTCONN, errno.ESHUTDOWN): self.DEBUG(errtxt, 'error') log.error("Got Disconnected: " + errtxt) - self.pollend() - # don't proccess result, cas it will raise error + self.pollend(retry=(errnum in (ERR_DISCONN, errno.ECONNRESET))) + # don't process result, because it will raise an error return if received is None: @@ -451,7 +451,7 @@ class NonBlockingTcp(PlugIn, IdleObject): self.DEBUG(errtxt, 'error') log.error("Error: " + errtxt) if self.state >= 0: - self.pollend() + self.pollend(retry=True) return received = '' From c09e6e0b93cfaaa81b4a56da3172d19e9de27f73 Mon Sep 17 00:00:00 2001 From: junglecow Date: Wed, 13 Dec 2006 20:15:22 +0000 Subject: [PATCH 11/13] [PyOpenSSL] - Improved data extraction from exceptions - Clearer error messages - Reduced exception spam --- src/common/xmpp/transports_nb.py | 36 ++++++++++++++++++++++++-------- 1 file changed, 27 insertions(+), 9 deletions(-) diff --git a/src/common/xmpp/transports_nb.py b/src/common/xmpp/transports_nb.py index 7da9bb6c9..221491335 100644 --- a/src/common/xmpp/transports_nb.py +++ b/src/common/xmpp/transports_nb.py @@ -79,12 +79,10 @@ class SSLWrapper: def __init__(this, sock=None, exc=None, errno=None, strerror=None, peer=None): this.parent = IOError - errno = errno or gattr(exc, 'errno', 0) + errno = errno or gattr(exc, 'errno') strerror = strerror or gattr(exc, 'strerror') or gattr(exc, 'args') if not isinstance(strerror, basestring): strerror = repr(strerror) - this.parent.__init__(this, errno, strerror) - this.sock = sock this.exc = exc this.peer = peer @@ -98,6 +96,15 @@ class SSLWrapper: this.exc_args = gattr(this.exc, 'args') this.exc_str = str(this.exc) this.exc_repr = repr(this.exc) + if not errno: + try: + if isinstance(exc, OpenSSL.SSL.SysCallError): + if this.exc_args[0] > 0: + errno = this.exc_args[0] + strerror = this.exc_args[1] + except: traceback.print_exc() # FIXME: pass + + this.parent.__init__(this, errno, strerror) if this.peer is None and sock is not None: try: @@ -356,8 +363,11 @@ class NonBlockingTcp(PlugIn, IdleObject): self.remove_timeout() self._owner.disconnected() self.idlequeue.unplug_idle(self.fd) - try: self._sock.shutdown(socket.SHUT_RDWR) - except: traceback.print_exc() + try: + self._sock.shutdown(socket.SHUT_RDWR) + except socket.error, e: + if e[0] != errno.ENOTCONN: + traceback.print_exc() try: self._sock.close() except: traceback.print_exc() # socket descriptor cannot be (un)plugged anymore @@ -441,7 +451,7 @@ class NonBlockingTcp(PlugIn, IdleObject): if errnum in (ERR_DISCONN, errno.ECONNRESET, errno.ENOTCONN, errno.ESHUTDOWN): self.DEBUG(errtxt, 'error') - log.error("Got Disconnected: " + errtxt) + log.error("Connection to %s lost: %s [%d]", self.getName(), errtxt, errnum) self.pollend(retry=(errnum in (ERR_DISCONN, errno.ECONNRESET))) # don't process result, because it will raise an error return @@ -449,7 +459,7 @@ class NonBlockingTcp(PlugIn, IdleObject): if received is None: if errnum != 0: self.DEBUG(errtxt, 'error') - log.error("Error: " + errtxt) + log.error("Connection to %s lost: %s [%d]", self.getName(), errtxt, errnum) if self.state >= 0: self.pollend(retry=True) return @@ -513,8 +523,9 @@ class NonBlockingTcp(PlugIn, IdleObject): try: self._sock.connect(self._server) except socket.error, e: - traceback.print_exc() errnum = e[0] + if errnum != errno.EINPROGRESS: + traceback.print_exc() # in progress, or would block if errnum in (errno.EINPROGRESS, errno.EALREADY, errno.EWOULDBLOCK): return @@ -580,7 +591,14 @@ class NonBlockingTcp(PlugIn, IdleObject): def getHost(self): ''' Return the 'host' value that is connection is [will be] made to.''' return self._server[0] - + + def getName(self): + ''' Return the server's name, or 'getHost()' if not available.''' + retval = None + if self._owner: retval = gattr(self._owner, 'name') + if retval: return retval + return self.getHost() + def getPort(self): ''' Return the 'port' value that is connection is [will be] made to.''' return self._server[1] From 8c78a14c3c8abc00f1d4a6ef4179966e90bea2bb Mon Sep 17 00:00:00 2001 From: junglecow Date: Fri, 15 Dec 2006 10:57:25 +0000 Subject: [PATCH 12/13] - In [7647], reading of PID file was moved out of try..except block. Fixed. - [PyOpenSSL] Small fix to error handling. --- src/common/xmpp/transports_nb.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/common/xmpp/transports_nb.py b/src/common/xmpp/transports_nb.py index 221491335..109c4eae2 100644 --- a/src/common/xmpp/transports_nb.py +++ b/src/common/xmpp/transports_nb.py @@ -436,7 +436,7 @@ class NonBlockingTcp(PlugIn, IdleObject): except SSLWrapper.Error, e: print "caught " + str(e) errnum = gattr(e, 'errno', ERR_OTHER) - if errnum == 0: errnum = ERR_OTHER # unset, but we must put a status + if not errnum: errnum = ERR_OTHER # unset, but we must put a status errtxt = gattr(e, 'strerror') or repr(e.args) # Should we really do this? In C, recv() will happily return 0 @@ -595,7 +595,7 @@ class NonBlockingTcp(PlugIn, IdleObject): def getName(self): ''' Return the server's name, or 'getHost()' if not available.''' retval = None - if self._owner: retval = gattr(self._owner, 'name') + retval = gattr(self._owner, 'name') if retval: return retval return self.getHost() From fddb000a89d637958138803b2610a893a9fcb1db Mon Sep 17 00:00:00 2001 From: junglecow Date: Wed, 20 Dec 2006 20:40:08 +0000 Subject: [PATCH 13/13] =?UTF-8?q?[Trunk]=20=20-=20In=20verbose=20mode,=20p?= =?UTF-8?q?rint=20encodings.=20(Especially=20for=20Windows=20users=20who?= =?UTF-8?q?=20don't=20have=20Python)=20(gajim.py)=20=20-=20Attempt=20at=20?= =?UTF-8?q?fixing=20traceback=20when=20getting=20user's=20home=20directory?= =?UTF-8?q?=20in=20Windows.=20See=20#2812.=20(c/configpaths.py)=20=20-=20S?= =?UTF-8?q?how=20'error'=20icon=20next=20to=20account=20while=20waiting=20?= =?UTF-8?q?for=20reconnect.=20Fixes=20#2786.=20(c/connection=5Fhandlers.py?= =?UTF-8?q?,=20c/gajim.py,=20c/connection.py)=20[PyOpenSSL]=20=20-=20Fix?= =?UTF-8?q?=20100%=20CPU=20usage=20and=20hanging=20connection=20when=20ser?= =?UTF-8?q?ver=20closes=20connection=20on=20us.=20(c/x/transports=5Fnb.py)?= =?UTF-8?q?=20=20-=20Fix=20'hanging'=20connection=20when=20server=20closes?= =?UTF-8?q?=20the=20connection=20on=20us=20before=20we=20can=20open=20the?= =?UTF-8?q?=20XML=20stream.=20(Disconnect=20handler=20didn't=20get=20calle?= =?UTF-8?q?d.)=20(c/x/client=5Fnb.py)=20=20-=20Change=20prints=20to=20logg?= =?UTF-8?q?er=20calls,=20various=20enhancements=20to=20debug=20printing,?= =?UTF-8?q?=20reduce=20spam=20(c/x/transports=5Fnb.py)=20=20-=20this=20?= =?UTF-8?q?=E2=86=92=20self=20(c/x/transports=5Fnb.py)=20=20-=20Call=20=5F?= =?UTF-8?q?do=5Freceive()=20once=20to=20collect=20error=20message=20from?= =?UTF-8?q?=20socket,=20when=20error=20flag=20is=20raised=20in=20scheduler?= =?UTF-8?q?.=20(c/x/transports=5Fnb.py)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- src/common/xmpp/client_nb.py | 8 +- src/common/xmpp/transports_nb.py | 346 ++++++++++++++++--------------- 2 files changed, 183 insertions(+), 171 deletions(-) diff --git a/src/common/xmpp/client_nb.py b/src/common/xmpp/client_nb.py index 111416bb3..314f0a232 100644 --- a/src/common/xmpp/client_nb.py +++ b/src/common/xmpp/client_nb.py @@ -123,8 +123,12 @@ class NBCommonClient(CommonClient): self.on_connect_failure(retry) def _on_connected(self): - # connect succeeded, so no need of this callback anymore - self.on_connect_failure = None + # FIXME: why was this needed? Please note that we're working + # in nonblocking mode, and this handler is actually called + # as soon as connection is initiated, NOT when connection + # succeeds, as the name suggests. + # # connect succeeded, so no need of this callback anymore + # self.on_connect_failure = None self.connected = 'tcp' if self._Ssl: transports_nb.NonBlockingTLS().PlugIn(self, now=1) diff --git a/src/common/xmpp/transports_nb.py b/src/common/xmpp/transports_nb.py index 109c4eae2..08e2325f6 100644 --- a/src/common/xmpp/transports_nb.py +++ b/src/common/xmpp/transports_nb.py @@ -46,12 +46,12 @@ try: import OpenSSL.SSL import OpenSSL.crypto USE_PYOPENSSL = True - print "PyOpenSSL loaded." + log.info("PyOpenSSL loaded") except ImportError: # FIXME: Remove these prints before release, replace with a warning dialog. - print "=" * 79 - print "PyOpenSSL not found, falling back to Python builtin SSL objects (insecure)." - print "=" * 79 + print >> sys.stderr, "=" * 79 + print >> sys.stderr, "PyOpenSSL not found, falling back to Python builtin SSL objects (insecure)." + print >> sys.stderr, "=" * 79 # timeout to connect to the server socket, it doesn't include auth CONNECT_TIMEOUT_SECONDS = 30 @@ -76,169 +76,162 @@ def gattr(obj, attr, default=None): class SSLWrapper: class Error(IOError): - def __init__(this, sock=None, exc=None, errno=None, strerror=None, peer=None): - this.parent = IOError + def __init__(self, sock=None, exc=None, errno=None, strerror=None, peer=None): + self.parent = IOError errno = errno or gattr(exc, 'errno') strerror = strerror or gattr(exc, 'strerror') or gattr(exc, 'args') if not isinstance(strerror, basestring): strerror = repr(strerror) - this.sock = sock - this.exc = exc - this.peer = peer - this.exc_name = None - this.exc_args = None - this.exc_str = None - this.exc_repr = None + self.sock = sock + self.exc = exc + self.peer = peer + self.exc_name = None + self.exc_args = None + self.exc_str = None + self.exc_repr = None - if this.exc is not None: - this.exc_name = str(this.exc.__class__) - this.exc_args = gattr(this.exc, 'args') - this.exc_str = str(this.exc) - this.exc_repr = repr(this.exc) + if self.exc is not None: + self.exc_name = str(self.exc.__class__) + self.exc_args = gattr(self.exc, 'args') + self.exc_str = str(self.exc) + self.exc_repr = repr(self.exc) if not errno: try: if isinstance(exc, OpenSSL.SSL.SysCallError): - if this.exc_args[0] > 0: - errno = this.exc_args[0] - strerror = this.exc_args[1] - except: traceback.print_exc() # FIXME: pass + if self.exc_args[0] > 0: + errno = self.exc_args[0] + strerror = self.exc_args[1] + except: pass - this.parent.__init__(this, errno, strerror) + self.parent.__init__(self, errno, strerror) - if this.peer is None and sock is not None: + if self.peer is None and sock is not None: try: - ppeer = this.sock.getpeername() + ppeer = self.sock.getpeername() if len(ppeer) == 2 and isinstance(ppeer[0], basestring) \ and isinstance(ppeer[1], int): - this.peer = ppeer + self.peer = ppeer except: pass - def __str__(this): - s = str(this.__class__) - if this.peer: s += " for %s:%d" % this.peer - if this.errno is not None: s += ": [Errno: %d]" % this.errno - if this.strerror: s += " (%s)" % this.strerror - if this.exc_name: - s += ", Caused by %s" % this.exc_name - if this.exc_str: - if this.strerror: s += "(%s)" % this.exc_str - else: s += "(%s)" % str(this.exc_args) + def __str__(self): + s = str(self.__class__) + if self.peer: s += " for %s:%d" % self.peer + if self.errno is not None: s += ": [Errno: %d]" % self.errno + if self.strerror: s += " (%s)" % self.strerror + if self.exc_name: + s += ", Caused by %s" % self.exc_name + if self.exc_str: + if self.strerror: s += "(%s)" % self.exc_str + else: s += "(%s)" % str(self.exc_args) return s - def __init__(this, sslobj, sock=None): - this.sslobj = sslobj - this.sock = sock - print "init called with", sslobj + def __init__(self, sslobj, sock=None): + self.sslobj = sslobj + self.sock = sock + log.debug("%s.__init__ called with %s", self.__class__, sslobj) - # We can return None out of this function to signal that no data is - # available right now. Better than an exception, which differs - # depending on which SSL lib we're using. Unfortunately returning '' - # can indicate that the socket has been closed, so to be sure, we avoid - # this. + def recv(self, data, flags=None): + """ Receive wrapper for SSL object + + We can return None out of this function to signal that no data is + available right now. Better than an exception, which differs + depending on which SSL lib we're using. Unfortunately returning '' + can indicate that the socket has been closed, so to be sure, we avoid + this by returning None. """ - def recv(this, data, flags=None): raise NotImplementedException() - def send(this, data, flags=None): + def send(self, data, flags=None): raise NotImplementedException() class PyOpenSSLWrapper(SSLWrapper): '''Wrapper class for PyOpenSSL's recv() and send() methods''' - def __init__(this, *args): - this.parent = SSLWrapper - this.parent.__init__(this, *args) + def __init__(self, *args): + self.parent = SSLWrapper + self.parent.__init__(self, *args) - def is_numtoolarge(this, e): + def is_numtoolarge(self, e): t = ('asn1 encoding routines', 'a2d_ASN1_OBJECT', 'first num too large') return isinstance(e.args, (list, tuple)) and len(e.args) == 1 and \ isinstance(e.args[0], (list, tuple)) and len(e.args[0]) == 2 and \ e.args[0][0] == e.args[0][1] == t - def recv(this, bufsize, flags=None): + def recv(self, bufsize, flags=None): retval = None try: - #print "recv: thread id:", thread.get_ident() - if flags is None: retval = this.sslobj.recv(bufsize) - else: retval = this.sslobj.recv(bufsize, flags) + if flags is None: retval = self.sslobj.recv(bufsize) + else: retval = self.sslobj.recv(bufsize, flags) except (OpenSSL.SSL.WantReadError, OpenSSL.SSL.WantWriteError), e: - log.debug("Recv: " + repr(e)) + pass + # log.debug("Recv: " + repr(e)) except OpenSSL.SSL.SysCallError, e: - log.error("Recv: Got OpenSSL.SSL.SysCallError: " + repr(e)) - traceback.print_exc() - raise SSLWrapper.Error(this.sock or this.sslobj, e) + log.error("Recv: Got OpenSSL.SSL.SysCallError: " + repr(e), exc_info=True) + #traceback.print_exc() + raise SSLWrapper.Error(self.sock or self.sslobj, e) except OpenSSL.SSL.Error, e: - if this.is_numtoolarge(e): + if self.is_numtoolarge(e): # warn, but ignore this exception log.warning("Recv: OpenSSL: asn1enc: first num too large (ignored)") else: - log.warning("Recv: Caught OpenSSL.SSL.Error:") - traceback.print_exc() - print "Current Stack:" - traceback.print_stack() - raise SSLWrapper.Error(this.sock or this.sslobj, e) + log.error("Recv: Caught OpenSSL.SSL.Error:", exc_info=True) + #traceback.print_exc() + #print "Current Stack:" + #traceback.print_stack() + raise SSLWrapper.Error(self.sock or self.sslobj, e) return retval - def send(this, data, flags=None): + def send(self, data, flags=None): try: - #print "send: thread id:", thread.get_ident() - if flags is None: return this.sslobj.send(data) - else: return this.sslobj.send(data, flags) + if flags is None: return self.sslobj.send(data) + else: return self.sslobj.send(data, flags) except (OpenSSL.SSL.WantReadError, OpenSSL.SSL.WantWriteError), e: - log.debug("Send: " + repr(e)) + #log.debug("Send: " + repr(e)) time.sleep(0.1) # prevent 100% CPU usage except OpenSSL.SSL.SysCallError, e: - log.error("Send: Got OpenSSL.SSL.SysCallError: " + repr(e)) - traceback.print_exc() - raise SSLWrapper.Error(this.sock or this.sslobj, e) + log.error("Send: Got OpenSSL.SSL.SysCallError: " + repr(e), exc_info=True) + #traceback.print_exc() + raise SSLWrapper.Error(self.sock or self.sslobj, e) except OpenSSL.SSL.Error, e: - if this.is_numtoolarge(e): + if self.is_numtoolarge(e): # warn, but ignore this exception log.warning("Send: OpenSSL: asn1enc: first num too large (ignored)") else: - log.warning("Send: Caught OpenSSL.SSL.Error:") - traceback.print_exc() - print "Current Stack:" - traceback.print_stack() - raise SSLWrapper.Error(this.sock or this.sslobj, e) + log.error("Send: Caught OpenSSL.SSL.Error:", exc_info=True) + #traceback.print_exc() + #print "Current Stack:" + #traceback.print_stack() + raise SSLWrapper.Error(self.sock or self.sslobj, e) return 0 class StdlibSSLWrapper(SSLWrapper): '''Wrapper class for Python's socket.ssl read() and write() methods''' - def __init__(this, *args): - this.parent = SSLWrapper - this.parent.__init__(this, *args) + def __init__(self, *args): + self.parent = SSLWrapper + self.parent.__init__(self, *args) - def recv(this, bufsize, flags=None): - # we simply ignore flags since ssl object doesn't support it - retval = None - try: - retval = this.sslobj.read(bufsize) - except socket.sslerror, e: - print "Got socket.sslerror" - print e, e.args - traceback.print_exc() - print "Current Stack:" - traceback.print_stack() - if e.args[0] not in (socket.SSL_ERROR_WANT_READ, socket.SSL_ERROR_WANT_WRITE): - raise SSLWrapper.Error(this.sock or this.sslobj, e) - - return retval - - def send(this, data, flags=None): + def recv(self, bufsize, flags=None): # we simply ignore flags since ssl object doesn't support it try: - return this.sslobj.write(data) + return self.sslobj.read(bufsize) except socket.sslerror, e: - print "Got socket.sslerror" - print e, e.args - traceback.print_exc() - print "Current Stack:" - traceback.print_stack() + log.debug("Recv: Caught socket.sslerror:", exc_info=True) + #traceback.print_exc() if e.args[0] not in (socket.SSL_ERROR_WANT_READ, socket.SSL_ERROR_WANT_WRITE): - raise SSLWrapper.Error(this.sock or this.sslobj, e) + raise SSLWrapper.Error(self.sock or self.sslobj, e) + return None + + def send(self, data, flags=None): + # we simply ignore flags since ssl object doesn't support it + try: + return self.sslobj.write(data) + except socket.sslerror, e: + log.debug("Send: Caught socket.sslerror:", exc_info=True) + #traceback.print_exc() + if e.args[0] not in (socket.SSL_ERROR_WANT_READ, socket.SSL_ERROR_WANT_WRITE): + raise SSLWrapper.Error(self.sock or self.sslobj, e) return 0 class NonBlockingTcp(PlugIn, IdleObject): @@ -259,6 +252,7 @@ class NonBlockingTcp(PlugIn, IdleObject): self.on_connect_failure = on_connect_failure self.on_receive = None self.on_disconnect = None + self.printed_error = False # 0 - not connected # 1 - connected @@ -288,6 +282,7 @@ class NonBlockingTcp(PlugIn, IdleObject): Also registers self.disconnected method in the owner's dispatcher. Called internally. ''' self.idlequeue = owner.idlequeue + self.printed_error = False if not self._server: self._server=(self._owner.Server,5222) if self.connect(self._server) is False: @@ -310,12 +305,14 @@ class NonBlockingTcp(PlugIn, IdleObject): server=self._server else: self._server = server + self.printed_error = False self.state = 0 try: self._sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM) self._sock.setblocking(False) except: - traceback.print_exc() + log.error("Exception trying to connect to %s:", self.getName(), exc_info=True) + #traceback.print_exc() if self.on_connect_failure: self.on_connect_failure() return False @@ -350,6 +347,10 @@ class NonBlockingTcp(PlugIn, IdleObject): self._do_receive() def pollend(self, retry=False): + if not self.printed_error: + self.printed_error = True + try: self._do_receive(errors_only=True) + except: log.error("pollend: Got exception from _do_receive:", exc_info=True) conn_failure_cb = self.on_connect_failure self.disconnect() if conn_failure_cb: @@ -367,9 +368,9 @@ class NonBlockingTcp(PlugIn, IdleObject): self._sock.shutdown(socket.SHUT_RDWR) except socket.error, e: if e[0] != errno.ENOTCONN: - traceback.print_exc() + log.error("Error shutting down socket for %s:", self.getName(), exc_info=True) try: self._sock.close() - except: traceback.print_exc() + except: log.error("Error closing socket for %s:", self.getName(), exc_info=True) # socket descriptor cannot be (un)plugged anymore self.fd = -1 if self.on_disconnect: @@ -409,7 +410,7 @@ class NonBlockingTcp(PlugIn, IdleObject): if not recv_handler(None) and _tmp == self.on_receive: self.on_receive = recv_handler - def _do_receive(self): + def _do_receive(self, errors_only=False): ''' Reads all pending incoming data. Calls owner's disconnected() method if appropriate.''' ERR_DISCONN = -2 # Misc error signifying that we got disconnected ERR_OTHER = -1 # Other error @@ -420,39 +421,35 @@ class NonBlockingTcp(PlugIn, IdleObject): # get as many bites, as possible, but not more than RECV_BUFSIZE received = self._recv(RECV_BUFSIZE) except (socket.error, socket.herror, socket.gaierror), e: - print "Got socket exception" - traceback.print_exc() - print "Current Stack:" - traceback.print_stack() + log.error("_do_receive: got %s:", e.__class__, exc_info=True) + #traceback.print_exc() + #print "Current Stack:" + #traceback.print_stack() errnum = e[0] errtxt = str(errnum) + ':' + e[1] except socket.sslerror, e: - print "Got unknown socket.sslerror" - traceback.print_exc() - print "Current Stack:" - traceback.print_stack() + log.error("_do_receive: got unknown %s:", e.__class__, exc_info=True) + #traceback.print_exc() + #print "Current Stack:" + #traceback.print_stack() errnum = ERR_OTHER errtxt = repr("socket.sslerror: " + e.args) except SSLWrapper.Error, e: - print "caught " + str(e) + log.debug("Caught: %s", str(e)) errnum = gattr(e, 'errno', ERR_OTHER) if not errnum: errnum = ERR_OTHER # unset, but we must put a status errtxt = gattr(e, 'strerror') or repr(e.args) - # Should we really do this? In C, recv() will happily return 0 - # in nonblocking mode when there is no data waiting, and in - # some cases select() will mark the socket for reading when - # there is nothing to read, and the socket is still open. For - # example, this can happen when the remote sends a zero-length - # tcp packet. - if received is '': + if received == '': errnum = ERR_DISCONN errtxt = "Connection closed unexpectedly" if errnum in (ERR_DISCONN, errno.ECONNRESET, errno.ENOTCONN, errno.ESHUTDOWN): self.DEBUG(errtxt, 'error') log.error("Connection to %s lost: %s [%d]", self.getName(), errtxt, errnum) - self.pollend(retry=(errnum in (ERR_DISCONN, errno.ECONNRESET))) + self.printed_error = True + if not errors_only: + self.pollend(retry=(errnum in (ERR_DISCONN, errno.ECONNRESET))) # don't process result, because it will raise an error return @@ -460,12 +457,13 @@ class NonBlockingTcp(PlugIn, IdleObject): if errnum != 0: self.DEBUG(errtxt, 'error') log.error("Connection to %s lost: %s [%d]", self.getName(), errtxt, errnum) - if self.state >= 0: + self.printed_error = True + if not errors_only and self.state >= 0: self.pollend(retry=True) return received = '' - if self.state < 0: + if errors_only or self.state < 0: return # we have received some bites, stop the timeout! @@ -504,9 +502,10 @@ class NonBlockingTcp(PlugIn, IdleObject): self._plug_idle() self._on_send() except socket.error, e: - traceback.print_exc() if e[0] == socket.SSL_ERROR_WANT_WRITE: return True + log.error("_do_send:", exc_info=True) + #traceback.print_exc() if self.state < 0: self.disconnect() return @@ -519,13 +518,16 @@ class NonBlockingTcp(PlugIn, IdleObject): if self.state != 0: return self._sock.setblocking(False) + self._send = self._sock.send + self._recv = self._sock.recv errnum = 0 try: self._sock.connect(self._server) except socket.error, e: errnum = e[0] if errnum != errno.EINPROGRESS: - traceback.print_exc() + log.error("_do_connect:", exc_info=True) + #traceback.print_exc() # in progress, or would block if errnum in (errno.EINPROGRESS, errno.EALREADY, errno.EWOULDBLOCK): return @@ -541,8 +543,6 @@ class NonBlockingTcp(PlugIn, IdleObject): self.state = 1 self._sock.setblocking(False) - self._send = self._sock.send - self._recv = self._sock.recv self._plug_idle() if self.on_connect: self.on_connect() @@ -627,7 +627,8 @@ class NonBlockingTLS(PlugIn): try: res = self._startSSL() except Exception, e: - traceback.print_exc() + log.error("PlugIn: while trying _startSSL():", exc_info=True) + #traceback.print_exc() self._owner.socket.pollend() return self.tls_start() @@ -669,37 +670,39 @@ class NonBlockingTLS(PlugIn): self.tls_start() raise NodeProcessed - def _dumpX509(this, cert): - print "Digest (SHA-1):", cert.digest("sha1") - print "Digest (MD5):", cert.digest("md5") - print "Serial #:", cert.get_serial_number() - print "Version:", cert.get_version() - print "Expired:", torf(cert.has_expired(), "Yes", "No") - print "Subject:" - this._dumpX509Name(cert.get_subject()) - print "Issuer:" - this._dumpX509Name(cert.get_issuer()) - this._dumpPKey(cert.get_pubkey()) + def _dumpX509(self, cert, stream=sys.stderr): + print >> stream, "Digest (SHA-1):", cert.digest("sha1") + print >> stream, "Digest (MD5):", cert.digest("md5") + print >> stream, "Serial #:", cert.get_serial_number() + print >> stream, "Version:", cert.get_version() + print >> stream, "Expired:", torf(cert.has_expired(), "Yes", "No") + print >> stream, "Subject:" + self._dumpX509Name(cert.get_subject(), stream) + print >> stream, "Issuer:" + self._dumpX509Name(cert.get_issuer(), stream) + self._dumpPKey(cert.get_pubkey(), stream) - def _dumpX509Name(this, name): - print "X509Name:", str(name) + def _dumpX509Name(self, name, stream=sys.stderr): + print >> stream, "X509Name:", str(name) - def _dumpPKey(this, pkey): + def _dumpPKey(self, pkey, stream=sys.stderr): typedict = {OpenSSL.crypto.TYPE_RSA: "RSA", OpenSSL.crypto.TYPE_DSA: "DSA"} - print "PKey bits:", pkey.bits() - print "PKey type: %s (%d)" % (typedict.get(pkey.type(), "Unknown"), pkey.type()) + print >> stream, "PKey bits:", pkey.bits() + print >> stream, "PKey type: %s (%d)" % (typedict.get(pkey.type(), "Unknown"), pkey.type()) def _startSSL(self): ''' Immidiatedly switch socket to TLS mode. Used internally.''' - print "_startSSL called" + log.debug("_startSSL called") if USE_PYOPENSSL: return self._startSSL_pyOpenSSL() return self._startSSL_stdlib() def _startSSL_pyOpenSSL(self): - print "_startSSL_pyOpenSSL called, thread id:", thread.get_ident() + #log.debug("_startSSL_pyOpenSSL called, thread id: %s", str(thread.get_ident())) + log.debug("_startSSL_pyOpenSSL called") tcpsock = self._owner.Connection # FIXME: should method be configurable? - tcpsock._sslContext = OpenSSL.SSL.Context(OpenSSL.SSL.TLSv1_METHOD) + #tcpsock._sslContext = OpenSSL.SSL.Context(OpenSSL.SSL.TLSv1_METHOD) + tcpsock._sslContext = OpenSSL.SSL.Context(OpenSSL.SSL.SSLv23_METHOD) tcpsock._sslContext.set_info_callback(self._ssl_info_callback) tcpsock._sslObj = OpenSSL.SSL.Connection(tcpsock._sslContext, tcpsock._sock) tcpsock._sslObj.set_connect_state() # set to client mode @@ -708,22 +711,22 @@ class NonBlockingTLS(PlugIn): tcpsock._recv = wrapper.recv tcpsock._send = wrapper.send - print "Initiating handshake..." + log.debug("Initiating handshake...") #tcpsock._sslObj.setblocking(True) try: self.starttls='in progress' tcpsock._sslObj.do_handshake() except (OpenSSL.SSL.WantReadError, OpenSSL.SSL.WantWriteError), e: - log.debug("do_handshake: " + repr(e)) + pass #tcpsock._sslObj.setblocking(False) #print "Done handshake" - print "Async handshake started..." + log.debug("Async handshake started...") # fake it, for now self.starttls='success' def _on_ssl_handshake_done(self): - print "Handshake done!" + log.debug("Handshake done!") #self.starttls='success' tcpsock = self._owner.Connection @@ -737,14 +740,14 @@ class NonBlockingTLS(PlugIn): peercert = tcpsock._sslObj.get_peer_certificate() ciphers = tcpsock._sslObj.get_cipher_list() - print "Ciphers:", ciphers - print "Peer cert:", peercert + print >> sys.stderr, "Ciphers:", ciphers + print >> sys.stderr, "Peer cert:", peercert self._dumpX509(peercert) - print OpenSSL.crypto.dump_certificate(OpenSSL.crypto.FILETYPE_PEM, peercert) + print >> sys.stderr, OpenSSL.crypto.dump_certificate(OpenSSL.crypto.FILETYPE_PEM, peercert) def _startSSL_stdlib(self): - print "_startSSL_stdlib called" + log.debug("_startSSL_stdlib called") tcpsock=self._owner.Connection tcpsock._sock.setblocking(True) tcpsock._sslObj = socket.ssl(tcpsock._sock, None, None) @@ -756,13 +759,16 @@ class NonBlockingTLS(PlugIn): tcpsock._send = wrapper.send self.starttls='success' - def _ssl_info_callback(this, sslconn, type, st): + def _ssl_info_callback(self, sslconn, type, st): # Exceptions can't propagate up through this callback, so print them here. - try: this._ssl_info_callback_guarded(sslconn, type, st) - except: traceback.print_exc() + try: + self._ssl_info_callback_guarded(sslconn, type, st) + except: + log.error("Exception caught in _ssl_info_callback:", exc_info=True) + traceback.print_exc() # Make sure something is printed, even if log is disabled. - def _ssl_info_callback_guarded(this, sslconn, type, st): - b = this.ssl_h_bits + def _ssl_info_callback_guarded(self, sslconn, type, st): + b = self.ssl_h_bits #if type & b['SSL_CB_LOOP']: # if type & SSL_ST_CONNECT: tls_state = "connect" @@ -782,7 +788,7 @@ class NonBlockingTLS(PlugIn): #print "mask:", mask, st if type & b['SSL_CB_HANDSHAKE_DONE']: - this._on_ssl_handshake_done() + self._on_ssl_handshake_done() def StartTLSHandler(self, conn, starttls): ''' Handle server reply if TLS is allowed to process. Behaves accordingly. @@ -797,7 +803,8 @@ class NonBlockingTLS(PlugIn): try: self._startSSL() except Exception, e: - traceback.print_exc() + log.error("StartTLSHandler:", exc_info=True) + #traceback.print_exc() self._owner.socket.pollend() return self._owner.Dispatcher.PlugOut() @@ -856,7 +863,8 @@ class NBHTTPPROXYsocket(NonBlockingTcp): try: proto, code, desc = reply.split('\n')[0].split(' ', 2) except: - traceback.print_exc() + log.error("_on_headers_sent:", exc_info=True) + #traceback.print_exc() raise error('Invalid proxy reply') if code <> '200': self.DEBUG('Invalid proxy reply: %s %s %s' % (proto, code, desc),'error')