Множественные запросы Flask, Gunicorn, ведение журнала Nginx не работают

Я провожу тестирование производительности в своем приложении Flask.

  ngnix -> gunicorn -> flask

Лог-файлы:

  • access.log ОК
  • gunicorn.log ОК
  • api.log Только показан 1 запрос

Я использую инструмент для тестирования пресса. Мои запросы обрабатываются правильно и правильно регистрируются в файле журнала Flask в моей среде разработки (MacOS 10.10.5).

ab -c 10 -n 10 -A username:password https://1.1.1.1:8443/api/1.0/echo/

Когда я перехожу к производству (Ubuntu), я не вижу, чтобы все 10 запросов регистрировались в файле журнала Flask. Я вижу только 1 в файле журнала API. Инструмент ab сообщает, что все запросы обрабатываются правильно.

Я вижу 10 запросов в Ngnix, Gunicorn, но не во Flask.

Стартовый скрипт gunicorn (Supervisord)

GUNICORN_LOGFILE=/usr/local/src/imbue/application/imbue/log/gunicorn.log
NUM_WORKERS=8
TIMEOUT=60
WORKER_CONNECTIONS=2000
BACKLOG=1000
exec gunicorn api:api_app --bind 0.0.0.0:8081 --log-level=DEBUG --log-file=$GUNICORN_LOGFILE --workers $NUM_WORKERS --worker-connections=$WORKER_CONNECTIONS --backlog=$BACKLOG --timeout $TIMEOUT

файл api:

from application.app import api_app

if __name__ == "__main__":
    api_app.run(debug=False, threaded=True)

api_app приложение Flask

# =========================================================
# API Logs
# =========================================================

log = logging_conf.LoggerManager().getLogger("___app___", logging_file=settings.api_logfile)

# =========================================================
# Flask Application imports and database
# =========================================================
from flask import Flask
from flask.ext import restful
from werkzeug.contrib.fixers import ProxyFix

# =========================================================
# Flask Main Application
# =========================================================

api_app = Flask(__name__)  # Flask Application
api_app.config.from_pyfile("../../../conf/settings.py")  # Flask configuration

imbue_api = restful.Api(api_app)  # Define API
db = Model.db.init_app(api_app)  # Initialize database

# =========================================================
# API Definition
# =========================================================

imbue_api.add_resource(ApiBase, settings.BASE_API_URL)
imbue_api.add_resource(Echo, '/api/1.0/echo/')
# =========================================================
# API Proxy WSGi for gunicorn
# =========================================================

api_app.wsgi_app = ProxyFix(api_app.wsgi_app)
log.info('Initializing API >>>')

api_main

import logging

# =========================================================
# IMBUE imports
# =========================================================

from flask import current_app
from flask import jsonify, request, Response, url_for
from flask.ext import restful
from flask.ext.restful import Resource

# =========================================================
# API Controller
# =========================================================

api = restful.Api

# =========================================================
# API Logs
# =========================================================

log = logging_conf.LoggerManager().getLogger("___app___", logging_file=settings.api_logfile)

# =========================================================
# API Version information
# =========================================================

class Echo(Resource):
    @authenticator.requires_auth
    def get(self):
        """

        :return:
        """
        try:
            # =========================================================
            # GET API
            # =========================================================
            log.info(request.remote_addr + ' ' + request.__repr__())
            if request.headers['Content-Type'] == 'application/json':
                # =========================================================
                # Send API version information
                # =========================================================
                log.info('api() | GET | Version' + settings.api_version)
                response = json.dumps('version: ' + settings.api_version)
                resp = Response(response, status=200, mimetype='application/json')
                return resp

Версии

gunicorn==19.3.0
Flask==0.10.1
Flask-HTTPAuth==2.7.0
Flask-Limiter==0.9.3
Flask-Login==0.3.2
Flask-Mail==0.9.1
Flask-Migrate==1.6.0
Flask-OAuthlib==0.9.1
Flask-Principal==0.4.0
Flask-RateLimiter==0.2.0
Flask-RESTful==0.3.5
Flask-Restless==0.17.0
Flask-Script==2.0.5
Flask-Security==1.7.5
Flask-SQLAlchemy==2.1
Flask-WTF==0.12

logging_conf

class Singleton(type):
    """

    """
    _instances = {}

    def __call__(cls, *args, **kwargs):
        if cls not in cls._instances.keys():
            cls._instances[cls] = super(Singleton, cls).__call__(*args, **kwargs)
        return cls._instances[cls]


class LoggerManager(object):
    """

    """
    __metaclass__ = Singleton

    _loggers = {}

    def __init__(self, *args, **kwargs):
        pass

    @staticmethod
    def getLogger(name='___app___', logging_file='imbued.log', **kwargs):
        """

        :param name:
        :param logging_file:
        :param kwargs:
        :return:
        """
        # Define timezone
        logging.basicConfig(filename=logging_file,
                            filemode='w+',
                            level=logging.INFO,
                            format='%(asctime)s.%(msecs).03d %(levelname)s %(message)s',
                            datefmt='%m/%d/%Y %H:%M:%S')

        if not name:
            return logging.getLogger()
        elif name not in LoggerManager._loggers.keys():
            LoggerManager._loggers[name] = logging.getLogger(str(name))
        return LoggerManager._loggers[name]

person gogasca    schedule 18.05.2016    source источник
comment
куда идет logging_conf?   -  person Filipe Amaral    schedule 18.05.2016
comment
Только что обновил исходный вопрос   -  person gogasca    schedule 18.05.2016


Ответы (1)


Проблема возникает, когда вы объявляете переменную log. Несколько потоков gunicorn вызывают несколько экземпляров getLogger, а затем перезаписывают ваш файл журнала. Этого не происходит, когда вы используете сервер Werkzeug с threaded параметром app.run(threaded=True).

Если вам просто нужно регистрировать запросы, вы можете использовать параметр --access-logfile REQUEST_LOG_FILE в стартовом скрипте gunicorn.

GUNICORN_LOGFILE=/usr/local/src/imbue/application/imbue/log/gunicorn.log
NUM_WORKERS=8
TIMEOUT=60
WORKER_CONNECTIONS=2000
BACKLOG=1000
REQUEST_LOG_FILE=./request-log-file.log
exec gunicorn api:api_app --bind 0.0.0.0:8081 --log-level=DEBUG --log-file=$GUNICORN_LOGFILE --workers $NUM_WORKERS --worker-connections=$WORKER_CONNECTIONS --backlog=$BACKLOG --timeout $TIMEOUT --access-logfile REQUEST_LOG_FILE

Подробнее о входе в систему см. в документации.

Внимание! ВОЗМОЖНО НЕ БЕЗОПАСНО

В качестве простого обходного пути вы можете изменить метод basicConfig внутри getLogger, чтобы вместо перезаписи файла он добавлялся к существующему файлу. Это небезопасно, несколько потоков, изменяющих один и тот же файл, могут привести к неожиданным результатам.

logging.basicConfig(filename=logging_file,
                        filemode='w+', # Open, read and truncate the file.
                        level=logging.INFO,
                        format='%(asctime)s.%(msecs).03d %(levelname)s %(message)s',
                        datefmt='%m/%d/%Y %H:%M:%S')

to

logging.basicConfig(filename=logging_file,
                        filemode='a+', # Open, read and append to a file.
                        level=logging.INFO,
                        format='%(asctime)s.%(msecs).03d %(levelname)s %(message)s',
                        datefmt='%m/%d/%Y %H:%M:%S')

ИЗМЕНИТЬ 1

По-видимому, логирование является потокобезопасным, но я не уверен, будет ли это расширено для рабочих-стрелков...

person Filipe Amaral    schedule 18.05.2016