修改jvm-sandbox源码导致线程安全分析
作者:雨翔河
正文
今天收到运维同事的消息,广告组某应用 cpu 从 5 月 29 号下午 16:30 开始陡增不下,本着对问题的好奇心帮忙排查了下这个问题。
首先看了下 java 进程的线程 cpu 使用情况,有四个处理线程每一个几乎一直处于 40%-99% 的 cpu 使用,正常情况下不应该出现这种情况,还好是多核机器,不然这容易直接搞崩溃机器。
堆栈信息
同事提供了几分堆栈信息,在不同的时间段拿到的 jstack 信息占用高的 cpu 线程都指向了以下四个线程
"ForkJoinPool.commonPool-worker-1" #754509 daemon prio=5 os_prio=0 tid=0x00xxxxx36800 nid=0x1a9ec runnable [0x000xxxxx000] java.lang.Thread.State: RUNNABLE at java.util.HashMap$TreeNode.putTreeVal(HashMap.java:2002) at java.util.HashMap.putVal(HashMap.java:637) at java.util.HashMap.put(HashMap.java:611) at java.util.HashSet.add(HashSet.java:219) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventProcessor.setcurrentThread(EventProcessor.java:147) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventProcessor$Process.pushInvokeId(EventProcessor.java:45) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleOnBefore(EventListenerHandler.java:353) at java.com.alibaba.jvm.sandbox.spy.Spy.spyMethodOnBefore(Spy.java:164) at com.alibaba.dubbo.rpc.proxy.javassist.JavassistProxyFactory$1.doInvoke(JavassistProxyFactory.java) at com.alibaba.dubbo.rpc.proxy.AbstractProxyInvoker.invoke(AbstractProxyInvoker.java:72) at com.alibaba.dubbo.rpc.protocol.AbstractProxyProtocol$2.doInvoke(AbstractProxyProtocol.java:93) at com.alibaba.dubbo.rpc.protocol.AbstractInvoker.invoke(AbstractInvoker.java:144) at com.alibaba.dubbo.rpc.listener.ListenerInvokerWrapper.invoke(ListenerInvokerWrapper.java:74) at com.alibaba.extension.filter.AccessInvokeLogFilter.invoke(AccessInvokeLogFilter.java:29) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.csp.sentinel.adapter.dubbo.SentinelDubboConsumerFilter.invoke(SentinelDubboConsumerFilter.java:60) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:75) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.csp.sentinel.adapter.dubbo.DubboAppContextFilter.invoke(DubboAppContextFilter.java:41) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.protocol.dubbo.filter.FutureFilter.invoke(FutureFilter.java:53) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.ConsumerContextFilter.invoke(ConsumerContextFilter.java:48) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:53) at com.alibaba.dubbo.rpc.cluster.support.FailoverClusterInvoker.doInvoke(FailoverClusterInvoker.java:77) at com.alibaba.dubbo.rpc.cluster.support.AbstractClusterInvoker.invoke(AbstractClusterInvoker.java:227) at com.alibaba.dubbo.rpc.cluster.support.wrapper.MockClusterInvoker.invoke(MockClusterInvoker.java:72) at com.alibaba.dubbo.rpc.proxy.InvokerInvocationHandler.invoke(InvokerInvocationHandler.java:52) "DubboServerHandler-xxxx3:xxxx-thread-781" #1937 daemon prio=5 os_prio=0 tid=0x000xxxx4000 nid=0x804 runnable [0x000xxxx000] java.lang.Thread.State: RUNNABLE at java.util.HashMap$TreeNode.balanceDeletion(HashMap.java:2282) at java.util.HashMap$TreeNode.removeTreeNode(HashMap.java:2094) at java.util.HashMap.removeNode(HashMap.java:839) at java.util.HashMap.remove(HashMap.java:798) at java.util.HashSet.remove(HashSet.java:235) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventProcessor.clean(EventProcessor.java:189) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventProcessor$Process.popInvokeId(EventProcessor.java:65) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleOnEnd(EventListenerHandler.java:420) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleOnReturn(EventListenerHandler.java:389) at java.com.alibaba.jvm.sandbox.spy.Spy.spyMethodOnReturn(Spy.java:192) at com.alibaba.dubbo.rpc.proxy.javassist.JavassistProxyFactory$1.doInvoke(JavassistProxyFactory.java:46) at com.alibaba.dubbo.rpc.proxy.AbstractProxyInvoker.invoke(AbstractProxyInvoker.java:72) at com.alibaba.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:53) at com.alibaba.extension.filter.AccessInvokeLogFilter.invoke(AccessInvokeLogFilter.java:29) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.ExceptionFilter.invoke(ExceptionFilter.java:64) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.csp.sentinel.adapter.dubbo.SentinelDubboProviderFilter.invoke(SentinelDubboProviderFilter.java:66) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:75) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.TimeoutFilter.invoke(TimeoutFilter.java:42) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.protocol.dubbo.filter.TraceFilter.invoke(TraceFilter.java:78) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.ContextFilter.invoke(ContextFilter.java:60) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.GenericFilter.invoke(GenericFilter.java:112) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.ClassLoaderFilter.invoke(ClassLoaderFilter.java:38) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.EchoFilter.invoke(EchoFilter.java:38) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.protocol.dubbo.DubboProtocol$1.reply(DubboProtocol.java:108) at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.handleRequest(HeaderExchangeHandler.java:84) at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.received(HeaderExchangeHandler.java:170) at com.alibaba.dubbo.remoting.transport.DecodeHandler.received(DecodeHandler.java:52) at com.alibaba.dubbo.remoting.transport.dispatcher.ChannelEventRunnable.run(ChannelEventRunnable.java:82) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) "DubboServerHandler-1xxxx:xxxxx-thread-724" #1879 daemon prio=5 os_prio=0 tid=0x00xxxx800 nid=0x7ca runnable [0x0000xxx000] java.lang.Thread.State: RUNNABLE at java.util.HashMap$TreeNode.find(HashMap.java:1865) at java.util.HashMap$TreeNode.getTreeNode(HashMap.java:1873) at java.util.HashMap.removeNode(HashMap.java:823) at java.util.HashMap.remove(HashMap.java:798) at java.util.HashSet.remove(HashSet.java:235) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventProcessor.clean(EventProcessor.java:189) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventProcessor$Process.popInvokeId(EventProcessor.java:65) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleOnEnd(EventListenerHandler.java:420) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleOnReturn(EventListenerHandler.java:389) at java.com.alibaba.jvm.sandbox.spy.Spy.spyMethodOnReturn(Spy.java:192) at com.alibaba.dubbo.rpc.proxy.javassist.JavassistProxyFactory$1.doInvoke(JavassistProxyFactory.java:46) at com.alibaba.dubbo.rpc.proxy.AbstractProxyInvoker.invoke(AbstractProxyInvoker.java:72) at com.alibaba.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:53) at com.alibaba.extension.filter.AccessInvokeLogFilter.invoke(AccessInvokeLogFilter.java:29) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.ExceptionFilter.invoke(ExceptionFilter.java:64) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.csp.sentinel.adapter.dubbo.SentinelDubboProviderFilter.invoke(SentinelDubboProviderFilter.java:66) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:75) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.TimeoutFilter.invoke(TimeoutFilter.java:42) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.protocol.dubbo.filter.TraceFilter.invoke(TraceFilter.java:78) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.ContextFilter.invoke(ContextFilter.java:60) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.GenericFilter.invoke(GenericFilter.java:112) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.ClassLoaderFilter.invoke(ClassLoaderFilter.java:38) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.EchoFilter.invoke(EchoFilter.java:38) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.protocol.dubbo.DubboProtocol$1.reply(DubboProtocol.java:108) at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.handleRequest(HeaderExchangeHandler.java:84) at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.received(HeaderExchangeHandler.java:170) at com.alibaba.dubbo.remoting.transport.DecodeHandler.received(DecodeHandler.java:52) at com.alibaba.dubbo.remoting.transport.dispatcher.ChannelEventRunnable.run(ChannelEventRunnable.java:82) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) "DubboServerHandler-xxxx:xxxx-thread-735" #1890 daemon prio=5 os_prio=0 tid=0x000xxxx800 nid=0x7d5 runnable [0x0000xxxxx00] java.lang.Thread.State: RUNNABLE at java.util.HashMap$TreeNode.putTreeVal(HashMap.java:2002) at java.util.HashMap.putVal(HashMap.java:637) at java.util.HashMap.put(HashMap.java:611) at java.util.HashSet.add(HashSet.java:219) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventProcessor.setcurrentThread(EventProcessor.java:147) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventProcessor$Process.pushInvokeId(EventProcessor.java:45) at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleOnBefore(EventListenerHandler.java:353) at java.com.alibaba.jvm.sandbox.spy.Spy.spyMethodOnBefore(Spy.java:164) at com.alibaba.dubbo.rpc.proxy.javassist.JavassistProxyFactory$1.doInvoke(JavassistProxyFactory.java) at com.alibaba.dubbo.rpc.proxy.AbstractProxyInvoker.invoke(AbstractProxyInvoker.java:72) at com.alibaba.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:53) at com.alibaba.extension.filter.AccessInvokeLogFilter.invoke(AccessInvokeLogFilter.java:29) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.ExceptionFilter.invoke(ExceptionFilter.java:64) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.csp.sentinel.adapter.dubbo.SentinelDubboProviderFilter.invoke(SentinelDubboProviderFilter.java:66) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:75) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.TimeoutFilter.invoke(TimeoutFilter.java:42) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.protocol.dubbo.filter.TraceFilter.invoke(TraceFilter.java:78) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.ContextFilter.invoke(ContextFilter.java:60) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.GenericFilter.invoke(GenericFilter.java:112) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.ClassLoaderFilter.invoke(ClassLoaderFilter.java:38) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.EchoFilter.invoke(EchoFilter.java:38) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.protocol.dubbo.DubboProtocol$1.reply(DubboProtocol.java:108) at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.handleRequest(HeaderExchangeHandler.java:84) at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.received(HeaderExchangeHandler.java:170) at com.alibaba.dubbo.remoting.transport.DecodeHandler.received(DecodeHandler.java:52) at com.alibaba.dubbo.remoting.transport.dispatcher.ChannelEventRunnable.run(ChannelEventRunnable.java:82) 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:745)
这四个线程都是 jvm-sandbox 的执行线程,这部分执行代码并不在应用层面,而是应用挂载的 jvm-sandbox,目前是用这个来对方法执行拦截,打标,mock,主要是为了全链路压测引入的。
jvm-sandbox 分支
下载下来了 jvm-sandbox 的源码,我在 com.alibaba.jvm.sandbox.core.enhance.weaver.EventProcessor
类里并没有看到相应的 hashmap 的操作,怀疑是改动了 jvm-sandbox 源码,悄悄的搞到了公司的 jvm-sandbox 分支源码,发现如下:
增加了一个 HashSet
来记录当前线程集合,这里的 HashSet
的定义是在单线程执行的方法体外,会被多线程访问到,这就意味着它存在线程安全的问题。HashSet
的底层实现是 HashMap
,这也是为什么我们看到堆栈都是 HashMap
的插入查找移除的方法。
原因分析
具体原因没有去深究(如果去生产环境导出堆信息找到这个 map,然后去看这里面的结构,理论上是可以分析出这个 hashmap 里面的某棵树是不是出现了问题),因为不好复现,多线程这种需要看脸的报错,我自己写了测试用例可以做到增删查失败的情况,但是很难判断这种性能效率问题,因为 HashMap
本身是一个数组 + 链表的结构,这种结构在遇到 hash 冲突严重的时候链表会转换为一颗红黑树,如果这时候是多线程对这颗红黑树进行了增加和移除查找操作,红黑树是需要自平衡的,多线程的时候自平衡的过程中运气不好会导致自锁和查询效率极低,甚至引发死循环的概率,我没有深究过它的源码,但是我们可以想象父节点指针指向孩子节点,这个时候查询操作本来是正常往下走的,红黑树发生了自平衡,很可能进入这颗红黑树的时候进入死循环,或者查询效率及其低下,for 循环次数过多。
首先举个最简单的例子,假设 HashMap
的链表已经形成了红黑树,里面取某一条链的 root 节点,当你多线程进行操作这条链的时候就有可能会发生两个父节点互相引用的情况,因为多线程下自平衡的结果结构不确定,这样在取 root 节点的时候就有可能会陷入这个死循环。
这个假设理论上在没有变换为红黑树的情况下是个链表也应该是成立的,JDK8 之前,比如 JDK7 的 hash 冲突是使用的纯链表,而且是头插法的方式做的扩容,这个多线程情况下在一定概率会出现一个环形的引用关系导致死循环,因为节点如果出现相互指向的话,这个链表的查询会进入死循环。JDK8 之后用的是尾插法扩容不会有链表的死循环引用问题,但是会出现丢失数据的情况,其次就是变成红黑树之后,这个过程如果发生自平衡就会变成不可控。
所以在多线程情况下一定不要去使用 HashMap
,就如同上面的问题,要解决:
如果要用,将 HashMap
放入单个的方法体内用,避免线程安全问题。
使用 ConcurrentHashMap
,缺点就是性能会下降,毕竟 jvm-sandbox 是在最底层进行类方法执行的拦截标记等操作的,效率是非常非常重要的。
以上就是修改jvm-sandbox源码导致线程安全分析的详细内容,更多关于jvm-sandbox线程安全的资料请关注脚本之家其它相关文章!