遇到打开文件描述符消息时 Python 日志记录失败

Question

我有以下 Python 代码来在 Linux 计算机上创建 lvm 快照。

#!/usr/bin/env python3.1

import subprocess
import logging
logging.basicConfig(filename='/var/log/lvsnap.log', filemode='w', level=logging.DEBUG)

lvm_vg = 'vg00-crunchbang'
lvm_name = 'root'
lvm_snapshot_size = '100'

def lvmCreateSnapshot(lvm_vg, lvm_name, lvm_snapshot_size):
    return subprocess.check_call(['lvcreate', '-s', '-l', '+' + lvm_snapshot_size + '%FREE', '-n', lvm_name + '-snapshot', lvm_vg + '/' + lvm_name])

logging.debug('logging is working before lvm snapshot')

''' create lvm snapshot '''
lvm_create_snapshot = lvmCreateSnapshot(lvm_vg, lvm_name, lvm_snapshot_size)
if lvm_create_snapshot:
    logging.debug('create lvm snapshot of %s/%s exited with status %s', lvm_vg, lvm_name, lvm_create_snapshot)

logging.debug('logging is working after lvm snapshot')

lvmCreateSnapshot 运行正常并以 0 退出，然后应该运行 if 语句中的logging.debug 行。 然而，这并没有发生，而是我从脚本收到了以下输出：

> /tmp/lvmsnap.py 
File descriptor 3 (/var/log/lvsnap.log) leaked on lvcreate invocation. Parent PID 7860: python3.1
Logical volume "root-snapshot" created
>

日志的输出是：

> cat /var/log/lvsnap.log 
DEBUG:root:logging is working before lvm snapshot
DEBUG:root:logging is working after lvm snapshot
>

正如您所看到的，其中缺少 lvmlogging.debug 消息（它应该出现在我创建的 2 条测试日志记录消息之间） 。

为什么会发生这种情况以及如何解决它？

Answer 1

您没有调用“缺失”的 logging.debug，因为 lvmCreateSnapshot 返回零，因此永远不会满足您的 if 条件。尝试

if lvm_create_snapshot:
    logging.debug('Error creating lvm snapshot of %s/%s, exited with status %s', lvm_vg, lvm_name, lvm_create_snapshot)
else:
    logging.debug('created lvm snapshot of %s/%s, lvm_vg, lvm_name)

在成功调用 subprocess 时执行 else 并执行 if 条件，或者

if not lvm_create_snapshot:
    logging.debug('...debugging text...')

仅在以下情况下输出调试消息： code>subprocess 返回错误。

编辑：

我刚刚查看了 subprocess.check_call() 的文档，请参阅 http://docs.python.org/library/subprocess.html，其中指出如果子进程调用成功，则 subprocess.check_call 返回零，并引发 CalledProcessError< /代码> 异常 否则。因此，您必须使用通常的 try/ except 块捕获此异常。像下面这样的东西就足够了：

try:
    lvmCreateSnapshot(lvm_vg, lvm_name, lvm_snapshot_size)
    logging.debug('created lvm snapshot of %s/%s', lvm_vg, lvm_name)
except CalledProcessError as e:
    logging.debug('Error creating lvm snapshot of {0}/{1}. Return code was {2}'.format(lvm_vg,
        lvm_name, e.returncode))
    raise

最后的加注是为了打印回溯。您当然可以使用诸如 return 1 之类的东西来代替。