因为现在大家都在做测试平台,论坛好多后端使用 django，flask 的测试平台，大部分情况下 Python 项目服务是使用 gunicorn[或者 uwsgi] 启动，自动化用例的执行难免会用到异步方案，可能想到 Celery，但 Celery 太重，偶尔的异步任务，可以使用 multiprocessing 或者是 concurrent 或者是协程就可以解决,但异步一不小心就会碰到各种坑,今天大家分享一个采坑。

  1. 需求背景

    前端用户输入相关参数后，异步为用户创建一个流水线.

  2. 问题描述

    本机运行 ok，但是在服务器上，不执行异步任务.

  3. 开发环境 + 技术栈

    开发环境: Mac + Pycharm
    服务器：CentOS(以下测试都是在阿里云的 CentOS7 下验证)
    技术栈：Python3.6.6 + Flask + Gunicorn + .....

  4. 定位问题

    因为在本地开发，所以直接 flask run 启动服务，出现问题后，首先定位到服务器上是使用 gunicorn 启的服务,本地换成 gunicorn 启动后测试，果然异步任务也是不执行。在异步方法前后打日志，一步一步的定位，就是卡死在异步任务那儿，既没有报错日志，也没有任何的异常抛出，好像启动的异步线程假死。唯一想到是 gunicorn 的原因，因为区别就是在这了，各种 google，也没找到答案。没办法，看了下 gunicorn 的源码和 gunicorn 源码的解析，找到了重要的线索。

先看下项目

目录结构

[root@devops application]# tree
.
├── flask_demo.py
├── gunicorn.conf.py

启动命令

# 服务器上是通过脚本内配置以下命令启动的，本地直接使用以下命令启动
gunicorn --preload -c gunicon.conf.py flask_demo:app

具体代码

# gunicorn.conf.py

bind = ":8000"
workers = 2
# threads = 2
max_requests = 50000
max_requests_jitter = 2
timeout = 70
graceful_timeout = 30
limit_request_line = 8190
limit_request_fields = 200
limit_request_fields_size = 8190

pidfile = "gunicorn.pid"
# user = "admin"
pythonpath = "/Users/admin/CODE/cmdb/"
accesslog = "gunicorn_access.log"
errorlog = "gunicorn_error.log"
loglevel = 'debug'
access_log_format = '%(h)s %(t)s %(l)s %(u)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s"'
daemon = False
# daemon = True
raw_env = "CONFIG_ENV=uat"
# raw_env = "FLASK_CONFIG=dev"
capture_output = True
work_class = "sync"


# flask_demo.py

import logging
from multiprocessing.pool import ThreadPool

from flask import Flask

logging.basicConfig(level=logging.INFO,
                    format="[%(asctime)s] 进程ID：%(process)d 线程ID：%(thread)d %(name)s %(levelname)s [%(module)s:%(lineno)s:%(funcName)s] %(message)s")
logger = logging.getLogger(__name__)

pool = ThreadPool(processes=1)  # 模式①

logger.info('in main thread')

# 需要异步执行的任务
def bar():
    '''
    这个异步任务可能是长耗时或对于时效性要求没那么高的业务场景.
    '''
    logger.info('async task run success')
    return 'task done'


app = Flask(__name__)


@app.route('/')
def hello():
    # pool = ThreadPool(processes=1)  # 模式②
    logger.info('start apply async')
    pool.apply_async(bar)
    logger.info('apply async done')

    return 'Hello, World!'

模式①执行失败 (在 master 进程中启线程)

《执行日志》- 注意最后两行日志
[2019-02-27 17:53:20,468] 进程ID：11323 线程ID：139846288471872 flask_demo INFO [flask_demo:13:<module>] in main thread
[2019-02-27 17:53:20 +0800] [11323] [INFO] Starting gunicorn 19.9.0
[2019-02-27 17:53:20 +0800] [11323] [DEBUG] Arbiter booted
[2019-02-27 17:53:20 +0800] [11323] [INFO] Listening at: http://0.0.0.0:8000 (11323)
[2019-02-27 17:53:20 +0800] [11323] [INFO] Using worker: sync
[2019-02-27 17:53:20 +0800] [11366] [INFO] Booting worker with pid: 11366
[2019-02-27 17:53:20 +0800] [11367] [INFO] Booting worker with pid: 11367
[2019-02-27 17:53:20 +0800] [11323] [DEBUG] 2 workers
[2019-02-27 17:53:40 +0800] [11367] [DEBUG] GET /
[2019-02-27 17:53:40,339] 进程ID：11367 线程ID：139846288471872 flask_demo INFO [flask_demo:26:hello] start apply async
[2019-02-27 17:53:40,340] 进程ID：11367 线程ID：139846288471872 flask_demo INFO [flask_demo:28:hello] apply async done



《请求前进程树-ps:不带{}代表进程，带{}代表线程》,可以看到确实是有启动线程
[root@devops application]# pstree -p 11323
gunicorn(11323)─┬─gunicorn(11366)
                ├─gunicorn(11367)
                ├─{gunicorn}(11362)
                ├─{gunicorn}(11363)
                ├─{gunicorn}(11364)
                └─{gunicorn}(11365)


《请求的结果也正常》             
[root@devops application]# http get http://47.101.49.169:8000/
HTTP/1.1 200 OK
Connection: close
Content-Length: 13
Content-Type: text/html; charset=utf-8
Date: Wed, 27 Feb 2019 09:53:40 GMT
Server: gunicorn/19.9.0

Hello, World!


《请求后的进程树》
[root@devops application]# pstree -p 11323
gunicorn(11323)─┬─gunicorn(11366)
                ├─gunicorn(11367)
                ├─{gunicorn}(11362)
                ├─{gunicorn}(11363)
                ├─{gunicorn}(11364)
                └─{gunicorn}(11365)

模式②执行成功 (在 worker 进程中启线程)

《执行日志》
[2019-02-27 18:04:31,513] 进程ID：11671 线程ID：139621494204224 flask_demo INFO [flask_demo:13:<module>] in main thread
[2019-02-27 18:04:31 +0800] [11671] [INFO] Starting gunicorn 19.9.0
[2019-02-27 18:04:31 +0800] [11671] [DEBUG] Arbiter booted
[2019-02-27 18:04:31 +0800] [11671] [INFO] Listening at: http://0.0.0.0:8000 (11671)
[2019-02-27 18:04:31 +0800] [11671] [INFO] Using worker: sync
[2019-02-27 18:04:31 +0800] [11710] [INFO] Booting worker with pid: 11710
[2019-02-27 18:04:31 +0800] [11711] [INFO] Booting worker with pid: 11711
[2019-02-27 18:04:31 +0800] [11671] [DEBUG] 2 workers
[2019-02-27 18:04:56 +0800] [11711] [DEBUG] GET /
[2019-02-27 18:04:56,860] 进程ID：11711 线程ID：139621494204224 flask_demo INFO [flask_demo:26:hello] start apply async
[2019-02-27 18:04:56,860] 进程ID：11711 线程ID：139621494204224 flask_demo INFO [flask_demo:28:hello] apply async done
[2019-02-27 18:04:56,861] 进程ID：11711 线程ID：139621255997184 flask_demo INFO [flask_demo:17:bar] async task run success


《请求前的进程树》
[root@devops application]# pstree -p 11671
gunicorn(11671)─┬─gunicorn(11710)
                └─gunicorn(11711)

《请求结果》
[root@devops application]# http get http://47.101.49.169:8000/
HTTP/1.1 200 OK
Connection: close
Content-Length: 13
Content-Type: text/html; charset=utf-8
Date: Wed, 27 Feb 2019 10:04:56 GMT
Server: gunicorn/19.9.0

Hello, World!

《请求后的进程树》
[root@devops application]# pstree -p 11671
gunicorn(11671)─┬─gunicorn(11710)
                └─gunicorn(11711)─┬─{gunicorn}(11795)
                                  ├─{gunicorn}(11796)
                                  ├─{gunicorn}(11797)
                                  └─{gunicorn}(11798)

重要：

看到区别了吗，在模式 2 的情况下，启动的新线程是放到了 worker 进程 (主进程：gunicorn(11671)→子进程：gunicorn(11711)) 下，执行成功。

模式 1 启动的新线程是放到了 master 进程 (主进程：gunicorn(11323)) 下,其实就是子进程内线程没办法和主进程下的线程进行通信，执行失败。

而 master 进程是不负责具体业务代码执行。因为 gunicorn 就是这么设计的，gunicorn的实现是由一个master进程管理多个worker进程，【所有的请求都是由worker进程处理】，master 进程主要向各 worker 进程发送信号，监控 worker 进程的运行状态，当 worker 进程退出后 (异常情况下)，自动重新启动新的 worker 进程. 简单来说就是 worker 才负责具体代码执行。

总结

解决这个 bug 现在看很简单，就是把 pool = ThreadPool(processes=1) 放到 request 内。但当时解决起来花费很久的时间，不像我们平时的 debug，看错误堆栈就可以了, 因为没有任何的异常信息抛出。

‘这个 bug 解决的方案还有很多中，大家有时间的话可以去尝试下。’

另外说下自身情况，之前在测试行业，一直关注 TesterHome，已经转到后端研发，在做 DevOps 相关的实践，有兴趣可以一起交流, 谢谢大家！

PS:后续可能还会转回到测试,O(∩_∩) O 哈哈~

gunicorn 启动步骤：

（1）加载 worker_class 并实例化（默认为同步模型 SyncWorker）
（2）父进程（master 进程）fork 之后 return，之后的逻辑都在子进程中运行
（3）调用 worker.init_process 进入循环，worker 的所有工作都在这个循环中
（4）循环结束之后，调用 sys.exit(0)
（5）最后，在 finally 中，记录 worker 进程的退出

gunicorn 概念

Gunicorn“绿色独角兽” 是一个被广泛使用的高性能的 Python WSGI UNIX HTTP 服务器，移植自 Ruby 的独角兽（Unicorn ）项目,使用 pre-fork worker 模式，具有使用非常简单，轻量级的资源消耗，以及高性能等特点。

参考：

gunicorn Arbiter 源码解析

gunicorn 源码分析

Gunicorn 运行与配置

有机会和大家分享下，关于 gunicorn 的的 work_class_type 配置不同的使用场景。


↙↙↙阅读原文可查看相关链接，并与作者交流