首先說明專案中ES使用版本為2.4版本，ES JavaClient為2.4.4版本，服務器配置為16G、8核，
現象
我們一個地區專案中有一個查詢ES的介面莫名其妙的翻頁會出現超時，可能翻第一頁會出現，可能翻第三頁會出現，
排查思路
由于專案沒有做任何監控系統，因此唯一的排查思路就是定位到底是哪里執行超時的，在代碼中可能發生超時的位置都打了日志并進行臨時發布，最后發現是在呼叫查詢ES的時候卡住的（`searchRequestBuilder.execute().actionGet();`），并且沒有任何的例外日志，代碼執行的程序中很安詳的就結束了，<br />到此為止，還沒有任何的頭緒，
懷疑點
- 查詢
ActionRequestBuilder#execute原始碼看到使用到了執行緒池，因此懷疑是機器配置不夠，執行緒不夠用了？
public ListenableActionFuture<Response> execute() {
PlainListenableActionFuture<Response> future = new PlainListenableActionFuture<>(threadPool);
execute(future);
return future;
}
因此進入容器內使用top 1命令查看cpu占用，發現每個cpu占用都很低，因此排除機器配置問題，
?
- 難道是記憶體不夠用了？JVM一直進行GC，STW了？
使用jstat -gcutil -t 行程jd 1000 1000查看GC資訊，發現GC也正常，Eden、S1、S0、Old區占用都 處于正常范圍，FULL GC才3次，Yong GC和Old GC也不是很頻繁，因此排除是記憶體不夠導致，
?
- 再次懷疑是執行緒問題
使用jstack -l 命令將執行緒資訊輸出出來，查看后，發現有大量的es執行緒，并且執行緒狀態為WAITING (parking)，具體執行緒資訊如下
發現執行緒是阻塞在BaseFuture#get位置，并且是在呼叫AdapterActionFuture#actionGet時發生的，因此跟蹤原始碼，發現BaseFuture內部Sync實作了AQS，AQS相關文章可查看我之前寫的幾篇博客，
?
原始碼跟蹤
BaseFuture#get實際上是呼叫的Sync#get，原始碼如下：
BaseFuture.Sync#get
V get() throws CancellationException, ExecutionException,
InterruptedException {
// Acquire the shared lock allowing interruption.
//AQS的模板方法，嘗試獲取共享鎖
acquireSharedInterruptibly(-1);
return getValue();
}
AQS#acquireSharedInterruptibly
public final void acquireSharedInterruptibly(int arg)
throws InterruptedException {
if (Thread.interrupted())
throw new InterruptedException();
if (tryAcquireShared(arg) < 0)
doAcquireSharedInterruptibly(arg);
}
看到AQS#acquireSharedInterruptibly中呼叫了tryAcquireShared(arg)判斷是否拿到了共享鎖，tryAcquireShared(arg)在Sync中實作了，代碼如下
/*
* Acquisition succeeds if the future is done, otherwise it fails.
*/
@Override
protected int tryAcquireShared(int ignored) {
if (isDone()) {
return 1;
}
return -1;
}
boolean isDone() {
return (getState() & (COMPLETED | CANCELLED)) != 0;
}
getState是AQS的方法，state默認為0，0與任何數都是0，因此只有當state不為0的時候，才會回傳true，那什么時候state才會更改呢，看到這里估計也能猜個八九不離十了，肯定是從ES拿到資料，或者例外后才會修改state，查看Sync看到重寫了tryReleaseShared方法，
@Override
protected boolean tryReleaseShared(int finalState) {
setState(finalState);
return true;
}
原來就是在這里修改state的，查看該方法被哪里呼叫了，最終是從Sync#complete呼叫過去的，根據方法名稱我們也可以知道就是完成的時候呼叫，
private boolean complete(@Nullable V v, @Nullable Throwable t,
int finalState) {
boolean doCompletion = compareAndSetState(RUNNING, COMPLETING);
if (doCompletion) {
// If this thread successfully transitioned to COMPLETING, set the value
// and exception and then release to the final state.
this.value = https://www.cnblogs.com/502819L/p/v;
this.exception = t;
releaseShared(finalState);
} else if (getState() == COMPLETING) {
// If some other thread is currently completing the future, block until
// they are done so we can guarantee completion.
acquireShared(-1);
}
return doCompletion;
}
問題定位
到這里，我們基本就確定了問題所在，我們在呼叫ES Client去查詢的時候，實際上是開啟了一個查詢執行緒和一個等待執行緒，由于查詢執行緒一直沒有回呼結果，等待執行緒一直阻塞，導致查詢失敗，
解決方案
由于用戶著急使用，因此采用臨時方案，觀察到現象為偶發，因此嘗試在失敗時增加重試機制，發現#actionGet方法可以設定超時時間，因此更換可設定超時API，并捕獲ElasticsearchTimeoutException，在捕獲到例外時進行重試，問題解決，
public T actionGet(long timeout, TimeUnit unit) {
try {
return get(timeout, unit);
} catch (TimeoutException e) {
throw new ElasticsearchTimeoutException(e.getMessage());
} catch (InterruptedException e) {
throw new IllegalStateException("Future got interrupted", e);
} catch (ExecutionException e) {
throw rethrowExecutionException(e);
}
}
至于為何查詢執行緒遲遲不回呼，還沒有具體的定論，還在繼續排查，
本文由博客一文多發平臺 OpenWrite 發布！
轉載請註明出處，本文鏈接：https://www.uj5u.com/houduan/331947.html
標籤：Java