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

Re: [xmlblaster] Unable to connect



Hi Ralthor,

here are some steps to track it down:

1/ Test the C client:

cd xmlBlaster
 build c

cd xmlBlaster/demo/c/socket/bin
HelloWorld3 -logLevel DUMP


2/ Then try to switch on more traces for the server:

java org.xmlBlaster.Main -trace[socket] true -call[socket] true -dump[socket] true

3/ During the client hangs: Check if the connection is established

# lsof -i | grep 7607
java 8537 xmlblast 7u IPv6 24871 TCP noty.site:7607 (LISTEN)
java 8537 xmlblast 15u IPv6 25293 TCP noty.site:7607->noty.site:13413 (ESTABLISHED)
Subscribe 8686 xmlblast 3u IPv4 25338 TCP noty.site:13413->noty.site:7607 (ESTABLISHED)


or

# netstat | grep 7607
tcp 0 0 noty.site:29105 noty.site:7607 ESTABLISHED
tcp 0 0 noty.site:7607 noty.site:29105 ESTABLISHED



4/ During the client hangs please do a

 killall -3 java    (or Ctrl-Break on Windows)

and look at the stack trace of the server, where does the java thread block?


Do you have any special firewall installed?

Regards,
Marcel


Ralthor wrote:

I have been playing with XMLBlaster on windows for a couple weeks, but
decided to switch to Linux.  Spec:

Red hat 9, Linux 2.40.20, gcc 3.2.2, XMLBlaster 1.0.3, Xerces 2.6.0

It compiled fine, the java server and client demos run fine, but when
I try and run any of the c++ demos it won't connect to the server.  It
says it successfully connected, but just hangs.  I ran a trace to try
and track down why it wouldn't go any further, but couldn't figure it
out.  This is what I get when it tries to connect:

----------------------------------------
INFO  XmlBlasterAccess-client/empred Callback settings: type=CACHE
onOverflow=deadMessage onFailure=deadMessage maxEntries=1000
type=SOCKET oneway=false burstMode.collectTime=0
TRACE XmlBlasterAccess-client/empred ::connect. CbServer done
TRACE ClientQueueProperty ::initialized to:
<!-- QueuePropertyBase -->
<queue relating='connection' storeSwapLevel='1468006'
storeSwapBytes='524288' reloadSwapLevel='629145'
reloadSwapBytes='524288'/>
TRACE XmlBlasterAccess-client/empred ::connect. connectQos:
<qos>
 <securityService type="htpasswd" version="1.0">
  <![CDATA[
  <user>joe</user>
  <passwd>secret</passwd>
  ]]>
 </securityService>
 <ptp>true</ptp>
 <session name='client/joe' timeout='86400000' maxSessions='10'
clearSessions='false' reconnectSameClientOnly='false'/>

 <!-- QueuePropertyBase -->
 <queue relating='connection' storeSwapLevel='1468006' storeSwapBytes='524288'
reloadSwapLevel='629145' reloadSwapBytes='524288'>
  <address type='SOCKET' bootstrapHostname='127.0.0.1'>
     socket://127.0.0.1:3412
  </address>
 </queue>
 <!-- QueuePropertyBase -->
 <queue relating='callback' storeSwapLevel='1468006'
storeSwapBytes='524288' reloadSwapLevel='629145'
reloadSwapBytes='524288'>
  <callback type='SOCKET' bootstrapHostname='127.0.0.1'>
     socket://127.0.0.1:34696
  </callback>
 </queue>
</qos>
TRACE ConnectionsHandler-1119036246593028000 connect: number of
retries during communication failure: -1
TRACE ConnectionsHandler-1119036246593028000 connect: Ping Interval: 10000
TRACE DispatchManager getPlugin: type: 'SOCKET', version: '1.0' for
instance '1119036246593028000'
TRACE SocketDriverFactory number of instances for '0x80e0fa0' are 1
TRACE /home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
Invoking connect()
TRACE /home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
Connecting with qos=
<qos>
 <securityService type="htpasswd" version="1.0">
  <![CDATA[
  <user>joe</user>
  <passwd>secret</passwd>
  ]]>
 </securityService>
 <ptp>true</ptp>
 <session name='client/joe' timeout='86400000' maxSessions='10'
clearSessions='false' reconnectSameClientOnly='false'/>

 <!-- QueuePropertyBase -->
 <queue relating='connection' storeSwapLevel='1468006' storeSwapBytes='524288'
reloadSwapLevel='629145' reloadSwapBytes='524288'>
  <address type='SOCKET' bootstrapHostname='127.0.0.1'>
     socket://127.0.0.1:3412
  </address>
 </queue>
 <!-- QueuePropertyBase -->
 <queue relating='callback' storeSwapLevel='1468006'
storeSwapBytes='524288' reloadSwapLevel='629145'
reloadSwapBytes='524288'>
  <callback type='SOCKET' bootstrapHostname='127.0.0.1'>
     socket://127.0.0.1:34696
  </callback>
 </queue>
</qos>
TRACE /home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterConnectionUnparsed.c
sendData(udp=false) requestId '0' increment to '1', dataLen=838
TRACE /home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
preSendEvent(connect) occurred
TRACE /home/empred/xmlBlaster/build.tmp/src/c/socket/CallbackServerUnparsed.c
addResponseListener(i=0, requestId=1)
TRACE /home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
preSendEvent(requestId=1, msgRequestInfoP->responseBlob.dataLen=0),
entering lock
TRACE /home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterConnectionUnparsed.c
Lowlevel writing data to socket ...
TRACE /home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterConnectionUnparsed.c
Lowlevel writing data to socket done.
TRACE /home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
postSendEvent(requestId=1) responseMutex is LOCKED, entering wait ...
TRACE /home/empred/xmlBlaster/build.tmp/src/c/socket/CallbackServerUnparsed.c
TCP arrived, success=true
TRACE /home/empred/xmlBlaster/build.tmp/src/c/socket/XmlBlasterAccessUnparsed.c
responseEvent() responseMutex is LOCKED

---------------------------------------
at this point it hangs and I can't do anything. It never goes any
further, closing the server doesn't even send any information to it. Finally I just have to kill the process.


I also traced the server and got this at the same time:
-----------------------------------------------------
[Jun 17, 2005 1:27:42 PM INFO  XmlBlaster.SOCKET.tcpListener-joe
Authenticate-/node/xmlBlaster_127_0_0_1_3412] Successful login for
client /node/xmlBlaster_127_0_0_1_3412/client/joe/-2, session expires
after [ 24 h 0 millis ], 1 of 10 sessions are in use.
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
SessionQos] initialize
session.name=/node/xmlBlaster_127_0_0_1_3412/client/empred nodeId=null
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
QueuePropertyBase] Lookup of nodeId=xmlBlaster_127_0_0_1_3412
context=null getRootTagName=queue relating=connection propName=
defaultValue=CACHE,1.0
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
QueuePropertyBase] Initialized:
<queue relating='connection' maxEntries='10000000' maxEntriesCache='1000'/>
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
AddressBase] type=IOR nodeId=null context=null className=dispatch
instanceName=connection envPrefix=plugin/ior/
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
AddressBase] setRawAddress=socket://127.0.0.1:3412
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
QueuePropertyBase] Lookup of nodeId=xmlBlaster_127_0_0_1_3412
context=null getRootTagName=queue relating=subject propName=
defaultValue=CACHE,1.0
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
QueuePropertyBase] Initialized:
<queue relating='subject'/>
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
CbQueueProperty] Created CbQueueProperty subject
xmlBlaster_127_0_0_1_3412
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
QueuePropertyBase] Lookup of nodeId=xmlBlaster_127_0_0_1_3412
context=null getRootTagName=queue relating=callback propName=
defaultValue=CACHE,1.0
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
QueuePropertyBase] Initialized:
<queue relating='callback' maxEntries='1000' maxEntriesCache='1000'/>
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
CbQueueProperty] Created CbQueueProperty callback
xmlBlaster_127_0_0_1_3412
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListenewent wrong,
any help would be appreciated.r-joe AddressBase] type=IOR nodeId=null
context=null className=dispatch instanceName=callback
envPrefix=plugin/ior/
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
AddressBase] setRawAddress=socket://127.0.0.1:34747
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
SocketExecutor] TCP data is send
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
SocketExecutor] Successfully sent response for connect(1)
[Jun 17, 2005 1:27:42 PM TRACE XmlBlaster.SOCKET.tcpListener-joe
Parser] Entering readOneMsg(), waiting on inputStream
--------------------------------------------------
It then sits there for a couple minutes and then outputs:
--------------------------------------------------


file sync interval: 59709 file sync: 2 [Jun 17, 2005 1:28:38 PM TRACE XmlBlaster.PingTimer DispatchConnection-callback:/node/xmlBlaster_127_0_0_1_3412/client/__sys__jdbc/-1] timeout -> Going to ping remote server, physicalConnectionOk=true, serverAcceptsRequests=true ... [Jun 17, 2005 1:28:38 PM TRACE XmlBlaster.PingTimer DispatchConnection-callback:/node/xmlBlaster_127_0_0_1_3412/client/__sys__jdbc/-1] Success for ping(''), return='<qos><state id='OK'/></qos>' [Jun 17, 2005 1:28:38 PM TRACE XmlBlaster.PingTimer DispatchConnection-callback:/node/xmlBlaster_127_0_0_1_3412/client/__sys__jdbc/-1] Connection transition ALIVE -> toReconnected=true byDispatchConnectionsHandler=false: [Jun 17, 2005 1:28:42 PM TRACE XmlBlaster.PingTimer DispatchConnection-callback:/node/xmlBlaster_127_0_0_1_3412/client/joe/-2] timeout -> Going to ping remote server, physicalConnectionOk=true, serverAcceptsRequests=true ... [Jun 17, 2005 1:28:42 PM TRACE XmlBlaster.PingTimer SocketExecutor] Invoking parser type='INVOKE' message ping(requestId=joe:1) oneway=false udp=false [Jun 17, 2005 1:28:42 PM TRACE XmlBlaster.PingTimer SocketExecutor] TCP data is send



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


I thought maybe there was some problem with the SOCKET protocol so I installed omniORB 4.0.6, configured it, compiled it fine, but again when I try to run HelloWorld (or any c++ client that tries to connect to the server) it hangs after saying it connected.

here is the trace from the one using omniOrb:
--------------------------------------

INFO  ConnectionsHandler-1118958657481842000 successfully connected
with sessionId = 'IIOP:00141607050C010B014D10'
INFO  HelloWorld2 reconnected
TRACE ConnectionsHandler-1118958657481842000 startPinger (no request
to stop the pinger is active for the moment)
TRACE ConnectionsHandler-1118958657481842000
startPinger(status=ALIVE): parameters are: delay '5000' and
pingInterval '10000
TRACE Global ::getPingTimer: creating the singleton 'ping timer'
TRACE Timeout-ping timer-0x8107ff0  before creating the running thread
TRACE Timeout-ping timer-0x8107ff0  run(): is running
TRACE Timeout-ping timer-0x8107ff0 No timer is registered, nothing to do
TRACE Timeout-ping timer-0x8107ff0 sleeping ... 100000 milliseconds
TRACE Timeout-ping timer-0x8107ff0  start: waiting for the thread to
be ready (waiting for the first timeout addition)
TRACE Timeout-ping timer-0x8107ff0  start: running thread created and ready
TRACE Timeout-ping timer-0x8107ff0  default constructor: after
starting the thread
TRACE Timeout-ping timer-0x8107ff0 addTimeoutListener, adding key:
1118958667911737000
TRACE Timeout-ping timer-0x8107ff0 addTimeoutListener, going to notify

-------------------------------------
Then same thing it hangs.

I can't figure out what is going wrong, any help would be appreciated.


Thanks