Pinpoint: AppClassLoader and PinpointUrlClassLoader Circular dependency deadlock

Created on 28 Apr 2017 · 9Comments · Source: pinpoint-apm/pinpoint

Description

Hello, I've got a problem recently. In my application, I used pinpoint-1.6.0 to trace my dubbo service. I found that my application can't start sometimes, not always. When I used jstack to see the thread debug information, I have got the below:

yh_jstack.txt the whole log file

Found one Java-level deadlock:

"Pinpoint-stat-monitor(18-0)":
waiting to lock monitor 0x086e0958 (object 0xe768b260, a sun.misc.Launcher$AppClassLoader),
which is held by "main"
"main":
waiting to lock monitor 0x08102094 (object 0xe768b210, a com.navercorp.pinpoint.bootstrap.PinpointURLClassLoader),
which is held by "Pinpoint-stat-monitor(18-0)"

Java stack information for the threads listed above:

"Pinpoint-stat-monitor(18-0)":
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:293)
- waiting to lock <0xe768b260> (a sun.misc.Launcher$AppClassLoader)
at java.lang.ClassLoader.loadClass(ClassLoader.java:247)
at com.navercorp.pinpoint.bootstrap.PinpointURLClassLoader.loadClass(PinpointURLClassLoader.java:65)
- locked <0xe768b210> (a com.navercorp.pinpoint.bootstrap.PinpointURLClassLoader)
at java.lang.ClassLoader.loadClass(ClassLoader.java:247)
at com.navercorp.pinpoint.profiler.monitor.codahale.activetrace.metric.ActiveTraceMetricSet$ActiveTraceHistogramGauge.getValue(ActiveTraceMetricSet.java:69)
at com.navercorp.pinpoint.profiler.monitor.codahale.activetrace.metric.ActiveTraceMetricSet$ActiveTraceHistogramGauge.getValue(ActiveTraceMetricSet.java:57)
at com.navercorp.pinpoint.profiler.monitor.codahale.activetrace.DefaultActiveTraceMetricCollector.collect(DefaultActiveTraceMetricCollector.java:50)
at com.navercorp.pinpoint.profiler.monitor.codahale.activetrace.DefaultActiveTraceMetricCollector.collect(DefaultActiveTraceMetricCollector.java:33)
at com.navercorp.pinpoint.profiler.monitor.AgentStatMonitor$CollectJob.collectAgentStat(AgentStatMonitor.java:154)
at com.navercorp.pinpoint.profiler.monitor.AgentStatMonitor$CollectJob.run(AgentStatMonitor.java:131)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)
"main":
at com.navercorp.pinpoint.profiler.instrument.ASMClass.addField(ASMClass.java:223)
at com.navercorp.pinpoint.plugin.jdbc.oracle.OraclePlugin$1.doInTransform(OraclePlugin.java:71)
at com.navercorp.pinpoint.profiler.plugin.MatchableClassFileTransformerGuardDelegate.transform(MatchableClassFileTransformerGuardDelegate.java:70)
at com.navercorp.pinpoint.profiler.ClassFileTransformerDispatcher.transform0(ClassFileTransformerDispatcher.java:120)
at com.navercorp.pinpoint.profiler.ClassFileTransformerDispatcher.transform(ClassFileTransformerDispatcher.java:101)
at sun.instrument.TransformerManager.transform(TransformerManager.java:169)
at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:365)
at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClassCond(ClassLoader.java:631)
at java.lang.ClassLoader.defineClass(ClassLoader.java:615)
at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:141)
at java.net.URLClassLoader.defineClass(URLClassLoader.java:283)
at java.net.URLClassLoader.access$000(URLClassLoader.java:58)
at java.net.URLClassLoader$1.run(URLClassLoader.java:197)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:190)
at java.lang.ClassLoader.loadClass(ClassLoader.java:306)
- locked <0xe768b260> (a sun.misc.Launcher$AppClassLoader)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:301)
- locked <0xe768b260> (a sun.misc.Launcher$AppClassLoader)
at java.lang.ClassLoader.loadClass(ClassLoader.java:247)
at oracle.jdbc.driver.OracleDriver.(OracleDriver.java:281)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:249)
at org.apache.tomcat.jdbc.pool.PooledConnection.connectUsingDriver(PooledConnection.java:246)
at org.apache.tomcat.jdbc.pool.PooledConnection.connect(PooledConnection.java:182)
at org.apache.tomcat.jdbc.pool.ConnectionPool.createConnection(ConnectionPool.java:702)
at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:634)
at org.apache.tomcat.jdbc.pool.ConnectionPool.init(ConnectionPool.java:488)
at org.apache.tomcat.jdbc.pool.ConnectionPool.(ConnectionPool.java:144)
at org.apache.tomcat.jdbc.pool.DataSourceProxy.pCreatePool(DataSourceProxy.java:116)
- locked <0xe12e4730> (a org.apache.tomcat.jdbc.pool.DataSource)
at org.apache.tomcat.jdbc.pool.DataSourceProxy.createPool(DataSourceProxy.java:103)
at org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:127)
at org.apache.ibatis.mapping.VendorDatabaseIdProvider.getDatabaseProductName(VendorDatabaseIdProvider.java:76)
at org.apache.ibatis.mapping.VendorDatabaseIdProvider.getDatabaseName(VendorDatabaseIdProvider.java:61)
at org.apache.ibatis.mapping.VendorDatabaseIdProvider.getDatabaseId(VendorDatabaseIdProvider.java:49)
at org.mybatis.spring.SqlSessionFactoryBean.buildSqlSessionFactory(SqlSessionFactoryBean.java:445)
at org.mybatis.spring.SqlSessionFactoryBean.afterPropertiesSet(SqlSessionFactoryBean.java:336)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1571)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1509)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:521)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:458)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:296)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:223)
- locked <0xe772dc70> (a java.util.concurrent.ConcurrentHashMap)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:293)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:194)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.findAutowireCandidates(DefaultListableBeanFactory.java:912)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:855)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:770)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireByType(AbstractAutowireCapableBeanFactory.java:1224)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1131)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:458)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:296)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:223)
- locked <0xe772dc70> (a java.util.concurrent.ConcurrentHashMap)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:293)
at org.springframework.beans.factory.support.AbstractBeanFactory.getTypeForFactoryBean(AbstractBeanFactory.java:1374)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.getTypeForFactoryBean(AbstractAutowireCapableBeanFactory.java:750)
at org.springframework.beans.factory.support.AbstractBeanFactory.isTypeMatch(AbstractBeanFactory.java:529)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.doGetBeanNamesForType(DefaultListableBeanFactory.java:356)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeanNamesForType(DefaultListableBeanFactory.java:334)
at org.springframework.beans.factory.BeanFactoryUtils.beanNamesForTypeIncludingAncestors(BeanFactoryUtils.java:187)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.findAutowireCandidates(DefaultListableBeanFactory.java:897)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:855)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:770)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireByType(AbstractAutowireCapableBeanFactory.java:1224)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1131)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:458)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:296)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:223)
- locked <0xe772dc70> (a java.util.concurrent.ConcurrentHashMap)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:293)
at org.springframework.beans.factory.support.AbstractBeanFactory.getTypeForFactoryBean(AbstractBeanFactory.java:1374)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.getTypeForFactoryBean(AbstractAutowireCapableBeanFactory.java:750)
at org.springframework.beans.factory.support.AbstractBeanFactory.isTypeMatch(AbstractBeanFactory.java:529)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.doGetBeanNamesForType(DefaultListableBeanFactory.java:356)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeanNamesForType(DefaultListableBeanFactory.java:334)
at org.springframework.beans.factory.BeanFactoryUtils.beanNamesForTypeIncludingAncestors(BeanFactoryUtils.java:187)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.findAutowireCandidates(DefaultListableBeanFactory.java:897)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:855)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:770)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireByType(AbstractAutowireCapableBeanFactory.java:1224)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1131)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:458)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:296)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:223)
- locked <0xe772dc70> (a java.util.concurrent.ConcurrentHashMap)

Analysis

From the debug info, the deadlock happend between the main thread and the monitor thread, they bouth want to use the AppClassLoader and PinpointUrlClassLoader. But it is a Circular dependency. I thought if I want to resolve problem, I need to make the pinpoint-agent load the need class at the begining of the application start, but I can't find out which package I need to load first.

Can you gave me a help or some advise, thank you very much?

bug agent

Source

zhangzhaoyu

Most helpful comment

the method's signature of "loadClass()" in ClassLoader in jdk1.7.0_67 and jdk1.8.0_45 are not same as defined in jdk6 and in PinpointURLClassLoader.The last two's method signature have keyword "synchronized" , this may cause deadlock in jdk6 , and some other Scenario(i guess). you can lookup in this website:http://docs.oracle.com/javase/7/docs/technotes/guides/lang/cl-mt.html . I think this may have give you some clues to solve this problem .

huayaoyue6 on 14 Aug 2017

❤1 😄1 👍1

All 9 comments

We have not yet supported the parallel classloader.

There is a problem with JDK 6 compatibility.

emeroad on 28 Apr 2017

Hi zhangzhaoyu

I was aware of the problem, and I was worried about it.

I added function of parallel load to ClassLoader when using JDK7 or later.
If possible, I recommend you try again with the latest master branch using JDK7 or later.

If you have any problems, please let me know

thanks. :)

koo-taejin on 2 May 2017

Thanks for your answer. When I tested it on JDK1.8, It worked well. But in my comapny, because of some reasons I just can use JDK1.6.

zhangzhaoyu on 10 May 2017

@zhangzhaoyu
I used preload to avoid the deadlock problem.
Please check if deadlock occurs in JDK6.

emeroad on 15 May 2017

Hi @emeroad , I was so busy the past days. But currently, I have time to test this issue. Whether I just need to clone the pinpoint master branch code to test? I see your milestore is 1.7.0 which has not been released.

zhangzhaoyu on 22 May 2017

Hi, @emeroad @koo-taejin , I have cloned the current master branch and test it with my application in jdk1.6. Unfortunately, the bug is still here.

The log of the console stoped here often, when the dead lock happened:

jstack01