Garbage-free Steady State Logging(无垃圾的记录日志)Garbage collection pauses are a common cause of latency spikes and for many systems significant effort is spent on controlling these pauses.(垃圾收集暂停是导致延迟尖峰的一个常见原因,许多系统的重要的工作都是花在控制这些暂停上。) Many logging libraries, including previous versions of Log4j, allocate temporary objects like log event objects, Strings, char arrays, byte arrays and more during steady state logging. This contributes to pressure on the garbage collector and increases the frequency with which GC pauses occur.(许多日志库,包括log4j的以前的版本中,在记录日志的时候为日志事件对象,字符串,字符数组,字节数组和其他的对象分配临时对象。 这会增加垃圾收集器的压力并增加GC暂停发生的频率。) From version 2.6, Log4j runs in "garbage free" mode by default where objects and buffers are reused and no temporary objects are allocated as much as possible. There is also a "low garbage" mode which is not completely garbage free but does not use ThreadLocal fields. This is the default mode when Log4j detects it is running in a web application. Finally, it is possible to switch off all garbage-free logic and run in "classic mode" instead. For details, see the Configuration section below.(从2.6版本开始,Log4j在默认情况下将以“garbage free”模式运行,以这种模式运行,对象和缓冲区会被重用,并且不会有多的临时对象被分配。 还有一个“小垃圾”的模式,它不是完全没有垃圾的,但是它没有使用ThreadLocal的字段。 当Log4j检测到它是在一个Web应用程序的运行,这就会是默认的模式 。 最后,还有可能关闭所有无垃圾的逻辑,而运行在“经典模式”下。 有关详细信息,请参见下面的配置部分。) A Contrived Example(一个例子)To highlight the difference that garbage-free logging can make, we used Java Flight Recorder to measure a simple application that does nothing but log a simple string as often as possible for about 12 seconds.(为了突出“ garbage-free ”记录可以做的“差异,我们使用Java Flight Recorde(jdk的bin目录下的jmc.exe) 测量一个简单的应用程序,它什么事都没有做,只会尽可能频繁地记录一个简单的字符串 大约12秒。) The application was configured to use Async Loggers, a RandomAccessFile appender and a "%d %p %c{1.} [%t] %m %ex%n" pattern layout. (Async Loggers used the Yield WaitStrategy.)(应用程序被配置为使用一个异步日志记录器,一个RandomAccessFile类型的 appender和 "%d %p %c{1.} [%t] %m %ex%n" 的模式布局。(异步日志记录器使用的退让等待策略。)) Mission Control shows that with Log4j 2.5 this application allocates memory at a rate of about 809 MB/sec, resulting in 141 minor collections. Log4j 2.6 does not allocate temporary objects in this configuration, and as a result the same application with Log4j 2.6 has a memory allocation rate of 1.6 MB/sec and was GC-free with 0 (zero) garbage collections.(任务控制显示,使用log4j 2.5,这个应用程序分配内存的速度大约809 MB /秒, 导致141个小集合。 Log4j 2.6在这个配置中没有分配临时对象,导致了这样一个结果, 相同的应用程序使用log4j 2.6分配内存的速度大约 为1.6 MB /秒并且没有垃圾收集。) Configuration(配置)Garbage-free logging in Log4j 2.6 is partially implemented by reusing objects in ThreadLocal fields,
and partially by reusing buffers when converting text to bytes.(在log4j 2.6中Garbage-free记录日志的部分是通过重用ThreadLocal的字段中的对象来实现的, ThreadLocal fields holding non-JDK classes can cause memory leaks in web applications when the application server‘s thread pool continues to reference these fields after the web application is undeployed. To avoid causing memory leaks, Log4j will not use these ThreadLocals when it detects that it is used in a web application (when the javax.servlet.Servlet class is in the classpath, or when system property log4j2.is.webapp is set to "true").(ThreadLocal字段持有非JDK类,在web应用程序中,如果应用程序服务器的线程池在web应用程序被卸载后继续引用这些字段,可能会导致内存泄漏 。为了避免造成内存泄漏,Log4将不会使用这些ThreadLocal,如果它检测到它是在一个Web应用程序中使用(当javax.servlet.servlet类在类路径中,或者当系统属性log4j2.is.webapp设置为“true”)) Some garbage-reducing functionality does not rely on ThreadLocals and is enabled by default for all applications: in Log4j 2.6, converting log events to text and text to bytes can be done by directly encoding text into a reused ByteBuffer without creating intermediary Strings, char arrays and byte arrays. So while logging is not completely garbage-free for web applications yet, the pressure on the garbage collector can still be significantly reduced.(一些垃圾减少功能不依赖于ThreadLocal并且在所有的应用程序中默认启用:在log4j 2.6中,将事件事件转换成文本及将文本转换成字节可以直接将文本编码到复用的ByteBuffer中,不需要创建一个中间的字符串,字符数组和字节数组。因此,尽管日志对于Web应用程序并不是不会产生垃圾的,但是对垃圾收集器的压力仍然可以显著降低。)
Disabling Garbage-free Logging(禁用无垃圾记录)There are two separate system properties for manually controlling the mechanisms Log4j uses to avoid creating temporary objects:(有两个独立的系统属性用来手动控制避免Log4j创建临时对象 的l机制 )
Instead of system properties, the above properties can also be specified in a file named log4j2.component.properties by including this file in the classpath of the application.(除了系统属性,上面的属性也可以被在一个叫做log4j2.component.properties 的文件指定,这个文件要被包含在应用程序的类路径中) Supported Appenders(支持的Appenders)The following appenders are garbage-free during steady-state logging:(下面的appenders 在记录日志的时候不会产生垃圾:)
Any other appenders not in the above list (including AsyncAppender) create temporary objects during steady-state logging. Instead of AsyncAppender, use Async Loggers to log asynchronously in a garbage-free manner.(任何不在上面列表(包括AsyncAppender)中的其它appenders会在记录日志的时候创建临时对象。而AsyncAppender,使用异步日志记录器以一种garbage-free 的方式来异步记录日志) Supported Filters(支持的过滤器)The following filters are garbage-free during steady-state logging:(下面的过滤器在记录日志的期间不会产生垃圾)
Other filters like BurstFilter, RegexFilter and ScriptFilter are not trivial to make garbage free, and there is currently no plan to change them.(其他的过滤器,像BurstFilter,regexfilter和scriptfilter让他们不产生垃圾也不繁琐,但是目前没有计划去改变他们) Supported Layouts(支持的布局)GelfLayoutGelfLayout is garbage-free when used with compressionType="OFF", as long as no additional field contains ‘${‘ (variable substitution).(当compressionType="OFF" 时gelflayout是不会产生垃圾的,只要没有额外的字段包含‘$ {’(变量代换)。) PatternLayoutPatternLayout with the following limited set of conversion patterns is garbage-free. Format modifiers to control such things as field width, padding, left and right justification will not generate garbage.(以下patternlayout有限的转换模式是不会产生垃圾的。格式修饰符来控制字段宽度、填充、左对齐和右对齐并且不会产生垃圾。)
Other PatternLayout conversion patterns, and other Layouts may be updated to avoid creating temporary objects in future releases. (Patches welcome!)(其它的PatternLayout转换模式和其它的布局会在以后的版本中来更新他们,让他们避免创建临时变量 ) Note: Logging exceptions and stack traces will create temporary objects with any layout. (However, Layouts will only create these temporary objects when an exception actually occurs.) We haven‘t figured out a way to log exceptions and stack traces without creating temporary objects. That is unfortunate, but you probably still want to log them when they happen.(在任何的布局中,如果出现日志异常和堆栈跟踪都会创建临时变量。(不敢怎样,布局在异常正在发生的时候,仅会创建这些临时对象。)我们还没有找到一种不创建临时对象的方法来记录异常和堆栈的痕迹。 这是不幸的,但在他们发生时你可能仍然想记录。)
API ChangesMethods have been added to the Logger interface so that no vararg array objects are created when logging messages with up to ten parameters.(方法已经被添加到Logger接口中,所以当你的日志消息有多达10个参数也不会创建临时数组对象) Also, methods have been added to the Logger interface to log java.lang.CharSequence messages. User-defined objects that implement the CharSequence interface can be logged without creating temporary objects: Log4j will try to turn CharSequence messages, Object messages and message parameters into text by appending them to a StringBuilder as a CharSequence. This avoids calling toString() on these objects.(方法也已经被添加到Logger接口来打印java.lang.CharSequence 消息。用户定义的对象只要实现了CharSequence 接口就也可以被打印,而不创建临时对象:Log4j会尝试将你的对象转换成CharSequence 消息,对象消息和消息参数会被作为一个CharSequence,通过将它们追加到一个StringBuilder再转换成文本 。这样可以避免调用这些对象的toString()) An alternative is to implement the org.apache.logging.log4j.util.StringBuilderFormattable interface. If an object is logged that implements this interface, its formatTo method is called instead of toString().(另一种方式就是实现org.apache.logging.log4j.util.StringBuilderFormattable 接口。如果一个对象实现了这个接口,在打印它的时候就不会调用toString()方法,而是调用formatTo方法) Log4j may call toString() on message and parameter objects when garbage-free logging is disabled (when system property log4j2.enable.threadlocals is set to "false".)(如果你将garbage-free禁用,在打印信息和信息对象的时候会调用toString()方法。 ) Impact on Application Code: Autoboxing(对应用程序代码的影响:自动装箱)We made an effort to make logging garbage-free without requiring code changes in existing applications, but there is one area where this was not possible. When logging primitive values (i.e. int, double, boolean, etc.) the JVM autoboxes these primitive values to their Object wrapper equivalents, creating garbage.(我们努力使现有应用程序的代码在不进行更改的条件下打印日志而不产生垃圾,但是有一个地方不可能实现。当打印基础数量类型的值(如:int ,double, boolean 等)时,JVM会将他们封装成它们的包装类型,这就会产生垃圾) Log4j provides an Unbox utility to prevent autoboxing of primitive parameters. This utility contains a thread-local pool of reused StringBuilders. The Unbox.box(primitive) methods write directly into a StringBuilder, and the resulting text will be copied into the final log message text without creating temporary objects.(Log4j提过了一个Unbox 工具来阻止基础数据类型参数的字段装箱。这个工具包含一个可以重用的StringBuilder的本地线程池。 Unbox.box(primitive) 方法直接将参数写入到StringBuilder中,并且结果文本会被复制到最终的日志消息文本中,在这个过程中不会创建临时对象)
Performance(性能)Response Time Latency(响应时间延迟)Response time is how long it takes to log a message under a certain load. What is often reported as latency is actually service time: how long it took to perform the operation. This hides the fact that a single spike in service time adds queueing delay for many of the subsequent operations. Service time is easy to measure (and often looks good on paper) but is irrelevant for users since it omits the time spent waiting for service. For this reason we report response time: service time plus wait time. See the response time section of the performance page for more detail.(响应时间是在一定负载下记录消息的时间。经常报告的延迟实际上是指提供服务需要的时间:需要多长时间 去执行操作。这隐藏了一个事实,即一个单一的服务时间尖峰增加 了许多后续操作的排队延迟。服务时间是很容易测量(通常理论上看起来不难)但是对于用户来说服务时间没有任何作用,因为它忽略了用户等待服务的时间。为此,我们报告的响应时间为:服务时间加上等待时间。查看performance 章节的响应时间部分来获取更多详细信息。) The response time test results below were all derived from running the ResponseTimeTest class which can be found in the Log4j 2 unit test source directory. If you want to run these tests yourself, here are the command line options we used:(下面的响应时间的测试结果均来自ResponseTimeTest 类的运行,这个类可以在log4j 2单元测试的源码目录中找到。如果你想自己运行这些测试,这是我们使用的命令行选项:)
Async Loggers(异步日志记录器)The graph below compares "classic" logging to garbage-free logging response time behaviour for Log4j‘s Async Loggers. In the graph, "100k" means logging at a sustained load of 100,000 messages/second, "800k" is a sustained load of 800,000 messages/second.(下面的图表,比较了异步日志记录器中的“classic”记录日志和“garbage-free”记录日志行为的响应时间。在图表中,“100k”意味着记录日志的持续负载为100,000条消息每秒,“800k”意味着记录日志的持续负载为800,000条消息每秒,) In classic mode we see numerous minor garbage collections which pause the application threads for 3 milliseconds or more. This quickly adds up to response time delays of almost 10 milliseconds. As you can see in the graph, increasing the load shifts the curve to the left (there are more spikes). This makes sense: logging more means more pressure on the garbage collector resulting in more minor GC pauses. We experimented a little with reducing the load to 50,000 or even 5000 messages/second, but this did not eliminate the 3 millisecond pauses, it just made them occur less frequently. Note that all GC pauses in this test are minor GC pauses. We did not see any full garbage collections. In garbage-free mode, maximum response time remains well below 1 millisecond under a wide range of loads. (Max 780 us at 800,000 messages/sec, max 407 us at 600,000 messages/sec, with the 99% around 5 us for all loads up to 800,000 messages/sec.) Increasing or decreasing the load does not change the response time behaviour. We did not investigate the cause of the 200-300 microsecond pauses we saw in these tests. When we increased the load further we begin to see larger response time pauses for both classic and garbage-free logging. At sustained loads of 1 million messages/second or more we start to approach the maximum throughput of the underlying RandomAccessFile Appender (see the synchronous logging throughput chart below). At these loads the ringbuffer starts to fill up and backpressure kicks in: attempting to add another message when the ringbuffer is full will block until a free slot becomes available. We start to see response times of tens of milliseconds or more; and attempting to increase the load even more results in larger and larger response time spikes. Synchronous File Logging(异步文件记录)With synchronous file logging, garbage-free logging still performs better than classic logging, but the difference is less pronounced.(使用异步文件记录,garbage-free logging仍然比classic logging性能好,但是差异不太明显) At a workload of 100,000 messages/second, classic logging max response time was a little over 2 milliseconds where garbage-free logging was a little over 1 millisecond. When the workload is increased to 300,000 messages/second, classic logging shows response time pauses of 6 milliseconds where the garbage-free response times were less than 3 milliseconds. It may be possible to improve on this, we did not investigate further yet. The above results are obtained with the ResponseTimeTest class which can be found in the Log4j 2 unit test source directory, running on JDK 1.8.0_45 on RHEL 6.5 (Linux 2.6.32-573.1.1.el6.x86_64) with 10-core Xeon CPU E5-2660 v3 @2.60GHz with hyperthreading switched on (20 virtual cores). Classic Logging has Slightly Higher Throughput(经典Logging 有较高的吞吐量)Throughput is slightly worse for garbage-free logging, compared to classic logging. This is true for both synchronous and asynchronous logging. The graph below compares the sustained throughput of synchronous logging to a file with Log4j 2.6 in garbage-free mode, classic mode and Log4j 2.5.(相比 classic logging ,garbage-free logging 的吞吐量稍微差点。不管是同步的还是异步的都是这样。下面的图表比较了在Log4j2.6的garbage-free 模式, classic 模式 和log4j2.5 下同步将日志记录到文件的持续的吞吐量。) The results above are obtained with the JMH Java benchmark harness. See the FileAppenderBenchmark source code in the log4j-perf module. Under the Hood(在底层)Custom Message implementations that implement org.apache.logging.log4j.util.StringBuilderFormattable can be converted to text by garbage-free Layouts without creating temporary objects. PatternLayout uses this mechanism and other layouts that convert LogEvents to text will likely also look for this interface.(通过实现org.apache.logging.log4j.util.StringBuilderFormattable 接口自定义的消息可以通过garbage-free 布局转换成文本,这个过程不会创建临时对象。使用这种机制的PatternLayout 和其它的需要将LogEvents转换成文本的layouts 也可能会去查找这个接口。) Custom Layouts that want to be garbage-free should implement the Encoder<LogEvent> interface. For custom Layouts that convert a LogEvent to a text representation, the org.apache.logging.log4j.core.layout.StringBuilderEncoder class may be useful to convert this text to bytes in a garbage-free manner.(想自定义garbage-free 类型的Layouts 应该 实现Encoder<LogEvent> 接口。为了自定义可以将一个LogEvent 转换成文本来显示的Layouts, org.apache.logging.log4j.core.layout.StringBuilderEncoder 这个类在将文本转换成字节时非常有用,它使用的方式是 garbage-free ) Custom Appenders that want to be garbage-free should provide their Layout with a ByteBufferDestination implementation that the Layout can directly write into.(想要自定义一个garbage-free 类型的Appender,应该为 Appender提供一个实现了ByteBufferDestination 接口的Layout ,这个Layout 能够直接写入。) AbstractOutputStreamAppender has been modified to make the ConsoleAppender, (Rolling)FileAppender, (Rolling)RandomAccessFileAppender and MemoryMappedFileAppender garbage-free. An effort has been made to minimize impact on custom Appenders that extend AbstractOutputStreamAppender, but it is impossible to guarantee that changing the superclass will not impact any and all subclasses. Custom Appenders that extend AbstractOutputStreamAppender should verify that they still function correctly. In case there is a problem, system property log4j2.enable.direct.encoders can be set to "false" to revert to the pre-Log4j 2.6 behaviour.(AbstractOutputStreamAppender 已被修改,目的是使cConsoleAppender, (Rolling)FileAppender, (Rolling)RandomAccessFileAppender and MemoryMappedFileAppender 无垃圾。已作出努力,以减少对自定义Appenders 和继承AbstractOutputStreamAppender 的影响,但它不可能保证改变父类不会影响任何一个和所有的子类。自定义Appenders---继承AbstractOutputStreamAppender 应该确认他们的功能是否仍然正确。万一出现问题,系统属性log4j2.enable.direct.encoders可以设置为“false”恢复到log4j 2.6之前的行为。) |
Log4j – Garbage-free Steady State Logging - Apache Log4j 2
原文:http://www.cnblogs.com/jimboi/p/6392327.html