[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: [xmlblaster] Re: Unable to connect



Hi Ralthor,

it seems the C clients mutex is too late:

  responseMutex is LOCKED

i'll look into it.
Which threading approach does RedHat use?

Thanks for reporting
Marcel


Ralthor wrote:

Thanks for getting back to me.

I set the redhat security level to no
firewall and I haven't installed any other firewalls so that should be fine.
Normally it is set up for a static IP
address on its own router, usually not connecting with anyone else. Although sometimes I reconfigure for DHCP and attach to a different
router so that I can get on the Internet with it and, say post logs. At glance (without doing a diff with all the dump logs) it appears to
do the same thing whether it is grabbing a static IP on its own little
network or on the web. I did all these test while set for DHCP and on
the Internet in case that makes a difference:


Launched the c Client
-----------------------------------------------------------------------------------------------------------------
[empred at localhost bin]$ ./HelloWorld3 -logLevel DUMP
[client] XmlBlaster 1.0.3 C SOCKET client, try option '-help' if you need usage
informations
[Mon Jun 20 09:43:51 2005 INFO
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
thread0x4004a4a0] Multi threaded callback delivery is activated with
-plugin/socket/multiThreaded true
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
thread0x4004a4a0] Created handle: -logLevel=DUMP
-plugin/socket/responseTimeout=60000
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
thread0x4004a4a0] Created XmlBlasterConnectionUnparsed
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterConnectionUnparsed.c
thread0x4004a4a0] Lookup xmlBlaster on
-dispatch/connection/plugin/socket/hostname localhost.localdomain
-dispatch/connection/plugin/socket/port 7607 ...
[Mon Jun 20 09:43:51 2005 INFO
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterConnectionUnparsed.c
thread0x4004a4a0] Connected to xmlBlaster
[Mon Jun 20 09:43:51 2005 INFO
/home/empred/xmlBlaster/build.tmp/src/c/socket/CallbackServerUnparsed.c
thread0x4004a4a0] Forced callback server to reuse socket
descriptor '3' on localHostname=127.0.0.1 localPort=32878
[Mon Jun 20 09:43:51 2005 INFO
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
thread0x4004a4a0] Created CallbackServerUnparsed instance, creating on
a separate thread a listener on socket://127.0.0.1:32878...
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/CallbackServerUnparsed.c
thread0x4084ad40] Reusing connection socket to tunnel callback
messages
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/CallbackServerUnparsed.c
thread0x4084ad40] Going to block on socket read until a
new message arrives ...
[xmlBlasterSocket] Blocking now for tcp callback messages ...
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
thread0x4004a4a0] initialize() successful
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
thread0x4004a4a0] Invoking connect()
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
thread0x4004a4a0] Connecting with qos=<qos> <securityService
type='htpasswd' version='1.0'> <![CDATA[ <user>fritz</user> <passwd>secret</passwd> ]]> </securityService><queue
relating='callback' maxEntries='50000' maxEntriesCache='10000'> <callback type='SOCKET' sessionId='topSecret'>
socket://127.0.0.1:32878 </callback></queue></qos>
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterConnectionUnparsed.c
thread0x4004a4a0] sendData(udp=false) requestId '0' increment to '1',
dataLen=308
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
thread0x4004a4a0] preSendEvent(connect) occurred
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/CallbackServerUnparsed.c
thread0x4004a4a0] addResponseListener(i=0, requestId=1)
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
thread0x4004a4a0] preSendEvent(requestId=1,
msgRequestInfoP->responseBlob.dataLen=0), entering lock
[xmlBlasterSocket] Sending now 339 bytes -> ' 339**I**11*connect**308*<qos> <securityService type='htpasswd'
version='1.0'> <![CDATA[ <user>fritz</user> <passwd>secret</passwd> ]]> </securityService><queue
relating='callback' maxEntries='50000' maxEntriesCache='10000'> <callback type='SOCKET' sessionId='topSecret'> socket://127.0.0.1:32878 </callback></queue></qos>'
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterConnectionUnparsed.c
thread0x4004a4a0] Lowlevel writing data to socket
...
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterConnectionUnparsed.c
thread0x4004a4a0] Lowlevel writing data to socket
done.
[Mon Jun 20 09:43:51 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
thread0x4004a4a0] postSendEvent(requestId=1) responseMutex is LOCKED,
entering wait ...
[xmlBlasterSocket] Receiving message of size 837 ...
[xmlBlasterSocket] Read 837 bytes from socket -> '837* 837**R**11*connect*sessionId:127.0.0.1-null-1119282232011-1731617154-3**
<qos>
<securityService type="htpasswd" version="1.0"><![CDATA[
<user>fritz</user>
<passwd>secret</passwd>
]]></securityService>
<session name='/node/xmlBlaster_127_0_0_1_3412/client/fritz/-2'
timeout='86400000' maxSessions='10' clearSessions='false'
reconnectSameClientOnly='false'
sessionId='sessionId:127.0.0.1-null-1119282232011-1731617154-3'/>
<queue relating='connection' maxEntries='10000000' maxEntriesCache='1000'>
<address type='IOR' dispatchPlugin='undef'>
</address>
</queue>
<queue relating='subject'/>
<queue relating='callback' maxEntries='50000' maxEntriesCache='10000'>
<callback type='SOCKET' sessionId='topSecret' dispatchPlugin='undef'>
socket://127.0.0.1:32878
</callback>
</queue>
</qos>**0*'
[Mon Jun 20 09:43:52 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/CallbackServerUnparsed.c
thread0x4084ad40] TCP arrived, success=true
[Mon Jun 20 09:43:52 2005 TRACE
/home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
thread0x4084ad40] responseEvent() responseMutex is LOCKED
---------------------------------------------------------------------------------------



Not sure how much of the server log you need, I decided no to include everything just to try to not make this message to much longer than it already is since I don't think it is server side, I figured anything important would happen after the client connected. Here are the warnings I got however:

-----------------------------------------------------------------------------------------
[empred at localhost xmlBlaster]$ java org.xmlBlaster.Main -trace[socket] true -cal
l[socket] true -dump[socket] true
Property: Loading xmlBlaster.properties from directory /home/empred
Property: No args array given.
Property: Added 3 property pairs
.....

[Jun 20, 2005 9:49:25 AM WARN  XmlBlaster.MainThread CorbaDriver-/node/xmlBlaste
r_127_0_0_1_3412.NoNameService] XmlBlasterException errorCode=[resource.configur
ation] serverSideException=true location=[CorbaDriver-/node/xmlBlaster_127_0_0_1
_3412.NoNameService] message=[#1.0.3 No CORBA naming service found - start <xmlB
laster/bin/ns ns.ior> and specify <-ORBInitRef NameService=...> if you want one.
: org.omg.CORBA.TRANSIENT: Retries exceeded, couldn't reconnect to 127.0.0.1:76
08  vmcid: 0x0  minor code: 0  completed: No] [See URL http://www.xmlblaster.org
/xmlBlaster/doc/requirements/admin.errorcodes.listing.html#resource.configuratio
n]

.....

[Jun 20, 2005 9:49:25 AM WARN  XmlBlaster.MainThread JdbcDriver-/node/xmlBlaster
_127_0_0_1_3412] Couldn't initialize driver <com.mckoi.JDBCDriver>, please check
your CLASSPATH

..

Jun 20, 2005 9:49:25 AM WARN  XmlBlaster.MainThread JdbcDriver-/node/xmlBlaster
_127_0_0_1_3412] Couldn't initialize driver <oracle.jdbc.driver.OracleDriver>, p
lease check your CLASSPATH
[Jun 20, 2005 9:49:25 AM WARN  XmlBlaster.MainThread JdbcDriver-/node/xmlBlaster
_127_0_0_1_3412] Couldn't initialize driver <com.microsoft.jdbc.sqlserver.SQLSer
verDriver>, please check your CLASSPATH

...

[Jun 20, 2005 9:49:25 AM WARN  XmlBlaster.MainThread JdbcDriver-/node/xmlBlaster
_127_0_0_1_3412] Couldn't initialize driver <de.sag.jdbc.adabasd.ADriver>, pleas
e check your CLASSPATH
[Jun 20, 2005 9:49:25 AM WARN  XmlBlaster.MainThread JdbcDriver-/node/xmlBlaster
_127_0_0_1_3412] Couldn't initialize driver <com.sybase.jdbc2.jdbc.SybDriver>, p
lease check your CLASSPATH
[Jun 20, 2005 9:49:25 AM WARN  XmlBlaster.MainThread JdbcDriver-/node/xmlBlaster
_127_0_0_1_3412] Couldn't initialize driver <SQLite.JDBCDriver>, please check yo
ur CLASSPATH
[Jun 20, 2005 9:49:25 AM WARN  XmlBlaster.MainThread HtPasswd] Security risk, no
access control: The passwd file is switched off with 'Security.Server.Plugin.ht
passwd.secretfile=NONE'
...

----------------------------------------------
[Jun 20, 2005 9:49:25 AM INFO XmlBlaster.MainThread
Main-/node/xmlBlaster_127_0_0_1_3412] | 1.0.3 06/17/2005 04:02 PM |
[Jun 20, 2005 9:49:25 AM INFO XmlBlaster.MainThread
Main-/node/xmlBlaster_127_0_0_1_3412] | READY - press <?> and <enter>
for options |
[Jun 20, 2005 9:49:25 AM INFO XmlBlaster.MainThread
Main-/node/xmlBlaster_127_0_0_1_3412] ----------------------------------------------
file sync interval: 59728
file sync: 5
---------------------------------------------------------------------------------------------------


Then it is ready for the connection.  I assume the warnings are just
that and hopefully
won't effect anything.  The first warning is the only one that worried
me, but when I looked it up on your site it sounded like it shouldn't
make a difference.  I Have the rest of the log saved so if the entire
thing would be helpful let me know and I will post it.

This is the log after I try and connect with the C client

---------------------------------------------------------------------------------------------------
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SocketDriver SocketExecutor]
responseTimeout=60000
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SocketDriver SocketExecutor]
SoTimeout=0
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SocketDriver SocketExecutor]
SoLingerTimeout=60000
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SocketDriver
SOCKET-HandleClient] -plugin/socket/threadPrio 5
[Jun 20, 2005 9:58:01 AM CALL XmlBlaster.SOCKET SOCKET-HandleClient]
Handling client request ...
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SOCKET SOCKET-HandleClient]
Client accepted, coming from host=/127.0.0.1 port=33072
[Jun 20, 2005 9:58:01 AM CALL XmlBlaster.SOCKET Parser] Entering parse()
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SOCKET Parser] Entering
readOneMsg(), waiting on inputStream
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SOCKET Parser] Got first 10
bytes of total length=339
[Jun 20, 2005 9:58:01 AM DUMP XmlBlaster.SOCKET Parser] Raw message
received '************I**11*connect**308*<qos> <securityService
type='htpasswd' version='1.0'> <![CDATA[ <user>fritz</user> <passwd>secret</passwd> ]]> </securityService><queue
relating='callback' maxEntries='50000' maxEntriesCache='10000'> <callback type='SOCKET' sessionId='topSecret'> socket://127.0.0.1:33072 </callback></queue></qos>'
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SOCKET Parser] Ignoring
given unzipped message length of size 308
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SOCKET Parser] Leaving
parse(), message successfully parsed
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SOCKET SOCKET-HandleClient]
Receiving message connect(1)
[Jun 20, 2005 9:58:01 AM DUMP XmlBlaster.SOCKET SOCKET-HandleClient]
Receiving message > 343**I**11*connect**308*<qos>
<securityService type='htpasswd' version='1.0'> <![CDATA[ <user>fritz</user> <passwd>secret</passwd> ]]>
</securityService><queue relating='callback' maxEntries='50000'
maxEntriesCache='10000'> <callback type='SOCKET'
sessionId='topSecret'> socket://127.0.0.1:33072 </callback></queue></qos>**0*<
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SOCKET SocketExecutor]
Receiving 'INVOKE' message connect(1)
[Jun 20, 2005 9:58:01 AM INFO XmlBlaster.SOCKET.tcpListener-fritz
SOCKET-HandleClient-fritz] Client connected, coming from
host=/127.0.0.1 port=33072
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SOCKET.tcpListener-fritz
SOCKET-HandleClient-fritz] remoteUrl='socket://127.0.0.1:33072'
cbUrl='socket://127.0.0.1:33072'
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SOCKET.tcpListener-fritz
SOCKET-HandleClient-fritz] Tunneling callback messages through same
SOCKET to 'socket://127.0.0.1:33072'
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SOCKET.tcpListener-fritz
SOCKET-HandleClient-fritz] run: register new callback driver:
'SOCKETsocket://127.0.0.1:33072'
[Jun 20, 2005 9:58:01 AM CALL XmlBlaster.SOCKET.tcpListener-fritz
CallbackSocketDriver-/node/xmlBlaster_127_0_0_1_3412] init()
[Jun 20, 2005 9:58:01 AM INFO XmlBlaster.SOCKET.tcpListener-fritz
DispatchConnection-callback:/node/xmlBlaster_127_0_0_1_3412/client/fritz/-2]
Connection 'SOCKET' transition UNDEF -> ALIVE: Success,
callback:/node/xmlBlaster_127_0_0_1_3412/client/fritz/-2 connected.
[Jun 20, 2005 9:58:01 AM INFO XmlBlaster.SOCKET.tcpListener-fritz
Authenticate-/node/xmlBlaster_127_0_0_1_3412] Successful login for
client /node/xmlBlaster_127_0_0_1_3412/client/fritz/-2, session
expires after [ 24 h 0 millis ], 1 of 10 sessions are in use.
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SOCKET.tcpListener-fritz
SocketExecutor]
TCP data is send
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SOCKET.tcpListener-fritz
SocketExecutor]
Successfully sent response for connect(1)
[Jun 20, 2005 9:58:01 AM DUMP XmlBlaster.SOCKET.tcpListener-fritz
SocketExecutor]
Successful sent response for connect() > 839**R**11*connect*sessionId:127.0.0.1-null-1119283081678--1680746555-3**
<qos>
<securityService type="htpasswd" version="1.0"><![CDATA[
<user>fritz</user>
<passwd>secret</passwd>
]]></securityService>
<session name='/node/xmlBlaster_127_0_0_1_3412/client/fritz/-2'
timeout='86400000' maxSessions='10' clearSessions='false'
reconnectSameClientOnly='false'
sessionId='sessionId:127.0.0.1-null-1119283081678--1680746555-3'/>
<queue relating='connection' maxEntries='10000000' maxEntriesCache='1000'>
<address type='IOR' dispatchPlugin='undef'>
</address>
</queue>
<queue relating='subject'/>
<queue relating='callback' maxEntries='50000' maxEntriesCache='10000'>
<callback type='SOCKET' sessionId='topSecret' dispatchPlugin='undef'>
socket://127.0.0.1:33072
</callback>
</queue>
</qos>**0*<
[Jun 20, 2005 9:58:01 AM CALL XmlBlaster.SOCKET.tcpListener-fritz
Parser] Entering parse()
[Jun 20, 2005 9:58:01 AM TRACE XmlBlaster.SOCKET.tcpListener-fritz
Parser] Entering readOneMsg(), waiting on inputStream
-------------------------------------------------------------------------------


Then we hang, looks like the connection got established:

[empred at localhost empred]$ lsof -i |grep 7607
java      4417 empred    5u  IPv4   9033       TCP
localhost.localdomain:7607 (LISTEN)
java      4417 empred   12u  IPv4   9034       TCP
localhost.localdomain:7607->localhost.localdomain:33072 (ESTABLISHED)
HelloWorl 4448 empred    3u  IPv4  12031       TCP
localhost.localdomain:33072->localhost.localdomain:7607 (ESTABLISHED)


[empred at localhost empred]$ netstat | grep 7607 tcp 0 0 localhost.localdom:7607 localhost.localdo:33072 ESTABLISHED tcp 0 0 localhost.localdo:33072 localhost.localdom:7607 ESTABLISHED

Then we get the time out:

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


[Jun 20, 2005 9:59:01 AM TRACE XmlBlaster.PingTimer SocketExecutor] Invoking parser type='INVOKE' message ping(requestId=fritz:1) oneway=false udp=false [Jun 20, 2005 9:59:01 AM DUMP XmlBlaster.PingTimer SocketExecutor] Sending now : > 35**I**1fritz:1*ping*****0*< [Jun 20, 2005 9:59:01 AM TRACE XmlBlaster.PingTimer SocketExecutor] TCP data is send [Jun 20, 2005 9:59:01 AM DUMP XmlBlaster.PingTimer SocketExecutor] Successful sent message: > 35**I**1fritz:1*ping*****0*< [Jun 20, 2005 10:00:01 AM WARN XmlBlaster.PingTimer DispatchConnection-callback:/node/xmlBlaster_127_0_0_1_3412/client/fritz/-2] Connection transition ALIVE -> DEAD: retryCounter=0, maxRetries=0 [Jun 20, 2005 10:00:01 AM CALL XmlBlaster.PingTimer CallbackSocketDriver-/node/xmlBlaster_127_0_0_1_3412] shutdown() [Jun 20, 2005 10:00:01 AM TRACE XmlBlaster.PingTimer SOCKET-HandleClient-fritz] Shutdown cb connection to fritz ... [Jun 20, 2005 10:00:01 AM TRACE XmlBlaster.PingTimer SOCKET-HandleClient-fritz] Closed socket for 'fritz'. [Jun 20, 2005 10:00:01 AM WARN XmlBlaster.PingTimer MsgErrorHandler-/node/xmlBlaster_127_0_0_1_3412/client/fritz/-2] Callback server is lost, killing login session of client callback:/node/xmlBlaster_127_0_0_1_3412/client/fritz/-2: XmlBlasterException errorCode=[communication.noConnection.dead] serverSideException=true location=[CallbackSocketDriver-/node/xmlBlaster_127_0_0_1_3412] message=[#1.0.3 SOCKET callback ping failed : errorCode=communication.noConnection message=#1.0.3 Callback ping failed : errorCode=communication.responseTimeout message=#1.0.3 Timeout of 60000 milliseconds occured when waiting on ping(fritz:1) response. You can change it with -plugin/socket/responseTimeout <millis>] [See URL http://www.xmlblaster.org/xmlBlaster/doc/requirements/admin.errorcodes.listing.html#communication.noConnection.dead] [Jun 20, 2005 10:00:01 AM INFO XmlBlaster.PingTimer Authenticate-/node/xmlBlaster_127_0_0_1_3412] Disconnecting client /node/xmlBlaster_127_0_0_1_3412/client/fritz/-2, instanceId=-2, secretSessionId=sessionId:127.0.0.1-null-1119283081678--1680746555-3 [Jun 20, 2005 10:00:01 AM INFO XmlBlaster.PingTimer SubjectInfo-3-/node/xmlBlaster_127_0_0_1_3412/client/fritz] Destroying SubjectInfo. Nobody is logged in and no queue entries available [Jun 20, 2005 10:00:01 AM TRACE XmlBlaster.SOCKET.tcpListener-fritz SOCKET-HandleClient-fritz] TCP socket '/127.0.0.1:33072' is shutdown: java.net.SocketException: Socket closed [Jun 20, 2005 10:00:01 AM TRACE XmlBlaster.SOCKET.tcpListener-fritz SOCKET-HandleClient-fritz] Closed socket for 'fritz'. [Jun 20, 2005 10:00:01 AM TRACE XmlBlaster.SOCKET.tcpListener-fritz SOCKET-HandleClient-fritz] Deleted thread for 'fritz'. [Jun 20, 2005 10:00:01 AM INFO XmlBlaster.PingTimer Authenticate-/node/xmlBlaster_127_0_0_1_3412] loginNameSubjectInfoMap has 2 entries and sessionInfoMap has 1 entries

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


I restarted everything and then did the kill before the timeout occured just in case that mattered, I am not exactly sure what I am looking for here though.

It gave this:

-------------------------------------------------------------------------------
Full thread dump Java HotSpot(TM) Client VM (1.4.2_08-b03 mixed mode):

"XmlBlaster.SOCKET.tcpListener-fritz" daemon prio=1 tid=0x08441100
nid=0x1180 runnable [4e5fb000..4e5fbd14]
       at java.net.SocketInputStream.socketRead0(Native Method)
       at java.net.SocketInputStream.read(SocketInputStream.java:129)
       at org.xmlBlaster.protocol.socket.Parser.readOneMsg(Parser.java:502)
       - locked <0x44e7d740> (a java.net.SocketInputStream)
       at org.xmlBlaster.protocol.socket.Parser.parse(Parser.java:565)
       at org.xmlBlaster.protocol.socket.HandleClient.run(HandleClient.java:302)
       at java.lang.Thread.run(Thread.java:534)

"XmlBlaster.PingTimer" daemon prio=1 tid=0x084926d0 nid=0x1180 in
Object.wait() [4e57b000..4e57bd94]
       at java.lang.Object.wait(Native Method)
       - waiting on <0x44e773c0> (a org.xmlBlaster.util.Timeout)
       at org.xmlBlaster.util.Timeout.run(Timeout.java:180)
       - locked <0x44e773c0> (a org.xmlBlaster.util.Timeout)

"XmlBlaster.MessageTimer" daemon prio=1 tid=0x0849c6a8 nid=0x1180 in
Object.wait()
[4e4fb000..4e4fbe14]
       at java.lang.Object.wait(Native Method)
       - waiting on <0x44e77430> (a org.xmlBlaster.util.Timeout)
       at org.xmlBlaster.util.Timeout.run(Timeout.java:180)
       - locked <0x44e77430> (a org.xmlBlaster.util.Timeout)

"Thread-4" daemon prio=1 tid=0x08499f38 nid=0x1180 runnable [4e47b000..4e47be94]
       at java.net.PlainSocketImpl.socketAccept(Native Method)
       at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:353)
       - locked <0x44e65570> (a java.net.PlainSocketImpl)
       at java.net.ServerSocket.implAccept(ServerSocket.java:448)
       at java.net.ServerSocket.accept(ServerSocket.java:419)
       at remotecons.SocketListener.run(SocketListener.java:146)

"XML-RPC Weblistener" prio=1 tid=0x08499348 nid=0x1180 runnable
[4e3fb000..4e3fbf14]
       at java.net.PlainSocketImpl.socketAccept(Native Method)
       at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:353)
       - locked <0x44e65698> (a java.net.PlainSocketImpl)
       at java.net.ServerSocket.implAccept(ServerSocket.java:448)
       at java.net.ServerSocket.accept(ServerSocket.java:419)
       at org.apache.xmlrpc.WebServer.run(Unknown Source)
       at java.lang.Thread.run(Thread.java:534)

"Thread-3" daemon prio=1 tid=0x08499698 nid=0x1180 in Object.wait()
[4e276000..4e277094]
       at java.lang.Object.wait(Native Method)
       - waiting on <0x44e657e0> (a java.lang.Object)
       at java.lang.Object.wait(Object.java:429)
       at org.jacorb.orb.giop.GIOPConnection.waitUntilConnected(GIOPConnection.java:219)
       - locked <0x44e657e0> (a java.lang.Object)
       at org.jacorb.orb.giop.GIOPConnection.getMessage(GIOPConnection.java:252)
       at org.jacorb.orb.giop.GIOPConnection.receiveMessages(GIOPConnection.java:363)
       at org.jacorb.orb.giop.MessageReceptor.doWork(MessageReceptor.java:53)
       at org.jacorb.util.threadpool.ConsumerTie.run(ConsumerTie.java:68)
       at java.lang.Thread.run(Thread.java:534)

"XmlBlaster.HttpIORServer" daemon prio=1 tid=0x08496030 nid=0x1180
runnable [4e37b000..4e37bf94]
       at java.net.PlainSocketImpl.socketAccept(Native Method)
       at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:353)
       - locked <0x44e658e0> (a java.net.PlainSocketImpl)
       at java.net.ServerSocket.implAccept(ServerSocket.java:448)
       at java.net.ServerSocket.accept(ServerSocket.java:419)
       at org.xmlBlaster.authentication.HttpIORServer.run(HttpIORServer.java:100)

"RequestController-2" daemon prio=1 tid=0x08441bd0 nid=0x1180 in
Object.wait() [4e2f6000..4e2f7014]
       at java.lang.Object.wait(Native Method)
       - waiting on <0x44e61d88> (a java.lang.Object)
       at java.lang.Object.wait(Object.java:429)
       at org.jacorb.poa.RequestController.waitForQueue(RequestController.java:602)
       - locked <0x44e61d88> (a java.lang.Object)
       at org.jacorb.poa.RequestController.run(RequestController.java:517)

"Thread-1" daemon prio=1 tid=0x0847f550 nid=0x1180 runnable [4e1f6000..4e1f7114]
       at java.net.PlainSocketImpl.socketAccept(Native Method)
       at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:353)
       - locked <0x44e61e00> (a java.net.PlainSocketImpl)
       at java.net.ServerSocket.implAccept(ServerSocket.java:448)
       at java.net.ServerSocket.accept(ServerSocket.java:419)
       at org.jacorb.orb.iiop.IIOPListener$Acceptor.run(IIOPListener.java:507)

"RequestController-1" daemon prio=1 tid=0x08482b68 nid=0x1180 in
Object.wait() [4e177000..4e177194]
       at java.lang.Object.wait(Native Method)
       - waiting on <0x44e61ee0> (a java.lang.Object)
       at java.lang.Object.wait(Object.java:429)
       at org.jacorb.poa.RequestController.waitForQueue(RequestController.java:602)
       - locked <0x44e61ee0> (a java.lang.Object)
       at org.jacorb.poa.RequestController.run(RequestController.java:517)

"XmlBlaster.SocketDriver" daemon prio=1 tid=0x0819cec0 nid=0x1180
runnable [4e0f7000..4e0f7214]
       at java.net.PlainSocketImpl.socketAccept(Native Method)
       at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:353)
       - locked <0x44e4f688> (a java.net.PlainSocketImpl)
       at java.net.ServerSocket.implAccept(ServerSocket.java:448)
       at java.net.ServerSocket.accept(ServerSocket.java:419)
       at org.xmlBlaster.protocol.socket.SocketDriver.run(SocketDriver.java:503)

"XmlBlaster.TopicTimer" daemon prio=1 tid=0x08471ab0 nid=0x1180 in
Object.wait() [4e077000..4e077294]
       at java.lang.Object.wait(Native Method)
       - waiting on <0x44e3c2e8> (a org.xmlBlaster.util.Timeout)
       at org.xmlBlaster.util.Timeout.run(Timeout.java:180)
       - locked <0x44e3c2e8> (a org.xmlBlaster.util.Timeout)

"XmlBlaster.SessionTimer" daemon prio=1 tid=0x08474ad0 nid=0x1180 in
Object.wait()
[4dff7000..4dff7314]
       at java.lang.Object.wait(Native Method)
       - waiting on <0x44e2b8e0> (a org.xmlBlaster.util.Timeout)
       at org.xmlBlaster.util.Timeout.run(Timeout.java:180)
       - locked <0x44e2b8e0> (a org.xmlBlaster.util.Timeout)

"Thread-0" daemon prio=1 tid=0x08158f20 nid=0x1180 in Object.wait()
[4df77000..4df77394]
       at java.lang.Object.wait(Native Method)
       - waiting on <0x44ce2db0> (a org.hsqldb.lib.HsqlTimer)
       at org.hsqldb.lib.HsqlTimer.nextTask(Unknown Source)
       - locked <0x44ce2db0> (a org.hsqldb.lib.HsqlTimer)
       at org.hsqldb.lib.HsqlTimer$TaskRunner.run(Unknown Source)
       at java.lang.Thread.run(Thread.java:534)

"Signal Dispatcher" daemon prio=1 tid=0x080a6ae8 nid=0x1180 waiting on
condition [0..0]

"Finalizer" daemon prio=1 tid=0x080921c8 nid=0x1180 in Object.wait()
[4c97f000..4c97f614]
       at java.lang.Object.wait(Native Method)
       - waiting on <0x44c6cf90> (a java.lang.ref.ReferenceQueue$Lock)
       at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
       - locked <0x44c6cf90> (a java.lang.ref.ReferenceQueue$Lock)
       at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
       at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=1 tid=0x08091620 nid=0x1180 in
Object.wait() [4c8ff000..4c8ff694]
       at java.lang.Object.wait(Native Method)
       - waiting on <0x44c6cff8> (a java.lang.ref.Reference$Lock)
       at java.lang.Object.wait(Object.java:429)
       at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:115)
       - locked <0x44c6cff8> (a java.lang.ref.Reference$Lock)

"XmlBlaster.MainThread" prio=1 tid=0x0805bdd0 nid=0x1180 runnable
[bfffb000..bfffbe78]
       at java.io.FileInputStream.readBytes(Native Method)
       at java.io.FileInputStream.read(FileInputStream.java:194)
       at java.io.BufferedInputStream.read1(BufferedInputStream.java:220)
       at java.io.BufferedInputStream.read(BufferedInputStream.java:277)
       - locked <0x44c6e3f8> (a java.io.BufferedInputStream)
       at sun.nio.cs.StreamDecoder$CharsetSD.readBytes(StreamDecoder.java:408)
       at sun.nio.cs.StreamDecoder$CharsetSD.implRead(StreamDecoder.java:450)
       at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:182)
       - locked <0x44e7d578> (a java.io.InputStreamReader)
       at java.io.InputStreamReader.read(InputStreamReader.java:167)
       at java.io.BufferedReader.fill(BufferedReader.java:136)
       at java.io.BufferedReader.readLine(BufferedReader.java:299)
       - locked <0x44e7d578> (a java.io.InputStreamReader)
       at java.io.BufferedReader.readLine(BufferedReader.java:362)
       at org.xmlBlaster.Main.checkForKeyboardInput(Main.java:304)
       at org.xmlBlaster.Main.init(Main.java:231)
       at org.xmlBlaster.Main.<init>(Main.java:109)
       at org.xmlBlaster.Main.main(Main.java:573)

"VM Thread" prio=1 tid=0x080903c0 nid=0x1180 runnable

"VM Periodic Task Thread" prio=1 tid=0x080a92e0 nid=0x1180 waiting on condition
"Suspend Checker Thread" prio=1 tid=0x080a6148 nid=0x1180 runnable

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

I couldn't remember if I used the SOCKET protocol when I first tested
the java client or not, so I ran HelloWorld4 with the socket protocol
and it went through everything fine.  It seems like there has to be
something on my end interferring with it, but I can't find it.  Before
I started working on it again thismorning I went through and disabled
all the services I didn't need, but that hasn't seemed to make a
difference.

I have no idea what these logs should look like.  So I'm hoping its
some stupid little thing I forgot to do that will pop out as obvious
to you guys.

Thanks for spending the time looking at them either way,
	Chris