深入Log4J源码之Appender.docx

深入Log4J源码之Appender Appender负责定义日志输出的目的地，它可以是控制台（ConsoleAppender）、文件（FileAppender）、JMS服务器（JmsLogAppender）、以Email的形式发送出去（SMTPAppender）等。Appender是一个命名的实体，另外它还包含了对Layout、ErrorHandler、Filter等引用：1publicinterfaceAppender2voidaddFilter(FilternewFilter);3publicFiltergetFilter();4publicvoidclearFilters();5publicvoidclose();6publicvoiddoAppend(LoggingEventevent);7publicStringgetName();8publicvoidsetErrorHandler(ErrorHandlererrorHandler);9publicErrorHandlergetErrorHandler();10publicvoidsetLayout(Layoutlayout);11publicLayoutgetLayout();12publicvoidsetName(Stringname);13publicbooleanrequiresLayout();14简单的，在配置文件中，Appender会注册到Logger中，Logger在写日志时，通过继承机制遍历所有注册到它本身和其父节点的Appender（在additivity为true的情况下），调用doAppend()方法，实现日志的写入。在doAppend方法中，若当前Appender注册了Filter，则doAppend还会判断当前日志时候通过了Filter的过滤，通过了Filter的过滤后，如果当前Appender继承自SkeletonAppender，还会检查当前日志级别时候要比当前Appender本身的日志级别阀门要打，所有这些都通过后，才会将LoggingEvent实例传递给Layout实例以格式化成一行日志信息，最后写入相应的目的地，在这些操作中，任何出现的错误都由ErrorHandler字段来处理。Log4J中的Appender类图结构：在Log4J Core一小节中已经简单的介绍过了AppenderSkeleton、WriterAppender、ConsoleAppender以及 Filter，因小节将直接介绍具体的几个常用的Appender。FileAppender类FileAppender继承自WriterAppender，它将日志写入文件。主要的日志写入逻辑已经在WriterAppender中处理，FileAppender主要处理的逻辑主要在于将设置日志输出文件名，并通过设置的文件构建WriterAppender中的QuiteWriter字段实例。如果Log文件的目录没有创建，在setFile()方法中会先创建目录，再设置日志文件。另外，所有FileAppender字段在调用activateOptions()方法中生效。1protectedbooleanfileAppend=true;2protectedStringfileName=null;3protectedbooleanbufferedIO=false;4protectedintbufferSize=8*1024;56publicvoidactivateOptions()7if(fileName!=null)8try9setFile(fileName,fileAppend,bufferedIO,bufferSize);10catch(java.io.IOExceptione)11errorHandler.error(setFile(+fileName+,+fileAppend12+)callfailed.,e,ErrorCode.FILE_OPEN_FAILURE);1314else15LogLog.warn(Fileoptionnotsetforappender+name+.);16LogLog.warn(AreyouusingFileAppenderinsteadofConsoleAppender?);17181920publicsynchronizedvoidsetFile(StringfileName,booleanappend,21booleanbufferedIO,intbufferSize)throwsIOException22LogLog.debug(setFilecalled:+fileName+,+append);23if(bufferedIO)24setImmediateFlush(false);2526reset();27FileOutputStreamostream=null;28try29ostream=newFileOutputStream(fileName,append);30catch(FileNotFoundExceptionex)31StringparentName=newFile(fileName).getParent();32if(parentName!=null)33FileparentDir=newFile(parentName);34if(!parentDir.exists()&parentDir.mkdirs()35ostream=newFileOutputStream(fileName,append);36else37throwex;3839else40throwex;414243Writerfw=createWriter(ostream);44if(bufferedIO)45fw=newBufferedWriter(fw,bufferSize);4647this.setQWForFiles(fw);48this.fileName=fileName;49this.fileAppend=append;50this.bufferedIO=bufferedIO;51this.bufferSize=bufferSize;52writeHeader();53LogLog.debug(setFileended);54DailyRollingFileAppender类DailyRollingFileAppender继承自FileAppender，不过这个名字感觉有点不靠谱，事实上，DailyRollingFileAppender会在每隔一段时间可以生成一个新的日志文件，不过这个时间间隔是可以设置的，不仅仅只是每隔一天。时间间隔通过setDatePattern()方法设置，datePattern必须遵循SimpleDateFormat中的格式。支持的时间间隔有：1. 每天：.YYYY-MM-dd（默认）2. 每星期：.YYYY-ww3. 每月：.YYYY-MM4. 每隔半天：.YYYY-MM-dd-a5. 每小时：.YYYY-MM-dd-HH6. 每分钟：.YYYY-MM-dd-HH-mmDailyRollingFileAppender需要设置的两个属性：datePattern和fileName。其中datePattern用于确定时间间隔以及当日志文件过了一个时间间隔后用于重命名之前的日志文件；fileName用于设置日志文件的初始名字。在实现过程中，datePattern用于实例化SimpleDateFormat，记录当前时间以及计算下一个时间间隔时间。在每次写日志操作之前先判断当前时间是否已经操作计算出的下一间隔时间，若是，则将之前的日志文件重命名（向日志文件名尾添加datePattern指定的时间信息），并创新的日志文件，同时重新设置当前时间以及下一次的时间间隔。1publicvoidactivateOptions()2super.activateOptions();3if(datePattern!=null&fileName!=null)4now.setTime(System.currentTimeMillis();5sdf=newSimpleDateFormat(datePattern);6inttype=computeCheckPeriod();7printPeriodicity(type);8rc.setType(type);9Filefile=newFile(fileName);10scheduledFilename=fileName11+sdf.format(newDate(file.lastModified();1213else14LogLog.error(EitherFileorDatePatternoptionsarenotsetforappender15+name+.);161718voidrollOver()throwsIOException19if(datePattern=null)20errorHandler.error(MissingDatePatternoptioninrollOver().);21return;222324StringdatedFilename=fileName+sdf.format(now);25if(scheduledFilename.equals(datedFilename)26return;2728this.closeFile();29Filetarget=newFile(scheduledFilename);30if(target.exists()31target.delete();3233Filefile=newFile(fileName);34booleanresult=file.renameTo(target);35if(result)36LogLog.debug(fileName+-+scheduledFilename);37else38LogLog.error(Failedtorename+fileName+to39+scheduledFilename+.);4041try42this.setFile(fileName,true,this.bufferedIO,this.bufferSize);43catch(IOExceptione)44errorHandler.error(setFile(+fileName+,true)callfailed.);4546scheduledFilename=datedFilename;4748protectedvoidsubAppend(LoggingEventevent)49longn=System.currentTimeMillis();50if(n=nextCheck)51now.setTime(n);52nextCheck=rc.getNextCheckMillis(now);53try54rollOver();55catch(IOExceptionioe)56if(ioeinstanceofInterruptedIOException)57Thread.currentThread().interrupt();5859LogLog.error(rollOver()failed.,ioe);606162super.subAppend(event);63按Log4J文档，DailyRollingFileAppender存在线程同步问题。不过本人木有找到哪里出问题了，望高人指点。RollingFileAppender类RollingFileAppender继承自FileAppender，不同于DailyRollingFileAppender是基于时间作为阀值，RollingFileAppender则是基于文件大小作为阀值。当日志文件超过指定大小，日志文件会被重命名成”日志文件名.1”，若此文件已经存在，则将此文件重命名成”日志文件名.2”，一次类推。若文件数已经超过设置的可备份日志文件最大个数，则将最旧的日志文件删除。如果要设置不删除任何日志文件，可以将maxBackupIndex设置成Integer最大值，如果这样，这里rollover()方法的实现会引起一些性能问题，因为它要冲最大值开始遍历查找已经备份的日志文件。1protectedlongmaxFileSize=10*1024*1024;2protectedintmaxBackupIndex=1;3privatelongnextRollover=0;45publicvoidrollOver()6Filetarget;7Filefile;8if(qw!=null)9longsize=(CountingQuietWriter)qw).getCount();10LogLog.debug(rollingovercount=+size);11/ifoperationfails,donotrollagainuntil12/maxFileSizemorebytesarewritten13nextRollover=size+maxFileSize;1415LogLog.debug(maxBackupIndex=+maxBackupIndex);1617booleanrenameSucceeded=true;18/IfmaxBackups0)20/Deletetheoldestfile,tokeepWindowshappy.21file=newFile(fileName+.+maxBackupIndex);22if(file.exists()23renameSucceeded=file.delete();2425/Map(maxBackupIndex-1),2,1tomaxBackupIndex,3,26/227for(inti=maxBackupIndex-1;i=1&renameSucceeded;i-)28file=newFile(fileName+.+i);29if(file.exists()30target=newFile(fileName+.+(i+1);31LogLog.debug(Renamingfile+file+to+target);32renameSucceeded=file.renameTo(target);33343536if(renameSucceeded)37/RenamefileNametofileName.138target=newFile(fileName+.+1);39this.closeFile();/keepwindowshappy.40file=newFile(fileName);41LogLog.debug(Renamingfile+file+to+target);42renameSucceeded=file.renameTo(target);43/44/iffilerenamefailed,reopenfilewithappend=true45/46if(!renameSucceeded)47try48this.setFile(fileName,true,bufferedIO,bufferSize);49catch(IOExceptione)50if(einstanceofInterruptedIOException)51Thread.currentThread().interrupt();5253LogLog.error(setFile(+fileName54+,true)callfailed.,e);555657585960/61/ifallrenamesweresuccessful,then62/63if(renameSucceeded)64try65this.setFile(fileName,false,bufferedIO,bufferSize);66nextRollover=0;67catch(IOExceptione)68if(einstanceofInterruptedIOException)69Thread.currentThread().interrupt();7071LogLog.error(setFile(+fileName+,false)callfailed.,e);7273747576publicsynchronizedvoidsetFile(StringfileName,booleanappend,77booleanbufferedIO,intbufferSize)throwsIOException78super.setFile(fileName,append,this.bufferedIO,this.bufferSize);79if(append)80Filef=newFile(fileName);81(CountingQuietWriter)qw).setCount(f.length();828384protectedvoidsetQWForFiles(Writerwriter)85this.qw=newCountingQuietWriter(writer,errorHandler);8687protectedvoidsubAppend(LoggingEventevent)88super.subAppend(event);89if(fileName!=null&qw!=null)90longsize=(CountingQuietWriter)qw).getCount();91if(size=maxFileSize&size=nextRollover)92rollOver();939495AsyncAppender类AsyncAppender顾名思义，就是异步的调用Appender中的doAppend()方法。有多种方法实现这样的功能，比如每当调用doAppend()方法时，doAppend()方法内部启动一个线程来处理这一次调用的逻辑，这个线程可以是新建的线程也可以是线程池，然而我们知道线程是一个比较耗资源的实体，为每一次的操作都创建一个新的线程，而这个线程在这一次调用结束后就不再使用，这种模式是非常不划算的，性能低下；而且即使在这里使用线程池，也会导致在非常多请求同时过来时引起消耗大量的线程池中的线程或者因为线程池已满而阻塞请求。因而这种直接使用线程去处理每一次的请求是不可取的。另一种常用的方案可以使用生产者和消费中的模式来实现类似的逻辑。即每一次请求做为一个生产者，将请求放到一个Queue中，而由另外一个或多个消费者读取Queue中的内容以处理真正的逻辑。在最新的Java版本中，我们可以使用BlockingQueue类简单的实现类似的需求，然而由于Log4J的存在远早于BlockingQueue的创建，因而为了实现对以前版本的兼容，它还是自己实现了这样一套生产者消费者模型。AsyncAppender并不会在每一次的doAppend()调用中都直接将消息输出，而是使用了buffer，即只有等到buffer中LoggingEvent实例到达bufferSize个的时候才真正的处理这些消息，当然我们也可以讲bufferSize设置成1，从而实现每一个LoggingEvent实例的请求都会直接执行。如果bufferSize设置过大，在应用程序异常终止时可能会丢失部分日志。1publicstaticfinalintDEFAULT_BUFFER_SIZE=128;2privatefinalListbuffer=newArrayList();3privatefinalMapdiscardMap=newHashMap();4privateintbufferSize=DEFAULT_BUFFER_SIZE;5privatefinalThreaddispatcher;6privatebooleanlocationInfo=false;7privatebooleanblocking=true;对其他字段，discardMap用于存放当当前LoggingEvent请求数已经超过bufferSize或当前线程被中断的情况下能继续保留这些日志信息；locationInfo用于设置是否需要保留位置信息；blocking用于设置在消费者正在处理时，是否需要生产者“暂停”下来，默认为true；而dispatcher即是消费者线程，它在构建AsyncAppender是启动，每次监听buffer这个list，如果发现buffer中存在LoggingEvent实例，则将所有buffer和discardMap中的LoggingEvent实例拷贝到数组中，清空buffer和discardMap，并调用AsyncAppender内部注册的Appender实例打印日志。1publicvoidrun()2booleanisActive=true;3try4while(isActive)5LoggingEventevents=null;6synchronized(buffer)7intbufferSize=buffer.size();8isActive=!parent.closed;910while(bufferSize=0)&isActive)11buffer.wait();12bufferSize=buffer.size();13isActive=!parent.closed;1415if(bufferSize0)16events=newLoggingEventbufferSize17+discardMap.size();18buffer.toArray(events);19intindex=bufferSize;2021for(Iteratoriter=discardMap.values().iterator();iter22.hasNext();)23eventsindex+=(DiscardSummary)iter.next()24.createEvent();2526buffer.clear();27discardMap.clear();28buffer.notifyAll();293031if(events!=null)32for(inti=0;ievents.length;i+)33synchronized(appenders)34appenders.appendLoopOnAppenders(eventsi);3536373839catch(InterruptedExceptionex)40Thread.currentThread().interrupt();4142这里其实有一个bug，即当程序停止时只剩下discardMap中有日志信息，而buffer中没有日志信息，由于Dispatcher线程不检查discardMap中的日志信息，因而此时会导致discardMap中的日志信息丢失。即使在生成者中当buffer为空时，它也会激活buffer锁，然而即使激活后buffer本身大小还是为0，因而不会处理之后的逻辑，因而这个逻辑也处理不了该bug。对于生产者，它首先处理当消费者线程出现异常而不活动时，此时将同步的输出日志；而后根据配置获取LoggingEvent中的数据；再获得buffer的对象锁，如果buffer还没满，则直接将LoggingEvent实例添加到buffer中，否则如果blocking设置为true，即生产者会等消费者处理完后再继续下一次接收数据。如果blocking设置为fasle或者消费者线程被打断，那么当前的LoggingEvent实例则会保存在discardMap中，因为此时buffer已满。1publicvoidappend(finalLoggingEventevent)2if(dispatcher=null)|!dispatcher.isAlive()|(bufferSize=0)3synchronized(appenders)4appenders.appendLoopOnAppenders(event);56return;78event.getNDC();9event.getThreadName();10event.getMDCCopy();11if(locationInfo)12event.getLocationInformation();1314event.getRenderedMessage();15event.getThrowableStrRep();16synchronized(buffer)17while(true)18intpreviousSize=buffer.size();19if(previousSize=bufferSize)22flushBuffer();2324publicvoidflushBuffer()25removes.ensureCapacity(buffer.size();26for(Iteratori=buffer.iterator();i.hasNext();)27try28LoggingEventlogEvent=(LoggingEvent)i.next();29Stringsql=getLogStatement(logEvent);30execute(sql);31removes.add(logEvent);32catch(SQLExceptione)33errorHandler.error(Failedtoexcutesql,e,34ErrorCode.FLUSH_FAILURE);353637buffer.removeAll(removes);38removes.clear();3940protectedStringgetLogStatement(LoggingEventevent)41returngetLayout().format(event);4243protectedvoidexecute(Stringsql)throwsSQLException44Connectioncon=null;45Stat