一个spring+hibernate的事务管理详细debug

17:25:01,109 DEBUG OpenSessionInViewFilter:239 - Using SessionFactory 'sessionFactory' for OpenSessionInViewFilter
17:25:01,109 DEBUG DefaultListableBeanFactory:241 - Returning cached instance of singleton bean 'sessionFactory'
17:25:01,187 DEBUG OpenSessionInViewFilter:181 - Opening single Hibernate Session in OpenSessionInViewFilter
17:25:01,296 DEBUG SessionFactoryUtils:316 - Opening Hibernate Session
17:25:01,453 DEBUG SessionImpl:257 - opened session at timestamp: 5209818322239488
17:25:01,484 DEBUG TransactionSynchronizationManager:183 - Bound value [org.springframework.orm.hibernate3.SessionHolder@ae4d15] for key [org.hibernate.impl.SessionFactoryImpl@1fcc032] to thread [http-8080-1]
17:25:01,531 DEBUG DispatcherServlet:643 - Bound request context to thread: org.apache.catalina.connector.RequestFacade@b52821
17:25:01,546 DEBUG DispatcherServlet:690 - DispatcherServlet with name 'callcenter' processing POST request for [/callcenter/user/login]
17:25:01,562 DEBUG DispatcherServlet:939 - Testing handler map [org.springframework.web.servlet.mvc.annotation.DefaultAnnotationHandlerMapping@a84a4f] in DispatcherServlet with name 'callcenter'
17:25:01,578 DEBUG DefaultAnnotationHandlerMapping:219 - Mapping [/user/login] to handler 'com.fantong.call.web.login.LoginController@107a53f'
17:25:01,578 DEBUG DispatcherServlet:976 - Testing handler adapter [org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter@1bff563]
17:25:01,781 DEBUG CachedIntrospectionResults:222 - Getting BeanInfo for class [com.fantong.call.entity.KfUser]
17:25:01,796 DEBUG CachedIntrospectionResults:238 - Caching PropertyDescriptors for class [com.fantong.call.entity.KfUser]
17:25:01,796 DEBUG CachedIntrospectionResults:246 - Found bean property 'authregionid' of type [java.lang.Long]
17:25:01,796 DEBUG CachedIntrospectionResults:246 - Found bean property 'authregiontype' of type [java.lang.Long]
17:25:01,796 DEBUG CachedIntrospectionResults:246 - Found bean property 'cityid' of type [int]
17:25:01,796 DEBUG CachedIntrospectionResults:246 - Found bean property 'class' of type [java.lang.Class]
17:25:01,812 DEBUG CachedIntrospectionResults:246 - Found bean property 'email' of type [java.lang.String]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'ip' of type [java.lang.String]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'ipflag' of type [int]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'localcity' of type [java.lang.Long]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'mother' of type [java.lang.Long]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'ordertype' of type [int]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'password' of type [java.lang.String]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'phone' of type [java.lang.String]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'roles' of type [java.util.Set]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'servercode' of type [java.lang.String]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'status' of type [java.lang.Long]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'truename' of type [java.lang.String]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'userid' of type [java.lang.Long]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'username' of type [java.lang.String]
17:25:01,828 DEBUG CachedIntrospectionResults:246 - Found bean property 'zxno' of type [int]
17:25:01,828 DEBUG HandlerMethodInvoker:165 - Invoking request handler method: public org.springframework.web.servlet.ModelAndView com.fantong.call.web.login.LoginController.login(com.fantong.call.entity.KfUser)
17:25:07,296 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@ae4d15] for key [org.hibernate.impl.SessionFactoryImpl@1fcc032] bound to thread [http-8080-1]
17:25:07,718 DEBUG QueryTranslatorImpl:272 - parse() - HQL: from com.fantong.call.entity.KfUser kf where kf.username=:name and kf.password=:pass
17:25:07,812 DEBUG AST:291 - --- HQL AST ---
\-[QUERY] Node: 'query'
+-[SELECT_FROM] Node: 'SELECT_FROM'
| \-[FROM] Node: 'from'
| \-[RANGE] Node: 'RANGE'
| +-[DOT] Node: '.'
| | +-[DOT] Node: '.'
| | | +-[DOT] Node: '.'
| | | | +-[DOT] Node: '.'
| | | | | +-[IDENT] Node: 'com'
| | | | | \-[IDENT] Node: 'fantong'
| | | | \-[IDENT] Node: 'call'
| | | \-[IDENT] Node: 'entity'
| | \-[IDENT] Node: 'KfUser'
| \-[ALIAS] Node: 'kf'
\-[WHERE] Node: 'where'
\-[AND] Node: 'and'
+-[EQ] Node: '='
| +-[DOT] Node: '.'
| | +-[IDENT] Node: 'kf'
| | \-[IDENT] Node: 'username'
| \-[COLON] Node: ':'
| \-[IDENT] Node: 'name'
\-[EQ] Node: '='
+-[DOT] Node: '.'
| +-[IDENT] Node: 'kf'
| \-[IDENT] Node: 'password'
\-[COLON] Node: ':'
\-[IDENT] Node: 'pass'

17:25:07,812 DEBUG ErrorCounter:91 - throwQueryException() : no errors
17:25:08,031 DEBUG HqlSqlBaseWalker:111 - select << begin [level=1, statement=select]
17:25:08,140 DEBUG FromElement:157 - FromClause{level=1} : com.fantong.call.entity.KfUser (kf) -> kfuser0_
17:25:08,156 DEBUG FromReferenceNode:74 - Resolved : kf -> kfuser0_.userid
17:25:08,171 DEBUG DotNode:613 - getDataType() : username -> org.hibernate.type.StringType@1cfc6ee
17:25:08,171 DEBUG FromReferenceNode:74 - Resolved : kf.username -> kfuser0_.username
17:25:08,203 DEBUG FromReferenceNode:74 - Resolved : kf -> kfuser0_.userid
17:25:08,203 DEBUG DotNode:613 - getDataType() : password -> org.hibernate.type.StringType@1cfc6ee
17:25:08,203 DEBUG FromReferenceNode:74 - Resolved : kf.password -> kfuser0_.password
17:25:08,203 DEBUG HqlSqlBaseWalker:117 - select : finishing up [level=1, statement=select]
17:25:08,203 DEBUG HqlSqlWalker:611 - processQuery() : ( SELECT ( FromClause{level=1} kf_user kfuser0_ ) ( where ( and ( = ( kfuser0_.username kfuser0_.userid username ) ? ) ( = ( kfuser0_.password kfuser0_.userid password ) ? ) ) ) )
17:25:08,265 DEBUG HqlSqlWalker:854 - Derived SELECT clause created.
17:25:08,296 DEBUG JoinProcessor:179 - Using FROM fragment [kf_user kfuser0_]
17:25:08,296 DEBUG HqlSqlBaseWalker:123 - select >> end [level=1, statement=select]
17:25:08,296 DEBUG AST:258 - --- SQL AST ---
\-[SELECT] QueryNode: 'SELECT' querySpaces (kf_user)
+-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
| +-[SELECT_EXPR] SelectExpressionImpl: 'kfuser0_.userid as userid3_' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=kf,role=null,tableName=kf_user,tableAlias=kfuser0_,origin=null,columns={,className=com.fantong.call.entity.KfUser}}}
| \-[SQL_TOKEN] SqlFragment: 'kfuser0_.authregionid as authregi2_3_, kfuser0_.authregiontype as authregi3_3_, kfuser0_.cityid as cityid3_, kfuser0_.email as email3_, kfuser0_.ip as ip3_, kfuser0_.ipflag as ipflag3_, kfuser0_.localcity as localcity3_, kfuser0_.mother as mother3_, kfuser0_.ordertype as ordertype3_, kfuser0_.password as password3_, kfuser0_.phone as phone3_, kfuser0_.servercode as servercode3_, kfuser0_.status as status3_, kfuser0_.truename as truename3_, kfuser0_.username as username3_, kfuser0_.zxno as zxno3_'
+-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[kf], fromElementByTableAlias=[kfuser0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
| \-[FROM_FRAGMENT] FromElement: 'kf_user kfuser0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=kf,role=null,tableName=kf_user,tableAlias=kfuser0_,origin=null,columns={,className=com.fantong.call.entity.KfUser}}
\-[WHERE] SqlNode: 'where'
\-[AND] SqlNode: 'and'
+-[EQ] BinaryLogicOperatorNode: '='
| +-[DOT] DotNode: 'kfuser0_.username' {propertyName=username,dereferenceType=ALL,propertyPath=username,path=kf.username,tableAlias=kfuser0_,className=com.fantong.call.entity.KfUser,classAlias=kf}
| | +-[ALIAS_REF] IdentNode: 'kfuser0_.userid' {alias=kf, className=com.fantong.call.entity.KfUser, tableAlias=kfuser0_}
| | \-[IDENT] IdentNode: 'username' {originalText=username}
| \-[NAMED_PARAM] ParameterNode: '?' {name=name, expectedType=org.hibernate.type.StringType@1cfc6ee}
\-[EQ] BinaryLogicOperatorNode: '='
+-[DOT] DotNode: 'kfuser0_.password' {propertyName=password,dereferenceType=ALL,propertyPath=password,path=kf.password,tableAlias=kfuser0_,className=com.fantong.call.entity.KfUser,classAlias=kf}
| +-[ALIAS_REF] IdentNode: 'kfuser0_.userid' {alias=kf, className=com.fantong.call.entity.KfUser, tableAlias=kfuser0_}
| \-[IDENT] IdentNode: 'password' {originalText=password}
\-[NAMED_PARAM] ParameterNode: '?' {name=pass, expectedType=org.hibernate.type.StringType@1cfc6ee}

17:25:08,296 DEBUG ErrorCounter:91 - throwQueryException() : no errors
17:25:08,359 DEBUG QueryTranslatorImpl:241 - HQL: from com.fantong.call.entity.KfUser kf where kf.username=:name and kf.password=:pass
17:25:08,359 DEBUG QueryTranslatorImpl:242 - SQL: select kfuser0_.userid as userid3_, kfuser0_.authregionid as authregi2_3_, kfuser0_.authregiontype as authregi3_3_, kfuser0_.cityid as cityid3_, kfuser0_.email as email3_, kfuser0_.ip as ip3_, kfuser0_.ipflag as ipflag3_, kfuser0_.localcity as localcity3_, kfuser0_.mother as mother3_, kfuser0_.ordertype as ordertype3_, kfuser0_.password as password3_, kfuser0_.phone as phone3_, kfuser0_.servercode as servercode3_, kfuser0_.status as status3_, kfuser0_.truename as truename3_, kfuser0_.username as username3_, kfuser0_.zxno as zxno3_ from kf_user kfuser0_ where kfuser0_.username=? and kfuser0_.password=?
17:25:08,359 DEBUG ErrorCounter:91 - throwQueryException() : no errors
17:25:08,468 DEBUG AbstractBatcher:410 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17:25:08,468 DEBUG ConnectionManager:444 - opening JDBC connection
17:25:08,515 DEBUG SQL:111 -
select
kfuser0_.userid as userid3_,
kfuser0_.authregionid as authregi2_3_,
kfuser0_.authregiontype as authregi3_3_,
kfuser0_.cityid as cityid3_,
kfuser0_.email as email3_,
kfuser0_.ip as ip3_,
kfuser0_.ipflag as ipflag3_,
kfuser0_.localcity as localcity3_,
kfuser0_.mother as mother3_,
kfuser0_.ordertype as ordertype3_,
kfuser0_.password as password3_,
kfuser0_.phone as phone3_,
kfuser0_.servercode as servercode3_,
kfuser0_.status as status3_,
kfuser0_.truename as truename3_,
kfuser0_.username as username3_,
kfuser0_.zxno as zxno3_
from
kf_user kfuser0_
where
kfuser0_.username=?
and kfuser0_.password=?
Hibernate:
select
kfuser0_.userid as userid3_,
kfuser0_.authregionid as authregi2_3_,
kfuser0_.authregiontype as authregi3_3_,
kfuser0_.cityid as cityid3_,
kfuser0_.email as email3_,
kfuser0_.ip as ip3_,
kfuser0_.ipflag as ipflag3_,
kfuser0_.localcity as localcity3_,
kfuser0_.mother as mother3_,
kfuser0_.ordertype as ordertype3_,
kfuser0_.password as password3_,
kfuser0_.phone as phone3_,
kfuser0_.servercode as servercode3_,
kfuser0_.status as status3_,
kfuser0_.truename as truename3_,
kfuser0_.username as username3_,
kfuser0_.zxno as zxno3_
from
kf_user kfuser0_
where
kfuser0_.username=?
and kfuser0_.password=?
17:25:09,750 DEBUG AbstractBatcher:426 - about to open ResultSet (open ResultSets: 0, globally: 0)
17:25:09,765 DEBUG Loader:1218 - result row: EntityKey[com.fantong.call.entity.KfUser#1]
17:25:09,812 DEBUG AbstractBatcher:433 - about to close ResultSet (open ResultSets: 1, globally: 1)
17:25:09,812 DEBUG AbstractBatcher:418 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17:25:09,828 DEBUG TwoPhaseLoad:131 - resolving associations for [com.fantong.call.entity.KfUser#1]
17:25:09,875 DEBUG TwoPhaseLoad:239 - done materializing entity [com.fantong.call.entity.KfUser#1]
17:25:09,890 DEBUG StatefulPersistenceContext:892 - initializing non-lazy collections
17:25:09,890 DEBUG ConnectionManager:325 - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
17:25:09,921 DEBUG Loader:2054 - loading collection: [com.fantong.call.entity.KfUser.roles#1]
17:25:09,921 DEBUG AbstractBatcher:410 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17:25:09,921 DEBUG SQL:111 -
select
roles0_.userid as userid3_1_,
roles0_.roleid as roleid1_,
kfrole1_.id as id2_0_,
kfrole1_.authregiontype as authregi2_2_0_,
kfrole1_.localcity as localcity2_0_,
kfrole1_.mother as mother2_0_,
kfrole1_.name as name2_0_
from
kf_userrole roles0_,
kf_role kfrole1_
where
roles0_.roleid=kfrole1_.id
and roles0_.userid=?
Hibernate:
select
roles0_.userid as userid3_1_,
roles0_.roleid as roleid1_,
kfrole1_.id as id2_0_,
kfrole1_.authregiontype as authregi2_2_0_,
kfrole1_.localcity as localcity2_0_,
kfrole1_.mother as mother2_0_,
kfrole1_.name as name2_0_
from
kf_userrole roles0_,
kf_role kfrole1_
where
roles0_.roleid=kfrole1_.id
and roles0_.userid=?
17:25:10,062 DEBUG AbstractBatcher:426 - about to open ResultSet (open ResultSets: 0, globally: 0)
17:25:10,062 DEBUG Loader:1099 - result set contains (possibly empty) collection: [com.fantong.call.entity.KfUser.roles#1]
17:25:10,078 DEBUG Loader:1218 - result row: EntityKey[com.fantong.call.entity.KfRole#2]
17:25:10,078 DEBUG Loader:1029 - found row of collection: [com.fantong.call.entity.KfUser.roles#1]
17:25:10,093 DEBUG AbstractBatcher:433 - about to close ResultSet (open ResultSets: 1, globally: 1)
17:25:10,093 DEBUG AbstractBatcher:418 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17:25:10,109 DEBUG TwoPhaseLoad:131 - resolving associations for [com.fantong.call.entity.KfRole#2]
17:25:10,109 DEBUG TwoPhaseLoad:239 - done materializing entity [com.fantong.call.entity.KfRole#2]
17:25:10,109 DEBUG CollectionLoadContext:240 - 1 collections were found in result set for role: com.fantong.call.entity.KfUser.roles
17:25:10,109 DEBUG CollectionLoadContext:283 - collection fully initialized: [com.fantong.call.entity.KfUser.roles#1]
17:25:10,109 DEBUG CollectionLoadContext:249 - 1 collections initialized for role: com.fantong.call.entity.KfUser.roles
17:25:10,109 DEBUG StatefulPersistenceContext:892 - initializing non-lazy collections
17:25:10,109 DEBUG Loader:2078 - done loading collection
普通客服人员------------- start
17:25:10,125 DEBUG Loader:2054 - loading collection: [com.fantong.call.entity.KfRole.functions#2]
17:25:10,125 DEBUG AbstractBatcher:410 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17:25:10,125 DEBUG SQL:111 -
select
functions0_.role_id as role1_2_1_,
functions0_.func_code as func2_1_,
kffunction1_.code as code1_0_,
kffunction1_.inuse as inuse1_0_,
kffunction1_.mother as mother1_0_,
kffunction1_.name as name1_0_
from
kf_rolefunc functions0_,
kf_function kffunction1_
where
functions0_.func_code=kffunction1_.code
and functions0_.role_id=?
Hibernate:
select
functions0_.role_id as role1_2_1_,
functions0_.func_code as func2_1_,
kffunction1_.code as code1_0_,
kffunction1_.inuse as inuse1_0_,
kffunction1_.mother as mother1_0_,
kffunction1_.name as name1_0_
from
kf_rolefunc functions0_,
kf_function kffunction1_
where
functions0_.func_code=kffunction1_.code
and functions0_.role_id=?
17:25:10,171 DEBUG AbstractBatcher:426 - about to open ResultSet (open ResultSets: 0, globally: 0)
17:25:10,171 DEBUG Loader:1099 - result set contains (possibly empty) collection: [com.fantong.call.entity.KfRole.functions#2]
17:25:10,171 DEBUG Loader:1218 - result row: EntityKey[com.fantong.call.entity.KfFunction#11]
17:25:10,171 DEBUG Loader:1029 - found row of collection: [com.fantong.call.entity.KfRole.functions#2]
17:25:10,171 DEBUG Loader:1218 - result row: EntityKey[com.fantong.call.entity.KfFunction#1]
17:25:10,171 DEBUG Loader:1029 - found row of collection: [com.fantong.call.entity.KfRole.functions#2]
17:25:10,171 DEBUG Loader:1218 - result row: EntityKey[com.fantong.call.entity.KfFunction#13]
17:25:10,171 DEBUG Loader:1029 - found row of collection: [com.fantong.call.entity.KfRole.functions#2]
17:25:10,171 DEBUG Loader:1218 - result row: EntityKey[com.fantong.call.entity.KfFunction#14]
17:25:10,171 DEBUG Loader:1029 - found row of collection: [com.fantong.call.entity.KfRole.functions#2]
17:25:10,171 DEBUG Loader:1218 - result row: EntityKey[com.fantong.call.entity.KfFunction#15]
17:25:10,171 DEBUG Loader:1029 - found row of collection: [com.fantong.call.entity.KfRole.functions#2]
17:25:10,171 DEBUG Loader:1218 - result row: EntityKey[com.fantong.call.entity.KfFunction#16]
17:25:10,171 DEBUG Loader:1029 - found row of collection: [com.fantong.call.entity.KfRole.functions#2]
17:25:10,171 DEBUG Loader:1218 - result row: EntityKey[com.fantong.call.entity.KfFunction#41]
17:25:10,187 DEBUG Loader:1029 - found row of collection: [com.fantong.call.entity.KfRole.functions#2]
17:25:10,187 DEBUG AbstractBatcher:433 - about to close ResultSet (open ResultSets: 1, globally: 1)
17:25:10,187 DEBUG AbstractBatcher:418 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17:25:10,187 DEBUG TwoPhaseLoad:131 - resolving associations for [com.fantong.call.entity.KfFunction#11]
17:25:10,187 DEBUG TwoPhaseLoad:239 - done materializing entity [com.fantong.call.entity.KfFunction#11]
17:25:10,187 DEBUG TwoPhaseLoad:131 - resolving associations for [com.fantong.call.entity.KfFunction#1]
17:25:10,187 DEBUG TwoPhaseLoad:239 - done materializing entity [com.fantong.call.entity.KfFunction#1]
17:25:10,187 DEBUG TwoPhaseLoad:131 - resolving associations for [com.fantong.call.entity.KfFunction#13]
17:25:10,187 DEBUG TwoPhaseLoad:239 - done materializing entity [com.fantong.call.entity.KfFunction#13]
17:25:10,187 DEBUG TwoPhaseLoad:131 - resolving associations for [com.fantong.call.entity.KfFunction#14]
17:25:10,187 DEBUG TwoPhaseLoad:239 - done materializing entity [com.fantong.call.entity.KfFunction#14]
17:25:10,203 DEBUG TwoPhaseLoad:131 - resolving associations for [com.fantong.call.entity.KfFunction#15]
17:25:10,203 DEBUG TwoPhaseLoad:239 - done materializing entity [com.fantong.call.entity.KfFunction#15]
17:25:10,203 DEBUG TwoPhaseLoad:131 - resolving associations for [com.fantong.call.entity.KfFunction#16]
17:25:10,203 DEBUG TwoPhaseLoad:239 - done materializing entity [com.fantong.call.entity.KfFunction#16]
17:25:10,203 DEBUG TwoPhaseLoad:131 - resolving associations for [com.fantong.call.entity.KfFunction#41]
17:25:10,203 DEBUG TwoPhaseLoad:239 - done materializing entity [com.fantong.call.entity.KfFunction#41]
17:25:10,203 DEBUG CollectionLoadContext:240 - 1 collections were found in result set for role: com.fantong.call.entity.KfRole.functions
17:25:10,203 DEBUG CollectionLoadContext:283 - collection fully initialized: [com.fantong.call.entity.KfRole.functions#2]
17:25:10,203 DEBUG CollectionLoadContext:249 - 1 collections initialized for role: com.fantong.call.entity.KfRole.functions
17:25:10,203 DEBUG StatefulPersistenceContext:892 - initializing non-lazy collections
17:25:10,203 DEBUG Loader:2078 - done loading collection

普通客服人员------------- end
--scc-----
17:25:10,250 DEBUG DefaultListableBeanFactory:1444 - Invoking afterPropertiesSet() on bean with name '/helloWorld'
17:25:10,250 DEBUG InternalResourceViewResolver:80 - Cached view [/helloWorld]
17:25:10,250 DEBUG DispatcherServlet:1058 - Rendering view [org.springframework.web.servlet.view.JstlView: name '/helloWorld'; URL [/WEB-INF/jsp//helloWorld.jsp]] in DispatcherServlet with name 'callcenter'
17:25:10,250 DEBUG JstlView:232 - Rendering view with name '/helloWorld' with model {kfUser=com.fantong.call.entity.KfUser@13e94d3, org.springframework.validation.BindingResult.kfUser=org.springframework.validation.BeanPropertyBindingResult: 0 errors} and static attributes {}
17:25:10,265 DEBUG JstlView:328 - Added model object 'kfUser' of type [com.fantong.call.entity.KfUser] to request in view with name '/helloWorld'
17:25:10,265 DEBUG JstlView:328 - Added model object 'org.springframework.validation.BindingResult.kfUser' of type [org.springframework.validation.BeanPropertyBindingResult] to request in view with name '/helloWorld'
17:25:10,343 DEBUG JstlView:236 - Forwarding to resource [/WEB-INF/jsp//helloWorld.jsp] in InternalResourceView '/helloWorld'
17:25:10,359 DEBUG DispatcherServlet:670 - Cleared thread-bound request context: org.apache.catalina.connector.RequestFacade@b52821
17:25:10,359 DEBUG DispatcherServlet:677 - Successfully completed request
17:25:10,359 DEBUG XmlWebApplicationContext:299 - Publishing event in WebApplicationContext for namespace 'callcenter-servlet': ServletRequestHandledEvent: url=[/callcenter/user/login]; client=[127.0.0.1]; method=[POST]; servlet=[callcenter]; session=[22ED76D1959066F192301274D4CFFF79]; user=[null]; time=[8875ms]; status=[OK]
17:25:10,359 DEBUG XmlWebApplicationContext:299 - Publishing event in Root WebApplicationContext: ServletRequestHandledEvent: url=[/callcenter/user/login]; client=[127.0.0.1]; method=[POST]; servlet=[callcenter]; session=[22ED76D1959066F192301274D4CFFF79]; user=[null]; time=[8875ms]; status=[OK]
17:25:10,359 DEBUG TransactionSynchronizationManager:229 - Removed value [org.springframework.orm.hibernate3.SessionHolder@ae4d15] for key [org.hibernate.impl.SessionFactoryImpl@1fcc032] from thread [http-8080-1]
17:25:10,359 DEBUG OpenSessionInViewFilter:207 - Closing single Hibernate Session in OpenSessionInViewFilter
17:25:10,359 DEBUG SessionFactoryUtils:789 - Closing Hibernate Session
17:25:10,359 DEBUG ConnectionManager:464 - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
17:25:10,375 DEBUG ConnectionManager:325 - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!