[pyar] Logging en un proceso demonizado con DaemonRunner

[Aníbal Lovaglio]

Hola a todos,

Tengo una aplicación en la cual, algunas de las 
tareas están delegadas sobre un demonio, que construí usando 
DaemonRunner (http://pydoc.net/python-daemon/1.4.2/daemon.runner), y 
hasta ahora ha probado resolver mi problema bastante elegantemente. El 
problema con el que me encontré es a la hora de agregarle un mecanismo 
de log para poder darle seguimiento. Estuve investigando una librería 
estándar que es exactamente lo que estaba buscando del paquete logging.

Cuando
 pongo a correr el demonio, con las entradas de log dispuestas en el 
código, estoy obteniendo el siguiente error (una vez por cada invocación
 al log que se hace en el código).

Logged from file foo.py, line 48
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 870, in emit
    self.flush()
  File "/usr/lib/python2.7/logging/__init__.py", line 832, in flush
    self.stream.flush()
IOError: [Errno 9] Bad file descriptor

Por lo que leí, entiendo que se trata de un impedimento a la hora de 
acceder al archivo por parte del logger, y sospecho que tiene que ver 
con la demonización del proceso. Tengo entendido que el DaemonRunner, 
antes de poner a correr el proceso demonio, cierra "todos los archivos 
abiertos" por alguna cuestión sobre la que leí muchísimas veces, 
honestamente sin entender realmente. De todas formas, el síntoma 
concreto es este error. Dejo el código del controlador del demonio y el "administrador" de logger que escribí para uniformizar la configuración.

Desde ya cualquier ayuda es bienvenida. Muchas gracias!


daemon_control.py
[code]

#!/usr/bin/python
import time
from datetime import datetime
from daemon.runner import DaemonRunner

from seal import settings #your project settings file
from django.core.management import setup_environ #environment setup function
import argparse
from auto_correction.log.logger_manager import LoggerManager
setup_environ(settings)

from auto_correction.automatic_correction_runner import AutomaticCorrectionRunner

class LoopRunner():
    
    LOOP_INTERVAL = 65
    
    def __init__(self):
        self.loop_interval = LoopRunner.LOOP_INTERVAL # in seconds
        self.stdin_path = '/dev/null'
        self.stdout_path = '/dev/tty'
        self.stderr_path = '/dev/tty'
        self.pidfile_path =  '/tmp/foo.pid'
        self.pidfile_timeout = 5
        self.automatic_correction_runner = AutomaticCorrectionRunner()
        self.log = LoggerManager().getLogger()
    
    def stall_loop(self, start_timestamp, finish_timestamp):
        delta = finish_timestamp - start_timestamp
        time_to_wait = self.loop_interval - delta.seconds # if the process took less than 30 seconds, we will wait
        if (time_to_wait > 0):
            time.sleep(time_to_wait)
        else:
            print("not sleeping... delta: " + str(delta))
        start_timestamp = datetime.today()
    
    def print_result(self, result):
        # TODO: pass to a log entry
        print str(datetime.today()) + " | " + str(result)
    
    def run(self):
        self.log = LoggerManager().getLogger("daemon control")
        self.log.info("Daemon's game loop started.")
        while True:
            start_timestamp = datetime.today()
            
            result = self.automatic_correction_runner.run()
            self.log.info(str(result))
            
            finish_timestamp = datetime.today()
            self.stall_loop(start_timestamp, finish_timestamp)

parser = argparse.ArgumentParser(description='Starts or stops the seal daemon.')
parser.add_argument('command', metavar='start/stop', 
                    help='the command that should be executed on the daemon')
args = parser.parse_args()

logger_manager = LoggerManager()
log = logger_manager.getLogger()
log.info("Daemon action recived: '%s'", args.command)

loop_runner = LoopRunner()
daemon_runner = DaemonRunner(loop_runner) # runner.DaemonRunner(loop_runner)
daemon_runner.do_action()

if("start".__eq__(args.command.lower())):
    log.info("Daemon launched.")
else:
    log.info("Daemon stopped.")


[/code]



logger_manager.py
[code]

import logging

class LoggerManager:
    
    LOGGER = None
    
    # FIXME: This should be in a configuration file or otherwise not hardcoded
    logfile = "/tmp/seal-daemon.log"
    
    def getLogger(self, logname=None):
        if(LoggerManager.LOGGER is None):
            logging.basicConfig(filename=self.logfile, format='%(asctime)s - %(levelname)s: %(message)s', level=logging.DEBUG,
                                datefmt='%Y-%m-%d %H:%M:%S')
            LoggerManager.LOGGER = logging.getLogger()
        return LoggerManager.LOGGER


[/code]

Saludos!
Aníbal
------------ próxima parte ------------
Se ha borrado un adjunto en formato HTML...
URL: <http://listas.python.org.ar/pipermail/pyar/attachments/20130129/5af44938/attachment.html>