MySQL 优化 02 之连接管理

问题描述

最近一直在服务端的性能优化,逐个解决线上之前遗留的一些问题,其中有一个问题是后端 rpc service MySQL 连接中出现大量 sleep 的连接,而且时间很长。我们技术栈用的是 Python,用 sqlalchemy 做 ORM 层,在 sqlalchemy 连接池中已经配置了对超过 300s 的连接做 recycle,但是 mysql 的 processlist 中出现了大量超过 300s 的连接。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
ID          USER    HOST              DB      COMMAND TIME    STATE   INFO
163487088 user 10.10.91.38:45925 martin Sleep 28233 NULL
163492031 user 10.10.91.38:46375 martin Sleep 26930 NULL
163517693 user 10.10.115.248:52431 martin Sleep 20166 NULL
163517692 user 10.10.115.248:52430 martin Sleep 20165 NULL
163520369 user 10.10.115.89:59120 martin Sleep 19472 NULL
163531406 user 10.10.195.222:36208 martin Sleep 16517 NULL
163535568 user 10.10.195.222:42941 martin Sleep 15500 NULL
163545536 user 10.10.91.38:52311 martin Sleep 9649 NULL
163548642 user 10.10.131.145:54374 martin Sleep 7659 NULL
163548641 user 10.10.131.145:54372 martin Sleep 7658 NULL
163548640 user 10.10.131.145:54366 martin Sleep 7658 NULL
163550399 user 10.10.131.145:59423 martin Sleep 6535 NULL
163551913 user 10.10.138.210:52551 martin Sleep 5582 NULL
163551912 user 10.10.138.210:52550 martin Sleep 5582 NULL
163551911 user 10.10.138.210:52547 martin Sleep 5582 NULL
163551910 user 10.10.138.210:52544 martin Sleep 5582 NULL
163551307 user 10.10.115.248:34162 martin Sleep 5378 NULL
163553402 user 10.10.1.39:58200 martin Sleep 4624 NULL
163553858 user 10.10.91.38:54184 martin Sleep 4321 NULL
163554229 user 10.10.55.228:51618 martin Sleep 4098 NULL
163553577 user 10.10.46.232:51933 martin Sleep 3982 NULL
163553712 user 10.10.46.232:52096 martin Sleep 3976 NULL
163554595 user 10.10.131.145:42649 martin Sleep 3873 NULL
163554582 user 10.10.1.39:34434 martin Sleep 3505 NULL
163556848 user 10.10.3.68:37552 martin Sleep 2440 NULL
163557218 user 10.10.46.232:55973 martin Sleep 2211 NULL
163556771 user 10.10.67.225:49920 martin Sleep 2150 NULL
163557587 user 10.10.67.225:52996 martin Sleep 1976 NULL
163558125 user 10.10.67.225:54897 martin Sleep 1648 NULL
163558292 user 10.10.1.39:48445 martin Sleep 1534 NULL
163558147 user 10.10.138.210:39829 martin Sleep 1510 NULL
163558505 user 10.10.131.145:51929 martin Sleep 1416 NULL
163558570 user 10.10.105.200:53281 martin Sleep 1374 NULL
163558339 user 10.10.165.71:45458 martin Sleep 1352 NULL
163558899 user 10.10.141.67:38908 martin Sleep 1176 NULL
163558631 user 10.10.131.145:52252 martin Sleep 1160 NULL
163558968 user 10.10.115.248:53551 martin Sleep 1128 NULL
163559006 user 10.10.1.39:51176 martin Sleep 1107 NULL
163559041 user 10.10.1.39:51377 martin Sleep 1079 NULL
163559090 user 10.10.15.53:38326 martin Sleep 1052 NULL
163559098 user 10.10.138.210:42150 martin Sleep 1048 NULL

理解 processlist

MySQL 的 processlist 显示的 MySQL 实例与所有 client 的连接状态,默认情况下只显示当前账户下面的连接,root 用户可以查看所有其他用户的连接,也可以为账户赋予 processlist 权限,方便查看所有用户的连接。

可以使用以下 SQL 查看 processlist 的数据,

1
2
select * from PROCESSLIST;
show PROCESSLIST;

processlist 各个 column 的含义在此不一一解释了,不懂的可以参考:

在此重点解释一下 Command 列状态是 Sleep Sleep 的状态的连接表示,该连接上在等待有 SQL 命令的执行,也就是说这是一个空闲的连接,由于 MySQL 的执行速度其实很快,两次使用 processlist 查看同一个连接如果都处于 Sleep 状态,并不表示说这个连接没有被使用,可能其实已经执行过一次 SQL 命令并且结束了。

问题分析

Sleep 状态的连接很多,而且占用时间超过连接池配置的 300s 的占在一半,并且实际 QPS 远没有这么多,说明很多连接其实是一直空闲的状态,基本得不到释放。

我们来举个实际的例子说明 connection pool 的配置中各个参数的影响和关系。某台数据库实例某段时间内连接数在 2k 左右,但是实际 QPS 峰值在 500 左右,也就是说 2k 中的连接只有 1/4 在工作,其他处于空闲状态,设置的 recycle 时间是 300s。假设从时间点 A 算起,过了 300s 之后到达时间点 B,由于峰值 QPS 是 500,也就是 2k 的连接中最多只需要 500,这时 connection pool 在触发检查 connection 的 recycle 时会把连接池从 2k 逐渐减少到 500,connection pool 是 FIFO 的机制,所有 connection 都有机会被获取,因而就有机会被释放。

在 sqlalchemy 的实现中,recycle 的操作发生在从 pool 中获取新的连接的时候,如果一个 connection 已经满足 recycle,也就是存在时间超过了 300s,那么会把该连接关闭,然后创建一个新的连接并返回 /lib/sqlalchemy/pool/base.py:_ConnectionRecord:get_connection

为了重现 recycle 的机制,在本地写了一个多线程的程序,首先设置 pool 大小是 10,recycle 时间是 90s,用 15 个线程,每隔 60s 去连接数据库,连接池配置如下:

1
2
3
4
5
6
7
engine = create_engine(
'mysql+pymysql://root:@localhost/blog?charset=utf8',
encoding='utf8',
echo=False,
pool_size=10,
pool_recycle=90,
)

多线程的连接如下:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20

def with_thread_test_pool_recyle():
thread_list = []
for _ in range(15):
t = threading.Thread(target=order_by)
thread_list.append(t)

for t in thread_list:
t.start()

for t in thread_list:
t.join()


def test_pool_recyle():
while 1:
print('thread start')
with_thread_test_pool_recyle()
print('thread end')
time.sleep(60)

order_by 是一个简单的通过 sqlalchemy session 连接 MySQL 查询的函数。

运行测试用例,通过在 sqlalchemy 代码中浸入日志的办法可以明显观察到 recycle 触发了,而且在本地 MySQL 中观察 show processlist 能够明显看到连接在存活 90s 之后由于触发 recycle 而回收了,当然由于 sqlalchemy 触发回收发生在获取 pool 中的连接时,如果不从 pool 中获取连接 ,recycle 是不会执行的。

上述的回收机制引来一个问题

假设把连接池的大小设置成 30,并把 recycle 的时间设置成 300s,也就是最大连接数是 30,如果正常的 QPS 是 20,每个请求都能及时归还 connection 到连接池中,那么下次请求一定会复用该连接,也就是说只要 20 个连接就能够满足要求。

现在流量涨到 30 QPS,且每个请求也能及时归还 connection 到连接池中,连接池实际连接会涨到 30,之后流量开始下降 QPS 回归到 20,由于连接池采用的 FIFO 的机制,只要有请求,每个请求都会得到机会触发 recycle,多余的 connection 会被慢慢回收。

一般的服务由于需要利用多核都会开多个进程,在我们刚才分析的上述问题的场景就是监听多个端口的多个 Python 的进程。

当流量突增,根据刚才单进程的分析,即使负载均衡稍微有点不均,每个进程连接池的实际连接大概率都会涨起来,流量退去之后,如果请求依然不均匀,导致部分进程承担了大部分流量,少部分进程只有少量请求分配,或没有请求分配,就会导致被增加的连接得不到触发回收的机会。

僵局

如果 sqlalchemy 根据 recycle 回收 connection 没有 bug,也没有任何连接不在 sqlalchemy 管制之下,比如由于 bug 发生内存泄露,sqlalchemy 失去了对 connection 的管理,使得 connection 得不到释放,假设这样的问题不存在,那么影响 connection 回收的时机就是最重要的,而影响时机的主要因素又是请求的分发时机。

因而合理控制好请求的分发让每个进程都能得到均衡的负载应该就可以保证每个进程的 SQL 连接数是均衡的。

但是在我们实际分析的这个场景中,一开始确实我们的代理层转发到后端 rpc service 服务的均衡由于有一个 bug 导致请求转发之后是不均匀的,但是在我们纠正之后,可以明显看到各个 rpc service 进程负载变均衡了,但是大量 Sleep 状态的 MySQL 连接依然存在。

问题陷入了僵局。

解开僵局

大量 Sleep 状态的 MySQL connection 依然存在,然后开始分析拥有这些 connection 的进程都有什么特点。

从 processlist 中能够看到连接到 MySQL 的端口,我们在例子中任意取一个端口,根据:

1
2
netsta -antlp | grep 45925
tcp 0 0 10.10.149.169:35099 10.10.109.32:3306 ESTABLISHED 32268/python

能够看到连接 MySQL 的进程 PID,然后根据 PID 获取监听的端口,turbo 是启动监听进程的文件名:

1
ps aux | grep turbo | grep 32268

通过几次尝试发现 Sleep 状态的连接都来自特定的监听端口,然后我们根据负载均衡器的策略对照了一遍终于发现了答案。

我们的负载均衡是自研的,根据自身业务的评估,把后端的机器和进程按照业务进行特定分组,不同的业务使用不同的进程,也就是不同的机器或者相同机器的不同端口。数据库实例也是按照业务的不同进行不同的分组,基本上进程中业务的划分和数据库的业务划分是对等的,但是也不是完全对等,也就是说总有 A 业务的 rpc 调用会连接 B 业务的数据库,但是量非常少,偶尔才会有一个调用出现,问题就是既然有调用出现,就会产生连接,这个连接池的管理,SQLAlchemy 是通过配置的数据库地址来进行的,也就是一个数据库地址是一个 connection pool,根据我们上面的分析,SQLAlchemy 是在获取新的连接时进行 recycle 的检查,如果一个连接池在创立之后,很少使用或几乎不用,那么该连接池中的 connection 也就没有办法得到释放,因为没有机会触发释放的时机了,正式因为有极个别的 A 业务的进程组使用了 B 业务的数据库,而且请求非常的少,导致 A 业务进程连接到 B 业务数据库的连接都没有机会得到释放,这才导致了 B 业务数据库中大量的 Sleep 状态的连接的出现

主动释放连接太长的 MySQL 连接

既然被动检查时间太长,可以考虑进主动检查,也就是每隔一段时间对所有已经建立的连接池进行检查清理,这样基本可以完全杜绝 Sleep 状态的连接的出现,至此这个问题就解决完了。

如何释放?

我查阅了 SQLalchemy 处理连接的代码,跟踪了一下整个连接建立的全部过程,SQLalchemy connection 建立的过程都是从 engine 出发,封装 DBAPI connection,然后把封装好的 connection 加入 pool 供应用程序使用,每个 connection 都会和一个 transaction 绑定,而且 SQLalchemy 并没有提供直接遍历 pool 中所有 connection 的 API,可以通过 engine 的 pool 对象获取到,但是不建议这样做,如果 SQLalchemy 版本发生变动,这个属性也有可能发生变化。

最好能直接通过 session 间接操作 connection,但是 session 中没有直接获取底层 connection 的属性,但是 session 提供了一个方法叫:invalidate,这个方法可以把和 session 绑定的 connection 直接关闭而不是又重新放回 pool,因而可以借助这个方法实现主动释放,基本原理是:pool 中 connection 是按照 FIFO 的机制循环获取,如果一个 connection 长期处于 Sleep 状态说明这个 connection 很久没有被使用,使用过的 connection Sleep 会重新归 0 开始计算,那么这个进程的连接池的队列上大概率上已经不循环了,所以任意取一个 session 并把它关闭了就有机会把那个需要 recycle 的 connection 关闭,即使没有取到符合条件的也只是释放了一个连接而已,并不会造成太大影响。

后端服务用的 gunicorn 并且模型是 gevent,可以借助 gevent 的非阻塞来定时处理:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
class MysqlConnectionRecycle(gevent.Greenlet):

def __init__(self, slist):
gevent.Greenlet.__init__(self)
self.slist = slist

def _run(self):
while True:
gevent.sleep(320)
for Session in self.slist:
session = Session()
try:
session.execute("select 1")
session.invalidate()
except Exception as e:
pass

定时器的周期是根据设置 pool 的 recycle 时间来定的,要让定时器在执行时有机会把需要 recycle 的 connection 关闭,所以可以选择略大于定时周期的时间,也可以设置成一个较短的周期,只要对服务的整体性能影响不大即可。

如果 gunicorn 模型是其他模型,如果是 tornado 可以借助 tornado 的 PeriodTask,如果是同步模型,可以借助多线程。

三月沙 wechat
扫描关注 wecatch 的公众号