如何在不注释掉Python日志调用的情况下去除它们？

Question

今天我想起了一年前写的一个Python项目，在其中我广泛使用了logging。我记得在内部循环场景（即90%的代码）中，由于开销大(hotshot指出它是我的最大瓶颈之一)，不得不注释掉许多日志调用。

现在我想知道，在Python应用程序中是否有某种规范的方法可以编程方式剥离日志调用，而不需要一直进行注释和取消注释。我认为可以使用检查/重新编译或字节码操作来执行此类操作，并且只针对导致瓶颈的代码对象进行操作。这样，您可以将操纵器作为后编译步骤添加，并使用集中式配置文件，如下所示：

[Leave ERROR and above]
my_module.SomeClass.method_with_lots_of_warn_calls

[Leave WARN and above]
my_module.SomeOtherClass.method_with_lots_of_info_calls

[Leave INFO and above]
my_module.SomeWeirdClass.method_with_lots_of_debug_calls

当然，你应该谨慎地使用它，可能只在已经显示出logging是瓶颈代码对象上使用。有人知道类似的东西吗？

注意：由于动态类型和延迟绑定等原因，这些操作更难以高效执行。例如，任何调用名为debug的方法都可能需要用if not isinstance(log，Logger)进行包装。无论如何，我假设所有次要细节都可以克服，或者通过绅士协议或一些运行时检查来解决。 :-)

- cdleary

---

你使用相同的根级别记录器吗？即logging.getLogger()？如果是这样，您需要先解决这个问题。如果不是，请提供这些模块中的一些getLogger调用。 - S.Lott

@S.Lott：我在每个模块上使用LOG = logging.getLogger(name)，然后调用LOG.debug(msg)等。但我真的不明白它与主题有什么关系。 - cdleary

Answer 1

怎么使用 logging.disable？

我还发现如果日志记录信息的生成成本很高，需要使用 logging.isEnabledFor。

- maccullt

---

事实证明，这正是Logger.debug的实现方式：http://svn.python.org/view/python/tags/r26/Lib/logging/__init__.py?view=markup - cdleary

实际上，进一步查看logging代码后，这可能就是我需要的优化。getEffectiveLevel会遍历日志记录器层次结构，而disable可以消除这种遍历。谢谢！ - cdleary

然而，问题在于记录器的参数仍然会被评估，这通常是记录器成本产生的地方。例如：logging.info("My msg %s", some_expensive_call())即使使用logging.disable，some_expensive_call仍将被调用和评估。 - Adam Parkin

如果使用if logger.isEnabledFor(<logging-level>):进行门控，那么日志记录语句中的参数不会被评估。@Adam Parkin - smci

你仍然需要使用if语句。我以为Python会在运行时内部通过检查不同记录器的日志级别并删除每个记录器下面的低于您的记录级别的语句来处理此问题。太糟糕了它没有这样做。 - radtek

Answer 2

使用pypreprocessor

该工具也可以在PYPI（Python Package Index）上找到，并可使用 pip 获取。

下面是一个基本用法示例：

from pypreprocessor import pypreprocessor

pypreprocessor.parse()

#define nologging

#ifdef nologging
...logging code you'd usually comment out manually...
#endif

基本上，预处理器以前您手动注释掉代码的方式。 它只是有条件地在运行时执行此操作，具体取决于您定义的内容。

您还可以通过在导入和parse（）语句之间添加“pypreprocessor.removeMeta = True”来从后处理代码中删除所有预处理指令和注释掉的代码。

字节码输出（.pyc）文件将包含优化的输出。

附注：pypreprocessor与python2x和python3k兼容。

免责声明：我是pypreprocessor的作者。

- Evan Plaice

---

我通常不是预处理器指令的忠实粉丝。在那种方法还没有任何其他Unix系统采用的时候，我曾经尝试过这种方法，但效果并不好。另一方面，作为外部模块添加该功能确实很棒。在某些情况下，它可能正是你所需要的。 - Jonathan Eunice

@Jonathan 我也不是，但有一些特殊情况下可以极大地减少维护工作。我最初创建它是为了能够在同一个文件中运行py2x和py3x代码（为多个版本并行开发），但是词法分析器会在预处理器之前使代码无效。对于这样的情况，它应该能够完美地工作。它基本上只是打开自己，读取代码，注释掉不必要的代码分支，并运行修改后的输出。相当hacky，但表现出奇效，尤其是您还可以将后处理的代码保存为文件。 - Evan Plaice

将我的代码放在#define nologging块中会导致出现NameError: global name 'logging' is not defined错误。 - radtek

Answer 3

我也看到过assert被这样使用。

assert logging.warn('disable me with the -O option') is None

我猜测警告函数始终返回None，如果不是这样，你将得到一个断言错误。

但实际上，这只是一个有趣的做法：

if __debug__: logging.warn('disable me with the -O option')

当你使用 -O 选项运行包含该行代码的脚本时，该行代码将从优化后的 .pyo 代码中删除。如果你有自己的变量，就像下面的例子一样，你会有一个条件语句总是会被执行（无论变量的值是什么），虽然条件语句应该比函数调用更快：

my_debug = True
...
if my_debug: logging.warn('disable me by setting my_debug = False')

如果我的理解是正确的话，调试(debug)似乎是一种不错的方法来消除不必要的日志调用。但相反的，它也会禁用所有断言(asserts)，所以如果你需要使用断言，这会成为一个问题。

- goodmami

---

是的，给每个调用前面都放一个断言太丑陋了。在每个东西前面加上 if my_debug 同样不可取和不优雅 -- 我希望有一些自动去除/修改它们的东西。 :-( 此外，始终使用 is None 来明确比较 None。 :-) - cdleary

Answer 4

作为一种不完美的捷径，你可以使用类似于MiniMock这样的东西来模拟特定模块中的logging。

例如，如果my_module.py是：

import logging
class C(object):
    def __init__(self, *args, **kw):
        logging.info("Instantiating")

你需要用以下代码替换你对 my_module 的使用：

from minimock import Mock
import my_module
my_module.logging = Mock('logging')
c = my_module.C()

“你只需要在导入模块之前执行一次这个操作。”

“通过模拟特定的方法或让logging.getLogger返回一个具有某些方法无效和其他方法委托给真正的logging模块的模拟对象，即可获得特定级别的行为。”

“实际上，你可能想用更简单、更快的东西替换MiniMock；至少要使用不会打印stdout的东西！当然，这并不能解决模块A从模块B中导入logging（因此A也导入了B的日志细粒度）的问题......”

“这永远不会像根本不运行日志语句那样快，但应该比深入logging模块的深处，只是发现这条记录不应该被记录，要快得多。”

- Alabaster Codify

---

这比字节码操纵听起来要合理得多，因为字节码操纵技术不一定能在虚拟机之间移植。我看到的唯一问题是，你只能通过堆栈跟踪检查找出哪个方法调用了你，如果我没有弄错的话，这也会很慢。 - cdleary

啊，好的...所以我认为模拟对象应该非常愚蠢，不关心（或不知道）它们从哪里被调用。您只能每个模块进行配置，而不是每个函数。选择注入模拟对象的模块是您唯一的灵活性，恐怕没有其他选择了。 - James Brady

Answer 5

您可以尝试这样做：

您可以尝试以下方法：

# Create something that accepts anything
class Fake(object):
    def __getattr__(self, key):
        return self
    def __call__(self, *args, **kwargs):
        return True

# Replace the logging module
import sys
sys.modules["logging"] = Fake()

它基本上用Fake的实例代替（或最初填充）日志模块的空间，该实例只需接受任何内容。在尝试使用日志模块之前，您必须运行上面的代码（仅一次！）。这是一个测试：

import logging

logging.basicConfig(level=logging.DEBUG,
                    format='%(asctime)s %(levelname)-8s %(message)s',
                    datefmt='%a, %d %b %Y %H:%M:%S',
                    filename='/temp/myapp.log',
                    filemode='w')
logging.debug('A debug message')
logging.info('Some information')
logging.warning('A shot across the bows')

以上操作未记录任何内容，这是可以预料的。

- Evan Fosmark

---

那么你没有办法按模块或级别选择性地打开或关闭日志记录吗？ - James Brady

Answer 6

:-) 我们曾经称之为预处理器，虽然 C 的预处理器具有某些功能，但 IBM 大型机 PL/I 的预处理器是“山上之王”。它在预处理器中提供了广泛的语言支持（完整的赋值、条件、循环等），并且可以仅使用 PL/I PP 编写“编写程序的程序”。

我编写了许多应用程序，其中包括完整的复杂程序和数据跟踪（当时我们没有适用于后端进程的良好调试器）用于开发和测试，然后，当与适当的“运行时标志”一起编译时，只需清除所有跟踪代码而不会影响性能。

我认为装饰器的想法很好。您可以编写一个装饰器来包装需要记录日志的函数。然后，在运行时分发时，将装饰器转换为“无操作”，从而消除调试语句。

Jon R

- Jon

Answer 7

这也是我的项目中的一个问题——日志记录几乎总是出现在分析器报告中。

我之前在 PyFlakes 的一个分支（http://github.com/kevinw/pyflakes）中使用过 _ast 模块……而且你在问题中所建议的去检查和注入日志方法调用前的保护是完全可行的（尽管你已经承认了必须进行一些运行时类型检查的限制）。请参见 http://pyside.blogspot.com/2008/03/ast-compilation-from-python.html 获取简单的示例。

编辑：我刚刚注意到了我的 planetpython.org 订阅源上的 MetaPython——其示例用例是在导入时删除日志记录语句。

也许最好的解决方案是有人重新实现日志记录作为一个 C 模块，但我不会是第一个做出这样的……机会 :p

- Kevin Watters

Answer 8

我会使用一些漂亮的日志装饰器，或者一堆这样的装饰器：

def doLogging(logTreshold):
    def logFunction(aFunc):
        def innerFunc(*args, **kwargs):
            if LOGLEVEL >= logTreshold:
                print ">>Called %s at %s"%(aFunc.__name__, time.strftime("%H:%M:%S"))
                print ">>Parameters: ", args, kwargs if kwargs else "" 
            try:
                return aFunc(*args, **kwargs)
            finally:
                print ">>%s took %s"%(aFunc.__name__, time.strftime("%H:%M:%S"))
        return innerFunc
    return logFunction

你只需要在每个模块中声明LOGLEVEL常量（或者全局声明并在所有模块中导入它），然后就可以像这样使用它：

@doLogging(2.5)
def myPreciousFunction(one, two, three=4):
    print "I'm doing some fancy computations :-)"
    return

如果 LOGLEVEL 不小于 2.5，则会得到如下输出：

>>Called myPreciousFunction at 18:49:13
>>Parameters:  (1, 2) 
I'm doing some fancy computations :-)
>>myPreciousFunction took 18:49:13

如您所见，需要一些工作来更好地处理kwargs，因此如果存在默认值，则会打印它们，但这是另一个问题。

您应该使用一些logger模块，而不是原始的print语句，但我想集中精力介绍装饰器的思想，并避免让代码太长。

无论如何 - 通过这样的装饰器，您可以获得函数级别的日志记录，任意多个日志级别，方便应用于新函数，要禁用日志记录，您只需要设置LOGLEVEL。如果您愿意，您可以为每个函数定义不同的输出流/文件。您可以将doLogging编写为：

 def doLogging(logThreshold, outStream=sys.stdout):
      .....
      print >>outStream, ">>Called %s at %s" etc.

并利用按函数定义的日志文件。

- Abgan

---

我使用logging模块从方法内部记录日志 - 你的方法只能记录外部可见的内容（args，kwargs，返回值和执行时间）。 - cdleary

你写到了如何在每个函数中使用日志记录，而且你的伪代码示例也暗示了这一点。我的方法可以扩展 - 你可以向你的函数添加额外的关键字参数。那个额外的参数将是一个由装饰器提供的日志记录器或虚拟对象 :-) - Abgan

不是一个理想的解决方案，我同意，但是装饰器是非常可扩展的，对吧？ - Abgan

我认为你忽略了一个重要的部分，就是日志调用是从函数内部进行的，而Logger.debug本身的调用导致了减速。你真的需要从方法内部剔除这些调用。 - cdleary

你可以使用装饰器来检查函数的代码并重写/重新编译它，但这基本上等同于字节码后处理器。现在想想，这实际上可能比后处理更好，所以指向一个好方向！ - cdleary

Answer 9

我目前正在进行一个项目，使用广泛的日志记录来测试逻辑和执行时间，用于使用Pandas库的数据分析API。我发现了这个字符串，其中有类似的担忧 - 即使将logging.basicConfig级别设置为level=logging.WARNING，logging.debug语句的开销是多少。我已经编写了以下脚本，在部署之前注释或取消注释调试日志记录：

import os
import fileinput

comment = True

# exclude files or directories matching string
fil_dir_exclude = ["__","_archive",".pyc"]

if comment :
    ## Variables to comment
    source_str = 'logging.debug'
    replace_str = '#logging.debug'
else :
    ## Variables to uncomment
    source_str = '#logging.debug'
    replace_str = 'logging.debug'

# walk through directories
for root, dirs, files in os.walk('root/directory') :
    # where files exist
    if files:
        # for each file
        for file_single in files :
            # build full file name
            file_name = os.path.join(root,file_single)
            # exclude files with matching string
            if not any(exclude_str in file_name for exclude_str in fil_dir_exclude) :
                # replace string in line
                for line in fileinput.input(file_name, inplace=True):
                    print "%s" % (line.replace(source_str, replace_str)),

这是一个文件递归，根据一系列标准排除文件，并基于此处找到的答案执行就地替换：在Python中搜索并替换文件中的一行。请注意，保留HTML标签。

- job

Answer 10

我喜欢“if __debug_”的解决方案，只是在每个调用前面加上它有点分散注意力和不美观。我曾经遇到过同样的问题，并通过编写一个脚本来自动解析源文件并将日志语句替换为pass语句（以及被注释掉的日志语句的副本）来克服这个问题。它还可以撤销此转换。

当我将新代码部署到生产环境时，如果有很多不需要在生产环境中使用的日志语句，并且它们影响性能，我会使用它。

你可以在这里找到该脚本：http://dound.com/2010/02/python-logging-performance/

- David Underhill