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

Re: [xmlblaster] Client connection not being restored properly?



David Kerry wrote:
Hello All,

I'm seeing some odd behaviour on one of my clients here and I'm
not sure if it's a bug, feature, or configuration problem. Client
and server are running the 1.6.2 version of code.
Hi David,

1. Why is secretSessionId invalid?
We would need to see the server log for this, possibly the session timed out.


2. Is the client connecting in fail safe mode?
  o With public session ID > 0:  -session.name spiderman_test/1
  o -dispatch/callback/retries -1

To detect going DEAD you can register xmlBlasterAccess.registerConnectionListener()
and react Kerry-like (see xmlBlaster/demo/HelloWorld4.java).


Still it would be good to know why the secret sessionId got invalid.

best regards
Marcel, Michele
Situation:

o client connects to the server and after some time, something
  marks the connection 'idle' or dead.

o client notices this and markes the connection state as 'dead'.

so far so good...

o further attempts by the client to publish succeed just fine,
  but get pushed into the save-queue to be published when the
  connection comes 'back' instead of actually re-initiating a
  connection to the server.  Basically the client sort of goes
  zombie on me - living dead :-)


Here's a relevant chunk of logging from the client side when this situation happens, just as it gets the reply from the server while attempting to publish a message:

Feb 22, 2008 2:36:02 PM org.xmlBlaster.client.protocol.socket.SocketCallbackImpl run
FINEST: Receiving message >      1757**E**1dummyLoginName:1203708962442000000*publish*sessionId:172.23.254.12-null-1203703214979--1091490067-10**user.security.authentication.accessDenied*XmlBlasterException errorCode=[user.security.authentication.accessDenied] serverSideException=true location=[Authenticate] message=[#exported Your secretSessionId is invalid, no access to spiderman_test. : ] [See URL http://www.xmlblaster.org/xmlBlaster/doc/requirements/admin.errorcodes.listing.html#user.security.authentication.accessDenied]*1248*user.security.authentication.accessDenied*spiderman_test*Authenticate*en*#exported Your secretSessionId is invalid, no access to spiderman_test.*version=1.6.2,revision=exported,os.name=Linux,os.version=2.4.20,java.vm.vendor=Sun Microsystems Inc.,java.vm.version=1.5.0_06-b05,os.arch=i386,build.timestamp=12/03/2007 03:42 PM,build.java.vendor=Sun Microsystems Inc.,build.java.version=1.4.2_06*2008-02-22 14:36:02.459*errorCode=user.security.authentication.accessDenied message=#exported Your secretSessionId is invalid, no access to spiderman_test.
        at org.xmlBlaster.authentication.Authenticate.check(Authenticate.java:852)
        at org.xmlBlaster.engine.XmlBlasterImpl.publishArr(XmlBlasterImpl.java:189)
        at org.xmlBlaster.util.protocol.RequestReplyExecutor.receiveReply(RequestReplyExecutor.java:408)
        at org.xmlBlaster.protocol.socket.HandleClient.handleMessage(HandleClient.java:231)
        at org.xmlBlaster.protocol.socket.HandleClient$1.run(HandleClient.java:389)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:665)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:690)
        at java.lang.Thread.run(Thread.java:595)**<transaction/>*true*<
, checksum=false, compressed=false, type=69, byte4=0, byte5=0, version=1, requestId=dummyLoginName:1203708962442000000, methodName=publish, sessionId=sessionId:172.23.254.12-null-1203703214979--1091490067-10
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.protocol.RequestReplyExecutor receiveReply
FINE: Receiving 'EXCEPTION' message publish(dummyLoginName:1203708962442000000)
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.protocol.RequestReplyExecutor removeResponseListener
FINE: removeResponseListener(dummyLoginName:1203708962442000000) done
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.protocol.RequestReplyExecutor$1 incomingMessage
FINE: RequestId=dummyLoginName:1203708962442000000: return value arrived ...
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.protocol.RequestReplyExecutor requestAndBlockForReply
FINE: Waking up, got response for publish(requestId=dummyLoginName:1203708962442000000)
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.protocol.RequestReplyExecutor requestAndBlockForReply
FINEST: Response for publish(dummyLoginName:1203708962442000000) is: errorCode=user.security.authentication.accessDenied message=#exported Your secretSessionId is invalid, no access to spiderman_test.
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.dispatch.DispatchConnectionsHandler removeDispatchConnection
FINER: connection:client/ejb_test1203703214006: removeDispatchConnection(ClientDispatchConnection-connection:client/ejb_test1203703214006) ...
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.dispatch.DispatchConnection shutdown
FINER: DispatchConnection-connection:client/ejb_test1203703214006 Entering shutdown ...
Feb 22, 2008 2:36:02 PM org.xmlBlaster.client.protocol.socket.SocketConnection shutdown
FINER: Entering shutdown of callback server
Feb 22, 2008 2:36:02 PM org.xmlBlaster.client.protocol.socket.SocketCallbackImpl shutdownSocket
FINE: Entering shutdownSocket()
Feb 22, 2008 2:36:02 PM org.xmlBlaster.client.protocol.socket.SocketConnection shutdown
FINE: InputStream.close(): java.net.SocketException: Socket is closed
Feb 22, 2008 2:36:02 PM org.xmlBlaster.client.protocol.socket.SocketConnection shutdown
FINE: OutputStream.close(): java.net.SocketException: Socket is closed
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.dispatch.DispatchConnectionsHandler removeDispatchConnection
FINE: connection:client/ejb_test1203703214006: Destroyed one callback connection, 0 remain.
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.dispatch.DispatchConnectionsHandler updateState
FINE: connection:client/ejb_test1203703214006: updateState() oldState=ALIVE conList.size=0
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.dispatch.DispatchManager shutdownFomAnyState
FINER: connection:client/ejb_test1203703214006: Switch from ALIVE to DEAD
Feb 22, 2008 2:36:02 PM org.xmlBlaster.client.XmlBlasterAccess toDead
FINER: client/ejb_test/-42: Changed from connection state ALIVE to DEAD connectInProgress=false
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.dispatch.DispatchManager givingUpDelivery
FINE: connection:client/ejb_test1203703214006: Entering givingUpDelivery(), state is DEAD
Feb 22, 2008 2:36:02 PM org.xmlBlaster.client.ClientErrorHandler handleError
FINER: Entering handleError for 0 messages
Feb 22, 2008 2:36:02 PM org.xmlBlaster.client.protocol.socket.SocketCallbackImpl run
FINE: Terminating socket callback thread
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.dispatch.DispatchManager shutdown
FINER: connection:client/ejb_test1203703214006: Entering shutdown ...
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.dispatch.DispatchConnectionsHandler shutdown
FINER: connection:client/ejb_test1203703214006: Entering shutdown ...
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.dispatch.DispatchManager handleSyncWorkerException
FINER: connection:client/ejb_test1203703214006: Sync delivery failed connection state is DEAD: errorCode=communication.noConnection.dead message=#exported Your secretSessionId is invalid, no access to spiderman_test. : O
riginal erroCode=user.security.authentication.accessDenied
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.dispatch.DispatchManager checkSending
FINE: connection:client/ejb_test1203703214006: The dispatcher is shutdown, can't activate callback worker thread
 <DispatchManager id='connection:client/ejb_test1203703214006' numEntries='0' isShutdown='true'>
  <DispatchConnectionsHandler state='DEAD'>
   <noDispatchConnection/>
  </DispatchConnectionsHandler>
  <dispatchWorkerIsActive>false</dispatchWorkerIsActive>
 </DispatchManager>
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.dispatch.DispatchManager switchToASyncMode
INFO: connection:client/ejb_test1203703214006: Switched to asynchronous message delivery
Feb 22, 2008 2:36:02 PM org.xmlBlaster.client.dispatch.ClientDispatchConnectionsHandler createFakedReturnObjects
FINER: Entering createFakedReturnObjects() for 1 entries
Feb 22, 2008 2:36:02 PM org.xmlBlaster.client.dispatch.ClientDispatchConnectionsHandler createFakedReturnObjects
FINE: Creating faked return for 'publish' invocation
Feb 22, 2008 2:36:02 PM org.xmlBlaster.util.dispatch.DispatchManager handleSyncWorkerException
FINE: connection:client/ejb_test1203703214006: Delivery failed, pushed 1 entries into tail back queue
Feb 22, 2008 2:36:02 PM org.xmlBlaster.client.XmlBlasterAccess queueMessage
FINE: client/ejb_test/-42: Forwarded one 'publish' message, current state is DEAD
Feb 22, 2008 2:36:59 PM org.xmlBlaster.util.dispatch.DispatchConnection finalize
FINE: DispatchConnection-connection:client/ejb_test1203703214006 finalize - garbage collected
Feb 22, 2008 2:36:59 PM org.xmlBlaster.util.queuemsg.MsgQueueEntry finalize
FINE: finalize - garbage collect

At this point, the client is still running, but it never reconnects back to
the server, regardless of how many publish() calls are made - the messages are
effectively lost in the client-side queue now.

Is this a bug, or a configuration issue or is there some method I
should be calling to 'kick' the connection back up and allow the queued
messages to get published to the server?



--
Marcel Ruff
http://www.xmlBlaster.org
http://watchee.net
Phone: +49 7551 309371