Component and bandersnatch?

Hi All,

I’'m trying to get Bandersnatch to work as a component service to Jive Messenger.

The corporate environment I am working within would like to implement messaging resources, but wants everything logged to a database.

So far, I’'ve set up the service port, and the shared secret.

I’'ve configured the bandersnatch settings. But… when I try it with the Jive Messenger, I get the following in the jive error logs:

2005.09.26 14:46:35 org.jivesoftware.messenger.net.SocketReader.run(SocketReader.java:145) Connection closed before session established

Socket[addr=/127.0.0.1,port=33315,localport=5526]

Additionally, when running bandersnatch, it says:

  1. perl bandersnatch2.pl config.xml

not well-formed (invalid token) at line 1, column 183, byte 183 at /usr/lib/perl5/site_perl/5.8.6/XML/SAX/Expat/Incremental.pm line 41

Server Error: read: 0 ->

Connected to MySQL database (bandersnatch@localhost) …Socket error: read, 0,

We got disconneted

I shut down the messenger and used netcat:

nc -l 5526

<stream:stream xmlns:stream=’‘http://etherx.jabber.org/streams’’ xmlns=’‘http://jabberd.jabberstudio.org/ns/component/1.0’’ to=’‘localhost’’ version=’‘1.0’’>

Ok… Interesting.

So, Then I decided to look at the conversation in detail:

/opt/jive_messenger/bin/messenger start

Starting messenger

nohup: appending output to `nohup.out’’

tethereal -x -i lo -T text port 5526

Capturing on lo

0.145085 127.0.0.1 -> 127.0.0.1 TCP 53859 > 5526 Seq=1 Ack=1 Win=32768 Len=149 TSV=1997205324 TSER=1997205179

0000 00 00 00 00 00 00 00 00 00 00 00 00 08 00 45 00 …E.

0010 00 c9 2f c6 40 00 40 06 0c 67 7f 00 00 01 7f 00 …/.@.@…g…

0020 00 01 d2 63 15 96 41 2e c1 7a 41 62 e3 4a 80 18 …c…A…zAb.J…

0030 20 00 fe bd 00 00 01 01 08 0a 77 0a ef 4c 77 0a …w…Lw.

0040 ee bb 3c 73 74 72 65 61 6d 3a 73 74 72 65 61 6d …<stream:stream

0050 20 78 6d 6c 6e 73 3a 73 74 72 65 61 6d 3d 27 68 xmlns:stream=’'h

0060 74 74 70 3a 2f 2f 65 74 68 65 72 78 2e 6a 61 62 ttp://etherx.jab

0070 62 65 72 2e 6f 72 67 2f 73 74 72 65 61 6d 73 27 ber.org/streams’’

0080 20 78 6d 6c 6e 73 3d 27 68 74 74 70 3a 2f 2f 6a xmlns=’'http://j

0090 61 62 62 65 72 64 2e 6a 61 62 62 65 72 73 74 75 abberd.jabberstu

00a0 64 69 6f 2e 6f 72 67 2f 6e 73 2f 63 6f 6d 70 6f dio.org/ns/compo

00b0 6e 65 6e 74 2f 31 2e 30 27 20 74 6f 3d 27 6c 6f nent/1.0’’ to=’'lo

00c0 63 61 6c 68 6f 73 74 27 20 76 65 72 73 69 6f 6e calhost’’ version

00d0 3d 27 31 2e 30 27 3e =’‘1.0’’>

0.151472 127.0.0.1 -> 127.0.0.1 TCP 5526 > 53859 Seq=1 Ack=150 Win=32768 Len=182 TSV=1997205331 TSER=1997205324

0000 00 00 00 00 00 00 00 00 00 00 00 00 08 00 45 00 …E.

0010 00 ea 0d f8 40 00 40 06 2e 14 7f 00 00 01 7f 00 …@.@…

0020 00 01 15 96 d2 63 41 62 e3 4a 41 2e c2 0f 80 18 …cAb.JA…

0030 20 00 fe de 00 00 01 01 08 0a 77 0a ef 53 77 0a …w…Sw.

0040 ef 4c 3c 3f 78 6d 6c 20 76 65 72 73 69 6f 6e 3d .L<?xml version=

0050 27 31 2e 30 27 20 65 6e 63 6f 64 69 6e 67 3d 27 ‘‘1.0’’ encoding=’’

0060 55 54 46 2d 38 27 3f 3e 3c 73 74 72 65 61 6d 3a UTF-8’’?><stream:

0070 65 72 72 6f 72 20 78 6d 6c 6e 73 3a 73 74 72 65 error xmlns:stre

0080 61 6d 3d 22 68 74 74 70 3a 2f 2f 65 74 68 65 72 am="http://ether

0090 78 2e 6a 61 62 62 65 72 2e 6f 72 67 2f 73 74 72 x.jabber.org/str

00a0 65 61 6d 73 22 3e 3c 62 61 64 2d 6e 61 6d 65 73 eams"><bad-names

00b0 70 61 63 65 2d 70 72 65 66 69 78 20 78 6d 6c 6e pace-prefix xmln

00c0 73 3d 22 75 72 6e 3a 69 65 74 66 3a 70 61 72 61 s="urn:ietf:para

00d0 6d 73 3a 78 6d 6c 3a 6e 73 3a 78 6d 70 70 2d 73 ms:xml:ns:xmpp-s

00e0 74 72 65 61 6d 73 22 2f 3e 3c 2f 73 74 72 65 61 treams"/></strea

00f0 6d 3a 65 72 72 6f 72 3e m:error>

Putting things together:

…E…/.@.@…g…c…A…zAb.J…w…Lw…<stream:stream xmlns:stream=’‘http://etherx.jabber.org/streams’’ xmlns=’‘http://jabberd.jabberstudio.org/ns/component/1.0’’ to=’‘localhost’’ version=’‘1.0’’>

…E…@.@…cAb.JA…w…Sw…L<?xml version=''1.0'' encoding=''UTF-8''?><stream:error xmlns:stream=“http://etherx.jabber.org/streams”></stream:error>

Also, noticed this in the Jive Messenger DEBUG logs once I turned on DEBUG:

2005.09.26 15:36:28 Connect Socket[addr=/127.0.0.1,port=46703,localport=5526]

… Why is there a SLASH preceeding the host ip?

So, we started looking at the script and dumping the data at different points to verify, with a debug switch we found also turned on:

perl bandersnatch2.pl

before dbi

after dbi

before xml::stream

after stream

All modules loaded

LOADED CONFIG BITCH

DBI::db=HASH(0x98ac3ec) trace level set to 0x0/2 (DBI @ 0x0/0) in DBI 1.48-ithread (pid 18310)

not well-formed (invalid token) at line 1, column 183, byte 183 at /usr/lib/perl5/site_perl/5.8.6/XML/SAX/Expat/Incremental.pm line 41

Server Error: read: 0 ->

server -> localhost

site -> 0

Connected to MySQL database (bandersnatch@localhost) …Socket error: read, 0,

We got disconneted

! -> DESTROY for DBD::mysql::db (DBI::db=HASH(0x98ac3ec)~INNER) thr#8ec2008

&imp_dbh->mysql: 98aca8c

! <- DESTROY= undef during global destruction

… This is pretty much where our troubleshooting abilities ended, since we, well, really had no idea where to look beyond this… we were thinking as we troubleshot:

  1. Server’‘s not liking something about the way bandersnatch component is connecting. Evidenced by logs in the server log screen, /var/log/messages, and bandersnatch’'s barfing. So, the connection actually happens, and then is severed. This is not a database error, as we had those previous and they were different, and ceased once we got things working. Verified by logging into mysql with the bandersnatch credentials.

  2. noticed the error being returned by the server using ethereal and netcat; marveled at how easy this error would have been to pass to the logs to be helpful; mused at that it was somehow not. Regardless, this means something in the format of the initial XML was not to Jive’'s liking.

  3. noticed DEBUG log function in Jive Messenger. Turned it on. Saw the leading slash in the IP. Thought “Maybe bandersnatch is misreading the config file, or parsing it incorrectly, leaving a leading slash before the IP (later we noticed that this would not be the case. see #4)”. So we started putting print statements and reading hashes at various points in the script before the socket connections were made. everything was correct. It was then that we realized…

  4. if bandersnatch tried connecting to ‘‘127.0.0.1’’ on ‘‘lo’’ as ‘’/127.0.0.1’’ it would never have worked… duh. not valid address. So… it was then that we theorized that somehow Jive Messenger is misinterpreting the connection from 127.0.0.1 as ‘’/127.0.0.1’’ – or is this just the way the debug log gets displayed? not sure. Moving on…

So… bandersnatch tries to connect, does, sends some XML, server doesn’'t like it, makes log entries, returns an error, then bandersnatch gives up its ghost.

Any ideas? I hope I’'ve included enough to go on…

Thanks,

-jre

Hey jre,

It seems that bandersnatch is not using url=http://www.jabber.org/jeps/jep-0114.htmlJEP-0114: Jabber Component Protocol[/url] to connect to the server. The server is expecting the namespace to be jabber:component:accept[/i] instead of http://jabberd.jabberstudio.org/ns/component/1.0[/i] as described in JEP-114.

Anyway, I think that bandersnatch is expecting the server to forward copies of the packets to the component. Jive Messenger does not currently have support for that though it would be quite easy to create a plugin for the required functionality. I created the issue JM-420 so you can now vote for it to raise its priority.

Regards,

– Gato

Thanks for the input! I also posted the same message to the bandersnatch email list, and then tried the previous version of bandersnatch - here’'s the one reply (thus far) and more info-- the previous version seems to format the request correctly using jabber:component:accept, yet it still dies… ideas?


lukasz.wiechec wrote:

Hi!

when XML declaration is produced? I think some servers does not like <?xml ...?>

string, maybe this is the problem?

On Tue, Sep 27, 2005 at 01:38:23PM -0700, joseph r. erlewein wrote:

Hi!

Well, see, the thing is the first section is what bandersnatch sends to the server. The second is Jive Messenger’‘s response… Since it’‘s Jive that is having the issue and sending back the <?xml ..?> junk with the error in it, I was hoping I’'d find something incorrectly configured on the bandersnatch side.

Yesterday after sending this, I decided to play around with an earlier version of bandersnatch, and here are the results:

perl bandersnatch

2005.09.27 15:08:06 org.jivesoftware.messenger.net.SocketReader.run(SocketReader.java:145) Connection closed before session established

Socket[addr=/127.0.0.1,port=35181,localport=5526]

Bandersnatch: (ERROR) Unable to connect to Jabber server (localhost) …

Bandersnatch: (HASH(0x8fdbd6c))

On the Jive Messenger side of things, here are the log entries:

2005.09.27 15:08:06 org.jivesoftware.messenger.net.SocketReader.run(SocketReader.java:145) Connection closed before session established

Socket[addr=/127.0.0.1,port=35181,localport=5526]

debug:

2005.09.27 15:08:06 Connect Socket[addr=/127.0.0.1,port=35181,localport=5526]

2005.09.27 15:08:06 Starting registration of new external component for domain: bandersnatch@ofsloans.com

!! note - this is a good sign! Something in the transaction at least made Jive recognize this as a component! I decided to look at the session list under the component section, and lo, there is a session defined, albeit a bit ‘‘incorrect’’ for the attempt:

Domain Name Category Type Creation Date Last Activity domain.com/699f3d04 null null null Sep 27, 2005 3:01:41 PM Dec 31, 1969 5:00:00 PM

Hm. Null creation name, type, and category. Last activity 1969!? hm. something is NOT smoothly flowing. Clicking on the domain name (clickable element):

Exception:

java.lang.NullPointerException

at org.jivesoftware.messenger.admin.component_002dsession_002ddetails_jsp._jspServ ice(component_002dsession_002ddetails_jsp.java:164)

at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:94)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)

at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:427)

at org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:822)

at org.jivesoftware.util.LocaleFilter.doFilter(LocaleFilter.java:43)

at org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:813)

at org.jivesoftware.util.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingF ilter.java:41)

at org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:813)

at org.jivesoftware.admin.AuthCheckFilter.doFilter(AuthCheckFilter.java:98)

at org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:813)

at org.mortbay.jetty.servlet.WebApplicationHandler.dispatch(WebApplicationHandler. java:494)

at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:569)

at org.mortbay.http.HttpContext.handle(HttpContext.java:1482)

at org.mortbay.jetty.servlet.WebApplicationContext.handle(WebApplicationContext.ja va:624)

at org.mortbay.http.HttpContext.handle(HttpContext.java:1434)

at org.mortbay.http.HttpServer.service(HttpServer.java:896)

at org.mortbay.http.HttpConnection.service(HttpConnection.java:814)

at org.mortbay.http.HttpConnection.handleNext(HttpConnection.java:981)

at org.mortbay.http.HttpConnection.handle(HttpConnection.java:831)

at org.mortbay.http.SocketListener.handleConnection(SocketListener.java:244)

at org.mortbay.util.ThreadedServer.handle(ThreadedServer.java:366)

at org.mortbay.util.ThreadPool$PoolThread.run(ThreadPool.java:534)

Here’'s the meat of the transaction, the tcpdump pasted back together. 0000 00 00 00 00 00 00 00 00 00 00 00 00 08 00 45 00 …E.

0010 01 01 54 6d 40 00 40 06 e7 87 7f 00 00 01 7f 00 …Tm@.@…

0020 00 01 c9 f8 15 96 27 78 b0 cb 26 f5 a9 7c 80 18 …''x…&…|…

0030 20 00 fe f5 00 00 01 01 08 0a 7b 61 e5 2c 7b 61 …{a.,{a

0040 e4 a3 3c 3f 78 6d 6c 20 76 65 72 73 69 6f 6e 3d …<?xml version=

0050 27 31 2e 30 27 3f 3e 3c 73 74 72 65 61 6d 3a 73 ‘‘1.0’’?><stream:s

0060 74 72 65 61 6d 20 76 65 72 73 69 6f 6e 3d 27 31 tream version=''1

0070 2e 30 27 20 78 6d 6c 6e 73 3a 73 74 72 65 61 6d .0’’ xmlns:stream

0080 3d 27 68 74 74 70 3a 2f 2f 65 74 68 65 72 78 2e =''http://etherx.

0090 6a 61 62 62 65 72 2e 6f 72 67 2f 73 74 72 65 61 jabber.org/strea

00a0 6d 73 27 20 78 6d 6c 6e 73 3d 27 6a 61 62 62 65 ms’’ xmlns=''jabbe

00b0 72 3a 63 6f 6d 70 6f 6e 65 6e 74 3a 61 63 63 65 r:component:acce

00c0 70 74 27 20 74 6f 3d 27 62 61 6e 64 65 72 73 6e pt’’ to=''bandersn

00d0 61 74 63 68 40 6f 66 73 6c 6f 61 6e 73 2e 63 6f atch@ofsloans.co

00e0 6d 27 20 66 72 6f 6d 3d 27 6c 6f 63 61 6c 68 6f m’’ from=''localho

00f0 73 74 2e 6c 6f 63 61 6c 64 6f 6d 61 69 6e 27 20 st.localdomain’’

0100 78 6d 6c 3a 6c 61 6e 67 3d 27 65 6e 27 20 3e xml:lang=‘‘en’’ >

And Again, combining:

…E…Tm@.@…‘‘x…&…|…{a.,{a…<?xml version=''1.0''?><stream:stream version=’‘1.0’’ xmlns:stream=‘‘http://etherx.jabber.org/streams’’ xmlns=‘‘jabber:component:accept’’ to=‘‘bandersnatch@domain.com’’ from=‘‘localhost.localdomain’’ xml:lang=‘‘en’’>

This was odd, as bandersnatch sent this, but then the Jive Messenger apparently didn’‘t say anything in response. There was a “timeout-like” delay in receiving the output from the bandersnatch execution after the first couple lines. It’'s like bandersnatch says “Hello” to Jive in this version, and Jive is waiting for something more, never gets is, and bandersnatch times out - are both waiting for some sort of reply?

Jive Messenger keeps a session placeholder open and alive for each time this is tried. At one point in my troubleshooting, there were six placeholders for the component. Each had the invalid last activity date, null fields as above, but different session numbers after the domain name.

I think, then, that Jive is working correctly as a component ‘‘receiver’’ - I wonder what bandersnatch is doing, or not doing, to cause this issue?

Or is this incorrect?

Thanks again,

-jre


Bandersnatch-funkypenguin.co.za mailing list

Bandersnatch-funkypenguin.co.za@lists.funkypenguin.co.za

http://lists.funkypenguin.co.za/listinfo.cgi/bandersnatch-funkypenguin.co.za

Hey jre,

The null values and the incorrect date are the consequence of the external component not fully connecting with the server. I’'m now fixing that so that the display would behave in a more appropriate way. Anyway, we still have to figure out why is bandersnatch not able to fully connect with the server.

One thing that you may want to check is that the domain that bandersnatch is using is a subdomain of the server. In other words, if the server is named “jivesoftware.com” then bandersnatch should use a domain like “bandersnatch.jivesoftware.com”. From the debug log I see that bandersnatch is using bandersnatch@ofsloans.com so try changing that and let me know how it goes.

However, remember that even if bandersnatch is able to fully connect to the server you won’'t be able to audit the packets since the server will not forward the packets to the external component. We need to implement the jira issue that I mentioned in the previous post.

Regards,

– Gato

Hm. I changed the domain like you said, but there doesn’'t seem to be any change in behaviour.

re: JIRA issue:

“Doh!” I thought that it only applied to a native Jive Messenger plugin - I figured if I got a component to do this that it would work. :confused:

Rats…

Who’'s writing the plugin/whatever? is there any way i could help?

-jre

jabberd2’'s component protocol is described here: http://jabberd.jabberstudio.org/dev/docs/component.shtml

The basic enhancements over JEP-0114 are: binding to more than one domain, binding/unbinding to domains after you’'re connected, binding as the default route, binding as a logger - i.e. receive a copy of every packet sent.

The protocol needs to be extended to support binding to namespaces too. i.e. Disco and PEP (JEP-0163). That way it becomes much easier to implement PEP without messing around with the server too much.