雨翔河
首页
列表
关于
修改 jvm-sandbox 源码导致的线程安全问题
2020-06-03 16:33
今天收到运维同事的消息，广告组某应用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的源码，我在 `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` ，就如同上面的问题，要解决： 1. 如果要用，将`HashMap` 放入单个的方法体内用，避免线程安全问题。 2. 使用 `ConcurrentHashMap`，缺点就是性能会下降，毕竟jvm-sandbox是在最底层进行类方法执行的拦截标记等操作的，效率是非常非常重要的。
类型：工作
标签：jvm,sandbox,java,线程安全
Copyright © 雨翔河
我与我周旋久
独孤影