Thanks for the tips. We'll use that to see if we can learn anymore. I guess the main thing I want to try and figure out is if this is a Tapestry problem, or a problem in something we're doing with Tapestry. The latter seems more likely but we'll try to find out.
The good news is that we can reproduce this fairly consistently on server startup under simulated load, so we'll see what we can learn. -----Original Message----- From: Ben Weidig <b...@netzgut.net> Sent: Sunday, November 17, 2024 8:14 AM To: Tapestry users <users@tapestry.apache.org> Subject: Re: Thread locking (deadlock) issue using Tapestry 5.8.7 under heavy load [You don't often get email from b...@netzgut.net. Learn why this is important at https://aka.ms/LearnAboutSenderIdentification ] Hi Scott, Thanks for bringing this issue to our attention. I've looked through the JIRA and found https://issues.apache.org/jira/browse/TAP5-2621 with a similar thread dump attached. We're running multiple Tapestry instances with a varying degree of concurrent users and have yet to encounter a ClassLoader deadlock. Debugging and finding a deadlock in a ClassLoader is quite challenging due to the overall complexity of class loading. Deadlocks are quite hard to track down if there's no obvious problem in the ClassLoader code itself. That said, there are steps to gather additional information that might help pinpoint the root cause. Be aware that these are just my suggestions, as I'm highly versed ClassLoader infrastructure, maybe Thiago has some additional insights or better ideas In my opinion, identifying the specific class (and its dependencies) that triggers the deadlock would be an important first step. This could help highlight potential issues such as cyclic class dependencies, complex static initializers, or nested class loading. If the deadlock consistently involves the same classes, it would be a good starting point. Depending on your JVM/execution environment, you could try to enable more detailed logging around class loading using some of the following arguments: -verbose:class -XX:+UnlockDiagnosticVMOptions -XX:+PrintConcurrentLocks -XX:+TraceClassLoading -XX:+TraceClassResolution https://docs.oracle.com/javase/8/docs/technotes/tools/unix/java.html Having a full thread dump so https://jstack.review/ could visualize and making it easier to navigate could be helpful, too. Unfortunately, without a reproducible test case, it’s difficult to provide more concrete help, as these kind of issues usually require direct observation and debugability :-/ Cheers Ben On Fri, Nov 15, 2024 at 4:38 PM Scott McCarthy <scott.mccar...@clarivate.com> wrote: > Hi All, > > I just realised I'd previously posted this into the DEV group when I > should have posted it in the USER group. > Reposting in the correct mailing list - Sorry about that... > > I'll likely raise a JIRA ticket for this, but I wanted to start with > this mailing list. > I'll try to explain what we're seeing... > > We are running a fairly large Tapestry application with hundreds of > concurrent users. > When under load, we are occasionally seeing an instance go into > deadlock, whereby the Tomcat threads max out, but the CPU is virtually zero. > This can commonly occur when a new instance starts up under heavy > load, but can also happen on an instance that has been running for several > days. > > The log files give clues as to what's happening, but nothing definitive. > For example: > > > 2024-11-12T15:26:20.925Z {name=ip-10-242-182-176.ec2.internal} ERROR > [2024-11-12T15:26:13,611] > PQSL-STAT,start=2024-11-11.14:23:02,instance=i-01da4661bc7f47e18,host= > ip-10-242-182-176,sub=main,version=2024.11.0.7644 > 31/10/2024 > 07:39:01,hours=25.05,threadBlktime=0,threads=408,run=57,block=38,wait= > 133,timed=180,locks=[org.apache.tapestry5.services.pageload.PageClassL > oaderContextManagerImpl(2),java.util.jar.JarFile(10),java.lang.Object( > 25),java.io.ExpiringCache(1)],heapuse=16092,heapmax=24849,gc=1, > > 2024-11-12T15:26:20.925Z {name=ip-10-242-182-176.ec2.internal} ERROR > [2024-11-12T15:26:13,611] java.base@11.0.16 > /java.util.zip.ZipFile.getEntry(ZipFile.java:347)<mailto:java.base@11. > 0.16 /java.util.zip.ZipFile.getEntry(ZipFile.java:347)> > > 2024-11-12T15:26:20.925Z {name=ip-10-242-182-176.ec2.internal} > java.base@11.0.16 > /java.util.zip.ZipFile$1.getEntry(ZipFile.java:1143)<mailto: > java.base@11.0.16/java.util.zip.ZipFile$1.getEntry(ZipFile.java:1143)> > > 2024-11-12T15:26:20.925Z {name=ip-10-242-182-176.ec2.internal} > java.base@11.0.16 > /java.util.jar.JarFile.getEntry0(JarFile.java:586)<mailto: > java.base@11.0.16/java.util.jar.JarFile.getEntry0(JarFile.java:586)> > > 2024-11-12T15:26:20.925Z {name=ip-10-242-182-176.ec2.internal} > java.base@11.0.16 > /java.util.jar.JarFile.getEntry(JarFile.java:516)<mailto:java.base@11. > 0.16 /java.util.jar.JarFile.getEntry(JarFile.java:516)> > > 2024-11-12T15:26:20.926Z {name=ip-10-242-182-176.ec2.internal} > java.base@11.0.16 > /java.util.jar.JarFile.getJarEntry(JarFile.java:478)<mailto: > java.base@11.0.16/java.util.jar.JarFile.getJarEntry(JarFile.java:478)> > > 2024-11-12T15:26:20.926Z {name=ip-10-242-182-176.ec2.internal} > org.apache.catalina.webresources.AbstractSingleArchiveResourceSet.getA > rchiveEntry(AbstractSingleArchiveResourceSet.java:97) > > 2024-11-12T15:26:20.926Z {name=ip-10-242-182-176.ec2.internal} > > org.apache.catalina.webresources.AbstractArchiveResourceSet.getResourc > e(AbstractArchiveResourceSet.java:244) > > 2024-11-12T15:26:20.926Z {name=ip-10-242-182-176.ec2.internal} > > org.apache.catalina.webresources.StandardRoot.getResourceInternal(Stan > dardRoot.java:272) > > 2024-11-12T15:26:20.926Z {name=ip-10-242-182-176.ec2.internal} > org.apache.catalina.webresources.Cache.getResource(Cache.java:64) > > 2024-11-12T15:26:20.926Z {name=ip-10-242-182-176.ec2.internal} > > org.apache.catalina.webresources.StandardRoot.getResource(StandardRoot > .java:211) > > 2024-11-12T15:26:20.926Z {name=ip-10-242-182-176.ec2.internal} > > org.apache.catalina.webresources.StandardRoot.getClassLoaderResource(S > tandardRoot.java:220) > > 2024-11-12T15:26:20.926Z {name=ip-10-242-182-176.ec2.internal} > > org.apache.catalina.loader.WebappClassLoaderBase.findClassInternal(Web > appClassLoaderBase.java:2170) > > 2024-11-12T15:26:20.926Z {name=ip-10-242-182-176.ec2.internal} > > org.apache.catalina.loader.WebappClassLoaderBase.findClass(WebappClass > LoaderBase.java:797) > > 2024-11-12T15:26:20.926Z {name=ip-10-242-182-176.ec2.internal} > > org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClass > LoaderBase.java:1272) > > 2024-11-12T15:26:20.926Z {name=ip-10-242-182-176.ec2.internal} > > org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClass > LoaderBase.java:1120) > > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} ERROR > [2024-11-12T15:47:08,652] > PQSL-STAT,start=2024-11-12.15:46:07,instance=i-05996408538cc4fa2,host= > ip-10-243-125-250,sub=main,version=2024.11.0.7644 > 31/10/2024 > 07:39:01,hours=0.02,threadBlktime=0,threads=130,run=16,block=12,wait=7 > 8,timed=24,locks=[org.apache.tapestry5.internal.plastic.PlasticClassLo > ader(9),org.apache.tapestry5.beanmodel.internal.services.PropertyAcces > sImpl(3)],heapuse=607,heapmax=24849,gc=7, > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} ERROR > [2024-11-12T15:47:08,653] > > org.apache.tapestry5.internal.plastic.PlasticClassPool.realizeTransfor > medClass(PlasticClassPool.java:164) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.internal.plastic.PlasticClassImpl.createInstantia > tor(PlasticClassImpl.java:650) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.plastic.PlasticManager.createProxy(PlasticManager > .java:289) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.plastic.PlasticManager.createProxy(PlasticManager > .java:262) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.plastic.PlasticManager.createProxy(PlasticManager > .java:229) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.beanmodel.services.PlasticProxyFactoryImpl.create > Proxy(PlasticProxyFactoryImpl.java:86) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > org.apache.tapestry5.beanmodel.internal.services.PropertyConduitSource > Impl.build(PropertyConduitSourceImpl.java:1527) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > org.apache.tapestry5.beanmodel.internal.services.PropertyConduitSource > Impl.create(PropertyConduitSourceImpl.java:1441) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > $PropertyConduitSource_134db79fe0.create(Unknown Source) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.internal.bindings.PropBindingFactory.newBinding(P > ropBindingFactory.java:56) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > $BindingFactory_134db7a16b.newBinding(Unknown Source) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > $BindingFactory_134db7a162.newBinding(Unknown Source) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.internal.services.BindingSourceImpl.newBinding(Bi > ndingSourceImpl.java:82) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > $BindingSource_134db7a0ba.newBinding(Unknown Source) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > org.apache.tapestry5.internal.services.PageElementFactoryImpl.parseAtt > ributeExpansionExpression(PageElementFactoryImpl.java:117) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.internal.services.PageElementFactoryImpl.newBindi > ng(PageElementFactoryImpl.java:177) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > $PageElementFactory_134db7a0d5.newBinding(Unknown Source) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.internal.pageload.PageLoaderImpl$10.execute(PageL > oaderImpl.java:941) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.internal.pageload.ComponentAssemblerImpl.runActio > ns(ComponentAssemblerImpl.java:229) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.internal.pageload.ComponentAssemblerImpl.access$3 > 00(ComponentAssemblerImpl.java:37) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.internal.pageload.ComponentAssemblerImpl$2.run(Co > mponentAssemblerImpl.java:180) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.ioc.internal.OperationTrackerImpl.run(OperationTr > ackerImpl.java:56) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.ioc.internal.PerThreadOperationTracker.run(PerThr > eadOperationTracker.java:60) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.ioc.internal.RegistryImpl.run(RegistryImpl.java:1 > 286) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > org.apache.tapestry5.internal.pageload.ComponentAssemblerImpl.assemble > EmbeddedComponent(ComponentAssemblerImpl.java:158) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.internal.pageload.PageLoaderImpl$12.execute(PageL > oaderImpl.java:1021) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.internal.pageload.ComponentAssemblerImpl.runActio > ns(ComponentAssemblerImpl.java:229) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.internal.pageload.ComponentAssemblerImpl.access$3 > 00(ComponentAssemblerImpl.java:37) > > 2024-11-12T15:47:12.497Z {name=ip-10-243-125-250.ec2.internal} > > org.apache.tapestry5.internal.pageload.ComponentAssemblerImpl$2.run(Co > mponentAssemblerImpl.java:180) > > > 2024-11-12T16:16:05.913Z {name=ip-10-243-120-52.ec2.internal} ERROR > [2024-11-12T16:15:56,585] > PQSL-STAT,start=2024-11-11.14:22:40,instance=i-08bb147e7134c32e0,host= > ip-10-243-120-52,sub=main,version=2024.11.0.7644 > 31/10/2024 > 07:39:01,hours=25.89,threadBlktime=0,threads=436,run=70,block=93,wait= > 135,timed=130,locks=[org.apache.tapestry5.ioc.internal.util.Concurrent > Barrier$ThreadBoolean(31), > java.io > .RandomAccessFile(2),org.apache.logging.log4j.core.appender.rolling.Ro > llingFileManager(1),java.lang.Object(45),org.apache.catalina.webresour > ces.CachedResource(14)],heapuse=16444,heapmax=24849,gc=1, > > 2024-11-12T16:16:05.913Z {name=ip-10-243-120-52.ec2.internal} ERROR > [2024-11-12T16:15:56,585] > org.apache.catalina.webresources.AbstractSingleArchiveResourceSet.getA > rchiveEntries(AbstractSingleArchiveResourceSet.java:66) > > 2024-11-12T16:16:05.913Z {name=ip-10-243-120-52.ec2.internal} > > org.apache.catalina.webresources.AbstractArchiveResourceSet.getResourc > e(AbstractArchiveResourceSet.java:246) > > 2024-11-12T16:16:05.914Z {name=ip-10-243-120-52.ec2.internal} > > org.apache.catalina.webresources.StandardRoot.getResourceInternal(Stan > dardRoot.java:272) > > 2024-11-12T16:16:05.914Z {name=ip-10-243-120-52.ec2.internal} > > org.apache.catalina.webresources.CachedResource.validateResource(Cache > dResource.java:127) > > 2024-11-12T16:16:05.914Z {name=ip-10-243-120-52.ec2.internal} > org.apache.catalina.webresources.Cache.getResource(Cache.java:78) > > 2024-11-12T16:16:05.914Z {name=ip-10-243-120-52.ec2.internal} > > org.apache.catalina.webresources.StandardRoot.getResource(StandardRoot > .java:211) > > 2024-11-12T16:16:05.914Z {name=ip-10-243-120-52.ec2.internal} > > org.apache.catalina.webresources.StandardRoot.getClassLoaderResource(S > tandardRoot.java:220) > > 2024-11-12T16:16:05.914Z {name=ip-10-243-120-52.ec2.internal} > > org.apache.catalina.loader.WebappClassLoaderBase.findResource(WebappCl > assLoaderBase.java:872) > > 2024-11-12T16:16:05.914Z {name=ip-10-243-120-52.ec2.internal} > > org.apache.catalina.loader.WebappClassLoaderBase.getResource(WebappCla > ssLoaderBase.java:981) > > 2024-11-12T16:16:05.914Z {name=ip-10-243-120-52.ec2.internal} > java.base@11.0.16/java.lang.Class.getResource(Class.java:2740)<mailto: > java.base@11.0.16/java.lang.Class.getResource(Class.java:2740)> > > > 07:39:01,hours=0.05,threadBlktime=0,threads=135,run=15,block=10,wait=8 > 4,timed=26,locks=[org.apache.tapestry5.internal.plastic.PlasticClassPo > ol(3),java.util.concurrent.ConcurrentHashMap$ReservationNode(2),java.u > til.concurrent.ConcurrentHashMap$Node(1),org.apache.tapestry5.beanmode > l.internal.services.PropertyAccessImpl(3),java.lang.Object(1)],heapuse > =279,heapmax=24849,gc=1, > ERROR [2024-11-14T12:12:47,871] > > org.apache.tapestry5.internal.plastic.PlasticClassLoader.loadClass(PlasticClassLoader.java:59) > java.base@11.0.16 > /java.lang.ClassLoader.loadClass(ClassLoader.java:522)<mailto: > java.base@11.0.16/java.lang.ClassLoader.loadClass(ClassLoader.java:522 > )> > > org.apache.tapestry5.internal.plastic.PlasticClassPool.createTransform > ation(PlasticClassPool.java:511) > > > org.apache.tapestry5.internal.plastic.PlasticClassPool.getPlasticClass > Transformation(PlasticClassPool.java:492) > > org.apache.tapestry5.internal.plastic.PlasticClassPool.loadAndTransfor > mClass(PlasticClassPool.java:399) > > org.apache.tapestry5.internal.plastic.PlasticClassLoader.loadClass(PlasticClassLoader.java:76) > java.base@11.0.16 > /java.lang.ClassLoader.loadClass(ClassLoader.java:522)<mailto: > java.base@11.0.16/java.lang.ClassLoader.loadClass(ClassLoader.java:522 > )> > > org.apache.tapestry5.internal.plastic.PlasticClassPool.getClassInstant > iator(PlasticClassPool.java:667) > > org.apache.tapestry5.plastic.PlasticManager.getClassInstantiator(Plast > icManager.java:187) > > org.apache.tapestry5.internal.services.ComponentInstantiatorSourceImpl > $2.invoke(ComponentInstantiatorSourceImpl.java:436) > > org.apache.tapestry5.internal.services.ComponentInstantiatorSourceImpl > $2.invoke(ComponentInstantiatorSourceImpl.java:385) > > org.apache.tapestry5.ioc.internal.OperationTrackerImpl.invoke(Operatio > nTrackerImpl.java:82) > > org.apache.tapestry5.ioc.internal.PerThreadOperationTracker.invoke(Per > ThreadOperationTracker.java:72) > > org.apache.tapestry5.ioc.internal.RegistryImpl.invoke(RegistryImpl.jav > a:1292) > > org.apache.tapestry5.internal.services.ComponentInstantiatorSourceImpl > .createInstantiatorForClass(ComponentInstantiatorSourceImpl.java:383) > > > org.apache.tapestry5.internal.services.ComponentInstantiatorSourceImpl > $$Lambda$351/0x0000000800872040.apply(Unknown > Source) > java.base@11.0.16 > /java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1737)<mailto: > java.base@11.0.16 > /java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHash > Map.java:1737)> > > Have I uncovered a genuine thread locking issue that I should raise a > JIRA ticket for? > Or does anyone have any ideas of something I can change to prevent this? > > I realise I'm only providing a tiny snippet of our overall system, but > any suggestions would be welcome. > > Thank you. > > Scott > > Confidentiality note: This e-mail may contain confidential information > from Clarivate. If you are not the intended recipient, be aware that > any disclosure, copying, distribution or use of the contents of this > e-mail is strictly prohibited. If you have received this e-mail in > error, please delete this e-mail and notify the sender as soon as possible. > Confidentiality note: This e-mail may contain confidential information from Clarivate. If you are not the intended recipient, be aware that any disclosure, copying, distribution or use of the contents of this e-mail is strictly prohibited. If you have received this e-mail in error, please delete this e-mail and notify the sender as soon as possible. --------------------------------------------------------------------- To unsubscribe, e-mail: users-unsubscr...@tapestry.apache.org For additional commands, e-mail: users-h...@tapestry.apache.org
