[MAGNOLIA-8362] Add debug logging for tracking SystemRepositoryStrategy instances Created: 25/Mar/22 Updated: 15/Apr/22 Resolved: 29/Mar/22 |
|
| Status: | Closed |
| Project: | Magnolia |
| Component/s: | core |
| Affects Version/s: | None |
| Fix Version/s: | 6.2.18 |
| Type: | Improvement | Priority: | Neutral |
| Reporter: | Michael Duerig | Assignee: | Michael Duerig |
| Resolution: | Done | Votes: | 0 |
| Labels: | foundation_team | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Issue Links: |
|
||||||||||||||||
| Template: |
|
||||||||||||||||
| Acceptance criteria: |
Empty
|
||||||||||||||||
| Task DoD: |
[X]*
Doc/release notes changes? Comment present?
[X]*
Downstream builds green?
[X]*
Solution information and context easily available?
[X]*
Tests
[X]*
FixVersion filled and not yet released
[ ] 
Architecture Decision Record (ADR)
|
||||||||||||||||
| Release notes required: |
Yes
|
||||||||||||||||
| Date of First Response: | |||||||||||||||||
| Description |
|
org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [magnoliaAuthor] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@7d3d101b]) and a value of type [info.magnolia.context.SystemRepositoryStrategy] (value [info.magnolia.context.SystemRepositoryStrategy@5cdec700]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak. So far we were not able to reliably reproduce the problem. For making it easier to diagnose the problem we should implement additional logging to make above warning more helpful. Instead of logging SystemRepositoryStrategy@5cdec700 we should log the stack trace from the time the affected SystemRepositoryStrategy instance was created. |
| Comments |
| Comment by Michael Duerig [ 25/Mar/22 ] |
|
Implemented solution When WebappClassLoaderBase.checkThreadLocalMapForLeaks() detects a leaked SystemRepositoryStrategy instance it now logs it as SystemRepositoryStrategy[No creation stack trace available. Enable DEBUG logging for class info.magnolia.context.SystemRepositoryStrategy to enable it.] indicating that enabling debug logging for info.magnolia.context.SystemRepositoryStrategy helps to collect the stack traces for where those leaked instances have been created. With debug logging enabled SystemRepositoryStrategy instances are logged as SystemRepositoryStrategy[Creation stack trace =[info.magnolia.context.SystemRepositoryStrategy.<init>(SystemRepositoryStrategy.java:64), sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method), sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62), sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45), java.lang.reflect.Constructor.newInstance(Constructor.java:423), info.magnolia.objectfactory.ObjectManufacturer.newInstance(ObjectManufacturer.java:129), info.magnolia.objectfactory.ObjectManufacturer.newInstance(ObjectManufacturer.java:99), info.magnolia.objectfactory.guice.GuiceComponentProvider.newInstanceWithParameterResolvers(GuiceComponentProvider.java:134), info.magnolia.objectfactory.guice.GuiceComponentProvider.newInstanceWithParameterResolvers(GuiceComponentProvider.java:120), info.magnolia.objectfactory.guice.GuiceComponentProvider.newInstance(GuiceComponentProvider.java:115), info.magnolia.objectfactory.Components.newInstance(Components.java:100), info.magnolia.context.JCRSessionPerThreadSystemContext.getRepositoryStrategy(JCRSessionPerThreadSystemContext.java:50), info.magnolia.context.AbstractContext.getJCRSession(AbstractContext.java:124), info.magnolia.module.groovy.support.classes.MgnlGroovyResourceLoader.loadGroovySourceFromRepository(MgnlGroovyResourceLoader.java:110), info.magnolia.module.groovy.support.classes.MgnlGroovyResourceLoader.loadGroovySource(MgnlGroovyResourceLoader.java:89), groovy.lang.GroovyClassLoader.loadClass(GroovyClassLoader.java:906), groovy.lang.GroovyClassLoader.loadClass(GroovyClassLoader.java:745), info.magnolia.module.groovy.support.classes.GroovyClassFactory.forName(GroovyClassFactory.java:99), info.magnolia.objectfactory.configuration.LegacyComponentsConfigurer.classForName(LegacyComponentsConfigurer.java:150), info.magnolia.objectfactory.configuration.LegacyComponentsConfigurer.addComponent(LegacyComponentsConfigurer.java:95), info.magnolia.objectfactory.configuration.LegacyComponentsConfigurer.doWithConfiguration(LegacyComponentsConfigurer.java:88), info.magnolia.objectfactory.guice.GuiceComponentProviderBuilder.build(GuiceComponentProviderBuilder.java:111), info.magnolia.objectfactory.guice.GuiceComponentProviderBuilder.build(GuiceComponentProviderBuilder.java:195), info.magnolia.cms.beans.config.ConfigLoader.load(ConfigLoader.java:142), info.magnolia.init.MagnoliaServletContextListener$1.doExec(MagnoliaServletContextListener.java:259), info.magnolia.context.MgnlContext$VoidOp.exec(MgnlContext.java:407), info.magnolia.context.MgnlContext$VoidOp.exec(MgnlContext.java:404), info.magnolia.context.MgnlContext.doInSystemContext(MgnlContext.java:378), info.magnolia.init.MagnoliaServletContextListener.startServer(MagnoliaServletContextListener.java:256), info.magnolia.init.MagnoliaServletContextListener.contextInitialized(MagnoliaServletContextListener.java:182), info.magnolia.init.MagnoliaServletContextListener.contextInitialized(MagnoliaServletContextListener.java:128), org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4643), org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5109), org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183), org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:742), org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:718), org.apache.catalina.core.StandardHost.addChild(StandardHost.java:703), org.apache.catalina.startup.HostConfig.manageApp(HostConfig.java:1737), sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method), sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62), sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43), java.lang.reflect.Method.invoke(Method.java:498), org.apache.tomcat.util.modeler.BaseModelMBean.invoke(BaseModelMBean.java:287), com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819), com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801), org.apache.catalina.mbeans.MBeanFactory.createStandardContext(MBeanFactory.java:457), org.apache.catalina.mbeans.MBeanFactory.createStandardContext(MBeanFactory.java:406), sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method), sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62), sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43), java.lang.reflect.Method.invoke(Method.java:498), org.apache.tomcat.util.modeler.BaseModelMBean.invoke(BaseModelMBean.java:287), com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819), com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801), com.sun.jmx.remote.security.MBeanServerAccessController.invoke(MBeanServerAccessController.java:468), javax.management.remote.rmi.RMIConnectionImpl.doOperation(RMIConnectionImpl.java:1468), javax.management.remote.rmi.RMIConnectionImpl.access$300(RMIConnectionImpl.java:76), javax.management.remote.rmi.RMIConnectionImpl$PrivilegedOperation.run(RMIConnectionImpl.java:1309), java.security.AccessController.doPrivileged(Native Method), javax.management.remote.rmi.RMIConnectionImpl.doPrivilegedOperation(RMIConnectionImpl.java:1408), javax.management.remote.rmi.RMIConnectionImpl.invoke(RMIConnectionImpl.java:829), sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method), sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62), sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43), java.lang.reflect.Method.invoke(Method.java:498), sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357), sun.rmi.transport.Transport$1.run(Transport.java:200), sun.rmi.transport.Transport$1.run(Transport.java:197), java.security.AccessController.doPrivileged(Native Method), sun.rmi.transport.Transport.serviceCall(Transport.java:196), sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:573), sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:834), sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:688), java.security.AccessController.doPrivileged(Native Method), sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:687), java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149), java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624), java.lang.Thread.run(Thread.java:748)]] |
| Comment by Roman Kovařík [ 28/Mar/22 ] |
|
Could we forward-port this to 6.3? |