配置不当引起的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同一级

重启服务，可以看到配置生效了。