Log2: A Cost-Aware Logging Mechanism for Performance Diagnosis

文章解决一个核心问题:whether to log。这个log和传统的log不一样,这个log的意思是Monitored Code Region的执行时间。 论文用了两层filter,本地过滤器负责丢弃琐碎的日志请求,全局过滤器负责将排名靠前的日志请求flush到磁盘上。

A Survey of Logging Practice in Microsoft

很有意思。 主要提了三个方面:

  • logging overhead
  • Lack of cost-awareness during log instrumentation
  • Burden in log analysis

Design and Implementation

Logging Reqeusts

实际上就是在监控代码区域"(Monitored Code Region,MCR)前后打两个时间戳!

典型的MCR的例子包括。

  • 昂贵的系统级API,如I/O、数据库、网络等方面的操作。
  • 循环块。以前的工作发现,现实世界的性能问题有很大一部分是由低效的循环造成的。
  • 函数调用跨越了应用层面的组件边界,比如RPC或者GUI和后端服务之间的连接。

性能日志应该在MCR的开始和结束时记录两个时间戳,这足以计算MCR的执行时间。 Log2提供了两个日志API,Begin和End,分别表示一个MCR的开始和结束。 这些API可以计算出MCR的执行时间,并记录MCR的唯一ID。

Overall Workflow

采用两个过滤阶段,即本地过滤器和全局过滤器,来决定是否应该记录进入的日志请求(是否记录)。 这种两阶段的过滤机制是为了避免当大量的日志请求同时进入时,单一的集中式过滤器可能造成的瓶颈。

本地过滤器负责丢弃琐碎的日志请求。 每个线程的日志请求都有一个本地过滤器。 只有效用分数(动态计算)高于全局阈值的日志请求才能通过本地过滤器进入全局过滤器的内存缓冲区。其他日志请求被丢弃。

全局过滤器负责将排名靠前的日志请求flush到磁盘上,同时遵守日志预算的规定。

全局阈值是动态调整的,以适应环境的动态变化,同时优化Log2的效能和效率。 通常情况下,在第一阶段有相当高比例的日志请求被丢弃。 在全局过滤器中,关于日志输出的最终决定是定期做出的,以确保符合logging budget的约束。 The logging requests from all local filters during the last time window are cached in memory. 当一个周期性事件被触发时,缓存的日志请求会根据它们的效用分数进行排序。 只有总体积等于日志预算的排名靠前的请求被刷到磁盘。 同时,全局过滤器通过考虑最近的时间间隔内的日志请求量来更新效用分数的全局阈值。最后,全局过滤器将新的阈值反馈给每个本地过滤器。

Local Filter

我们的直觉是,如果一个MCR的执行时间与它过去的行为相去甚远,那么效用得分应该更高。 naive的方法就是用直方图,但是给每一个MCR维护一个直方图开销太大。因此采用的方法是method of moments。

给了三种分数,非常简单。但是因为mean和stderr是一直在变得,所以加了update的几个式子,还有exponential smoothing。

Global Filter

Log flushing

日志flush是定期触发的,这样的时间段被称为flush间隔。 当定时器被触发时,Log2首先根据利用率得分对缓冲的日志进行排序,然后flush排名靠前的日志,使flush的日志总量不超过日志预算。 所有被选中的日志被打包在一起,并以batched方式被flush一次。

缓冲区设计:适当的缓冲区设计对于减少日志的开销很重要,特别是对于减少CPU的使用。 Log2包括一个叫做交换缓冲区的数据结构,它有两个缓冲区:一个用于插入操作,另一个用于排序和冲洗操作。 这两个缓冲区在冲刷间隔后定期交换。一个0/1标志被用来指示哪个缓冲区当前用于插入,哪个用于冲刷。 这样的机制保证了两个线程在不同的缓冲区工作,除了交换全局标志外,没有锁的争夺。

flush间隔的选择:30秒

Utility threshold adjustment

阈值用于控制插入交换缓冲区的日志量。因为只有效用分数大于阈值的日志生成请求才会被缓存,所以设置一个合适的阈值对Log2来说是非常重要的。

我们设计了一个迭代的方法,通过 "从历史中学习 "来调整阈值。每次迭代的时间称为调整区间。 直观地说,当前一个调整区间的日志量高于预算时,阈值应该被提高。当前一个调整区间的日志量低于预算时,阈值应该降低。

调整方式:equation 8

调整间隔:30秒

Details

我们用C#语言实现了Log2。关于该实现的一些细节如下。

有限制的内存使用:Log2的最大内存使用量在配置中被设置为50MB。 在我们的实现中,当达到最大内存使用量时,新的日志请求将在相同的刷新间隔内被放弃。

处理系统空闲时间:系统空闲是一种特殊的情况,需要加以处理。 具体来说,当记录请求很少时,无论如何调整效用阈值,都不会达到预算。其结果是,效用阈值可能会非常低,因此,当记录请求的强度恢复到正常时,系统将大幅超调(即,将有一阵冲洗)。 为了避免这种情况,我们对调整间隔设置了一个下限。在我们的实现中,我们将下限设置为0。这种机制通常用于控制工程领域。

Nested instrumentation:为了支持nested instrumentation,每个本地过滤器实际上都维护着一个时间戳堆栈,以匹配记录的开始-结束对。