Jabber connection unreliable

[aaronworsham]

Since upgrading to version 1.2.6 an hour ago, connections to our local Jabber server have been cycling. This is happening to three different Adium users locally who all upgraded at the same time. Spark clients are not seeing connection issues to the same Spark Jabber server.

From log: Changed status to Offline (10:05:48 AM) Changed status to Online (10:05:48 AM) Changed status to Offline (10:30:52 AM) Changed status to Online (10:30:52 AM) Changed status to Offline (10:34:57 AM) Changed status to Online (10:34:58 AM) Changed status to Offline (10:38:03 AM) Changed status to Online (10:38:03 AM) Changed status to Offline (10:41:39 AM) Changed status to Online (10:41:39 AM) Changed status to Offline (10:44:45 AM) Changed status to Online (10:44:45 AM) Changed status to Offline (10:49:50 AM) Changed status to Online (10:49:50 AM)

[miner]

I see this as well, connecting to eJabberd v1.1.4

I do not lose my connection to GTalk, AOL, MSN or Yahoo. I get this in the system error log every time:

7/2/08 10:21:54 AM [0x0-0x8cf8cf].com.adiumX.adiumX[62882] SocketRead: read(5) error 0 
7/2/08 10:21:54 AM [0x0-0x8cf8cf].com.adiumX.adiumX[62882] SocketRead err = -9802 

[Maradatscha]

I see excactly the same issue with adium 1.3b6 connecting to jabber.org and jabber.ccc.de GTalk works

[zjt]

I run the server that 'miner' is connecting to (ejabberd 1.1.4). I just upgraded Adium to 1.2.6.

I have not been able to simulate the bug.

Maybe it has something to do with the other accounts (e.g. Gmail) that are configured? I have 3 jabber accounts (all ejabberd 1.1.4) configured, but I do not have Gmail or any of the proprietary IM networks configured.

[jesse]

I'm also seeing the same issue here.

Server: jabberd-2.0

Seen in server log:

Wed Jul  2 10:09:25 2008 [notice] [92] [67.160.124.242, port=55311] connect
Wed Jul  2 10:09:25 2008 [notice] [92] SASL authentication succeeded: mechanism=DIGEST-MD5; authzid=jesse@jabber.xyz.com
Wed Jul  2 10:09:25 2008 [notice] [92] bound: jid=jesse@jabber.xyz.com/Adium
Wed Jul  2 10:09:26 2008 [notice] [92] requesting session: jid=jesse@jabber.xyz.com/Adium
Wed Jul  2 10:09:27 2008 [notice] [92] [jesse@jabber.xyz.com/Adium] error: XML parse error (not well-formed (invalid token))
Wed Jul  2 10:09:27 2008 [notice] [92] [67.160.124.242, port=55311] disconnect

That is repeated until the user forces a completed disconnect. Issue seems to 'clear up' after 5-10 minutes.

[miner]

In any case, reverting to 1.2.5 "fixes" the problem for me. For the record, I do have: AIM, MSN, Yahoo, Gchat, Bonjour and our local eJabberd configured.

[etherbob]

I've been running into the same issue with Adium 1.3b6

I've also noticed a half dozen other Mac users with similar issues (not sure if they're all using Adium, but it would seem to fit).

[jstownsley]

Seeing this as well with 1.3b6 clients against my Jabber 1.x server. Server shows repeating login/logouts. I've attached an adium debug taken during a connect FWIW.

[librarian]

As a user I was simply unable to connect to any servers. I use AOL and Jabber, both an internal company Jabber server and Google's server, and the results are the same: attempting to connect has no apparent effect. I don't know what it was doing under the hood, but rolling back to 1.2.5 fixed it.

[rsmclane]

I've been running into this as well since the 1.2.6 upgrade. It will work fine for a while but then I'll get disconnected and get repeated connect/disconnects until I completely restart Adium. We're running jabberd-2.1.23 compiled against libgsasl-0.2.25 and mu-conference-0.7

I don't see anything in my local console.

Here are the errors I'm seeing on the jabber server.

Jul  2 14:40:31 engr01jab jabberd/sm[1758]: session started: jid=rsmclane@jabber.eos.ncsu.edu/daedalus
Jul  2 14:40:31 engr01jab jabberd/c2s[1760]: [42] [rsmclane@jabber.eos.ncsu.edu] error: XML parse error (not well-formed (invalid token))
Jul  2 14:40:31 engr01jab jabberd/c2s[1760]: [42] [rsmclane@jabber.eos.ncsu.edu] error: XML parse error (not well-formed (invalid token))
Jul  2 14:40:31 engr01jab jabberd/c2s[1760]: [42] [152.1.68.35, port=65358] disconnect jid=rsmclane@jabber.eos.ncsu.edu/daedalus, packets: 156
Jul  2 14:40:31 engr01jab jabberd/sm[1758]: session ended: jid=rsmclane@jabber.eos.ncsu.edu/daedalus

Is the more common one, I've also seen this one.

Jul  2 14:36:45 engr01jab jabberd/c2s[1760]: [42] [rsmclane@jabber.eos.ncsu.edu] error: XML parse error (reference to invalid character number)

[jayoungncsu]

personally, I seem to be seriously screwed - as is at least one other of my users - I don't know the total scope of the problem with other users yet.

Upgrading to 1.2.6 caused my main account on my server (Openfire 3.5.1 to start, I took the whole thing down and upgraded to Openfire 3.5.2) to stop receiving any messages, I could see them coming in via wireshark, but adium wouldn't display them. I upgraded to 1.3b6 - same problem, and ran the debug console in the beta - saw the messages coming in, but adium wouldn't display it. Additionally, Adium would disconnect with ping timeouts, although Openfire was returing it's own pong of sorts (the 503 service unavailable in response to the xmpp:ping) Used another account in Adium, that was fine, iChat was fine for all accounts. Tried switching to 1.2.5 *on another mac* that hadn't upgraded yet (though behind the same NAT) - and now *that* client is not receiving messages, and getting the ping disconnects. Tried downgrading to 1.2.5 on the original machine - still no luck. I've restarted one of the clients twice, and the server once (after the Openfire 3.5.2 upgrade) - that's about all I can get away with :-). I've removed and re-added contacts between accounts - no luck. So I have what looks to be a client initiated problem that's cascaded into the server. Or something. It's one of the strangest things I think I've ever seen.

[m00k0w]

3 of 5 (or so) clients that were upgraded this morning to 1.2.6 disconnect continuously from ejabbered 2.0.1. The last packet from the server (courtesy of the Adium XML Console):

<error xmlns=' http://etherx.jabber.org/streams'>

<xml-not-well-formed xmlns='urn:ietf:params:xml:ns:xmpp-streams'/>

</error>

[zacw]

What XML is Adium sending which it considers not well formed?

[lazyone]

I was experiencing the same problem with a friend, we both upgraded to 1.2.6 today. Every time we are online at the same time, both with Adium, we constantly get disconnected (the error message visible in the preferences window is: Invalid XML). If just one of us is online, everything is fine. If one is using Pidgin and the other one Adium, it works fine, too. If one disconnects, the other one can stay online without problems, too. (Note that all other of our Jabber contacts do not use Adium, but Pidgin or something else.)

[m00k0w]

I ended up reinstalling 1.2.5, then updated to 1.2.6 again to debug a bit more, only to find the disconnect problem had gone away.

[evands]

I think there are at least 2 issues in this ticket. adium_jabber_debug.txt from jstownsley, the attachment above, does not appear to have anything in it like the 'xml-not-well-formed' problem which most other posters are describing.

rsmclane: Could you please get a clientside from Adium doing this badness and the resulting server errors? If that's too hard, just the clientside log would likely be illustrative.

[jayoungncsu]

Not that it's worth much, but after a series of quitting the application and trying chats between two accounts and watching the debug window, and the XML console for the XMPP connection - in which I was seeing the XMPP communication data in the debug window, but not the XML console, other than the outbound XMPP pings. I just decided to quit, restart, and let it sit for awhile.

After one reconnect from a PingTimeout, I started seeing the XMPP transactions in both windows, I let it sit entirely just getting prescence notifications, vcards, etc for about 20 minutes. It just happily started receiving messages, stopped disconnecting, etc. I quit/restarted, and everything was happy.

I couldn't trace all the messages in the list, things get a little confusing when you start scrolling through Base64 body's for the avatar images, but they all looked fine, all the responses looked like you'd expect. There were some namespace errors coming back from Google Talk, but those seemed normal. It just... started working...

I went back to 1.2.6 on my other box in the house, and things broke again. Then ugpraded it to 1.3b6 to take advantage of the debug window and xml console, and it still broke without any good indication of why in either data stream. I let it "sit a while" - and it later came back fine. I think my problem is really Openfire caching something somewhere. So, anyway, 1.3b6 appears to be okay "after time" - and I have crap for data about what might be wrong ;-)

[jstownsley]

I'm definitely getting the same XML error. My jabber server was throttling the connections, so my trace above isn't complete I suspect.

I've attached another file. This is the XML ripped out of wireshark. XML error at the bottom. You can't tell easily from this file but the request/responses are all here.

[jstownsley]

And a client side log.

[jstownsley]

Having trouble uploading the client log file. I'll try again in a bit. Here's part of it, note that "nate" below is using Adium v3b6 as well.

18:50:53: Buddy icon update for nate@… 18:50:53: [buddy icon: nate@… got data] 18:50:53: (Libpurple: jabber) Recv (145): <iq type='get' id='purple40194c9f' to='jst@…/Adium' from='nate@…/Adium'><query xmlns='jabber:iq:version'/></iq> 18:50:53: (Libpurple: jabber) Sending: <iq type='result' to='nate@…/Adium' id='purple40194c9f'><query xmlns='jabber:iq:version'><name>Adium</name><version> ∑å†Ä&#x10; (libpurple 2.5.0devel)</version></query></iq> 18:50:53: (Libpurple: jabber) Recv (485): <iq type='get' id='purple40194ca0' to='jst@…/Adium' from='nate@…/Adium'><query xmlns='jabber:iq:last'/></iq><iq type='get' id='purple40194ca1' to='jst@…/Adium' from='nate@…/Adium'><query xmlns=' http://jabber.org/protocol/disco#items' node=' http://jabber.org/protocol/commands'/></iq><presence type='unavailable' from='nate@…/Adium' to='jst@…'><status>Disconnected</status></presence> 18:50:53: (Libpurple: jabber) Sending: <iq type='result' id='purple40194ca0' to='nate@…/Adium'><query xmlns='jabber:iq:last' seconds='0'/></iq> 18:50:53: (Libpurple: jabber) Sending: <iq type='result' id='purple40194ca1' to='nate@…/Adium'><query xmlns=' http://jabber.org/protocol/disco#items' node=' http://jabber.org/protocol/commands'/></iq> 18:50:53: (Libpurple: blist) Updating buddy status for nate@… (XMPP) 18:50:53: (Libpurple: jabber) Recv (40): <stream:error>Invalid XML</stream:error> 18:50:53: Connection Disconnected: gc=82c20d0 (Stream Error) 18:50:53: <ESPurpleJabberAccount:7179ec0 12>:jst@… accountConnectionReportDisconnect: Stream Error 18:50:53: (Libpurple: jabber) Disconnected: Connection reset by peer 18:50:53: (Libpurple: account) Disconnecting account 0x8295850 18:50:53: (Libpurple: connection) Disconnecting connection 0x82c20d0 18:50:53: (Libpurple: connection) Deactivating keepalive. 18:50:53: (Libpurple: jabber) XML parser error for JabberStream 0x0: Domain 1, code 5, level 3: Extra content at the end of the document

[evands]

D'oh! The problem is so obvious with a decent log - thanks. Any server or client which requests jabber:iq:version from us produces a denial-of-service because I screwed up with the new code which lets libpurple know about Adium's version. Argh. Thanks for your help.

[evands]

(In [24183]) g_hash_table_insert() does not copy keys or values passed to it. We must pass it allocated memory (or string constants). Putting [[NSApp applicationVersion] UTF8String] in the hash table as the version's value meant that when version was later accessed, it was more likely than not going to access garbage. Garbage does not make for good version numbers... or for well-formed XML.

The result was that anytime over XMPP we were asked for jabber:iq:version (which some servers do and some clients do), we sent out invalid XML. Ouch!

Fixes #10324 and any other "XMPP won't stay connected" or "XMPP server says we sent invalid XML" tickets filed against 1.2.6 or 1.3b6.

[evands]

(In [24184]) Merged [24183]: g_hash_table_insert() does not copy keys or values passed to it. We must pass it allocated memory (or string constants). Putting [[NSApp applicationVersion] UTF8String] in the hash table as the version's value meant that when version was later accessed, it was more likely than not going to access garbage. Garbage does not make for good version numbers... or for well-formed XML.

The result was that anytime over XMPP we were asked for jabber:iq:version (which some servers do and some clients do), we sent out invalid XML. Ouch!

Fixes #10324 and any other "XMPP won't stay connected" or "XMPP server says we sent invalid XML" tickets filed against 1.2.6 or 1.3b6.

[librarian]

Would this also cause problems for AOL? I wasn't able to connect there either with 1.2.6.

[evands]

Replying to librarian:

Would this also cause problems for AOL? I wasn't able to connect there either with 1.2.6.

No. Please create a ticket with your debug log from 1.2.6 and from 1.2.5-debug ASAP. I want to release the fix for this soon, and if there are other major problems they should be addressed at the same time.

[evands]

Folks: Please try  Adium_1.2.7b1 and let us know whether it fixes this issue for you.

[etherbob]

I have really slow logins. Looking in the account window it actually stalls out at "Initializing Stream (25%)"

[etherbob]

Debug for 1.2.7b1 connecting to a jabber server (not sure of the server software/version)

[jstownsley]

Replying to evands:

Folks: Please try  Adium_1.2.7b1 and let us know whether it fixes this issue for you.

Build 24186 is working for me with jabber.

[evands]

Replying to etherbob:

I have really slow logins. Looking in the account window it actually stalls out at "Initializing Stream (25%)"

Your log shows you connecting without problems so far as I can tell; you certainly get past Initializing Stream. Do you have any Console logging?

[etherbob]

relaunched and it works like a champ. Not sure what was going on before then...

[etherbob]

Also nothing in the console near as I can tell...

[evands]

Okay, thanks for your testing. This ticket has been resolved; please open a new ticket for any new issues :)

[dhawes]

I came across this bug after upgrading to 1.2.6 and was about to post it when I saw this ticket.

It is quite similar to a bug I posted to the Pidgin bug tracker:

 http://developer.pidgin.im/ticket/6031

Does the fix for this issue prevent the client from being disconnected when the control characters are sent from another client? I ask because a client would be dependent on other clients not sending invalid XML characters, which seems like a good way to deny service. The larger question is why does the client get disconnected when these characters are encountered?

[hgeisler]

Replying to evands:

Folks: Please try  Adium_1.2.7b1 and let us know whether it fixes this issue for you.

I have upgrade to this beta version as a result of the constant connection loop, unfortunately i am still having the issue!!

[dhawes]

I have tried 1.2.7.b1, and though the version string does not contain ASCII control characters, the XML processing will still fail when another person with 1.2.6 sends control characters in the version string.

Changeset 24183 ensures that garbage isn't put into the XML, but it does not take care of the real problem which is that XML processing essentially stops when an invalid XML character is encountered (see my pigin ticket link above).

So, to hgeisler, you need to get everyone in your contact list who has upgraded Adium to 1.2.6 to upgrade to 1.2.7b1 so the invalid XML messages won't be sent to your client (downgrade will work just as well).

[evands]

(In [24247]) libpurple.framework im.pidgin.pidgin 2.5.0mtn @ 2b2d7fb52, which should fix problems with XMPP XML parser error handling. Investigation and fix a combined effort of dhawes, catfish_man42, and myself.

Fixes #10347. Fixes #10353. Refs #10324.

May fix other issues, as well, or at least make them more debuggable, as there was no error handling previously.

[evands]

(In [24249]) libpurple.framework im.pidgin.pidgin.2.4.3, with all patches on adium-1.2 as of [24245], which should fix problems with XMPP XML parser error handling. Investigation and fix a combined effort of dhawes, catfish_man42, and myself.

Fixes #10347. Fixes #10353. Refs #10324.

May fix other issues, as well, or at least make them more debuggable, as there was no error handling previously.

[baburdick]

I'm still getting this error in 1.3b7:

Jul  5 13:38:12 Bruces-MacBook-Pro [0x0-0x59059].com.adiumX.adiumX[1101]: SocketRead: read(5) error 0
Jul  5 13:38:12 Bruces-MacBook-Pro [0x0-0x59059].com.adiumX.adiumX[1101]: SocketRead err = -9802

No version past 1.2.3 has been usable for me.

[dgc]

I started having this problem when I upgraded to 1.2.7. I've since tried reverting to 1.2.3, 1.2.4, and 1.2.5 and upgrading to 1.3b7. The older versions broke my XMPP completely (I could no longer receive messages, though I could open windows and send them), so not sure what was going on with those. Talked to people on IRC two days ago and moved to 1.3b7. The problem appeared resolved for a while, but then began happening again late yesterday. From debug logs it appears to be triggered by the invalid CDATA in <version/> from an Adium 1.2.6 client. As far as I and my co-workers can see, this bug is still present in 1.2.7 and 1.3b7 IF a 1.2.6 user is on the server and on your contact list and sending bad version text.

We made our 1.2.6 user upgrade, and now nobody else is seeing the disconnect problem. So far.

Seems like the real problem is with the parser, not the issuer. This amounts to a DOS attack, since the version text is (or can be) user-generated.

[Mongo]

I seem to be experiencing this problem since last week. I get disconnected/reconnected every 3-6 minutes. I have a standard install of Adium 1.2.7. (Are there any debug logs available I can share?)

Looking at console log, I see a bunch of these messages (which might be related to the reconnect more than they're related to the disconnect):

8/19/08 3:10:18 PM Adium[34837] *** NSRunLoop ignoring exception 'Error (1000) creating CGSWindow' that raised during posting of delayed perform with target 0x8483260 and selector 'rebuildMenu' 
8/19/08 3:10:18 PM [0x0-0x163163].com.adiumX.adiumX[34837] Tue Aug 19 15:10:18 mike-lamberts-macbook-pro-15.local Adium[34837] <Warning>: CGSResolveShmemReference : reference offset (65376) exceeds bounds (32768) on shmem obj 0x35660 
8/19/08 3:10:28 PM Adium[34837] Error (1000) creating CGSWindow 
8/19/08 3:10:28 PM [0x0-0x163163].com.adiumX.adiumX[34837] Tue Aug 19 15:10:28 mike-lamberts-macbook-pro-15.local Adium[34837] <Warning>: CGSResolveShmemReference : reference offset (65296) exceeds bounds (32768) on shmem obj 0x35660 

Please let me know if there's anything I can do to help debug/track/fix.

[Robby]

Mongo reported this for 1.3 in IRC as well. I also reopened #10353.

[evands]

Mongo, your problem is with your system; the 'Error (1000) creating CGSWindow' error is thrown by the window manager when it is out of resources. There's nothing Adium can do about it; restart your computer. You have not been experiencing the problem in this ticket (or if you have, you are reporting a separate issue).

Note that the 'denial of service' aspects mentioned should be fixed as of Adium 1.3.

[evands]

In any case, please open a new ticket for whatever issue you are reporting. It is unlikely the existing comments in this ticket are relevant to a new issue.