CreamTec

AjaxSwing => Commercial Technical Support => : subes December 20, 2011, 08:16:30 AM

: ConnectException without any other clue
: subes December 20, 2011, 08:16:30 AM
Our production systems encounter the dreadful ConnectException again:

:
2011/12/15 14:51:42:932 : http-10.1.200.34-8080-6 : [com.creamtec.ajaxswing.ServletHelper] Failed to process a request for session = org.apache.catalina.session.StandardSessionFacade@593bdac8 (Exception java.rmi.ConnectException, Connection refused to host: 172.25.161.113; nested exception is:
java.net.ConnectException: Connection refused: connect)
java.rmi.ConnectException: Connection refused to host: 172.25.161.113; nested exception is:
java.net.ConnectException: Connection refused: connect
at sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:601)
at sun.rmi.transport.tcp.TCPChannel.createConnection(TCPChannel.java:198)
at sun.rmi.transport.tcp.TCPChannel.newConnection(TCPChannel.java:184)
at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:110)
at com.creamtec.ajaxswing.ClientAgentImpl_Stub.processHttpRequest(Unknown Source)
at com.creamtec.ajaxswing.ServletHelper.delegateRequestToClientAgent(ServletHelper.java:549)
at com.creamtec.ajaxswing.ServletHelper.doPocessHttpRequest(ServletHelper.java:381)
at com.creamtec.ajaxswing.ServletHelper.processHttpRequest(ServletHelper.java:293)
at com.creamtec.ajaxswing.AjaxSwingRouter.doPost(AjaxSwingRouter.java:141)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
at com.creamtec.ajaxswing.AjaxSwingRouter.service(AjaxSwingRouter.java:106)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:864)
at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:579)
at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1665)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
at java.net.Socket.connect(Socket.java:529)
at java.net.Socket.connect(Socket.java:478)
at java.net.Socket.<init>(Socket.java:375)
at java.net.Socket.<init>(Socket.java:189)
at sun.rmi.transport.proxy.RMIDirectSocketFactory.createSocket(RMIDirectSocketFactory.java:22)
at sun.rmi.transport.proxy.RMIMasterSocketFactory.createSocket(RMIMasterSocketFactory.java:128)
at sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:595)
... 23 more

We checked all the previous causes for this, like:
- 2 network interfaces where one is blocked by firewall
- System.exit() that closes the whole JVM instead of only one session
- OutOfMemory issues
- Filesystem has no space left
- clientAgent.sh not executable

The interesting thing is, that these problems occur on both load balanced servers at nearly the same time. The machines are not at all on high load. The users as it seems get error pages when trying to get new sessions. Already running sessions seem not to be affected. This currently occurs with our own version of the 3.2.3 release. The problem only occured some days ago and previously worked flawlessly for some time.

The logs can be downloaded here: https://www.zeta-uploader.com/558570766
The download will expire in 30 days.

Do you have any other ideas why this could occur?
: Re: ConnectException without any other clue
: subes December 20, 2011, 08:25:57 AM
Also checked for the license, this seems to be ok aswell with the following output:

:
2011/12/20 06:21:19:843 : main : [com.creamtec.ajaxswing.core.LicenseManager] Reading lic...
2011/12/20 06:21:19:843 : main : [com.creamtec.ajaxswing.core.LicenseManager] Initializing un
: Re: ConnectException without any other clue
: Dev Team December 21, 2011, 11:58:52 AM
For 20111220_loglevel6.zip logs are for December 20, while latest connection exceptions in ajaxswing.logs are from December 16

For system1_loglevel4.zip any logs (any requests) in first JVM are done 10 minutes before ConnectionException and second JVM is started after that, you're saying these errors occurs when user is trying to get new session? On guess here might be that old JVM is stopped since user session expired (no actions, even pings), and then user opens application again having old session cookie, so he gets to same server and it finds old JVM by session cookie and opens RMI connection resulting in connection refused since that JVM was already turned off. (what is your clientsPerJVM and session timeout value? does timeout match with time difference between requests?) But this should not happen since AjaxSwing would know that session expired and start new instead of connecting to old JVM.

Do you have any custom mechanisms for session handling? Is it possible that you close application by your own timeout and AjaxSwing for some time still thinks that JVM/instance is alive (your timeout smaller then AjaxSwing timeout)?

One case when you get ConnectionException without any additional logs during new session start is if there's not enough PermGen memory in JVM to start new session.
: Re: ConnectException without any other clue
: subes December 22, 2011, 12:04:06 PM
Those are our properties:
:
router.preloadWaitForApp=false
agent.appStartClass=<...>
router.retireJVMAfterClients=20
router.inProcess=false
router.clientsPerJVM=20
common.classPath=<...>
router.sessionTimeout=900
Timeout thus is 15 minutes and clientsPerJVM is 20.

We have no own mechanism for session timeouts or session handling. Only our System.exit() replacement that is invoked by user actions:
:
package de.bertelsmann.general;

import java.security.AccessControlException;

import org.apache.log4j.Logger;

import com.creamtec.ajaxswing.AjaxSwingManager;
import com.creamtec.ajaxswing.core.ClientAgent;

public class SystemExitHelper {

private SystemExitHelper() {
}

@SuppressWarnings("rawtypes")
public static void initSystemExit(Class caller, int status) {
Logger log = Logger.getLogger(caller);
log.info("Excecute system exit with status " + status);
if (AjaxSwingManager.isAjaxSwingRunning()) {
if ((ClientAgent.getCurrentInstance() == null)) {
throw new Error("System.exit hätte ausgeführt werden sollen, jedoch ist der ClientAgent schon heruntergefahren.");
} else {
try{
ClientAgent.getCurrentInstance().exit();
}catch(AccessControlException e){
//Siehe: http://creamtec.com/forums/index.php?topic=942.0
if(!"exitVM".equals(e.getPermission().getName())){
throw e;
}
}
}
} else {
System.exit(status);
}
}
}
This should be no problem, because AjaxSwings SecurityManager calls this himself aswell on a System.exit() catch. We introduced this, because the SecurityManager seemed to not be able to catch all System.exit() calls and thus JVM were shutdown completely. This problem aswell caused ConnectExceptions, but with different symptoms than we have now.
Another project with AjaxSwing 3.2.5_2 runs fine with that code currently, only our other project with 3.2.3 has problems with this right now.

About the PermGen memory, we have the following setting in clientAgent.bat:
:
set JVM_OPTS=-Xms512m -Xmx1024m -XX:MaxPermSize=256m %JVM_OPTS%Or do you mean the AjaxSwingRouter inside Tomcat has not enough PermGen?

We also made sure that enableJDK16.bat is executed on the target machine and the asboot.jar and ajaxswing.jar gets copied from ajaxswing/lib/ to WEB-INF/lib and our own client/lib. But the ConnectExceptions still occur there.
: Re: ConnectException without any other clue
: subes December 22, 2011, 12:15:43 PM
Just noticed that we changed ClientsPerJVM and RetireJVM parameters from 20 to 5 when we changed the loglevel from 4 to 6. Thus since 20.12.1011 we have this setting on 5 instead of 20.
: Re: ConnectException without any other clue
: subes December 22, 2011, 12:17:56 PM
I've uploaded a new batch of logs from today: https://www.zeta-uploader.com/1259506115
The download will expire in 30 days.
: Re: ConnectException without any other clue
: Dev Team December 23, 2011, 11:34:01 AM
Do you have any information from users on when they get it?
1) Where they working with application and error suddenly appeared?
2) Or, was it during new session request
3) Or, after doing some action after long waiting from previous action

Based on log it seems that ConnectionException happens between ending old JVM and starting new one. Not sure if ConnectionException is a reason for new JVM startup or caused by startup.

You were saying you were not getting these errors previously and last thing you changed was changing ClientsPerJVM from 20 to 5? Can you try ClientPerJVM=5, but RetireJVM=20? Seems like there might be a race condition during JVM retire when it happens same time as new JVM startup.

Did you change anything else before ConnectionException started to appear?
: Re: ConnectException without any other clue
: subes January 09, 2012, 06:04:33 AM
There was nothing particularly changed before the ConnectExceptions occured.

The settings currently are:
router.clientsPerJVM=5
router.retireJVMAfterClients=5

We changed it from 20/20 to 5/5 after the ConnectExceptions in this particular case started to emerge to maybe decrease the impact of the bug if it again causes the whole jvm to crash. Though this is not the case since now.

We tried to use 5/20 and 20/5 that you suggested and it changed nothing, the ConnectExceptions still occured.
We were unable to reproduce this yet on our testing machines.

With the information I got I can tell that users get this on 2) during new session request. Though I don't know if they previously closed their open session or restarted the browser. I would suspect it is the first case.
: Re: ConnectException without any other clue
: subes January 09, 2012, 07:25:42 AM
Maybe we have a change that could be the cause of this. Since 15.12.2011 we have the ConnectExceptions. Since 13.12.2011 we installed a script on both production servers that restarts tomcat on 03:00 am evey night.

Could it be the case that simply restarting tomcat leaves some ClientAgents running which somehow get reused later without being fully capable of something or getting killed later somehow? Have you encountered problems like this previously? Maybe it would be better to restart the servers instead of the tomcats?

Though this idea is quite vague, because the exceptions occur during the day, while the tomcats are restarted during night. This is quite a loose connection.
: Re: ConnectException without any other clue
: subes January 10, 2012, 10:52:48 AM
I was able to reproduce this with a stress test locally. The ConnectExceptions occur both with AjaxSwing 3.2.6 and AjaxSwing 3.2.3. I've done this with our application and 5 parallel test users sequencially logging in and out.

I am currently working on trying to isolate this problem into a sample, which was unsuccessful for now.
: Re: ConnectException without any other clue
: Dev Team January 10, 2012, 11:31:47 AM
Looking forward for a sample.

Script for server restart should not cause ConnectionException, even if it would, that should happen in next 2-3 minutes after restart because old ClientAgent would exit after that with timeout.
: Re: ConnectException without any other clue
: subes January 11, 2012, 08:08:06 AM
I was able to reproduce the problem in a sample. I've sent it to support@creamtec.com and to Alexander Ponomarenko who is familiar with our samples.

I am now experimenting with trying out some workarounds like disabling router.preloadApp.
: Re: ConnectException without any other clue
: subes January 12, 2012, 07:49:15 AM
Were you able to download the sample and reproduce the problem?

Here are the results of some workarounds I've tried:
1) Changing to router.preloadApp=false does not help.
2) The problem is also reproducible both with common.classPath and agent.classpath.
3) I've tried to change to router.inProcess=false which seems to help in the sample. This might be because ClientAgents don't get created in the first place and thus cannot eat up the memory. Though we cannot go with this workaround in our application because it is incompatible with this setting at the moment.
: Re: ConnectException without any other clue
: subes January 16, 2012, 08:21:43 AM
We were able to find a connection between the sample we've sent you and the problem we encountered in our production systems.
Here you can download the logs that show the ConnectExceptions on the 10.01.2012:
https://www.zeta-uploader.com/531935087

I've also attached the picture of the statistics of the memory usage on the machine on that day. The logs show that between 10:30 and 12:10 lots of ConnectExceptions occured. The statistics identically show that the memory usage is on its peak for that day during that time. Similarly to our sample, when the ConnectExceptions appear, lots of memory gets freed up in a short time.

Interesting about this is the fact, that the machine still had about 3GB of RAM left when the peak occured. This leads to the conclusion that it was not the machines memory limit that was reached (in our test environment our machines have only 3GB RAM, which is way less than our production machines have), but instead another one before that. We currently have the suspicion that the tomcat process suffers from not having enough max memory configured. Thus we are going to monitor our tomcat process to verify that.
: Re: ConnectException without any other clue
: subes January 16, 2012, 08:24:33 AM
I've also tested router.inProcess=false in a minimal stress test over the weekend. This was done with 3 parallel clients in a lighweight login-logout-test seperate from our application. After about 3 days, tomcat used up all the available memory and let sessions crash with OutOfMemoryExceptions. Thus using this setting as a workaround is impossible.
: Re: ConnectException without any other clue
: subes January 17, 2012, 06:00:25 AM
I've analyzed tomcat during a stress test. Interestingly the memory usage of tomcat is pretty low, but I've found a different interesting fact about the problem as it seems.

The screenshots show JVisualVM once at about 28 minutes of running the test and another time after stopping the test after 20 hours.

In the first screenshot it is visible in the process list on the left, that ClientAgents do not get shut down properly. They just linger around without being used anymore (those are quite much for only 3 clients, and they even got more during the test). Only when the machine reaches a specific memory limit, the JVMs get killed somehow (many at the same time). During the whole time, tomcat accumulates a lot of live threads that are not getting stopped. Visible in the second screenshot is that after 20 hours, tomcat has over 1000 live threads running.

Interesting about monitoring with JVisualVM is, that no ConnectExceptions occured during the test, even though JVMs got killed without the threads in tomcat getting stopped aswell.

Maybe this is a cleanup issue. Because it seems AjaxSwing leaves everything running without cleaning up after sessions.
: Re: ConnectException without any other clue
: subes January 17, 2012, 06:32:55 AM
Here are the screenshots showing JVisualVM
: Re: ConnectException without any other clue
: subes January 17, 2012, 06:36:19 AM
Instead of ConnectExceptions the following Exceptions occured:

:
2012/01/16 15:25:04:142 : main : Override beforeFirstWindowShown for Window failed (Exception java.lang.NoSuchFieldException, beforeFirstWindowShown)
java.lang.NoSuchFieldException: beforeFirstWindowShown
at java.lang.Class.getDeclaredField(Class.java:1854)
at com.creamtec.ajaxswing.core.ClientAgent.installToolkit(ClientAgent.java:1183)
at com.creamtec.ajaxswing.core.ClientAgent.<init>(ClientAgent.java:163)
at com.creamtec.ajaxswing.rendering.html.HTMLClientAgent.<init>(HTMLClientAgent.java:47)
at com.creamtec.ajaxswing.ServletHelper$InProcessClientAgent.<init>(ServletHelper.java:1012)
at com.creamtec.ajaxswing.ServletHelper.createClientAgent(ServletHelper.java:971)
at com.creamtec.ajaxswing.core.ClientAgentFactory.<init>(ClientAgentFactory.java:67)
at com.creamtec.ajaxswing.core.ClientAgentFactory.init(ClientAgentFactory.java:113)
at com.creamtec.ajaxswing.AjaxSwingRouter.init(AjaxSwingRouter.java:54)
at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1029)
at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:862)
at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4013)
at org.apache.catalina.core.StandardContext.start(StandardContext.java:4357)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:823)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:807)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:595)
at org.apache.catalina.core.StandardHostDeployer.install(StandardHostDeployer.java:277)
at org.apache.catalina.core.StandardHost.install(StandardHost.java:832)
at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:625)
at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:431)
at org.apache.catalina.startup.HostConfig.start(HostConfig.java:983)
at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:349)
at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:119)
at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1091)
at org.apache.catalina.core.StandardHost.start(StandardHost.java:789)
at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1083)
at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:478)
at org.apache.catalina.core.StandardService.start(StandardService.java:480)
at org.apache.catalina.core.StandardServer.start(StandardServer.java:2313)
at org.apache.catalina.startup.Catalina.start(Catalina.java:556)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:592)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:287)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:425)

:
2012/01/16 15:57:33:638 : http-8040-Processor22 : [com.creamtec.ajaxswing.ServletHelper] Failed to process a request for session = org.apache.catalina.session.StandardSessionFacade@185c0de (Exception java.util.ConcurrentModificationException)
java.util.ConcurrentModificationException
at java.util.Hashtable$Enumerator.next(Hashtable.java:1031)
at com.creamtec.ajaxswing.rendering.AbstractDocumentRenderer.initializeDocument(AbstractDocumentRenderer.java:111)
at com.creamtec.ajaxswing.rendering.html.HTMLPage.reset(HTMLPage.java:784)
at com.creamtec.ajaxswing.rendering.html.positioned.AjaxPage.reset(AjaxPage.java:450)
at com.creamtec.ajaxswing.rendering.AbstractDocument.setClientAgent(AbstractDocument.java:45)
at com.creamtec.ajaxswing.rendering.html.positioned.AjaxPage.setClientAgent(AjaxPage.java:479)
at com.creamtec.ajaxswing.core.ClientAgent.setHTMLPage(ClientAgent.java:707)
at com.creamtec.ajaxswing.core.ClientAgent.init(ClientAgent.java:211)
at com.creamtec.ajaxswing.ClientAgentImpl.init(ClientAgentImpl.java:62)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:305)
at sun.rmi.transport.Transport$1.run(Transport.java:159)
at java.security.AccessController.doPrivileged(Native Method)
at sun.rmi.transport.Transport.serviceCall(Transport.java:155)
at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:535)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
at sun.rmi.transport.StreamRemoteCall.exceptionReceivedFromServer(StreamRemoteCall.java:255)
at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:233)
at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:142)
at com.creamtec.ajaxswing.ClientAgentImpl_Stub.init(Unknown Source)
at com.creamtec.ajaxswing.ServletHelper.initNewAgent(ServletHelper.java:1110)
at com.creamtec.ajaxswing.ServletHelper.processHttpRequest(ServletHelper.java:290)
at com.creamtec.ajaxswing.AjaxSwingRouter.doPost(AjaxSwingRouter.java:141)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:709)
at com.creamtec.ajaxswing.AjaxSwingRouter.service(AjaxSwingRouter.java:106)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at sun.reflect.GeneratedMethodAccessor51.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:239)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAsPrivileged(Subject.java:517)
at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:268)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:157)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:50)
at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:140)
at java.security.AccessController.doPrivileged(Native Method)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:136)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:214)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:198)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:152)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:118)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:929)
at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:160)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:799)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:705)
at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:577)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683)
at java.lang.Thread.run(Thread.java:662)

:
2012/01/16 16:05:24:661 : http-8040-Processor16 : [com.creamtec.ajaxswing.ServletHelper] Failed to process a request for session = org.apache.catalina.session.StandardSessionFacade@2b2057 (Exception java.lang.NullPointerException)
java.lang.NullPointerException
at com.creamtec.ajaxswing.rendering.html.positioned.AjaxPageRenderer.redirectoToStandardPage(AjaxPageRenderer.java:146)
at com.creamtec.ajaxswing.rendering.html.HTMLClientAgent.handleRequestException(HTMLClientAgent.java:352)
at com.creamtec.ajaxswing.rendering.html.HTMLClientAgent.processHttpRequest(HTMLClientAgent.java:181)
at com.creamtec.ajaxswing.ClientAgentImpl.processHttpRequest(ClientAgentImpl.java:113)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:305)
at sun.rmi.transport.Transport$1.run(Transport.java:159)
at java.security.AccessController.doPrivileged(Native Method)
at sun.rmi.transport.Transport.serviceCall(Transport.java:155)
at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:535)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
at sun.rmi.transport.StreamRemoteCall.exceptionReceivedFromServer(StreamRemoteCall.java:255)
at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:233)
at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:142)
at com.creamtec.ajaxswing.ClientAgentImpl_Stub.processHttpRequest(Unknown Source)
at com.creamtec.ajaxswing.ServletHelper.delegateRequestToClientAgent(ServletHelper.java:549)
at com.creamtec.ajaxswing.ServletHelper.doPocessHttpRequest(ServletHelper.java:381)
at com.creamtec.ajaxswing.ServletHelper.processHttpRequest(ServletHelper.java:293)
at com.creamtec.ajaxswing.AjaxSwingRouter.doPost(AjaxSwingRouter.java:141)
at com.creamtec.ajaxswing.AjaxSwingRouter.doGet(AjaxSwingRouter.java:120)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:689)
at com.creamtec.ajaxswing.AjaxSwingRouter.service(AjaxSwingRouter.java:106)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at sun.reflect.GeneratedMethodAccessor51.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:239)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAsPrivileged(Subject.java:517)
at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:268)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:157)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:50)
at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:140)
at java.security.AccessController.doPrivileged(Native Method)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:136)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:214)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:198)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:152)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:118)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:929)
at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:160)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:799)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:705)
at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:577)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683)
at java.lang.Thread.run(Thread.java:662)

Though I would count this as negligible, because this does not occur in production and may be caused by the monitoring. Currently the ConnectExceptions interest us the most.

Here is the link for the whole log:
https://www.zeta-uploader.com/1855793509
: Re: ConnectException without any other clue
: subes January 17, 2012, 08:51:08 AM
Those are the screenshots with AjaxSwing 3.2.6. This time the ConnectExceptions occured despite being monitored with JVisualVM.
: Re: ConnectException without any other clue
: subes January 17, 2012, 08:52:38 AM
And those is the log for AjaxSwing 3.2.6 with the ConnectExceptions.
It can be downloaded here: https://www.zeta-uploader.com/921236895
: Re: ConnectException without any other clue
: subes January 19, 2012, 11:17:46 AM
I have written a monitoring tool that attaches itself to every jvm running and monitors its health. Also the tool monitors how many java processes are running at any given time.

The logs can be downloaded here:
https://www.zeta-uploader.com/1382932232

In ajaxswing.log it is visible, that ConnectExceptions occur at 16:57. In attachment.log it is visible that the JVMs reach their top during that time with about 50. The test was done with AjaxSwing 3.2.3.

Maybe the cleanup processes for killing JVMs should be run more often, so that JVMs never reach a critical count? It would be good to have JVMs being used up with their session limits eagerly and immediately getting them killed after being used up. With this approach, JVMs would not eat up so much RAM and maybe the ConnectExceptions would go away.
: Re: ConnectException without any other clue
: subes January 19, 2012, 11:19:47 AM
The logs for the individual processes are named as follows:

JVMProcess => ClientAgent
Bootstrap => Tomcat
RemoteTestRunner => Selenium Client
Main => Monitoring Tool
UNKNOWN => Eclipse
jar => Selenium Server
: Re: ConnectException without any other clue
: subes January 19, 2012, 11:22:30 AM
The individual logs can be most comfortably viewed with Excel, because it automatically aligns the columns according to the csv-delimiter "\t" for tab. See attached screenshot.
: Re: ConnectException without any other clue
: Dev Team January 19, 2012, 05:56:30 PM
There is no cleanup process to kill JVMs, JVMs are still running because they have live ClientAgent's in them, in our test we are able to get up to 100 JVMs running with no connection exceptions, for JVMs that are not closed - we see active ClientAgent in them.

You can try it by simply running the server, open first client - you'll see 2 files created in log folder, if you try to delete them - you will get message that files are in use, now close client, open new one. You will still get this message, but after you close client 4, new JVM will be started, you will see 2 new files and you can delete old 2 logs with no error message and you won't see that JVM process, it's closed instantly after 4 client agent exists.

What happens is test case for some reason not always closes ClientAgent, so you get high load of JVMs which leads to RMI failure and ConnectionException. We're still investigating why would it happen in sample test case, since if Firefox wasn't able to exist ClientAgent it should be still getting same client agent when it starts next run, so there shouldn't be more active JVM's then active test runners.

One note is that you have sessionTimeout = 3600, so if someone closed the browser, you'll have that ClientAgent and JVM up for 1 more hour. since it seems that RMI failure happens due to overload of JVMs, try to decrease session timeout, maybe to 5 minutes and enable keepAlive, so session won't expire if user have tab with your application opened in browser.
: Re: ConnectException without any other clue
: subes January 23, 2012, 06:36:43 AM
Thanks, I will try the session timeout setting. Though, our production Servers have a setting of
    router.sessionTimeout=1500
for 25 minutes and
    #window.*.session.keepAlive=true
which I expect defaults to false. The tomcat processes have a http session timeout setting of 30 minutes.
: Re: ConnectException without any other clue
: subes January 24, 2012, 07:01:51 AM
This night the stress test did not throw ConnectExceptions with the settings:
    router.sessionTimeout=300
    window.*.session.keepAlive=true
So this might be a candidate for a workaround. We will try if it helps on production systems.
: Re: ConnectException without any other clue
: subes January 24, 2012, 09:20:22 AM
About the keepAlive. For security reasons we need sessions to timeout after about 30 minutes even if the tab is open during that time. Thus we had set the session timeout in AjaxSwing to 25 minutes and in tomcat to 30 minutes.

:
See: http://www.chemaxon.com/jchem/doc/admin/tomcat.html

4. Setting session timeout
In web applications every user is identified by a session. The session holds information about the user. A typical example is an internet shop: the contents of your shopping cart is stored in a session.

To prevent the number of sessions to increase infinitely, they are destroyed after certain time of inactivity (time without changing the page) from the user. This is called session timeout. All user data stored in the session disappears (e.g. you have fill your shopping cart again).

Sometimes the default session timeout may be too low, especially when the user is expected to spend a lot of time on a single page. To increase the timeout value in Tomcat, please locate the following section in [Tomcat_home]/conf/web.xml:

    <session-config>
        <session-timeout>30</session-timeout>
    </session-config>

The timeout value is specified in minutes.
Restart Tomcat after modifying the file, so the changes can take effect.

With session keepalive in AjaxSwing, will the tomcat session still timeout after 30 minutes of inactivity or does the keepalive cause anything that makes tomcat reset the timeout counter periodically? How exactly is the keepalive implemented? In the tomcat documentation the session timeout is specified as "time without changing the page", though this is quite vague how it actually might behave with AjaxSwing.
: Re: ConnectException without any other clue
: Dev Team January 24, 2012, 09:30:57 AM
KeepAlive would generate Ajax request, so tomcat session would not timeout. In latest version of AjaxSwing we have a public API that allows application to manage session on it's own, you can use it to see if there were any user actions in past 30 minutes and if not - exit the application.

AjaxSwing would periodically "ping" server while application is opened in browser (including inactive tab), ping interval is configurable in properties file. Normal requests (like button click) would also generate KeepAliveEvent and reset interval time.
AjaxSwing provides 2 ways to handle KeepAliveEvents:
1) Polling ClientAgent.
In any place in your code you can call "getLastKeepAliveEvent" method that would return last event at the moment:
Code sample:
if(AjaxSwingManager.isAjaxSwingRunning()) {
   KeepAliveEvent event = ClientAgent.getCurrentInstance().getLastKeepAliveEvent();
   System.out.println("Last keep alive event date: " + event.getEventDate());
}
2) Callback.
You can add a listener that would be called each time new KeepAliveEvent occurs, this listener would also get HttpRequestData that provides access to data submitted from browser.
Code sample:
if(AjaxSwingManager.isAjaxSwingRunning()) {
   ClientAgent.getCurrentInstance().addKeepAliveEventHandler(new KeepAliveEventHandler() {         
      @Override
      public void handle(ClientAgent agent, HttpRequestData requestData, KeepAliveEvent event) {
         System.out.println("Keep Alive Occurred");
         System.out.println("Event date: " + event.getEventDate());
         System.out.println("Previous event date: " + event.getPreviousEvent().getEventDate());
         System.out.println("Event generated by user activity: " + event.isUserActivity());
         System.out.println("Event action: " + requestData.getAction());
      }
   });
}
In both cases you get KeepAliveEvent object that contains:
Date eventDate - Date when event was received by server.
KeepAliveEvent previousEvent - previous event (note that event.previousEvent.previousEvent would be null).
boolean userActivity - indicates if event was created because of user activity. Would be "true" when user clicks on a button, resizes browser etc, would be "false" on "ping" and "update" requests from browser.
KeepAlive configurations are stored in application properties (AjaxSwing/conf/app.properties):
# Enables keep alive mechanism when set to true
window.*.session.keepAlive = true
# Keep alive ping interval in seconds
window.*.session.keepAliveInterval = 60
You would also need to make sure that "router.sessionTimeout" value is bigger then your timeout, or AjaxSwing would force close application before it's timeout.
: Re: ConnectException without any other clue
: subes January 26, 2012, 05:33:02 AM
The following configuration worked this night aswell on an extensive stress test in our integration environment:

default.properties:
router.sessionTimeout=300
window.*.session.keepAlive=true
window.*.session.keepAliveInterval = 60

client.properties:
router.retireJVMAfterClients=20
router.clientsPerJVM=20
router.sessionTimeout=300

With AjaxSwing 3.2.6 we additionally have the following KeepAliveHandler registered in our clients main method:

:
public final class AjaxSwingKeepAliveManager {

private AjaxSwingKeepAliveManager() {
}

public static void registriere() {
if (AjaxSwingManager.isAjaxSwingRunning()) {
ClientAgent.getCurrentInstance().addKeepAliveEventHandler(new KeepAliveEventHandler() {
@Override
public void handle(ClientAgent clientAgent, HttpRequestData data, KeepAliveEvent event) {
if (event.isUserActivity()) {
Session.putAjaxSwingKeepAliveLastUserActivity(event.getEventDate());
} else {
Date lastUserActivity = Session.getAjaxSwingKeepAliveLastUserActivity();
boolean sessionTimeoutAbgelaufen;
if (lastUserActivity != null) {
int sessionTimeoutNachMinuten = GlobalProperties.getAjaxSwingHartesSessionTimeoutInMinuten();
Date timeoutAbgelaufen = org.apache.commons.lang.time.DateUtils.addMinutes(lastUserActivity,
sessionTimeoutNachMinuten);
sessionTimeoutAbgelaufen = new Date().after(timeoutAbgelaufen);
} else {
// Login wurde noch nicht vollzogen, also kann Session auch noch nicht ablaufen!
sessionTimeoutAbgelaufen = false;
}

if (sessionTimeoutAbgelaufen) {
SystemExitHelper.initSystemExit(AjaxSwingKeepAliveManager.class, 0);
}
}
}
});
}
}

}

It would be nice if you can find a solution to the real cause of the ConnectExceptions and fix it in an upstream version of AjaxSwing, instead of having users find and implement this workaround. We currently expect this workaround to only have made it less likely that the ConnectExceptions occur. Until the root cause is not identified and fixed, we have the risk of getting into this trap again with maybe more users on a single system or under other circumstances.
: Re: ConnectException without any other clue
: Dev Team January 26, 2012, 05:55:48 AM
It seems that the root cause it just RMI failing to perform on server with many live JVM's, we've seen similar results even on AjaxSwing 2.4 where allowing more clients per JVM appears to be more stable then more JVMs.

It might be that AjaxSwing performs to much RMI request, or RMI should be configured differently, we performed several tests with different parameters, but didn't notice significant changes.

We have some ideas on how this can be improved, including ideas like remove RMI completely, change role of AjaxSwing servlet to simple load-balance http requests to JVMs (with sticky sessions). But currently we're working on some major changes in rendering/updating in AjaxSwing 4.0 and planning to release first versions of AjaxSwing 4.0 during this/next week.
: Re: ConnectException without any other clue
: subes February 06, 2012, 07:10:51 AM
It seems that the ConnectExceptions still occur in production with the proposed fix of the lower session timeouts with keepalive.

In our integration environment the ConnectExceptions did not occur with the provided workaround. We are further investigating what difference still makes the bug occur in production.
: Re: ConnectException without any other clue
: subes February 22, 2012, 09:07:37 AM
It seems the main cause for the ConnectExceptions was some special RDP-Client (http://remotedesktopmanager.com/), which killed processes on logout. The RDP-Client won't be used anymore and thus the ConnectExceptions do not occur again.

Anyway, the workaround with the session timeouts should hinder ConnectExceptions to occur on high server load. The problem is thus fixed.