Log4j是如何取得行号的(有源码分析)

Log4J是如何打印出行号的呢,之前一直以为是通过JAVA的反射.今天特意去查了一下,JAVA的方式好像没有提供这样的接口.于是研究了一下Log4J的代码,现在分享出来.

 

• 开门见山:

直接开门见山的讲重点, 其实要获得JAVA的行号,Log4j就是先抛出异常,然后在异常堆栈中找到调用函数所在位置. 下面根据下面的一个异常堆栈,来分析如何通过2歩找到找位置的办法.

1)找到org.apache.commons.logging.impl.Log4JLogger所在行

2)接下来,去掉下一行的1个空格,一个"at",就可以得到 "log.Main.main(Main.java:22)"

 

 

 

java.lang.Throwable
	at org.apache.log4j.spi.LoggingEvent.getLocationInformation(LoggingEvent.java:191)
	at org.apache.log4j.helpers.PatternParser$LocationPatternConverter.convert(PatternParser.java:483)
	at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.java:64)
	at org.apache.log4j.PatternLayout.format(PatternLayout.java:503)
	at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:301)
	at org.apache.log4j.WriterAppender.append(WriterAppender.java:159)
	at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:230)
	at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:65)
	at org.apache.log4j.Category.callAppenders(Category.java:203)
	at org.apache.log4j.Category.forcedLog(Category.java:388)
	at org.apache.log4j.Category.log(Category.java:853)
	at org.apache.commons.logging.impl.Log4JLogger.debug(Log4JLogger.java:171)
	at log.Main.main(Main.java:22)

 

 

• 关键代码分析:

Log4j打印出行号,关键就在LocationInfo. 这个Class就是通过对异常堆栈和org.apache.commons.logging.Log的实例(比如:org.apache.commons.logging.impl.Log4JLogger)的处理,来得到fullInfo(比如:log.Main.main(Main.java:22)). 接下来基于fullInfo再得到行号,类名,包名就手到擒来了.

 

下面是LocationInfo的构造函数的分析:
    public LocationInfo(Throwable t, String fqnOfCallingClass) {
      if(t == null)
	return;

      String s;
      // Protect against multiple access to sw.
      synchronized(sw) {
	t.printStackTrace(pw);
	s = sw.toString();
	sw.getBuffer().setLength(0);
      }
      //System.out.println("s is ["+s+"].");
      int ibegin, iend;

      // Given the current structure of the package, the line
      // containing "org.apache.log4j.Category." should be printed just
      // before the caller.

      // This method of searching may not be fastest but it's safer
      // than counting the stack depth which is not guaranteed to be
      // constant across JVM implementations.
	  //找到Log4JLogger对应的行的行头
      ibegin = s.lastIndexOf(fqnOfCallingClass);
      if(ibegin == -1)
	return;

	   //找到Log4JLogger对应的行的行尾
      ibegin = s.indexOf(Layout.LINE_SEP, ibegin);
      if(ibegin == -1)
	return;
	  //后移到下一行的行头,也就是真正需要信息所在行 
      ibegin+= Layout.LINE_SEP_LEN;

      // determine end of line
	  //找到真正需要信息所在行的行尾
      iend = s.indexOf(Layout.LINE_SEP, ibegin);
      if(iend == -1)
	return;

      // VA has a different stack trace format which doesn't
      // need to skip the inital 'at'
      if(!inVisualAge) {
	// back up to first blank character
	//判断,真正信息说在行是否有"at "这个关键字
	ibegin = s.lastIndexOf("at ", iend);
	if(ibegin == -1)
	  return;
	// Add 3 to skip "at ";
	//如果有"at "这样的关键字,就过滤掉.
	ibegin += 3;
      }
      // everything between is the requested stack item
      this.fullInfo = s.substring(ibegin, iend);
    }

 

 

• 来龙去脉:

为了分析Log4j行号的来龙去脉,我写了下面的测试类,

package log;

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;

public class Main {
	/**
	 * Logger for this class
	 */
	private static final Log logger = LogFactory.getLog(Main.class);

	/**
	 * @param args
	 */
	public static void main(String[] args) {
		if (logger.isDebugEnabled()) {
			logger.debug("main(String[]) - start"); //$NON-NLS-1$
		}
		 

		if (logger.isDebugEnabled()) {
			logger.debug("main(String[]) - end"); //$NON-NLS-1$
		}
	}

}

 

 

然后基于上面的代码,跟踪到了如下的调用栈,getLocationInformation就是上面分析得到行号的关键地方.

Thread [main] (Suspended)	
	owns: ConsoleAppender  (id=53)	
	owns: RootLogger  (id=49)	
	LocationInfo.<init>(Throwable, String) line: 146	
	LoggingEvent.getLocationInformation() line: 191	
	PatternParser$LocationPatternConverter.convert(LoggingEvent) line: 483	
	PatternParser$LocationPatternConverter(PatternConverter).format(StringBuffer, LoggingEvent) line: 64	
	PatternLayout.format(LoggingEvent) line: 503	
	ConsoleAppender(WriterAppender).subAppend(LoggingEvent) line: 301	
	ConsoleAppender(WriterAppender).append(LoggingEvent) line: 159	
	ConsoleAppender(AppenderSkeleton).doAppend(LoggingEvent) line: 230	
	AppenderAttachableImpl.appendLoopOnAppenders(LoggingEvent) line: 65	
	Logger(Category).callAppenders(LoggingEvent) line: 203	
	Logger(Category).forcedLog(String, Priority, Object, Throwable) line: 388	
	Logger(Category).log(String, Priority, Object, Throwable) line: 853	
	Log4JLogger.debug(Object) line: 171	
	Main.main(String[]) line: 22