一、Tomcat中啟動IoC容器的日志
啟動Tomcat等容器時,控制台每次都打印出一些日志。
最近剛好在研究Spring源碼,所以換個角度,從啟動日志來簡單的看看Spring的初始化過程!
以下是Tomcat啟動時日志,截取Spring部分。
//------------------------------------- //從這里開始Spring的初始化 十一月 10, 2015 8:52:03 上午 org.apache.catalina.core.ApplicationContext log 信息: Initializing Spring root WebApplicationContext 十一月 10, 2015 8:52:03 上午 org.springframework.web.context.ContextLoader initWebApplicationContext //ApplicationContext的預處理prepareRefresh 信息: Root WebApplicationContext: initialization started 十一月 10, 2015 8:52:04 上午 org.springframework.context.support.AbstractApplicationContext prepareRefresh 信息: Refreshing Root WebApplicationContext: startup date [Tue Nov 10 08:52:04 CST 2015]; root of context hierarchy //XmlBeanDefinitionReader的loadBeanDefinitions,加載bean 十一月 10, 2015 8:52:04 上午 org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDefinitions //<!-- bean定義的配置文件 --> //<context-param> // <param-name>contextConfigLocation</param-name> // <param-value>classpath:applicationContext.xml</param-value> //</context-param> 信息: Loading XML bean definitions from class path resource [applicationContext.xml] //初始化單例的bean //由於applicationContext.xml中定義了數據源所以有dataSource、jdbcTemplate,定義了事務所以有transactionManager、txAdvice 十一月 10, 2015 8:52:06 上午 org.springframework.beans.factory.support.DefaultListableBeanFactory preInstantiateSingletons 信息: Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@6f1ad0:
defining beans [org.springframework.context.annotation.internalConfigurationAnnotationProcessor,
org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.
context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.
internalCommonAnnotationProcessor,dataSource,jdbcTemplate,transactionManager,
org.springframework.aop.config.internalAutoProxyCreator,serviceMethod,org.springframework.aop.support.
DefaultBeanFactoryPointcutAdvisor#0,txAdvice,org.springframework.context.annotation.ConfigurationClassPostProcessor.importAwareProcessor];
root of factory hierarchy //初始化C3P0數據庫連接池 //mchange是C3P0的依賴包 十一月 10, 2015 8:52:06 上午 com.mchange.v2.log.MLog <clinit> 信息: MLog clients using java 1.4+ standard logging. 十一月 10, 2015 8:52:07 上午 com.mchange.v2.c3p0.C3P0Registry banner 信息: Initializing c3p0-0.9.1.2 [built 21-May-2007 15:04:56; debug? true; trace: 10] 十一月 10, 2015 8:52:08 上午 org.springframework.web.context.ContextLoader initWebApplicationContext 信息: Root WebApplicationContext: initialization completed in 4470 ms //到這里完成了WebApplicationContext的初始化 //-------------------------------------
二、大概流程:
1、初始化方法是在ContextLoader.initWebApplicationContext()中完成的;
2、首先進行的是預處理操作:AbstractApplicationContext.prepareRefresh();
3、然后從資源(這里是applicationContext.xml)中讀取bean的解析、加載bean:XmlBeanDefinitionReader.loadBeanDefinitions();
4、實例化單例的bean,實例化scope="singleton"(默認)且無lazy-init="true"的bean:DefaultListableBeanFactory.preInstantiateSingletons();
5、注冊C3P0數據庫連接池:C3P0Registry.banner();
6、到此完成了WebApplicationContext的初始化!
從上面的步奏可以大概看出Spring初始化的步奏,當然每個方法都隱藏了很多細節,后面再逐個慢慢品味吧!
------------------------------------------------------------------------------------------------------
三、打開Debug日志,進一步觀察:
默認的Spring自帶了log4j,但是需要我們配置。如果不配置,像debug沒有打印出來,下面我們將debug等信息輸出到控制台,便於我們分析源碼!
在web.xml中聲明log4.properties,在資源文件中配置:(調到Debug級別)
log4j.rootLogger=DEBUG, R
log4j.appender.R = org.apache.log4j.ConsoleAppender log4j.appender.R.Target = System.out log4j.appender.R.layout = org.apache.log4j.PatternLayout log4j.appender.R.layout.ConversionPattern =[SSH] %p %d{yyyy-MM-dd HH:mm:ss.SSS} %c %m(%L) %n
然后,我們就可以看到debug日志了!
關鍵日志分析:
可以結合Bean的生命周期一起分析:
為了便於觀察,applicationContext.xml中只配置最基本的bean
<bean id="book" name="book" class="com.sky.vo.Book" init-method="productBook" destroy-method="destroyBook"> <property name="title" value="小王子"/> </bean> <bean id="myBeanFactoryPostFactory" class="com.sky.processor.MyBeanFactoryPostFactory"/> <bean id="myBeanPostProcessor" class="com.sky.processor.MyBeanPostProcessor"/>
四、下面是日志的分析過程:
搜索web.xml中的配置信息
Adding [servletContextInitParams] PropertySource with lowest search precedence(107)
XmlWebApplicationContext
XmlWebApplicationContext Refreshing Root WebApplicationContext: startup date [Thu Nov 19 11:18:22 CST 2015]; root of context hierarchy(513)
從XML中讀取bean定義信息
XmlBeanDefinitionReader Loading XML bean definitions from class path resource [applicationContext.xml](315)
使用到了Reader,從applicationContext.xml中讀到三個bean(book和myBeanPostProcessor,還有BeanFactoryPostFactory)
注:定義了后置處理器,除了實現BeanPostProcessor接口,然后像普通bean一樣在xml中配置即可!
XmlBeanDefinitionReader Loaded 3 bean definitions from location pattern [classpath:applicationContext.xml](216)
給ApplicationContext配置BeanFactory,中找到<bean id="book">,<bean id="myBeanPostProcessor">的定義
XmlWebApplicationContext Bean factory for Root WebApplicationContext:
org.springframework.beans.factory.support.DefaultListableBeanFactory@148d148:
defining beans [book,myBeanFactoryPostFactory,myBeanPostProcessor]; root of factory hierarchy(543)
首先實例化單例的BeanFactoryPostProcessor,Spring容器后置處理器
DefaultListableBeanFactory Creating shared instance of singleton bean 'myBeanFactoryPostFactory'(215) DefaultListableBeanFactory Creating instance of bean 'myBeanFactoryPostFactory'(432)
調用了他的構造方法,於是控制台打印了:MyBeanFactoryPostProcessor構造初始化
為了解決bean的循環依賴,也把這個容器后置處理器像普通bean一樣緩存起來了
Eagerly caching bean 'myBeanFactoryPostFactory' to allow for resolving potential circular references(506)
到這一步時,完成了Spring容器后置處理器的實例化
DefaultListableBeanFactory Finished creating instance of bean 'myBeanFactoryPostFactory'(460)
同時馬上調用了容器后置處理器的方法,打印出了:MyBeanFactoryPostProcessor調用了postProcessBeanFactory
接下來,實例化BeanPostProcessor后置處理器
DefaultListableBeanFactory Creating shared instance of singleton bean 'myBeanPostProcessor'(215) DefaultListableBeanFactory Creating instance of bean 'myBeanPostProcessor'(432)
到這里時,完成了后置處理器的初始化,構造方法被調用了:
控制台輸出了:這是自定義的BeanPostProcessor 初始化
然后,像普通的bean那樣,緩存下來,以解決潛在的bean循環依賴的問題
DefaultListableBeanFactory Eagerly caching bean 'myBeanPostProcessor' to allow for resolving potential circular references(506)
繼續執行,完成了BeanPostProcessor這個后置處理器的實例化
DefaultListableBeanFactory Finished creating instance of bean 'myBeanPostProcessor'(460)
給ApplicationContext配置其他,如國際化資源、ApplicationContext事件、主題,這里暫時不太明白作用
XmlWebApplicationContext Unable to locate MessageSource with name 'messageSource':
using default [org.springframework.context.support.DelegatingMessageSource@1fb4479](810)
XmlWebApplicationContext Unable to locate ApplicationEventMulticaster with name 'applicationEventMulticaster':
using default [org.springframework.context.event.SimpleApplicationEventMulticaster@1c57594](834)
UiApplicationContextUtils Unable to locate ThemeSource with name 'themeSource':
using default [org.springframework.ui.context.support.ResourceBundleThemeSource@1feeacb](85)
預實例化單例bean
DefaultListableBeanFactory Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@fe4495: defining beans [book]; root of factory hierarchy(598)
創建book的bean
DefaultListableBeanFactory Creating shared instance of singleton bean 'book'(215)
DefaultListableBeanFactory Creating instance of bean 'book'(432)
到這里后,開始調用了構造函數,輸出了我寫的sysout: 控制台:"調用了Book默認構造函數"
緩存id為book的bean,解決潛在的循環引用!
DefaultListableBeanFactory Eagerly caching bean 'book' to allow for resolving potential circular references(506)
到這里后,調用了setting注入屬性title,控制台輸出了我寫在setTitle方法中語句:set注入了書本標題為:小王子
在setting注入后,隨即輸出的是:bean處理器:bean創建前,表示在注入后,調用了BeanPostProcessor的postProcessBeforeInitialization方法(看方法名也很直觀)
調用InitializingBean接口的afterPropertiesSet方法
DefaultListableBeanFactory Invoking afterPropertiesSet() on bean with name 'book'
這時控制台輸出寫在afterPropertiesSet的語句:InitializingBean,相當於init-method
調用生命周期方法init-method,在ApplicationContext.xml中bean中配置:
DefaultListableBeanFactory Invoking init method 'productBook' on bean with name 'book'(1612)
這里輸出了我自定義的init-method為birth方法的語句:書本初始化init-method
然后這里調用了Bean后置處理器的postProcessAfterInitialization方法,因為控制台打印了:bean處理器:bean創建后
到這里完成了bean的實例化
DefaultListableBeanFactory Finished creating instance of bean 'book'(460)
接下來和后置處理器相關,不太明白這里的返回是什么意思?
DefaultListableBeanFactory Returning cached instance of singleton bean 'myBeanFactoryPostFactory'(246) DefaultListableBeanFactory Returning cached instance of singleton bean 'myBeanPostProcessor'(246)
沒有找到生命周期處理器,可能是我們沒有定義,所以使用默認的。看不懂,不過看表述是這個意思。
XmlWebApplicationContext Unable to locate LifecycleProcessor with name 'lifecycleProcessor':
using default [org.springframework.context.support.DefaultLifecycleProcessor@dd7469](861)
返回緩存了這個處理器
DefaultListableBeanFactory Returning cached instance of singleton bean 'lifecycleProcessor'(246)
接下來的日志,更看不懂!總之,大概是JNDI相關的。。。
PropertySourcesPropertyResolver Searching for key 'spring.liveBeansView.mbeanDomain' in [servletConfigInitParams](81) PropertySourcesPropertyResolver Searching for key 'spring.liveBeansView.mbeanDomain' in [servletContextInitParams](81) PropertySourcesPropertyResolver Searching for key 'spring.liveBeansView.mbeanDomain' in [jndiProperties](81) JndiTemplate Looking up JNDI object with name [java:comp/env/spring.liveBeansView.mbeanDomain](150) PropertySourcesPropertyResolver Could not find key 'spring.liveBeansView.mbeanDomain' in any property source. Returning [null](103)
將Spring容器設置到Servlet容器(Web容器)中:
ContextLoader Published root WebApplicationContext
as ServletContext attribute with name [org.springframework.web.context.WebApplicationContext.ROOT](326)
五、正確的關閉Tomcat,而非kill時:
銷毀單例的bean,從這里也可以看到,Spring容器對prototype的bean不理會
DefaultListableBeanFactory Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@148d148: defining beans [book,myBeanFactoryPostFactory,myBeanPostProcessor]; root of factory hierarchy(444)
調用DisposableBean接口的destroy方法
DisposableBeanAdapter Invoking destroy() on bean with name 'book'(226)
打印出來:DisposableBean,相當於destroy-method
調用bean的destroy-method
DisposableBeanAdapter Invoking destroy method 'destroyBook' on bean with name 'book'(302)
打印:書本被銷毀destroy-method
六、幾個不小問題
1、如果name="book"的bean設置lazy-init="true",則啟動時不會實例化這個bean,日志中只會打印MyPostBeanProcessor實例化;
2、如果name="book"的bean設置scope="prototype",同樣不會在啟動時實例化,也不會緩存;什么時候實例化?getBean
而且prototype的bean,IoC容器只負責反射實例化,后續的生命周期不負責,相當於只new,當然像后置處理器等還是要執行的
3、BeanPostProcessor是IoC的一個擴展點,讓用戶有機會修改bean!而BeanFactoryPostProcessor是讓用戶有機會修改IoC容器的擴展點!
4、Spring的開閉原則:對擴展開放,對修改關閉??不太理解!
5、init-method和InitializingBean.afterPropertiesSet區別?
最終作用都一樣bean構造后執行初始化的方法
由於是接口,命名是限定死的,init-method屬性更靈活
其他同樣作用的方法,一種特殊的BeanPostProcessor,系統自動的CommonAnnotationBeanPostProcessor
-由於用標簽開啟了,<context:annotation-config />,作用類同<bean class="...CommonAnnotationBeanPostProcessor"/>
其中Spring自帶的注解@PostConstruct、@PreDestroy,用來修飾Book的另外兩個方法,這樣同時存在三種初始化方法!
CommonAnnotationBeanPostProcessor Invoking init method on bean 'book
初始時機:@PreDestroy----->InitializingBean------->init-method
注銷時機:@PreDestroy----->DisposableBean----->destroy-method
6、另外,如果Bean需要持有BeanFactory或ApplicationContext,則可以通過實現BeanFactoryAware和ApplicationContextAware接口獲取到,(通過@AutoWired應該也行吧!),調用時期:在實例化后setting的過程中:其實很容易理解,這和普通屬性的注入是一樣的嘛!
所以:打印
set注入了書本標題為:小王子
注入Bean工廠,通過BeanFactoryAware注入了BeanFactory
注入Spring應用上下文,通過ApplicationContextWare注入ApplicationContext
所以,生命周期圖:
-------------------------------------------------------------------------------------------------------
七、覆蓋Spring的源代碼
按照網上很多博客,先從GitHub中下載Spring源碼,然后使用Gradle編譯轉換成Eclipse可以導入的工程,但是貌似由於網絡原因,一直失敗,感覺非常麻煩!
后來想了想,要修改源碼,其實還有一個小技巧,就是覆蓋jar中文文件!!!
嘗試1:直接將源碼包下的單個文件夾spring-web下的org文件,復制到用來測試的Spring工程下(已經用pom.xml引入了Spring的所有包),引入之后,一大片報錯!缺少很多相關的jar包,總不可能一個個找出來吧!只有放棄!
嘗試2:如果我只是修改單個文件呢,如ContextLoader.java,單獨復制這個文件會怎樣?
結果是還是報錯:

不過比想象中好很多,只有一個servlet包找不到。原來是之前發布的方式是Tomcat提供的,所以這里pom.xml中顯示引入
<!-- 添加Servlet --> <dependency> <groupId>javax.servlet</groupId> <artifactId>servlet-api</artifactId> <version>2.5</version> <scope>provided</scope> </dependency>
重新編譯后,終於不再報錯了!
打開文件ContextLoader,修改幾行代碼,看看運行時是否執行了!
方便起見,修改幾行日志文件:
//servletContext.log("Initializing Spring root WebApplicationContext"); servletContext.log("你正在啟動Spring容器:WebApplicationContext!!!!!"); if (logger.isInfoEnabled()) { //logger.info("Root WebApplicationContext: initialization started"); logger.info("Spring容器開始初始化:Root WebApplicationContext: initialization started"); }
重新啟動Tomcat,打印的日志:
