天天看点

Log4j最佳实践

Julius Davies, June 9th, 2008

尤利乌斯·戴维斯,2008年6月9日

Before You Do Anything Else

在你做其他事情之前

Take a look at this logging checklist by Anton Chuvakin.

先看看Anton Chuvakin做的这个日志清单。

Introduction 简介

Logs must be thought out. An application’s log design should probably be signed-off by a software architect. Enhancements to the log design, as the system evolves, should be encouraged.

日志必须经过深思熟虑。一个应用的日志设计也许应该经过一个软件架构师的审核。随着系统的发展,应该鼓励对日志设计的增强。

Log Design 日志设计

There are only two things about a log that can be controlled by the application: the individual lines, and the separation into different log files.

应用对日志的控制只有两处:独立的行,和分成不同的日志文件。

Greppable Logs 可用grep抓取的日志

What is the end result that we want?

我们最终想要的结果是什么?

We want a greppable log. This means log design is focused entirely on a single line of log. A SINGLE LINE. Remember that. A log entry SHOULD NEVER go over multiple-lines. The only exception is java stacktraces.

我们想要可通过grep命令抓取的日志。这表示日志设计完全集中于日志中单一的行。单一的行。记住这点。一个日志条目永远不应该跨多行。唯一的例外就是java的堆栈路径。

We want a greppable log. In other words, what will we be asking of the log? Probably questions like:

我们想要可通过grep命令抓取的日志。换句话说,对日志需要询问些什么?可能是像这样的问题:

When did user 555444, branch 10, last log in?

· 用户555444,第10分部,最后一次登录的时间是何时?

Is our incoming connection from receiving any messages?

· 我们从来自的连接收到了什么信息吗?

How many times did our web-services partner go dead yesterday?

· 我们的web-services合作方昨天死机了多少次?

What’s the longest time required to make a transaction in September?

· 9月份的事务耗费的最长的一次时间是多少?

Did any transaction fail to complete?

· 是否有事务没有完成就失败了?

Make sure your log can answer questions like these.

确保你的日志能回答这样的问题。

Also, if your application EVER reports a problem, make sure your application logs it. It’s not enough to just show a webpage or send an email. You need the log (and hopefully the stacktrace/register-dump/diagnostics).

并且,如果你的应用某时报告了一个问题,确保你的应用日志记录了它。仅仅显示一个页面或者发一封电子邮件是不够的。你需要日志(最好包含了堆栈路径/寄存器dump/诊断报告)。

Four problems to avoid 四个需要避免的问题

1. Log is missing necessary information.      
  1. 日志缺少了必要的信息。

    We cannot answer, “When did user 555444, branch 10, last log in?” if the log file doesn’t ever contain the information.

    我们无法回答,“用户555444,第10分部,最后一次登录的时间是何时?”如果日志文件根本没有这些信息。

    2. Log unsuitable for grep because of redundant information.

  2. 日志不适宜进行grep,因为有太多冗余信息。

    We cannot answer, “Is recieving any messages?” if the log file mentions for every line of log, even lines unrelated to .

    我们无法回答,“是否收到任何信息?”如果日志文件的每一行甚至毫无关系的行都含有。

    3. Information split across more than one line (bad for grep).

  3. 日志信息被分割成多行(不便于grep)。

    Answering, “What’s the longest time required to make a billpayment in September?” or “Did any billpayments fail to complete” is impossible with grep if “billPayment start” and “billPayment done” are separate log statements. Answering might even be impossible with any tool if other log statements are present inbetween the “start” and “finish.”

    如果“账单支付开始”和“账单支付完成”是分开的日志语句,那么通过grep回答“9月份进行账单支付所消耗的最长的一次时间是多少?”,或者“是否有账单支付失败了?”就是不可能的。如果日志语句出现在“start”和“finish”中间,那么很可能用其他工具来回答也是不可能的。

    Instead, just log a single statement of “billPayment took 285ms” or “billPayment timed out”.

    取而代之,仅记录一条语句“账单支付耗时285ms”或“账单支付超时”到日志即可。

    4. Error reported to user, but not logged.

  4. 向用户报告了错误,却没有记录到日志。

    Don’t write code like this! 😉

    不要写这样的代码!😉

try {
  // set some variable
    } catch ( Exception e ) {
       // do nothing
    }
    // if variable is null, tell user there was a problem      

Separate files for different areas of interest 对不同关注领域分文件写日志

Log design is primarily focused on the individual line of log. However, partitioning the lines into various files can make useful information even more accessible.

日志的设计主要集中在日志中独立的行。然而,把这些行拆分到各个不同的文件中可以使有用的信息更加易于访问。

So far my approach is to try and segregate quieter events (that occur seldom) from noisier events. For a 100 txn/second application I wrote I created three main logs: a message log, a connection log (disconnects/reconnects), and a stacktrace log.

迄今为止我着手于尝试将更加安静的事件(即少量出现)和更加喧闹的时间分离开。我为我写的一个每秒100笔交易的应用创建了3个主要的日志:一个信息日志,一个链接日志(释放连接/重获连接),和一个堆栈路径日志。

I don’t worry about redundancy. I might log the same line in several files.

我不担心冗余。我可能会把同一行日志记录在几个文件中。

Timestamps 时间戳

Logs must contain timestamps, with timezone, to the millisecond or nanosecond.

日志必须包含时间戳,其中含有时区,精确到毫秒或纳秒。

2004-10-04/09:03:00.141141000/PDT*bad event
2004-10-04/09:03:20.217588221/PDT good event
2004-10-04/09:03:26.006912999/PDT another good event      

Why timezone? 为什么要有时区?

Answer: maybe half our servers are in Toronto. If our sysadmins decide every computer should use GMT (or PST), great, but let’s give the sysadmins the option! Timezone also helps around daylight-savings changes.

答:可能我们一半的服务器在多伦多。如果我们的系统管理员决定每台机器都用GMT(或者PST),很好,但是让我们把选择权交给系统管理员!时区在夏令时发生改变的情况下也有其作用。

Why nanosecond? Why not to the second? 为什么要精确到纳秒?为什么不精确到秒?

Answer: we want to minimize the number of lines occuring with identical timestamps. This is very important if you want to split logs into separate files covering different areas of interest (e.g. connection-history.log and messages.log). If your timestamps are to the nanosecond, you can re-merge these files together and usually not lose the order of events (“sort -m”).

答:我们想将时间戳完全相同的行数降到最少。这对你想要将日志分为覆盖不同的被关注的领域的多个文件会很重要(例如:connection-history.log 和 messages.log)。如果你的时间戳精确到纳秒,你可以重新合并这些文件并且通常不会打乱事项的顺序(“sort -m”)。

Personally, for Java I prefer to use “yyyy-MM-dd/HH:mm:ss.SSS/zzz”. (I would use nanoseconds if Java supported it).

从个人角度,对Java我更愿意使用 “yyyy-MM-dd/HH:mm:ss.SSS/zzz”。(如果Java支持的话我定会使用纳秒)。

High Volume Logging 大容量日志

High Volume Logging: It is probably impossible for any logging system to guarantee logs get written chronologically (in same order as the original events). In an extremely highly loaded system you will sometimes see out-of-order events in your log, usually by a few milliseconds. If you only log to the second, you cannot reestablish the chronology. Log analysis tools also need to be aware of this and not blowup when fed data that is not strictly chronological.

大容量日志:要让任何日志系统确保日志是按事件顺序(于原始事件相同顺序)记载的或许是不可能的。在一个极其高负荷的系统中你有时候会看到日志中有顺序被打乱了的事件,通常在几毫秒之间。如果你只记录到秒,你就无法恢复原始时间顺序。日志分析工具也需要了解这点并且在给予并非严格按时间顺序排列的数据时不要崩溃。

Always Log To Local Disk 始终记录到本地磁盘

Applications should not try to log directly to the network. Don’t be tempted by the syslog dream, and be careful not to accidentally (or overtly) log to a shared directory. So many times people say, “The network is not reliable.” This means it’s unsuitable for direct logging. Local disk is your loyal and trustworthy friend.

应用不应该将日志直接发到网络。不要被系统日志美梦所诱惑,并要注意不要偶然地(或公然地)记录日志到一个共享目录。人们说过多少次,“网络是不可靠的。”这说明它是不适用于直接记录日志的。本地磁盘才是你忠实的可信的伙伴

We do want our logs to be ultimately centralized and archived, but that task is best accomplished with cron or some other batch-oriented background process using a reliable transport (e.g. ftp, scp, nfs, smbfs). Also, be sure to compress your logs before they hit the network.

我们的确想要将我们的日志最终集中并且归档,但是那个任务最好由定时任务或者一些其他后台批处理进程通过可靠的传输(例如:ftp,scp,nfs,smbfs)来完成。并且,确保你的日志在触网之前已经被压缩。

Keep a week or two of the archived files in both places (local-disk and archive server), both to make trouble shooting easier for sysadmins, and to give you some breathing room should your archival process break down temporarily. Having a couple weeks of logs on the local-disk can be quite convenient, especially when faced with a question like, “Did this problem start in the last few days?” The sysadmin will be happier if she doesn’t have to always ssh into the central archive just to look at yesterday’s logs.

同时在两个地方保存一到两个星期的归档文件(本地磁盘和归档服务器),两者都可以使系统管理员更易于分析问题,给你一些呼吸空间让你的归档进程暂时中止。在本地磁盘保留几个星期的日志文件会很方便,尤其是面对一个犹如“这个问题是否从过去几天开始出现?”的疑问时,系统管理员不需要总是通过ssh登录到中央归档服务就可以查看昨天的日志会让她更高兴的。

Use Log4j 1.2.x (or a worthy competitor - e.g. Logback) 使用Log4j 1.2.x(或者一个相称的对手 - 如Logback)

There are several logging frameworks available for java.

有以下几个日志框架可用于Java。

· log4j-1.2.x (Note: the 1.3.x and 2.x versions are not production quality yet - avoid for now)

· Logback

· java.util.logging

· logKit

· For those that can’t decide: commons-logging, or slf4j

· log4j-1.2.x (注: 1.3.x 和 2.x 版本还没有产品化 - 只是现在)

· Logback

· java.util.logging

· logKit

· 对那些决定不下来的人: commons-logging, or slf4j

I have worked with several applications that use home-brew logging, java.util.logging and log4j. In my opinion log4j is the easiest to program with, the easiest to configure, and the most flexible. I recommend log4j, and strongly discourage all others. (Note: this was written before Logback was available).

我参与过几个应用的开发,他们使用了自制的日志工具、java.util.logging及log4j。在我看来开发中log4j是最易于使用的,最容易配置,并且最灵活。我推荐使用log4j,并极不提倡其他日志工具。(注:本文写于Logback发行之前)

Commons-logging and slf4j are interesting. The are both generalizations of logging, capable of supporting any underlying implementation. If you cannot decide on an implementation, or if you think you might want to change your implementation in the future, then commons-logging or slf4j are appropriate. Commons-logging is also good to know about, because many 3rd party tools (JBoss, HttpClient, Tomcat, etc…) use it.

Commons-logging和slf4j很有意思。他们是覆盖面很广的日志工具,能支持任何潜在的实现。如果你无法确定采用什么实现,或者你认为你有可能在将来变更你的实现,那么commons-logging或slf4j是适合你的。Commons-logging也很容易掌握,因为很多第三方的工具(JBoss,HttpClient,Tomcat,等)都是用它。

I recommend skipping the generalization if possible. You will have more control over log4j if you use it directly. You cannot execute log4j’s PropertyConfigurator.configure( “/etc/log4j.properties” ) at your leisure if using “commons-logging”.

我建议尽可能跳过这些通用的工具。如果你直接使用log4j你会拥有更多的控制权。如果你使用“Commons-logging”你就无法惬意的执行log4j的PropertyConfigurator.configure( “/etc/log4j.properties” )。

Programming with log4j 用log4j编程

Every class must contain this line:

private static Logger log = Logger.getLogger( MyClass.class )      

每一个class必须包含这一行:

private static Logger log = Logger.getLogger( MyClass.class )      

EVERY CLASS! I’ve configured IntelliJ to automatically generate that code whenever I create a new class. Some people recommend against making that line static, but Logger.getLogger() is synchronized, so non-static can degrade performance. It’s easier just to use “static” and not worry about it. Normally I don’t try to avoid synchronized calls, but this really is one of those rare places in Java these days, even with Java6, where synchronized can hurt, since every object’s constructor will now contend for the global log4j lock.

是每个Class!我已经配置我的IntelliJ在我心间一个class时自动生成这行代码。一些人反对将这行代码声明为静态的,但是Logger.getLogger()方法是同步的,所以非静态会降低其性能。使用“static”会更加容易编码并且不用担心会有什么问题。通常我不会刻意去避免同步调用,但现在在Java中这的确是一个一,即便是在使用同步很不利的Java6中,因为现在每个对象的构造方法都会竞争log4j的全局锁。

DO NOT: create a single class “com.foo.app.Log” and run all logging calls through that! You are severely impairing log4j’s flexibility if you do that.

不要做:创建一个class“com.foo.app.Log”然后通过它来运行所有的日志调用!你这样做会严重破坏log4j的灵活性。(译注:这里的意思是指不要所有的地方打印日志都用类似Logger.getLogger(“com.foo.app.Log”)这样通过同一个class产生的logger)

In log4j, all loggers are named. Dots in the name “.” act as hierarchy dividers. Through configuration, you can turn off “com.foo”, turn on INFO for “com.foo.abc” and turn on DEBUG for “com.foo.abc.Message”. But you can only do this if every logger is named after the class calling it.

在log4j中,所有的logger都是命名的。名称中的点“.”起到了划分层级的作用。通过配置,你可以关闭“com.foo”日志,对“com.foo.abc”打开INFO级别日志并且对“com.foo.abc.Message”打开DEBUG级别日志。但是只有在所有的logger都是用调用它的class来命名的才能这样做。

4 Types of Logging 日志的4个级别

· log.error()
    · log.warn()
    · log.info()
    · log.debug()      

There is also a “log.fatal()” but this is more intended for command-line tools that should stay quiet except for dire problems.

还有一个“log.fatal()”,但是它更多情况下是用于命令行工具,所以除非特别严重的问题,否则还是不要使用。

Logging Exceptions

日志记录异常

If the Exception is significant, at the very minimum, always do this:

如果异常是有实在意义的,最起码,要做到:

try { 
  // Code that might throw an exception... 
} catch (Exception e) { 
  log.error(e, e); 
}      

If you’re sending the stacktraces to a separate log file (more about this below), you can do this:

如果你要将堆栈路径放到另一个文件中(更多相关内容见下文),你可以这样做:

try {
  // Code that might throw an exception...
} catch (Exception e) {
  log.error(e);
  stacktraceLog.error(e,e);
}      

This way the error is in both files, but the actual stacktrace itself is only in the “stacktraces” logger.

这样错误信息就会在两个文件中,但是实际的堆栈路径只在“stacktraces”日志中存在。

Note to log4j developers: Please add the timestamp and level to each line of the stacktrace to keep it grep-friendly. I don’t like doing “grep -C 15” (e.g. show 15 lines before and after)!

log4j开发者注意:请添加时间戳和级别到堆栈路径的每一行来使它便于grep。我不喜欢用“grep -C 15”(例如:显示前后各15行)!

Performance Tweak 性能调优

Before assembling your greppable log statement you may want to check log.isInfoEnabled() or log.isDebugEnabled(). This way you save on some cpu cycles:

在组装你的可grab日志语句之前你可能要检查log.isInfoEnabled() 或者 log.isDebugEnabled()。这种方式可以节省一些cpu周期:

// Uses many cpu cycles:
String fancyLogString = buildFancyLogString();
    
// Does nothing because "debug" is currently disabled in log4j.properties:
log.debug( fancyLogString );
Better:
更优写法:
if ( log.isDebugEnabled() )
{
  // Uses many cpu cycles:
  String fancyLogString = buildFancyLogString();
  // Does nothing because "debug" is currently disabled in log4j.properties:
  log.debug( fancyLogString );
}      

Separate files for different areas of interest 对关注的不同领域用不同文件记录

For each file, you’ll need a separate Logger.

对每一个文件,你需要一个单独的Logger。

private static Logger log = Logger.getLogger( MyClass.class )
private static Logger connectionsLog = Logger.getLogger( "connections." + MyClass.class.getName() )
private static Logger stacktracesLog = Logger.getLogger( "stacktraces." + MyClass.class.getName() )
private static Logger httpLog = Logger.getLogger( "http." + MyClass.class.getName() )      

Configuration 配置

Log4j’s main disadvantage is that the documentation is confusing and hard to navigate. If you are brave, the javadoc for PatternLayout is handy. So is the manual http://logging.apache.org/log4j/docs/manual.html.

Log4j的主要缺点是文档混乱难以浏览。如果你够勇敢,PatternLayout的javadoc是很容易获取的。其手册也一样http://logging.apache.org/log4j/docs/manual.html。

I find log4j configuration much easier to deal with once you have an example:

我发现你一旦有过一个例子,那么log4j的配置就会非常简单:

log.dir=/var/log/foo
rrd.dir=${log.dir}/rrd
datestamp=yyyy-MM-dd/HH:mm:ss.SSS/zzz
roll.pattern.hourly=.yyyy-MM-dd.HH
roll.pattern.daily=.yyyy-MM-dd      

catchAll.log – Default catch-all.

log4j.rootLogger=DEBUG, defaultLog
log4j.appender.defaultLog=org.apache.log4j.DailyRollingFileAppender
log4j.appender.defaultLog.DatePattern=${roll.pattern.daily}
log4j.appender.defaultLog.File=${log.dir}/catchAll.log
log4j.appender.defaultLog.layout=org.apache.log4j.PatternLayout
log4j.appender.defaultLog.layout.ConversionPattern=%d{${datestamp}} [%t] %-5p %m%n      

foo.log

log4j.logger.com.foo.shared=INFO,fooLog
log4j.logger.com.foo.abc=INFO,fooLog
log4j.additivity.com.foo.shared=false
log4j.additivity.com.foo.abc=false
log4j.appender.fooLog=org.apache.log4j.DailyRollingFileAppender
log4j.appender.fooLog.File=${log.dir}/foo.log
log4j.appender.fooLog.DatePattern=${roll.pattern.hourly}
log4j.appender.fooLog.layout=org.apache.log4j.PatternLayout
log4j.appender.fooLog.layout.ConversionPattern=%d{${datestamp}}%p%m%n      

fooConnections.log

log4j.logger.connections.com.foo=INFO,fooConnections
log4j.additivity.connections=false
log4j.appender.fooConnections=org.apache.log4j.DailyRollingFileAppender
log4j.appender.fooConnections.File=${log.dir}/fooConnections.log
log4j.appender.fooConnections.DatePattern=${roll.pattern.daily}
log4j.appender.fooConnections.layout=org.apache.log4j.PatternLayout
log4j.appender.fooConnections.layout.ConversionPattern=%d{${datestamp}}%p%m%n      

fooStacktraces.log

log4j.logger.stacktraces.com.foo=INFO,stacktraces
log4j.additivity.stacktraces=false
log4j.appender.stacktraces=org.apache.log4j.DailyRollingFileAppender
log4j.appender.stacktraces.File=${log.dir}/fooStacktraces.log
log4j.appender.stacktraces.DatePattern=${roll.pattern.daily}
log4j.appender.stacktraces.layout=org.apache.log4j.PatternLayout
log4j.appender.stacktraces.layout.ConversionPattern=%d{${datestamp}}%p%m%n
Notice the use of property substitution! Very handy! Also, since I use single-character level strings (* instead of ERROR), I don't have to put spaces before and after %p.      

注意属性替换的用法!非常方便!并且,自从我使用单字符级别字符串(用*代替ERROR),我就不用在%p前后再加空格了。

Loading Configuration 加载配置

Log4j will automatically load the configuration if it is stored in a file called “log4j.properties” and is present on the classpath under “” (e.g. WEB-INF/classes/log4j.properties).

如果配置保存在名为“log4j.properties”的文件中,并且位于classpath下(例如:WEB-INF/classes/log4j.properties),Log4j就会自动加载它。

I don’t like that approach and prefer to load the configuration explicitly by calling:

我不喜欢这种用法,我喜欢明确的调用下面方法来加载配置:

PropertyConfigurator.configure( Config.ETC + "/log4j.properties" );      

This way I can reload the configuration at any time as long as my application is still running. I like to add a button to an administrative jsp, “Reload Log4J”.

通过这种方式我可以在任何时间重新加载配置,只要我的应用还在运行。我喜欢添加一个按钮到jsp管理页面,“重新加载Log4J”。

Dynamic Log File Location 动态日志文件位置

Many people complain that Log4j forces you to hard-code the location where your logs will be kept. Actually, it is possible to dynamically choose the log-file location, especially if you use the {log.dir}属性替换技术时。具体如下:

String dynamicLog = // log directory somehow chosen...
Properties p = new Properties( Config.ETC + "/log4j.properties" );
p.put( "log.dir", dynamicLog ); // overwrite "log.dir"
PropertyConfigurator.configure( p );      

Log rotation and archival 日志替换和归档

WARNING: Log4J has some catastrophic bugs (logs accidentally deleted) if more than one running JVM tries to rotate the same target log file. This is especially likely to happen if two instances of the same application are running in parallel in separate processes (e.g. two Tomcat instances), but both use identical log4j.properties.

警告:Log4J存在一些灾难性的bug(日志意外删除),如果一个以上的运行中的JVM试图替换相同的目标日志文件就可能出现。这特别有可能发生在两个相同的应用实例同时运行在两个进程中(例如:两个Tomcat实例),但是两者都使用同一个log4j.properties配置文件。

Logs should be rotated every hour, or every day. They should not be rotated by size (e.g. every 100MB). A log file containing only events between “13:00:00.000-13:59:59.999” is inherently organized in a way useful for humans, whereas a log file containing exactly 100MB of data is not.

日志文件应该每个小时或每天替换一次。它们不应该按大小(如:每100MB)来替换。一个仅包含“13:00:00.000-13.59.59.999”之间的事件的日志文件本质上是按对人有用的方式来组织的,而一个正好包含100MB数据的日志文件则不是的。

Log4j handles hourly/daily log rotation very nicely:

Log4j对每小时/每天的日志替换掌控的非常好:

log4j.appender.defaultLog=org.apache.log4j.DailyRollingFileAppender
log4j.appender.defaultLog.DatePattern=.yyyy-MM-dd.HH      

This particular config rotates the log every hour (yyyy-MM-dd.HH).

这种特有的配置每小时(yyyy-MM-dd.HH)替换一次日志。

Logs should be periodically gzipped and moved to a server devoted to log-archival. This should happen every night, or every hour. Archival is also a good stage to run all logs through the unix “sort” command to reestablish chronologically in case some events were logged out-of-order.

日志文件应该定期用gzip压缩并移动到一个专门的档案日志服务器。应该每天晚上,或者每小时这样做一次。在一些事件在记录时顺序被打乱的情况下,归档是一个很好的阶段来运行unix的“sort”命令来重建事件的时间顺序。

You should be arhiving logs on QA as well as Production, so that you can make sure you got it right.

你应该将QA日志和生产日志都归档,从而确保能得到正确的日志。

Personally I prefer gzip to bzip2. bzip2 makes smaller files, but it is a lot slower! When viewing compressed logs, use zgrep (or bzgrep). In other words, don’t decompress the logs to disk. Just decompress them to standard-out and run grep against that. You may also want to look into these related commands: zcat, zdiff, zcmp, zless.

从个人角度比起bzip2我更喜欢gzip。bzip2可以使文件更小,但是他太慢了!当浏览压缩的日志时,使用zgrep(或bzgrep)。换句话说,不要将日志解压缩到磁盘上。只要把他们解压缩到标准输出并对其运行grep即可。你也可以查看一些相关的命令:zcat,zdiff,zcmp,zless。

A Log Rotation Best Practice That Is Currently Not Possible 一个目前还不可能的日志替换最佳实践

When a log file rotates (either because of size, or daily/hourly), the first line of the new log file should contain important version information about the running application:

当一个日志文件替换时(无论是因为大小还是每天/每小时),新日志文件的第一行应包含运行中的应用的重要版本信息:

2008-06-06/09:00:00.000 APP=[FooApp-1.2.3] UPTIME=[382 Days, 10:51:11.231] VM=[Java HotSpot™ Client VM 1.4.2_16-b05] OS=[Windows XP 5.1 x86] CONTAINER=[Apache Tomcat/5.0.30] HEAP=[69MB/281MB 24.6%]

Additional log-related investigations become possible with this at the top of every rotated log file. For example, “Did the application encounter more of bug X when we upgraded the Linux kernel?” or “How much did response time improve after we upgraded Java?” Analyses like these are impossible without a “version-line” at the top of each log file.

有了这些信息在每个日志文件的顶部将会使附加的日志相关调查成为可能。举个例子,“在我们升级了Linux内核后应用是否遇到更多的bug X?”,或者“我们升级了Java后应答时间提高了多少?”。每个日志文件顶部没有“版本行”的话要做这些分析都是不可能的。

That version line should also print in the middle of the current log whenever the application restarts. The “version line” should be sent to all active log files. So if log4j.properties is managing 100 files, then all 100 should get this line. Personally, I would even recommend that during really quiet times logging frameworks should still create the file, and log the single version line, even if no other log events occurred during the day or hour in question. This way the absence of the file in the log archive would almost always mean “the application was shut down,” rather than “the application was either shut down, or was not doing anything,” as it currently means.

这个版本行还应该在任何时候应用重启时打印在当前日志中。“版本行”应该被送到所有的活动日志文件中。这样如果log4j.properties管理着100个文件,那么这100个文件都应该含有这一行日志。个人看来,我甚至建议经过了一段真的很安静的时间日志框架页仍应该创建这个文件,并记录一个版本行,即便没有其他日志事件在上述的一天或小时中出现。通过这种方式日志存档中如果缺失了这个文件就说明“应用停止了”,而不是意味着“应用要么停止了,要么什么也没做”。

Unfortunately, this “version line” feature is not possible in any existing Java logging framework. Hopefully one day someone will implement it. (Why is everyone looking at me?)

不幸的是,这个“版本行”特性在现有的任何Java日志框架中都是不可能的。希望有一天有人能实现它。(干嘛所有人都看着我啊?)

Cosmetic considerations 美化相关考虑

Consider this log snippet.

考虑这个日志片段。

2004-09-28/18:37:35.138/PDT Loading FooApp configuration from /home/julius/dev/foo/webapps/foo/WEB-INF/etc/foo.xml
2004-09-28/18:37:35.938/PDT 200-HEAD 325ms 0.0kB KEY=GOOGLE DST=http://www.google.ca/ [health]
2004-09-28/18:37:35.939/PDT!400-HEAD 238ms 0.0kB KEY=DLL DST=http://192.1.2.3/cgi-bin/cgi.dll/ext/ [health]
2004-09-28/18:37:37.745/PDT*ECHOSERVER DST=socket(localhost:5555) [java.net.ConnectException: Connection refused]
2004-09-28/18:37:41.886/PDT 200-HEAD 6306ms 0.0kB KEY=SOAP DST=https-easy://198.5.6.7/ [health]
2004-09-28/18:37:43.083/PDT*Timeout  7501ms KEY=TXN DST=http://10.1.2.3:8080/ [health]
2004-09-28/18:37:47.750/PDT ECHOSERVER DST=socket(localhost:5555) [Connected!]
2004-09-28/18:39:47.429/PDT*Timeout  7502ms KEY=TXN SRC=localhost.localdomain DST=http://10.1.2.3:8080/blah [bar:xyz foo:5050]
2004-09-28/18:40:44.581/PDT!com.foo.net.TimeoutException: Timeout  7501ms KEY=TXN DST=http://10.1.2.3:8080/ [client.executeMethod() failed]
2004-09-28/18:40:51.778/PDT!404-GET  86ms 1.22kB KEY=GOOGLE SRC=localhost.localdomain DST=http://www.google.ca/blah [bar:hamburger foo:5050]
2004-09-28/18:41:03.480/PDT SOCKET   558ms 0.26kB KEY=ECHOSERVER SRC=localhost.localdomain DST=DST=socket(localhost:5555) [bar:hamburger foo:5050]
2004-09-28/18:41:06.016/PDT SOCKET   13ms 0.26kB KEY=ECHOSERVER SRC=localhost.localdomain DST=DST=socket(localhost:5555) [bar:hamburger foo:5050]
2004-09-28/18:41:08.562/PDT SOCKET   7ms 0.26kB KEY=ECHOSERVER SRC=localhost.localdomain DST=DST=socket(localhost:5555) [bar:hamburger foo:5050]
2004-09-28/18:43:53.553/PDT!com.foo.net.TimeoutException: Timeout  7502ms KEY=TXN DST=http://10.1.2.3:8080/blah [client.executeMethod() failed]
2004-09-28/22:05:12.950/PDT*ECHOSERVER DST=socket(localhost:5555) [Closed]      

I’m trying to keep earlier parts of the log statement aligned. Notice the “millisecond” response-time reads are aligned.

我试图将保持日志语句的前面部分对齐。注意“毫秒”响应时间读取是对齐的。

I find ! * + and [space] more convenient to work with than the verbose “INFO, DEBUG, ERROR, WARN”. They are a little trickier to grep for, though, since the shell will try to expand them. I use single-quotes to stop the shell from interfering:

grep '*'    foo.log    Find all errors in log.
grep '!'    foo.log    Find all warnings in log.
grep '*|!' foo.log    Find all warnings AND errors in log!  The pipe is the OR operator in grep, but it needs backslash protection.      

我发现 ! * + 和[空格]使用起来比冗长的“INFO, DEBUG, ERROR, WARN”更加合适。尽管他们grep起来会有点麻烦,因为shell会尝试扩展他们。我用单引号来避免shell的多事:

grep '*'    foo.log    找出日志中所有的错误。
grep '!'     foo.log    找出日志中所有的警告。
grep '*|!'  foo.log    找出日志中所有的错误和警告!管道符在grep中是“或”操作, 但是它需要反斜杠的保护。      
package org.apache.log4j;
public class LevelChanger {
    public static void changeLevels() {
        Level.DEBUG.levelStr = "_";
        Level.INFO.levelStr = " ";
        Level.WARN.levelStr = "!";
        Level.ERROR.levelStr = "*";
        Level.FATAL.levelStr = "***";
    }
}