读Hibernate源码 之二

读读Hibernate中save(Object obj)这个看似简单的操作内有何乾坤。现在，来看看Hibernate在这过程中做了什么。

上次，我简单讲了一下Configuration#configure()和Configuration#buildSessionFactory()。这部分属性Hibernate的启动过程，内容很多，代码很长。但是代码很规矩，若如对启动过程的某点有兴趣的话，可以留言给我，我们继续来看。或者自己看看，也能看明。

像这种框架，直接读源码会很困难，所以我需要去其它信息。比如，读Lucene，索引文件将是它最大突破口。读Lucene朋友，注意了！一定要了解它索引文件的内容以及格式，这将会是一个巨大突破。那读其它框架，同样也会存在各种各样的马脚，好让我们去追踪阅读。这只腿就是日志信息，从日志信息可以看到很多有的东西，方便我们定位代码的位置。这一点很重要，很重要。下面，我把Hibernate的日志级别调为DEBUG之后打出来部分日志信息贴出来。

14:49:00,951 DEBUG logging:184 - Logging Provider: org.jboss.logging.Log4jLoggerProvider……14:44:10,396 DEBUG Configuration:784 - Mapping Package com.zframe.src.hibernate.pojo14:44:10,516  INFO Configuration:1985 - HHH000043: Configuring from resource: /hibernate.cfg.xml14:44:10,516  INFO Configuration:2004 - HHH000040: Configuration resource: /hibernate.cfg.xml……14:44:10,881 DEBUG IntegratorServiceImpl:59 - Adding Integrator [org.hibernate.cfg.beanvalidation.BeanValidationIntegrator].14:44:11,508 DEBUG Configuration:1753 - Preparing to build session factory with filters : {}14:44:11,622  INFO DriverManagerConnectionProviderImpl:97 - HHH000402: Using Hibernate built-in connection pool (not for production use!)14:44:11,641  INFO DriverManagerConnectionProviderImpl:133 - HHH000115: Hibernate connection pool size: 114:44:11,641  INFO DriverManagerConnectionProviderImpl:136 - HHH000006: Autocommit mode: false14:44:11,642  INFO DriverManagerConnectionProviderImpl:150 - HHH000401: using driver [com.mysql.jdbc.Driver] at URL [jdbc:mysql://localhost:3306/hibernate]14:44:11,642  INFO DriverManagerConnectionProviderImpl:153 - HHH000046: Connection properties: {user=root, password=123123}14:44:11,806 DEBUG DriverManagerConnectionProviderImpl:195 - Opening new JDBC connection14:44:13,514 DEBUG DriverManagerConnectionProviderImpl:218 - Created connection to: jdbc:mysql://localhost:3306/hibernate, Isolation Level: 414:44:13,514 DEBUG JdbcServicesImpl:121 - Database ->       name : MySQL    version : 5.5.33      major : 5      minor : 514:44:13,514 DEBUG JdbcServicesImpl:127 - Driver ->       name : MySQL Connector Java    version : mysql-connector-java-5.1.26 ( Revision: ${bzr.revision-id} )      major : 5      minor : 114:44:13,515 DEBUG JdbcServicesImpl:133 - JDBC version : 4.014:44:13,693  INFO Dialect:130 - HHH000400: Using dialect: org.hibernate.dialect.MySQL5Dialect14:44:13,805 DEBUG Configuration:3472 - Processing hbm.xml files14:44:13,805 DEBUG Configuration:3502 - Process annotated classes14:44:13,822 DEBUG AnnotationBinder:532 - Binding entity from annotated class: com.zframe.src.hibernate.pojo.UserVO14:44:13,850 DEBUG Ejb3Column:196 - Binding column: Ejb3DiscriminatorColumn{logicalColumnName'DTYPE', discriminatorTypeName='string'}14:44:13,853 DEBUG AnnotationBinder:990 - No value specified for 'javax.persistence.sharedCache.mode'; using UNSPECIFIED14:44:13,883 DEBUG EntityBinder:394 - Import with entity name UserVO14:44:13,886 DEBUG EntityBinder:564 - Bind entity com.zframe.src.hibernate.pojo.UserVO on table tbl_user14:44:13,922 DEBUG Ejb3Column:196 - Binding column: Ejb3Column{table=org.hibernate.mapping.Table(tbl_user), mappingColumn=id, insertable=true, updatable=true, unique=false}14:44:13,924 DEBUG PropertyBinder:179 - MetadataSourceProcessor property id with lazy=false14:44:13,927 DEBUG SimpleValueBinder:331 - building SimpleValue for id14:44:13,928 DEBUG PropertyBinder:260 - Building property id14:44:13,963 DEBUG Ejb3Column:196 - Binding column: Ejb3Column{table=org.hibernate.mapping.Table(tbl_user), mappingColumn=address, insertable=true, updatable=true, unique=false}14:44:13,963 DEBUG PropertyBinder:179 - MetadataSourceProcessor property address with lazy=false14:44:13,964 DEBUG SimpleValueBinder:331 - building SimpleValue for address14:44:13,964 DEBUG PropertyBinder:260 - Building property address14:44:13,964 DEBUG Ejb3Column:196 - Binding column: Ejb3Column{table=org.hibernate.mapping.Table(tbl_user), mappingColumn=name, insertable=true, updatable=true, unique=false}14:44:13,964 DEBUG PropertyBinder:179 - MetadataSourceProcessor property name with lazy=false14:44:13,964 DEBUG SimpleValueBinder:331 - building SimpleValue for name14:44:13,964 DEBUG PropertyBinder:260 - Building property name14:44:13,966 DEBUG SimpleValueBinder:369 - Setting SimpleValue typeName for id14:44:13,966 DEBUG SimpleValueBinder:369 - Setting SimpleValue typeName for address14:44:13,966 DEBUG SimpleValueBinder:369 - Setting SimpleValue typeName for name14:44:13,967 DEBUG Configuration:1420 - Processing fk mappings (*ToOne and JoinedSubclass)14:44:13,968 DEBUG Configuration:1603 - Processing extends queue14:44:13,968 DEBUG Configuration:1661 - Processing extends queue14:44:13,968 DEBUG Configuration:1606 - Processing collection mappings14:44:13,968 DEBUG Configuration:1616 - Processing native query and ResultSetMapping mappings14:44:13,968 DEBUG Configuration:1624 - Processing association property references14:44:13,968 DEBUG Configuration:1646 - Creating tables' unique integer identifiers14:44:13,968 DEBUG Configuration:1647 - Processing foreign key constraints14:44:14,026 DEBUG SettingsFactory:114 - Automatic flush during beforeCompletion(): disabled14:44:14,026 DEBUG SettingsFactory:120 - Automatic session close at end of transaction: disabled14:44:14,026 DEBUG SettingsFactory:131 - JDBC batch size: 1514:44:14,026 DEBUG SettingsFactory:137 - JDBC batch updates for versioned data: disabled14:44:14,026 DEBUG SettingsFactory:147 - Scrollable result sets: enabled14:44:14,027 DEBUG SettingsFactory:153 - Wrap result sets: disabled14:44:14,027 DEBUG SettingsFactory:159 - JDBC3 getGeneratedKeys(): enabled14:44:14,027 DEBUG SettingsFactory:171 - multi-tenancy strategy : NONE14:44:14,027 DEBUG SettingsFactory:177 - Connection release mode: auto14:44:14,027  INFO TransactionFactoryInitiator:68 - HHH000399: Using default transaction strategy (direct JDBC transactions)14:44:14,077 DEBUG SettingsFactory:199 - Using BatchFetchStyle : LEGACY14:44:14,078 DEBUG SettingsFactory:218 - Maximum outer join fetch depth: 214:44:14,078 DEBUG SettingsFactory:224 - Default batch fetch size: 114:44:14,078 DEBUG SettingsFactory:230 - Generate SQL with comments: disabled14:44:14,078 DEBUG SettingsFactory:236 - Order SQL updates by primary key: disabled14:44:14,078 DEBUG SettingsFactory:242 - Order SQL inserts for batching: disabled14:44:14,079 DEBUG SettingsFactory:250 - Default null ordering: none14:44:14,085 DEBUG SettingsFactory:541 - Query translator: org.hibernate.hql.internal.ast.ASTQueryTranslatorFactory14:44:14,098  INFO ASTQueryTranslatorFactory:48 - HHH000397: Using ASTQueryTranslatorFactory14:44:14,098 DEBUG SettingsFactory:260 - Query language substitutions: {}14:44:14,099 DEBUG SettingsFactory:266 - JPA-QL strict compliance: disabled14:44:14,100 DEBUG SettingsFactory:274 - Second-level cache: enabled14:44:14,100 DEBUG SettingsFactory:280 - Query cache: disabled14:44:14,100 DEBUG SettingsFactory:481 - Cache region factory : org.hibernate.cache.internal.NoCachingRegionFactory14:44:14,103 DEBUG SettingsFactory:491 - org.hibernate.cache.internal.NoCachingRegionFactory did not provide constructor accepting java.util.Properties; attempting no-arg constructor.14:44:14,104 DEBUG SettingsFactory:295 - Optimize cache for minimal puts: disabled14:44:14,104 DEBUG SettingsFactory:310 - Structured second-level cache entries: disabled14:44:14,104 DEBUG SettingsFactory:320 - Second-level cache direct-reference entries: disabled14:44:14,104 DEBUG SettingsFactory:328 - Statistics: disabled14:44:14,104 DEBUG SettingsFactory:334 - Deleted entity synthetic identifier rollback: disabled14:44:14,104 DEBUG SettingsFactory:358 - Default entity-mode: pojo14:44:14,104 DEBUG SettingsFactory:364 - Named query checking : enabled14:44:14,105 DEBUG SettingsFactory:370 - Check Nullability in Core (should be disabled when Bean Validation is on): enabled14:44:14,105 DEBUG SettingsFactory:388 - Allow initialization of lazy state outside session : : disabled14:44:14,105 DEBUG SettingsFactory:398 - JTA Track by Thread: enabled14:44:14,216 DEBUG SessionFactoryImpl:225 - Building session factory14:44:14,397 DEBUG SessionFactoryImpl:277 - Session factory constructed with filter configurations : {}……14:44:14,420 DEBUG DefaultIdentifierGeneratorFactory:107 - Setting dialect [org.hibernate.dialect.MySQL5Dialect]14:44:15,918 DEBUG AbstractEntityPersister:3592 - Static SQL for entity: com.zframe.src.hibernate.pojo.UserVO14:44:15,919 DEBUG AbstractEntityPersister:3597 -  Version select: select id from tbl_user where id =?14:44:15,919 DEBUG AbstractEntityPersister:3600 -  Snapshot select: select uservo_.id, uservo_.address as address2_0_, uservo_.name as name3_0_ from tbl_user uservo_ where uservo_.id=?14:44:15,919 DEBUG AbstractEntityPersister:3603 -  Insert 0: insert into tbl_user (address, name, id) values (?, ?, ?)14:44:15,919 DEBUG AbstractEntityPersister:3604 -  Update 0: update tbl_user set address=?, name=? where id=?14:44:15,920 DEBUG AbstractEntityPersister:3605 -  Delete 0: delete from tbl_user where id=?14:44:15,920 DEBUG AbstractEntityPersister:3608 -  Identity insert: insert into tbl_user (address, name) values (?, ?)14:44:16,068 DEBUG Loader:123 - Static select for entity com.zframe.src.hibernate.pojo.UserVO [NONE]: select uservo0_.id as id1_0_0_, uservo0_.address as address2_0_0_, uservo0_.name as name3_0_0_ from tbl_user uservo0_ where uservo0_.id=?……14:44:23,716 DEBUG SessionFactoryRegistry:62 - Initializing SessionFactoryRegistry : org.hibernate.internal.SessionFactoryRegistry@c1186f14:44:23,731 DEBUG SessionFactoryRegistry:75 - Registering SessionFactory: 0c6f760a-cc15-4bc5-979d-ad632a5257a2 (<unnamed>)14:44:23,731 DEBUG SessionFactoryRegistry:82 - Not binding SessionFactory to JNDI, no JNDI name configured14:44:23,731 DEBUG SessionFactoryImpl:488 - Instantiated session factory14:44:23,856 DEBUG Configuration:3472 - Processing hbm.xml files14:44:23,857 DEBUG Configuration:3502 - Process annotated classes14:44:23,857 DEBUG Configuration:1420 - Processing fk mappings (*ToOne and JoinedSubclass)14:44:23,857 DEBUG Configuration:1603 - Processing extends queue14:44:23,857 DEBUG Configuration:1661 - Processing extends queue14:44:23,857 DEBUG Configuration:1606 - Processing collection mappings14:44:23,857 DEBUG Configuration:1616 - Processing native query and ResultSetMapping mappings14:44:23,858 DEBUG Configuration:1624 - Processing association property references14:44:23,858 DEBUG Configuration:1646 - Creating tables' unique integer identifiers14:44:23,858 DEBUG Configuration:1647 - Processing foreign key constraints14:44:23,858 DEBUG DefaultIdentifierGeneratorFactory:107 - Setting dialect [org.hibernate.dialect.MySQL5Dialect]14:44:23,882 DEBUG Configuration:3472 - Processing hbm.xml files14:44:23,882 DEBUG Configuration:3502 - Process annotated classes14:44:23,882 DEBUG Configuration:1420 - Processing fk mappings (*ToOne and JoinedSubclass)14:44:23,882 DEBUG Configuration:1603 - Processing extends queue14:44:23,883 DEBUG Configuration:1661 - Processing extends queue14:44:23,883 DEBUG Configuration:1606 - Processing collection mappings14:44:23,883 DEBUG Configuration:1616 - Processing native query and ResultSetMapping mappings14:44:23,883 DEBUG Configuration:1624 - Processing association property references14:44:23,883 DEBUG Configuration:1646 - Creating tables' unique integer identifiers14:44:23,883 DEBUG Configuration:1647 - Processing foreign key constraints14:44:23,884 DEBUG DefaultIdentifierGeneratorFactory:107 - Setting dialect [org.hibernate.dialect.MySQL5Dialect]14:44:23,884 DEBUG DefaultIdentifierGeneratorFactory:107 - Setting dialect [org.hibernate.dialect.MySQL5Dialect]14:44:23,902  INFO SchemaExport:343 - HHH000227: Running hbm2ddl schema export14:44:23,903 DEBUG SchemaExport:353 - Import file not found: /import.sql14:44:23,915 DEBUG SQL:104 - drop table if exists tbl_userHibernate: drop table if exists tbl_user14:44:24,504 DEBUG SQL:104 - create table tbl_user (id integer not null auto_increment, address varchar(255), name varchar(255), primary key (id))Hibernate: create table tbl_user (id integer not null auto_increment, address varchar(255), name varchar(255), primary key (id))14:44:24,717  INFO SchemaExport:405 - HHH000230: Schema export complete14:44:24,766 DEBUG SessionFactoryImpl:1068 - Checking 0 named HQL queries14:44:24,766 DEBUG SessionFactoryImpl:1091 - Checking 0 named SQL queries14:44:24,827 DEBUG StatisticsInitiator:110 - Statistics initialized [enabled=false]====================sessionfactorycreated=====================14:44:25,135 DEBUG AbstractTransactionImpl:158 - begin14:44:25,135 DEBUG LogicalConnectionImpl:212 - Obtaining JDBC connection14:44:25,135 DEBUG LogicalConnectionImpl:218 - Obtained JDBC connection14:44:25,135 DEBUG JdbcTransaction:69 - initial autocommit status: false14:44:25,272 DEBUG ActionQueue:213 - Executing identity-insert immediately14:44:25,293 DEBUG SQL:104 - insert into tbl_user (address, name) values (?, ?)Hibernate: insert into tbl_user (address, name) values (?, ?)14:44:25,445 DEBUG IdentifierGeneratorHelper:93 - Natively generated identity: 114:44:25,459 DEBUG AbstractTransactionImpl:173 - committing14:44:25,508 DEBUG AbstractFlushingEventListener:144 - Processing flush-time cascades14:44:25,510 DEBUG AbstractFlushingEventListener:185 - Dirty checking collections14:44:25,515 DEBUG AbstractFlushingEventListener:118 - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects14:44:25,515 DEBUG AbstractFlushingEventListener:125 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections14:44:25,516 DEBUG EntityPrinter:114 - Listing entities:14:44:25,516 DEBUG EntityPrinter:121 - com.zframe.src.hibernate.pojo.UserVO{id=1, address=null, name=null}14:44:25,763 DEBUG JdbcTransaction:113 - committed JDBC Connection14:44:25,779 DEBUG SessionFactoryImpl:1369 - HHH000031: Closing====================sessionfactoryclosed=====================

“……”表示删除了部分，信息量够大吧。这是整个Hibernate启动并执行Session#save(Object obj)全过程出来的信息。有这个，我们很容易知道，什么时候把对象给持久化了。至少范围小，基本定在 JdbcTransaction:69 之后，ActionQueue:213 之前。
(其实，我应该把delete拿出来讲的，而不应该是save，建议你们从delete开始)
本来想把Session#save(Object obj)这个操作，从它开始的到执行SQL的主线流程用Sequence图画出来的，后来我放弃了。原因有二，一：过程太长了，半天画不完；二：意义不大，懒得贴图了。由上，有下。下面是save的主线流程了。

SessionImpl#save(Object obj);save(String entityName, Object entity);fireSave(new SaveOrUpdateEvent(String, Object, EventSource));(SaveOrUpdateEventListener)listener.onSaveOrUpdate(SaveOrUpdateEvent)DefaultSaveOrUpdateEventListener //SaveOrUpdateEventListeneronSaveOrUpdate(SaveOrUpdateEvent event);event.setResultId(performSaveOrUpdate(event));(DefaultSaveEventListener) performSaveOrUpdate(SaveOrUpdateEvent event);entityIsPersistent(SaveOrUpdateEvent event);saveWithGeneratedOrRequestedId(event)saveWithGeneratedId(Object entity, String entityName, Object anything, EventSoure source, requiresImmediateIdAccess);performSave(Object, Serializable, EntityPersister, useIdentittyColumn, Object, EventSource, RequiresImmediateIdAccess);performSaveOrReplicate(Object,EntityKey, EntityPersister, Object, EventSource, boolean);addInsertAction(Object[], Serializable, Object, EntityPersiter, boolean, EventSource, boolean);ActionQueueaddAction( EntityIdentityInsertAction ) //source.getActionQueue().addAction( EntityIdentityInsertAction )addInsertAction( EntityInsertAction );addInsertAction( AbstractEntityInsertAction );addInsertResolvedEntityInsertAction( AbstractEntityInsertAction );execute( Executeable )EntityIdentityInsertAction execute();AbstractEntityPersister( SingleTableEntityPersister ).insert( Object[], Object, SessionImplementor );IdentityGenerator$GetGeneratedKeysDelegate // AbstractReturningDelegate performInsert( String, SessionImplmentor, Binder);//{ prepare(insertSQL, session), executeAndExtract(insert, session) }IdentityGeneratorexecuteAndExtract(PreparedStatement, SessionImplementor);session.getTransactionCoordinator().getJdbcCoordinator().getResultSetReturn().executeUpdate( PreparedStatement ); //这一步就执行了SQL了，后续还有一些操作。

到了这会，我只想说两句话：1.祝你读得愉快！（明显你已经很难快乐了）。2.对Hibernate的作者说，这脑瓜子神了。

在先把事件监听器(EventListener)注册到事件源(EventSource)上，就是事件的触发者。当某个事件(AbstractEvent)被触发之后，会被监听器接收到事件，然后当然就是处理事件。

我记得有个故事，那是发在哪年盛夏一个美好的夜里，我记得故事中有一段代码，跟我们今天要讲的东西很类似。各位，曾记否，Java有一个东西叫Awt。这个东西，我觉得很好玩。哦，不对，不说要说这个。它有一东西叫事件监听器。对，就是这货。代码如下：

JFrame#addMouseListener(new MouseListener(){@Overridepublic void mouseClicked(ActionEvent e){System.out.println("单击事件被监听了！");}……})

Hibernate也有个货，应该也叫事件监听器。因此，对下面所有不明白的，请查阅Java API。过程应该是这样的：先把事件监听器(EventListener)注册到事件源(EventSource)上，就是事件的拥有者。当某个事件(AbstractEvent)发生在事件源上之后，就会被事件源上的监听器接收到，然后做出相对应的事件处理。

这么说吧，首先JFrame拥有监听鼠标事件的能力，再者在该JFrame在注册了鼠标事件监听器。当某一天，一个事件发生在这个JFrame上，不一定是鼠标事件，但鼠标的单击事件被我们的JFrame监听了。那么，当单击事件发现在这个JFrame的时候，做出一些对应反应。
CP：
首先Session拥有监听CRUD事件的能力，再者在该Session在注册了删除事件监听器。当某一天，一个事件发生在这个Session上，不一定是删除事件，但删除事件被我们的Session监听了。那么，当单击事件发现在这个Session的时候，做出一些对应反应。

SessionImpl#fireEvent(new EventListener(){public void onEvent(AbstractEvent event){}})

这样好了吧。当时，ActionEvent是不是记录N多跟Event有关的东西。只有跟Event有关的东西都在这里可以找到，同样我们的AbstractEvent也是这样。
后面就是把Event中的实体拿出来，依事件该删的删了，该存的存了。这一段有不明白直接查看JAVA API。

其实，这不是最重要的。最重要的应该是Hibernate中怎么来处理一个对象的状态（PERSISTENT, TRANSIENT, DETACHED, DELETED），即实体在Session状态及状态变化，这是Hibernate花费很大力气来处理的内容。这里边有几个类或接口比较重要，大家先关注一下，今天先到这里。

EntityEntryContext

EntityPersister