每个请求的单独日志记录级别

在阅读ThoughtWorks Technology Radar时 ,我偶然发现了“ 每个请求单独记录 ”技术。 我们在Confirmit广泛使用日志记录,我想知道如何实现此功能。

问题描述


让我们看看有什么危险。 假设我们有一个Web服务。 在某个时候,它开始在生产服务器上崩溃,但仅针对某些请求。 例如,崩溃仅针对特定用户发生。 或仅在单独的访问点上...我们需要找到原因。 在这种情况下,日志记录对我们有帮助。

我们可以在代码中插入足够的日志记录指令,以了解问题的原因。 这些说明通常将您的消息与特定的日志级别相匹配(调试,信息,警告等)。 另外,日志本身也具有自己的级别。 级别高于日志级别的所有消息都将记录在日志存储中(文件,数据库等)。 如果消息级别低于日志级别,则将仅丢弃该消息。

当我们的应用程序运行正常时,我们希望看到尽可能少的日志条目,以便其大小保持较小。 同时,如果应用程序崩溃,我们希望日志具有足够的条目,以便我们能够了解问题的原因。 困难在于,我们通常为应用程序中的所有记录器设置一个记录级别。 如果一切正常,我们将其保持在较高水平(例如,警告)。 如果需要查找失败的原因,请在下面安装(例如Debug)。

每个应用程序的一级日志记录


当我们将应用程序中的日志记录级别设置为低时,我们的日志存储中将充满大量消息。 这些消息来自不同的请求,并且混合在一起,因为可以同时处理请求。 这导致许多潜在的问题:

  • 如何将有问题的请求的消息与其他请求的消息分开?
  • 尽管不会使用这些消息,但不会导致崩溃的请求仍然会花费时间来写入日志存储库。
  • 来自成功请求的消息将占用日志存储库中的空间,尽管永远不会使用这些消息。

老实说,这些困难不是无法克服的。 要将“良好”请求的消息与“不良”请求的消息分开,可以使用相关性ID 。 所有现代的日志处理系统都允许通过各种标准(包括此标准)过滤记录。

性能通常也不是主要问题。 日志记录系统支持异步记录,因此,大规模日志记录的效果通常不会造成破坏。

而且磁盘空间现在相对便宜,因此存储大量记录不是问题。 特别是如果我们可以不时删除旧记录。

但是,我们可以改善这个系统吗? 我们能否根据特定条件为每个请求设置单独的日志记录级别? 我想在这里考虑这个问题。

每个请求的单独日志记录级别


让我说一下我将要实现的解决方案的要求。 必须有一种方法可以为每个请求建立单独的日志记录级别。 必须有一种灵活的方法来指定条件,这些条件决定了针对特定请求选择此级别的条件。 并且应该有可能在程序执行期间更改这些条件,而无需重新启动它。

因此,任务已设置。 让我们开始吧。

我将基于.NET Core创建一个简单的Web服务。 他将只有一个控制器:

[Route("api/[controller]")] [ApiController] public class ValuesController : ControllerBase { ... // GET api/values [HttpGet] public ActionResult<IEnumerable<string>> Get() { Logger.Info("Executing Get all"); return new[] { "value1", "value2" }; } // GET api/values/5 [HttpGet("{id}")] public ActionResult<string> Get(int id) { Logger.Info($"Executing Get {id}"); return "value"; } } 

稍后我们将讨论Logger属性的实现。 对于此应用程序,我将使用log4net库进行日志记录。 该库提供了一个有趣的机会。 我说的是关卡继承 。 简而言之,如果您在此库的配置中说名称为X的日志应具有Info日志记录级别,这意味着所有名称以X开头的日志(例如XYXZXAB )都将继承该级别。

最初的想法来自这里。 对于每个请求,我都会以某种方式确定所需的日志记录级别。 然后,我将在log4net配置中创建一个新的命名日志。 该日志将具有所需的日志记录级别。 之后,作为当前请求的一部分创建的所有记录器对象的名称都应以我创建的此新日志的名称开头。 唯一的问题是log4net永远不会删除日志。 一旦创建,它们就存在于应用程序的整个生命周期中。 因此,我最初为每个可能的日志记录级别创建一个日志:

 <?xml version="1.0" encoding="utf-8" ?> <log4net> <appender name="Console" type="log4net.Appender.ConsoleAppender"> <layout type="log4net.Layout.PatternLayout"> <!-- Pattern to output the caller's file name and line number --> <conversionPattern value="%5level [%thread] (%file:%line) - %message%newline" /> </layout> </appender> <appender name="RollingFile" type="log4net.Appender.RollingFileAppender"> <file value="RequestLoggingLog.log" /> <appendToFile value="true" /> <maximumFileSize value="100KB" /> <maxSizeRollBackups value="2" /> <layout type="log4net.Layout.PatternLayout"> <conversionPattern value="%level %thread %logger - %message%newline" /> </layout> </appender> <root> <level value="WARN" /> <appender-ref ref="Console" /> <appender-ref ref="RollingFile" /> </root> <logger name="EdlinSoftware.Log.Error"> <level value="ERROR" /> </logger> <logger name="EdlinSoftware.Log.Warning"> <level value="WARN" /> </logger> <logger name="EdlinSoftware.Log.Info"> <level value="INFO" /> </logger> <logger name="EdlinSoftware.Log.Debug"> <level value="DEBUG" /> </logger> </log4net> 

现在,我有几个名为EdlinSoftware.Log.XXXX的日志。 这些名称将用作查询中使用的日志名称的前缀。 为了避免请求之间的冲突,我将为此请求计算出的前缀存储在AsyncLocal实例中。 该对象的值将在新的OWIN中间件中设置:

 app.Use(async (context, next) => { try { LogSupport.LogNamePrefix.Value = await LogSupport.GetLogNamePrefix(context); await next(); } finally { LogSupport.LogNamePrefix.Value = null; } }); 

设置此值后,使用所需的名称前缀创建记录器非常容易:

 public static class LogSupport { public static readonly AsyncLocal<string> LogNamePrefix = new AsyncLocal<string>(); public static ILog GetLogger(string name) { return GetLoggerWithPrefixedName(name); } public static ILog GetLogger(Type type) { return GetLoggerWithPrefixedName(type.FullName); } private static ILog GetLoggerWithPrefixedName(string name) { if (!string.IsNullOrWhiteSpace(LogNamePrefix.Value)) { name = $"{LogNamePrefix.Value}.{name}"; } return LogManager.GetLogger(typeof(LogSupport).Assembly, name); } .... } 

现在很清楚如何在我们的控制器中获取记录器实例:

 [Route("api/[controller]")] [ApiController] public class ValuesController : ControllerBase { private ILog _logger; private ILog Logger { get => _logger ?? (_logger = LogSupport.GetLogger(typeof(ValuesController))); } .... } 

剩下要做的只是一件事:以某种方式设置规则,我们可以根据这些规则选择每个请求的日志记录级别。 这应该是一个相当灵活的机制。 基本思想是使用C#脚本。 我将创建一个LogLevelRules.json文件,在其中定义一组“规则-日志记录级别”对:

 [ { "logLevel": "Debug", "ruleCode": "context.Request.Path.Value == \"/api/values/1\"" }, { "logLevel": "Debug", "ruleCode": "context.Request.Path.Value == \"/api/values/3\"" } ] 

在这里, logLevel是所需的日志记录级别, ruleCode是C#代码,它为给定的请求返回一个布尔值。 应用程序将一一运行规则代码。 其代码返回true的第一个规则将用于设置适当的日志记录级别。 如果所有规则都返回false,则将使用默认级别。

要从规则的字符串表示形式创建委托,请使用CSharpScript类:

 public class Globals { public HttpContext context; } internal class LogLevelRulesCompiler { public IReadOnlyList<LogLevelRule> Compile(IReadOnlyList<LogLevelRuleDescription> levelRuleDescriptions) { var result = new List<LogLevelRule>(); foreach (var levelRuleDescription in levelRuleDescriptions ?? new LogLevelRuleDescription[0]) { var script = CSharpScript.Create<bool>(levelRuleDescription.RuleCode, globalsType: typeof(Globals)); ScriptRunner<bool> runner = script.CreateDelegate(); result.Add(new LogLevelRule(levelRuleDescription.LogLevel, runner)); } return result; } } internal sealed class LogLevelRule { public string LogLevel { get; } public ScriptRunner<bool> Rule { get; } public LogLevelRule(string logLevel, ScriptRunner<bool> rule) { LogLevel = logLevel ?? throw new ArgumentNullException(nameof(logLevel)); Rule = rule ?? throw new ArgumentNullException(nameof(rule)); } } 

在这里, Compile方法检索从LogLevelRules.json文件读取的对象列表。 它为每个规则创建一个运行程序委托。

该代表列表可以保存:

 LogSupport.LogLevelSetters = new LogLevelRulesCompiler().Compile( new LogLevelRulesFileReader().ReadFile("LogLevelRules.json") ); 

并在未来使用:

 public static class LogSupport { internal static IReadOnlyList<LogLevelRule> LogLevelSetters = new LogLevelRule[0]; ... public static async Task<string> GetLogNamePrefix(HttpContext context) { var globals = new Globals { context = context }; string result = null; foreach (var logLevelSetter in LogLevelSetters) { if (await logLevelSetter.Rule(globals)) { result = $"EdlinSoftware.Log.{logLevelSetter.LogLevel}"; break; } } return result; } } 

因此,在应用程序启动时,我们读取LogLevelRules.json ,使用CSharpScript类将其内容转换为委托列表,然后将此列表保存在LogSupport.LogLevelSetters字段中。 然后,对于每个请求,我们从该列表中运行委托以获取日志记录级别。

剩下要做的唯一事情就是跟踪LogLevelRules.json文件中的更改。 如果要设置某些查询的日志记录级别,则向该文件添加新规则。 为了强制我们的应用程序应用这些更改而无需重新启动,必须​​监视文件:

 var watcher = new FileSystemWatcher { Path = Directory.GetCurrentDirectory(), Filter = "*.json", NotifyFilter = NotifyFilters.LastWrite }; watcher.Changed += (sender, eventArgs) => { // ,  ,  ,   . Thread.Sleep(1000); LogSupport.LogLevelSetters = new LogLevelRulesCompiler().Compile( new LogLevelRulesFileReader().ReadFile("LogLevelRules.json") ); }; watcher.EnableRaisingEvents = true; 

应该注意的是,为了简洁起见,在使用LogSupport.LogLevelSetters字段时,我省略了流同步代码。 但是实际上,这种同步是必需的。

完整的应用程序代码可以在GitHub找到

缺点


上面显示的代码使您能够解决为每个请求设置单独的日志记录级别的问题。 但是他有很多缺点。 让我们讨论一下。

1.此方法更改日志的名称。 因此,类似“ Edlinsoft.Log.Debug.MyClassLogger ”的内容将存储在日志存储库中,而不是“ MyClassLogger ”。 您可以忍受它,但是它不是很方便。 也许可以通过更改日志的布局(日志布局)来解决该问题。

2.现在无法使用记录器类的静态实例,因为必须为每个请求分别创建它们。 我认为,这里最严重的问题是开发人员应始终牢记这一点。 有人可能会意外地用记录器创建一个静态字段并得到奇怪的结果。 您可以通过为记录器创建包装器类而不是直接使用log4net类来克服这种情况。 这样的包装程序始终可以为每个操作创建log4net记录器的新实例。 在这种情况下,它可以在静态字段中自由使用。

3.所描述的方法创建了许多记录器实例。 这在创建和垃圾回收期间都会消耗内存和处理器周期。 根据您的应用程序,这可能不是重要问题。

4.当我们使用规则更改JSON文件时,规则代码可能包含错误。 使用try-catch块非常简单,因此这些错误不会破坏我们的主应用程序。 但是,我们需要以某种方式找出问题所在。 错误有两种:

  • 委托中规则代码的编译时间错误。
  • 这些委托的运行时错误。

我们需要以某种方式找出这些错误,否则我们的日志记录将根本无法工作,甚至我们都不知道。

5. JSON文件中的规则代码原则上可以包含任何指令。 这可能会导致安全问题。 有必要以某种方式限制此代码的功能。 另一方面,如果攻击者能够直接写入您的应用程序文件,则安全问题显而易见。

结论


通常,我没有得到这样的解决方案应该替代现有的日志记录方法的印象。 即使对整个应用程序使用单一级别的日志记录,具有筛选日志条目功能的良好工具也可以在此处提供帮助。 尽管如此,我希望对这个问题的分析能为您提供思考的机会。

Source: https://habr.com/ru/post/zh-CN436340/


All Articles