This session has been closed

[federicos727792]

Hey, we're seeing this problem (session closed) randomly and in general under heavy load.

25.01.201704:23:19.269 *ERROR* [pool-7-thread-5]com.xxx.global.aem.web.service.widget.WidgetPollingSchedulerRun failed java.lang.IllegalStateException:This session has been closed at com.google.common.base.Preconditions.checkState(Preconditions.java:150) at org.apache.jackrabbit.oak.core.ContentSessionImpl.checkLive(ContentSessionImpl.java:85) at org.apache.jackrabbit.oak.core.MutableRoot.checkLive(MutableRoot.java:172) at org.apache.jackrabbit.oak.core.MutableRoot.getTree(MutableRoot.java:216) at org.apache.jackrabbit.oak.core.MutableRoot.getTree(MutableRoot.java:66) at org.apache.jackrabbit.oak.query.QueryImpl.getTree(QueryImpl.java:1034) at org.apache.jackrabbit.oak.query.ast.SelectorImpl.getTree(SelectorImpl.java:525) at org.apache.jackrabbit.oak.query.ast.SelectorImpl.next(SelectorImpl.java:433) at org.apache.jackrabbit.oak.query.QueryImpl$RowIterator.fetchNext(QueryImpl.java:773) at org.apache.jackrabbit.oak.query.QueryImpl$RowIterator.hasNext(QueryImpl.java:798) at org.apache.jackrabbit.oak.jcr.query.QueryResultImpl$1.fetch(QueryResultImpl.java:108) at org.apache.jackrabbit.oak.jcr.query.QueryResultImpl$1.next(QueryResultImpl.java:127) at org.apache.jackrabbit.oak.jcr.query.QueryResultImpl$1.next(QueryResultImpl.java:91) at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate$SynchronizedIterator.next(SessionDelegate.java:694) at org.apache.jackrabbit.oak.jcr.query.PrefetchIterator.next(PrefetchIterator.java:97) at org.apache.jackrabbit.commons.iterator.RangeIteratorAdapter.next(RangeIteratorAdapter.java:152) at org.apache.jackrabbit.commons.iterator.RangeIteratorDecorator.next(RangeIteratorDecorator.java:92) at org.apache.jackrabbit.commons.iterator.RowIteratorAdapter.nextRow(RowIteratorAdapter.java:76) at com.day.cq.search.impl.builder.QueryImpl$RowIterAdapter.next(QueryImpl.java:845) at com.day.cq.search.impl.builder.QueryImpl$RowIterAdapter.next(QueryImpl.java:832) at org.apache.jackrabbit.commons.iterator.RangeIteratorAdapter.next(RangeIteratorAdapter.java:152) at org.apache.jackrabbit.commons.iterator.RangeIteratorDecorator.next(RangeIteratorDecorator.java:92) at org.apache.jackrabbit.commons.iterator.RowIteratorAdapter.nextRow(RowIteratorAdapter.java:76) at com.day.cq.search.impl.result.SearchResultImpl.<init>(SearchResultImpl.java:126) at com.day.cq.search.impl.builder.QueryImpl.execute(QueryImpl.java:587) at com.day.cq.search.impl.builder.QueryImpl.getResult(QueryImpl.java:106) at com.xxx.global.aem.web.service.widget.WidgetResourceUtilImpl.getWidgetEndpoints(WidgetResourceUtilImpl.java:50) at com.xxx.global.aem.web.service.widget.WidgetPollingScheduler.poll(WidgetPollingScheduler.java:77) at com.xxx.global.aem.web.service.widget.WidgetPollingScheduler.run(WidgetPollingScheduler.java:60) at org.apache.sling.commons.scheduler.impl.QuartzJobExecutor.execute(QuartzJobExecutor.java:115) at org.quartz.core.JobRunShell.run(JobRunShell.java:202) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)

The code:

public Set<String> getWidgetEndpoints() throws LoginException, RepositoryException { PredicateGroup predicateGroup = PredicateGroup.create(getQueryParameters()); ResourceResolver resolver = getServiceResourceResolver(); QueryBuilder queryBuilder = resolver.adaptTo(QueryBuilder.class); Query query = queryBuilder.createQuery(predicateGroup, resolver.adaptTo(Session.class)); return getUniqueEndpoints(query.getResult()); } public ResourceResolver getServiceResourceResolver() throws LoginException { Map<String, Object> serviceParams = new HashMap<>(); serviceParams.put(ResourceResolverFactory.SUBSERVICE, SUBSERVICE_NAME); return resourceResolverFactory.getServiceResourceResolver(serviceParams); }

We're aware of http://help-forums.adobe.com/content/adobeforums/en/experience-manager-forum/adobe-experience-manage...

and http://tech.ethomasjoseph.com/2015/09/sling-who-is-closing-my-jcr-session.html and afaik we're not in either of those cases.

Any idea what could be happening?

Thx

[Feike_Visser1]

My first reaction would to close the session in a finally-block, this is not happening currently.

[federicos727792]

Ah yes, I forgot to mention that we're changing that soon, closing the resource resolver in fact.

But that would fix a potential session / memory leak, not the problem we're having. Also a quick inspection of the source code showed that sessions themselves are not reused.

[Feike_Visser1]

What is the code in this method getUniqueEndpoints(query.getResult());?

[federicos727792]

It iterates the result hits and adds some of the properties to a set, but I think that doesn't really matter, as query.getResult() fails before going into that method.

[Feike_Visser1]

You are right, I wouldn't know now where to look. Except my previous recommendation on closing the resourceresolver.

Here an article on how to debug sessions, maybe that helps.

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

[Jörg_Hoh]

Hi,

is this a consistent problem or does it happen only rarely (so one could assume that it's a race condition)?

Jörg

[federicos727792]

Feike, Thx for the link. We're going to try that.

Jörg, Only rarely. Indeed it looks like a race condition.

[girtorapankaj]

I am also facing the similar issue, when there are multiple sling jobs, then this issue is occurring consistently on cloud.

I have checked and all session/resource resolver are closing properly. Not sure why and how session is getting closed while fetching nodes from query result.

@federicos727792 Did you find any thing specific to this to resolve it?