[Home]

Summary:ASTERISK-11119: [patch] res_jabber appears to not be working correctly in /trunk
Reporter:David Van Ginneken (davevg)Labels:
Date Opened:2007-12-27 15:43:02.000-0600Date Closed:2008-01-07 08:22:26.000-0600
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Resources/res_jabber
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) trunk-11644-1.diff
( 1) trunk-11644-2.diff
Description:I did an in-place upgrade from a recent asterisk/branch/1.4 to asterisk/trunk.  res_jabber did work correctly with 1.4 svn.  With the trunk version every 4 seconds I receive this error:
[Dec 27 16:25:02] WARNING[16509]: res_jabber.c:1943 aji_recv_loop: JABBER: socket read error
Both asterisk and jabber are located on the same server (CentOS 5) in this instance.  See Additional info for details.

****** ADDITIONAL INFORMATION ******

If I comment out the host in jabber.conf, and restart it stays quiet.  (Like it should)  Then when I uncomment and issue a jabber reload command the output is this:

asterisk*CLI> jabber reload
Jabber Reloaded.
 == Parsing '/etc/asterisk/jabber.conf':   == Found
asterisk*CLI>
JABBER: asterisk OUTGOING: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='my.jabber.host' version='1.0'>
asterisk*CLI>
JABBER: asterisk INCOMING: <?xml version='1.0' encoding='UTF-8'?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="my.jabber.host" id="92a3b417" xml:lang="en" version="1.0"><stream:features><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"></starttls><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>DIGEST-MD5</mechanism><mechanism>PLAIN</mechanism><mechanism>CRAM-MD5</mechanism></mechanisms><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/></stream:features>
asterisk*CLI>
JABBER: asterisk OUTGOING: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>
asterisk*CLI>
JABBER: asterisk INCOMING: <proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>
asterisk*CLI>
JABBER: asterisk OUTGOING: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='my.jabber.host' version='1.0'>
asterisk*CLI>
JABBER: asterisk INCOMING: <?xml version='1.0' encoding='UTF-8'?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="my.jabber.host" id="92a3b417" xml:lang="en" version="1.0"><stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>DIGEST-MD5</mechanism><mechanism>PLAIN</mechanism><mechanism>CRAM-MD5</mechanism></mechanisms><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/></stream:features>
asterisk*CLI>
JABBER: asterisk OUTGOING: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
JABBER: asterisk OUTGOING: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='my.jabber.host' version='1.0'>
[Dec 27 16:28:20] WARNING[16557]: res_jabber.c:1943 aji_recv_loop: JABBER: socket read error
asterisk*CLI>
JABBER: asterisk OUTGOING: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='my.jabber.host' version='1.0'>
[Dec 27 16:28:24] WARNING[16557]: res_jabber.c:1943 aji_recv_loop: JABBER: socket read error
asterisk*CLI>
JABBER: asterisk OUTGOING: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='my.jabber.host' version='1.0'>
[Dec 27 16:28:28] WARNING[16557]: res_jabber.c:1943 aji_recv_loop: JABBER: socket read error
asterisk*CLI>
JABBER: asterisk OUTGOING: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='my.jabber.host' version='1.0'>
[Dec 27 16:28:32] WARNING[16557]: res_jabber.c:1943 aji_recv_loop: JABBER: socket read error
asterisk*CLI>
JABBER: asterisk OUTGOING: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='my.jabber.host' version='1.0'>
[Dec 27 16:28:36] WARNING[16557]: res_jabber.c:1943 aji_recv_loop: JABBER: socket read error
asterisk*CLI>

If I then comment out the jabber host again and issue a jabber reload command, It appears the changes do not take as it continues to return the socket read errors.  Only way to stop them was to issue a "restart now" command


jabber.conf
[general]
debug=yes                               ;;Turn on debugging by default.
autoprune=yes                           ;;Auto remove users from buddy list.
autoregister=yes                        ;;Auto register users from buddy list.

[asterisk]                              ;;label
type=client                             ;;Client or Component connection
serverhost=my.jabber.host
username=asterisk@my.jabber.host/asterisk      ;;Username with optional roster.
secret=mypassword                         ;;Password
port=5222                               ;;Port to use defaults to 5222
usetls=yes                              ;;Use tls or not
usesasl=yes                             ;;Use sasl or not
timeout=100      

It makes no difference if usetls and usesasl are commented out, same issue.
Comments:By: Michael L. Young (elguero) 2007-12-27 17:03:16.000-0600

Does your XMPP server restrict users to using SSL?  The reason why I am asking is that I am surprised that no one else has had a problem since the change from GNU/TLS to OpenSSL was done a while back.

I too have had a problem and my XMPP server restricts connections to SSL.  I have traced it down in the code to where after the SSL socket is setup, a call is made to a iksemel function and iksemel tries to do a send using SSL but the function in iksemel is trying to use GNU/TLS in order to send instead of the SSL socket that was setup using OpenSSL.  That is if I am reading the code properly.

I wish I could put in some more info but I am in a rush right now.  I saw this bug report and just wanted to help narrow it down.  I will try to add to this bug report as soon as I can.  I will admit that I hesitated to report this because I thought that maybe I was missing something somewhere and didn't have time to keep tracing it down.


By: David Van Ginneken (davevg) 2007-12-27 19:55:27.000-0600

I'm using an Openfire jabber server which accepts both secure and unsecure connections.  The setting right now is that secured connections are optional.  I tested using the Psi client that both connection ways actually work.  It also worked fine in 1.4 although it did get a socket error and needed to reconnect about every 6 minutes.  But trunk doesn't even seem to connect with the same settings.
By: Michiel van Baak (mvanbaak) 2007-12-28 04:31:20.000-0600

Trunk does connect to talk.google.com.
But I get the same loop of warnings once the connection is down for a couple of seconds. Sometimes it runs fine for days, sometimes I get them after about an hour. Looks like it wont reconnect.

This is my jabber.conf:

[general]
autoprune=yes
autoregister=yes

[asterisk]
type=client
serverhost=talk.google.com
username=YYYY@gmail.com/Talk
secret=XXX
port=5222
usetls=yes
usesasl=yes
buddy=mvanbaak@gmail.com
buddy=mvanbaak@jabber.org
statusmessage="I am available"
timeout=100
By: snuffy (snuffy) 2007-12-28 05:44:33.000-0600

There is a known issue with openfire and authentication. (pidgin also has issue with this)
taken from a website:
http://www.thelinuxpimp.com/main/index.php?name=News&file=article&sid=745
quote:
'the crux of the matter, as far as I understand is that Java's CRAM-MD5 implementation and Cryus SASL's implementation (used by Fedora, and perhaps Ubuntu) differ slightly'

From what I remember reading... it should be fixed in an upcoming version of openfire


By: phsultan (phsultan) 2007-12-28 05:45:37.000-0600

The XMPP server announces both DIGEST-MD5 and PLAIN as SASL authentication mechanisms, and we choose DIGEST-MD5, which eventually leads to call 'iks_send' somewhere, which is bad, as elguero reported it.

Can you try the attached patch, and report back please?

Basically, we probably don't want to authenticate with SASL DIGEST-MD5 anymore. Reasons for that are that the very mechanism itself is subject to discussion at the IETF, and that other XMPP open-source projects reported problems when trying to implement it.

See :
http://www.ietf.org/internet-drafts/draft-melnikov-digest-to-historic-00.txt
http://ietfreport.isoc.org/ids-wg-sasl.html (latest publications of the SASL WG mention deprecating SASL DIGEST-MD5)
http://trac.adiumx.com/ticket/8135 (Bug report for the Adium XMPP client related to SASL DIGEST-MD5)

Michiel, I suspect Asterisk fails to reconnect when detecting a dead link, but that's another bug that's worth opening another report. Please provide us with as much information as you can, it looks hard to reproduce.
By: Michiel van Baak (mvanbaak) 2007-12-28 05:52:17.000-0600

phsultan: I'll try to grab some more info and create a new ticket.
It is hard to reproduce, and I added some extra debug lines in res_jabber but till now I cant hit the correct variable or datastore where it goes wrong.
By: David Van Ginneken (davevg) 2007-12-28 07:50:30.000-0600

Patch fixed my issue.  After applying the patch it was successfully able to connect.  I also tested the JabberSend application and it also worked.  Thanks!
By: Michael L. Young (elguero) 2007-12-28 10:07:01.000-0600

I too will try the patch later and report back.

The XMPP server I am using is ejabberd.  Currently, I have it set to only accept SSL but that can be changed (since our server is internal anyways) as you have pointed out some very good reasons for not supporting it for the time being.
By: phsultan (phsultan) 2007-12-28 10:34:48.000-0600

elguero: you mean SASL DIGEST-MD5 rather than SSL in your note, right?

SSL/TLS is used to protect the network connection, SASL (PLAIN, DIGEST-MD5, ..) refers to the authentication mechanism.

If we use SASL PLAIN as the authentication mechanism, we *must* protect the network connection with SSL/TLS, in order to safely authenticate to the XMPP server.
By: Michael L. Young (elguero) 2007-12-28 10:36:16.000-0600

Correct.  I am sorry for my mis-wording.
By: phsultan (phsultan) 2007-12-28 10:40:44.000-0600

Ok, I'll most likely read your feedback next year :)

Dave, thanks for reporting back.

We'll figure out how to properly fix this in trunk after we make sure that we can safely deprecate SASL DIGEST-MD5.

Enjoy the new year celebration!
By: Digium Subversion (svnbot) 2007-12-28 13:45:41.000-0600

Repository: asterisk
Revision: 95257

U   team/bweschke/originate_w_jabber/res/res_jabber.c

------------------------------------------------------------------------
r95257 | bweschke | 2007-12-28 13:45:40 -0600 (Fri, 28 Dec 2007) | 3 lines

Bring in the patch from issue ASTERISK-11119 because it does what it is supposed to do.


------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=95257
By: Michael L. Young (elguero) 2008-01-01 23:08:10.000-0600

Yep.  You were right.  Here is my feedback.

Upon applying the patch, this is what I am getting on the console:

JABBER: asterisk INCOMING: <?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='2327307689' from='xxxxxx.xxxxxx.com' version='1.0' xml:lang='en'><stream:features><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'><required/></starttls><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism><mechanism>PLAIN</mechanism></mechanisms><register xmlns='http://jabber.org/features/iq-register'/></stream:features>

JABBER: asterisk OUTGOING: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>

JABBER: asterisk INCOMING: <proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>

JABBER: asterisk OUTGOING: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='xxxxxx.xxxxxx.com' version='1.0'>

JABBER: asterisk INCOMING: <?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='2944940555' from='xxxxxx.xxxxxx.com' version='1.0' xml:lang='en'>

JABBER: asterisk INCOMING: <stream:features><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism><mechanism>PLAIN</mechanism></mechanisms><register xmlns='http://jabber.org/features/iq-register'/></stream:features>

JABBER: asterisk OUTGOING: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='PLAIN'>encodedpassword</auth>

JABBER: asterisk INCOMING: <failure xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><bad-protocol/></failure>
[Jan  1 23:55:25] ERROR[16134]: res_jabber.c:912 aji_act_hook: JABBER: encryption failure. possible bad password.
      > JABBER: reconnecting.

JABBER: asterisk OUTGOING: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='xxxxxx.xxxxxx.com' version='1.0'>
[Jan  1 23:56:19] WARNING[16134]: res_jabber.c:1926 aji_recv_loop: JABBER: socket read error
      > JABBER: reconnecting.

I confirmed that I am using the right password by using another client to connect to the server.
By: phsultan (phsultan) 2008-01-02 04:08:44.000-0600

elguero: can you connect to your ejabberd server using Asterisk SVN 1.4 rather than trunk?
By: Digium Subversion (svnbot) 2008-01-02 05:31:12.000-0600

Repository: asterisk
Revision: 95794

U   trunk/res/res_jabber.c

------------------------------------------------------------------------
r95794 | phsultan | 2008-01-02 05:31:11 -0600 (Wed, 02 Jan 2008) | 5 lines

Set stream flags to zero upon initialization.

When the XMPP over TLS/SSL connection resets for some reason, it is
wrongly believed as being secured, which makes the re-connection
process endlessly fail. This was reported by mvanbaak in issue ASTERISK-11119.
------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=95794
By: Michael L. Young (elguero) 2008-01-02 21:09:48.000-0600

phsultan:  Let me try it and I will report back.  I know that I used to connect before the switch to OpenSSL.
By: Michael L. Young (elguero) 2008-01-02 21:33:19.000-0600

phsultan:  Yes, branch 1.4 works.  After reinstalling gnutls (I removed it when trunk switched to OpenSSL) and recompiling iksemel, upon startup 1.4 logged in right away.
By: Michael L. Young (elguero) 2008-01-02 21:57:36.000-0600

phsultan:  Okay.  A little more playing around with this and hopefully this clarifies things.

1.4 branch - my ejabberd server is announcing mechanisms sasl-md5 and sasl-plain for authentication.  Therefore, the code in 1.4 was using sasl-md5 to authenticate and it works.  I commented out the code to force sasl-plain and it fails with the same error that I was getting when using the patch created in this issue for trunk.


By: phsultan (phsultan) 2008-01-03 07:36:27.000-0600

Thanks for the detailed report elguero, it looks like ejabberd does like the password string we send, neither jabberd2 (I tested it too).

We compute a base64 value from the following string : \0username\0password\0 , and jabberd2 refuses to authenticate by replying with a <malformed-request> error. If we encode \0username\0password, jabberd2 authenticates correctly. Please try the attached patch to see if this works ok with ejabberd.

Openfire and Google's XMPP server seem less restrictive. Dave, can you confirm this new patch does not break your authentication to you Openfire server?


By: Michael L. Young (elguero) 2008-01-03 08:01:48.000-0600

That will do it.  The latest patch works for ejabberd!
By: David Van Ginneken (davevg) 2008-01-03 08:08:59.000-0600

New patch trunk-11644-2.diff works for me using Openfire.
By: phsultan (phsultan) 2008-01-03 08:16:34.000-0600

Great, thanks for the quick reports!

I suggest we keep the SASL DIGEST-MD5 mechanism to authenticate over a non-encrypted network connection, and use SASL PLAIN instead.

If you don't object, I'll commit that soon.
By: phsultan (phsultan) 2008-01-04 11:17:37.000-0600

Fixed in trunk, revision 96499.

Thanks!
By: Digium Subversion (svnbot) 2008-01-07 08:22:26.000-0600

Repository: asterisk
Revision: 96797

U   branches/1.4/res/res_jabber.c

------------------------------------------------------------------------
r96797 | phsultan | 2008-01-07 08:22:25 -0600 (Mon, 07 Jan 2008) | 5 lines

Compute the base64 value over the [authzid] authcid password string,
thus excluding the trailing NULL byte.

This change has already been committed to trunk, see ASTERISK-11119.

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=96797