isotopic-logging 2.0.0

概要

isotopic-logging是一个小的 Python 库，旨在帮助您在整个执行流程中跟踪单独的操作及其部分。这是通过在日志消息的开头注入操作前缀来完成的。

这个库诞生于具有 Web 应用程序和后台任务队列的真实项目的深处，每个项目都可以有多个工作人员。这个库解决了两个关键点：

• 作为管理员，我希望在单个操作中使用相同前缀标记日志条目，以便即使日志是从多个线程或源写入的，我也可以区分和跟踪操作。

• 作为开发人员，我想在某些上下文中存储前缀，这样我就不需要在每次调用记录器时对其进行格式化，这样我就可以在嵌套函数调用中访问它，而无需直接将前缀传递给函数并搞砸它的语义。

当您有一个由并行源（线程或进程）填充的日志流时， isotopic-logging非常有用，并且您需要在一堆交织的日志消息中检测单个操作的流并区分不同的实例相同的操作。

该库也可用于单进程和单线程应用程序。您可能仍然需要检测操作并跟踪它们的执行时间，并且您可以做得很好。

快速输出示例

例如，单个复杂操作的日志可能如下所示：

INFO     [2015-12-15 21:45:04,339] D6EF95 | Heavy task has started.
DEBUG    [2015-12-15 21:46:36,148] D6EF95 | Checking user permissions.
INFO     [2015-12-15 21:46:36,654] D6EF95 | Analysis | Analysis phase has started.
DEBUG    [2015-12-15 21:46:41,756] D6EF95 | Analysis | Analysing current state of devices.
DEBUG    [2015-12-15 21:46:42,959] D6EF95 | Analysis | Analysing new state of devices.
DEBUG    [2015-12-15 21:46:47,565] D6EF95 | Analysis | Analysing changes.
INFO     [2015-12-15 21:46:51,871] D6EF95 | Analysis | Analysis phase has finished.
INFO     [2015-12-15 21:46:54,073] D6EF95 | Pushing data to central storage.
INFO     [2015-12-15 21:46:55,278] D6EF95 | Communication | Communication phase has started.
DEBUG    [2015-12-15 21:46:58,884] D6EF95 | Communication | Spreading out parallel subtasks for every involved device.
DEBUG    [2015-12-15 21:47:02,089] D6EF95 | Communication | 478272 | Connecting to device #3.
DEBUG    [2015-12-15 21:47:03,493] D6EF95 | Communication | 28B208 | Connecting to device #1.
INFO     [2015-12-15 21:47:04,798] D6EF95 | Communication | 28B208 | Running job at device #1.
DEBUG    [2015-12-15 21:47:10,501] D6EF95 | Communication | AE2677 | Connecting to device #2.
INFO     [2015-12-15 21:47:12,501] D6EF95 | Communication | AE2677 | Running job at device #2.
INFO     [2015-12-15 21:47:17,707] D6EF95 | Communication | 478272 | Running job at device #3.
INFO     [2015-12-15 21:47:21,709] D6EF95 | Communication | Communication phase has finished.
DEBUG    [2015-12-15 21:47:24,412] D6EF95 | Commiting changes.
INFO     [2015-12-15 21:47:27,013] D6EF95 | Heavy task has finished, elapsed time: 00:23:11.004120.

需要注意的重要事项：上面示例日志的每一行都可能由在不同线程或进程中运行的不同函数产生。他们不需要记住并将日志前缀从一个传递到另一个，这让您专注于开发过程并防止您因日志消息格式而分心。

安装

要安装该库，只需在Cheese Shop (PyPI) 获取它：

pip install isotopic-logging

关键概念

该库的工作基于几个关键概念：

• 前缀注入器：它们存储或/和生成前缀并将它们注入到字符串中。

• 注入上下文：它们管理注入器（获取或创建它们）并跟踪作用域执行时间。

• 注入范围：它们驱动注入器的创建和绑定操作执行时间。

• 记录器包装器：其他概念的高潮。包装记录器并提供创建注入上下文的方法。

这些概念可以单独使用，也可以以记录器包装器的形式作为一个整体组合使用。这种方法对于灵活的定制很有用。

前缀注入器

前缀注入器是存储或/和生成前缀属性访问的 前缀并使用mark()方法注入目标字符串的对象 。

默认注入器在isotopic_logging.injectors模块中定义，如下所述。

from isotopic_logging.injectors import DirectPrefixInjector

inj = DirectPrefixInjector("foo > ")
inj.mark("message")
# "foo > message"

from isotopic_logging.injectors import StaticPrefixInjector

inj = StaticPrefixInjector("foo")
inj.mark("message")
# "foo | message"

inj = StaticPrefixInjector("foo", delimiter=":")
inj.mark("message")
# "foo:message"

from isotopic_logging.injectors import AutoprefixInjector

inj1 = AutoprefixInjector()
inj1.mark("message")
# "C220A0 | message"

inj2 = AutoprefixInjector()
inj2.mark("message")
# "4118BB | message"

from itertools import cycle
from isotopic_logging.injectors import AutoprefixInjector

generator = cycle(["foo", "bar", ])

inj1 = AutoprefixInjector(generator)
inj1.mark("message")
# "foo | message"

inj2 = AutoprefixInjector(generator)
inj2.mark("message")
# "bar | message"

from isotopic_logging.concurrency import threadsafe_iter

def generate():
    i = 1
    while True:
        yield "gen-%d" % i
        i += 1

generator = threadsafe_iter(generate())

inj = AutoprefixInjector(delimiter=":")
inj.mark("message")
# "74D3B2:message"

from isotopic_logging.injectors import HybridPrefixInjector

inj1 = HybridPrefixInjector("static")
inj1.mark("message")
# "78E519 | static | message"

inj2 = HybridPrefixInjector("static")
inj2.mark("message")
# "EF8A74 | static | message"

from itertools import cycle
from isotopic_logging.injectors import HybridPrefixInjector

generator = cycle(["foo", "bar", ])

inj1 = HybridPrefixInjector("static", generator, delimiter=":")
inj1.mark("message")
# "foo:static:message"

inj2 = HybridPrefixInjector("static", generator, delimiter=":")
inj2.mark("message")
# "bar:static:message"

注入上下文

注入上下文用于范围管理。范围在下一节中描述。

上下文负责为您提供适当的注入器。注射器是按需创建的。一般来说，这可以描述为：

• “给我当前的喷油器或创建新的特定喷油器，如果没有当前的喷油器”

• 或“尽管有任何事情，但仍创建从当前注入器继承的新注入器”。

上下文将注入器组织成堆栈。堆栈是线程本地的，不会相互干扰。堆栈大小没有限制。这应该不是问题，因为注入器是惰性创建的。仅当堆栈为空或您明确想要继承当前前缀（通常是为了区分子操作）时才会发生这种情况。

当前注入器是当前线程中堆栈顶部的注入器。

注入上下文管理器在isotopic_logging.context模块中定义。每种类型的前缀注入器都有一个适当的上下文管理器。上下文管理器接受与它们将要生成的注入器相同的参数。

例子：

from isotopic_logging.context import direct_injector, static_injector
from isotopic_logging.context import auto_injector, hybrid_injector

with direct_injector("foo > ") as inj:
    inj.mark("message")
    # "foo > message"

with static_injector("foo") as inj:
    inj.mark("message")
    # "foo | message"

with auto_injector() as inj:
    inj.mark("message")
    # "25EBB8 | message"

with hybrid_injector("static") as inj:
    inj.mark("message")
    # "0F9A8F | static | message"

注入范围

范围由上下文创建，它们用于驱动注入器的创建。有两种作用域：顶级作用域和嵌套作用域。嵌套范围允许继承前缀。

让我们看一些例子来抓住这个想法。

from isotopic_logging.context import auto_injector, hybrid_injector

def helper():
    with auto_injector() as inj:
        print(inj.mark("call from helper"))

def operation():
    with hybrid_injector("operation") as inj:
        print(inj.mark("start"))
        helper()
        print(inj.mark("end"))

helper()
# ED5ED5 | call from helper
helper()
# 14F7CE | call from helper

operation()
# A15324 | operation | start
# A15324 | operation | call from helper
# A15324 | operation | end

from isotopic_logging.context import (
    auto_injector, static_injector, hybrid_injector,
)

def helper():
    with auto_injector() as inj:
        print(inj.mark("call from helper"))

def suboperation():
    with static_injector("suboperation", inherit=True) as inj:
        print(inj.mark("start"))
        helper()
        print(inj.mark("end"))

def operation():
    with hybrid_injector("operation") as inj:
        print(inj.mark("start"))
        suboperation()
        print(inj.mark("end"))

operation()
# 9F3A34 | operation | start
# 9F3A34 | operation | suboperation | start
# 9F3A34 | operation | suboperation | call from helper
# 9F3A34 | operation | suboperation | end
# 9F3A34 | operation | end

记录器包装器

isotopic_logging允许您包装您的记录器，以防止您在 每次将一些消息记录到日志时输入inj.mark() 。这节省了代码空间并使其更具可读性。

包装是通过isotopic_logging.IsotopicLogger记录器包装器完成的。它包装了记录器，这些记录器是logging.Logger及其子类的实例。

Wrapper 提供了使用预定义的前缀注入器创建记录器代理的方法：

• DirectPrefixInjector的direct()；

• 静态前缀注入器的静态（）；

• 用于AutoprefixInjector的auto()；

• Hybrid()用于HybridPrefixInjector。

这些方法接受与适当的注入上下文管理器相同的参数。他们返回上下文管理器以获取记录器代理。代理充当通常的记录器，它们使用特定前缀包装记录调用。

例子：

import logging

from isotopic_logging import IsotopicLogger

LOG = IsotopicLogger(logging.getLogger(__name__))

with LOG.auto() as log:
    log.debug("debug message")
    log.info("info message")
    log.warning("warning message")
    log.error("error message")
    log.critical("critical message")

# DEBUG    [2015-12-31 13:38:55,554] 4B9FB5 | debug message
# INFO     [2015-12-31 13:38:55,554] 4B9FB5 | info message
# WARNING  [2015-12-31 13:38:55,554] 4B9FB5 | warning message
# ERROR    [2015-12-31 13:38:55,554] 4B9FB5 | error message
# CRITICAL [2015-12-31 13:38:55,554] 4B9FB5 | critical message

在这里，LOG.auto()生成上下文，该上下文使用注入的自动前缀创建记录器代理。

时间跟踪

前缀注入器允许您跟踪范围内的执行时间。他们提供：

• elapsed_time属性，以秒为单位计算 elapsed_time；

• format_elapsed_time()方法，它可以接受自定义格式以将经过的时间输出为字符串。

例子：

import time
from isotopic_logging import auto_injector

with auto_injector() as inj:
    time.sleep(0.1)
    print(inj.elapsed_time)

# 0.105129003525

嵌套和继承范围有自己的内部时间跟踪：

with auto_injector() as inj1:
    time.sleep(0.1)

    with auto_injector() as inj2:
        time.sleep(0.1)
        print("inj2", inj2.elapsed_time)

    print("inj1", inj1.elapsed_time)

# ('inj2', 0.10514497756958008)
# ('inj1', 0.2101149559020996)

默认格式输出小时、分钟、秒和微秒：

with auto_injector() as inj:
    time.sleep(0.1)
    print(inj.format_elapsed_time())

# 00:00:00.105154

您可以使用与datetime.datetime.strftime()格式兼容的自定义格式 ：

format = "%H/%M/%S"

with auto_injector() as inj:
    time.sleep(5)
    print(inj.format_elapsed_time(format))

# 00/00/05

线程间前缀传输

有时您可能需要在线程或进程之间传递操作前缀。例如，您通过处理 HTTP 请求开始操作并在后台工作程序中继续它。

这可以通过使用注入器的前缀属性和 DirectPrefixInjector轻松实现：

def suboperation_in_another_thread_or_process(parent_prefix):
    with direct_injector(parent_prefix) as inj:
        print(inj.mark("foo"))

def operation():
    with auto_injector() as inj:
        print(inj.mark("foo"))
        suboperation_in_another_thread_or_process(inj.prefix)

operation()

# 3539DB | foo
# 3539DB | foo

变更日志

• 2.0.0（2015 年 12 月 31 日）

  • 功能：支持继承的前缀（问题 #1）。

  • 功能：将前缀注入到现有记录器的调用中的简单而干净的方法（问题 #4）。

  • 功能：获取上下文执行时间的能力（问题 #3）。

  • 优化：注入器的实例只有在定义了新的范围时才会被创建（问题#5）。

  • 改进：确保前缀和目标消息在连接期间转换为字符串。

  • 重命名：

    • prefix_injector到static_injector；

    • autoprefix_injector到auto_injector；

    旧名称被保留并且仍然可以使用。

  • 减少：从任何地方删除可选的容器参数。

• 1.0.1（2015 年 7 月 30 日）

  • 修复：对autoprefix_injector和hybrid_injector默认使用的default_oid_generator的线程支持（问题 #2）。

• 1.0.0（2015 年 5 月 3 日）

  初始版本