Comment dois-je me connecter lors de l'utilisation du multitraitement en Python?

239

À l'heure actuelle, j'ai un module central dans un cadre qui génère plusieurs processus à l'aide du multiprocessingmodule Python 2.6 . Parce qu'il utilise multiprocessing, il est au niveau du module journal multitraitement-conscient, LOG = multiprocessing.get_logger(). Selon la documentation , cet enregistreur a des verrous partagés de processus afin que vous ne perdiez pas les choses sys.stderr(ou quoi que ce soit) en ayant plusieurs processus écrivant simultanément.

Le problème que j'ai maintenant, c'est que les autres modules du cadre ne sont pas compatibles avec le multitraitement. D'après ce que je vois, je dois faire en sorte que toutes les dépendances de ce module central utilisent une journalisation prenant en charge le multitraitement. C'est ennuyeux dans le cadre, et encore moins pour tous les clients du cadre. Y a-t-il des alternatives auxquelles je ne pense pas?

cdleary
la source
10
Les documents auxquels vous vous connectez indiquent exactement le contraire de ce que vous dites, l'enregistreur n'a aucun processus de verrouillage partagé et les choses se mélangent - un problème que j'ai eu également.
Sebastian Blask
3
voir des exemples dans les documents stdlib: connexion à un seul fichier à partir de plusieurs processus . Les recettes ne nécessitent pas que d'autres modules soient compatibles avec le multitraitement.
jfs
Alors, à quoi sert le cas d'utilisation multiprocessing.get_logger()? Il semble que, sur la base de ces autres méthodes de journalisation, la fonctionnalité de journalisation ait multiprocessingpeu de valeur.
Tim Ludwinski
4
get_logger()est l'enregistreur utilisé par le multiprocessingmodule lui-même. C'est utile si vous souhaitez déboguer un multiprocessingproblème.
jfs

Réponses:

69

La seule façon de gérer ce problème de manière non intrusive est de:

  1. Générez chaque processus de travail de telle sorte que son journal soit transféré vers un descripteur de fichier différent (sur disque ou sur canal.) Idéalement, toutes les entrées de journal doivent être horodatées.
  2. Votre processus de contrôleur peut alors effectuer l' une des opérations suivantes:
    • Si vous utilisez des fichiers disque: fusionnez les fichiers journaux à la fin de l'exécution, triés par horodatage
    • Si vous utilisez des tuyaux (recommandé): fusionnez les entrées de journal à la volée à partir de tous les tuyaux, dans un fichier journal central. (Par exemple, périodiquement à selectpartir des descripteurs de fichiers des canaux, effectuez un tri par fusion sur les entrées de journal disponibles et effectuez un vidage dans le journal centralisé. Répétez.)
vladr
la source
Bien, c'était 35s avant d'y penser (j'ai pensé utiliser atexit:-). Le problème est qu'il ne vous donnera pas une lecture en temps réel. Cela peut faire partie du prix du multitraitement par opposition au multithreading.
cdleary
@cdleary, en utilisant l'approche canalisée, ce serait aussi proche du temps réel que possible (surtout si stderr n'est pas mis en mémoire tampon dans les processus générés.)
vladr
1
Soit dit en passant, grosse hypothèse ici: pas Windows. Êtes-vous sous Windows?
vladr
22
Pourquoi ne pas simplement utiliser un multiprocessing.Queue et un fil de journalisation dans le processus principal? Semble plus simple.
Brandon Rhodes
1
@BrandonRhodes - Comme je l'ai dit, sans intrusion . L'utilisation multiprocessing.Queuene sera pas plus simple s'il y a beaucoup de code à recâbler à utiliser multiprocessing.Queueet / ou si les performances sont un problème
vladr
122

Je viens d'écrire mon propre gestionnaire de journaux qui alimente tout simplement le processus parent via un canal. Je ne le teste que depuis dix minutes mais cela semble plutôt bien fonctionner.

( Remarque: ceci est codé en dur RotatingFileHandler, ce qui est mon propre cas d'utilisation.)


Mise à jour: @javier maintient maintenant cette approche comme un package disponible sur Pypi - voir multiprocessing-logging sur Pypi, github sur https://github.com/jruere/multiprocessing-logging


Mise à jour: mise en œuvre!

Cela utilise désormais une file d'attente pour une gestion correcte de la concurrence, et récupère également les erreurs correctement. Je l'utilise maintenant en production depuis plusieurs mois, et la version actuelle ci-dessous fonctionne sans problème.

from logging.handlers import RotatingFileHandler
import multiprocessing, threading, logging, sys, traceback

class MultiProcessingLog(logging.Handler):
    def __init__(self, name, mode, maxsize, rotate):
        logging.Handler.__init__(self)

        self._handler = RotatingFileHandler(name, mode, maxsize, rotate)
        self.queue = multiprocessing.Queue(-1)

        t = threading.Thread(target=self.receive)
        t.daemon = True
        t.start()

    def setFormatter(self, fmt):
        logging.Handler.setFormatter(self, fmt)
        self._handler.setFormatter(fmt)

    def receive(self):
        while True:
            try:
                record = self.queue.get()
                self._handler.emit(record)
            except (KeyboardInterrupt, SystemExit):
                raise
            except EOFError:
                break
            except:
                traceback.print_exc(file=sys.stderr)

    def send(self, s):
        self.queue.put_nowait(s)

    def _format_record(self, record):
        # ensure that exc_info and args
        # have been stringified.  Removes any chance of
        # unpickleable things inside and possibly reduces
        # message size sent over the pipe
        if record.args:
            record.msg = record.msg % record.args
            record.args = None
        if record.exc_info:
            dummy = self.format(record)
            record.exc_info = None

        return record

    def emit(self, record):
        try:
            s = self._format_record(record)
            self.send(s)
        except (KeyboardInterrupt, SystemExit):
            raise
        except:
            self.handleError(record)

    def close(self):
        self._handler.close()
        logging.Handler.close(self)
zzzeek
la source
4
Le gestionnaire ci-dessus effectue toute l'écriture de fichiers à partir du processus parent et utilise un seul thread pour recevoir les messages transmis par les processus enfants. Si vous appelez le gestionnaire lui-même à partir d'un processus enfant généré, cela ne l'utilise pas correctement et vous obtiendrez tous les mêmes problèmes que RotatingFileHandler. J'ai utilisé le code ci-dessus pendant des années sans problème.
zzzeek
9
Malheureusement, cette approche ne fonctionne pas sous Windows. De docs.python.org/library/multiprocessing.html 16.6.2.12 "Notez que sur Windows, les processus enfants n'hériteront que du niveau de l'enregistreur du processus parent - aucune autre personnalisation de l'enregistreur ne sera héritée." Les sous-processus n'hériteront pas du gestionnaire et vous ne pouvez pas le transmettre explicitement car il n'est pas picklable.
Noah Yetter
2
Il convient de noter qu'il multiprocessing.Queueutilise un thread pour entrer put(). N'invoquez donc pas put(c'est-à-dire enregistrez un msg à l'aide d'un MultiProcessingLoggestionnaire) avant de créer tous les sous-processus. Sinon, le thread sera mort dans le processus enfant. Une solution consiste à appeler Queue._after_fork()au début de chaque processus enfant, ou à utiliser à la multiprocessing.queues.SimpleQueueplace, ce qui n'implique pas de thread mais est bloquant.
Danqi Wang
5
Pourriez-vous ajouter un exemple simple qui montre l'initialisation, ainsi que l'utilisation d'un processus enfant hypothétique? Je ne sais pas exactement comment le processus enfant est censé accéder à la file d'attente sans instancier une autre instance de votre classe.
JesseBuesking
11
@zzzeek, ​​cette solution est bonne mais je n'ai pas pu trouver de package avec elle ou quelque chose de similaire, alors j'en ai créé un appelé multiprocessing-logging.
Javier
30

QueueHandlerest natif de Python 3.2+, et fait exactement cela. Il est facilement répliqué dans les versions précédentes.

Les documents Python ont deux exemples complets: Connexion à un seul fichier à partir de plusieurs processus

Pour ceux qui utilisent Python <3.2, copiez simplement QueueHandlerdans votre propre code à partir de: https://gist.github.com/vsajip/591589 ou importez également logutils .

Chaque processus (y compris le processus parent) place sa journalisation dans Queue, puis un listenerthread ou un processus (un exemple est fourni pour chacun) les récupère et les écrit tous dans un fichier - aucun risque de corruption ou de brouillage.

fantabolique
la source
21

Vous trouverez ci-dessous une autre solution axée sur la simplicité pour quiconque (comme moi) qui arrive ici de Google. L'enregistrement devrait être facile! Seulement pour 3.2 ou supérieur.

import multiprocessing
import logging
from logging.handlers import QueueHandler, QueueListener
import time
import random


def f(i):
    time.sleep(random.uniform(.01, .05))
    logging.info('function called with {} in worker thread.'.format(i))
    time.sleep(random.uniform(.01, .05))
    return i


def worker_init(q):
    # all records from worker processes go to qh and then into q
    qh = QueueHandler(q)
    logger = logging.getLogger()
    logger.setLevel(logging.DEBUG)
    logger.addHandler(qh)


def logger_init():
    q = multiprocessing.Queue()
    # this is the handler for all log records
    handler = logging.StreamHandler()
    handler.setFormatter(logging.Formatter("%(levelname)s: %(asctime)s - %(process)s - %(message)s"))

    # ql gets records from the queue and sends them to the handler
    ql = QueueListener(q, handler)
    ql.start()

    logger = logging.getLogger()
    logger.setLevel(logging.DEBUG)
    # add the handler to the logger so records from this process are handled
    logger.addHandler(handler)

    return ql, q


def main():
    q_listener, q = logger_init()

    logging.info('hello from main thread')
    pool = multiprocessing.Pool(4, worker_init, [q])
    for result in pool.map(f, range(10)):
        pass
    pool.close()
    pool.join()
    q_listener.stop()

if __name__ == '__main__':
    main()
user2133814
la source
2
Les classes QueueHandleret QueueListenerpeuvent également être utilisées sur Python 2.7, disponible dans le logutilspackage.
Lev Levitsky
5
L'enregistreur du processus principal doit également utiliser un QueueHandler. Dans votre code actuel, le processus principal contourne la file d'attente afin qu'il puisse y avoir des conditions de concurrence entre le processus principal et les travailleurs. Tout le monde doit se connecter à la file d'attente (via un QueueHandler) et seul le QueueListener doit être autorisé à se connecter au StreamHandler.
Ismael EL ATIFI
De plus, vous n'avez pas à initialiser l'enregistreur pour chaque enfant. Initialisez simplement l'enregistreur dans le processus parent et récupérez l'enregistreur dans chaque processus enfant.
okwap
20

Une autre alternative pourrait être les divers gestionnaires de journalisation non basés sur des fichiers dans le loggingpackage :

  • SocketHandler
  • DatagramHandler
  • SyslogHandler

(et d'autres)

De cette façon, vous pourriez facilement avoir un démon de journalisation quelque part dans lequel vous pourriez écrire en toute sécurité et gérer correctement les résultats. (Par exemple, un simple serveur de socket qui décompresse simplement le message et le transmet à son propre gestionnaire de fichiers rotatif.)

Ils s'en SyslogHandleroccuperaient également pour vous. Bien sûr, vous pouvez utiliser votre propre instance de syslog, pas celle du système.

Ali Afshar
la source
13

Une variante des autres qui maintient le thread de journalisation et de file d'attente séparé.

"""sample code for logging in subprocesses using multiprocessing

* Little handler magic - The main process uses loggers and handlers as normal.
* Only a simple handler is needed in the subprocess that feeds the queue.
* Original logger name from subprocess is preserved when logged in main
  process.
* As in the other implementations, a thread reads the queue and calls the
  handlers. Except in this implementation, the thread is defined outside of a
  handler, which makes the logger definitions simpler.
* Works with multiple handlers.  If the logger in the main process defines
  multiple handlers, they will all be fed records generated by the
  subprocesses loggers.

tested with Python 2.5 and 2.6 on Linux and Windows

"""

import os
import sys
import time
import traceback
import multiprocessing, threading, logging, sys

DEFAULT_LEVEL = logging.DEBUG

formatter = logging.Formatter("%(levelname)s: %(asctime)s - %(name)s - %(process)s - %(message)s")

class SubProcessLogHandler(logging.Handler):
    """handler used by subprocesses

    It simply puts items on a Queue for the main process to log.

    """

    def __init__(self, queue):
        logging.Handler.__init__(self)
        self.queue = queue

    def emit(self, record):
        self.queue.put(record)

class LogQueueReader(threading.Thread):
    """thread to write subprocesses log records to main process log

    This thread reads the records written by subprocesses and writes them to
    the handlers defined in the main process's handlers.

    """

    def __init__(self, queue):
        threading.Thread.__init__(self)
        self.queue = queue
        self.daemon = True

    def run(self):
        """read from the queue and write to the log handlers

        The logging documentation says logging is thread safe, so there
        shouldn't be contention between normal logging (from the main
        process) and this thread.

        Note that we're using the name of the original logger.

        """
        # Thanks Mike for the error checking code.
        while True:
            try:
                record = self.queue.get()
                # get the logger for this record
                logger = logging.getLogger(record.name)
                logger.callHandlers(record)
            except (KeyboardInterrupt, SystemExit):
                raise
            except EOFError:
                break
            except:
                traceback.print_exc(file=sys.stderr)

class LoggingProcess(multiprocessing.Process):

    def __init__(self, queue):
        multiprocessing.Process.__init__(self)
        self.queue = queue

    def _setupLogger(self):
        # create the logger to use.
        logger = logging.getLogger('test.subprocess')
        # The only handler desired is the SubProcessLogHandler.  If any others
        # exist, remove them. In this case, on Unix and Linux the StreamHandler
        # will be inherited.

        for handler in logger.handlers:
            # just a check for my sanity
            assert not isinstance(handler, SubProcessLogHandler)
            logger.removeHandler(handler)
        # add the handler
        handler = SubProcessLogHandler(self.queue)
        handler.setFormatter(formatter)
        logger.addHandler(handler)

        # On Windows, the level will not be inherited.  Also, we could just
        # set the level to log everything here and filter it in the main
        # process handlers.  For now, just set it from the global default.
        logger.setLevel(DEFAULT_LEVEL)
        self.logger = logger

    def run(self):
        self._setupLogger()
        logger = self.logger
        # and here goes the logging
        p = multiprocessing.current_process()
        logger.info('hello from process %s with pid %s' % (p.name, p.pid))


if __name__ == '__main__':
    # queue used by the subprocess loggers
    queue = multiprocessing.Queue()
    # Just a normal logger
    logger = logging.getLogger('test')
    handler = logging.StreamHandler()
    handler.setFormatter(formatter)
    logger.addHandler(handler)
    logger.setLevel(DEFAULT_LEVEL)
    logger.info('hello from the main process')
    # This thread will read from the subprocesses and write to the main log's
    # handlers.
    log_queue_reader = LogQueueReader(queue)
    log_queue_reader.start()
    # create the processes.
    for i in range(10):
        p = LoggingProcess(queue)
        p.start()
    # The way I read the multiprocessing warning about Queue, joining a
    # process before it has finished feeding the Queue can cause a deadlock.
    # Also, Queue.empty() is not realiable, so just make sure all processes
    # are finished.
    # active_children joins subprocesses when they're finished.
    while multiprocessing.active_children():
        time.sleep(.1)
ironhacker
la source
J'aime une idée de récupérer le nom de l'enregistreur à partir de l'enregistrement de file d'attente. Cela permet d'utiliser le conventionnel fileConfig()dans MainProcess et un enregistreur à peine configuré dans PoolWorkers (avec seulement setLevel(logging.NOTSET)). Comme je l'ai mentionné dans un autre commentaire, j'utilise Pool, j'ai donc dû obtenir ma file d'attente (proxy) auprès de Manager au lieu du multitraitement afin qu'elle puisse être décapée. Cela me permet de passer la file d'attente à un travailleur à l'intérieur d'un dictionnaire (dont la plupart est dérivée de l'objet argsparse utilisant vars()). J'ai l'impression qu'à la fin c'est la meilleure approche pour MS Windows qui manque de fork () et casse la solution @zzzeak.
mlt
@mlt Je pense que vous pouvez également mettre une file d'attente multiprocessing dans l'init au lieu d'utiliser un gestionnaire (voir la réponse à stackoverflow.com/questions/25557686/… - il s'agit de verrous mais je crois que cela fonctionne aussi pour les files d'attente)
fantastique
@fantabolous Cela ne fonctionnera pas sur MS Windows ou toute autre plate-forme qui manque fork. De cette façon, chaque processus aura sa propre file d'attente inutile indépendante. La deuxième approche dans le Q / A lié ne fonctionnera pas sur de telles plateformes. C'est un moyen de code non portable.
mlt
@mlt Intéressant. J'utilise Windows et cela semble fonctionner correctement pour moi - peu de temps après mon dernier commentaire, j'ai mis en place un pool de processus partageant un multiprocessing.Queueavec le processus principal et je l'utilise constamment depuis. Je ne prétends pas comprendre pourquoi cela fonctionne.
fantastique
10

Toutes les solutions actuelles sont trop couplées à la configuration de journalisation à l'aide d'un gestionnaire. Ma solution présente l'architecture et les fonctionnalités suivantes:

  • Vous pouvez utiliser tout configuration de journalisation que vous souhaitez
  • La journalisation se fait dans un thread démon
  • Arrêt sécurisé du démon à l'aide d'un gestionnaire de contexte
  • La communication avec le thread de journalisation se fait par multiprocessing.Queue
  • Dans les sous-processus logging.Logger(et les instances déjà définies) sont corrigés pour envoyer tous les enregistrements à la file d'attente
  • Nouveau : formater le retraçage et le message avant de les envoyer à la file d'attente pour éviter les erreurs de décapage

Le code avec l'exemple d'utilisation et la sortie peut être trouvé dans le Gist suivant: https://gist.github.com/schlamar/7003737

schlamar
la source
À moins que je me manque quelque chose, ce n'est pas en fait un fil démon, puisque vous ne définissez daemon_thread.daemonà True. J'avais besoin de le faire pour que mon programme Python se ferme correctement lorsqu'une exception se produit dans le gestionnaire de contexte.
blah238
J'ai aussi besoin de prises, des exceptions et des journaux Swallow lancées par la cible funcen logged_call, sinon l'exception obtiendrait brouillée avec une autre sortie registré. Voici ma version modifiée de ceci: gist.github.com/blah238/8ab79c4fe9cdb254f5c37abfc5dc85bf
blah238
8

Comme nous pouvons représenter la journalisation multiprocessus autant d'éditeurs et d'un abonné (auditeur), l'utilisation de ZeroMQ pour implémenter la messagerie PUB-SUB est en effet une option.

De plus, le module PyZMQ , les liaisons Python pour ZMQ, implémente PUBHandler , qui est un objet pour publier des messages de journalisation sur un socket zmq.PUB.

Il existe une solution sur le Web pour la journalisation centralisée à partir d'applications distribuées à l'aide de PyZMQ et PUBHandler, qui peut être facilement adoptée pour travailler localement avec plusieurs processus de publication.

formatters = {
    logging.DEBUG: logging.Formatter("[%(name)s] %(message)s"),
    logging.INFO: logging.Formatter("[%(name)s] %(message)s"),
    logging.WARN: logging.Formatter("[%(name)s] %(message)s"),
    logging.ERROR: logging.Formatter("[%(name)s] %(message)s"),
    logging.CRITICAL: logging.Formatter("[%(name)s] %(message)s")
}

# This one will be used by publishing processes
class PUBLogger:
    def __init__(self, host, port=config.PUBSUB_LOGGER_PORT):
        self._logger = logging.getLogger(__name__)
        self._logger.setLevel(logging.DEBUG)
        self.ctx = zmq.Context()
        self.pub = self.ctx.socket(zmq.PUB)
        self.pub.connect('tcp://{0}:{1}'.format(socket.gethostbyname(host), port))
        self._handler = PUBHandler(self.pub)
        self._handler.formatters = formatters
        self._logger.addHandler(self._handler)

    @property
    def logger(self):
        return self._logger

# This one will be used by listener process
class SUBLogger:
    def __init__(self, ip, output_dir="", port=config.PUBSUB_LOGGER_PORT):
        self.output_dir = output_dir
        self._logger = logging.getLogger()
        self._logger.setLevel(logging.DEBUG)

        self.ctx = zmq.Context()
        self._sub = self.ctx.socket(zmq.SUB)
        self._sub.bind('tcp://*:{1}'.format(ip, port))
        self._sub.setsockopt(zmq.SUBSCRIBE, "")

        handler = handlers.RotatingFileHandler(os.path.join(output_dir, "client_debug.log"), "w", 100 * 1024 * 1024, 10)
        handler.setLevel(logging.DEBUG)
        formatter = logging.Formatter("%(asctime)s;%(levelname)s - %(message)s")
        handler.setFormatter(formatter)
        self._logger.addHandler(handler)

  @property
  def sub(self):
      return self._sub

  @property
  def logger(self):
      return self._logger

#  And that's the way we actually run things:

# Listener process will forever listen on SUB socket for incoming messages
def run_sub_logger(ip, event):
    sub_logger = SUBLogger(ip)
    while not event.is_set():
        try:
            topic, message = sub_logger.sub.recv_multipart(flags=zmq.NOBLOCK)
            log_msg = getattr(logging, topic.lower())
            log_msg(message)
        except zmq.ZMQError as zmq_error:
            if zmq_error.errno == zmq.EAGAIN:
                pass


# Publisher processes loggers should be initialized as follows:

class Publisher:
    def __init__(self, stop_event, proc_id):
        self.stop_event = stop_event
        self.proc_id = proc_id
        self._logger = pub_logger.PUBLogger('127.0.0.1').logger

     def run(self):
         self._logger.info("{0} - Sending message".format(proc_id))

def run_worker(event, proc_id):
    worker = Publisher(event, proc_id)
    worker.run()

# Starting subscriber process so we won't loose publisher's messages
sub_logger_process = Process(target=run_sub_logger,
                                 args=('127.0.0.1'), stop_event,))
sub_logger_process.start()

#Starting publisher processes
for i in range(MAX_WORKERS_PER_CLIENT):
    processes.append(Process(target=run_worker,
                                 args=(stop_event, i,)))
for p in processes:
    p.start()
Samuel
la source
6

J'aime aussi la réponse de zzzeek, ​​mais André a raison de dire qu'une file d'attente est nécessaire pour éviter les déformations. J'ai eu de la chance avec la pipe, mais j'ai vu des gargarismes qui sont quelque peu attendus. L'implémenter s'est avéré plus difficile que je ne le pensais, en particulier en raison de l'exécution sous Windows, où il existe des restrictions supplémentaires sur les variables globales et autres (voir: Comment le multiprocessing Python est-il implémenté sous Windows? )

Mais je l'ai finalement fait fonctionner. Cet exemple n'est probablement pas parfait, donc les commentaires et suggestions sont les bienvenus. Il ne prend pas non plus en charge la définition du formateur ou autre chose que l'enregistreur racine. Fondamentalement, vous devez réactiver l'enregistreur dans chacun des processus de pool avec la file d'attente et configurer les autres attributs sur l'enregistreur.

Encore une fois, toutes les suggestions sur la façon d'améliorer le code sont les bienvenues. Je ne connais certainement pas encore toutes les astuces Python :-)

import multiprocessing, logging, sys, re, os, StringIO, threading, time, Queue

class MultiProcessingLogHandler(logging.Handler):
    def __init__(self, handler, queue, child=False):
        logging.Handler.__init__(self)

        self._handler = handler
        self.queue = queue

        # we only want one of the loggers to be pulling from the queue.
        # If there is a way to do this without needing to be passed this
        # information, that would be great!
        if child == False:
            self.shutdown = False
            self.polltime = 1
            t = threading.Thread(target=self.receive)
            t.daemon = True
            t.start()

    def setFormatter(self, fmt):
        logging.Handler.setFormatter(self, fmt)
        self._handler.setFormatter(fmt)

    def receive(self):
        #print "receive on"
        while (self.shutdown == False) or (self.queue.empty() == False):
            # so we block for a short period of time so that we can
            # check for the shutdown cases.
            try:
                record = self.queue.get(True, self.polltime)
                self._handler.emit(record)
            except Queue.Empty, e:
                pass

    def send(self, s):
        # send just puts it in the queue for the server to retrieve
        self.queue.put(s)

    def _format_record(self, record):
        ei = record.exc_info
        if ei:
            dummy = self.format(record) # just to get traceback text into record.exc_text
            record.exc_info = None  # to avoid Unpickleable error

        return record

    def emit(self, record):
        try:
            s = self._format_record(record)
            self.send(s)
        except (KeyboardInterrupt, SystemExit):
            raise
        except:
            self.handleError(record)

    def close(self):
        time.sleep(self.polltime+1) # give some time for messages to enter the queue.
        self.shutdown = True
        time.sleep(self.polltime+1) # give some time for the server to time out and see the shutdown

    def __del__(self):
        self.close() # hopefully this aids in orderly shutdown when things are going poorly.

def f(x):
    # just a logging command...
    logging.critical('function number: ' + str(x))
    # to make some calls take longer than others, so the output is "jumbled" as real MP programs are.
    time.sleep(x % 3)

def initPool(queue, level):
    """
    This causes the logging module to be initialized with the necessary info
    in pool threads to work correctly.
    """
    logging.getLogger('').addHandler(MultiProcessingLogHandler(logging.StreamHandler(), queue, child=True))
    logging.getLogger('').setLevel(level)

if __name__ == '__main__':
    stream = StringIO.StringIO()
    logQueue = multiprocessing.Queue(100)
    handler= MultiProcessingLogHandler(logging.StreamHandler(stream), logQueue)
    logging.getLogger('').addHandler(handler)
    logging.getLogger('').setLevel(logging.DEBUG)

    logging.debug('starting main')

    # when bulding the pool on a Windows machine we also have to init the logger in all the instances with the queue and the level of logging.
    pool = multiprocessing.Pool(processes=10, initializer=initPool, initargs=[logQueue, logging.getLogger('').getEffectiveLevel()] ) # start worker processes
    pool.map(f, range(0,50))
    pool.close()

    logging.debug('done')
    logging.shutdown()
    print "stream output is:"
    print stream.getvalue()
Mike Miller
la source
1
Je me demande si if 'MainProcess' == multiprocessing.current_process().name:peut être utilisé au lieu de passer child?
2013
Si quelqu'un d'autre essaie d'utiliser le pool de processus au lieu d'objets de processus séparés sous Windows, il convient de mentionner que Manager doit être utilisé pour transmettre la file d'attente aux sous-processus car il n'est pas directement picklable.
2013
Cette implémentation a bien fonctionné pour moi. Je l'ai modifié pour fonctionner avec un nombre arbitraire de gestionnaires. De cette façon, vous pouvez configurer votre gestionnaire racine de manière non multiprocesseur, puis là où il est sûr de créer la file d'attente, de passer les gestionnaires racine à cela, de les supprimer et d'en faire le seul gestionnaire.
Jaxor24
3

il suffit de publier quelque part votre instance de l'enregistreur. de cette façon, les autres modules et clients peuvent utiliser votre API pour obtenir l'enregistreur sans avoir à le faire import multiprocessing.

Javier
la source
1
Le problème est que les enregistreurs multiprocesseurs ne semblent pas nommés, vous ne pourrez donc pas déchiffrer facilement le flux de messages. Il serait peut-être possible de les nommer après leur création, ce qui les rendrait plus raisonnables à regarder.
cdleary
Eh bien, publiez un enregistreur pour chaque module, ou mieux, exportez différentes fermetures qui utilisent l'enregistreur avec le nom du module. le point est de laisser d'autres modules utiliser votre API
Javier
Certainement raisonnable (et +1 de moi!), Mais cela me manquerait de pouvoir import logging; logging.basicConfig(level=logging.DEBUG); logging.debug('spam!')de n'importe où et de le faire fonctionner correctement.
cdleary
3
C'est un phénomène intéressant que je vois lorsque j'utilise Python, que nous nous habituons tellement à pouvoir faire ce que nous voulons en 1 ou 2 lignes simples que l'approche simple et logique dans d'autres langues (par exemple, pour publier l'enregistreur ou le wrapper multitraitement) dans un accessoire) se sent toujours comme un fardeau. :)
Kylotan
3

J'ai aimé la réponse de zzzeek. Je remplacerais simplement le tuyau par une file d'attente, car si plusieurs threads / processus utilisent la même extrémité de tuyau pour générer des messages de journal, ils seront tronqués.

André Cruz
la source
J'avais des problèmes avec le gestionnaire, même si ce n'était pas que les messages étaient tronqués, c'est juste que le tout cesserait de fonctionner. J'ai changé Pipe pour être Queue car c'est plus approprié. Cependant, les erreurs que j'obtenais n'étaient pas résolues par cela - j'ai finalement ajouté un essai / sauf à la méthode receive () - très rarement, une tentative de journalisation des exceptions échouait et finissait par être interceptée. Une fois que j'ai ajouté le try / except, il s'exécute pendant des semaines sans problème et un fichier standarderr saisira environ deux exceptions errantes par semaine.
zzzeek
2

Que diriez-vous de déléguer toute la journalisation à un autre processus qui lit toutes les entrées de journal d'une file d'attente?

LOG_QUEUE = multiprocessing.JoinableQueue()

class CentralLogger(multiprocessing.Process):
    def __init__(self, queue):
        multiprocessing.Process.__init__(self)
        self.queue = queue
        self.log = logger.getLogger('some_config')
        self.log.info("Started Central Logging process")

    def run(self):
        while True:
            log_level, message = self.queue.get()
            if log_level is None:
                self.log.info("Shutting down Central Logging process")
                break
            else:
                self.log.log(log_level, message)

central_logger_process = CentralLogger(LOG_QUEUE)
central_logger_process.start()

Partagez simplement LOG_QUEUE via l'un des mécanismes multiprocessus ou même l'héritage et tout fonctionne bien!

Sawan
la source
1

J'ai une solution similaire à celle d'ironhacker, sauf que j'utilise logging.exception dans certains de mes codes et j'ai constaté que je devais formater l'exception avant de la renvoyer sur la file d'attente car les retraits ne sont pas picklables:

class QueueHandler(logging.Handler):
    def __init__(self, queue):
        logging.Handler.__init__(self)
        self.queue = queue
    def emit(self, record):
        if record.exc_info:
            # can't pass exc_info across processes so just format now
            record.exc_text = self.formatException(record.exc_info)
            record.exc_info = None
        self.queue.put(record)
    def formatException(self, ei):
        sio = cStringIO.StringIO()
        traceback.print_exception(ei[0], ei[1], ei[2], None, sio)
        s = sio.getvalue()
        sio.close()
        if s[-1] == "\n":
            s = s[:-1]
        return s
Richard Jones
la source
J'ai trouvé un exemple complet dans ce sens ici .
Aryeh Leib Taurog
1

Ci-dessous est une classe qui peut être utilisée dans un environnement Windows, nécessite ActivePython. Vous pouvez également hériter d'autres gestionnaires de journalisation (StreamHandler, etc.)

class SyncronizedFileHandler(logging.FileHandler):
    MUTEX_NAME = 'logging_mutex'

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

        self.mutex = win32event.CreateMutex(None , False , self.MUTEX_NAME)
        return super(SyncronizedFileHandler , self ).__init__(*args , **kwargs)

    def emit(self, *args , **kwargs):
        try:
            win32event.WaitForSingleObject(self.mutex , win32event.INFINITE)
            ret = super(SyncronizedFileHandler , self ).emit(*args , **kwargs)
        finally:
            win32event.ReleaseMutex(self.mutex)
        return ret

Et voici un exemple qui montre l'utilisation:

import logging
import random , time , os , sys , datetime
from string import letters
import win32api , win32event
from multiprocessing import Pool

def f(i):
    time.sleep(random.randint(0,10) * 0.1)
    ch = random.choice(letters)
    logging.info( ch * 30)


def init_logging():
    '''
    initilize the loggers
    '''
    formatter = logging.Formatter("%(levelname)s - %(process)d - %(asctime)s - %(filename)s - %(lineno)d - %(message)s")
    logger = logging.getLogger()
    logger.setLevel(logging.INFO)

    file_handler = SyncronizedFileHandler(sys.argv[1])
    file_handler.setLevel(logging.INFO)
    file_handler.setFormatter(formatter)
    logger.addHandler(file_handler)

#must be called in the parent and in every worker process
init_logging() 

if __name__ == '__main__':
    #multiprocessing stuff
    pool = Pool(processes=10)
    imap_result = pool.imap(f , range(30))
    for i , _ in enumerate(imap_result):
        pass
user6336812
la source
Utiliser probablement multiprocessing.Lock()au lieu de Windows Mutex rendrait la solution portable.
xmedeko
1

Voici mon hack / solution de contournement simple ... pas le plus complet, mais facilement modifiable et plus simple à lire et à comprendre, je pense que toutes les autres réponses que j'ai trouvées avant d'écrire ceci:

import logging
import multiprocessing

class FakeLogger(object):
    def __init__(self, q):
        self.q = q
    def info(self, item):
        self.q.put('INFO - {}'.format(item))
    def debug(self, item):
        self.q.put('DEBUG - {}'.format(item))
    def critical(self, item):
        self.q.put('CRITICAL - {}'.format(item))
    def warning(self, item):
        self.q.put('WARNING - {}'.format(item))

def some_other_func_that_gets_logger_and_logs(num):
    # notice the name get's discarded
    # of course you can easily add this to your FakeLogger class
    local_logger = logging.getLogger('local')
    local_logger.info('Hey I am logging this: {} and working on it to make this {}!'.format(num, num*2))
    local_logger.debug('hmm, something may need debugging here')
    return num*2

def func_to_parallelize(data_chunk):
    # unpack our args
    the_num, logger_q = data_chunk
    # since we're now in a new process, let's monkeypatch the logging module
    logging.getLogger = lambda name=None: FakeLogger(logger_q)
    # now do the actual work that happens to log stuff too
    new_num = some_other_func_that_gets_logger_and_logs(the_num)
    return (the_num, new_num)

if __name__ == '__main__':
    multiprocessing.freeze_support()
    m = multiprocessing.Manager()
    logger_q = m.Queue()
    # we have to pass our data to be parallel-processed
    # we also need to pass the Queue object so we can retrieve the logs
    parallelable_data = [(1, logger_q), (2, logger_q)]
    # set up a pool of processes so we can take advantage of multiple CPU cores
    pool_size = multiprocessing.cpu_count() * 2
    pool = multiprocessing.Pool(processes=pool_size, maxtasksperchild=4)
    worker_output = pool.map(func_to_parallelize, parallelable_data)
    pool.close() # no more tasks
    pool.join()  # wrap up current tasks
    # get the contents of our FakeLogger object
    while not logger_q.empty():
        print logger_q.get()
    print 'worker output contained: {}'.format(worker_output)
nmz787
la source
1

Il y a ce super package

Package: https://pypi.python.org/pypi/multiprocessing-logging/

code: https://github.com/jruere/multiprocessing-logging

Installer:

pip install multiprocessing-logging

Puis ajouter:

import multiprocessing_logging

# This enables logs inside process
multiprocessing_logging.install_mp_handler()
Juan Isaza
la source
3
Cette bibliothèque est littéralement basée sur un autre commentaire sur la publication SO actuelle: stackoverflow.com/a/894284/1698058 .
Chris Hunt
Origines: stackoverflow.com/a/894284/1663382 J'apprécie l'exemple d'utilisation du module, en plus de la documentation sur la page d'accueil.
Liquidgenius
0

L'une des alternatives est d'écrire la journalisation du multiprocessing dans un fichier connu et d'enregistrer un atexitgestionnaire pour se joindre à ces processus, relisez-le sur stderr; cependant, vous n'obtiendrez pas un flux en temps réel vers les messages de sortie sur stderr de cette façon.

cdleary
la source
est l'approche que vous proposez ci-dessous identique à celle de votre commentaire ici stackoverflow.com/questions/641420/…
iruvar
0

Si des blocages se produisent dans une combinaison de verrous, de threads et de fourches dans le loggingmodule, cela est signalé dans le rapport de bogue 6721 (voir également la question SO connexe ).

Il existe une petite solution de correction publiée ici .

Cependant, cela corrigera simplement tous les blocages potentiels logging. Cela ne réglera pas le fait que les choses sont peut-être confuses. Voir les autres réponses présentées ici.

Albert
la source
0

Idée la plus simple mentionnée:

  • Saisissez le nom de fichier et l'ID de processus du processus en cours.
  • Mettre en place a [WatchedFileHandler][1]. Les raisons de ce gestionnaire sont discutées en détail ici , mais en bref, il existe certaines conditions de concurrence plus mauvaises avec les autres gestionnaires de journalisation. Celui-ci a la fenêtre la plus courte pour la condition de course.
    • Choisissez un chemin pour enregistrer les journaux comme / var / log / ...
user1460675
la source
0

Pour ceux qui pourraient en avoir besoin, j'ai écrit un décorateur pour le package multiprocessing_logging qui ajoute le nom du processus actuel aux journaux, il devient donc clair qui enregistre quoi.

Il exécute également install_mp_handler (), il devient donc inutile de l'exécuter avant de créer un pool.

Cela me permet de voir quel travailleur crée quels messages de journaux.

Voici le plan avec un exemple:

import sys
import logging
from functools import wraps
import multiprocessing
import multiprocessing_logging

# Setup basic console logger as 'logger'
logger = logging.getLogger()
console_handler = logging.StreamHandler(sys.stdout)
console_handler.setFormatter(logging.Formatter(u'%(asctime)s :: %(levelname)s :: %(message)s'))
logger.setLevel(logging.DEBUG)
logger.addHandler(console_handler)


# Create a decorator for functions that are called via multiprocessing pools
def logs_mp_process_names(fn):
    class MultiProcessLogFilter(logging.Filter):
        def filter(self, record):
            try:
                process_name = multiprocessing.current_process().name
            except BaseException:
                process_name = __name__
            record.msg = f'{process_name} :: {record.msg}'
            return True

    multiprocessing_logging.install_mp_handler()
    f = MultiProcessLogFilter()

    # Wraps is needed here so apply / apply_async know the function name
    @wraps(fn)
    def wrapper(*args, **kwargs):
        logger.removeFilter(f)
        logger.addFilter(f)
        return fn(*args, **kwargs)

    return wrapper


# Create a test function and decorate it
@logs_mp_process_names
def test(argument):
    logger.info(f'test function called via: {argument}')


# You can also redefine undecored functions
def undecorated_function():
    logger.info('I am not decorated')


@logs_mp_process_names
def redecorated(*args, **kwargs):
    return undecorated_function(*args, **kwargs)


# Enjoy
if __name__ == '__main__':
    with multiprocessing.Pool() as mp_pool:
        # Also works with apply_async
        mp_pool.apply(test, ('mp pool',))
        mp_pool.apply(redecorated)
        logger.info('some main logs')
        test('main program')
Orsiris de Jong
la source
-5

À mes enfants qui rencontrent le même problème depuis des décennies et ont trouvé cette question sur ce site, je laisse cette réponse.

Simplicité vs complexité excessive. Utilisez simplement d'autres outils. Python est génial, mais il n'a pas été conçu pour faire certaines choses.

L'extrait suivant pour le démon logrotate fonctionne pour moi et ne complique pas les choses. Planifiez-le pour fonctionner toutes les heures et

/var/log/mylogfile.log {
    size 1
    copytruncate
    create
    rotate 10
    missingok
    postrotate
        timeext=`date -d '1 hour ago' "+%Y-%m-%d_%H"`
        mv /var/log/mylogfile.log.1 /var/log/mylogfile-$timeext.log
    endscript
}

Voici comment je l'installe (les liens symboliques ne fonctionnent pas pour logrotate):

sudo cp /directpath/config/logrotate/myconfigname /etc/logrotate.d/myconfigname
sudo cp /etc/cron.daily/logrotate /etc/cron.hourly/logrotate
baldr
la source