一次"too many open files"的问题跟踪

问题发现

某一次线上API突然访问报错,于是检查日志,发现存在大量的Too many open files的错误,继续跟踪,发现这些错误是日志在打开文件时出现的。

跟踪

最开始想到的是多个进程打开一个文件可能会造成文件打开数过多,但实际API只开启了4个进程,且每一个使用到文件的地方都已经关闭,因此排除文件描述符泄漏的问题。那么除了打开文件以外,有没有可能是其他占用导致的文件描述符不够呢,众所周知,Linux中万物皆文件,对于API这种网络应用来说,TCP连接数也同样会很多,想到这,我立马使用lsof命令查看文件描述符占用情况。
先使用ps命令查出某个gunicorn进程的PID

ps -ef | grep gunicorn

然后查看其中一个gunicorn进程的文件描述符情况

lsof -p <PID> | grep TCP | wc -l

结果发现一个进程所打开的TCP连接符就高达1000多个,且大部分都是3306端口,即myslq连接非常多。但问题来了,即便存在大量的TCP连接,它的数量也并没有超过1024个,而通过之前的设置,即已经配置/etc/security/limit.conf中的文件描述符打开数为65535个,那么为什么文件描述符打开数达到1024就已经报错呢

supervisor的限制

为了验证我的文件描述符限制修改是否生效,我使用ulimit -n命令查看当前文件描述符限制,的确是65535,与我配置的值一致,这就很奇怪了,1024远远没有达到65535,且这个数字明显就是默认的值,这说明我的配置没有对进程生效?显然Linux不可能有这样的BUG,我突然想到除了可以查看全局的ulimit之外,还可以查看进程本身的相关信息,而已经打开的进程会将信息存储在以PID号为命名的文件夹中,于是

cat /proc/<PID>/limits

进程信息

可以发现,进程的Max open files的软限制为1024,硬限制为4096,与全局设置并不一致,为什么会这样,我陷入了沉思。我突然想到,在开发环境进行测试的时候,并没有出现过这样的问题,而代码都是同一套,那么是不是启动方式有什么区别呢,在开发的时候,API是采用前台启动的,而正式环境则是使用supervisor,那么问题很明显了,一定是supervisor的某些设置限制了其管理的进程的文件描述符,经过查证,果然在supervisord.conf配置中有一行minfds,表示进程可以打开的文件数
supervisord.conf

那么只需要将其设置成65535,问题就可以解决,至此,真相大白

问题又出

本以为事情解决,可以告一段落了,可没想到没过多久,API又出现了不能访问的问情况,而这一次,日志中不再是文件描述符打开过多的错误了,而是出现了如下错误

sqlalchemy.exc.TimeoutError: QueuePool limit of size 500 overflow 100 reached, connection timed out, timeout 30

难道是数据连接池的大小设置的不够吗,我又将连接池的上限设置到了2000,因为我用的是flask-sqlalchemy,因此只需要将SQLALCHEMY_POOL_SIZE设置成2000即可。经过设置之后,暂时解决了问题,可过了一段时间之后,它居然又报出连接池超限的错误,而我们的API显然不可能真的有如此高的并发,肯定是有连接泄漏的问题存在,可我已经将SQLALCHEMY_COMMIT_ON_TEARDOWN设置为True,而该行配置表示在每次请求之后会自动断开连接

真相大白

经过查阅flask-sqlalchemy的更新日志,发现它在v2.0以上版本将配置SQLALCHEMY_COMMIT_ON_TEARDOWN给移除掉了,因此设置该值已经不再起作用,解决办法就是显式地在每一次请求结束后断开连接,于是我利用钩子去做

@app.teardown_request
def teardown_request(exception):
    """在每次结束请求前清理掉mysql连接"""
    if exception:
        db.session.rollback()
    db.session.remove()

结果仍然不行,随后我又仔细观察一下代码,发现定义模型的地方使用了sqlalchemy,而flask中却又是使用flask-sqlalchemy进行调用,因此我怀疑这个钩子中释放的连接是否跟模型中的sqlalchemy是同一个呢,经过调试打印两者的内存地址,果然,钩子每次释放的连接并不是模型的,至此,本次问题真正真相大白了,而解决办法也很简单,将flask-sqlalchemy替换成sqlalchemy即可,不要混用,代码如下

engine = create_engine(get_mysql_info(),
                       pool_size=webconfig.SQLALCHEMY_POOL_SIZE,
                       max_overflow=webconfig.SQLALCHEMY_MAX_OVERFLOW,
                       pool_recycle=webconfig.SQLALCHEMY_POOL_RECYCLE,
                       pool_timeout=webconfig.SQLALCHEMY_POOL_TIMEOUT,
                       pool_pre_ping=True,
                       convert_unicode=True)
db_session = scoped_session(sessionmaker(autocommit=False,
                                         autoflush=False,
                                         expire_on_commit=False,
                                         bind=engine))
Base.query = db_session.query_property()

使用db_session去替换所有使用到db.session的地方即可

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 213,711评论 6 493
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 91,079评论 3 387
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 159,194评论 0 349
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 57,089评论 1 286
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 66,197评论 6 385
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,306评论 1 292
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,338评论 3 412
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,119评论 0 269
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,541评论 1 306
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,846评论 2 328
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,014评论 1 341
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,694评论 4 337
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,322评论 3 318
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,026评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,257评论 1 267
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 46,863评论 2 365
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 43,895评论 2 351

推荐阅读更多精彩内容