最近的任務(wù)經(jīng)常涉及到日志的記錄,特意去又學(xué)了一遍logging的記錄方法。跟java一樣,python的日志記錄也是比較繁瑣的一件事,在寫一條記錄之前,要寫好多東西。典型的日志記錄的步驟是這樣的:
寫成代碼差不多就是醬嬸的(這個是照別的網(wǎng)頁抄的,參考附注): 1 import logging 2 3 # 1、創(chuàng)建一個logger 4 logger = logging.getLogger('mylogger') 5 logger.setLevel(logging.DEBUG) 6 7 # 2、創(chuàng)建一個handler,用于寫入日志文件 8 fh = logging.FileHandler('test.log') 9 fh.setLevel(logging.DEBUG) 10 11 # 再創(chuàng)建一個handler,用于輸出到控制臺 12 ch = logging.StreamHandler() 13 ch.setLevel(logging.DEBUG) 14 15 # 3、定義handler的輸出格式(formatter) 16 formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') 17 18 # 4、給handler添加formatter 19 fh.setFormatter(formatter) 20 ch.setFormatter(formatter) 21 22 # 5、給logger添加handler 23 logger.addHandler(fh) 24 logger.addHandler(ch) 之后才可以正式的開始記錄日志。Java里面的java.util.Logging類差不多也是這樣,代碼還要更復(fù)雜一點。Golang的日志相對寫法簡單一些,不過沒有什么格式,系統(tǒng)記錄一條時間,內(nèi)容格式完全自己手畫。第三方的日志庫倒是沒有接觸過,像Java的Log4j,Golang的log4go和seelog等等,不知道用起來會不會簡單一點。我一直都記不住這些,因為不太理解logger和handler為什么要這樣寫。一直到這次任務(wù)中出現(xiàn)的在我看來相當(dāng)“詭異”的bug,才深入理解了一下。 我的任務(wù)是這樣的,要做一個日志切割的工具,按天將日志分割開,即每天0點產(chǎn)生一個新日志,將舊日志改名。并且,將超過3個月的日志刪除掉,以保證磁盤空間不會被log占滿。程序要求可以切割多個目錄中的不同日志,具體路徑由json中配置。 這里用到了logging.handlers類中的TimedRotatingFileHandler方法,用以獲得一個handler。大概的寫法為: 1 logger = logging.getLogger() #獲得logger 2 handler = logging.handlers.TimedRotatingFileHandler(logfile, 'S', 1, 0) #切割日志 3 handler.suffix = '%Y%m%d' #切割后的日志設(shè)置后綴 4 logger.addHandler(handler) #把logger添加上handler 5 logger.fatal(datetime.datetime.now().strftime('%Y-%m-%d')) #在新日志中寫上當(dāng)天的日期 這里我沒有設(shè)置level和formatter。因為只是分割,對新日志沒有什么影響。TimedRotatingFileHandler函數(shù)的方法見附注,或查看python的源碼,這個函數(shù)是python寫的,可以找到定義。這里我使用的是每秒生成一個新的日志文件,之后用Crontab在每天0點調(diào)度,然后用for循環(huán)處理json中的每一個日志文件。 但是奇怪的是,每次運(yùn)行程序,第一個切割的日志生成一個分割后的文件,而后面的都生成兩個新日志。百思不得其解。后檢查代碼覺得,可能是程序中設(shè)置的時間太短了,每秒生成一個文件,有可能一秒鐘處理不完,就生成了兩個。雖然這個說法沒有什么科學(xué)根據(jù),但是還是把TimedRotatingFileHandler中的第三個參數(shù)改成了60,即每60秒生成一個文件。完成,靜靜的等待crontab到時間。 叮!時間到。趕緊檢查一下結(jié)果。一個好消息和一個壞消息。好消息是這次每個日志都只切割生成了一個新文件,沒有生成兩個。壞消息是每個文件里面添加的當(dāng)天的日期的數(shù)量見鬼了。我切割了4條日志,生成的新日志里面就分別寫上了一、二、三、四行當(dāng)天日期。 此刻我的內(nèi)心幾乎是崩潰的。我開始思考為什么會這樣。很明顯四行日期是調(diào)用了4次logger.fatal('datetime.datetime.now().strftime('%Y-%m-%d')) 這個函數(shù)。換句話說,我每一次for循環(huán)都在這個log里面寫了一句話。可是明明每個for是處理一個日志,下一次for應(yīng)該是處理下一個日志的,為什么會再處理這個日志一次?我突然想到,logger.addHandler(handler)是每次循環(huán)都會運(yùn)行的,也就是說,logger是同一個logger,添加了4次handler。到第4次循環(huán)的時候,這個logger中有4個handler,也就會往4個不同的日志中添加內(nèi)容了。呃。 如果是這樣的話,那么把上面的程序改改,第一句和最后一句放在循環(huán)外,循環(huán)內(nèi)只用中間的三句。這次OK了?;仡^再看log記錄的步驟,也就明白了logger和handler到底是個什么鬼:logger可以看做是一個記錄日志的人,對于記錄的每個日志,他需要有一套規(guī)則,比如記錄的格式(formatter),等級(level)等等,這個規(guī)則就是handler。使用logger.addHandler(handler)添加多個規(guī)則,就可以讓一個logger記錄多個日志。至于logging.getLogger()方法獲得的root logger和繼承關(guān)系,可以詳見附注的網(wǎng)頁,這里我也只是大概明白了什么意思,還沒有具體用過。也許將來在框架中使用,要記錄較為復(fù)雜的日志時候會用到吧。
附:本篇博客中參考的幾個網(wǎng)頁:
|
|