日志记录最佳实践
在本地开发环境中运行应用程序时,查看其运行情况的实际策略当然是连接调试器。您可以逐行执行代码,并检查每个变量。这很简单。但是,对于无法连接调试器的更高级别的环境(例如 QA、Staging 或 Production)该怎么办呢?我们如何深入了解应用程序在这些环境中的运行情况?答案只有一个:日志!
日志级别
日志不仅仅是用来捕获错误的。一个强大的日志记录策略会充分利用日志框架提供的所有不同日志级别。作为一名 .NET 开发人员,在我的职业生涯中,我使用过几种不同的日志框架,它们都提供相同的六个日志级别,但命名略有不同。为了保持一致性,我们将在本文中使用 Microsoft 日志级别的名称。
微软 | Serilog | 对数网络 | 描述 |
---|---|---|---|
批判的 | 致命的 | 致命的 | 描述无法恢复的应用程序或系统崩溃,或需要立即关注的灾难性故障的日志。 |
错误 | 错误 | 错误 | 突出显示当前执行流程因故障而停止的日志。这些日志应指示当前活动中的故障,而不是应用程序范围的故障。 |
警告 | 警告 | 警告 | 突出显示应用程序流程中的异常或意外事件的日志,但不会导致应用程序执行停止。 |
信息 | 信息 | 信息 | 跟踪应用程序总体流程的日志。这些日志应该具有长期价值。 |
调试 | 调试 | 调试 | 用于开发过程中交互式调查的日志。这些日志主要包含调试有用的信息,不具有长期价值。 |
痕迹 | 详细 | 全部 | 包含最详细消息的日志。这些消息可能包含敏感的应用程序数据。这些消息默认处于禁用状态,并且不应在生产环境中启用。 |
最佳实践
应用程序中唯一的日志记录通常Error
来自 try/catch 块内部。虽然这样做很好,但如果您只这样做,那么一旦应用程序离开本地开发环境,您对应用程序执行情况的了解将非常有限。请考虑根据下文所述的最佳实践,更好地利用其他日志级别。
通过外部配置设置当前日志级别
设置当前日志级别应始终是一项操作任务,切勿硬编码。外部配置允许操作员通过环境变量、配置文件等按需切换详细日志记录。
默认为信息日志级别
为您的应用程序选择全局默认日志级别(例如 inweb.config
或)通常是一个不错的选择。这意味着、和日志条目将被写入,而和日志条目将被抑制。因此,您可能希望为每个环境提供不同的默认日志级别(例如 in或);例如在开发环境和质量保证环境中。appsettings.json
Information
Critical
Error
Warning
Information
Debug
Trace
web.{env}.config
appsettings.{env}.json
Trace
Debug
使用关键日志级别记录灾难性故障
作为开发人员,我们通常很擅长记录常见的错误:捕获异常,记录错误消息,然后继续。但灾难性的故障就完全不同了。
在某些情况下,应用程序在启动过程中可能会遇到不可恢复的错误并抛出异常。您可以捕获该异常,使用Critical
日志级别(而不是)记录它Error
,然后干净地退出。在此流程中,日志条目应该从应用程序中退出,因为应用程序决定自行结束其生命周期,而不是在突发事故中死亡。
其他灾难性故障则不那么容易处理。可能是启动过程中抛出了超出您控制范围的异常,或者 Kubernetes 由于内存限制而决定从外部终止容器。在前一种情况下,任何可能写入的日志条目就像人们试图逃离着火的建筑物;有些人可能在建筑物倒塌之前逃生,而其他人则可能一无所获。在后一种情况下,应用程序本身并不知道故障的存在。前一毫秒它还健康地运行着,下一毫秒它的整个执行环境就被摧毁了。甚至没有机会尝试写入日志条目。请注意这些潜在情况,并在发生时与您的运营团队合作进行诊断。
明智地使用警告和信息日志级别
Critical
和Error
很容易适当使用(即当事情出轨时)但Warning
和Information
不是那么清晰。
Warning
应该保留用于非错误(它们不会妨碍执行)但并非完全正常行为的日志。例如,缓存未命中一个本应存在于缓存中的高开销对象、一段代码完成但耗时超过预期、登录尝试失败或访问控制违规。关键在于警告应该是可操作的。不应将不打算采取任何行动的警告塞满日志。仅当您计划在警告持续出现在日志中时采取措施时才使用它们。
Information
当应用程序正常运行,但您希望向操作员传达一些信息时,应该使用此选项。其中最常见的可能是应用程序生命周期事件,例如Application started
或Application stopped
。如果没有监控工具(例如 New Relic、AppDynamics 或 DataDog),则在日志级别记录应用程序事件可能比较合适Information
,但如果您有这些工具,则应该考虑将应用程序事件写入日志级别,而不是直接写入日志。
不要过于频繁地使用这两个日志级别,以免应用程序在运行正常时写入大量日志。健康的应用程序的日志应该基本保持静默;或许只有偶尔出现的Information
日志条目来确认应用程序仍在运行。
使用调试日志级别单步执行代码
当您的应用程序出现问题时,您当然希望能够更好地了解其运行情况。您的第一反应可能是尝试在本地开发环境中使用调试器重现错误,但这并不总是可行的。您可能对错误了解不够,无法在本地重现。它可能与特定环境的配置或数据有关。“它在我的机器上正常”,对吗?那么在这种情况下我们该怎么做呢?如果您Debug
在编写代码时充分利用了日志级别,那么只需简单更改配置,就可以从发生问题的环境中获取更详细的日志记录。
但是“良好地使用Debug
日志级别”是什么样的呢?要回答这个问题,让我们想想我们如何使用调试器。当您调试应用程序时,您可能做的第一件事就是在代码中策略性地放置一些断点,以查看哪些断点被命中、以什么顺序命中、命中了多少次等等。您通常会在发现错误后临时执行此操作,但如果您在开发过程中主动且有条不紊地执行此操作呢?您可以Debug
在每个可能使用调试器放置断点的地方记录一个条目。稍后,当您的应用程序在更高环境中行为异常时,您可以要求操作将日志级别切换到Debug
,查看日志条目,并在源代码中跟踪以查看您的应用程序在野外执行的操作。想象一下为未来的自己留下一张地图。
这些日志条目应该只是一些里程碑标记,以便您识别应用程序正在执行的代码行。不要在这些日志中放入任何数据,例如变量和参数的值。这些数据应该保留给Trace
日志级别使用。
使用跟踪日志级别检查变量
Trace
是最详细的日志级别,应仅在万不得已的情况下启用。当使用此Debug
日志级别单步执行代码不足以解决问题时,可以使用此Trace
选项将变量、参数和设置的值写入日志以供检查。这模拟了使用调试器检查变量内容的行为。此操作应仅在万不得已的情况下使用,原因有二:1) 如果您要求彻底检查,这将大幅增加应用程序生成的日志数据量,从而影响存储、成本和性能;2) 使用此日志级别写入的日志条目中可能包含敏感数据(下一节将详细介绍)。
切勿记录个人身份信息或秘密
永远不要——我是真的永远不要——将个人身份信息、凭证或其他机密信息写入任何日志级别(包括Trace
)。真的,千万不要这么做!
个人身份信息
关于 PII,将这些信息写入日志会使您在处理 GDPR、CCPA 以及未来可能出现的其他隐私法时更加困难。您肯定不希望因为日志保留期限超过了 GDPR 要求的 30 天期限而担心从日志中清除 PII。
您应避免记录的 PII 包括但不限于:
- 名
- 姓
- 用户名
- 性别
- 生日
- 邮寄/账单地址
- 电子邮件地址
- 电话号码
- 社会安全号码
- 信用卡号
秘密
说到机密信息,将这些信息写入日志是严重的安全隐患。在技术组织中,日志通常对广大受众公开,因此写入日志的任何内容都会被很多人看到。这意味着,如果日志中出现了任何不应公开的内容,系统管理员必须进行修改,以维护安全。
您应该避免记录的秘密包括但不限于:
- 用户名
- 密码
- API 密钥
- 加密密钥
- 连接字符串
- 魔法 URL
例子
public class Goku
{
private readonly ILogger _logger;
public Goku(ILogger<Goku> logger)
{
_logger = logger;
}
public int PowerUp(int desiredPower)
{
_logger.LogDebug($"BEGIN {MethodInfo.GetCurrentMethod()}");
_logger.LogTrace("desiredPower = {desiredPower}", desiredPower);
try
{
var power = 0;
var warned = false;
for (; power < desiredPower; power += 100)
{
_logger.LogDebug("Charging ...");
_logger.LogTrace("power = {power}", power);
_logger.LogTrace("warned = {warned}", warned);
if (power > 9000 && !warned)
{
_logger.LogWarning("It's over 9000!");
warned = true;
}
}
_logger.LogDebug("Power up complete.");
_logger.LogTrace("power = {power}", power);
}
catch(Exception ex)
{
_logger.LogError(ex, "Failed to complete power up.");
}
_logger.LogDebug($"END {MethodInfo.GetCurrentMethod()}");
return power;
}
}