Analyze Unclosed Sessions in Oak (1.0.13)

[Former Community Member]

Is there a session analyzer tool for Oak? The one referenced in this article [1] only seems to work for CRX in lower version.

Looking at a recent heap dump, we seem to have trouble with sessions not closing properly and are trying to narrow down where it's coming from.

[1] https://helpx.adobe.com/experience-manager/kb/AnalyzeUnclosedSessions.html

[Sham_HC]

the article should work for oak also..   However you should be able to see in jmx since MBean added to track sessions.  There are additional tools worked & don;t have latest status handy.  Please file official support request

[Jörg_Hoh]

Hi,

since CQ 5.5 (5.6? Don't know exactly) CQ reports unclosed sessions on WARN level in the error.log; you don't need to have a special tool for analysis anymore.

kind regards,
Jörg

[Former Community Member]

Hi Jörg, is this the sort of warning you are talking about?

*WARN* [ip [1432319636774] GET something HTTP/1.1] org.apache.jackrabbit.oak.jcr.session.RefreshStrategy This session has been idle for 2 minutes and might be out of date. Consider using a fresh session or explicitly refresh the session.

If so, how would I go from this to finding out where this session is opened? The "session_analyzer.jar" from the article referenced above [1] seems to do just that. However, when run on an Oak repo, it doesn't seem to return anything (output.txt has 0 bytes). 

Sham, where in JMX would I see this sort of session information?

[Sham_HC]

http://localhost:4502/system/console/jmx/org.apache.jackrabbit.oak%3Aid%3D7%2Cname%3D%22Oak+Reposito...

[Jörg_Hoh]

Hi,

Yes, I was referring to this message, but there should be also a stacktrace when this session has been opened.

kind regards,
Jörg

[Former Community Member]

Sham HC, is there documentation anywhere on how to read and work with the "Oak Repository Statistics" that you mentioned? From just the number of sessions I don't see anything unusual.

[Former Community Member]

Thanks, Jörg. Yes, there is a stack trace, it's not really helpful though. I was hoping it would point me to the place in our code that's wrong. All I see here is OOTB AEM classes...

10.03.2015 10:39:03.933 *WARN* [123.123.123.123 [1426001576294] GET /content/blabla.html HTTP/1.1] org.apache.jackrabbit.oak.jcr.session.RefreshStrategy This session has been idle for 1 minutes and might be out of date. Consider using a fresh session or explicitly refresh the session. java.lang.Exception: The session was created here: at org.apache.jackrabbit.oak.jcr.session.RefreshStrategy$LogOnce.<init>(RefreshStrategy.java:124) at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl.createRefreshStrategy(RepositoryImpl.java:450) at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl.login(RepositoryImpl.java:255) at com.adobe.granite.repository.impl.CRX3RepositoryImpl.login(CRX3RepositoryImpl.java:92) at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl.login(RepositoryImpl.java:197) at org.apache.sling.jcr.base.AbstractSlingRepository2.login(AbstractSlingRepository2.java:297) at org.apache.sling.jcr.resource.internal.helper.jcr.JcrResourceProviderFactory.getResourceProviderInternal(JcrResourceProviderFactory.java:289) at org.apache.sling.jcr.resource.internal.helper.jcr.JcrResourceProviderFactory.getResourceProvider(JcrResourceProviderFactory.java:201) at org.apache.sling.resourceresolver.impl.tree.ResourceProviderFactoryHandler.login(ResourceProviderFactoryHandler.java:164) at org.apache.sling.resourceresolver.impl.tree.RootResourceProviderEntry.loginToRequiredFactories(RootResourceProviderEntry.java:95) at org.apache.sling.resourceresolver.impl.CommonResourceResolverFactoryImpl.getResourceResolverInternal(CommonResourceResolverFactoryImpl.java:109) at org.apache.sling.resourceresolver.impl.CommonResourceResolverFactoryImpl.getResourceResolver(CommonResourceResolverFactoryImpl.java:90) at org.apache.sling.resourceresolver.impl.ResourceResolverFactoryImpl.getResourceResolver(ResourceResolverFactoryImpl.java:93) at org.apache.sling.auth.core.impl.SlingAuthenticator.getAnonymousResolver(SlingAuthenticator.java:839) at org.apache.sling.auth.core.impl.SlingAuthenticator.doHandleSecurity(SlingAuthenticator.java:478) at org.apache.sling.auth.core.impl.SlingAuthenticator.handleSecurity(SlingAuthenticator.java:438) at org.apache.sling.engine.impl.SlingHttpContext.handleSecurity(SlingHttpContext.java:121) at org.apache.felix.http.base.internal.context.ServletContextImpl.handleSecurity(ServletContextImpl.java:335) at org.apache.felix.http.base.internal.handler.ServletHandler.doHandle(ServletHandler.java:337) at org.apache.felix.http.base.internal.handler.ServletHandler.handle(ServletHandler.java:300) at org.apache.felix.http.base.internal.dispatch.ServletPipeline.handle(ServletPipeline.java:93) at org.apache.felix.http.base.internal.dispatch.InvocationFilterChain.doFilter(InvocationFilterChain.java:50) at org.apache.felix.http.base.internal.dispatch.HttpFilterChain.doFilter(HttpFilterChain.java:31) at org.apache.sling.i18n.impl.I18NFilter.doFilter(I18NFilter.java:128) at org.apache.felix.http.base.internal.handler.FilterHandler.doHandle(FilterHandler.java:108) at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:80) at org.apache.felix.http.base.internal.dispatch.InvocationFilterChain.doFilter(InvocationFilterChain.java:46) at org.apache.felix.http.base.internal.dispatch.HttpFilterChain.doFilter(HttpFilterChain.java:31) at org.apache.felix.http.sslfilter.internal.SslFilter.doFilter(SslFilter.java:55) at org.apache.felix.http.base.internal.handler.FilterHandler.doHandle(FilterHandler.java:108) at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:80) at org.apache.felix.http.base.internal.dispatch.InvocationFilterChain.doFilter(InvocationFilterChain.java:46) at org.apache.felix.http.base.internal.dispatch.HttpFilterChain.doFilter(HttpFilterChain.java:31) at org.apache.sling.security.impl.ReferrerFilter.doFilter(ReferrerFilter.java:290) at org.apache.felix.http.base.internal.handler.FilterHandler.doHandle(FilterHandler.java:108) at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:80) at org.apache.felix.http.base.internal.dispatch.InvocationFilterChain.doFilter(InvocationFilterChain.java:46) at org.apache.felix.http.base.internal.dispatch.HttpFilterChain.doFilter(HttpFilterChain.java:31) at org.apache.felix.http.sslfilter.internal.SslFilter.doFilter(SslFilter.java:89) at org.apache.felix.http.base.internal.handler.FilterHandler.doHandle(FilterHandler.java:108) at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:80) at org.apache.felix.http.base.internal.dispatch.InvocationFilterChain.doFilter(InvocationFilterChain.java:46) at org.apache.felix.http.base.internal.dispatch.HttpFilterChain.doFilter(HttpFilterChain.java:31) at com.adobe.granite.license.impl.LicenseCheckFilter.doFilter(LicenseCheckFilter.java:298) at org.apache.felix.http.base.internal.handler.FilterHandler.doHandle(FilterHandler.java:108) at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:80) at org.apache.felix.http.base.internal.dispatch.InvocationFilterChain.doFilter(InvocationFilterChain.java:46) at org.apache.felix.http.base.internal.dispatch.HttpFilterChain.doFilter(HttpFilterChain.java:31) at org.apache.sling.featureflags.impl.FeatureManager.doFilter(FeatureManager.java:115) at org.apache.felix.http.base.internal.handler.FilterHandler.doHandle(FilterHandler.java:108) at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:80) at org.apache.felix.http.base.internal.dispatch.InvocationFilterChain.doFilter(InvocationFilterChain.java:46) at org.apache.felix.http.base.internal.dispatch.HttpFilterChain.doFilter(HttpFilterChain.java:31) at org.apache.sling.engine.impl.log.RequestLoggerFilter.doFilter(RequestLoggerFilter.java:75) at org.apache.felix.http.base.internal.handler.FilterHandler.doHandle(FilterHandler.java:108) at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:80) at org.apache.felix.http.base.internal.dispatch.InvocationFilterChain.doFilter(InvocationFilterChain.java:46) at org.apache.felix.http.base.internal.dispatch.HttpFilterChain.doFilter(HttpFilterChain.java:31) at org.apache.felix.http.base.internal.dispatch.FilterPipeline.dispatch(FilterPipeline.java:76) at org.apache.felix.http.base.internal.dispatch.Dispatcher.dispatch(Dispatcher.java:49) at org.apache.felix.http.base.internal.DispatcherServlet.service(DispatcherServlet.java:67) at javax.servlet.http.HttpServlet.service(HttpServlet.java:722) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:684) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:501) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1086) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:428) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1020) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135) at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:255) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116) at org.eclipse.jetty.server.Server.handle(Server.java:370) at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:494) at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:971) at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:1033) at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:644) at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235) at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82) at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:667) at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543) at java.lang.Thread.run(Thread.java:745)

[Jörg_Hoh · Accepted solution]

Hi,

the stacktrace you posted isn't a session leak; it's just a request, which takes a long time. And therefor the session associated with the request is open for more than 1 minute. So from a memory point of view there is nothing to worry about.

kind regards,
Jörg

[Former Community Member]

Yeah, that's what the message sounds like. I think this error actually occurs when AEM is slowly dying (GC can't keep up). But what sort of error message would I look for then to point me to session leaks?

[Jörg_Hoh]

Hm, good question. I actually looked up the source code, and I haven't found any indication, that there's a leak detection at all (like it was in JR 2.x); would be a good question on the Oak list.

Jörg