最近碰到 MySQL server has gone away
的报错,报错出现的现象是:
ThreadPoolExecutor
执行的异步任务中执行 mysql
查询操作,其他查询操作正常
项目基本情况:基于 python3.5+django1.8
,数据库 mysql
,生产和测试环境都是通过 nginx+uwsgi
部署
谷歌了一下 MySQL server has gone away
问题可能的原因:
1. MySQL
服务宕了
2. 连接超时
3 . 进程在server
端被主动 kill
4. SQL
语句太长
再结合项目实际情况逐条分析:
MySQL
服务宕了”,查看 mysql
的报错日志,看有没有重启信息,同时查看 mysql
的运行时长。 mysql> show global status like 'uptime'; +---------------+----------+ | Variable_name | Value | +---------------+----------+ | Uptime | 13881221 | +---------------+----------+ 1 row in set (0.00 sec)
报错日志中并没有服务重启的信息,同时 uptime
值很大,表示已经运行很长时间。因此第一条原因可以排除
server
端被主动 kill
”,当有长时间的慢查询时执行 kill
导致。查一下慢查询数量。 mysql> show global status like 'com_kill'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | Com_kill | 12 | +---------------+-------+ 1 row in set (0.00 sec)
Com_kill
居然有这么多-_-//,但也不确定出错的查询语句是否是慢查询。找了一下报错代码的查询语句,属于索引查询,而且查询时间不超过100ms,因此,这一条也可以排除。
第四条, SQL
语句太长导致。直接找到报错的查询语句,属于普通查询长度,所以这一条应该也可以排除。
那么第二条,连接超时,当某个连接很长时间没有新的请求了,达到了 mysql
服务器的超时时间,被强行关闭,再次使用该连接时,其实已经失效,就会出现” MySQL server has gone away
“的报错了。首先看一下数据库连接的最大超时时间设置多大。
mysql> show global variables like 'wait_timeout'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | wait_timeout | 86400 | +---------------+-------+ 1 row in set (0.00 sec)
目前设置的最大超时时间是24小时,也就是在这24小时内有数据库连接超时,超时连接后面又被用到,导致报错。
之前在django数据库连接中分析了 django
的数据库连接是基于线程( thread.local
)创建的全局变量,即线程本地变量,下面简称为线程变量。
对于常规请求,要获取数据库连接时,会首先查看当前线程变量中是否有可用连接,没有就创建并保存到线程变量中。每个 request
在开始和结束之前,会检查当前线程的数据库连接是否可用,并关闭不可用连接。这样就保证了每次请求获取到的一定是可用的数据库连接。
对于基于 ThreadPoolExecutor
的异步任务,线程池是在项目启动时创建的,当其中的线程被调起执行异步任务时,首次查询数据库时创建数据库连接,后续会一直保存在该异步线程中,该线程也会一直保存在线程池中。
由于没有像常规请求一样的在开始和结束之前检查数据库连接是否可用的机制,线程池中的线程保存的数据库连接也许是不可用的,就导致下次被调起执行数据库操作时出现“ MySQL server has gone away
”的报错。
再结合出错现象分析一下:
每到周末,生产环境活跃的用户数量减少,尤其是涉及到异步任务的业务场景触发减少,所以到周末线程池中的线程保存的部分数据库连接闲置超过24小时,周一上班后用户活跃增加,失效连接被调起,自然就会报错了。
线程池中的每个线程被调起的时机和次数都不同,某些线程最近刚被调起过,某些线程长时间没被调起,所以数据库连接失效,因此会出现部分异步任务报错的现象。
出现报错后一段时间自己恢复正常,而 ThreadPoolExecutor
本身也没有断掉异常连接或者杀掉线程的机制,但是查看业务日志,发现恢复正常后执行异步任务的线程和之前报错的线程不同,也就是基于某种机制,之前的线程被 kill
了。
看一下 ThreadPoolExecutor
中创建线程的逻辑:
def _adjust_thread_count(self): # When the executor gets lost, the weakref callback will wake up # the worker threads. def weakref_cb(_, q=self._work_queue): q.put(None) # TODO(bquinlan): Should avoid creating new threads if there are more # idle threads than items in the work queue. if len(self._threads) < self._max_workers: t = threading.Thread(target=_worker, args=(weakref.ref(self, weakref_cb), self._work_queue)) # 线程被设为守护线程 t.daemon = True t.start() self._threads.add(t) _threads_queues[t] = self._work_queue
线程池中创建的线程属于守护线程,当主线程退出,子线程也会跟着退出。而子线程是在调用 submit
方法提交异步任务时,若线程池中实际线程数量小于指定数量,便会创建。因此主线程是请求线程。
在用 uWSGI
部署的 django
项目中,请求线程是由 uWSGI
分配的。 uWSGI
会根据配置文件中的 process
, threads
参数决定开多少工作进程和子线程,同时还有 max-requests
参数,表示为每个工作进程设置的请求数上限。
当该工作进程请求数达到这个值,就会被回收重用(重启),其子线程也会重启。所以上面的报错现象中,其实是工作进程重启了,请求子线程也会重建,导致线程池中的守护线程也会被 kill
了,报错就停止了。
由于 django
的数据库连接是保存到线程本地变量中的,通过 ThreadPoolExecutor
创建的线程会保存各自的数据库连接。当连接被保存的时间超过mysql连接的最大超时时间,连接失效,但不会被线程释放。之后再调起线程执行涉及到数据库操作的异步任务时,会用到失效的数据库连接,导致报错。
又由于 uWSGI
的工作进程达到 max-requests
数量而重启,导致请求线程重启,线程池中的线程是根据请求线程创建的守护线程,因此会被 kill
,所以后面自己恢复正常。
要解决这个问题,最直接的办法是在线程池的所有异步任务中,在执行数据库操作之前,检查数据库连接是否可用,然后关掉不可用连接。
from threading import local def close_old_connections(): # 获取当前线程本地变量 connections = local() # 根据数据库别名获取数据库连接 if hasattr(connections, 'default'): conn = getattr(connections, 'default') # 检查连接可用性,并关闭不可用连接 conn.close_if_unusable_or_obsolete()
或者改写一下 django
获取和保存数据库连接的机制,可以创建一个全局的数据库连接池,不管是常规请求还是异步任务,都从连接池获取数据库连接,由连接池保证数据库连接的数量和可用性。
参考阅读
MySQL server has gone away报错原因分析
django数据库连接
WSGI & uwsgi