pinpoint-apm / pinpoint

APM, (Application Performance Management) tool for large-scale distributed systems.
https://pinpoint-apm.gitbook.io/
Apache License 2.0
13.42k stars 3.76k forks source link

initializing deadlock issue #8712

Open jiho-song-yanolja opened 2 years ago

jiho-song-yanolja commented 2 years ago

What version of pinpoint are you using?

v2.3.3

Describe the bug

I found a deadlock while initializing pintpoint version 2.3.3.

Because of this deadlock, the application system couldn't be initialized at all.

Personally I suspect two of same java constructor initializing locks may be locked each other, but not sure if this is the case, since we don't have any more details within the stack trace.

I attached the thread dump along with this.

03-17 08:13:12.012 [eadlock-monitor] WARN c.n.p.p.m.DeadlockMonitorTask -- ================================================================ [PINPOINT] Found one Java-level deadlock: If pinpoints affect the deadlock below, please put all the information posted on pinpoint's github. (https://github.com/naver/pinpoint/issues) ================================================================ "main" Id=1 BLOCKED on jdk.internal.loader.URLClassPath@4b98bcf0 owned by "Attach Listener" Id=33 at java.base@11.0.14.1/jdk.internal.loader.URLClassPath.getLoader(URLClassPath.java:423) - blocked on jdk.internal.loader.URLClassPath@4b98bcf0 at java.base@11.0.14.1/jdk.internal.loader.URLClassPath.getResource(URLClassPath.java:314) at java.base@11.0.14.1/jdk.internal.loader.BuiltinClassLoader.findClassOnClassPathOrNull(BuiltinClassLoader.java:695) at java.base@11.0.14.1/jdk.internal.loader.BuiltinClassLoader.loadClassOrNull(BuiltinClassLoader.java:621) at java.base@11.0.14.1/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:579) at java.base@11.0.14.1/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:178) at java.base@11.0.14.1/java.lang.ClassLoader.loadClass(ClassLoader.java:522) at app//org.springframework.boot.loader.jar.JarFile.getUrl(JarFile.java:321) at app//org.springframework.boot.loader.archive.JarFileArchive.getUrl(JarFileArchive.java:73) at app//org.springframework.boot.loader.Launcher.createClassLoader(Launcher.java:62) at app//org.springframework.boot.loader.Launcher.launch(Launcher.java:49) at app//org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:51) "Attach Listener" Id=33 BLOCKED on [I@a131288 owned by "main" Id=1 at java.base@11.0.14.1/java.lang.Class.getDeclaredConstructors0(Native Method) - blocked on [I@a131288 at java.base@11.0.14.1/java.lang.Class.privateGetDeclaredConstructors(Class.java:3137) at java.base@11.0.14.1/java.lang.Class.getConstructor0(Class.java:3342) at java.base@11.0.14.1/java.lang.Class.newInstance(Class.java:556) at java.base@11.0.14.1/java.net.URL.lookupViaProperty(URL.java:1291) at java.base@11.0.14.1/java.net.URL.getURLStreamHandler(URL.java:1441) at java.base@11.0.14.1/java.net.URL.<init>(URL.java:451) at java.base@11.0.14.1/jdk.internal.loader.URLClassPath$JarLoader.<init>(URLClassPath.java:720) at java.base@11.0.14.1/jdk.internal.loader.URLClassPath$3.run(URLClassPath.java:494) at java.base@11.0.14.1/jdk.internal.loader.URLClassPath$3.run(URLClassPath.java:477) at java.base@11.0.14.1/java.security.AccessController.doPrivileged(Native Method) at java.base@11.0.14.1/jdk.internal.loader.URLClassPath.getLoader(URLClassPath.java:476) at java.base@11.0.14.1/jdk.internal.loader.URLClassPath.getLoader(URLClassPath.java:445) at java.base@11.0.14.1/jdk.internal.loader.URLClassPath.getResource(URLClassPath.java:314) at java.base@11.0.14.1/jdk.internal.loader.BuiltinClassLoader.findClassOnClassPathOrNull(BuiltinClassLoader.java:695) at java.base@11.0.14.1/jdk.internal.loader.BuiltinClassLoader.loadClassOrNull(BuiltinClassLoader.java:621) at java.base@11.0.14.1/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:579) at java.base@11.0.14.1/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:178) at java.base@11.0.14.1/java.lang.ClassLoader.loadClass(ClassLoader.java:522) at java.instrument@11.0.14.1/sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:431) at java.instrument@11.0.14.1/sun.instrument.InstrumentationImpl.loadClassAndCallAgentmain(InstrumentationImpl.java:535)

What did you do to trigger the bug?

This only happens on the very small chance. We've been using pinpoint v2.3.3 from this january for many instances, but this is the first and last case.

  1. Our pinpoint agent is up and running by ebexentenstion of AWS while initializing the instance.
  2. Among those pinpoint configuration(pinpoint.config), we set profiler.kafka.producer.enable to true, profiler.redis.lettuce.enable to false, profiler/tomcat/excludeurl to /health. (I'm not sure if this is relevant to the issue)

Expected behavior

pinpoint agent should be initialized without any problem.

Additional context

I feel sorry If the log wasn't helpful enough. I would appreciate if you can guide us on how i might find better information/logs for debugging. Thank you.

emeroad commented 2 years ago

If the problem is reproduced, could you please create a thread dump?

jstack -l ${JAVA_PID} > thread-dump.txt

https://www.baeldung.com/java-thread-dump

testn commented 1 year ago

Did you manage to reproduce it?

lu1235353884 commented 9 months ago

we use pinpoint version is v2.3.0 we found a deadlock while initializing pintpoint :

Among those pinpoint configuration(pinpoint.config), we set profiler.plugin.disable=com.navercorp.pinpoint.plugin.gson.GsonPlugin

initializing log:

01-22 13:31:36.036 [eadlock-monitor] WARN  c.n.p.p.m.DeadlockMonitorTask            -- 
================================================================
[PINPOINT] Found one Java-level deadlock:

If pinpoints affect the deadlock below, please put all the information posted on pinpoint's github.
(https://github.com/naver/pinpoint/issues)
================================================================
"http-nio-32622-exec-61" Id=176 BLOCKED on [I@29708459 owned by "http-nio-32622-exec-55" Id=170
    at com.digiwin.bm.mosc.mo.service.impl.business.mkp.modaily.GetSingleSchedulePlanInfoService.getSingleSchedulePlanInfo(GetSingleSchedulePlanInfoService.java:77)
    -  blocked on [I@29708459
    at com.digiwin.bm.mosc.mo.service.impl.business.mkp.modaily.GetSingleSchedulePlanInfoService$$FastClassBySpringCGLIB$$a8664c22.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:747)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.transaction.interceptor.TransactionInterceptor$$Lambda$1021/1132755845.proceedWithInvocation(Unknown Source)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:294)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at com.digiwin.app.container.ServicePublicMethodLogInterceptor.invoke(ServicePublicMethodLogInterceptor.java:66)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
    at com.digiwin.bm.mosc.mo.service.impl.business.mkp.modaily.GetSingleSchedulePlanInfoService$$EnhancerBySpringCGLIB$$f44a9aaf.getSingleSchedulePlanInfo(<generated>)
    at com.digiwin.bm.mosc.mo.service.impl.mkp.modaily.ModailyService.getSingleSchedulePlanInfo(ModailyService.java:312)
    at com.digiwin.bm.mosc.mo.service.impl.mkp.modaily.ModailyService$$FastClassBySpringCGLIB$$f282c739.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:747)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at com.digiwin.app.container.ServicePublicMethodLogInterceptor.invoke(ServicePublicMethodLogInterceptor.java:66)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
    at com.digiwin.bm.mosc.mo.service.impl.mkp.modaily.ModailyService$$EnhancerBySpringCGLIB$$ee16fa40.getSingleSchedulePlanInfo(<generated>)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.digiwin.app.container.ServiceFuse.execute(ServiceFuse.java:17)
    at com.digiwin.gateway.fuse.execute.DWFuseRunnable.lambda$getReturnConsumer$11(DWFuseRunnable.java:47)