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:
- 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:
-
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.
-
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.
-
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…
-
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