現(xiàn)象:
生產(chǎn)中心進(jìn)行拷機(jī)任務(wù)下了300個(gè)任務(wù),過了一陣時(shí)間后發(fā)現(xiàn)任務(wù)不再被調(diào)度起來,查看后臺(tái)日志發(fā)現(xiàn)日志輸出停在某個(gè)時(shí)間點(diǎn)。
分析:
1、首先確認(rèn)進(jìn)程存在并沒有dead。
2、然后用strace –p看了一下進(jìn)程,發(fā)現(xiàn)進(jìn)程卡在futex調(diào)用上面,應(yīng)該是在鎖操作上面出問題了。
3、用gdb attach進(jìn)程ID,用py-bt查看一下堆棧,發(fā)現(xiàn)堆棧的信息大致為:sig_handler(某個(gè)信號(hào)處理函數(shù))->auroralogger(自定義的日志函數(shù))->logging(python的logging模塊)->threading.acquire(獲取鎖)。從gdb的bt信息基本驗(yàn)證了上面的猜想,應(yīng)該是出現(xiàn)了死鎖。
4、Python的logging模塊本身肯定不會(huì)有死鎖的這種bug有可能出問題的就是我們的使用方式,看python中l(wèi)ogging模塊的doc,發(fā)現(xiàn)有一個(gè)有一個(gè)Thread Safety的章節(jié),內(nèi)容很簡單但是也一下就解釋了我遇到的這個(gè)問題,內(nèi)容如下:
The logging module is intended to be thread-safe without any special work needing to be done by its clients. It achieves this though using threading locks; there is one lock to serialize access to the module's shared data, and each handler also creates a lock to serialize access to its underlying I/O.
If you are implementing asynchronous signal handlers using the signal module, you may not be able to use logging from within such handlers. This is because lock implementations in the threading module are not always re-entrant, and so cannot be invoked from such signal handlers.
第一部分是說logging是線程安全的,通過threading的lock對公用的數(shù)據(jù)進(jìn)行了加鎖。
第二部分特意提到了在異步的信號(hào)處理函數(shù)中不能使用logging模塊,因?yàn)閠hreading的lock機(jī)制是不支持重入的。
這樣就解釋了上面我遇到的死鎖問題,因?yàn)槲以谛盘?hào)處理函數(shù)中調(diào)用了不可以重入的logging模塊。
線程安全和可重入:
從上面的logging模塊來看線程安全和可重入不是等價(jià)的,那么這兩個(gè)概念之間有什么聯(lián)系、區(qū)別呢?
1、可重入函數(shù):從字面意思來理解就是這個(gè)函數(shù)可以重復(fù)調(diào)用,函數(shù)被多個(gè)線程亂序執(zhí)行甚至交錯(cuò)執(zhí)行都能保證函數(shù)的輸出和函數(shù)單獨(dú)被執(zhí)行一次的輸出一致。也就是說函數(shù)的輸出只決定于輸入。
線程安全函數(shù):函數(shù)可以被多個(gè)線程調(diào)用,并且保證不會(huì)引用到錯(cuò)誤的或者臟的數(shù)據(jù)。線程安全的函數(shù)輸出不僅僅依賴于輸入還可能依賴于被調(diào)用時(shí)的順序。
2、可重入函數(shù)和線程安全函數(shù)之間有一個(gè)最大的差異是:是否是異步信號(hào)安全。可重入函數(shù)在異步信號(hào)處理函數(shù)中可以被安全調(diào)用,而線程安全函數(shù)不保證可以在異步信號(hào)處理函數(shù)中被安全調(diào)用。
上面我們遇到的loggin模塊就是非異步信號(hào)安全的,在主線程中我們正在使用log函數(shù)而log函數(shù)調(diào)用了threading.lock來獲取到了鎖,此時(shí)一個(gè)異步信號(hào)產(chǎn)生程序跳轉(zhuǎn)到信號(hào)處理函數(shù)中,信號(hào)處理函數(shù)又正好調(diào)用了log函數(shù),因?yàn)榍耙粋€(gè)被調(diào)用的log函數(shù)還未釋放鎖,最后就形成了一個(gè)死鎖。
1、可重入函數(shù)必然是線程安全函數(shù)和異步信號(hào)安全函數(shù),線程安全函數(shù)不一定是可重入函數(shù)。
總結(jié):
異步信號(hào)處理函數(shù)中一定要盡可能的功能簡單并且不能調(diào)用不可重入的函數(shù)。
Python loggin模塊是線程安全但是是不可重入的。
補(bǔ)充:Python—logging模塊使用教程
簡單用法
日志等級(jí)
級(jí)別 |
何時(shí)使用 |
DEBUG |
細(xì)節(jié)信息,僅當(dāng)診斷問題時(shí)適用。 |
INFO |
確認(rèn)程序按預(yù)期運(yùn)行 |
WARNING |
表明有已經(jīng)或即將發(fā)生的意外(例如:磁盤空間不足)。程序仍按預(yù)期進(jìn)行 |
ERROR |
由于嚴(yán)重的問題,程序的某些功能已經(jīng)不能正常執(zhí)行 |
CRITICAL |
嚴(yán)重的錯(cuò)誤,表明程序已不能繼續(xù)執(zhí)行 |
控制臺(tái)輸出日志
import logging
logging.warning('Watch out!')
logging.info('I told you so')
將日志保存到文件并且設(shè)置時(shí)間和輸出格式
import logging
# 保存文件為example.log,記錄等級(jí)為DEBUG,即只記錄DENBUG及以上的日志
# 輸出格式為 2019-19-06 18:47:06 - WARNING - And this, too
logging.basicConfig(
filename='example.log',
filemode='w',
level=logging.DEBUG,
format='%(asctime)s - %(levelname)s - %(message)s',
datefmt='%Y-%d-%d %H:%M:%S'
)
logging.debug('This message should go to the log file')
logging.info('So shoul this')
logging.warning('And this, too')
參數(shù)解釋
filename
日志文件路徑
filemode
記錄日志文件的模式,w為每次啟動(dòng)程序都創(chuàng)建一個(gè)全新的文件記錄, a表示追加到文件末尾, 默認(rèn)為a
level
記錄日志的等級(jí)
format
日志輸出的格式
datefmt
日志輸出時(shí)間的格式
使用配置文件配置日志
[loggers]
# 配置日志對象名, 默認(rèn)為root
keys=root, poj
[handlers]
# 日志配置名對象名
keys=writeFileHandlers
[formatters]
# 日志輸出格式對象名
keys=writeFileFormatters
[logger_root]
level=DEBUG
handlers=writeFileHandlers
[logger_poj]
level=DEBUG
handlers=writeFileHandlers
qualname=writeFileFormatters
propagate=0
[logger_leetcode]
level=DEBUG
handlers=writeFileHandlers
qualname=writeFileFormatters
propagate=0
[handler_writeFileHandlers]
# 設(shè)置writeFileHandlers對象的配置
class=FileHandler
level=DEBUG
formatter=writeFileFormatters
# 記錄在文件中,以追加的形式
args=("demo.log", "a")
[formatter_writeFileFormatters]
設(shè)置writeFileHandlers對象的輸出配置
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s
datefmt=%Y-%d-%m %H:%M:%S
使用配置文件
import logging.config
# 加載配置文件
logging.config.fileConfig('logging.conf')
# 獲取日志對象名為poj的
logger = logging.getLogger("poj")
logger.debug('This message should go to the log file')
logger.info('So shoul this')
logger.warning('And this, too')
以上為個(gè)人經(jīng)驗(yàn),希望能給大家一個(gè)參考,也希望大家多多支持腳本之家。如有錯(cuò)誤或未考慮完全的地方,望不吝賜教。
您可能感興趣的文章:- Python日志模塊logging簡介
- Python接口自動(dòng)化淺析logging封裝及實(shí)戰(zhàn)操作
- Python基礎(chǔ)之logging模塊知識(shí)總結(jié)
- Python的logging模塊基本用法
- Python logging簡介詳解