789745 - Cannot connect to XMPP servers that don't support SASL authentication

Status: VERIFIED FIXED

(Thunderbird :: Instant Messaging, defect)

Description

[Ryan Foster]

User Agent: Mozilla/5.0 (Windows NT 6.0; rv:15.0) Gecko/20100101 Firefox/15.0.1
Build ID: 20120905151427

Steps to reproduce:

1. Set up a new XMPP account in Thunderbird.
1.a. Use the format username@domain for the username.
1.b. Leave XMPP Options on default settings.
1.c. Uncheck "Connect this account now."
2. Open the "Instant messaging status" window via Tools > Chat Status > Show Accounts... (or any other valid method).
3. Select the desired account.
4. Click the "Connect" button.




Actual results:

The status changes to "Connecting", followed shortly by "Connecting: Initializing stream..." that never seems to time out (left it open for at least 20 minutes).  Nothing is reported in the Error Console.


Expected results:

Thunderbird should connect to the chat account if connection is possible.  If connection is not possible, Thunderbird should produce useful and visible errors to the user to indicate a problem.


I do not have any proxies configured, so this shouldn't be related to bug 741536.  This is not a secure XMPP connection, so it shouldn't be bug 780749 or other related Self-Signed Certificate bugs.  I thought it might be a possible domain name mismatch between the username and the server (this is on shared web hosting), but even when I tried to adjust the settings for that, it would exhibit the same behavior described earlier.

Using the same account settings, I can connect to the account with:
- Digsby - Build 30295
- Psi v0.14
- Pidgin 2.10.6 (libpurple 2.10.6)
- Instantbird version 1.2 (20120806152218)
  - Gecko 14.0.1 (20120806152218)
  - libpurple 2.10.4

Comment 1

[Florian Quèze [:florian]]

Are there any JavaScript errors in the Error Console (from the Tools menu) when the connection gets stuck on "Initializing stream…"?

Comment 2

[Ryan Foster]

The Error Console shows no errors while the connection is stuck on "Initializing stream...".  If I leave it go for a very long time (1 hour or more), I do start to get some errors, but I didn't copy them down.  Something about "this account is null" I think?

I've set it to try to connect again to see if anything happens.  So far, it's behaving the same as described in Comment 0, but nothing has popped up in the Error Console yet.

Comment 3

[Ryan Foster]

I left the connection attempt running for 8+ hours yesterday and couldn't reproduce the error message about the account being null, so perhaps it was an unrelated message.  The only error messages produces during those 8 hours were messages about one of my RSS feeds updating.

Any luck on your end?  Do you need me to do anything?

Comment 4

[Ryan Foster]

Just wanted to check in.  Any leads?  Is there anything I can do to help?

Comment 5

[Florian Quèze [:florian]]

(In reply to Ryan Foster from comment #4)
> Is there anything I can do to help?

You can give us a debug log.
Go to the preference window, in the Advanced Tab open the Config Editor,
set purple.debug.loglevel to 1 to see the raw XMPP being
sent to/from the server in the error console.

Clear the content of the error console, and then attempt to connect the XMPP account.
There should be lots of messages there. If there are too many to copy paste them, you can upload a screenshot somewhere instead.

Comment 6

[Ryan Foster]

Changed the setting and got a debug log as instructed. Scrubbed out the domain name.

Timestamp: 10/1/2012 3:46:52 PM
Warning: Connecting to: domain.com:5222
Source Code:
xmpp-session

Timestamp: 10/1/2012 3:46:52 PM
Warning: onTransportStatus(STATUS_RESOLVING)
Source Code:
xmpp-session

Timestamp: 10/1/2012 3:46:52 PM
Warning: onTransportStatus(STATUS_RESOLVED)
Source Code:
xmpp-session

Timestamp: 10/1/2012 3:46:52 PM
Warning: onTransportStatus(STATUS_CONNECTING_TO)
Source Code:
xmpp-session

Timestamp: 10/1/2012 3:46:52 PM
Warning: onTransportStatus(STATUS_CONNECTED_TO)
Source Code:
xmpp-session

Timestamp: 10/1/2012 3:46:52 PM
Warning: Sending:
<?xml version="1.0"?><stream:stream to="domain.com" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" version="1.0">
Source Code:
xmpp-session

Timestamp: 10/1/2012 3:46:52 PM
Warning: onTransportStatus(STATUS_SENDING_TO)
Source Code:
xmpp-session

Timestamp: 10/1/2012 3:46:53 PM
Warning: onTransportStatus(STATUS_RECEIVING_FROM)
Source Code:
xmpp-session

Timestamp: 10/1/2012 3:46:53 PM
Warning: onStartRequest
Source Code:
xmpp-session

Comment 7

[Florian Quèze [:florian]]

And nothing after that? It's strange, it seems the server accepts the network connection, but doesn't send anything back to us.

Comment 8

[Ryan Foster]

Yeah, that was it.  Is it possible to get debug information for any of the other applications to see why they connect?

Comment 9

[Florian Quèze [:florian]]

With Instantbird 1.2, you can get a debug log with exactly the same steps.

Anyway, your debug log shows that the connection attempt fails before we start encrypting the connection, so you can look at what other clients do at this point with wireshark.

Comment 10

[Ryan Foster]

I've got a log from Instantbird.  Is there any connection/authentication info I should obscure?

What encryption are you referring to?  This account is not setup to use SSL, to my knowledge.

Comment 11

[Florian Quèze [:florian]]

If you are concerned that the log may contain information that should stay private, you can email it to me instead of attaching it here.

Comment 12

[Ryan Foster]

Email sent.

Comment 13

[Florian Quèze [:florian]]

The log that Ryan emailed me and then the connection attempts I made after he gave me the domain name of the server showed that the server doesn't support SASL authentication, and libpurple falls back to the obsolete Non-SASL Authentication (http://xmpp.org/extensions/xep-0078.html).

Comment 14

[Florian Quèze [:florian]]

Attachment: WIP

Changes included in this WIP:
- log the <stream:stream... initial stanza.
- detect that the server doesn't support SASL (no version="1.0" in the stream:stream opening stanza), and send an initial iq get stanza for the legacy auth method.

I will need to have an account on the server to finish the implementation of non-SASL authentication.

Comment 15

[Florian Quèze [:florian]]

Apparently the server affected by this is http://jabberd.org/news/, the last major release of which was in 2006.

Non-SASL authentication has been deprecated in September 2006 and obsoleted in October 2008: http://xmpp.org/extensions/xep-0078.html#appendix-revs

Comment 16

[Florian Quèze [:florian]]

Attachment: Patch v2

Comment 17

[Patrick Cloke [:clokep]]

Comment on attachment 667915 [details] [diff] [review]
Patch v2

Review of attachment 667915 [details] [diff] [review]:
-----------------------------------------------------------------

This looks good, my only question was about the "0" + splice(-2), which is to ensure the hex is converted into a two character hex code.

Comment 18

[Patrick Cloke [:clokep]]

Committed for Instantbird: http://hg.instantbird.org/instantbird/rev/25d1ab3841be

Comment 19

[Florian Quèze [:florian]]

https://hg.mozilla.org/comm-central/rev/c4143a904267

Comment 20

[Florian Quèze [:florian]]

Comment on attachment 667915 [details] [diff] [review]
Patch v2

[Approval Request Comment]
I think we can take this (low risk: mostly additional code, no real change to the existing code) for comm-aurora (Tb17) but I won't mind if we don't.

User impact: This bug is causing support requests from people who fail to connect to very old Jabber servers (typically jabberd14 or iChat server) that use an authentication method that's been deprecated since 2006. As most existing XMPP clients were implemented at a time when this old authentication method was still widely used, they tend to support this, so if Thunderbird is the only client that can't connect to the server, from a user point of view it's Thunderbird that's broken.

Comment 21

[Florian Quèze [:florian]]

https://hg.mozilla.org/releases/comm-aurora/rev/0e1dbdf95831

Comment 22

[Ryan Foster]

(In reply to Florian Quèze [:florian] [:flo] from comment #21)
> https://hg.mozilla.org/releases/comm-aurora/rev/0e1dbdf95831

Should the Target Milestone be set to 17.0 then?

Comment 23

[Florian Quèze [:florian]]

(In reply to Ryan Foster from comment #22)
> (In reply to Florian Quèze [:florian] [:flo] from comment #21)
> > https://hg.mozilla.org/releases/comm-aurora/rev/0e1dbdf95831
> 
> Should the Target Milestone be set to 17.0 then?

Target Milestone tracks the milestone that was in development at the time the fix landed on comm-central. For fixes that landed in branches (aurora, beta, ...) we use the status-* tracking flags.

You can see "status-thunderbird17: 	fixed" on the top right of this page.

Comment 24

[Ryan Foster]

Ah, I see.  My mistake.  Does the 2012-10-05 nightly have this fix in it, or should I wait for a later one?

Comment 25

[Ryan Foster]

I see that the first Thunderbird 17.0 beta is available now.  However, the Release Notes and list of fixed bugs for it does not seem to include this bug.  Is that an oversight, or did the fix somehow not make it into this beta?  I just want to know if I can test something that has the fix present.

Comment 26

[Florian Quèze [:florian]]

This fix is not important enough to be listed in the release notes, but yes, the fix is included in the first Thunderbird 17 beta, please verify that you can now connect your XMPP account :).

Comment 27

[Ryan Foster]

(In reply to Florian Quèze [:florian] [:flo] from comment #26)
> This fix is not important enough to be listed in the release notes, but yes,
> the fix is included in the first Thunderbird 17 beta, please verify that you
> can now connect your XMPP account :).

I can confirm that I can connect to the account using Thunderbird 17.0 beta 1.  Thanks for fixing this!

Perhaps unrelated to this bug, but related to the above comment...
If not all fixes are included on Bug Fixes page (http://www.mozilla.org/en-US/thunderbird/17.0beta/releasenotes/buglist.html), then perhaps the text on that page should be changed to indicate this, since it currently reads:
See the complete list of Thunderbird bugs fixed by the new version.

That's my opinion anyway.  Thanks again!

Comment 28

[Florian Quèze [:florian]]

(In reply to Ryan Foster from comment #27)

> I can confirm that I can connect to the account using Thunderbird 17.0 beta
> 1.

Ok, thanks for checking, marking verified.

> Thanks for fixing this!

You are welcome!


> Perhaps unrelated to this bug, but related to the above comment...
> If not all fixes are included on Bug Fixes page
> (http://www.mozilla.org/en-US/thunderbird/17.0beta/releasenotes/buglist.
> html), then perhaps the text on that page should be changed to indicate
> this, since it currently reads:
> See the complete list of Thunderbird bugs fixed by the new version.

Mark, do you know how this list is generated, and if there would be an easy way to include the bugs with "status-thunderbird17: fixed" and "status-thunderbird17: verified" in addition to the bugs with "Target Milestone: Thunderbird 17.0"?

Comment 29

[Mark Banner (:standard8)]

(In reply to Florian Quèze [:florian] [:flo] from comment #28)
> > Perhaps unrelated to this bug, but related to the above comment...
> > If not all fixes are included on Bug Fixes page
> > (http://www.mozilla.org/en-US/thunderbird/17.0beta/releasenotes/buglist.
> > html), then perhaps the text on that page should be changed to indicate
> > this, since it currently reads:
> > See the complete list of Thunderbird bugs fixed by the new version.
> 
> Mark, do you know how this list is generated, and if there would be an easy
> way to include the bugs with "status-thunderbird17: fixed" and
> "status-thunderbird17: verified" in addition to the bugs with "Target
> Milestone: Thunderbird 17.0"?

It already does include those, but I generated it about a week in advance of starting the beta, and forgot to re-generate it, hence its missing a few bugs.

Comment 30

[Alexei Colin]

Attachment: Connection log for a server without SASL but with 'version=1.0' attribute

Thank you for IM-in-Thunderbird. I might have a server here that does not support SASL, but still reports 'version="1.0"' in stream:stream stanza. Server info: [1]; more server info: [2]. Attached is the log from the error console*. The error reported to the user is same as in Thunderbird 16: 'No authentication mechanism offered by the server'.

I know nothing about this, so please ignore as you see fit: Is the presence of 'version="1.0"' attribute the best way to check for this? Doesn't the list of supported mechanisms in stream:features tell you whether the server supports SASL or not?

Note: I can successfully connect to a different server with SASL support. This is Thunderbird 17b1.

[1] http://fastmail.wikia.com/wiki/ChatService
[2] http://blog.fastmail.fm/2012/09/26/one-step-forward-two-steps-back/

* Is it possible to select+copy multiple entries at once in the Error Console, or pipe it to a file?

Comment 31

[Florian Quèze [:florian]]

(In reply to Alexei Colin from comment #30)
> Created attachment 675910 [details]
> Connection log for a server without SASL but with 'version=1.0' attribute

Thanks for the log.


> Is the presence
> of 'version="1.0"' attribute the best way to check for this?

Usually yes.

> Doesn't the
> list of supported mechanisms in stream:features tell you whether the server
> supports SASL or not?

The list of mechanisms is part of SASL. Servers that don't support it don't send a feature list at all, so in that case (when seeing the version 0.9) we have to start the legacy auth immediately without expecting a list of features.


But the iq-auth line in this stanza should let us detect that only the old auth is supported:
<stream:features xmlns="http://etherx.jabber.org/streams">
 <auth xmlns="http://jabber.org/features/iq-auth"/>
</stream:features>

> * Is it possible to select+copy multiple entries at once in the Error
> Console, or pipe it to a file?

Unfortunately it's not possible at this point.


Thanks for reporting this. However, I would appreciate if you could file a new bug for this issue that's slightly different from the one initially reported here. It will make it easier to track the progress on fixing this.

Comment 32

[Alexei Colin]

(In reply to Florian Quèze [:florian] [:flo] from comment #31)
> Thanks for reporting this. However, I would appreciate if you could file a
> new bug for this issue that's slightly different from the one initially
> reported here. It will make it easier to track the progress on fixing this.
Bug 806228.