DAS解决访问数据库延时突高的案例分享

1、前言

一、DAS介绍

DAS是信也科技自研的数据库访问框架。它包括数据库控制台das console，数据库客户端das client和数据库服务端das server三部分。DAS是基于Java语言开发的，支持数据库管理，ORM，SQL建立，分库分表操做的一体化数据库访问解决方案。DAS项目从去年开始已经在GitHub上开源：https://github.com/ppdaicorp/das

DAS直连方式架构图：

信也科技的应用大量使用DAS做为数据库访问中间件，目前几百个应用接入了DAS。

做为公司的标准数据库访问技术，DAS上线以来一直运行稳定。做为DAS团队，咱们在接入的众多应用实战中积累了很多数据库访问相关的经验。
虽然咱们这里分享的是DAS的真实技术支持的案例，可是我认为它的通过和结果对相似的情景仍旧颇有借鉴的意义。

二、问题背景

去年公司有一个使用了DAS的对接外部系统的应用，应用开发人员反映系统会时不时地发生数据库慢查询。咱们经过日志系统发现这些慢查询发生的比率极低，甚至低于千分之一。

若是这是个普通的应用，低于千分之一的慢查询比率是能够接受的。可是这一个对接外部系统的应用，外部系统对延时要求很是高，即便千分之一的高延迟仍旧不知足需求。

三、问题定位

首先，咱们联系了DBA，从数据库日志角度查看是数据库端是否有慢查询发生。DBA团队在MySQL上面有专门记录慢查询的日志。慢查询的日志结果是否认的，并且数据库的数据量也在合理的水平。若是数据库端没有发生慢查询，那必定是整个链路其余地方发生了延时，随后咱们把精力回到应用端。

经过研究日志，咱们发现了和直觉相反的现象：延时没有发生在数据库操做频率比较高的操做上，而是发生在一些操做频率很低的操做上。

问题极可能和程序状态变迁有关。在应用端，DAS自己是一个无状态的架构，它主要依赖于无状态的JDBC和DataSource。DataSource是典型有状态的程序，因此问题发生在DataSource的可能性最大。

DataSource的本质是为了节省程序的时间和空间，对数据库链接作的缓存。它的设计思路和其余软件缓存的设计思路是同样的：要把实例放到缓存池管理，只不过这里的实例是数据库链接。每种数据库缓存池都有一系列的配置参数，它们都是用来调节缓存池的行为，经过不一样的参数配置就能为不一样的场景服务。

经过分析DataSource的配置，咱们找到了缘由。缘由是因为数据库数据库两次操做间隔空闲时间太长，致使链接池里全部的idle链接被清空。后续新链接须要创建物理链接，每次创建物理链接，须要创建socket以及数据库的安全认证这些费时操做。

既然问题定位在DataSource对idle链接的行为上，那么咱们就从idle的配置着手。DAS使用Tomcat的DataSource获取数据库链接实例。Tomcat的数据源提供了有不少的配置参数，这些参数决定了数据源的行为。
咱们最后把参数定位在minIdle这个参数上。从Tomcat官方文档上这样解释这个参数：

The minimum number of established connections that should be kept in the pool at all times.

若是把数据源看作一个缓存，那么minIdle就是这个缓存的minimum pool size。当时咱们这个minIdle参数设置的是0，设置成0的目的在于节省数据库链接。数据库链接是一种宝贵的资源，一个程序保持idle的链接太多不释放是一种浪费，对数据库这个共享的资源更是浪费，一个数据库每每同时被多个应用共同使用。
DBA会设置每一个数据库的最大链接数（max_connections）用以保护数据库不被请求压垮。当一个应用占据过多idle的链接，势必会影响其余应用的链接获取。

当minIdle参数设置成0，当然节约链接，可是它在极端状况下可能产生效果就是：当链接池中的链接长久不用时，链接池内全部idle链接所有被清空。Tomcat数据源会在后台定时启一个线程清理idle的链接，将idle的链接数降到minIdle。
在设置成0以后，至关于链接池会被清空，因而后续第一个链接就须要创建真正的物理数据库链接，致使耗时飙高。在这个案例中，就是发生了这个状况。

2、解决过程

一、初步尝试

咱们将参数minIdle从0改成1，这样一来链接池中至少有一个链接能够被复用，并且保持一个idle链接也不算浪费。同时，咱们经过增大了minEvictableIdleTimeMillis的参数把链接池中idle链接的最小空闲时间从30秒增大到10分钟。这样的话，位于缓存池里的idle链接生命周期延长了，池子里的idle数变多，增长了缓存命中率。须要注意的是minEvictableIdleTimeMillis这个参数控制的是evict掉缓存池里大于minIdle数的链接，在minIdle范围里面的链接是不会被它evict的。

是否是完美解决问题？不，故事未完。

二、遇到新问题

当咱们在测试的时候发现，程序会报异常：

Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException:
The last packet successfully received from the server was 9,969,393 milliseconds ago.

这是由minIdle设置为1形成的。经过调查发现，这是因为MySQL服务器有一个wait_timeout的参数，默认是8小时。这也是一个保护MySQL数据库自我节省资源的行为。咱们的数据库设置的30分钟，是也就是说一个链接空闲超过30分钟，MySQL服务器将主动断开该链接。例子中的9,969,393毫秒至关于好几个小时，远超30分钟，因此致使了这种异常。这时应用从DataSource取链接的话，取到的就是那个失效的链接。minIdle设置成1之后，那个长时间idle的链接就一直呆在链接池里面，甚至被MySQL服务器端断掉。

那加大wait_timeout？加大wait_timeout是不符合DBA规范。怎么办？Tomcat数据源提供了另外一个有用的参数testOnBorrow，官方文档上这样解释这个参数：

The indication of whether objects will be validated before being borrowed from the pool.
If the object fails to validate, it will be dropped from the pool, and we will attempt to borrow another.

若是把这个默认false值变为true以后，链接池会把链接从链接池拿出的时候会作验证链接有效性。这样就保证了从池里出来都是有效的链接。

三、验证与上线

最后，咱们在本地开发环境验证了解决这个链接超时的方案。首先，先把本地测试MySQL服务器的wait_timeout的参数调低便于模拟超时，而后经过代码逻辑控制，将两次访问数据库的时间间隔超过wait_timeout参数时间，观察数据源在这种场景下的表现。在两个不一样的数据源配置测试条件下，观察两次程序的结果。

本地验证成功以后，为了不修改配置以后引起新的问题，咱们首先进行了JUnit单元回归测试，保证基本功能完整。经过这几百个JUnit单元测试以后，把新配置部署到正式的测试环境进行观察。确认测试环境运行正常之后，最后才把配置更新到预发和生产环境。正规完善的流程是软件质量的保证。

至此，完美解决了这个问题。

四、其余数据源的应对

有人会问若是我没用Tomcat的数据源，用的是其余的数据源实现该如何作呢？
对于一个成熟的数据源产品来讲，Idle connection handling和Validation都是必有的功能。市面上大部分主流的数据源产品都有这些相似的参数。
譬如说流行的Druid和DBCP2，他们也都有如出一辙的minIdle，minEvictableIdleTimeMillis和testOnBorrow配置项。HikariCP的相似配置项是minimumIdle和idleTimeout。

3、感悟与总结

解决这个延时突高的问题，只是咱们中间件团队众多平常技术支持的一个案例。

咱们中间件团队和其余技术团队相比有特别之处，在于须要服务于公司各类不一样的业务线和技术线。咱们的用户有着不一样的需求和特性，应用场景不一样，技术要求也不一样，也就会产生各类各样的问题。有对并发要求高的，有对延时要求高的，有对API易用性要求高的，有对监控数据要求高的，等等。

虽然遇到故障和问题各色各样，可是咱们仍是从这些实战中总结出一些共性的地方。咱们能够把解决问题的过程总结为：反复地假设问题和论证，最后定位解决问题的过程。拿这个案例来讲，起初用户来找到咱们报问题的时候，咱们也一头雾水：为啥低并发的延时比高并发还高？起初，由于没有明确的怀疑点，因此咱们将链路上的每一点都检查了一下。从数据库到网络，甚至咨询了作监控的同窗，以确认延时时间的正确性。经过反复调查，咱们才将问题定位在客户端。

在排查问题的过程当中，好的监控起到了关键做用。通常监控有两类输出：警告和日志。应用团队就是经过警告及时发现了问题，而咱们中间件团队利用日志排查问题。日志的质量每每决定了定位问题的效率。好的监控可以提升你从表面现象到找到背后缘由（从what到why）的效率。

在这个解决这个延时突高的案例上，咱们也是从日志上获得蛛丝马迹。DAS自己会打详细的日志，经过这些日志，咱们能够看到DAS的代码和它底层JDBC消耗的时间，从而定位耗时发生在DAS的更底层。咱们还有个集中式日志系统，能在上面看到异常日志的原始信息，也能够在这个系统上面看各类维度的统计数据，譬如说，对这个案例相当重要的999线和QPS。若是咱们没有这些信息，我怀疑还能不能定位这个问题。

但愿咱们的此次排查问题的经历通过对你们有所帮助！

最后，请掏出你的手机：

---

做者介绍

Shengyuan，信也科技布道师、框架中间件资深专家、目前主要从事DAS相关的研发、运维工做。