天天看點

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 = "***";
    }
}