【飞天奔月出品】剖析logback2:logback启动

飞天奔月

浏览: 520154 次
性别:
来自: 上海

最近访客更多访客>>

chao_t

xinxiangli

Comven_eye

天意之都

博主相关

博客

微博

相册

留言

关于我

文章分类

社区版块

存档分类

博客分类：

logback slf4j

1.logback这货是怎么启动呢？

就系统启动的时候，会自动读取配置文件，以便后续代码执行这操行，那必定是在 static block中执行的

static{

do logic;

}

并且这个类要被加载，static block也好，static变量也好才会执行

关于static block 参见我曾在百度知道的一个回帖

http://zhidao.baidu.com/question/294516388

顺着藤，摸着瓜，果不其然 logback-classic-1.1.13.jar中的 org.slf4j.impl.StaticLoggerBinder类

  /**
   * The unique instance of this class.
   */
  private static StaticLoggerBinder SINGLETON = new StaticLoggerBinder();

  private static Object KEY = new Object();

  static {
    SINGLETON.init();
  }

我们来看看 init()方法

  void init() {
    try {
      try {
        new ContextInitializer(defaultLoggerContext).autoConfig();
      } catch (JoranException je) {
        Util.report("Failed to auto configure default logger context", je);
      }
      // logback-292
      if(!StatusUtil.contextHasStatusListener(defaultLoggerContext)) {
        StatusPrinter.printInCaseOfErrorsOrWarnings(defaultLoggerContext);
      }
      contextSelectorBinder.init(defaultLoggerContext, KEY);
      initialized = true;
    } catch (Throwable t) {
      // we should never get here
      Util.report("Failed to instantiate [" + LoggerContext.class.getName()
          + "]", t);
    }
  }

跟踪代码，发现

step1. 加载配置文件

关于加载配置文件的顺序，可以参看我的这个帖子 logback1.1.13配置文件加载顺序

step2. 构造 contextSelector

我们来看看 ch.qos.logback.classic.util.ContextSelectorStaticBinder.init(LoggerContext, Object) 代码

  public void init(LoggerContext defaultLoggerContext, Object key) throws ClassNotFoundException,
      NoSuchMethodException, InstantiationException, IllegalAccessException,
      InvocationTargetException  {
    if(this.key == null) {
      this.key = key;
    } else if (this.key != key) {
      throw new IllegalAccessException("Only certain classes can access this method.");
    }
    
    
    String contextSelectorStr = OptionHelper
        .getSystemProperty(ClassicConstants.LOGBACK_CONTEXT_SELECTOR);
    if (contextSelectorStr == null) {
      contextSelector = new DefaultContextSelector(defaultLoggerContext);
    } else if (contextSelectorStr.equals("JNDI")) {
      // if jndi is specified, let's use the appropriate class
      contextSelector = new ContextJNDISelector(defaultLoggerContext);
    } else {
      contextSelector = dynamicalContextSelector(defaultLoggerContext,
          contextSelectorStr);
    }
  }

转换成流程图是 :

2.好，那么问题来了，代码中使用 log.debug(叉叉叉),log.info(叉叉叉),log.warn(叉叉叉),log.info(叉叉叉)等等会发生什么事情呢？为毛这里的log 是slf4j的log 会调用到logback的配置呢？

好，带着问题，我们再来走两步

瞧瞧这个简单的 HelloWorldTest 测试类

public class HelloWorldTest{

    /** The Constant log. */
    private static final Logger log = LoggerFactory.getLogger(HelloWorldTest.class);

    @Test
    public void testHelloWorldTest(){
        log.error("hello world");
    }

}

我们上面的问题，其实就发生在 LoggerFactory.getLogger(HelloWorldTest.class)

通过跟踪代码，我们发现初始化 perform Initialization会调用

org.slf4j.LoggerFactory.findPossibleStaticLoggerBinderPathSet() 来查找项目中的 "org/slf4j/impl/StaticLoggerBinder.class" 类

private static Set<URL> findPossibleStaticLoggerBinderPathSet() {
        // use Set instead of list in order to deal with bug #138
        // LinkedHashSet appropriate here because it preserves insertion order during iteration
        Set<URL> staticLoggerBinderPathSet = new LinkedHashSet<URL>();
        try {
            ClassLoader loggerFactoryClassLoader = LoggerFactory.class.getClassLoader();
            Enumeration<URL> paths;
            if (loggerFactoryClassLoader == null) {
                paths = ClassLoader.getSystemResources(STATIC_LOGGER_BINDER_PATH);
            } else {
                paths = loggerFactoryClassLoader.getResources(STATIC_LOGGER_BINDER_PATH);
            }
            while (paths.hasMoreElements()) {
                URL path = (URL) paths.nextElement();
                staticLoggerBinderPathSet.add(path);
            }
        } catch (IOException ioe) {
            Util.report("Error getting resources from path", ioe);
        }
        return staticLoggerBinderPathSet;
    }

当然咯，从代码中可见，如果项目中有多个 org/slf4j/impl/StaticLoggerBinder.class 类会提示 "Class path contains multiple SLF4J bindings."

    private static void reportMultipleBindingAmbiguity(Set<URL> staticLoggerBinderPathSet) {
        if (isAmbiguousStaticLoggerBinderPathSet(staticLoggerBinderPathSet)) {
            Util.report("Class path contains multiple SLF4J bindings.");
            Iterator<URL> iterator = staticLoggerBinderPathSet.iterator();
            while (iterator.hasNext()) {
                URL path = (URL) iterator.next();
                Util.report("Found binding in [" + path + "]");
            }
            Util.report("See " + MULTIPLE_BINDINGS_URL + " for an explanation.");
        }
    }

而 org.slf4j.LoggerFactory.bind()方法中的 StaticLoggerBinder.getSingleton();

首先会加载StaticLoggerBinder类，从而调用本文开头写的static block方法,从而调用 init方法

private final static void bind() {
        try {
            Set<URL> staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet();
            reportMultipleBindingAmbiguity(staticLoggerBinderPathSet);
            // the next line does the binding
            StaticLoggerBinder.getSingleton();
            INITIALIZATION_STATE = SUCCESSFUL_INITIALIZATION;
            reportActualBinding(staticLoggerBinderPathSet);
            fixSubstitutedLoggers();

而这些操作都执行完了，会调用 StaticLoggerBinder.getSingleton().getLoggerFactory() 方法返回

public static ILoggerFactory getILoggerFactory() {
        if (INITIALIZATION_STATE == UNINITIALIZED) {
            INITIALIZATION_STATE = ONGOING_INITIALIZATION;
            performInitialization();
        }
        switch (INITIALIZATION_STATE) {
        case SUCCESSFUL_INITIALIZATION:
            return StaticLoggerBinder.getSingleton().getLoggerFactory();
        case NOP_FALLBACK_INITIALIZATION:
            return NOP_FALLBACK_FACTORY;
        case FAILED_INITIALIZATION:
            throw new IllegalStateException(UNSUCCESSFUL_INIT_MSG);
        case ONGOING_INITIALIZATION:
            // support re-entrant behavior.
            // See also http://bugzilla.slf4j.org/show_bug.cgi?id=106
            return TEMP_FACTORY;
        }
        throw new IllegalStateException("Unreachable code");
    }

我们再来看看 org.slf4j.impl.StaticLoggerBinder.getLoggerFactory() 方法

  public ILoggerFactory getLoggerFactory() {
    if (!initialized) {
      return defaultLoggerContext;
    }

    if (contextSelectorBinder.getContextSelector() == null) {
      throw new IllegalStateException(
          "contextSelector cannot be null. See also " + NULL_CS_URL);
    }
    return contextSelectorBinder.getContextSelector().getLoggerContext();
  }

好，这么一转，又回到了我们之前写的 contextSeletor部分了

从而基本上，我们可以确定，

一般情况下，会使用ch.qos.logback.classic.selector.DefaultContextSelector,使用的是默认的 ch.qos.logback.classic.LoggerContext

3.如果重复调用 Logger log = LoggerFactory.getLogger(HelloWorldTest.class) 会怎么样呢？

改造下代码

public class HelloWorldTest{

    /**
     * TestHelloWorldTest.
     * 
     * @throws InterruptedException
     */
    @Test
    public void testHelloWorldTest() throws InterruptedException{
        Logger log = LoggerFactory.getLogger(HelloWorldTest.class);
        log.error("hello world");
    }
}

从代码中发现，如果第二次调用

  public static ILoggerFactory getILoggerFactory() {
        if (INITIALIZATION_STATE == UNINITIALIZED) {
            INITIALIZATION_STATE = ONGOING_INITIALIZATION;
            performInitialization();
        }
        switch (INITIALIZATION_STATE) {
        case SUCCESSFUL_INITIALIZATION:
            return StaticLoggerBinder.getSingleton().getLoggerFactory();

此处直接返回 StaticLoggerBinder.getSingleton().getLoggerFactory();

由于StaticLoggerBinder 是单例模式的设计，此处不会重复初始化log context

而从LoggerFactory 到log 的过程中，我们发现 log 有 map(ConcurrentHashMap) cache 机制，第一次会通过logger name得到log 会设置到map cache中，第二次，相同的logger name 会直接从map cache 中返回

 public final Logger getLogger(final String name) {

    if (name == null) {
      throw new IllegalArgumentException("name argument cannot be null");
    }

    // if we are asking for the root logger, then let us return it without
    // wasting time
    if (Logger.ROOT_LOGGER_NAME.equalsIgnoreCase(name)) {
      return root;
    }

    int i = 0;
    Logger logger = root;

    // check if the desired logger exists, if it does, return it
    // without further ado.
    Logger childLogger = (Logger) loggerCache.get(name);
    // if we have the child, then let us return it without wasting time
    if (childLogger != null) {
      return childLogger;
    }