generar - python libreria logging

Flask app logger no funciona cuando se ejecuta dentro de gunicornio

Question

Intento guardar los mensajes de registro de la aplicación desde una aplicación de matraz muy simple en un archivo de registro. Si bien esto funciona sin problemas cuando ejecuto la aplicación con el servidor Flask incorporado, no funciona en absoluto cuando se ejecuta dentro de gUnicorn, básicamente, no se redirige ninguna salida de la aplicación ni al archivo de registro (el especificado en mi aplicación Flask) ni a el STDOUT cuando se ejecuta gunicornio.

Dicho eso, esta es mi aplicación Flask:

@app.route(''/'')
def index():
    app.logger.debug(''Into /!!!!'')
    print ''Will this print?''
    return ''Flask is running!''


if __name__ == ''__main__'':
    #Setup the logger
    file_handler = FileHandler(''test.log'')
    handler = logging.StreamHandler()
    file_handler.setLevel(logging.DEBUG)
    handler.setLevel(logging.DEBUG)
    file_handler.setFormatter(Formatter(
    ''%(asctime)s %(levelname)s: %(message)s ''
    ''[in %(pathname)s:%(lineno)d]''))
    handler.setFormatter(Formatter(
    ''%(asctime)s %(levelname)s: %(message)s ''
    ''[in %(pathname)s:%(lineno)d]''))
    app.logger.addHandler(handler)
    app.logger.addHandler(file_handler)
    app.run(debug=True)

Ahora si inicio la aplicación como:

python app.py

Obtengo el resultado esperado:

 * Running on http://127.0.0.1:5000/ (Press CTRL+C to quit)
 * Restarting with stat

--------------------------------------------------------------------------------
DEBUG in app [app.py:23]:
Into /!!!!
--------------------------------------------------------------------------------
2015-03-11 09:36:18,375 DEBUG: Into /!!!! [in app.py:23]
Will this print?
127.0.0.1 - - [11/Mar/2015 09:36:18] "GET / HTTP/1.1" 200 -

Tailing test.log, veo:

2015-03-11 09:36:18,375 DEBUG: Into /!!!! [in app.py:23]

Todo se ve muy bien hasta ahora, luego, cuando trato de ejecutar la aplicación con nginx + gunicorn, primero he intentado ejecutar gunicornio de esta manera:

gunicorn app:app -b localhost:8000 --debug --log-level debug

La aplicación está funcionando, si voy a http: // localhost :

curl http://localhost
Flask is running!

Pero mirando el archivo de registro, está vacío, no se escribe nada. Agregué 777 permisos solo para verificar si fue un problema de permiso en vano. Luego, mirando el stdout de gunicornio, no se escribe nada además de la declaración impresa:

2015-03-11 09:42:06 [25641] [DEBUG] GET /
Will this print?

Mirando a mi alrededor , traté de redirigir toda la producción a los registros de gunicornio, y luego comencé a disparar de esta manera:

gunicorn app:app -b localhost:8000 --debug --log-file /tmp/test.log --log-level debug --error-logfile /tmp/error.log

Pero ahora ni siquiera obtengo las declaraciones de impresión en los archivos de gunicorn, este es el resultado de test.log y error.log (son idénticos):

2015-03-11 09:46:17 [26257] [DEBUG]   tmp_upload_dir: None
2015-03-11 09:46:17 [26257] [DEBUG]   keyfile: None
2015-03-11 09:46:17 [26257] [DEBUG]   backlog: 2048
2015-03-11 09:46:17 [26257] [DEBUG]   logger_class: simple
2015-03-11 09:46:17 [26257] [INFO] Starting gunicorn 17.5
2015-03-11 09:46:17 [26257] [DEBUG] Arbiter booted
2015-03-11 09:46:17 [26257] [INFO] Listening at: http://127.0.0.1:8000 (26257)
2015-03-11 09:46:17 [26257] [INFO] Using worker: sync
2015-03-11 09:46:17 [26262] [INFO] Booting worker with pid: 26262
2015-03-11 09:48:15 [26262] [DEBUG] GET /

Hay una pregunta muy similar aquí , ¿una de las respuestas parece sugerir que no hay registrador de aplicaciones disponible cuando se ejecuta dentro de gunicornio? Esto suena, al menos, bastante extraño ... ¿cómo se supone que debo iniciar sesión entonces?

Otra solución propuesta parece sugerir no usar Flask Logger, pero no está relacionado con gunicornio (creo) ...

¿Qué me estoy perdiendo? ¿Debería renunciar a gunicornio y buscar Apache-mod wsgi? Nginx-uWSGI? FastCGI? ¿Algunas ideas?

¡Gracias! Alejandro

EDITAR:

He intentado esta misma configuración con uWGSI en lugar de gunicornio y el mismo comportamiento, no se obtiene ningún registro de aplicación.

Ahora, en base a esta respuesta y a esta otra , se me ocurrió esto (en gUnicorn y uWSGI, en ambos funciona)

from flask import Flask
import logging
from logging import Formatter, FileHandler

app = Flask(__name__)

LOGGER = logging.getLogger(''whatever'')
file_handler = FileHandler(''test.log'')
handler = logging.StreamHandler()
file_handler.setFormatter(Formatter(
    ''%(asctime)s %(levelname)s: %(message)s ''
    ''[in %(pathname)s:%(lineno)d]''
))
handler.setFormatter(Formatter(
    ''%(asctime)s %(levelname)s: %(message)s ''
    ''[in %(pathname)s:%(lineno)d]''
))
LOGGER.addHandler(file_handler)
LOGGER.addHandler(handler)
LOGGER.setLevel(logging.INFO)

@app.route(''/'')
def hello():
    LOGGER.info(''info log'')
    LOGGER.debug(''debug log'')
    return ''Hello!''

if __name__ == ''__main__'':
    app.run()

Salida de gunicornio:

2015-03-11 12:25:01 [11540] [INFO] Starting gunicorn 17.5
2015-03-11 12:25:01 [11540] [INFO] Listening at: http://127.0.0.1:8000 (11540)
2015-03-11 12:25:01 [11540] [INFO] Using worker: sync
2015-03-11 12:25:01 [11545] [INFO] Booting worker with pid: 11545
2015-03-11 12:26:20,765 INFO: info log [in /home/mosquito/www/flask-project/flask-project/app.py:24]

Y mirando mi archivo test.log:

2015-03-11 12:26:20,765 INFO: info log [in /home/mosquito/www/flask-project/flask-project/app.py:24]

Así que sí, funciona un poco, pero la pregunta original sigue siendo ... ¿Por qué diablos el registrador Flask no parece funcionar cuando se ejecuta dentro de contenedores wsgi - gunicornio, uSSGI?

Answer 1

Flask usa Werkzeug para WSGI. Los "registros de Flask" que ve son en realidad del servidor de desarrollo incorporado de Werkzeug y no del propio Flask.

Cuando reemplazas ese servidor de desarrollo con algo como Gunicorn o uWSGI, no ves sus registros.

Lo mismo aplica para el depurador. Puede ver la conocida "página de depuración de Flask" incluso si solo usa el Depurador de Werkzeug .

Ahora lo sabes. :)

Answer 2

Usted respondió su pregunta usted mismo aquí. Aunque agregaré mi respuesta con la esperanza de que ayude a alguien más a tener un problema similar.

Como tu pregunta tiene 2 partes, de las cuales se resuelve la primera parte, marca mi respuesta para cada parte:

PARTE 1: No se registra si en lugar de ejecutar directamente la aplicación a través de python, lo ejecuta bajo gunicorn Esto fue porque, cuando se ejecuta directamente, el nombre == '' main '' es True y el código inicializó un FileHandler y un StreamHandler, y la registración funcionó. Pero cuando se ejecuta a través de gunicorn, el nombre == '' main '' fallaría, ya que el nombre contendría el nombre de tu módulo. Esto significa que no se inicializarán manejadores efectivos . Y, por lo tanto, no se ve ningún registro.

PARTE 2: ¿Por qué el registrador Flask no funciona de manera predeterminada en gunicorn / uWSGI? Las últimas versiones de matraz inicializan la aplicación.logger desde cero y adjuntan algunos controladores como DebugHandler, StreamHandler de forma predeterminada, dependiendo de si app.debug == True. Aún así, el registrador no es suficiente y solo se registrará en STDERR. Ha habido varios cambios en gunicornio en las últimas versiones. La versión 19.4.1 no captura STDOUT y STDERR en gunicorn error.log. Pero pone a disposición registradores con los nombres ''gunicorn'', ''gunicorn.access'' y ''gunicorn.error''. El último tiene un FileHandler escribiendo en el error.log configurado. En caso de que desee que los registros de la aplicación del matraz vayan a error.log, utilice uno de los siguientes enfoques: Método 1:

#only use gunicorn.error logger for all logging
LOGGER = logging.getLogger(''gunicorn.error'')
LOGGER.info(''my info'')
LOGGER.debug(''debug message'')
# this would write the log messages to error.log

Enfoque2:

# Only use the FileHandler from gunicorn.error logger
gunicorn_error_handlers = logging.getLogger(''gunicorn.error'').handlers
app.logger.handlers.extend(gunicorn_error_handlers )
app.logger.addHandler(myhandler1)
app.logger.addHandler(myhandler2)
app.logger.info(''my info'')
app.logger.debug(''debug message'')

Te recomendará el enfoque 2, ya que puedes guardar los manejadores que desees además de gunicorn.error. Además, puede optar por no agregar controladores gunicorn.error en función de una condición.

Gracias

Answer 3

Con gunicorn 19.6, --capture-output --enable-stdio-inheritance parece funcionar.