陈一乐
微服务
Accelerator
About
# Spring Cloud 之极端续租间隔时间的影响 本文基于某环境一个真实Case,它配置了非常极端的续租间隔时间。虽然知道服务注册的基本知识,但未深入了解过,正好基于这个Case学习下。 ## 问题现象 先简述下问题现象。 * 日志中大约以几秒一次的频率循环出现 *TimedSupervisorTask 67 task supervisor timed out* * 摘除流量后,Eden区约800M,Minor GC频率约 **4分钟/次**,GC后对象基本全部回收,Old区基本未增长 错误日志如下图:  ## 续租机制 ### heartbeat 在Spring Cloud中,各服务以heartbeat方式向Eureka Server续租以表明自己仍然存活。下面是两个续租相关配置。 * eureka.instance.lease-renewal-interval-in-seconds:续租(心跳)频率,服务定期向Server续租(即表明自己仍然存活,不要把自己剔除掉) * eureka.instance.lease-expiration-duration-in-seconds:租约有效期,在该时间内若client未更新租约,将剔除client 续租频率默认30s,租约有效期默认90秒,即 **client有3次重试机会**。 ###续租源码 `com.netflix.discovery.DiscoveryClient` 启动过程中,会以固定频率向Eureka Server续租。 贴纯代码很不友好,画了个简图,再结合代码解释下。  > TimedSupervisorTask 和 HeartbeatThread 都实现了Runnable接口 续租很简单,用了JUC的线程池,首先用 **scheduler** 管理 **TimedSupervisorTask**,然后 TimedSupervisorTask利用 **executor** 来submit心跳线程 **HeartbeatThread**,心跳线程以 **HTTP请求** 的方式向Eureka Server续租。 若HeartbeatThread执行超时,则进入 **超时处理逻辑**:即过一小会再执行心跳线程。 到底过多久再执行?延迟时间*2。延时时间初始值就是**续租间隔时间(renewalIntervalInSecs)**。 假设renewalIntervalInSecs设置为10秒,那第一次超时后将等待20秒再尝试续约,第二次超时后将等待40秒再尝试续约,以此类推。若续约成功,延迟时间将恢复为renewalIntervalInSecs。 了解以上逻辑后,再反向看源码。 HeartbeatThread是DiscoveryClient的内部类,向Eureka Server发送HTTP请求进行续约。 ```java private class HeartbeatThread implements Runnable { public void run() { if (renew()) { lastSuccessfulHeartbeatTimestamp = System.currentTimeMillis(); } } // 伪代码,有删减 boolean renew() { try { httpResponse = sendHeartBeat(应用名, 应用ID, 应用info); // HTTP请求 if (httpResponse.getStatusCode() == 404) { return register(); } return httpResponse.getStatusCode() == 200; } catch (Throwable e) { return false; } } } ``` schedule TimedSupervisorTask来监控HeartbeatThread,如果超时则执行超时处理逻辑;没超时则由HeartbeatThread正常处理即可。 ```java // Heartbeat timer scheduler.schedule( new TimedSupervisorTask( "heartbeat", scheduler, heartbeatExecutor, renewalIntervalInSecs, TimeUnit.SECONDS, expBackOffBound, new HeartbeatThread() ), renewalIntervalInSecs, TimeUnit.SECONDS); ``` TimedSupervisorTask这个任务代码如下,主要看下超时处理和`finally`中的重新schedule(有较大删减,仅保留必要代码)。 ```java public class TimedSupervisorTask extends TimerTask { public TimedSupervisorTask(...) { this.scheduler = scheduler; this.executor = executor; this.timeoutMillis = timeUnit.toMillis(timeout); this.task = task; //就是HeartbeatThread this.delay = new AtomicLong(timeoutMillis); // 延时时间 this.maxDelay = timeoutMillis * expBackOffBound; } public void run() { Future future = null; try { future = executor.submit(task); // 完成心跳或超时 future.get(timeoutMillis, TimeUnit.MILLISECONDS); delay.set(timeoutMillis); } catch (TimeoutException e) { logger.error("task supervisor timed out", e); long currentDelay = delay.get(); long newDelay = Math.min(maxDelay, currentDelay * 2); // 延时时间加倍 delay.compareAndSet(currentDelay, newDelay); } finally { if (!scheduler.isShutdown()) { // 重新schedule心跳任务 scheduler.schedule(this, delay.get(), TimeUnit.MILLISECONDS); } } } ``` heartbeatExecutor是JUC中的Executor,不特别介绍。 ```java ThreadPoolExecutor heartbeatExecutor = new ThreadPoolExecutor( 1, clientConfig.getHeartbeatExecutorThreadPoolSize(), 0, TimeUnit.SECONDS, new SynchronousQueue<Runnable>(), new ThreadFactoryBuilder() .setNameFormat("DiscoveryClient-HeartbeatExecutor-%d") .setDaemon(true) .build() ``` scheduler这个线程池用来管理TimedSupervisorTask。 ```java ScheduledExecutorService scheduler = Executors.newScheduledThreadPool(2, new ThreadFactoryBuilder() .setNameFormat("DiscoveryClient-%d") .setDaemon(true) .build()); ``` ## 回归问题 ### 续租配置 现在,我们回归问题现象。先看看问题应用的续租时间(renewalIntervalInSecs)配置: ```properties eureka.instance.lease-renewal-interval-in-seconds=1 ``` **是的,就是1秒,不要问我为什么,我也不知道!** 现在,至少可以确定:**应用在高频续租** ### 为何TimeoutException TimedSupervisorTask设定的超时时间是?看看时间监控伙计的timeout属性: ```java public TimedSupervisorTask(String name, ScheduledExecutorService scheduler, ThreadPoolExecutor executor,int timeout, TimeUnit timeUnit, int expBackOffBound, Runnable task) ``` **timeout**配置是new TimedSupervisorTask()时传进来的,使用的是**renewalIntervalInSecs**。好了,是一秒!在内网,正常来说1秒也是够的,但因各种情况总是免不了会超时,且HTTP超时时间设置为1秒的也是少之又少。 ```java scheduler.schedule( new TimedSupervisorTask( "heartbeat", scheduler, heartbeatExecutor, renewalIntervalInSecs, TimeUnit.SECONDS, expBackOffBound, new HeartbeatThread() ), renewalIntervalInSecs, TimeUnit.SECONDS); ``` 现在,出现 TimeoutException: *task supervisor timed out* 就比较清楚了。 想本地重现超时异常的话,在续租renew()中加个断点,模拟下超时,就可以抛出该异常。 ### 高频续租对GC的影响 在摘掉应用流量后,800M的Eden区在4分钟内被耗光。一下也找不到原因,在本地创建了Eureka Server和Client两个简单应用,观察Client的内存消耗情况。 为了便于观察,堆内存设置很小,如下: ```shell -Xmx40m -Xms40m -XX:NewRatio=3 -verbosegc -XX:+PrintGCTimeStamps -Xloggc:/Users/cyj/gcdebug.log ``` 接下来做2个对比实验: **1秒1次心跳** ```shell # 排除从Eureka Server获取所有实例的影响, 设置为10分钟 eureka.client.registry-fetch-interval-seconds=600 # 1秒一次心跳 eureka.instance.lease-renewal-interval-in-seconds=1 ``` 丢弃掉应用启动时的频繁GC,最后三次的 GC如下: ```java 2018-08-28T22:35:25.459-0800: 116.798: [GC (Allocation Failure) ... 2018-08-28T22:37:45.378-0800: 256.719: [GC (Allocation Failure) ... 2018-08-28T22:39:26.500-0800: 357.844: [GC (Allocation Failure) ... ``` 平均GC时间约 **2分钟/次**。 **不进行心跳** 接下来,将续租间隔、租约时间都设置成10分钟,达到在观察期间不进行心跳的效果。 ```properties eureka.client.registry-fetch-interval-seconds=600 eureka.instance.lease-expiration-duration-in-seconds=600 eureka.instance.lease-renewal-interval-in-seconds=600 ``` 丢弃掉应用启动时的频繁GC,最后三次的 GC如下: ```java 2018-08-28T22:39:53.806-0800: 7.546: [Full GC (Ergonomics) ... 2018-08-28T22:49:53.416-0800: 607.167: [GC (Allocation Failure) ... 2018-08-28T22:57:37.248-0800: 1071.009: [GC (Allocation Failure) ... ``` 碰巧来了次FullGC,但是不影响数据。平均GC时间接近**9分钟/次**的样子。 这两次对比实验虽然不是特别合适,但可以说明**不合理的心跳时间会加速内存的消耗**。 **调整问题应用的结果** 摘除问题应用的流量后,将续租间隔调整为默认值30秒后,该应用的Minor GC频率从 **4分钟/次** 降低到 **13分钟/次**。
本文由
陈一乐
创作,可自由转载、引用,但需署名作者且注明文章出处。
文章标题:
Spring Cloud 之极端续租间隔时间的影响
文章链接:
https://chenyongjun.vip/articles/70
扫码或搜索 codercyj 关注微信公众号, 结伴学习, 一起努力