[387] in BarnOwl Developers
Re: bug report: barnowl hangs under Ubuntu 6.06 on jabberlogin
daemon@ATHENA.MIT.EDU (Erik Nygren)
Thu Oct 29 18:05:37 2009
Resent-From: nelhage@mit.edu
Resent-To: barnowl-dev-mtg@charon.mit.edu
Date: Sun, 21 Jan 2007 16:29:06 -0500
From: "Erik Nygren" <erik@nygren.org>
To: dirty-owl-hackers@mit.edu
In-Reply-To: <38894e500701151500hf73666bo6d5396e1f1d440d2@mail.gmail.com>
It looks like this is due to the version of libio-socket-ssl-perl.
The Ubuntu 6.06 version is 0.97-2build1 while the version
from CPAN (1.02) seems to work fine.
I haven't tracked down the root cause, but
from the change-log it looks like full non-blocking socket support
wasn't added to IO::Socket::SSL until 0.98.
Erik
On 1/15/07, Erik Nygren <erik@nygren.org> wrote:
> barnowl seems to hang right after pressing return on
> the "jabberlogin nygren@mit.edu" on a machine running
> Ubuntu 6.06 with the appropriate Debian packages installed.
> I haven't yet had much time to debug so I'd thought
> that I'd send a bug report first. This is with the svn head.
> Debian package versions:
>
> ||/ Name Version Description
> +++-============================-============================-========================================================================
> ii libnet-dns-perl 0.53-2 Perform
> DNS queries from a Perl script
> ii libauthen-sasl-perl 2.09-1
> Authen::SASL - SASL Authentication framework
> ii libio-socket-ssl-perl 0.97-2build1 Perl
> module implementing object oriented interface to SSL sockets
> ii libdigest-sha1-perl 2.10-1 NIST
> SHA-1 message digest algorithm
>
> It looks like the hang is right between these lines in jabber.log:
>
> XML::Stream: Send: (<?xml version='1.0'?><stream:stream version='1.0'
> xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client'
> to='mit.edu' from='aurora.meepity.net' xml:lang='en' >)
> XML::Stream: Read: buff(<?xml version='1.0'?><stream:stream
>
> I get similar behavior trying to login to "nygren@gmail.com"
> although there it is just really slow and prompts for a password
> after a minute or so and then gives a "Error in connect:"
> a minute or so after a password is entered.
>
> From jabber.log for the @mit.edu login:
>
> XML::Stream: new: hostname = (aurora.meepity.net)
> XML::Stream: SetCallBacks: tag(node) func(CODE(0x8a6ecbc))
> XMPP::Conn: SetCallBacks: tag(message) func(CODE(0x8a4e43c))
> XMPP::Conn: SetCallBacks: tag(presence) func(CODE(0x8a4e3b8))
> XMPP::Conn: SetCallBacks: tag(iq) func(CODE(0x8a5eb54))
> XMPP::Conn: SetDirectXPathCallBacks:
> xpath(/[@xmlns="urn:ietf:params:xml:ns:xmpp-tls"])
> func(CODE(0x8a6f6c4))
> XMPP::Conn: SetDirectXPathCallBacks:
> xpath(/[@xmlns="urn:ietf:params:xml:ns:xmpp-sasl"])
> func(CODE(0x8a6db34))
> XMPP::Conn: SetXPathCallBacks: xpath(/iq[@type="result" or
> @type="set"]/query[@xmlns="jabber:iq:roster"]) func(CODE(0x8a6dce4))
> XMPP::Conn: SetXPathCallBacks: xpath(/presence) func(CODE(0x8a6dd38))
> XMPP::Conn: Connect: host(JABBER.MIT.EDU:5222) namespace(jabber:client)
> XMPP::Conn: Connect: timeout(10)
> XML::Stream: Connect: type(tcpip)
> XML::Stream: Connect: Got a connection
> XML::Stream: Send: (<?xml version='1.0'?><stream:stream version='1.0'
> xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client'
> to='mit.edu' from='aurora.meepity.net' xml:lang='en' >)
> XML::Stream: Read: buff(<?xml version='1.0'?><stream:stream
> xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client'
> to='aurora.meepity.net' from='mit.edu' version='1.0'
> id='zhkmijuq9d5rb64nh0xsusbein3k3t73asptbjkl'>)
> XML::Stream: Read: buff(<stream:features
> xmlns:stream='http://etherx.jabber.org/streams'><starttls
> xmlns='urn:ietf:params:xml:ns:xmpp-tls'><required/></starttls></stream:features>)
> XMPP::Conn: Connect: connection made
> XML::Stream: SetCallBacks: tag(node) func(CODE(0x8a6f58c))
> XML::Stream: Send: (<starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>)
> XML::Stream: Read: buff(<proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>)
> XML::Stream: TLSClientProceed: Convert normal socket to SSL
> XML::Stream: TLSClientProceed: sock(IO::Socket::INET=GLOB(0x8a6f4b4))
> XML::Stream: LoadSSL: Load the IO::Socket::SSL module
> XML::Stream: LoadSSL: Success
> XML::Stream: TLSClientProceed: ssl_sock(IO::Socket::SSL=GLOB(0x8a6f4b4))
> XML::Stream: TLSClientProceed: SSL: We are secure
> XML::Stream: Send: (<?xml version='1.0'?><stream:stream version='1.0'
> xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client'
> to='mit.edu' from='aurora.meepity.net' xml:lang='en' >)
> XML::Stream: Read: buff(<?xml version='1.0'?><stream:stream
> xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client'
> to='aurora.meepity.net' from='mit.edu' version='1.0'
> id='xqc8whveis6clir36un9ovczn2szlcli2yqzfmdy'><stream:features
> xmlns:stream='http://etherx.jabber.org/streams'><mechanisms
> xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism><mechanism>GSSAPI</mechanism></mechanisms></stream:features>)
> XMPP::Conn: AuthSASL: shiney new auth
> XML::Stream: Send: (<auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl'
> mechanism='PLAIN'>AG55Z3JlbgA=</auth>)
> XMPP::Conn: AuthSASL: haven't authed yet... let's wait.
> XMPP::Conn: Process: timeout(1)
>
>
> Additional for the gmail.com login:
>
> XML::Stream: Read: buff(<?xml version="1.0"
> encoding="UTF-8"?><stream:stream from="gmail.com"
> id="470271ADE7F94187" version="1.0"
> xmlns:stream="http://etherx.jabber.org/streams"
> xmlns="jabber:client"><stream:features><mechanisms
> xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism><mechanism>X-GOOGLE-TOKEN</mechanism></mechanisms></stream:features>)
> XMPP::Conn: AuthSASL: shiney new auth
> XML::Stream: Send: (<auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl'
> mechanism='PLAIN'>[...]</auth>)
> XMPP::Conn: AuthSASL: haven't authed yet... let's wait.
> XMPP::Conn: Process: timeout(1)
> XML::Stream: Read: buff()
> XML::Stream: Read: ERROR
> XML::Stream: Send: (</stream:stream>)
> XML::Stream: SetCallBacks: tag(node) func(CODE(0x8ba1d4c))
> XMPP::Conn: Disconnect: bye bye
>
>
> From the owldebug log:
>
> [6720 - Mon Jan 15 17:38:25 2007 - 14 seconds]: executing command:
> jabberlogin nygren@gmail.com
> [6720 - Mon Jan 15 17:38:25 2007 - 14 seconds]: executing command: getvar debug
> [6720 - Mon Jan 15 17:39:02 2007 - 51 seconds]: About to do gethostbyaddr
> [6720 - Mon Jan 15 17:39:02 2007 - 51 seconds]: owl_log_message: entering
> [6720 - Mon Jan 15 17:39:02 2007 - 51 seconds]: owl_log_message: not
> logging message
> [6720 - Mon Jan 15 17:39:16 2007 - 65 seconds]: executing command:
> editresponse:done
> [6720 - Mon Jan 15 17:39:16 2007 - 65 seconds]: executing command: getvar debug
> [6720 - Mon Jan 15 17:39:37 2007 - 86 seconds]: executing command:
> error Error in connect:
> [6720 - Mon Jan 15 17:39:37 2007 - 86 seconds]: ERROR: Error in connect:
> [6720 - Mon Jan 15 17:39:37 2007 - 86 seconds]: About to do gethostbyaddr
>
> Some appropriate debian packages:
> ii libnet-dns-perl 0.53-2
> Perform DNS queries from a Perl script
>
