如何在Python中正确记录错误/信息？

Question

我正在开发一个图形用户界面（GUI）程序，这个程序有一个主模块和四个不同的QThread模块。我希望能够正确记录未处理的异常和其他我指定的信息。因此，我决定使用Python自带的日志模块。

这是我配置的内容：

logging.basicConfig(filename="ubc.log", 
                    format='%(asctime)-6s: %(name)s - %(levelname)s - %(module)s - %(funcName)s - %(lineno)d - %(message)s', 
                    level=logging.DEBUG)

根据这个配置，我希望日志模块能告诉我错误或信息发生的具体行数、模块、函数等。但是，当我执行logging.info("text")时，日志中显示的是这样的内容：

2011-12-22 16:06:02,072: root - INFO - logging - info - 1592 - Calling load blog names function, tabWidget index is 0

不用说，这些信息对我来说大部分是没用的。行号肯定不是1592，函数名也不是info，模块更不是logging。

再说一遍，我想要的是这样的：当我执行logging.info("log this")时，我希望日志中能出现：

2011-12-22 16:06:02,072: root - INFO - WorkerThread1.py - upload_function(self, email, param) - line number 131 - log this

这样做可能吗？如果可以，应该怎么做呢？

编辑: 应要求，我添加了更多代码：

class UI(QMainWindow, ui_ui.Ui_MainWindow):

    def __init__(self, parent=None):
        super(BlogCreator, self).__init__(parent)
        self.setupUi(self)
        self.tabWidget.setCurrentIndex(0)

        logging.info("Prda!")

在GUI.py文件的第414行有logging.info("Prda!")。如你所见，这条信息应该在每次软件启动时都被记录（这是setupUi）。它确实被记录了，但写出来的内容是这样的：

2011-12-22 16:53:04,209: root - INFO - logging - info - 1592 - Prda!

编辑 #2 经过进一步检查，似乎是PyInstaller搞砸了事情。直接通过解释器运行软件能得到想要的结果；但当程序被编译成EXE文件后，就出现了上述情况。

Answer 1

也许你需要的是traceback模块：

import sys, traceback

try:
    my_function()
except Exception:
    exc_type, exc_value, exc_traceback = sys.exc_info()
    msg = u"\n".join(traceback.format_tb(exc_traceback))
    logging.error(msg)

Answer 2

我没有办法重现你遇到的问题。这个帖子里有一个非常简单的例子。请你试试看，告诉我们你是否能得到正确的结果：

myModule.py：

import logging
logging.basicConfig(filename="myLogFile.log", \
    format='%(asctime)-6s: %(name)s - %(levelname)s - %(module)s - %(funcName)s - %(lineno)d - %(message)s', \
    level=logging.DEBUG)

def myFct():
    logging.info("info at module.function level")

logging.info("info at module level")
myFct()

执行后，我的日志文件里包含：

2011-12-23 10:35:09,743: root - INFO - myModule - <module> - 11 - info at module level
2011-12-23 10:35:09,743: root - INFO - myModule - myFct - 9 - info at module.class.function level

Answer 3

你能发一个完整的代码片段吗？如果我按照你刚才说的做，我能得到一个正确的日志。我在这里发我的脚本（叫做 stackoverflow_8613924.py），方便对比：

import logging

logging.basicConfig(filename=None, format='%(asctime)-6s: %(name)s - %(levelname)s - %(module)s - %(funcName)s - %(lineno)d - %(message)s', level=logging.DEBUG)

def fname():
    logging.info('hello world')

fname()

运行它会给我：

$ python stackoverflow_8613924.py 
2011-12-23 09:05:35,678: root - INFO - stackoverflow_8613924 - fname - 6 - hello world