Umleiten der Ausgabe von Unterprozessen (stdout und stderr) an das Protokollierungsmodul

  • Ich arbeite an einem Python-Skript und suchte nach einer Methode, um stdout und stderr eines Unterprozesses an das Protokollierungsmodul umzuleiten. Der Unterprozess wird mit der Methode subprocess.call() erstellt.

    Die Schwierigkeit, der ich gegenüberstand, ist, dass ich mit Unterprozess stdout und stderr nur mit einem Dateideskriptor umleiten kann. Ich habe keine andere Methode gefunden, aber wenn es eine gibt, lass es mich wissen!

    Um dieses Problem zu lösen, habe ich den folgenden Code geschrieben, der im Grunde eine Pipe erstellt und einen Thread verwendet Aus der Pipe gelesen und eine Protokollnachricht mit der Python-Protokollierungsmethode generiert:

     import subprocess
    import logging
    import os
    import threading
    
    class LoggerWrapper(threading.Thread):
        """
        Read text message from a pipe and redirect them
        to a logger (see python's logger module),
        the object itself is able to supply a file
        descriptor to be used for writing
    
        fdWrite ==> fdRead ==> pipeReader
        """
    
        def __init__(self, logger, level):
            """
            Setup the object with a logger and a loglevel
            and start the thread
            """
    
            # Initialize the superclass
            threading.Thread.__init__(self)
    
            # Make the thread a Daemon Thread (program will exit when only daemon
            # threads are alive)
            self.daemon = True
    
            # Set the logger object where messages will be redirected
            self.logger = logger
    
            # Set the log level
            self.level = level
    
            # Create the pipe and store read and write file descriptors
            self.fdRead, self.fdWrite = os.pipe()
    
            # Create a file-like wrapper around the read file descriptor
            # of the pipe, this has been done to simplify read operations
            self.pipeReader = os.fdopen(self.fdRead)
    
            # Start the thread
            self.start()
        # end __init__
    
        def fileno(self):
            """
            Return the write file descriptor of the pipe
            """
            return self.fdWrite
        # end fileno
    
        def run(self):
            """
            This is the method executed by the thread, it
            simply read from the pipe (using a file-like
            wrapper) and write the text to log.
            NB the trailing newline character of the string
               read from the pipe is removed
            """
    
            # Endless loop, the method will exit this loop only
            # when the pipe is close that is when a call to
            # self.pipeReader.readline() returns an empty string
            while True:
    
                # Read a line of text from the pipe
                messageFromPipe = self.pipeReader.readline()
    
                # If the line read is empty the pipe has been
                # closed, do a cleanup and exit
                # WARNING: I don't know if this method is correct,
                #          further study needed
                if len(messageFromPipe) == 0:
                    self.pipeReader.close()
                    os.close(self.fdRead)
                    return
                # end if
    
                # Remove the trailing newline character frm the string
                # before sending it to the logger
                if messageFromPipe[-1] == os.linesep:
                    messageToLog = messageFromPipe[:-1]
                else:
                    messageToLog = messageFromPipe
                # end if
    
                # Send the text to the logger
                self._write(messageToLog)
            # end while
    
            print 'Redirection thread terminated'
    
        # end run
    
        def _write(self, message):
            """
            Utility method to send the message
            to the logger with the correct loglevel
            """
            self.logger.log(self.level, message)
        # end write
    
    # end class LoggerWrapper
    
    # # # # # # # # # # # # # #
    # Code to test the class  #
    # # # # # # # # # # # # # #
    logging.basicConfig(filename='command.log',level=logging.INFO)
    logWrap = LoggerWrapper( logging, logging.INFO)
    
    subprocess.call(['cat', 'file_full_of_text.txt'], stdout = logWrap, stderr = logWrap)
    
    print 'Script terminated'
     

    Zum Protokollieren der Ausgabe von Unterprozessen Google schlägt vor, die Ausgabe auf ähnliche Weise direkt in eine Datei umzuleiten:

     sobprocess.call( ['ls'] stdout = open( 'logfile.log', 'w') ) 
     

    Dies ist kein Option für mich, da ich die Formatierungs- und loglevel -Funktionen des Protokollierungsmoduls verwenden muss. Ich nehme außerdem an, dass das Öffnen einer Datei im Schreibmodus, aber zwei verschiedene Entitäten nicht zulässig ist / keine vernünftige Angelegenheit ist.

    Ich möchte jetzt Ihre Kommentare und einen Verbesserungsvorschlag sehen . Ich möchte auch wissen, ob es bereits ein ähnliches Objekt in der Python-Bibliothek gibt, da ich nichts gefunden habe, um diese Aufgabe auszuführen!

    19 August 2015
    Jamal
2 answers
  • Tolle Idee. Ich hatte das gleiche Problem und dieses half mir, es zu lösen. Ihre Methode für die Bereinigung ist jedoch falsch (wie Sie es bereits erwähnt haben). Grundsätzlich müssen Sie das Schreibende der Pipes schließen, nachdem Sie sie an den Unterprozess übergeben haben. Wenn der untergeordnete Prozess sein Ende der Pipes beendet und schließt, erhält der Protokollierungsthread auf diese Weise eine SIGPIPE und gibt wie erwartet eine Nachricht mit der Länge Null zurück.

    Andernfalls hält der Hauptprozess das Schreibende der Pipe für immer offen, wodurch readline auf unbestimmte Zeit blockiert wird, was dazu führt, dass Ihr Thread ebenso wie die Pipe für immer lebt . Dies wird nach einiger Zeit zu einem Hauptproblem, da Sie die Anzahl der geöffneten Dateideskriptoren erreicht haben.

    Außerdem sollte der Thread kein Daemon-Thread sein, da er erstellt wird das Risiko, Protokolldaten während des Herunterfahrens eines Prozesses zu verlieren. Wenn Sie wie beschrieben eine ordnungsgemäße Bereinigung durchführen, werden alle Threads ordnungsgemäß beendet, sodass sie nicht als Daemons markiert werden müssen.

    Schließlich kann die while -Schleife mit einer for Schleife.

    Die Implementierung all dieser Änderungen ergibt:

     import logging
    import threading
    import os
    import subprocess
    
    logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.INFO)
    
    class LogPipe(threading.Thread):
    
        def __init__(self, level):
            """Setup the object with a logger and a loglevel
            and start the thread
            """
            threading.Thread.__init__(self)
            self.daemon = False
            self.level = level
            self.fdRead, self.fdWrite = os.pipe()
            self.pipeReader = os.fdopen(self.fdRead)
            self.start()
    
        def fileno(self):
            """Return the write file descriptor of the pipe
            """
            return self.fdWrite
    
        def run(self):
            """Run the thread, logging everything.
            """
            for line in iter(self.pipeReader.readline, ''):
                logging.log(self.level, line.strip('\n'))
    
            self.pipeReader.close()
    
        def close(self):
            """Close the write end of the pipe.
            """
            os.close(self.fdWrite)
    
    # For testing
    if __name__ == "__main__":
        import sys
    
        logpipe = LogPipe(logging.INFO)
        with subprocess.Popen(['/bin/ls'], stdout=logpipe, stderr=logpipe) as s:
            logpipe.close()
    
        sys.exit()
     

    Ich habe an verschiedenen Stellen verschiedene Namen verwendet, aber ansonsten ist es die gleiche Idee, außer ein wenig sauberer und robuster.

    Einstellung close_fds=True für den Aufruf des Unterprozesses (welcher ist eigentlich die Standardeinstellung), da dies dazu führt, dass der Dateideskriptor vor dem Aufruf von exec im untergeordneten (untergeordneten) Prozess geschlossen wird. Der Dateideskriptor muss jedoch im übergeordneten Prozess (d. H. Vor der Gabelung) geschlossen werden.

    Die beiden Streams werden immer noch nicht richtig synchronisiert. Ich bin mir ziemlich sicher, dass wir zwei separate Threads verwenden. Ich denke, wenn wir nur einen Thread für die Protokollierung verwendet haben, wäre das Problem gelöst.

    Das Problem ist, dass es sich um zwei verschiedene Puffer (Pipes) handelt. Wenn Sie zwei Threads haben (jetzt erinnere ich mich), erhalten Sie eine ungefähre Synchronisierung, indem Sie die Daten schreiben

    29 October 2015
    Vineet Bhatia
  • Wenn Sie nichts dagegen haben, dass STDOUT und STDERR unter derselben Protokollierungsstufe protokolliert werden, können Sie Folgendes tun:

     import logging
    import subprocess
    
    logger = logging.getLogger(__name__)
    
    
    def execute(system_command, **kwargs):
        """Execute a system command, passing STDOUT and STDERR to logger.
    
        Source: https://stackoverflow.com/a/4417735/2063031
        """
        logger.info("system_command: '%s'", system_command)
        popen = subprocess.Popen(
            shlex.split(system_command),
            stdout=subprocess.PIPE,
            stderr=subprocess.STDOUT,
            universal_newlines=True,
            **kwargs)
        for stdout_line in iter(popen.stdout.readline, ""):
            logger.debug(stdout_line.strip())
        popen.stdout.close()
        return_code = popen.wait()
        if return_code:
            raise subprocess.CalledProcessError(return_code, system_command)
     

    Auf diese Weise müssen Sie sich nicht mit Threads herumschlagen.

    04 June 2018
    alpha_989ostrokach