ES某节点CPU增长至100%的诡异问题

这是一个从事发到目前为止我没有从根本上解决的技术问题,也是我心中的一个非常大的疑惑。 写于: 2020-06-14 周日,下午14:00

问题已解决,解决过程和方案可以看文章最末尾,解决方案写于 2020-06-20 15:26

问题一: 2020年6月4号上午10点左右(高峰期),A集群某节点,我们姑且称之为37号节点,CPU增长至100%居高不下,导致查询队列积压,大量查询请求被拒绝,扩容后问题解决(我们之后新增了五个节点),但是扩容之后的集群里,37号节点平时的CPU占用还是要远远高于其他节点, 相差10倍左右,也就是说其它节点在闲置着看戏,但是扩容后至少不会出现CPU占满的情况。

问题二: 2020年6月12号上午10点左右(高峰期),B集群某节点,我们姑且称之为2号节点,CPU增长至100%居高不下,导致查询队列积压,大量查询请求被拒绝,扩容后问题解决,但是2号节点平时的CPU占用要远远高于其他节点, 相差10倍左右。 我们排查出第三方接口查询量突增非常多的量,因为时间紧急,我们熔断了第三方的查询接口,超过N的QPS直接返回错误信息,2号节点的CPU直线下跌至正常状态,其它节点在这期间闲置看戏。

问题一,经过排查,我们检查了当时37号节点的ES进程里占用非常高的线程情况:

1"elasticsearch[logsearch-datanode-36][index][T#14]" #273 daemon prio=5 os_prio=0 tid=0x00007ef8e8084800 nid=0x6f62 runnable [0x00007ef4d37eb000] 2 java.lang.Thread.State: RUNNABLE 3 at java.lang.ThreadLocal$ThreadLocalMap.getEntryAfterMiss(ThreadLocal.java:444) 4 at java.lang.ThreadLocal$ThreadLocalMap.getEntry(ThreadLocal.java:419) 5 at java.lang.ThreadLocal$ThreadLocalMap.access$000(ThreadLocal.java:298) 6 at java.lang.ThreadLocal.get(ThreadLocal.java:163) 7 at org.apache.lucene.util.CloseableThreadLocal.get(CloseableThreadLocal.java:78) 8 at org.elasticsearch.common.lucene.uid.Versions.getLookupState(Versions.java:81) 9 at org.elasticsearch.common.lucene.uid.Versions.loadDocIdAndVersion(Versions.java:123) 10 at org.elasticsearch.common.lucene.uid.Versions.loadVersion(Versions.java:140) 11 at org.elasticsearch.index.engine.InternalEngine.loadCurrentVersionFromIndex(InternalEngine.java:1032) 12 at org.elasticsearch.index.engine.InternalEngine.innerDelete(InternalEngine.java:582) 13 - locked <0x00000000c3c36900> (a java.lang.Object) 14 at org.elasticsearch.index.engine.InternalEngine.delete(InternalEngine.java:558) 15 at org.elasticsearch.index.shard.IndexShard.delete(IndexShard.java:641) 16 at org.elasticsearch.action.delete.TransportDeleteAction.executeDeleteRequestOnPrimary(TransportDeleteAction.java:143) 17 at org.elasticsearch.action.delete.TransportDeleteAction.shardOperationOnPrimary(TransportDeleteAction.java:136) 18 at org.elasticsearch.action.delete.TransportDeleteAction.shardOperationOnPrimary(TransportDeleteAction.java:54) 19 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryPhase.doRun(TransportReplicationAction.java:639) 20 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 21 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:279) 22 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:271) 23 at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:75) 24 at org.elasticsearch.transport.TransportService$4.doRun(TransportService.java:376) 25 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 26 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 27 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 28 at java.lang.Thread.run(Thread.java:745) 29 30 Locked ownable synchronizers: 31 - <0x000000008ae17720> (a java.util.concurrent.ThreadPoolExecutor$Worker) 32 33"elasticsearch[logsearch-datanode-36][index][T#13]" #272 daemon prio=5 os_prio=0 tid=0x00007ef8f4085000 nid=0x6f61 runnable [0x00007ef4d38ec000] 34 java.lang.Thread.State: RUNNABLE 35 at java.lang.ThreadLocal$ThreadLocalMap.getEntryAfterMiss(ThreadLocal.java:444) 36 at java.lang.ThreadLocal$ThreadLocalMap.getEntry(ThreadLocal.java:419) 37 at java.lang.ThreadLocal$ThreadLocalMap.access$000(ThreadLocal.java:298) 38 at java.lang.ThreadLocal.get(ThreadLocal.java:163) 39 at org.apache.lucene.util.CloseableThreadLocal.get(CloseableThreadLocal.java:78) 40 at org.elasticsearch.common.lucene.uid.Versions.getLookupState(Versions.java:81) 41 at org.elasticsearch.common.lucene.uid.Versions.loadDocIdAndVersion(Versions.java:123) 42 at org.elasticsearch.common.lucene.uid.Versions.loadVersion(Versions.java:140) 43 at org.elasticsearch.index.engine.InternalEngine.loadCurrentVersionFromIndex(InternalEngine.java:1032) 44 at org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:501) 45 - locked <0x00000001619253d8> (a java.lang.Object) 46 at org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:457) 47 at org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:601) 48 at org.elasticsearch.index.engine.Engine$Index.execute(Engine.java:836) 49 at org.elasticsearch.action.index.TransportIndexAction.executeIndexRequestOnPrimary(TransportIndexAction.java:237) 50 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnPrimary(TransportIndexAction.java:158) 51 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnPrimary(TransportIndexAction.java:66) 52 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryPhase.doRun(TransportReplicationAction.java:639) 53 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 54 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:279) 55 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:271) 56 at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:75) 57 at org.elasticsearch.transport.TransportService$4.doRun(TransportService.java:376) 58 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 59 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 60 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 61 at java.lang.Thread.run(Thread.java:745) 62 63 Locked ownable synchronizers: 64 - <0x000000008ae10650> (a java.util.concurrent.ThreadPoolExecutor$Worker) 65 66"elasticsearch[logsearch-datanode-36][index][T#12]" #271 daemon prio=5 os_prio=0 tid=0x00007ef8f8083800 nid=0x6f60 runnable [0x00007ef4d39ed000] 67 java.lang.Thread.State: RUNNABLE 68 at java.lang.ThreadLocal$ThreadLocalMap.getEntryAfterMiss(ThreadLocal.java:444) 69 at java.lang.ThreadLocal$ThreadLocalMap.getEntry(ThreadLocal.java:419) 70 at java.lang.ThreadLocal$ThreadLocalMap.access$000(ThreadLocal.java:298) 71 at java.lang.ThreadLocal.get(ThreadLocal.java:163) 72 at org.apache.lucene.util.CloseableThreadLocal.get(CloseableThreadLocal.java:78) 73 at org.elasticsearch.common.lucene.uid.Versions.getLookupState(Versions.java:81) 74 at org.elasticsearch.common.lucene.uid.Versions.loadDocIdAndVersion(Versions.java:123) 75 at org.elasticsearch.common.lucene.uid.Versions.loadVersion(Versions.java:140) 76 at org.elasticsearch.index.engine.InternalEngine.loadCurrentVersionFromIndex(InternalEngine.java:1032) 77 at org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:501) 78 - locked <0x0000000156f6a138> (a java.lang.Object) 79 at org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:457) 80 at org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:601) 81 at org.elasticsearch.index.engine.Engine$Index.execute(Engine.java:836) 82 at org.elasticsearch.action.index.TransportIndexAction.executeIndexRequestOnReplica(TransportIndexAction.java:196) 83 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnReplica(TransportIndexAction.java:170) 84 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnReplica(TransportIndexAction.java:66) 85 at org.elasticsearch.action.support.replication.TransportReplicationAction$AsyncReplicaAction.doRun(TransportReplicationAction.java:392) 86 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 87 at org.elasticsearch.action.support.replication.TransportReplicationAction$ReplicaOperationTransportHandler.messageReceived(TransportReplicationAction.java:291) 88 at org.elasticsearch.action.support.replication.TransportReplicationAction$ReplicaOperationTransportHandler.messageReceived(TransportReplicationAction.java:283) 89 at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:75) 90 at org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.doRun(MessageChannelHandler.java:300) 91 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 92 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 93 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 94 at java.lang.Thread.run(Thread.java:745) 95 96 Locked ownable synchronizers: 97 - <0x000000008ae1b570> (a java.util.concurrent.ThreadPoolExecutor$Worker) 98 99"elasticsearch[logsearch-datanode-36][index][T#11]" #270 daemon prio=5 os_prio=0 tid=0x00007ef8e0003000 nid=0x6f5f runnable [0x00007ef4d3aee000] 100 java.lang.Thread.State: RUNNABLE 101 at java.lang.ThreadLocal$ThreadLocalMap.set(ThreadLocal.java:467) 102 at java.lang.ThreadLocal$ThreadLocalMap.access$100(ThreadLocal.java:298) 103 at java.lang.ThreadLocal.setInitialValue(ThreadLocal.java:184) 104 at java.lang.ThreadLocal.get(ThreadLocal.java:170) 105 at java.util.concurrent.locks.ReentrantReadWriteLock$Sync.tryAcquireShared(ReentrantReadWriteLock.java:481) 106 at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1282) 107 at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:727) 108 at org.elasticsearch.common.util.concurrent.ReleasableLock.acquire(ReleasableLock.java:55) 109 at org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:450) 110 at org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:601) 111 at org.elasticsearch.index.engine.Engine$Index.execute(Engine.java:836) 112 at org.elasticsearch.action.index.TransportIndexAction.executeIndexRequestOnPrimary(TransportIndexAction.java:237) 113 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnPrimary(TransportIndexAction.java:158) 114 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnPrimary(TransportIndexAction.java:66) 115 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryPhase.doRun(TransportReplicationAction.java:639) 116 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 117 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:279) 118 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:271) 119 at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:75) 120 at org.elasticsearch.transport.TransportService$4.doRun(TransportService.java:376) 121 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 122 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 123 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 124 at java.lang.Thread.run(Thread.java:745) 125 126 Locked ownable synchronizers: 127 - <0x000000008ae15d78> (a java.util.concurrent.ThreadPoolExecutor$Worker) 128 129"elasticsearch[logsearch-datanode-36][index][T#10]" #269 daemon prio=5 os_prio=0 tid=0x00007ef910083800 nid=0x6f5e runnable [0x00007ef4d3bee000] 130 java.lang.Thread.State: RUNNABLE 131 at java.lang.ThreadLocal$ThreadLocalMap.getEntryAfterMiss(ThreadLocal.java:444) 132 at java.lang.ThreadLocal$ThreadLocalMap.getEntry(ThreadLocal.java:419) 133 at java.lang.ThreadLocal$ThreadLocalMap.access$000(ThreadLocal.java:298) 134 at java.lang.ThreadLocal.get(ThreadLocal.java:163) 135 at org.apache.lucene.util.CloseableThreadLocal.get(CloseableThreadLocal.java:78) 136 at org.elasticsearch.common.lucene.uid.Versions.getLookupState(Versions.java:81) 137 at org.elasticsearch.common.lucene.uid.Versions.loadDocIdAndVersion(Versions.java:123) 138 at org.elasticsearch.common.lucene.uid.Versions.loadVersion(Versions.java:140) 139 at org.elasticsearch.index.engine.InternalEngine.loadCurrentVersionFromIndex(InternalEngine.java:1032) 140 at org.elasticsearch.index.engine.InternalEngine.innerDelete(InternalEngine.java:582) 141 - locked <0x000000016c7c8a98> (a java.lang.Object) 142 at org.elasticsearch.index.engine.InternalEngine.delete(InternalEngine.java:558) 143 at org.elasticsearch.index.shard.IndexShard.delete(IndexShard.java:641) 144 at org.elasticsearch.action.delete.TransportDeleteAction.executeDeleteRequestOnPrimary(TransportDeleteAction.java:143) 145 at org.elasticsearch.action.delete.TransportDeleteAction.shardOperationOnPrimary(TransportDeleteAction.java:136) 146 at org.elasticsearch.action.delete.TransportDeleteAction.shardOperationOnPrimary(TransportDeleteAction.java:54) 147 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryPhase.doRun(TransportReplicationAction.java:639) 148 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 149 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:279) 150 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:271) 151 at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:75) 152 at org.elasticsearch.transport.TransportService$4.doRun(TransportService.java:376) 153 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 154 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 155 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 156 at java.lang.Thread.run(Thread.java:745) 157 158 Locked ownable synchronizers: 159 - <0x000000008ae19da0> (a java.util.concurrent.ThreadPoolExecutor$Worker) 160 161"elasticsearch[logsearch-datanode-36][index][T#9]" #267 daemon prio=5 os_prio=0 tid=0x00007ef8f0082800 nid=0x6f5c runnable [0x00007ef4d3df0000] 162 java.lang.Thread.State: RUNNABLE 163 at java.lang.ThreadLocal$ThreadLocalMap.getEntryAfterMiss(ThreadLocal.java:444) 164 at java.lang.ThreadLocal$ThreadLocalMap.getEntry(ThreadLocal.java:419) 165 at java.lang.ThreadLocal$ThreadLocalMap.access$000(ThreadLocal.java:298) 166 at java.lang.ThreadLocal.get(ThreadLocal.java:163) 167 at org.apache.lucene.util.CloseableThreadLocal.get(CloseableThreadLocal.java:78) 168 at org.elasticsearch.common.lucene.uid.Versions.getLookupState(Versions.java:81) 169 at org.elasticsearch.common.lucene.uid.Versions.loadDocIdAndVersion(Versions.java:123) 170 at org.elasticsearch.common.lucene.uid.Versions.loadVersion(Versions.java:140) 171 at org.elasticsearch.index.engine.InternalEngine.loadCurrentVersionFromIndex(InternalEngine.java:1032) 172 at org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:501) 173 - locked <0x0000000156f71bf8> (a java.lang.Object) 174 at org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:457) 175 at org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:601) 176 at org.elasticsearch.index.engine.Engine$Index.execute(Engine.java:836) 177 at org.elasticsearch.action.index.TransportIndexAction.executeIndexRequestOnPrimary(TransportIndexAction.java:237) 178 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnPrimary(TransportIndexAction.java:158) 179 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnPrimary(TransportIndexAction.java:66) 180 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryPhase.doRun(TransportReplicationAction.java:639) 181 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 182 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:279) 183 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:271) 184 at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:75) 185 at org.elasticsearch.transport.TransportService$4.doRun(TransportService.java:376) 186 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 187 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 188 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 189 at java.lang.Thread.run(Thread.java:745) 190 191 Locked ownable synchronizers: 192 - <0x000000008ae178c8> (a java.util.concurrent.ThreadPoolExecutor$Worker) 193 194"elasticsearch[logsearch-datanode-36][index][T#8]" #266 daemon prio=5 os_prio=0 tid=0x00007ef8e8082800 nid=0x6f5b runnable [0x00007ef4d3ef1000] 195 java.lang.Thread.State: RUNNABLE 196 at java.lang.ThreadLocal$ThreadLocalMap.getEntryAfterMiss(ThreadLocal.java:444) 197 at java.lang.ThreadLocal$ThreadLocalMap.getEntry(ThreadLocal.java:419) 198 at java.lang.ThreadLocal$ThreadLocalMap.access$000(ThreadLocal.java:298) 199 at java.lang.ThreadLocal.get(ThreadLocal.java:163) 200 at java.util.concurrent.locks.ReentrantReadWriteLock$Sync.tryAcquireShared(ReentrantReadWriteLock.java:481) 201 at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1282) 202 at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:727) 203 at org.elasticsearch.common.util.concurrent.ReleasableLock.acquire(ReleasableLock.java:55) 204 at org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:450) 205 at org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:601) 206 at org.elasticsearch.index.engine.Engine$Index.execute(Engine.java:836) 207 at org.elasticsearch.action.index.TransportIndexAction.executeIndexRequestOnPrimary(TransportIndexAction.java:237) 208 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnPrimary(TransportIndexAction.java:158) 209 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnPrimary(TransportIndexAction.java:66) 210 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryPhase.doRun(TransportReplicationAction.java:639) 211 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 212 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:279) 213 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:271) 214 at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:75) 215 at org.elasticsearch.transport.TransportService$4.doRun(TransportService.java:376) 216 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 217 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 218 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 219 at java.lang.Thread.run(Thread.java:745) 220 221 Locked ownable synchronizers: 222 - <0x000000008ae19f48> (a java.util.concurrent.ThreadPoolExecutor$Worker) 223 224"elasticsearch[logsearch-datanode-36][index][T#7]" #265 daemon prio=5 os_prio=0 tid=0x00007ef8f4083000 nid=0x6f5a runnable [0x00007ef4d3ff3000] 225 java.lang.Thread.State: RUNNABLE 226 at java.lang.ThreadLocal$ThreadLocalMap.set(ThreadLocal.java:467) 227 at java.lang.ThreadLocal$ThreadLocalMap.access$100(ThreadLocal.java:298) 228 at java.lang.ThreadLocal.setInitialValue(ThreadLocal.java:184) 229 at java.lang.ThreadLocal.get(ThreadLocal.java:170) 230 at org.apache.lucene.util.CloseableThreadLocal.get(CloseableThreadLocal.java:78) 231 at org.apache.lucene.index.CodecReader.getNumericDocValues(CodecReader.java:143) 232 at org.apache.lucene.index.FilterLeafReader.getNumericDocValues(FilterLeafReader.java:430) 233 at org.elasticsearch.common.lucene.uid.PerThreadIDAndVersionLookup.<init>(PerThreadIDAndVersionLookup.java:77) 234 at org.elasticsearch.common.lucene.uid.Versions.getLookupState(Versions.java:83) 235 at org.elasticsearch.common.lucene.uid.Versions.loadDocIdAndVersion(Versions.java:123) 236 at org.elasticsearch.common.lucene.uid.Versions.loadVersion(Versions.java:140) 237 at org.elasticsearch.index.engine.InternalEngine.loadCurrentVersionFromIndex(InternalEngine.java:1032) 238 at org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:501) 239 - locked <0x00000001aa0732e0> (a java.lang.Object) 240 at org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:457) 241 at org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:601) 242 at org.elasticsearch.index.engine.Engine$Index.execute(Engine.java:836) 243 at org.elasticsearch.action.index.TransportIndexAction.executeIndexRequestOnReplica(TransportIndexAction.java:196) 244 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnReplica(TransportIndexAction.java:170) 245 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnReplica(TransportIndexAction.java:66) 246 at org.elasticsearch.action.support.replication.TransportReplicationAction$AsyncReplicaAction.doRun(TransportReplicationAction.java:392) 247 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 248 at org.elasticsearch.action.support.replication.TransportReplicationAction$ReplicaOperationTransportHandler.messageReceived(TransportReplicationAction.java:291) 249 at org.elasticsearch.action.support.replication.TransportReplicationAction$ReplicaOperationTransportHandler.messageReceived(TransportReplicationAction.java:283) 250 at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:75) 251 at org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.doRun(MessageChannelHandler.java:300) 252 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 253 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 254 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 255 at java.lang.Thread.run(Thread.java:745) 256 257 Locked ownable synchronizers: 258 - <0x000000008ae1b718> (a java.util.concurrent.ThreadPoolExecutor$Worker) 259 260"elasticsearch[logsearch-datanode-36][index][T#6]" #264 daemon prio=5 os_prio=0 tid=0x00007ef8f8082000 nid=0x6f59 runnable [0x00007ef4d40f4000] 261 java.lang.Thread.State: RUNNABLE 262 at java.lang.ThreadLocal$ThreadLocalMap.getEntryAfterMiss(ThreadLocal.java:444) 263 at java.lang.ThreadLocal$ThreadLocalMap.getEntry(ThreadLocal.java:419) 264 at java.lang.ThreadLocal$ThreadLocalMap.access$000(ThreadLocal.java:298) 265 at java.lang.ThreadLocal.get(ThreadLocal.java:163) 266 at org.apache.lucene.util.CloseableThreadLocal.get(CloseableThreadLocal.java:78) 267 at org.elasticsearch.common.lucene.uid.Versions.getLookupState(Versions.java:81) 268 at org.elasticsearch.common.lucene.uid.Versions.loadDocIdAndVersion(Versions.java:123) 269 at org.elasticsearch.common.lucene.uid.Versions.loadVersion(Versions.java:140) 270 at org.elasticsearch.index.engine.InternalEngine.loadCurrentVersionFromIndex(InternalEngine.java:1032) 271 at org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:501) 272 - locked <0x00000000c3c36b70> (a java.lang.Object) 273 at org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:457) 274 at org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:601) 275 at org.elasticsearch.index.engine.Engine$Index.execute(Engine.java:836) 276 at org.elasticsearch.action.index.TransportIndexAction.executeIndexRequestOnPrimary(TransportIndexAction.java:237) 277 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnPrimary(TransportIndexAction.java:158) 278 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnPrimary(TransportIndexAction.java:66) 279 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryPhase.doRun(TransportReplicationAction.java:639) 280 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 281 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:279) 282 at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:271) 283 at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:75) 284 at org.elasticsearch.transport.TransportService$4.doRun(TransportService.java:376) 285 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 286 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 287 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 288 at java.lang.Thread.run(Thread.java:745) 289 290 Locked ownable synchronizers: 291 - <0x000000008ae15f20> (a java.util.concurrent.ThreadPoolExecutor$Worker) 292 293"elasticsearch[logsearch-datanode-36][index][T#5]" #263 daemon prio=5 os_prio=0 tid=0x00007ef8e0001000 nid=0x6f58 runnable [0x00007ef4d41f5000] 294 java.lang.Thread.State: RUNNABLE 295 at java.lang.ThreadLocal$ThreadLocalMap.getEntryAfterMiss(ThreadLocal.java:444) 296 at java.lang.ThreadLocal$ThreadLocalMap.getEntry(ThreadLocal.java:419) 297 at java.lang.ThreadLocal$ThreadLocalMap.access$000(ThreadLocal.java:298) 298 at java.lang.ThreadLocal.get(ThreadLocal.java:163) 299 at org.apache.lucene.util.CloseableThreadLocal.get(CloseableThreadLocal.java:78) 300 at org.elasticsearch.common.lucene.uid.Versions.getLookupState(Versions.java:81) 301 at org.elasticsearch.common.lucene.uid.Versions.loadDocIdAndVersion(Versions.java:123) 302 at org.elasticsearch.common.lucene.uid.Versions.loadVersion(Versions.java:140) 303 at org.elasticsearch.index.engine.InternalEngine.loadCurrentVersionFromIndex(InternalEngine.java:1032) 304 at org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:501) 305 - locked <0x0000000156f69b08> (a java.lang.Object) 306 at org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:457) 307 at org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:601) 308 at org.elasticsearch.index.engine.Engine$Index.execute(Engine.java:836) 309 at org.elasticsearch.action.index.TransportIndexAction.executeIndexRequestOnReplica(TransportIndexAction.java:196) 310 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnReplica(TransportIndexAction.java:170) 311 at org.elasticsearch.action.index.TransportIndexAction.shardOperationOnReplica(TransportIndexAction.java:66) 312 at org.elasticsearch.action.support.replication.TransportReplicationAction$AsyncReplicaAction.doRun(TransportReplicationAction.java:392) 313 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 314 at org.elasticsearch.action.support.replication.TransportReplicationAction$ReplicaOperationTransportHandler.messageReceived(TransportReplicationAction.java:291) 315 at org.elasticsearch.action.support.replication.TransportReplicationAction$ReplicaOperationTransportHandler.messageReceived(TransportReplicationAction.java:283) 316 at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:75) 317 at org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.doRun(MessageChannelHandler.java:300) 318 at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) 319 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 320 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 321 at java.lang.Thread.run(Thread.java:745) 322 323 Locked ownable synchronizers: 324 - <0x000000008ae1a0f0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

起初我是怀疑是不是 ThreadLocal里的ThreadLocalMap导致的,为此又恶补了下 ThreadLocalMap 的原理,当存储线程变量的时候,它会分配一个数组给这个线程用,变量放进去的时候用ThreadLocal的这个变量的hash值定位到在数组的那个位置去,如果有冲突则找这个位置的下一个位置。

这是设置值的时候,如果在get的时候也是通过ThreadLocal的hash去找到数组的位置,冲突了之后找当前位置的下一个位置,如果下一个位置的这个key已经是null了说明被回收了,那么要进行一次清理,它会向后清理掉为空的值,这就是所谓的启发式清理,没有固定的线程去做这个,靠着查询的时候出现空值来进行清理。

本来我怀疑这里有问题,因为当冲突过多的时候,或者这个数组太大了,因为冲突多了,就会扩容这个数组,导致每次冲突就要往下寻找数据,这是一个循环操作非常的损耗CPU,会不会是这个数组快要满了但是又没有满,导致了查询一直在循环的寻找这个ThreadLocal,后来我在本地起了20个线程,跑了40亿个数据来验证这个观点,每一千万次查询和插入操作,只会出现三四个这种耗时达到100ms以上的情况,且耗时长的那三四个操作都维持在200ms左右,这对性能理论上没有影响。

问题二:

后来又觉得会不会是数据不均衡导致的,我们看了下数据分片存储的数据大小,几乎都是一致的,只有1G的差别大小,这可以忽略不计。

又怀疑是系统核心参数配置的问题导致的,那台机器的CPU配置是节能模式,我们改为了高性能模式,也没有太大的变化。

到这里又发现了一个疑点,所有节点进来的流量是一样的,但是唯独那台机器出去的流量是别的节点的10倍。

是否是某个查询的结果落到了2号节点,那个数据分片正好都在2号,那个查询结果的量特别特别的大,但是我们粗略的也没看出来有哪个查询的量特别庞大。

最后猜测是否是机器原因,别的机器都正常,唯独那两个集群的那两个节点存在问题。

两个集群的ES版本都比较低,2.3.4

问题节点的机器是物理机,配置很高。

记录下,后续再看下怎么解决。

问题已解决,写于 2020-06-20 15:26

  1. 6-16号晚上我们将CPU高的那台36机器下线了,集群就变成平稳且健康了。

  2. 下线的这台36物理机器从配置上来看是非常高的,内存60G以上,CPU是32核,但是下线了这个CPU高的节点后就恢复了。另外一个集群也把CPU飙高的02节点下线了,集群整体非常稳定。

  3. 这里猜测原因是第一,这两个节点的硬件或者系统存在问题,第二是ES 2.3.4版本对集群内部的机器异构支持很差(集群内部机器的硬件配置不一致)。

事发整个实际过程回顾

2020-06-04,快递员集群出现CPU负载过高的问题,37和36节点都出现CPU很高,其他节点闲置。

2020-06-04 10:00 到 2020-06-04 12:00 出现的问题:件已经入柜,但是FC管家查询不到信息,不会有明显影响,只是写入ES的速度很慢,kafka消息积压,等到恢复后,受影响的积压数据自动就写入了。

2020-06-04 13:16分左右,37节点突然下降到正常水平,36节点在持续CPU负载过高。

2020-06-04 14:30左右,36节点瞬间恢复正常水平。

2020-06-04 下午17:10左右,36节点的CPU又达到90%以上,37稍微有点高,但是还是健康状态。

2020-06-04 下午17:10 到 2020-06-04 18:30 出现的问题:件已经取出,但是FC管家查询到的数据还是未取状态,不会有明显影响,只是写入ES的速度很慢,kafka消息积压,等到恢复后,受影响的积压数据自动就写入了。

2020-06-04 下午18:55左右,36节点的CPU瞬间由高点下降到正常水平.

2020-06-04 晚上20:00 开始扩容,加入了6台物理机,晚上22:40分左右完成扩容。

2020-06-05 早上10:00 一切正常,36节点略微有点偏高但是处于正常水平,CPU负载20%左右,CPU负载明显高于其他节点。

2020-06-12 10:00 左右 消费者集群 post_consumer_data_02节点出现CPU负载变高,我们称之为189节点。

2020-06-12 10:20左右,客服和全员群上报微信支付分订单问题,原因:微信支付分查询使用的是消费者集群的索引数据。

2020-06-12 10:30左右开放平台报大量请求查询变慢甚至查询不出来结果,经研发排查,发现是第三方(华为)接口查询量大增,查询流量进入消费者集群。

2020-06-12 10:45左右, 紧急熔断掉第三方调用我方流量最大的查询接口。

2020-06-12 10:50左右,189节点的CPU在10:52从99%瞬间回落至8%,业务恢复正常,后续问题上报存在时间差,其实已经恢复。

2020-06-12 11:00 ,和第三方沟通查询量限制,但是189节点CPU变高的原因尚未找到。

2020-06-13 周六,继续熔断第三方接口,限流。 2020-06-14 周日,继续熔断第三方接口,限流。

2020-06-15 周一晚上,如果继续限流,PDD和HW等第三方都会来投诉,15号晚上我们把第三方的查询接口由消费者集群切换到了快递员集群。 基于2020-06-04那天晚上快递员集群已经扩容,我们把流量导向这个性能更强大的集群,取消限流。

2020-06-16 周二早上10:19分,快递员集群的36节点CPU开始变高,其他节点闲置。客服系统、工单系统、FC管家查询派件信息卡顿、缓慢、查不到结果。

2020-06-16 11:30,对第三方查询接口进行限流,36节点CPU瞬间恢复。

2020-06-16 中午13:04分左右,对37节点的分片进行了迁移,切换了该节点上的两个分片到别的节点,效果不是非常明显。

2020-06-16 13:44,取消第三方查询接口的流量限制。

2020-06-16 15:37分左右,36节点CPU开始增长且上下波动剧烈。讨论ES快递员集群全部下线虚拟机节点,下掉出问题严重的36节点。

2020-06-16 23:50左右开始准备ES快递员集群的迁移,下掉所有的虚拟机节点,下掉问题节点36节点。

2020-06-17 凌晨04:27分,快递员集群14个数据节点 2个master节点 2个client节点 全部运行于物理机,36机器移除快递员ES集群。

2020-06-17 上午10:00,快递员集群正常,高峰期,37这个节点比起其它的节点还是弱了一些,没有36后它是最差的,但是处于健康可控状态。

2020-06-17 晚上22:55左右,下线之前出问题的消费者集群189节点。

2020-06-18 到 现在,集群处理稳定监控状态,快递员集群37节点的CPU负载要略高于所有其他节点两倍,但是处于健康可控状态。

结论:

快递员集群36节点和消费者189节点存在系统或者机器问题, 37节点也存在类似的问题,但是相对于差的来说要好一些。

点赞
收藏

评论区

加载中...

相关推荐

手写Java HashMap源码

HashMap的使用教程HashMap的使用教程HashMap的使用教程HashMap的使用教程HashMap的使用教程22

tidb集群某个节点报错之:node_exporter

今天启动集群tidb时出现一个错误,是某个tikv节点报错:node\_exporter9100.service failed一个节点的问题会导致整个集群启动失败。去此节点下的日志文件中查找,发现没有什么报错原因。无奈此时只能去系统日志中查看发生了什么问题果然发现了问题Jan1615:35:05ip1723126133

Tomcat基于MSM+Memcached实现Session共享

前言在Tomcat集群中,当一个节点出现故障,其他节点该如何接管故障节点的Session信息呢?本文带来的解决方案是基于MSMMemcached实现Session共享。相关介绍MSMMSM–MemcachedSessionManager是一个高可用的TomcatSession共享解决方案,除了可以从本机内存

IE7、IE8、IE9对min

问题:    IE7、IE8、IE9对minheight不识别,其他无问题解决:   box{width:100px;height:35px;}   htmlbodybox{width:auto;height:auto;width:100px;minheight:35px;} 实例:

Kubernetes Pod OOM 排查日记

一、发现问题在一次系统上线后,我们发现某几个节点在长时间运行后会出现内存持续飙升的问题,导致的结果就是Kubernetes集群的这个节点会把所在的Pod进行驱逐OOM;如果调度到同样问题的节点上,也会出现Pod一直起不来的问题。我们尝试了杀死Pod后手动调度的办法(label),当然也可以排除调度节点。但是在一段时间后还会复现,我们通过监控

Hadoop中重新格式化namenode

题记:Hadoop在我放下很久以后,再次拿起来。使用bin/startall.sh命令启动hadoop集群,死活不见namenode节点。在解决这个问题的时候,又不断的引出了很多新的问题。虽然这些问题在以前学习hadoop时都解决过。但,正因为以前解决过,现在遇到这些问题就更不想重复解决了。想要以最快的速度启动集群。最后想了

ES某节点CPU增长至100%的诡异问题 - HelloWorld