Log4J基本应用

Introduction
  Log4j是一个开源代码的项目(Opensourceproject),它使开发人员能最大限度的灵活控制程序调试信息的输出，这一点它是通过额外的配置文件实现的。而且log4j开发包很容易上手，同时可能会使一些开发人员上瘾。
  绝大多数的大型开发项目都有它们自己专门用于记录程序日志和对程序跟踪调试的API。许多经验证明，调试信息的管理在软件开发过程中扮演了十分重要的角色。日志管理通常提供了以下的几点好处：首先，它能在程序运行过程中精确的提供运行时的上下文(context)方便我开发人员找到BUG,一旦在程序中加入了Log输出的代码，程序运行过程中就能自动的生成并输出logging信息。其次，log信息可以输出到不同的地方（控制台，文件，日志服务器等等）以备时候研究。最后，除了在开发过程中发挥它的作用外，一个功能足够强大的日志记录开发包能当作一个审计工具(audittool)使用。
  为了能够适应以上的规律，早在1996年EUSEMPER(SecureElectronicMarketplaceforEurope)项目组决定开发自己的日志管理开发包(tracingAPI)，经过了无数次的改动和功能加强，最终诞生了log4j——一个十分广受欢迎的javalogging开发工具包。这个开发工具包的发行遵循IBMPublicLicense，certifiedbytheopensourceinitiative。
  同时，Logging确实也存在一些缺陷，比如，它影响了程序运行的速度，增加了代码的开销，增加了许多无谓的输出。为了减少这些负面因数的影响，log4j被设计得尽量的高效和灵活。因为，很少有哪个应用程序（系统）把记录日志当作主要的功能，log4j的开发人员尽量使log4j容易理解和使用。
  这篇文章首先描述log4j的大致框架和重要的组成部分。作者通过一些简单的例子来说明如何使用log4j。
Categories,appenders,andlayouts
Log4j最主要的三大基本构件：
1．Categories（对log信息进行分类筛选，通俗的讲就是什么信息应该被输出，什么log信息应该被忽略）
2．Appenders（定义了log信息输出的设备，log信息应该被输出到什么地方，控制台、文件、网络设备等）
3．Layouts（对log信息进行格式化）
软件开发人员能通过这三大构件实现根据日志的类型和优先级进行记录，并且能在程序运行时去控制log信息输出的格式（formatted）和往什么地方输出（控制台、log文件），让我们依次去了解他们。
Categoryhierarchy
  与System.out.println方式输出调试信息相比，一个专门的日志控制工具(loggingAPI)的最组要优点在于它能够在适当的时候关闭一些调试信息输出以不影响其他人的调试。这种能力的实现决定于程序开发人员能够根据一定的标准对这些logging信息进行分类。
  基于以上原则，org.apache.log4j.Category类实现了整个log4j包的核心，调试信息被根据一般开发人员的习惯进行了分类并命名。和java开发包的分类规则类似，（acategoryissaidtobeaparentofanothercategoryifitsnamefollowedbyadot,isaprofixofthechildcategoryname.）比如，命名为com.foo的category是被命名为com.foo.Bar的category的parent.就象我们习惯的java是java.util的parent，并且是java.util.vector的ancestor一样。
  最上层的Category被称为根(rootcategory)，根category有两个特点:
(1)它总是存在(Italwaysexists)
(2)它的名字不能被直接得到
  在Category类里面，我们通过getRoot()方法得到rootcategory。而静态方法getInstance()实例化所有其他的Category.getInstance()通过调用时传递的叁数得到该被实例化的Category的实例名。Category类的其它方法在下面列出：
packageorg.apache.log4j;
publicCategoryclass{
//Creation&retrievalmethods:
publicstaticCategorygetRoot();
publicstaticCategorygetInstance(Stringname);
//printingmethods:
publicvoiddebug(Stringmessage);
publicvoidinfo(Stringmessage);
publicvoidwarn(Stringmessage);
publicvoiderror(Stringmessage);
//genericprintingmethod:
publicvoidlog(Priorityp,Stringmessage);
}
  我们可以通过org.apache.log4j.Priority类中的set方法定义一个Category的优先级。（设置的Category的优先级别和传统的UnixSyslog定义的级别一样）。但log4j仅鼓励使用以下的四个优先级别：ERROR,WARN,INFO和DEBUG,这四个级别的优先级为ERROR> WARN> INFO> DEBUG。但org.apache.log4j.Propority中的set方法提供了更高的灵活性，即用户可以通过Priority类的子类去定义自己的优先级。如果一个category没有被定义自己的优先级别，它将继承最接近的祖先所定义的优先级别。这样就保证了所有的Category最终都继承一个优先级别（因为根category总是有一个默认的优先级定义）。
  我们获得了一个Category的实例以后，就可以通过调用以下的方法输出调试信息：
1.error()输出ERROR级别的调试信息
2.warn()输出WARN级别的调试信息
3.info()输出INFO级别的调试信息
4.debug()输出DEBUG级别的调试信息
5.log()普通的LOG信息
  根据定义，以上的5个方法将自己判断输出信息的优先级别。打个比方，假如c是一个Category类的实例，那么语句c.info(“……”)只有在优先级达到INFO级的输出请求（Aloggingrequest）时候才被执行。
  日志输出请求(Aloggingrequest)是指当调试级别高于或等于该级别的时候才被允许执行。否则，被认为这个日志输出请求为不允许，一个没有被定义优先级别的category将自动根据层次关系从它的parent或ancestor继承优先级别。
  通过下面的程序段，你将发现这个规则：
//getacategoryinstancenamed"com.foo "
Categorycat=Category.getInstance( "com.foo ");
//Nowsetitspriority.
cat.setPriority(Priority.INFO);
Categorybarcat=Category.getInstance( "com.foo.Bar ");
//Thisrequestisenabled,becauseWARN> =INFO.
cat.warn( "Lowfuellevel. ");
//Thisrequestisdisabled,becauseDEBUG<INFO.
cat.debug( "Startingsearchfornearestgasstation. ");
//Thecategoryinstancebarcat,named"com.foo.Bar ",
//willinherititspriorityfromthecategorynamed
//"com.foo "Thus,thefollowingrequestisenabled
//becauseINFO> =INFO.
barcat.info( "Locatednearestgasstation. ");
//Thisrequestisdisabled,becauseDEBUG<INFO.
barcat.debug( "Exitinggasstationsearch ");
  如果通过一样的叁数多次调用getInstance()方法将返回第一次调用时生成的category对象的引用。因此，通过这种方式我们可以配置一个Category然后不需要其他额外的处理就能在其他地方得到这个对象。Category能通过任何顺序创建和配置。有一点值得注意的就是一个parentcategory回自动找到并连接属于他的child的cagetory，即使，他是在他的childcategory之后被定义。Log4j通常是在程序或类被初始化的时候被设定的。最好的方式是通过额外的配置文件去定义log4j的配置信息，接下来我们将简要的讨论这方面的内容。
  Log4j允许通过程序构件的名称去定义Category的名字。这样我们就可以为每一个java类文件名（包含该类的包名）定义一个Category，这是一种有用并且直观的category实例名的定义方式。并且这样我们就能方便的从大量log信息中判断出它们各自的来源。当然了，那不是硬性规定的，实际上Log4j没有对设置category的实例名做什么限制，程序员可以根据自己的喜好随意定义category的实例名。
Appendersandlayouts
  通过category实现有灵活控制log信息的输出仅是log4j包吸引人的方面之一，Log4j的Appenders类还实现了将log信息输出到许多不同的输出设备中。目前，log4j的Appenders可以实现将log信息输出到以下几种输出设备中：
1.Console
2.Files
3.GUIcomponents
4.Remotesocketservers
5.NTEventLoggers
6.RemoteUNIXSyslogdaemons
  一个Category可以同时被对个appenders引用，也就是说，一个Category的log信息可以同时输出到多个输出设备中。打个比方，假如你使一个rootcategory的log信息输出到console,那么很自然的，这个rootcategory所有被允许输出的log信息将被输出到console，接着，你又定义了一个childcategory，并且设定这个childcategory的log信息输出到Fileappenders，我们假定这个childcategory的名字为C，那么C以及C的childcategory的所有被允许的Log信息将被同时输出到consoleappender和Fileappender。同时值得注意的是，我们可以覆盖这个默认的设置从而避免由于category的继承关系而导致一些戎余appender被自动配置到parentcategory中。
  通常的，用户不但需要自己指定log信息的输出设备，而且，他们还需要配置log信息的输出格式，这个功能是通过和appender类相关的layout类实现的。虽然appender类只是实现了如何将一个格式化过的log信息输出到相关的输出设备，Layout类能够根据用户的需要去格式化log信息的输出。PatternLayout是log4j发行包中的一部分，它提供了和C语言中的printf方法一样的灵活性去让程序员自己格式化log信息。
  例如，格式化语句%r[%t]%-5p%c-%m%n将产生以下的输出格式：
176[main]INFOorg.foo.Bar–Locatednearestgasstation
格式说明如下：
第一个区域“176”等于程序从开始运行到打印出这个信息所运行的毫秒数
第二个区域“[main]”是输出这个log信息的线程
第三个区域“INFO”是这个log语句所属的优先级
第四个区域“org.foo.Bar”是输出这个log信息的Category的实例名
第五个区域“Locatednearestgasstation”这条log信息的内容
Configuration
  在程序中添加这些Log信息的输出语句所须的工作量是不可小视的，调查资料表明，在程序开发过程中，用于输出调试信息所需的代码量估计要占到整个应用程序总代码量的%4左右。因此，即便是最一般大小的应用程序也需要至少包含有几千行的log语句。这样，不需要我们人工地去维护这些log输出的语句就变的十分重要了。
  虽然，Log4j开发包能够在代码中去灵活控制log输出，但是通过配置文件去实现Log信息的控制比在代码中实现灵活得多。目前，Log4j的配置文件支持XML格式和JAVAproperties(key=value)格式。
  下面我们举个例子：
importcom.foo.Bar;
//Importlog4jclasses.
importorg.apache.log4j.Category;
importorg.apache.log4j.BasicConfigurator;
publicclassMyApp{
//Defineastaticcategoryvariablesothatitreferencesthe
//Categoryinstancenamed"MyApp ".
staticCategorycat=Category.getInstance(MyApp.class.getName());
publicstaticvoidmain(String[]args){
//Setupasimpleconfigurationthatlogsontheconsole.
BasicConfigurator.configure();
cat.info( "Enteringapplication. ");
Barbar=newBar();
bar.doIt();
cat.info( "Exitingapplication. ");
}
}
  正象大家所看到的，MyApp类首先引入log4j包中的相关类，然后定义一个命名为MyApp的静态的Category实例，大家注意到这个Category的名字恰好和MyApp的类名一样。
MyApp类还使用到了被定义在com.foo包中的Bar类：
packagecom.foo;
importorg.apache.log4j.Category;
publicclassBar{
staticCategorycat=Category.getInstance(Bar.class.getName());
publicvoiddoIt(){
cat.debug( "Diditagain! ");
}
}
  类MyApp是通过调用了BasicConfigurator.configure()方法获得了log4j的默认设置的。这个方法将rootCategory设定了一个ConsoleAppender让log信息输出到console。并且log信息的输出被默认的格式化为%-4r[%t]%-5p%c%x-%m%n。还有一点值得注意的是rootcategory的优先级别被默认的定义为Priority.DEBUG级。
  MyApp程序的log输出为：
0[main]INFOMyApp-Enteringapplication.
36[main]DEBUGcom.foo.Bar-Diditagain!
51[main]INFOMyApp-Exitingapplication.
  MyApp类通过调用BasicConfigurator.configure()方法得到log4j的默认配置，其它的类只需要引入org.log4j.Category类并得到一个Category就可以输出log了。
  上面的例子总是输出同样的log信息（除非改变源代码并重新编译，这和直接用System.out.println()函数输出调试信息是一样的）。但幸运的是，log4j允许我们对MyApp程序稍加修改就可以在程序运行时对log信息进行控制。下面是修改后的版本：
importcom.foo.Bar;
importorg.apache.log4j.Category;
importorg.apache.log4j.PropertyConfigurator;
publicclassMyApp{
staticCategorycat=Category.getInstance(MyApp.class.getName());
publicstaticvoidmain(String[]args){
//BasicConfiguratorreplacedwithPropertyConfigurator.
PropertyConfigurator.configure(args[0]);
cat.info( "Enteringapplication. ");
Barbar=newBar();
bar.doIt();
cat.info( "Exitingapplication. ");
}
}
  这个例子中MyApp通过传给PropertyConfigurator（）方法的叁数去指示程序去读取log配置文件。
  下面的是一个配置文件的简单例子，这个配置文件的结果将和log4j的默认配置相同：
#SetrootcategoryprioritytoDEBUGanditsonlyappendertoA1.
log4j.rootCategory=DEBUG,A1
#A1issettobeaConsoleAppenderwhichoutputstoSystem.out.
log4j.appender.A1=org.apache.log4j.ConsoleAppender
#A1usesPatternLayout.
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%-4r[%t]%-5p%c%x-%m%n
  假设我们不在需要包com.foo下的类的log输出，可以把log配置文件改成下面的形式：
log4j.rootCategory=DEBUG,A1
log4j.appender.A1=org.apache.log4j.ConsoleAppender
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
#PrintthedateinISO8601format
log4j.appender.A1.layout.ConversionPattern=%d[%t]%-5p%c-%m%n
#PrintonlymessagesofpriorityWARNoraboveinthepackagecom.foo.
log4j.category.com.foo=WARN
  使用新的配置文件将得到如下的log输出：
2000-09-0714:07:41,508[main]INFOMyApp-Enteringapplication.
2000-09-0714:07:41,529[main]INFOMyApp-Exitingapplication.
  因为categorycom.foo.Bar没有定义优先级别，它就只能从包com.foo中继承优先级别，而在配置文件中，我们给com.foocategory定义的优先级别为WARN。所以，com.foo.Bar类中的doIt()方法的log输出就被禁止了。
  下面，我们在举个例子，下面的配置文件使log信息同时输出到控制台和log文件：
log4j.rootCategory=debug,stdout,R
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
#Patterntooutputthecaller 'sfilenameandlinenumber.
log4j.appender.stdout.layout.ConversionPattern=%5p[%t](%F:%L)-%m%n
log4j.appender.R=org.apache.log4j.RollingFileAppender
log4j.appender.R.File=example.log
log4j.appender.R.MaxFileSize=100KB
#Keeponebackupfile
log4j.appender.R.MaxBackupIndex=1
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=%p%t%c-%m%n
调用这个增强版的配置文件将在控制台上看到如下的输出信息：
INFO[main](MyApp2.java:12)-Enteringapplication.
DEBUG[main](Bar.java:8)-Doingitagain!
INFO[main](MyApp2.java:15)-Exitingapplication.
  同时，上面的配置文件中我们在rootcategory增加了第二个输出对象FileAppender。log信息将同时被输出到example.log文件中。当example.log文件达到100KB的是后，example.log文件将自动被更名为example.log.1同时生成一个新的内容为空的example.log文件。（在英语中被称为rolledover）。
  有一点值得强调的是，我们在修改log信息输出时并不需要重新编译源程序。我们还可以简单的通过修改log配置文件就可以把log信息输出到UnixSyslogdaemon中或输出到NTEventlogger中。甚至我们还可以把log信息输出到远程的专用LOG服务器中。
Nesteddiagnosticcontexts
  当前我们开发的许多系统都需要处理多客户端并发的问题。在这种典型的并发系统中，通常是由不同的线程去分别处理不同的客户端请求的。Log开发工具包在这种情况下发挥了很重要的作用，一般情况下考虑，lot4j可以分别给不同的线程创建不同的Category从而能够从许多的Log信息中区分出那些log输出是属于某个线程的。但这种方式极大地加重了服务器的负担。
为了节约系统开销，log4j的设计者对处理同一类别任务的线程只定义一个Category让他们共同使用，然后在Log信息中增加能够足以区分不同客户端请求的信息。这是通过NDC(NestedDiagnosticContext)类实现的：
publicclassNDC{
//Usedwhenprintingthediagnostic
publicstaticStringget();
//RemovethetopofthecontextfromtheNDC.
publicstaticStringpop();
//Adddiagnosticcontextforthecurrentthread.
publicstaticvoidpush(Stringmessage);
//Removethediagnosticcontextforthisthread.
publicstaticvoidremove();
}
  NDC类为每一个线程单独维护一个保存线程上下文的堆栈。大家注意到，org.apache.log4j.NDC类中所有的方法都是静态的。一旦NDC功能被使用，这些线程上下文堆栈里的信息将被自动地添加到log信息中，而用不着用户去干涉。程序员需要做的只是将正确的信息保存到NDC堆栈中，这是通过push()和pop()方法来实现的。
  为了更进一步说明这一点，我们举个例子。假设我们有一个Servlet程序需要同时处理多个客户端的请求，这个Servlet程序在接到客户端的请求时首先建立创建一个新的线程，然后分配一个用来保存处理该请求的上下文的NDC堆栈，该上下文可能是发出请求的客户端的主机名、IP地址或其他能从请求信息中得到的并能区分不同客户端的信息，在WEB服务器中这些信息一般是在Cookies中维护的。这样即便这个Servlet程序可能同时要处理多个客户端的请求，这些Log信息仍然能够被区分开来，因为不同的客户端处理线程具有不同的NDC堆栈。这看起来就象为不同的客户端请求分别实例化不同的category一样。
Performance
  一些人反对在程序中使用log开发工具包是因为他们认为，log处理增加了程序的开销并影响程序执行的速度。这种看法也有道理，因为即便是一般大小的应用程序至少也需要包含几千个log输出。这是所有log开发工具需要努力解决的问题。Log4j秉承的设计原则是：速度和效率第一，灵活性第二。
  然而，用户仍然需要清楚的了解下面这些与性能相关的数据：
1．Loggingperformancewhenloggingisturnedoff.
当log被禁止时，应用程序仍然需要在方法的辨别和实例化一些叁数上做一些多余的系统开销。如下面的程序段：
cat.debug( "Entrynumber:"+i+"is"+String.valueOf(entry[i]));
即便是log被禁止，变量i和数组entry[i]仍然被初始化。为了尽量地减少这种开销我们最好把以上的代码段改为：
if(cat.isDebugEnabled(){
cat.debug( "Entrynumber:"+i+"is"+String.valueOf(entry[i]));
}
  这样，程序首先判断log功能是否开启，然后再决定是否应该实例化这些在Log代码段里面的变量。然而即便如此，当log功能开启时，程序仍需要做一次多余的判断，但相比之下，isDebugEnabled（）函数的执行时间只有整个log语句执行时间的1%。
  在log4j中，所有log信息的处理主要是由Category类来实现的。Category被设计成类而不是接口，主要是为了减少程序调用的开销，但这是以牺牲接口所能带来的灵活性为代价的。
2．ThePerformanceofdecidingwhethertologornottologwhenloggingisturnedon.
  接下来，最影响性能的因素是Category的层次关系。当log功能被打开时，log4j仍然需要根据不同的Log请求去判断该log信息是否需要输出。并且，有些Category实例化时可能并没有被设定Log信息的优先级别，这种Category必须从他的上一层Category上继承优先级，为了得到他们的优先级别设定，一些Category可能需要搜索他的Parentcategory甚至是它的ancestorcategory。
  Log4j在这方面做了很大的努力，以便使层次间的获得优先级设定的搜索尽可能的快速。
3．Actuallogging
最后一点可能对性能会产生较大影响的就是对log信息的格式化过程了。Log4j也充分地注意到了这一点，并做了优化。通常情况下，一个典型的格式化语句可能需要使用100到300微秒的处理时间。
  虽然，在Log4j开发工具包的设计过程中设计者尽量包含尽可能多的功能特性，但速度一直是他们首要考虑的因素。为了提升运行速度，log4j的许多部件曾经不止一次的被重写过。
Examplesinthereleasepackage
  目前log4j的最新版本号为1.2.4。发行包所带的例子放在examples目录下，下面简要的介绍一下发行包所附带的例子：
Trivial.java
packagesample;
importorg.apache.log4j.Category;
importorg.apache.log4j.Logger;
importorg.apache.log4j.BasicConfigurator;
importorg.apache.log4j.NDC;
publicclassTrivial{
staticLoggercat=Logger.getLogger(Trivial.class.getName());
publicstaticvoidmain(String[]args){
BasicConfigurator.configure();
NDC.push( "Client#45890 ");
cat.info( "Awakeawake.Putonthystrength. ");
Trivial.foo();
InnerTrivial.foo();
cat.info( "ExitingTrivial. ");
}
staticvoidfoo(){
NDC.push( "DB ");
cat.debug( "NowkingDavidwasold. ");
NDC.pop();
}
staticclassInnerTrivial{
staticCategorycat=Category.getInstance(InnerTrivial.class.getName());
staticvoidfoo(){
cat.info( "Enteredfoo. ");
}
}
}
  在编译运行这个例子以前，确保将log4j解压缩目录下的\dist\lib\log4j-1.2.4.jar包加到CLASSPATH中，然后编译，运行该程序，将在控制台上得到如下的输出信息：
0[main]INFOsample.TrivialClient#45890-Awakeawake.Putonthystrength.
10[main]DEBUGsample.TrivialClient#45890DB-NowkingDavidwasold.
40[main]INFOsample.Trivial$InnerTrivialClient#45890-Enteredfoo.
40[main]INFOsample.TrivialClient#45890-ExitingTrivial.
1)首先引入log4j包中的Category类、Logger类（Logger类是Category类的子类，将逐渐替代Category类）、BasicConfigurator类、NDC类。
2)实例化一个静态的Logger类的实例，实例名为sample.Trivial（通过Trivial.class.getName()方法得到）。
3)通过调用BasicConfigurator.configure()方法得到Log4j的默认配置（包括log信息优先级别、输出设备等）。
4)通过调用NDC的push()方法将线程上下文压入NDC堆栈中。
5)调用Logger的info（）方法输出INFO级别的log信息。
注：NDC堆栈内的信息将被保留除非调用了pop()方法。大家注意到在Trivial类里定义了一个名为InnerTrivial的InnerClass并重新获得了一个Category，但InnerTrivial中并不需要调用BasicConfigurator.configure()方法得到基本配置就可以直接调用info()函数输出log信息了，这是因为两个类中的Category具有相同的rootCategory，并都从rootCategory继承了配置信息。Sort.java和SortAlgo.java给出了如何使用配置文件的例子。
简单的如下:
=============================================
importorg.apache.log4j.PropertyConfigurator;
importorg.apache.log4j.Logger;
publicclasslog
{
publicstaticvoidmain(String[]argv)throwsException
{
  Loggerlogger=Logger.getLogger( "MYLOG ");
  PropertyConfigurator.configure(System.getProperty( "log4j.configuration "));
  while(true)
  {
logger.info( "Myinfo ");
logger.debug( "Mydebug ");
logger.error( "Myerror ");
Thread.sleep(3000);
  }
}
}
=================log4j.config======================================
####Usetwoappenders,onetologtoconsole,anothertologtoafile
log4j.rootLogger=debug,stdout,R
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=[%d{yyyy-mm-ddhh:mm},%6.6r]%-5p[%t]%x(%F:%L)-%m%n
log4j.appender.R=org.apache.log4j.DailyRollingFileAppender
log4j.appender.R.file=syslog.log
log4j.appender.R.datePattern= '. 'yyyy-MM-dd-HH-mm
log4j.appender.R.append=true
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=[%d{yyyy-mm-ddhh:mm},%6.6r]%-5p[%t]%x(%F:%L)-%m%n
========================================================
java.exe-Dlog4j.configuration=log4j.config  -classpath"./;./log4j-1.2.4.jar "log