dubbo學習筆記(一)超時與重試

dubbo提供在provider和consumer端，都提供了超時(timeout)和重試(retries)的參數配置。

---

配置方式

provider端在<dubbo:service>中配置，consumer端在<dubbo:reference>中配置。

默認值

timeout默認值為1000，單位毫秒，表示超時時間是1秒；

retries默認值為2，表示重試2次，加上本身調用1次，一共有3次調用；

在org.apache.dubbo.common.Constants類可以找到：

public static final int DEFAULT_TIMEOUT = 1000;
public static final int DEFAULT_RETRIES = 2;

優先級

consumer端配置優先於provider端配置

---

通過一個例子來對這2個參數進行詳細學習和解讀。
建立如下工程結構：

其中：
demo-consumer為consumer端應用(SpringBoot工程)
demo-provider為provider端父工程，它下面有2個子工程，
    demo-interface為dubbo服務接口定義
    demo-service為provider端應用(SpringBoot工程)，實現了demo-interface接口，

demo-interface里接口定義：

public interface HelloService {

    String hello(String name);
}

定義了1個HelloService接口，里面一個hello方法，請求參數為1個String，返回String。

在demo-service里對該接口的實現類：

@Service("helloService")
public class HelloServiceImpl implements HelloService {
    @Override
    public String hello(String name) {
        System.out.println("hello begin=>" + name);
        System.out.println("hello end=>" + name);
        return "hello " + name;
    }
}

demo-service中的dubbo-demo-provider.xml定義：

<dubbo:service ref="helloService" interface="com.cdfive.demo.service.HelloService"  />

demo-consumer中的dubbo-demo-consumer.xml定義：

<dubbo:reference id="helloService" interface="com.cdfive.demo.service.HelloService" />

為了通過瀏覽器輸入請求地址訪問，在demo-consumer定義了一個Controller：

@RequestMapping("test")
@RestController
public class TestController {

    @Autowired
    private HelloService helloService;

    @RequestMapping("hello")
    public String hello(String name) {
        return helloService.hello(name);
    }
}

這樣我們就可以通過瀏覽器里訪問http://localhost:8081/test/hello?name=xxx，來調用dubbo接口：HelloService#hello

demo-consumer的啟動類：

@Slf4j
@ImportResource("classpath:config/applicationContext.xml")
@SpringBootApplication(scanBasePackages = "com.cdfive")
public class DemoConsumerApplication {
    public static void main(String[] args) {
        SpringApplication.run(DemoConsumerApplication.class, args);
        log.info("demo consumer started");
    }
}

demo-service的啟動類：

@Slf4j
@ImportResource("classpath:config/applicationContext.xml")
@SpringBootApplication(scanBasePackages = "com.cdfive")
public class DemoProviderApplication {
    public static void main(String[] args) {
        SpringApplication.run(DemoProviderApplication.class, args);
        log.info("demo provider started");
    }
}

OK，准備工作完畢。
把provider端和consumer端應用都啟起來，瀏覽器中訪問：http://localhost:8081/test/hello?name=cdfive

可以看到，瀏覽器中顯示：
hello cdfive

在demo-service的控制台顯示：
hello begin=>cdfive
hello end=>cdfive

前面提到，timeout默認是1000，就是1秒超時。這里我們修改HelloServiceImpl的實現，通過Thread.sleep(2000)模擬業務方法超時，休眠2s：

@Service("helloService")
public class HelloServiceImpl implements HelloService {
    @Override
    public String hello(String name) {
        System.out.println("hello begin=>" + name);

        try {
            Thread.sleep(2000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

        System.out.println("hello end=>" + name);
        return "hello " + name;
    }
}

重啟demo-service，F5刷新瀏覽器再次訪問：http://localhost:8081/test/hello?name=cdfive

case 1： 默認情況，provider和consumer端的timeout和retires均不設置，使用默認值

觀察輸出結果
瀏覽器：
There was an unexpected error (type=Internal Server Error, status=500).
Failed to invoke the method hello in the service com.cdfive.demo.service.HelloService. Tried 3 times of the providers....

provider端：
hello begin=>cdfive
hello begin=>cdfive
hello end=>cdfive
hello begin=>cdfive
hello end=>cdfive
hello end=>cdfive

consumer端：
[ WARN ] [2019-01-01 14:52:03,007] [DubboClientHandler-192.168.1.100:20001-thread-2] com.alibaba.dubbo.remoting.exchange.support.DefaultFuture [71] - [DUBBO] The timeout response finally returned at 2019-01-01 14:52:03.007, response Response [id=6, version=null, status=20, event=false, error=null, result=RpcResult [result=hello cdfive, exception=null]], channel: /192.168.1.100:61755 -> /192.168.1.100:20001, dubbo version: 2.6.0, current host: 192.168.1.100
[ WARN ] [2019-01-01 14:52:04,008] [DubboClientHandler-192.168.1.100:20001-thread-2] com.alibaba.dubbo.remoting.exchange.support.DefaultFuture [71] - [DUBBO] The timeout response finally returned at 2019-01-01 14:52:04.008, response Response [id=7, version=null, status=20, event=false, error=null, result=RpcResult [result=hello cdfive, exception=null]], channel: /192.168.1.100:61755 -> /192.168.1.100:20001, dubbo version: 2.6.0, current host: 192.168.1.100
[ ERROR] [2019-01-01 14:52:04,011] [http-nio-8081-exec-6] org.apache.catalina.core.ContainerBase.[Tomcat].[localhost].[/].[dispatcherServlet] [182] - Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is com.alibaba.dubbo.rpc.RpcException: Failed to invoke the method hello in the service com.cdfive.demo.service.HelloService. Tried 3 times of the providers [192.168.1.100:20001] (1/1) from the registry localhost:2181 on the consumer 192.168.1.100 using the dubbo version 2.6.0. Last error is: Invoke remote method timeout. method: hello, provider: dubbo://192.168.1.100:20001/com.cdfive.demo.service.HelloService?anyhost=true&application=demo_consumer&check=false&default.check=false&dubbo=2.6.0&generic=false&interface=com.cdfive.demo.service.HelloService&methods=hello&pid=7032&register.ip=192.168.1.100&remote.timestamp=1546325119243&side=consumer&timestamp=1546324847011, cause: Waiting server-side response timeout. start time: 2019-01-01 14:52:03.006, end time: 2019-01-01 14:52:04.008, client elapsed: 1 ms, server elapsed: 1001 ms, timeout: 1000 ms, request: Request [id=8, version=2.0.0, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=hello, parameterTypes=[class java.lang.String], arguments=[cdfive], attachments={path=com.cdfive.demo.service.HelloService, interface=com.cdfive.demo.service.HelloService, version=0.0.0}]], channel: /192.168.1.100:61755 -> /192.168.1.100:20001] with root cause
com.alibaba.dubbo.remoting.TimeoutException: Waiting server-side response timeout. start time: 2019-01-01 14:52:03.006, end time: 2019-01-01 14:52:04.008, client elapsed: 1 ms, server elapsed: 1001 ms, timeout: 1000 ms, request: Request [id=8, version=2.0.0, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=hello, parameterTypes=[class java.lang.String], arguments=[cdfive], attachments={path=com.cdfive.demo.service.HelloService, interface=com.cdfive.demo.service.HelloService, version=0.0.0}]], channel: /192.168.1.100:61755 -> /192.168.1.100:20001
at com.alibaba.dubbo.remoting.exchange.support.DefaultFuture.get(DefaultFuture.java:134)
at com.alibaba.dubbo.remoting.exchange.support.DefaultFuture.get(DefaultFuture.java:111)
at com.alibaba.dubbo.rpc.protocol.dubbo.DubboInvoker.doInvoke(DubboInvoker.java:95)
at com.alibaba.dubbo.rpc.protocol.AbstractInvoker.invoke(AbstractInvoker.java:142)
at com.alibaba.dubbo.rpc.listener.ListenerInvokerWrapper.invoke(ListenerInvokerWrapper.java:73)
at com.alibaba.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:74)
at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68)
at com.alibaba.dubbo.rpc.protocol.dubbo.filter.FutureFilter.invoke(FutureFilter.java:53)
at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68)
at com.alibaba.dubbo.rpc.filter.ConsumerContextFilter.invoke(ConsumerContextFilter.java:47)
at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68)
at com.alibaba.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:52)
at com.alibaba.dubbo.rpc.cluster.support.FailoverClusterInvoker.doInvoke(FailoverClusterInvoker.java:77)
at com.alibaba.dubbo.rpc.cluster.support.AbstractClusterInvoker.invoke(AbstractClusterInvoker.java:232)
at com.alibaba.dubbo.rpc.cluster.support.wrapper.MockClusterInvoker.invoke(MockClusterInvoker.java:70)
at com.alibaba.dubbo.rpc.proxy.InvokerInvocationHandler.invoke(InvokerInvocationHandler.java:51)
at com.alibaba.dubbo.common.bytecode.proxy0.hello(proxy0.java)
at com.cdfive.demo.controller.TestController.hello(TestController.java:21)

瀏覽器打印了異常信息，其中Tried 3 times of the providers表明嘗試了3次調用；
provider打印了3次請求調用情況，注意到begin和end不是按順序的，也就是說上1個調用沒執行完，因為1秒超時時間到了，又開始了新的一次重試，而前面的調用並未終止；
consumer打印了3次WARN ...[DUBBO] The timeout response...，和一次ERROR，錯誤信息跟瀏覽器看到的一致，只是多了堆棧信息。

總結：
在不設置timeout和retries的時候，如果provider端接口一直出現超時，provider端會調用3次，而日志中沒有任何警告或錯誤信息；
consumer端雖然重試了2次，加本身調用的1次，一共發起3次調用，如果provider3次全部超時，consumer端會打印超時異常信息；
provider端日志中沒有任何警告或錯誤信息不利於發現問題；前面的調用並未終止，如果是非查詢類接口且接口沒有實現冪等性時，可能產生重復數據。

case 2： provider端retries=0，consumer端不設置

重啟並訪問，瀏覽器中仍然是錯誤信息，但是Tried 1 times of the providers，表示只調用了1次 ；
provider端僅打印了1次調用：
hello begin=>cdfive
hello end=>cdfive
consumer端打印1次WARN、1次ERROR

總結：
在provider端設置retries=0已經生效，接口僅調用了1次；

case 3： provider端retries=0，consumer端retries=1

重啟並訪問，瀏覽器中仍然是錯誤信息，但是Tried 2 times of the providers，表明調用了2次 ；
provider端打印了2次調用，consumer打印了2次WARN、1次ERROR

總結：
consumer的retries優先級較高，兩端都設置的情況下，以consumer端的retries為准。

case 4： provider端timeout=3000, retries=0，consumer端retries=0

接下來我們把重試都關閉(即都設置為0)，來看看timeout的情況，這里設置為3秒，因為方法休眠2s；
重啟並訪問：
瀏覽器正常輸出hello cdfive，provider輸出請求參數，consumer沒有輸出；

總結：
provider端設置timeout已生效。

case 5： provider端timeout=1000, retries=0，consumer端retries=0

provider端的超時設置為小於接口執行時間；
重啟並訪問：
跟case 1很像，因為重試為0，所以只調用了1次，唯一不同的provider端日志里多了1次WARN
[ WARN ] [2019-01-01 15:19:49,482] [DubboServerHandler-192.168.1.100:20001-thread-2] com.alibaba.dubbo.rpc.filter.TimeoutFilter [71] - [DUBBO] invoke time out. method: hello arguments: [cdfive]...

這是dubbo自帶的filter類TimeoutFilter輸出的。

總結：
provider端設置了timeout，如果接口調用超時，provider會打印WRAN信息。

case 6： provider端timeout=1000, retries=0，consumer端timeout=3000, retries=0

這里provider端的1秒小於接口方法的2秒，而consumer設置的3秒大於2秒，
重啟並訪問：
瀏覽器成功輸出hello cdfive，provider輸出請求參數，並打印了1次WARN，consumer沒有輸出；

總結：
consumer的timeout優先級較高，兩端都設置的情況下，以consumer端的timeout為准。

---

參考dubbo官網的文檔，並結合工作中項目實踐，對超時和重試這2個參數做個總結：

1.超時(timeout)默認1000毫秒，重試(retries)默認2次(即一共調用3次)；
2.provider端在<dubbo:service>中配置，consumer端在<dubbo:reference>中配置，consumer端的配置會覆蓋provider配置；
3.超時(timeout)建議在provider端配置，因為作為提供方，它更清楚自己接口的耗時情況，並且provider端設置了timeout，在日志中有TimeoutFilter的WARN信息；
4.在provider端一般接口timeout設置為5秒或者10秒，如果是復雜查詢、導出報表、調用第三方接口、本身是最上游的接口等，根據情況考慮設置大一點；
5.在consumer端配置設置timeout會覆蓋provider設置，但有時設置timeout能夠讓consumer快速失敗，而不因為下游provider服務接口的問題拖垮consumer本身；
6.retries建議在provider端設置為0，consumer根據情況也可以設置為0，因為重試可能因非冪等性原因導致重復數據，並且超時情況即便重試成功consumer端可能也收不到成功響應；

---

參考：
http://dubbo.apache.org/zh-cn/docs/user/recommend.html
http://dubbo.apache.org/zh-cn/docs/user/references/xml/dubbo-service.html
http://dubbo.apache.org/zh-cn/docs/user/references/xml/dubbo-reference.html