为什么 grpc java 线程在被阻塞行周围没有任何锁或同步语法的情况下被阻塞

问题描述 投票:0回答:1

在应用程序启动时,我注意到 gRPC 客户端流的初始化出现了极大的延迟。通过日志和 jstack 的彻底检查,我发现“grpc-default-executor-{x}”线程表现出严重的缓慢。我使用 jstack 以 0.1 秒的间隔进行定期线程转储,下面是从线程转储日志中提取的一些值得注意的行:

thread_dump_27.log:

2024-05-24 17:44:35
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.131-b11 mixed mode):
...
"grpc-default-executor-1" #246 daemon prio=5 os_prio=0 tid=0x00007fd6e803c000 nid=0x6427 runnable [0x00007fd6bf960000]
   java.lang.Thread.State: RUNNABLE
        at java.lang.ClassLoader$NativeLibrary.find(Native Method)
        at java.lang.ClassLoader.findNative(ClassLoader.java:1963)
        - locked <0x00000006c0065c20> (a java.util.Vector)
        at java.net.PlainDatagramSocketImpl.connect0(Native Method)
        at java.net.AbstractPlainDatagramSocketImpl.connect(AbstractPlainDatagramSocketImpl.java:114)
        at java.net.DatagramSocket.connectInternal(DatagramSocket.java:152)
        - locked <0x000000078c4fdd40> (a java.net.DatagramSocket)
        at java.net.DatagramSocket.connect(DatagramSocket.java:458)
        at com.sun.jndi.dns.DnsClient.doUdpQuery(DnsClient.java:400)
        - locked <0x000000078c4fdd40> (a java.net.DatagramSocket)
        at com.sun.jndi.dns.DnsClient.query(DnsClient.java:208)
        at com.sun.jndi.dns.Resolver.query(Resolver.java:81)
        at com.sun.jndi.dns.DnsContext.c_getAttributes(DnsContext.java:434)


...

"grpc-default-executor-0" #245 daemon prio=5 os_prio=0 tid=0x00007fd768037000 nid=0x6422 waiting for monitor entry [0x00007fd6bfe65000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at java.lang.ClassLoader.findNative(ClassLoader.java:1960)
        - waiting to lock <0x00000006c0065c20> (a java.util.Vector)
        at java.net.PlainDatagramSocketImpl.connect0(Native Method)
        at java.net.AbstractPlainDatagramSocketImpl.connect(AbstractPlainDatagramSocketImpl.java:114)
        at java.net.DatagramSocket.connectInternal(DatagramSocket.java:152)
        - locked <0x0000000788977f00> (a java.net.DatagramSocket)
        at java.net.DatagramSocket.connect(DatagramSocket.java:458)
        at com.sun.jndi.dns.DnsClient.doUdpQuery(DnsClient.java:400)
        - locked <0x0000000788977f00> (a java.net.DatagramSocket)
        at com.sun.jndi.dns.DnsClient.query(DnsClient.java:208

thread_dump_28.log

2024-05-24 17:44:36
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.131-b11 mixed mode):
...
"grpc-default-executor-1" #246 daemon prio=5 os_prio=0 tid=0x00007fd6e803c000 nid=0x6427 waiting for monitor entry [0x00007fd6bf961000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at io.grpc.netty.shaded.io.grpc.netty.NettyChannelBuilder$NettyTransportFactory.newClientTransport(NettyChannelBuilder.java:727)
        at io.grpc.internal.CallCredentialsApplyingTransportFactory.newClientTransport(CallCredentialsApplyingTransportFactory.java:58)
        at io.grpc.internal.InternalSubchannel.startNewTransport(InternalSubchannel.java:254)
        at io.grpc.internal.InternalSubchannel.access$400(InternalSubchannel.java:66)
        at io.grpc.internal.InternalSubchannel$2.run(InternalSubchannel.java:201)
        at io.grpc.SynchronizationContext.drain(SynchronizationContext.java:95)
        at io.grpc.SynchronizationContext.execute(SynchronizationContext.java:127)
        at io.grpc.internal.ManagedChannelImpl$NameResolverListener.onResult(ManagedChannelImpl.java:1878)
        at io.grpc.internal.DnsNameResolver$Resolve.run(DnsNameResolver.java:333)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

...
"grpc-default-executor-0" #245 daemon prio=5 os_prio=0 tid=0x00007fd768037000 nid=0x6422 runnable [0x00007fd6bfe5e000]
   java.lang.Thread.State: RUNNABLE
        at java.net.URL.toExternalForm(URL.java:929)
        at java.net.URL.toString(URL.java:915)
        at org.springframework.boot.loader.jar.Handler.isUrlInJarFile(Handler.java:94)
        at org.springframework.boot.loader.jar.Handler.openConnection(Handler.java:80)
        at java.net.URL.openConnection(URL.java:979)
        at sun.misc.URLClassPath$Loader.findResource(URLClassPath.java:705)
        at sun.misc.URLClassPath.findResource(URLClassPath.java:215)
        at java.net.URLClassLoader$2.run(URLClassLoader.java:569)
        at java.net.URLClassLoader$2.run(URLClassLoader.java:567)
        at java.security.AccessController.doPrivileged(Native Method)
        at java.net.URLClassLoader.findResource(URLClassLoader.java:566)
        at org.springframework.boot.loader.LaunchedURLClassLoader.findResource(LaunchedURLClassLoader.java:58)
        at java.lang.ClassLoader.getResource(ClassLoader.java:1096)
        at java.net.URLClassLoader.getResourceAsStream(URLClassLoader.java:232)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.dynamic.ClassFileLocator$ForClassLoader.locate(ClassFileLocator.java:438)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.dynamic.ClassFileLocator$ForClassLoader.locate(ClassFileLocator.java:419)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.dynamic.ClassFileLocator$Compound.locate(ClassFileLocator.java:1933)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.pool.TypePool$Default.doDescribe(TypePool.java:665)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.pool.TypePool$Default$WithLazyResolution.access$001(TypePool.java:747)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.pool.TypePool$Default$WithLazyResolution.doResolve(TypePool.java:845)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.pool.TypePool$Default$WithLazyResolution$LazyTypeDescription.delegate(TypePool.java:914)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.description.type.TypeDescription$AbstractBase$OfSimpleType$WithDelegation.getInterfaces(TypeDescription.java:8056)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.description.type.TypeDescription$Generic$OfNonGenericType.getInterfaces(TypeDescription.java:3654)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.description.type.TypeDescription$Generic$LazyProjection$WithEagerNavigation.getInterfaces(TypeDescription.java:6393)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.matcher.HasSuperTypeMatcher.matches(HasSuperTypeMatcher.java:66)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.matcher.HasSuperTypeMatcher.matches(HasSuperTypeMatcher.java:31)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.matcher.ElementMatcher$Junction$Conjunction.matches(ElementMatcher.java:122)
        at java.security.AccessController.doPrivileged(Native Method)
        at org.apache.skywalking.apm.dependencies.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:10186)
        at sun.instrument.TransformerManager.transform(TransformerManager.java:188)
        at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428)
        at java.lang.ClassLoader.defineClass1(Native Method)
        at java.lang.ClassLoader.defineClass(ClassLoader.java:763)
        at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
        at java.net.URLClassLoader.defineClass(URLClassLoader.java:467)
        at java.net.URLClassLoader.access$100(URLClassLoader.java:73)
        at java.net.URLClassLoader$1.run(URLClassLoader.java:368)
        at java.net.URLClassLoader$1.run(URLClassLoader.java:362)
        at java.security.AccessController.doPrivileged(Native Method)
        at java.net.URLClassLoader.findClass(URLClassLoader.java:361)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        - locked <0x00000007a78eebe8> (a java.lang.Object)
        at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:92)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at io.grpc.netty.shaded.io.grpc.netty.NettyChannelBuilder$NettyTransportFactory.newClientTransport(NettyChannelBuilder.java:727)
        at io.grpc.internal.CallCredentialsApplyingTransportFactory.newClientTransport(CallCredentialsApplyingTransportFactory.java:58)
        at io.grpc.internal.InternalSubchannel.startNewTransport(InternalSubchannel.java:254)
        at io.grpc.internal.InternalSubchannel.access$400(InternalSubchannel.java:66)
        at io.grpc.internal.InternalSubchannel$2.run(InternalSubchannel.java:201)
        at io.grpc.SynchronizationContext.drain(SynchronizationContext.java:95)
        at io.grpc.SynchronizationContext.execute(SynchronizationContext.java:127)
        at io.grpc.internal.ManagedChannelImpl$NameResolverListener.onResult(ManagedChannelImpl.java:1878)
        at io.grpc.internal.DnsNameResolver$Resolve.run(DnsNameResolver.java:333)

thread_dump_29.log:

2024-05-24 17:44:37
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.131-b11 mixed mode):
...
"grpc-default-executor-1" #246 daemon prio=5 os_prio=0 tid=0x00007fd6e803c000 nid=0x6427 in Object.wait() [0x00007fd6bf961000]
   java.lang.Thread.State: RUNNABLE
        at io.grpc.netty.shaded.io.grpc.netty.NettyClientTransport.start(NettyClientTransport.java:217)
        at io.grpc.internal.ForwardingConnectionClientTransport.start(ForwardingConnectionClientTransport.java:34)
        at io.grpc.internal.ForwardingConnectionClientTransport.start(ForwardingConnectionClientTransport.java:34)
        at io.grpc.internal.InternalSubchannel.startNewTransport(InternalSubchannel.java:259)
        at io.grpc.internal.InternalSubchannel.access$400(InternalSubchannel.java:66)
        at io.grpc.internal.InternalSubchannel$2.run(InternalSubchannel.java:201)
        at io.grpc.SynchronizationContext.drain(SynchronizationContext.java:95)
        at io.grpc.SynchronizationContext.execute(SynchronizationContext.java:127)
        at io.grpc.internal.ManagedChannelImpl$NameResolverListener.onResult(ManagedChannelImpl.java:1878)
        at io.grpc.internal.DnsNameResolver$Resolve.run(DnsNameResolver.java:333)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
        - <0x000000077bcf1750> (a java.util.concurrent.ThreadPoolExecutor$Worker)

...

"grpc-default-executor-0" #245 daemon prio=5 os_prio=0 tid=0x00007fd768037000 nid=0x6422 runnable [0x00007fd6bfe65000]
   java.lang.Thread.State: RUNNABLE
        at io.grpc.netty.shaded.io.netty.handler.codec.http2.Http2ConnectionHandler.<clinit>(Http2ConnectionHandler.java:71)
        at io.grpc.netty.shaded.io.grpc.netty.NettyClientTransport.start(NettyClientTransport.java:217)
        at io.grpc.internal.ForwardingConnectionClientTransport.start(ForwardingConnectionClientTransport.java:34)
        at io.grpc.internal.ForwardingConnectionClientTransport.start(ForwardingConnectionClientTransport.java:34)
        at io.grpc.internal.InternalSubchannel.startNewTransport(InternalSubchannel.java:259)
        at io.grpc.internal.InternalSubchannel.access$400(InternalSubchannel.java:66)
        at io.grpc.internal.InternalSubchannel$2.run(InternalSubchannel.java:201)
        at io.grpc.SynchronizationContext.drain(SynchronizationContext.java:95)
        at io.grpc.SynchronizationContext.execute(SynchronizationContext.java:127)
        at io.grpc.internal.ManagedChannelImpl$NameResolverListener.onResult(ManagedChannelImpl.java:1878)
        at io.grpc.internal.DnsNameResolver$Resolve.run(DnsNameResolver.java:333)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
        - <0x000000077c398b10> (a java.util.concurrent.ThreadPoolExecutor$Worker)

thread_dump_30.log:

2024-05-24 17:44:39
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.131-b11 mixed mode):
...
"grpc-default-executor-1" #246 daemon prio=5 os_prio=0 tid=0x00007fd6e803c000 nid=0x6427 in Object.wait() [0x00007fd6bf961000]
   java.lang.Thread.State: RUNNABLE
        at io.grpc.netty.shaded.io.grpc.netty.NettyClientTransport.start(NettyClientTransport.java:217)
        at io.grpc.internal.ForwardingConnectionClientTransport.start(ForwardingConnectionClientTransport.java:34)
        at io.grpc.internal.ForwardingConnectionClientTransport.start(ForwardingConnectionClientTransport.java:34)
        at io.grpc.internal.InternalSubchannel.startNewTransport(InternalSubchannel.java:259)
        at io.grpc.internal.InternalSubchannel.access$400(InternalSubchannel.java:66)
        at io.grpc.internal.InternalSubchannel$2.run(InternalSubchannel.java:201)
        at io.grpc.SynchronizationContext.drain(SynchronizationContext.java:95)
        at io.grpc.SynchronizationContext.execute(SynchronizationContext.java:127)
        at io.grpc.internal.ManagedChannelImpl$NameResolverListener.onResult(ManagedChannelImpl.java:1878)
        at io.grpc.internal.DnsNameResolver$Resolve.run(DnsNameResolver.java:333)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
        - <0x00000007bbb850a0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

我想知道

  1. 为什么
    #246
    线程在thread_dump_28.log中被阻塞:而该行周围没有任何锁定或同步语法https://github.com/grpc/grpc-java/blob/3500243f4320fcde1d567184b822c98de017498e/netty/src/主/java/io/grpc/netty/NettyChannelBuilder.java#L727 enter image description here
  1. 为什么
    #246
    线程可以在thread_dump_29.logthread_dump_30.log中运行,而甚至没有一行被执行,即堆栈头是同一行。
multithreading garbage-collection java-threads grpc-java
1个回答
0
投票

根据提供的提交哈希,您使用的是 grpc-java 1.46,它相当旧(最新的是 1.64)。请升级到最新版本,看看问题是否不会出现。

© www.soinside.com 2019 - 2024. All rights reserved.