タイムスタンプの付いたカスタムロガー

Question

私はprintステートメントでプロジェクトに多くのコードを書いていて、これらのprintステートメントの素早い汚れたロガーを作ってカスタムルートを作ることに決めました。私はターミナルとファイルの両方に（このサイトの助けを借りて）プリントするロガーをまとめましたが、今はそれぞれのステートメントに単純なタイムスタンプを追加したいと思い、奇妙な問題にぶつかっています。

ここに私のロギングクラスがあります。

class Logger(object): 
    def __init__(self, stream): 
     self.terminal = stream 
     self.log = open("test.log", 'a') 

    def write(self, message): 
     self.terminal.flush() 
     self.terminal.write(self.stamp() + message) 
     self.log.write(self.stamp() + message) 

    def stamp(self): 
     d = datetime.today() 
     string = d.strftime("[%H:%M:%S] ") 
     return string 

私が書き込みメソッドで使用しようとしているスタンプ方法に注目してください。

私は予期しない出力を得る次の2行で実行：

sys.stdout = Logger(sys.stdout) 
print("Hello World!") 

を出力：

[11:10:47] Hello World![11:10:47] 

この出力はまたしかし、ログファイルに見えるもの、私はない理由を見ません追加している文字列が末尾に追加されます。誰かがここで私を助けることができる？

更新 以下の回答を参照してください。しかしながら、より速い参照のために、問題は一般に "print（）"を使用しています。変数を割り当てた後にsys.stdout.writeと置き換えてください。

バットから離れた長期的な/より大きなプロジェクトでは、 "ロギング"も使用してください。

Answer 1

ストリームの.write()メソッドを2度コールします。これは、cpythonでprintがストリーム.write()を2回呼び出すためです。最初はオブジェクトを使用し、2回目は改行文字を書き込みます。例えばline 138 in the pprint module in cpython v3.5.2

def pprint(self, object): 
    self._format(object, self._stream, 0, 0, {}, 0) 
    self._stream.write("\n") # <- write() called again! 

を見てあなたはこれを試すことができます。

>>> from my_logger import Logger # my_logger.py has your Logger class 
>>> import sys 
>>> sys.stdout = Logger(stream=sys.stdout) 
>>> sys.stdout.write('hi\n') 
[14:05:32] hi 

あなたはsedを使用してコード内のどこでもprint(<blah>)を置き換えることができます。

$ for mymodule in *.py; do 
> sed -i -E "s/print\((.+)\)/LOGGER.debug(\1)/" $mymodule 
> done 

チェックアウトPython's Logging builtin module。これは、すべてのメッセージ形式でタイムスタンプを含めるなど、かなり包括的なロギングを備えています。

import logging 
FORMAT = '%(asctime)-15s %(message)s' 
DATEFMT = '%Y-%m-%d %H:%M:%S' 
logging.basicConfig(format=FORMAT, datefmt=DATEFMT) 
logger = logging.getLogger(__name__) 
logger.setLevel(logging.DEBUG) 

logger.debug('message: %s', 'message') 

2016-07-29 11:44:20 message: messageからstdoutを出力します。ファイルに出力を送るハンドラもあります。 basic tutorial,advanced tutorialおよびcookbook of common logging recipesがあります。

料理の本にsimultaneous file and console loggersを使用した例があります。

import logging 

LOGGER = logging.getLogger(__name__) # get logger named for this module 
LOGGER.setLevel(logging.DEBUG) # set logger level to debug 

# create formatter 
LOG_DATEFMT = '%Y-%m-%d %H:%M:%S' 
LOG_FORMAT = ('\n[%(levelname)s/%(name)s:%(lineno)d] %(asctime)s ' + 
       '(%(processName)s/%(threadName)s)\n> %(message)s') 
FORMATTER = logging.Formatter(LOG_FORMAT, datefmt=LOG_DATEFMT) 

CH = logging.StreamHandler() # create console handler 
CH.setLevel(logging.DEBUG) # set handler level to debug 
CH.setFormatter(FORMATTER) # add formatter to ch 
LOGGER.addHandler(CH) # add console handler to logger 

FH = logging.FileHandler('myapp.log') # create file handler 
FH.setLevel(logging.DEBUG) # set handler level to debug 
FH.setFormatter(FORMATTER) # add formatter to fh 
LOGGER.addHandler(FH) # add file handler to logger 

LOGGER.debug('test: %s', 'hi') 

これは出力：

[DEBUG/__main__:22] 2016-07-29 12:20:45 (MainProcess/MainThread) 
> test: hi 

をコンソールと同時にファイルmyapp.logの両方に。

Answer 2

おそらく改行文字を使用する必要があります。

class Logger(object): 
    def __init__(self, stream): 
     self.terminal = stream 
     self.log = open("test.log", 'a') 

    def write(self, message): 
     self.terminal.flush() 
     self.terminal.write(self.stamp() + message + "\n") 
     self.log.write(self.stamp() + message + "\n") 

    def stamp(self): 
     d = datetime.today() 
     string = d.strftime("[%H:%M:%S] ") 
     return string 

とにかく、組み込みのロギングモジュールを使用する方が良いでしょう。