10

マルチプロセッシング サーバーでロギングを実装しようとしています。ドキュメントによると、「複数のプロセスから単一のファイルへのログ記録はサポートされていません」。このステートメントをチェックする小さなプログラムを作成しました。

import logging
import multiprocessing
import os

log = logging.getLogger()


def setup_logger():
    formatter = logging.Formatter('%(asctime)s %(name)s %(levelname)s: %(message)s')

    fileHandler = logging.FileHandler('test.log')
    fileHandler.setFormatter(formatter)

    log.setLevel(logging.DEBUG)
    log.addHandler(fileHandler)


def write_log_entries(identifier, start_event):
    start_event.wait()
    for i in range(100):
        s = ''.join(str(identifier) for k in range(30))
        log.info('[{}, {}] --- {}'.format(os.getpid(), identifier, s))


if __name__ == '__main__':
    setup_logger()
    procs = []
    start_event = multiprocessing.Event()
    for i in range(100, 300):
        p = multiprocessing.Process(target=write_log_entries, args=(i, start_event))
        procs.append(p)

    for p in procs:
        p.start()

    start_event.set()

    for p in procs:
        p.join()

上記のコードを実行した後、「test.log」に完全な混乱が見られると予想していましたが、すべて問題ないようです (もちろん、タイムスタンプは除きますが、これは順番どおりではありません)。

ログファイルが複数のプロセスによって同時に書き込まれているときに、ログエントリが重複しない理由を誰か説明できますか? この場合、log.info() はアトミックと見なすことができますか?

4

1 に答える 1

10

簡単な答え: カーネルは への 1 回の呼び出しをロックするwriteため、メッセージが小さい限り問題なく、1 回の でフラッシュされ、write一度writeにすべてを書き込むことに成功します。これが事実であるという一般的な保証はありません。そのため、ドキュメントはこれがまったく機能することを約束していません。

長い答え: を呼び出すたびにlog.info、ログ出力がフラッシュされます。これは必要です。そうしないと、ファイル内の最新のログ エントリを確認できなくなります。Python/libc レベルでは、flush は write(2) syscall への呼び出しとして実装されます。これは、ファイルのバッファーの内容を書き出すために呼び出されます (存在する場合)。あなたの場合、バッファの内容はログメッセージです。そのため、Python または libc は、使用されているファイルに応じて、次のような OS 呼び出しを呼び出します。

write(fd, buf, buflen);

...ここfdで、 はログ ファイルのシステム レベルのファイル記述子、bufは書き込みがバッファリングされたメモリ、buflenはメッセージの長さです。strace( Linuxなどのツールを使用して Python プロセスをトレースすると、これらの呼び出しを確認できます。)writeは、正常に書き込まれた文字数を返し、カーネルはそれらの文字をファイルの同じ領域内の他の書き込みとインターリーブしません。ファイルが O_APPEND モードで開かれている場合、少なくとも Unix では、書き込みがファイルの最後にあることが保証されます。したがって、buflen通常のログ メッセージの場合と同様に、 が小さければ、すべて問題ありません。しかし、少なくとも 2 つの問題が発生する可能性があります。

まず、 のすべてがbuflen単一の に書き出されるという保証はありませんwrite。write信号によって中断される可能性がありfd、固定サイズの書き込みを受け入れるデバイスを指す可能性があります。または、ログメッセージがカーネルが単一のチャンクで受け入れられないほど大きい可能性があります。通常、これは問題にはなりません。正しく記述されていれば、write常にループとして実装されます。しかし、あなたの場合、別の呼び出しが他のプロセスとインターリーブするため、これは惨事になりwrite ます。

第 2 に、ログ メッセージが stdio バッファー (8K 程度) に収まらないほど大きい場合、カーネルに到達する前にチャンクに分割されます。これは、トレースバックをログに記録するとき、またはログを XML のような冗長形式にフォーマットするときに簡単に発生する可能性があります。

于 2012-09-02T19:25:39.403 に答える