[MAGNOLIA-6729] Stale session on accessing JCR resources Created: 22/Jul/16 Updated: 03/Apr/17 Resolved: 27/Mar/17 |
|
| Status: | Closed |
| Project: | Magnolia |
| Component/s: | resource-loader |
| Affects Version/s: | 5.4.7 |
| Fix Version/s: | 5.4.12, 5.5.3 |
| Type: | Bug | Priority: | Critical |
| Reporter: | Richard Unger | Assignee: | Jaroslav Simak |
| Resolution: | Fixed | Votes: | 2 |
| Labels: | support | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Environment: |
LFRZ |
||
| Issue Links: |
|
||||||||||||
| Template: |
|
||||||||||||
| Patch included: |
Yes
|
||||||||||||
| Acceptance criteria: |
Empty
|
||||||||||||
| Task DoD: |
[ ]*
Doc/release notes changes? Comment present?
[ ]*
Downstream builds green?
[ ]*
Solution information and context easily available?
[ ]*
Tests
[ ]*
FixVersion filled and not yet released
[ ] 
Architecture Decision Record (ADR)
|
||||||||||||
| Bug DoR: |
[ ]*
Steps to reproduce, expected, and actual results filled
[ ]*
Affected version filled
|
||||||||||||
| Date of First Response: | |||||||||||||
| Sprint: | Kromeriz 89 | ||||||||||||
| Story Points: | 2 | ||||||||||||
| Description |
|
Originally reported as SUPPORT-6376 We have discovered the following issue in our effort to migrate to Magnolia 5.4.7: We are switching to light development, and now have definitions in YAML stored in the resources workspace. On the sites that use YAML definitions, we have observed that we sometimes get exceptions to do with stale sessions. Two sample stack traces are included below. The problem occurs because the definition is checked for modifications, and the getLastModified() call on the resource attempts to load the lastModified information from JCR, and encounters a stale session. The confusing part for me is that the JCRResource code actually checks for stale sessions and (theoretically) refreshes the node if needed. What is going on here? Stack trace 1:
Caused by: javax.jcr.RepositoryException: This session has been closed. See the chained exception for a trace of where the session was closed.
at org.apache.jackrabbit.core.session.SessionState.checkAlive(SessionState.java:150)
at org.apache.jackrabbit.core.ItemImpl.sanityCheck(ItemImpl.java:101)
at org.apache.jackrabbit.core.NodeImpl.hasProperty(NodeImpl.java:2456)
at info.magnolia.jcr.wrapper.DelegateNodeWrapper.hasProperty(DelegateNodeWrapper.java:304)
at info.magnolia.jcr.wrapper.DelegateNodeWrapper.hasProperty(DelegateNodeWrapper.java:304)
at info.magnolia.jcr.wrapper.DelegateNodeWrapper.hasProperty(DelegateNodeWrapper.java:304)
at info.magnolia.jcr.wrapper.DelegateNodeWrapper.hasProperty(DelegateNodeWrapper.java:304)
at info.magnolia.jcr.util.NodeTypes$Created.getCreated(NodeTypes.java:218)
at info.magnolia.jcr.util.NodeTypes$LastModified.getLastModified(NodeTypes.java:86)
at info.magnolia.resourceloader.jcr.JcrResourceOrigin.getLastModified(JcrResourceOrigin.java:178)
at info.magnolia.resourceloader.jcr.JcrResourceOrigin.getLastModified(JcrResourceOrigin.java:90)
at info.magnolia.resourceloader.AbstractResource.getLastModified(AbstractResource.java:89)
at info.magnolia.resourceloader.layered.LayeredResourceOrigin.getLastModified(LayeredResourceOrigin.java:148)
at info.magnolia.resourceloader.layered.LayeredResourceOrigin.getLastModified(LayeredResourceOrigin.java:73)
at info.magnolia.resourceloader.AbstractResource.getLastModified(AbstractResource.java:89)
at org.mgnlconfig.yaml.dependency.YamlFileConfigDependency.needsUpdate(YamlFileConfigDependency.java:64)
at org.mgnlconfig.yaml.YamlConfigurationDataProvider$1.apply(YamlConfigurationDataProvider.java:73)
at org.mgnlconfig.yaml.YamlConfigurationDataProvider$1.apply(YamlConfigurationDataProvider.java:70)
at com.google.common.collect.Iterators$7.computeNext(Iterators.java:652)
at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143)
at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138)
at com.google.common.collect.Iterators.tryFind(Iterators.java:752)
at com.google.common.collect.Iterables.tryFind(Iterables.java:675)
at org.mgnlconfig.yaml.YamlConfigurationDataProvider.needsUpdate(YamlConfigurationDataProvider.java:70)
at org.mgnlconfig.YamlDefinitionProvider.refreshYamlData(YamlDefinitionProvider.java:100)
at org.mgnlconfig.YamlDefinitionProvider.get(YamlDefinitionProvider.java:76)
at info.magnolia.config.registry.AbstractDefinitionProviderWrapper.get(AbstractDefinitionProviderWrapper.java:60)
at info.magnolia.rendering.template.registry.TemplateDefinitionRegistry$1.get(TemplateDefinitionRegistry.java:133)
at info.magnolia.rendering.template.registry.TemplateDefinitionRegistry$1.get(TemplateDefinitionRegistry.java:130)
at info.magnolia.rendering.template.registry.TemplateDefinitionRegistry.getTemplateDefinition(TemplateDefinitionRegistry.java:118)
at info.magnolia.rendering.template.assignment.MetaDataBasedTemplateDefinitionAssignment.getAssignedTemplateDefinition(MetaDataBasedTemplateDefinitionAssignment.java:100)
at at.lfrz.magnolia.jcr.predicate.TemplateParameterPredicate.evaluateTyped(TemplateParameterPredicate.java:33)
at at.lfrz.magnolia.jcr.predicate.TemplateParameterPredicate.evaluateTyped(TemplateParameterPredicate.java:13)
at at.lfrz.magnolia.jcr.predicate.AndPredicate.evaluateTyped(AndPredicate.java:35)
at at.lfrz.magnolia.jcr.predicate.XorPredicate.evaluateTyped(XorPredicate.java:22)
at at.lfrz.magnolia.jcr.predicate.AndPredicate.evaluateTyped(AndPredicate.java:35)
at info.magnolia.jcr.predicate.AbstractPredicate.evaluate(AbstractPredicate.java:49)
at org.apache.jackrabbit.commons.iterator.FilteringNodeIterator.seekNext(FilteringNodeIterator.java:114)
at org.apache.jackrabbit.commons.iterator.FilteringNodeIterator.<init>(FilteringNodeIterator.java:42)
at info.magnolia.jcr.util.NodeUtil.getNodes(NodeUtil.java:668)
at at.lfrz.magnolia.atk.templating.ContentListing.buildListing(ContentListing.java:433)
at at.lfrz.magnolia.atk.templating.ContentListing.getListing(ContentListing.java:217)
at at.lfrz.magnolia.atk.templating.ATKAbstractModelBase.getListing(ATKAbstractModelBase.java:82)
at sun.reflect.GeneratedMethodAccessor810.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at freemarker.ext.beans.BeansWrapper.invokeMethod(BeansWrapper.java:1385)
at freemarker.ext.beans.ReflectionCallableMemberDescriptor.invokeMethod(ReflectionCallableMemberDescriptor.java:52)
at freemarker.ext.beans.MemberAndArguments.invokeMethod(MemberAndArguments.java:48)
at freemarker.ext.beans.OverloadedMethodsModel.exec(OverloadedMethodsModel.java:62)
... 183 more
Caused by: java.lang.Exception: Stack trace of where session-admin-68869 was originally closed
at org.apache.jackrabbit.core.session.SessionState.close(SessionState.java:275)
at org.apache.jackrabbit.core.SessionImpl.logout(SessionImpl.java:943)
at org.apache.jackrabbit.core.XASessionImpl.logout(XASessionImpl.java:394)
at info.magnolia.jcr.wrapper.DelegateSessionWrapper.logout(DelegateSessionWrapper.java:262)
at info.magnolia.repository.mbean.TrackingSessionWrapper.logout(TrackingSessionWrapper.java:57)
at info.magnolia.jcr.wrapper.DelegateSessionWrapper.logout(DelegateSessionWrapper.java:262)
at info.magnolia.jcr.wrapper.DelegateSessionWrapper.logout(DelegateSessionWrapper.java:262)
at info.magnolia.jcr.wrapper.DelegateSessionWrapper.logout(DelegateSessionWrapper.java:262)
at info.magnolia.jcr.wrapper.DelegateSessionWrapper.logout(DelegateSessionWrapper.java:262)
at info.magnolia.context.AbstractRepositoryStrategy.releaseSession(AbstractRepositoryStrategy.java:99)
at info.magnolia.context.AbstractRepositoryStrategy.release(AbstractRepositoryStrategy.java:87)
at info.magnolia.context.SystemRepositoryStrategy.release(SystemRepositoryStrategy.java:59)
at info.magnolia.context.JCRSessionPerThreadSystemContext.releaseThread(JCRSessionPerThreadSystemContext.java:58)
at info.magnolia.context.MgnlContext.release(MgnlContext.java:631)
at info.magnolia.cms.filters.ContextFilter.doFilter(ContextFilter.java:131)
... 25 more
Stack trace 2: ERROR info.magnolia.rendering.engine.RenderingFilter 19.07.2016 10:45:57 -- This session has been closed. See the chained exception for a trace of where the session was closed. javax.jcr.RepositoryException: This session has been closed. See the chained exception for a trace of where the session was closed. at org.apache.jackrabbit.core.session.SessionState.checkAlive(SessionState.java:150) at org.apache.jackrabbit.core.ItemImpl.sanityCheck(ItemImpl.java:101) at org.apache.jackrabbit.core.NodeImpl.hasProperty(NodeImpl.java:2456) at info.magnolia.jcr.wrapper.DelegateNodeWrapper.hasProperty(DelegateNodeWrapper.java:304) at info.magnolia.jcr.wrapper.DelegateNodeWrapper.hasProperty(DelegateNodeWrapper.java:304) at info.magnolia.jcr.wrapper.DelegateNodeWrapper.hasProperty(DelegateNodeWrapper.java:304) at info.magnolia.jcr.wrapper.DelegateNodeWrapper.hasProperty(DelegateNodeWrapper.java:304) at info.magnolia.jcr.util.NodeTypes$Created.getCreated(NodeTypes.java:218) at info.magnolia.jcr.util.NodeTypes$LastModified.getLastModified(NodeTypes.java:86) at info.magnolia.resourceloader.jcr.JcrResourceOrigin.getLastModified(JcrResourceOrigin.java:178) at info.magnolia.resourceloader.jcr.JcrResourceOrigin.getLastModified(JcrResourceOrigin.java:90) at info.magnolia.resourceloader.AbstractResource.getLastModified(AbstractResource.java:89) at info.magnolia.resourceloader.layered.LayeredResourceOrigin.getLastModified(LayeredResourceOrigin.java:148) at info.magnolia.resourceloader.layered.LayeredResourceOrigin.getLastModified(LayeredResourceOrigin.java:73) at info.magnolia.resourceloader.AbstractResource.getLastModified(AbstractResource.java:89) at org.mgnlconfig.yaml.dependency.YamlFileConfigDependency.needsUpdate(YamlFileConfigDependency.java:64) at org.mgnlconfig.yaml.YamlConfigurationDataProvider$1.apply(YamlConfigurationDataProvider.java:73) at org.mgnlconfig.yaml.YamlConfigurationDataProvider$1.apply(YamlConfigurationDataProvider.java:70) at com.google.common.collect.Iterators$7.computeNext(Iterators.java:652) at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143) at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138) at com.google.common.collect.Iterators.tryFind(Iterators.java:752) at com.google.common.collect.Iterables.tryFind(Iterables.java:675) at org.mgnlconfig.yaml.YamlConfigurationDataProvider.needsUpdate(YamlConfigurationDataProvider.java:70) at org.mgnlconfig.YamlDefinitionProvider.refreshYamlData(YamlDefinitionProvider.java:100) at org.mgnlconfig.YamlDefinitionProvider.get(YamlDefinitionProvider.java:76) at info.magnolia.config.registry.AbstractDefinitionProviderWrapper.get(AbstractDefinitionProviderWrapper.java:60) at info.magnolia.rendering.template.registry.TemplateDefinitionRegistry$1.get(TemplateDefinitionRegistry.java:133) at info.magnolia.rendering.template.registry.TemplateDefinitionRegistry$1.get(TemplateDefinitionRegistry.java:130) at info.magnolia.rendering.template.registry.TemplateDefinitionRegistry.getTemplateDefinition(TemplateDefinitionRegistry.java:118) at info.magnolia.rendering.engine.RenderingFilter.render(RenderingFilter.java:185) at info.magnolia.rendering.engine.RenderingFilter.handleTemplateRequest(RenderingFilter.java:140) at info.magnolia.rendering.engine.RenderingFilter.doFilter(RenderingFilter.java:94) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.rendering.model.ModelExecutionFilter.doFilter(ModelExecutionFilter.java:109) at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.AggregatorFilter.doFilter(AggregatorFilter.java:100) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.security.BaseSecurityFilter.doFilter(BaseSecurityFilter.java:57) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.RepositoryMappingFilter.doFilter(RepositoryMappingFilter.java:108) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.CompositeFilter.doFilter(CompositeFilter.java:65) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:74) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.CompositeFilter.doFilter(CompositeFilter.java:65) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.VirtualUriFilter.doFilter(VirtualUriFilter.java:69) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.module.cache.executor.Bypass.processCacheRequest(Bypass.java:58) at info.magnolia.module.cache.executor.CompositeExecutor.processCacheRequest(CompositeExecutor.java:67) at info.magnolia.module.cache.filter.CacheFilter.doFilter(CacheFilter.java:174) at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.i18n.I18nContentSupportFilter.doFilter(I18nContentSupportFilter.java:74) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.RangeSupportFilter.doFilter(RangeSupportFilter.java:84) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.security.BaseSecurityFilter.doFilter(BaseSecurityFilter.java:57) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.multisite.filters.CrossSiteSecurityFilter.doFilter(CrossSiteSecurityFilter.java:104) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.security.SecurityCallbackFilter.doFilter(SecurityCallbackFilter.java:79) at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.security.LogoutFilter.doFilter(LogoutFilter.java:94) at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.module.site.filters.SiteMergeFilter.doFilter(SiteMergeFilter.java:119) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at at.lfrz.magnolia.atk.errorpages.ATKMultiSiteFilter.doFilter(ATKMultiSiteFilter.java:138) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.MultiChannelFilter.doFilter(MultiChannelFilter.java:83) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.module.cache.filter.GZipFilter.doFilter(GZipFilter.java:73) at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at at.lfrz.magnolia.atk.filter.ImprovedLoggingFilter.doFilter(ImprovedLoggingFilter.java:77) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.security.auth.login.LoginFilter.doFilter(LoginFilter.java:127) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.enterprise.registration.RegistrationFilter.doFilter(RegistrationFilter.java:64) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.CosMultipartRequestFilter.doFilter(CosMultipartRequestFilter.java:87) at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.module.devicedetection.filter.DeviceDetectionFilter.doFilter(DeviceDetectionFilter.java:71) at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.personalization.preview.filter.PreviewFilter.doFilter(PreviewFilter.java:92) at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.personalization.trait.AbstractTraitDetectorFilter.doFilter(AbstractTraitDetectorFilter.java:74) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.personalization.trait.AbstractTraitDetectorFilter.doFilter(AbstractTraitDetectorFilter.java:74) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.personalization.trait.AbstractTraitDetectorFilter.doFilter(AbstractTraitDetectorFilter.java:74) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.personalization.trait.AbstractTraitDetectorFilter.doFilter(AbstractTraitDetectorFilter.java:74) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.ContentTypeFilter.doFilter(ContentTypeFilter.java:148) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:74) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) at info.magnolia.cms.filters.CompositeFilter.doFilter(CompositeFilter.java:65) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at at.lfrz.magnolia.atk.filter.ImprovedLoggingFilter.doFilter(ImprovedLoggingFilter.java:77) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.ContextFilter.doFilter(ContextFilter.java:128) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) at info.magnolia.cms.filters.CompositeFilter.doFilter(CompositeFilter.java:65) at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) at info.magnolia.cms.filters.SafeDestroyMgnlFilterWrapper.doFilter(SafeDestroyMgnlFilterWrapper.java:107) at info.magnolia.cms.filters.MgnlFilterDispatcher.doDispatch(MgnlFilterDispatcher.java:67) at info.magnolia.cms.filters.MgnlMainFilter.doFilter(MgnlMainFilter.java:108) at info.magnolia.cms.filters.MgnlMainFilter.doFilter(MgnlMainFilter.java:94) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) at at.lfrz.net.tomcat.valve.LFRZAccessLogValve.invoke(LFRZAccessLogValve.java:460) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:436) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1078) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625) at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:318) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:745) Caused by: java.lang.Exception: Stack trace of where session-admin-17501 was originally closed at org.apache.jackrabbit.core.session.SessionState.close(SessionState.java:275) at org.apache.jackrabbit.core.SessionImpl.logout(SessionImpl.java:943) at org.apache.jackrabbit.core.XASessionImpl.logout(XASessionImpl.java:394) at info.magnolia.jcr.wrapper.DelegateSessionWrapper.logout(DelegateSessionWrapper.java:262) at info.magnolia.repository.mbean.TrackingSessionWrapper.logout(TrackingSessionWrapper.java:57) at info.magnolia.jcr.wrapper.DelegateSessionWrapper.logout(DelegateSessionWrapper.java:262) at info.magnolia.jcr.wrapper.DelegateSessionWrapper.logout(DelegateSessionWrapper.java:262) at info.magnolia.jcr.wrapper.DelegateSessionWrapper.logout(DelegateSessionWrapper.java:262) at info.magnolia.jcr.wrapper.DelegateSessionWrapper.logout(DelegateSessionWrapper.java:262) at info.magnolia.context.AbstractRepositoryStrategy.releaseSession(AbstractRepositoryStrategy.java:99) at info.magnolia.context.AbstractRepositoryStrategy.release(AbstractRepositoryStrategy.java:87) at info.magnolia.context.SystemRepositoryStrategy.release(SystemRepositoryStrategy.java:59) at info.magnolia.context.JCRSessionPerThreadSystemContext.releaseThread(JCRSessionPerThreadSystemContext.java:58) at info.magnolia.context.MgnlContext.release(MgnlContext.java:631) at info.magnolia.cms.filters.ContextFilter.doFilter(ContextFilter.java:131) ... 25 more Analysis: I have been looking at the code, and thinking about this problem. If you follow the code in the stack-trace, I think it gets interesting around the call to JcrResourceOrigin.getLastModified(JcrResource).
@Override
@SneakyThrows(RepositoryException.class)
protected long getLastModified(JcrResource resource) {
// TODO Compare: return resource.getNode().getProperty(JcrConstants.JCR_LASTMODIFIED)
final Calendar lastModified = NodeTypes.LastModified.getLastModified(resource.getNode());
if (lastModified == null) {
// TODO: shouldn't this happen in info.magnolia.jcr.util.NodeTypes.LastModified.getLastModified() ?
throw new RepositoryException("No lastModified or created date property on " + resource.getNode());
}
return lastModified.getTimeInMillis();
}
Note that is calls resource.getNode(). The method JcrResource.getNode() looks like this:
@SneakyThrows(RepositoryException.class)
Node getNode() {
if (!node.getSession().isLive()) {
this.node = ((JcrResourceOrigin)getOrigin()).getJcrSession().getNodeByIdentifier(this.uuid);
}
return node;
}
So it performs a session check on the node before returning it. The returned node is then passed to NodeTypes.LastModified.getLastModified(Node), which via a few more calls then results in the session closed RepositoryException:
Caused by: javax.jcr.RepositoryException: This session has been closed. See the chained exception for a trace of where the session was closed.
at org.apache.jackrabbit.core.session.SessionState.checkAlive(SessionState.java:150)
at org.apache.jackrabbit.core.ItemImpl.sanityCheck(ItemImpl.java:101)
at org.apache.jackrabbit.core.NodeImpl.hasProperty(NodeImpl.java:2456)
at info.magnolia.jcr.wrapper.DelegateNodeWrapper.hasProperty(DelegateNodeWrapper.java:304)
at info.magnolia.jcr.wrapper.DelegateNodeWrapper.hasProperty(DelegateNodeWrapper.java:304)
at info.magnolia.jcr.wrapper.DelegateNodeWrapper.hasProperty(DelegateNodeWrapper.java:304)
at info.magnolia.jcr.wrapper.DelegateNodeWrapper.hasProperty(DelegateNodeWrapper.java:304)
at info.magnolia.jcr.util.NodeTypes$Created.getCreated(NodeTypes.java:218)
at info.magnolia.jcr.util.NodeTypes$LastModified.getLastModified(NodeTypes.java:86)
at info.magnolia.resourceloader.jcr.JcrResourceOrigin.getLastModified(JcrResourceOrigin.java:178)
So in-between the session-check performed by JcrResource.getNode() and the one done in SessionState.checkAlive(), the session is being closed. This makes sense also when we consider that the error occurs when we "click around quickly", causing concurrent requests. The problem is made visible by our use of the light-yaml module, because the module causes a lot of JCR resource access when refreshing the YAML definitions, but it is not caused by that module. Rather, I think the problem is in the design of the new (JCR) resources layer: If you think about the code, and the way magnolia works, I think we have a clear race condition happening here. JcrResource.getNode() returns a cached node after checking its session. So you're relying on the session being alive after the call to JcrResource.getNode(), but the session-check and the subsequent use of the node object are not in a synchronized block. IMHO it is a fundamental design error to store any JCR node object in a field of an object that has application or session scope. A node object always only has validity within a JcrSession, and in magnolia the JcrSessions are opened/closed with the requests. Trying to cache nodes across requests doesn't work. So, if my analysis is correct, I see two potential fixes: 1. Get the node fresh for each call to JcrResource.getNode() Regards from Vienna, Richard |
| Comments |
| Comment by Richard Unger [ 22/Jul/16 ] |
|
I also have a potential fix for this at: https://runger@git.magnolia-cms.com/scm/~runger/main.git in the branch SUPPORT-6376 We will be testing this patch today, and will let you know how it works for us. Should I create a pull request for that? Who would I send it to? |
| Comment by Richard Unger [ 22/Jul/16 ] |
|
We have installed the patched version of the resourceloader module in our QS system, and now we can no longer reproduce the bug. Do you want a pull request? |
| Comment by Marcus Büttner [ 09/Feb/17 ] |
|
Is there a way to fix it asap? It's a little bit annoying to patch it again and again with every magnolia upgrade. For more than seven month there exists a patch which works. |
| Comment by Richard Unger [ 08/Mar/17 ] |
|
Agreed with Marcus. Please note that this is a fairly nasty issue, very easily fixed, and there is a support ticket waiting for bugfix release open since many months... |
| Comment by Jan Haderka [ 08/Mar/17 ] |
|
From what I can see in the stacktraces session was in both cases closed correctly once the processing of the request was finished. By that time all the rendering is/should be already done and no further access to the nodes should be made by any code. |
| Comment by Mikaël Geljić [ 08/Mar/17 ] |
|
had Resource reload happens in the JCR observation thread; there's no explicit Context#release or logout there, afaict. Resource-change events are dispatched synchronously within that thread—which for configuration sources triggers a reload of the definition. JCR resource origin gets the session from system context. I can imagine contention over that one, as it may be accessed from other threads. TBH, I'm surprised the stack-trace shows system context is the one being closed in ContextFilter, instead of a plain WebContext. There could be something else at play, "upgrading" current MgnlContext instance to system-context, and forgetting to set it back. Or do we have legit cases for this? —would back the contention nonetheless. Re: proposed fix |
| Comment by Richard Unger [ 10/Mar/17 ] |
|
Please don't close this without fixing. The associated support issue is still open, and we do expect a fix. Contrary to what Jan writes, it is an actual bug in magnolia (it's not that hard to follow in the code, JcrResource keeps a node reference around which goes stale and does not check it before using it again). |
| Comment by Mikaël Geljić [ 17/Mar/17 ] |
|
Hi Richard, TL;DR The bug only manifests itself because of the light-yaml module, precisely because YamlConfigurationDataProvider keeps hard-refs to JcrResources. This is otherwise not the case in the product—and I tried hard to prove otherwise. Each request gets a brand new JcrResource associated to its own node within current session/thread, and those resources are as much throwaway as the node itself. I don't debate JcrResource#getNode is error-prone, and upon short discussion should be fixed by using LazyNodeWrapper or SystemNodeWrapper. Any chance you can test if that does the trick as well for you? I'm asking because, for your information, YAML extends are being productized ( Now about light-yaml itself, I consider it as much a questionable choice to ping the registries and potentially refresh template defs upon rendering. I'm less bothered for dialog defs as they're not public-facing, though I can't see why they wouldn't suffer the same trouble here. I'll ask the guys to specifically verify it in the scope of Cheers, |