2016-02-06 23:41 GMT+01:00 Shawn McKinney <smckin...@apache.org>:
>
> > On Feb 6, 2016, at 1:53 PM, Jan Sindberg <jan.sindb...@gmail.com> wrote:
> >
> > When an application such as Fortress Commander is left inactive for
> hours -
> > all connections in the connection pool is closed (timed out ?). But for
> > each connection there is a 30 sec. timeout before the conclusion that the
> > connection is dead. With 10 connections that is a five minutes wait for
> the
> > first "unknowing victim" and an application-log with ten equal logs
> > including stack trace.
>
> A connection sometimes times out inside the client connection pool, on the
> server-side, or within the intermediaries (firewalls). First thing we’ll
> need is the stack trace and your fortress.properties, with necessary
> redactions of course, in order to (try and) pinpoint the root cause.
>
> >
> > On Feb 6, 2016, at 1:53 PM, Jan Sindberg <jan.sindb...@gmail.com> wrote:
> >
> > How are you dealing with this in your systems?
> > Can I configure this differently from Fortress or in ApacheDS?
> > Could we make Fortress be a little faster realising that the connection
> > pool needs to be "refreshed"?
> > I guess the issue could be simulated by restarting ApacheDS (I haven't
> > tested this yet) - that should break whatever open connections there we.
>
> There are settings in the client-side pooling mechanism that affect this
> behavior. There are code changes that can be made. There are settings on
> the server. But first we must understand why it’s happening in your tests.
>
> Just to be clear - what you're describing here is very bad behavior for an
> application to have, and deserves serious attention from us. To put it
> simply, it’s a show-stopper.
>
> Just now, I ran a couple of tests inside my local env. Using openldap as
> the server, and a max idle timeout of 30 seconds. After 30 seconds of
> inactivity, slapd will forcefully terminate any connections being held open
> by a client. I also had fortress web deployed to tomcat.
>
> First I restarted slapd daemon with open browser session logged into the
> app. Next I left the web session open for around 10 minutes.
>
> Neither test case resulted in a failure. For my tests, the ldap
> connection pool managed to recover.
>
> I need to re-run the same tests using ApacheDS server, and will will once
> I learn how to set its max idle timeout.
>
> But, just because I can’t recreate your issue inside my local env doesn’t
> tell us much. The good news, once we’ve got repeatable steps to recreate,
> this problem ought to get solved quickly.
>
> Thanks for reporting it,
>
> Shawn
>
To be clear, eventually, after 10 failed connections (five minutes), the
pool will recover.
The application might be idle over night. Then the first person trying to
use it will experience the long wait. Interestingly, I could not duplicate
this for Fortress Commander today, which points in the direction that it is
something on our own servers.
The log goes like this:
2016-02-06 13:07:26,485 ERROR
[org.apache.directory.ldap.client.api.LdapNetworkConnection]
Thread='http-0.0.0.0-14880-7' Bind failed : timeout occurred
2016-02-06 13:07:26,485 ERROR
[org.apache.directory.ldap.client.api.LdapNetworkConnection]
Thread='http-0.0.0.0-14880-7' The response queue has been emptied, no
response was found.
org.apache.directory.api.ldap.model.exception.LdapException: TimeOut
occurred
at
org.apache.directory.ldap.client.api.LdapNetworkConnection.bind(LdapNetworkConnection.java:1198)
at
org.apache.directory.ldap.client.api.AbstractLdapConnection.bind(AbstractLdapConnection.java:127)
at
org.apache.directory.ldap.client.api.AbstractLdapConnection.bind(AbstractLdapConnection.java:112)
at
org.apache.directory.ldap.client.api.MonitoringLdapConnection.bind(MonitoringLdapConnection.java:112)
at
org.apache.directory.ldap.client.api.DefaultLdapConnectionFactory.bindConnection(DefaultLdapConnectionFactory.java:64)
at
org.apache.directory.ldap.client.api.AbstractPoolableLdapConnectionFactory.activateObject(AbstractPoolableLdapConnectionFactory.java:60)
at
org.apache.directory.ldap.client.api.ValidatingPoolableLdapConnectionFactory.activateObject(ValidatingPoolableLdapConnectionFactory.java:111)
at
org.apache.directory.ldap.client.api.ValidatingPoolableLdapConnectionFactory.activateObject(ValidatingPoolableLdapConnectionFactory.java:55)
at
org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1204)
at
org.apache.directory.ldap.client.api.LdapConnectionPool.getConnection(LdapConnectionPool.java:123)
at
org.apache.directory.fortress.core.ldap.ApacheDsDataProvider.getAdminConnection(ApacheDsDataProvider.java:1432)
at
org.apache.directory.fortress.core.impl.UserDAO.getUser(UserDAO.java:829)
at
org.apache.directory.fortress.core.impl.UserP.read(UserP.java:217)
at
org.apache.directory.fortress.core.impl.UserP.createSessionTrusted(UserP.java:523)
at
org.apache.directory.fortress.core.impl.UserP.createSession(UserP.java:455)
at
org.apache.directory.fortress.core.impl.AccessMgrImpl.createSession(AccessMgrImpl.java:171)
at com.autorola.rbac.RBACUtil.createSession(RBACUtil.java:64)
at
com.autorola.rbac.RBACUtil.createSessionForTrustedUser(RBACUtil.java:51)
at
com.autorola.fmsecurity.FMRBACUtil.createSubject(FMRBACUtil.java:40)
at
com.autorola.fmsecurity.FMRBACUtil.updateSubject(FMRBACUtil.java:20)
at
dk.autocom.auction.common.PresSessionInformation.setUser(PresSessionInformation.java:494)
at
dk.autocom.auction.actions.AuctionAction.doLogin(AuctionAction.java:1065)
at
dk.autocom.auction.actions.bilsalg.LoginAction.checkLogin(LoginAction.java:329)
at
dk.autocom.auction.actions.bilsalg.LoginAction.execute(LoginAction.java:88)
at
org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:484)
at
dk.autocom.auction.struts.AutocomRequestProcessor.processActionPerform(AutocomRequestProcessor.java:206)
at
org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:274)
at
org.apache.struts.action.ActionServlet.process(ActionServlet.java:1482)
at
org.apache.struts.action.ActionServlet.doPost(ActionServlet.java:525)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
at
dk.autocom.auction.servlets.StrutsServlet.processRequest(StrutsServlet.java:753)
at
dk.autocom.auction.servlets.StrutsServlet.service(StrutsServlet.java:169)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at
dk.autocom.lib.servletutils.CharsetFilter.doFilter(CharsetFilter.java:38)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at
org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
at
org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:182)
at
org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at
org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:562)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at
dk.autocom.valves.CrawlerSessionManagerValve.invoke(CrawlerSessionManagerValve.java:210)
at
org.apache.catalina.connector.RemoteIpValve.invoke(RemoteIpValve.java:612)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262)
at
org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
at
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
at
org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446)
at java.lang.Thread.run(Thread.java:745)
2016-02-06 13:07:26,485 ERROR
[org.apache.directory.ldap.client.api.DefaultLdapConnectionFactory]
Thread='http-0.0.0.0-14880-7' unable to bind connection: The response queue
has been emptied, no response was found.
2016-02-06 13:07:26,487 ERROR
[org.apache.directory.ldap.client.api.AbstractPoolableLdapConnectionFactory]
Thread='http-0.0.0.0-14880-7' unable to unbind connection: Cannot connect
on the server, the connection is invalid
.... waiting for 30 sec. ...
2016-02-06 13:07:56,488 ERROR
[org.apache.directory.ldap.client.api.LdapNetworkConnection]
Thread='http-0.0.0.0-14880-7' Bind failed : timeout occurred
2016-02-06 13:07:56,488 ERROR
[org.apache.directory.ldap.client.api.LdapNetworkConnection]
Thread='http-0.0.0.0-14880-7' The response queue has been emptied, no
response was found.
org.apache.directory.api.ldap.model.exception.LdapException: TimeOut
occurred
.... [Repeating ...] ...
Today it only repeated twice. I guess I was the only one logging into the
system yesterday.
For fortress config we use a max of 10 connections, and we use SSL.
// Jan
