配置不當引起的Hystrix超時問題排查

最近發現一些服務檢查報錯 ，異常如下：

com.netflix.hystrix.exception.HystrixTimeoutException: null
at com.netflix.hystrix.AbstractCommand$HystrixObservableTimeoutOperator$1$1.run(AbstractCommand.java:1154)
at com.netflix.hystrix.strategy.concurrency.HystrixContextRunnable$1.call(HystrixContextRunnable.java:45)
at com.netflix.hystrix.strategy.concurrency.HystrixContextRunnable$1.call(HystrixContextRunnable.java:41)
at com.hikvision.hikkan.robotdevice.common.config.FeignHystrixConcurrencyStrategyIntellif$WrappedCallable.call(FeignHystrixConcurrencyStrategyIntellif.java:120)
at org.springframework.cloud.sleuth.instrument.async.TraceCallable.call(TraceCallable.java:63)
at com.netflix.hystrix.strategy.concurrency.HystrixContextRunnable.run(HystrixContextRunnable.java:61)
at com.netflix.hystrix.AbstractCommand$HystrixObservableTimeoutOperator$1.tick(AbstractCommand.java:1159)
at com.netflix.hystrix.util.HystrixTimer$1.run(HystrixTimer.java:99)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:305)
at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)

根據內容顯示明顯是 HystrixTimeoutException 請求超時了，但是根據全局記錄的整個請求的時間，如下圖所示也才3s。

2022-01-17 10:57:21.171 INFO robotdevice [XNIO-2 task-29] [com.xxx.GlobalHandler] - 請求方法:POST XXX 耗時:3118ms

而我們在application.yml中配置如下：

可知我們預期的超時時間足有25s這么長，但是為什么3s就超時了呢？ 懷疑是配置沒有生效。

於是需要找到關於hystrix配置相關的幾個類：

HystrixThreadPoolProperties 和 HystrixCommandProperties 這兩個類 分別代表設置線程池和Command的屬性類。其中HystrixCommandProperties可以設置對應的timeout。

HystrixThreadPoolPropertis中的配置

 HystrixCommandProperties中的配置

從上圖默認值大概能看出一些端倪，應該是配置沒有生效，而使用的默認配置 1s ，這樣3s就算超時了。

綜上在找一下對應的配置的configkey

//這是配置的賦值語句
this.executionTimeoutInMilliseconds = getProperty(propertyPrefix, key, "execution.isolation.thread.timeoutInMilliseconds",
 builder.getExecutionIsolationThreadTimeoutInMilliseconds(), default_executionTimeoutInMilliseconds);

//propertyPrefix如下是"hystrix"
protected HystrixCommandProperties(HystrixCommandKey key) {
　　this(key, new Setter(), "hystrix");
}

//具體的獲取配置並賦值
private static HystrixProperty<Integer> getProperty(String propertyPrefix, HystrixCommandKey key, String instanceProperty,
Integer builderOverrideValue, Integer defaultValue) {
  return forInteger()
     .add(propertyPrefix + ".command." + key.name() + "." + instanceProperty, builderOverrideValue)
     .add(propertyPrefix + ".command.default." + instanceProperty, defaultValue)
     .build();
}

debug看下這里超時時間設置的是默認的1s。

回頭看下我們配置

command放在了threadpool下面，所以找不到對應的配置。應該放在和threadpool同一級

重啟服務，可以看到配置生效了。