XMPP does not try subsequent mechs if GSSAPI fails

[raeburn]

Under 1.2.3, I could log in to one of my jabber accounts (<username> at mit.edu, connect server jabber.mit.edu) with my password. Under 1.2.4b2, I repeatedly get asked for my password, never getting logged in. I think whatever bit let me log in after trying and failing sasl/gssapi login no longer works. (Was there an openfire bug workaround that got backed out, e.g., as discussed in #8680?)

Another user on the same server has confirmed this problem comes in when updating Adium, using the same server.

The debug window shows a "not-authorized" error report coming back from the server.

Not much interesting in the console log, except some of these: 2008-03-18 12:32:20.086 Adium[26728] 1.000000

I do get in to a second jabber server, with no gssapi authentication.

[jas8522]

Something must have changed in the libpurple update to cause this. Raeburn, can you get us a debug log for the failed login? You can enable debug logging from the Adium menu under Debug Window.

[raeburn]

debug log

[raeburn]

debug log attached. first password prompt is after first line ("online"), second, where i hit cancel, was near end after "destroying connection".

[evands]

Please repeat the process with the CurrentAdiumDebug build and post that debug log for comparison.

[raeburn]

For some reason, version 1.2.3-debug that I get from the CurrentAdiumDebug page does not give me a debug-window menu item as described on that page.

[evands]

Heh, that reason is simple carelessness - I uploaded a new build which is identical to the release one. Please clear your cache and try the download again.

[raeburn]

log from 1.2.3-debug, successful login, up through start of contact list retrieval

[raeburn]

The new build worked. I uploaded the log from when I told Adium to connect to the account in question, through when it first started getting contact info back. I assume you don't need the other parts (like my contact list), but let me know if you do...

[evands]

This doesn't make sense to me... 1.2.3 skips GSSAPI because the server is not found in the kerberos database, and 1.2.4b does find it and continues the connect attempt. Nothing is different in the account or server configuration?

[raeburn]

1.2.3-debug tries to authenticate to xmpp/mit.edu (actually, xmpp/web.mit.edu because of some name mapping weirdness), and that doesn't exist in the Kerberos database.

1.2.4b2 tries to authenticate to xmpp/jabber.mit.edu, and that does exist (and a possibly-locally-modified gaim on the unix systems here uses that to successfully sign on).

My account configuration lists jabber.mit.edu as the connect server, for both versions. The server configuration hasn't changed while I've been doing this little experiment.

[evands]

Oh! Right. libpurple 2.4.0 fixed a bug in which the wrong name was used in various authentication situations; this clearly is one of them.

Okay, next question: Why is GSSAPI supported on this server but you don't have credentials?

[evands]

Or do you have credentials but it's failing to use them as described in  this current pidgin-devl thread?

[raeburn]

I do have credentials when running the test. The authentication step should succeed when Adium (libpurple) passes the correct server name through to the Kerberos code. In Greg's message about our earlier investigation, it was only after successful authentication that the authorization failure happened, because of a bug in OpenFire 3.3.x, and Adium didn't manage to fall back to password authentication correctly. If the wrong name was used, the authentication step failed, and Adium did do the password authentication correctly.

Maybe I should join pidgin-devl myself and catch up on what's going on.

Greg's message describes my understanding of the previous situation. If I understand the logic right -- that we should be using the name of the host we connect to, not the domain part of the JID -- then 1.2.4b2 is doing the right thing, and 1.2.3-debug is doing the wrong thing. If I remove the connect server setting, then 1.2.3-debug fails in the same way as 1.2.4b2 has been failing; Greg described this as bug 2 in his list. I don't know if it's the same bug or something new; is the OpenFire issue supposed to have been worked around? The message from nosnilmot on the 20th seems to suggest that the matter was dropped when a fixed OpenFire came out, at least in the pidgin community.

(As an aside, it does seem reasonable to me to configure a server to support Kerberos/GSSAPI for those users in its local Kerberos realm, and password-based authentication for additional users, so a user connecting to a server supporting GSSAPI might quite reasonably not have Kerberos credentials. Or, they might have credentials for a different realm, and not be able to do authentication between the realms, and thus still need to use a password. Or, cross-realm authentication can succeed, but permission for the non-local Kerberos identity to use that Jabber account hasn't been set up. But those aren't -- shouldn't be -- my case, though the last case might conceivably produce a similar-looking authorization failure report. I could try to experiment with that sometime.)

[raeburn]

A workaround has been found: If you can connect with "old-style SSL" on another port, it appears that Adium never even attempts GSSAPI authentication, and jumps right to PLAIN (and asks for your password, once).

[Robby]

Didn't make 1.2.4.

[jas8522]

Since you're working on it anyway, Evan.

[evands]

raeburn, please try  Adium_1.3svn20080411 and let us know if this fix works for you.

[raeburn]

Looks like the email I sent earlier hasn't gotten filed here for some reason.

I tried 1.3svn20080411, and it seems to work fine. I got signed on to the MIT jabber server, using GSSAPI, no password, no old-style SSL.

[evands]

Trac doesn't support posting via email, unfortunately.

Great, glad to hear it. Fix is by Stu Tomlinson (nosnilmot).

[evands]

(In [23128]) libpurple 2.4.0 updates to current im.pidgin.pidgin which includes Stu's patch to try subsequent XMPP authentication mechanisms if one fails, which fixes #9492 where GSSAPI fails but other mechs will work. Also, the libpurple 2.4.0 localization updates which weren't committing previously.

[evands]

(In [23129]) Merged [23128]: libpurple 2.4.0 updates to current im.pidgin.pidgin which includes Stu's patch to try subsequent XMPP authentication mechanisms if one fails, which fixes #9492 where GSSAPI fails but other mechs will work. Also, the libpurple 2.4.0 localization updates which weren't committing previously.

[raeburn]

Okay, found some problems... if Adium needs to reconnect because I enabled or disabled some VPN software while I was online, other accounts reconnect okay, but Adium now insists on getting the password for the account it should be able to do GSSAPI for. I don't know if random network hiccups will affect it the same way (versus local network events the OS can notify the application of).

Quitting and restarting does get it to use GSSAPI again.

[evands]

What dialogue is shown to get the password? Can you show the debug log of this happening please?

[raeburn]

Replying to evands:

What dialogue is shown to get the password? Can you show the debug log of this happening please?

"Please enter your account password" is the dialog window.

The debug log shows, from around the time of switching off the VPN until just after hitting "cancel" to the password prompt:

}Photo: {

NSFont = "Helvetica 12.00 pt. P [] (0x08df0a50) fobj=0x0049f480, spc=3.33";

}{

NSAttachment = AITextAttachmentExtension<8de1ee0>: <AITextAttachmentExtension: 0x8de1ee0>;

} { } 11:13:18: (Libpurple: imgstore) retrieved image id 14 11:13:47: (Libpurple: jabber) Sending (ssl): <iq type='get' id='purplea537f265'><ping xmlns='urn:xmpp:ping'/></iq> 11:13:47: (Libpurple: cdsa) receive failed (-9806): Connection reset by peer 11:13:47: Connection Disconnected: gc=8f7d6d0 (Read Error) 11:13:47: <ESPurpleJabberAccount:69ca6b0 11>:raeburn@… accountConnectionReportDisconnect: Read Error 11:13:47: (Libpurple: cdsa) receive failed (-9806): Unknown error: 0 11:13:47: (Libpurple: account) Disconnecting account 0x8dee2c0 11:13:47: (Libpurple: connection) Disconnecting connection 0x8f7d6d0 11:13:47: (Libpurple: connection) Deactivating keepalive. 11:13:47: (Libpurple: jabber) XML parser error for JabberStream 0x0: Domain 1, code 5, level 3: Extra content at the end of the document

11:13:47: Disconnected: gc=8f7d6d0 11:13:47: <ESPurpleJabberAccount:69ca6b0 11>:raeburn@…: Telling the core we disconnected 11:13:47: <ESPurpleJabberAccount:69ca6b0 11>:raeburn@…: Disconnected ("Read Error"): Automatically reconnecting immediately 11:13:47: <ESPurpleJabberAccount:69ca6b0 11>:raeburn@…: Updating status for key: Online 11:13:47: (Libpurple: connection) Destroying connection 0x8f7d6d0 11:13:52: (Libpurple: util) Writing file accounts.xml to directory /Users/raeburn/Library/Application Support/Adium 2.0/Users/Default/libpurple 11:13:52: (Libpurple: util) Writing file /Users/raeburn/Library/Application Support/Adium 2.0/Users/Default/libpurple/accounts.xml 11:13:52: (Libpurple: util) Writing file blist.xml to directory /Users/raeburn/Library/Application Support/Adium 2.0/Users/Default/libpurple 11:13:52: (Libpurple: util) Writing file /Users/raeburn/Library/Application Support/Adium 2.0/Users/Default/libpurple/blist.xml 11:13:59: <ESPurpleJabberAccount:69ca6b0 11>:raeburn@…: Updating status for key: Online

[raeburn]

Ouch. Sorry about the formatting.

[evands]

Replying to raeburn: Let's WikiFormatting that :)

}Photo: {
    NSFont = "Helvetica 12.00 pt. P [] (0x08df0a50) fobj=0x0049f480, spc=3.33";
}{
    NSAttachment = AITextAttachmentExtension<8de1ee0>: <AITextAttachmentExtension: 0x8de1ee0>;
}
{
}
11:13:18: (Libpurple: imgstore) retrieved image id 14
11:13:47: (Libpurple: jabber) Sending (ssl): <iq type='get' id='purplea537f265'><ping xmlns='urn:xmpp:ping'/></iq>
11:13:47: (Libpurple: cdsa) receive failed (-9806): Connection reset by peer
11:13:47: Connection Disconnected: gc=8f7d6d0 (Read Error)
11:13:47: <ESPurpleJabberAccount:69ca6b0 11>:raeburn@mit.edu accountConnectionReportDisconnect: Read Error
11:13:47: (Libpurple: cdsa) receive failed (-9806): Unknown error: 0
11:13:47: (Libpurple: account) Disconnecting account 0x8dee2c0
11:13:47: (Libpurple: connection) Disconnecting connection 0x8f7d6d0
11:13:47: (Libpurple: connection) Deactivating keepalive.
11:13:47: (Libpurple: jabber) XML parser error for JabberStream 0x0: Domain 1, code 5, level 3: Extra content at the end of the document

11:13:47: Disconnected: gc=8f7d6d0
11:13:47: <ESPurpleJabberAccount:69ca6b0 11>:raeburn@mit.edu: Telling the core we disconnected
11:13:47: <ESPurpleJabberAccount:69ca6b0 11>:raeburn@mit.edu: Disconnected ("Read Error"): Automatically reconnecting immediately
11:13:47: <ESPurpleJabberAccount:69ca6b0 11>:raeburn@mit.edu: Updating status for key: Online
11:13:47: (Libpurple: connection) Destroying connection 0x8f7d6d0
11:13:52: (Libpurple: util) Writing file accounts.xml to directory /Users/raeburn/Library/Application Support/Adium 2.0/Users/Default/libpurple
11:13:52: (Libpurple: util) Writing file /Users/raeburn/Library/Application Support/Adium 2.0/Users/Default/libpurple/accounts.xml
11:13:52: (Libpurple: util) Writing file blist.xml to directory /Users/raeburn/Library/Application Support/Adium 2.0/Users/Default/libpurple
11:13:52: (Libpurple: util) Writing file /Users/raeburn/Library/Application Support/Adium 2.0/Users/Default/libpurple/blist.xml
11:13:59: <ESPurpleJabberAccount:69ca6b0 11>:raeburn@mit.edu: Updating status for key: Online

[evands]

(In [23132]) Some password retriieval debugging. Refs #9492

[evands]

Same deal, but this time with debug logging to narrow down what's going on. It's not directly related to the patch committed with [23128], but I think we've revealed some underlying oddness.

Please try  Adium_1.3svn20080414 to get info as before.

[raeburn]

Here's the log data this time:

20:57:37: Getting accountActionMenuItems for <ESPurpleJabberAccount:5a8eea0 11>:raeburn@mit.edu
20:57:37: (Libpurple: jabber) jabber_actions: have pep: YES
20:57:39: Getting accountActionMenuItems for <ESPurpleJabberAccount:5a8eea0 11>:raeburn@mit.edu
20:57:39: (Libpurple: jabber) jabber_actions: have pep: YES
20:58:03: (Libpurple: jabber) Sending (ssl): <iq type='get' id='purple6fc3c851'><ping xmlns='urn:xmpp:ping'/></iq>
20:58:03: (Libpurple: cdsa) receive failed (-9806): Connection reset by peer
20:58:03: Connection Disconnected: gc=b4bfe40 (Read Error)
20:58:03: <ESPurpleJabberAccount:5a8eea0 11>:raeburn@mit.edu accountConnectionReportDisconnect: Read Error
20:58:03: (Libpurple: cdsa) receive failed (-9806): Unknown error: 0
20:58:03: (Libpurple: account) Disconnecting account 0x8c2ab10
20:58:03: (Libpurple: connection) Disconnecting connection 0xb4bfe40
20:58:03: (Libpurple: connection) Deactivating keepalive.
20:58:03: (Libpurple: jabber) XML parser error for JabberStream 0x0: Domain 1, code 5, level 3: Extra content at the end of the document

20:58:03: Disconnected: gc=b4bfe40
20:58:03: <ESPurpleJabberAccount:5a8eea0 11>:raeburn@mit.edu: Telling the core we disconnected
20:58:03: -[AIAccount(Abstract) serverReportedInvalidPassword]: <ESPurpleJabberAccount:5a8eea0 11>:raeburn@mit.edu
20:58:03: <ESPurpleJabberAccount:5a8eea0 11>:raeburn@mit.edu: Disconnected ("Read Error"): Automatically reconnecting immediately
20:58:03: -[AIAccount(Abstract) retrievePasswordThenConnect]: Retrieving <ESPurpleJabberAccount:5a8eea0 11>:raeburn@mit.edu's password (promptOption 1)
20:58:03: <ESPurpleJabberAccount:5a8eea0 11>:raeburn@mit.edu: Updating status for key: Online
20:58:03: (Libpurple: connection) Destroying connection 0xb4bfe40
20:58:08: (Libpurple: util) Writing file accounts.xml to directory /Users/raeburn/Library/Application Support/Adium 2.0/Users/Default/libpurple
20:58:08: (Libpurple: util) Writing file /Users/raeburn/Library/Application Support/Adium 2.0/Users/Default/libpurple/accounts.xml
20:58:08: (Libpurple: util) Writing file blist.xml to directory /Users/raeburn/Library/Application Support/Adium 2.0/Users/Default/libpurple
20:58:08: (Libpurple: util) Writing file /Users/raeburn/Library/Application Support/Adium 2.0/Users/Default/libpurple/blist.xml
20:58:18: <ESPurpleJabberAccount:5a8eea0 11>:raeburn@mit.edu: Updating status for key: Online

[jystickman]

This change appears to have broken logins for me.

I am trying to connect to a SunONE IM server (Jabber/XMPP) and AdiumX 1.2.5 no longer brings up a dialog to prompt me for a password. If I don't include a password in my Account Settings, Adium appears to try to log me in with no password, which results in Error: 403: Forbidden

The only way I can log in is to populate the password field. So it seems like it's failing to ask for a password now (instead of trying the alternate mechanisms).

Apologies if this is *not* the issue (I'll open another ticket), but given the behavior and the changes that look like have occurred as a result of this ticket, it sure smells suspicious.

[evands]

I've moved this discussion to #9748.The issue at hand in this ticket is fixed.