I've created a test case with two very simple classes, and two database tables (six fields total). If all I'm doing is creating an object, adding an instance of a Set defined as a one-to-many element, and then saving it, how is it possible that I'd be getting an exception telling me that the id key of the many instance has been altered? This all occurring within a session, and the error is generated when the transaction is committed.
Any help will be appreciated.
Need help with Hibernate? Read this first:
http://www.hibernate.org/ForumMailingli ... AskForHelp
Hibernate version: 3.2.1.ga
Mapping documents:
-- dbuser.hbm.xml
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
"-//Hibernate/Hibernate Mapping DTD 3.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">
<hibernate-mapping>
<class name="dbtest.DBUser" table="users">
<id name="id" column="id">
<generator class="uuid"/>
</id>
<property name="username" column="username"/>
<property name="realName" column="real_name"/>
<set name="authorities" table="authorities" cascade="all">
<key column="user_id"/>
<one-to-many class="dbtest.Authority"/>
</set>
</class>
</hibernate-mapping>
-- authorities.hbm.xml
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
"-//Hibernate/Hibernate Mapping DTD 3.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">
<hibernate-mapping>
<class name="dbtest.Authority" table="authorities">
<id name="id" column="id">
<generator class="uuid"/>
</id>
<property name="userId" insert="false" update="false">
<column name="user_id" not-null="true"/>
</property>
<property name="roleName" column="role_name"/>
<many-to-one name="user" class="dbtest.DBUser" column="user_id"/>
</class>
</hibernate-mapping>
Code between sessionFactory.openSession() and session.close():
Transaction tx = session.beginTransaction();
DBUser user = new DBUser(name);
Set authSet = user.getAuthorities();
Authority auth = new Authority(user, role);
authSet.add(auth);
session.save(user);
tx.commit();
Full stack trace of any exception that occurs:
org.hibernate.HibernateException: identifier of an instance of dbtest.Authority was altered from 402881e40f075781010f075784a00002 to null
at org.hibernate.event.def.DefaultFlushEntityEventListener.checkId(DefaultFlushEntityEventListener.java:58)
at org.hibernate.event.def.DefaultFlushEntityEventListener.getValues(DefaultFlushEntityEventListener.java:157)
at org.hibernate.event.def.DefaultFlushEntityEventListener.onFlushEntity(DefaultFlushEntityEventListener.java:113)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEntities(AbstractFlushingEventListener.java:196)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:76)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:26)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at dbtest.TestServlet.doGet(TestServlet.java:34)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:747)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:860)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:664)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
at java.lang.Thread.run(Unknown Source)
Name and version of the database you are using:
mysql 5.0.22
The generated SQL (show_sql=true):
No SQL is generated on the standard output.
Debug level Hibernate log excerpt:
2006-11-20 14:48:30,765 [org.hibernate.cfg.Environment] INFO <Hibernate 3.2.1
>2006-11-20 14:48:30,781 [org.hibernate.cfg.Environment] INFO <hibernate.properties not found
>2006-11-20 14:48:30,781 [org.hibernate.cfg.Environment] INFO <Bytecode provider name : cglib
>2006-11-20 14:48:30,796 [org.hibernate.cfg.Environment] INFO <using JDK 1.4 java.sql.Timestamp handling
>2006-11-20 14:48:30,921 [org.hibernate.cfg.Configuration] INFO <configuring from resource: /hibernate.cfg.xml
>2006-11-20 14:48:30,937 [org.hibernate.cfg.Configuration] INFO <Configuration resource: /hibernate.cfg.xml
>2006-11-20 14:48:31,015 [org.hibernate.util.DTDEntityResolver] DEBUG <trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd]
>2006-11-20 14:48:31,015 [org.hibernate.util.DTDEntityResolver] DEBUG <recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
>2006-11-20 14:48:31,015 [org.hibernate.util.DTDEntityResolver] DEBUG <located [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd] in classpath
>2006-11-20 14:48:31,078 [org.hibernate.cfg.Configuration] DEBUG <connection.driver_class=com.mysql.jdbc.Driver
>2006-11-20 14:48:31,078 [org.hibernate.cfg.Configuration] DEBUG <connection.url=jdbc:mysql://localhost/dbtest
>2006-11-20 14:48:31,078 [org.hibernate.cfg.Configuration] DEBUG <connection.username=dbtest
>2006-11-20 14:48:31,078 [org.hibernate.cfg.Configuration] DEBUG <connection.password=dbtest
>2006-11-20 14:48:31,078 [org.hibernate.cfg.Configuration] DEBUG <connection.pool_size=2
>2006-11-20 14:48:31,078 [org.hibernate.cfg.Configuration] DEBUG <dialect=org.hibernate.dialect.MySQLDialect
>2006-11-20 14:48:31,078 [org.hibernate.cfg.Configuration] DEBUG <hibernate_transaction_factory_class=org.hibernate.transaction.JDBCTransactionFactory
>2006-11-20 14:48:31,078 [org.hibernate.cfg.Configuration] DEBUG <current_session_context_class=thread
>2006-11-20 14:48:31,078 [org.hibernate.cfg.Configuration] DEBUG <show_sql=true
>2006-11-20 14:48:31,078 [org.hibernate.cfg.Configuration] DEBUG <null<-org.dom4j.tree.DefaultAttribute@94fe42 [Attribute: name resource value "dbuser.hbm.xml"]
>2006-11-20 14:48:31,078 [org.hibernate.cfg.Configuration] INFO <Reading mappings from resource : dbuser.hbm.xml
>2006-11-20 14:48:31,078 [org.hibernate.util.DTDEntityResolver] DEBUG <trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
>2006-11-20 14:48:31,078 [org.hibernate.util.DTDEntityResolver] DEBUG <recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
>2006-11-20 14:48:31,093 [org.hibernate.util.DTDEntityResolver] DEBUG <located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
>2006-11-20 14:48:31,234 [org.hibernate.cfg.HbmBinder] INFO <Mapping class: dbtest.DBUser -> users
>2006-11-20 14:48:31,265 [org.hibernate.cfg.HbmBinder] DEBUG <Mapped property: id -> id
>2006-11-20 14:48:31,296 [org.hibernate.cfg.HbmBinder] DEBUG <Mapped property: username -> username
>2006-11-20 14:48:31,296 [org.hibernate.cfg.HbmBinder] DEBUG <Mapped property: realName -> real_name
>2006-11-20 14:48:31,296 [org.hibernate.cfg.HbmBinder] DEBUG <Mapped property: authorities
>2006-11-20 14:48:31,296 [org.hibernate.cfg.Configuration] DEBUG <null<-org.dom4j.tree.DefaultAttribute@1be20c [Attribute: name resource value "authority.hbm.xml"]
>2006-11-20 14:48:31,296 [org.hibernate.cfg.Configuration] INFO <Reading mappings from resource : authority.hbm.xml
>2006-11-20 14:48:31,312 [org.hibernate.util.DTDEntityResolver] DEBUG <trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
>2006-11-20 14:48:31,312 [org.hibernate.util.DTDEntityResolver] DEBUG <recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
>2006-11-20 14:48:31,312 [org.hibernate.util.DTDEntityResolver] DEBUG <located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
>2006-11-20 14:48:31,328 [org.hibernate.cfg.HbmBinder] INFO <Mapping class: dbtest.Authority -> authorities
>2006-11-20 14:48:31,328 [org.hibernate.cfg.HbmBinder] DEBUG <Mapped property: id -> id
>2006-11-20 14:48:31,328 [org.hibernate.cfg.HbmBinder] DEBUG <Mapped property: userId -> user_id
>2006-11-20 14:48:31,328 [org.hibernate.cfg.HbmBinder] DEBUG <Mapped property: roleName -> role_name
>2006-11-20 14:48:31,468 [org.hibernate.cfg.HbmBinder] DEBUG <Mapped property: user -> user_id
>2006-11-20 14:48:31,468 [org.hibernate.cfg.Configuration] INFO <Configured SessionFactory: null
>2006-11-20 14:48:31,468 [org.hibernate.cfg.Configuration] DEBUG <properties: {show_sql=true, java.vendor=Sun Microsystems Inc., catalina.base=C:\Program Files\Apache Software Foundation\Tomcat 5.5, hibernate.connection.url=jdbc:mysql://localhost/dbtest, sun.management.compiler=HotSpot Client Compiler, catalina.useNaming=true, os.name=Windows XP, sun.boot.class.path=C:\Program Files\Java\jre1.5.0_09\lib\rt.jar;C:\Program Files\Java\jre1.5.0_09\lib\i18n.jar;C:\Program Files\Java\jre1.5.0_09\lib\sunrsasign.jar;C:\Program Files\Java\jre1.5.0_09\lib\jsse.jar;C:\Program Files\Java\jre1.5.0_09\lib\jce.jar;C:\Program Files\Java\jre1.5.0_09\lib\charsets.jar;C:\Program Files\Java\jre1.5.0_09\classes, java.util.logging.config.file=C:\Program Files\Apache Software Foundation\Tomcat 5.5\conf\logging.properties, hibernate.current_session_context_class=thread, sun.desktop=windows, java.vm.specification.vendor=Sun Microsystems Inc., java.runtime.version=1.5.0_09-b03, user.name=tom, shared.loader=${catalina.base}/shared/classes,${catalina.base}/shared/lib/*.jar, tomcat.util.buf.StringCache.byte.enabled=true, connection.driver_class=com.mysql.jdbc.Driver, current_session_context_class=thread, user.language=en, java.naming.factory.initial=org.apache.naming.java.javaURLContextFactory, sun.boot.library.path=C:\Program Files\Java\jre1.5.0_09\bin, webapp.root=C:\Program Files\Apache Software Foundation\Tomcat 5.5\webapps\acegi-security-sample-contacts-filter\, dialect=org.hibernate.dialect.MySQLDialect, java.version=1.5.0_09, java.util.logging.manager=org.apache.juli.ClassLoaderLogManager, user.timezone=America/Denver, sun.arch.data.model=32, java.endorsed.dirs=C:\Program Files\Apache Software Foundation\Tomcat 5.5\common\endorsed, sun.cpu.isalist=pentium_pro+mmx pentium_pro pentium+mmx pentium i486 i386 i86, sun.jnu.encoding=Cp1252, file.encoding.pkg=sun.io, package.access=sun.,org.apache.catalina.,org.apache.coyote.,org.apache.tomcat.,org.apache.jasper.,sun.beans., file.separator=\, java.specification.name=Java Platform API Specification, java.class.version=49.0, user.country=US, connection.url=jdbc:mysql://localhost/dbtest, java.home=C:\Program Files\Java\jre1.5.0_09, java.vm.info=mixed mode, os.version=5.1, path.separator=;, connection.password=dbtest, java.vm.version=1.5.0_09-b03, hibernate.connection.password=dbtest, user.variant=, java.awt.printerjob=sun.awt.windows.WPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=dbtest, package.definition=sun.,java.,org.apache.catalina.,org.apache.coyote.,org.apache.tomcat.,org.apache.jasper., java.naming.factory.url.pkgs=org.apache.naming, user.home=C:\Documents and Settings\tom, java.specification.vendor=Sun Microsystems Inc., java.library.path=C:\Program Files\Apache Software Foundation\Tomcat 5.5\bin;.;C:\WINDOWS\System32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\system32\WBEM;C:\Program Files\QuickTime\QTSystem\;C:\Program Files\Apache Software Foundation\apache-ant-1.6.5\bin;C:\Program Files\Java\jdk1.5.0_09\bin;C:\Program Files\MySQL\MySQL Server 5.0\bin;C:\Program Files\Pstools;C:\Program Files\GnuWin32\bin, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=com.mysql.jdbc.Driver, connection.username=dbtest, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=org.hibernate.dialect.MySQLDialect, common.loader=${catalina.home}/common/classes,${catalina.home}/common/i18n/*.jar,${catalina.home}/common/endorsed/*.jar,${catalina.home}/common/lib/*.jar, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=C:\Program Files\Apache Software Foundation\Tomcat 5.5\bin\bootstrap.jar, hibernate.bytecode.use_reflection_optimizer=false, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, catalina.home=C:\Program Files\Apache Software Foundation\Tomcat 5.5, hibernate_transaction_factory_class=org.hibernate.transaction.JDBCTransactionFactory, sun.cpu.endian=little, sun.os.patch.level=Service Pack 1, connection.pool_size=2, java.io.tmpdir=C:\Program Files\Apache Software Foundation\Tomcat 5.5\temp, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, server.loader=${catalina.home}/server/classes,${catalina.home}/server/lib/*.jar, os.arch=x86, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.ext.dirs=C:\Program Files\Java\jre1.5.0_09\lib\ext, user.dir=C:\Program Files\Apache Software Foundation\Tomcat 5.5, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, file.encoding=Cp1252, java.specification.version=1.5, hibernate.show_sql=true, hibernate.connection.pool_size=2}
>2006-11-20 14:48:31,468 [org.hibernate.cfg.Configuration] DEBUG <Preparing to build session factory with filters : {}
>2006-11-20 14:48:31,468 [org.hibernate.cfg.Configuration] DEBUG <processing extends queue
>2006-11-20 14:48:31,468 [org.hibernate.cfg.Configuration] DEBUG <processing collection mappings
>2006-11-20 14:48:31,468 [org.hibernate.cfg.CollectionSecondPass] DEBUG <Second pass for collection: dbtest.DBUser.authorities
>2006-11-20 14:48:31,468 [org.hibernate.cfg.HbmBinder] INFO <Mapping collection: dbtest.DBUser.authorities -> authorities
>2006-11-20 14:48:31,468 [org.hibernate.cfg.CollectionSecondPass] DEBUG <Mapped collection key: user_id, one-to-many: dbtest.Authority
>2006-11-20 14:48:31,468 [org.hibernate.cfg.Configuration] DEBUG <processing native query and ResultSetMapping mappings
>2006-11-20 14:48:31,468 [org.hibernate.cfg.Configuration] DEBUG <processing association property references
>2006-11-20 14:48:31,468 [org.hibernate.cfg.Configuration] DEBUG <processing foreign key constraints
>2006-11-20 14:48:31,468 [org.hibernate.cfg.Configuration] DEBUG <resolving reference to class: dbtest.DBUser
>2006-11-20 14:48:31,484 [org.hibernate.connection.DriverManagerConnectionProvider] INFO <Using Hibernate built-in connection pool (not for production use!)
>2006-11-20 14:48:31,484 [org.hibernate.connection.DriverManagerConnectionProvider] INFO <Hibernate connection pool size: 2
>2006-11-20 14:48:31,484 [org.hibernate.connection.DriverManagerConnectionProvider] INFO <autocommit mode: false
>2006-11-20 14:48:31,484 [org.hibernate.connection.DriverManagerConnectionProvider] INFO <using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost/dbtest
>2006-11-20 14:48:31,484 [org.hibernate.connection.DriverManagerConnectionProvider] INFO <connection properties: {user=dbtest, password=dbtest}
>2006-11-20 14:48:31,484 [org.hibernate.connection.DriverManagerConnectionProvider] DEBUG <total checked-out connections: 0
>2006-11-20 14:48:31,484 [org.hibernate.connection.DriverManagerConnectionProvider] DEBUG <opening new JDBC connection
>2006-11-20 14:48:32,312 [org.hibernate.connection.DriverManagerConnectionProvider] DEBUG <created connection to: jdbc:mysql://localhost/dbtest, Isolation Level: 4
>2006-11-20 14:48:32,312 [org.hibernate.cfg.SettingsFactory] INFO <RDBMS: MySQL, version: 5.0.22-community-nt
>2006-11-20 14:48:32,312 [org.hibernate.cfg.SettingsFactory] INFO <JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-3.1.12 ( $Date: 2005-11-17 15:53:48 +0100 (Thu, 17 Nov 2005) $, $Revision$ )
>2006-11-20 14:48:32,312 [org.hibernate.connection.DriverManagerConnectionProvider] DEBUG <returning connection to pool, pool size: 1
>2006-11-20 14:48:32,343 [org.hibernate.dialect.Dialect] INFO <Using dialect: org.hibernate.dialect.MySQLDialect
>2006-11-20 14:48:32,359 [org.hibernate.transaction.TransactionFactoryFactory] INFO <Using default transaction strategy (direct JDBC transactions)
>2006-11-20 14:48:32,359 [org.hibernate.transaction.TransactionManagerLookupFactory] INFO <No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
>2006-11-20 14:48:32,359 [org.hibernate.cfg.SettingsFactory] INFO <Automatic flush during beforeCompletion(): disabled
>2006-11-20 14:48:32,359 [org.hibernate.cfg.SettingsFactory] INFO <Automatic session close at end of transaction: disabled
>2006-11-20 14:48:32,359 [org.hibernate.cfg.SettingsFactory] INFO <JDBC batch size: 15
>2006-11-20 14:48:32,359 [org.hibernate.cfg.SettingsFactory] INFO <JDBC batch updates for versioned data: disabled
>2006-11-20 14:48:32,359 [org.hibernate.cfg.SettingsFactory] INFO <Scrollable result sets: enabled
>2006-11-20 14:48:32,359 [org.hibernate.cfg.SettingsFactory] DEBUG <Wrap result sets: disabled
>2006-11-20 14:48:32,359 [org.hibernate.cfg.SettingsFactory] INFO <JDBC3 getGeneratedKeys(): enabled
>2006-11-20 14:48:32,359 [org.hibernate.cfg.SettingsFactory] INFO <Connection release mode: auto
>2006-11-20 14:48:32,375 [org.hibernate.cfg.SettingsFactory] INFO <Maximum outer join fetch depth: 2
>2006-11-20 14:48:32,375 [org.hibernate.cfg.SettingsFactory] INFO <Default batch fetch size: 1
>2006-11-20 14:48:32,375 [org.hibernate.cfg.SettingsFactory] INFO <Generate SQL with comments: disabled
>2006-11-20 14:48:32,375 [org.hibernate.cfg.SettingsFactory] INFO <Order SQL updates by primary key: disabled
>2006-11-20 14:48:32,375 [org.hibernate.cfg.SettingsFactory] INFO <Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
>2006-11-20 14:48:32,375 [org.hibernate.hql.ast.ASTQueryTranslatorFactory] INFO <Using ASTQueryTranslatorFactory
>2006-11-20 14:48:32,375 [org.hibernate.cfg.SettingsFactory] INFO <Query language substitutions: {}
>2006-11-20 14:48:32,375 [org.hibernate.cfg.SettingsFactory] INFO <JPA-QL strict compliance: disabled
>2006-11-20 14:48:32,375 [org.hibernate.cfg.SettingsFactory] INFO <Second-level cache: enabled
>2006-11-20 14:48:32,375 [org.hibernate.cfg.SettingsFactory] INFO <Query cache: disabled
>2006-11-20 14:48:32,375 [org.hibernate.cfg.SettingsFactory] INFO <Cache provider: org.hibernate.cache.NoCacheProvider
>2006-11-20 14:48:32,375 [org.hibernate.cfg.SettingsFactory] INFO <Optimize cache for minimal puts: disabled
>2006-11-20 14:48:32,375 [org.hibernate.cfg.SettingsFactory] INFO <Structured second-level cache entries: disabled
>2006-11-20 14:48:32,375 [org.hibernate.exception.SQLExceptionConverterFactory] DEBUG <Using dialect defined converter
>2006-11-20 14:48:32,390 [org.hibernate.cfg.SettingsFactory] INFO <Echoing all SQL to stdout
>2006-11-20 14:48:32,390 [org.hibernate.cfg.SettingsFactory] INFO <Statistics: disabled
>2006-11-20 14:48:32,390 [org.hibernate.cfg.SettingsFactory] INFO <Deleted entity synthetic identifier rollback: disabled
>2006-11-20 14:48:32,390 [org.hibernate.cfg.SettingsFactory] INFO <Default entity-mode: pojo
>2006-11-20 14:48:32,453 [org.hibernate.impl.SessionFactoryImpl] INFO <building session factory
>2006-11-20 14:48:32,453 [org.hibernate.impl.SessionFactoryImpl] DEBUG <Session factory constructed with filter configurations : {}
>2006-11-20 14:48:32,453 [org.hibernate.impl.SessionFactoryImpl] DEBUG <instantiating session factory with properties: {java.vendor=Sun Microsystems Inc., show_sql=true, catalina.base=C:\Program Files\Apache Software Foundation\Tomcat 5.5, hibernate.connection.url=jdbc:mysql://localhost/dbtest, sun.management.compiler=HotSpot Client Compiler, catalina.useNaming=true, os.name=Windows XP, sun.boot.class.path=C:\Program Files\Java\jre1.5.0_09\lib\rt.jar;C:\Program Files\Java\jre1.5.0_09\lib\i18n.jar;C:\Program Files\Java\jre1.5.0_09\lib\sunrsasign.jar;C:\Program Files\Java\jre1.5.0_09\lib\jsse.jar;C:\Program Files\Java\jre1.5.0_09\lib\jce.jar;C:\Program Files\Java\jre1.5.0_09\lib\charsets.jar;C:\Program Files\Java\jre1.5.0_09\classes, java.util.logging.config.file=C:\Program Files\Apache Software Foundation\Tomcat 5.5\conf\logging.properties, hibernate.current_session_context_class=thread, sun.desktop=windows, java.vm.specification.vendor=Sun Microsystems Inc., java.runtime.version=1.5.0_09-b03, user.name=tom, shared.loader=${catalina.base}/shared/classes,${catalina.base}/shared/lib/*.jar, tomcat.util.buf.StringCache.byte.enabled=true, connection.driver_class=com.mysql.jdbc.Driver, current_session_context_class=thread, user.language=en, java.naming.factory.initial=org.apache.naming.java.javaURLContextFactory, sun.boot.library.path=C:\Program Files\Java\jre1.5.0_09\bin, webapp.root=C:\Program Files\Apache Software Foundation\Tomcat 5.5\webapps\acegi-security-sample-contacts-filter\, dialect=org.hibernate.dialect.MySQLDialect, java.version=1.5.0_09, java.util.logging.manager=org.apache.juli.ClassLoaderLogManager, user.timezone=America/Denver, sun.arch.data.model=32, java.endorsed.dirs=C:\Program Files\Apache Software Foundation\Tomcat 5.5\common\endorsed, sun.cpu.isalist=pentium_pro+mmx pentium_pro pentium+mmx pentium i486 i386 i86, sun.jnu.encoding=Cp1252, file.encoding.pkg=sun.io, package.access=sun.,org.apache.catalina.,org.apache.coyote.,org.apache.tomcat.,org.apache.jasper.,sun.beans., file.separator=\, java.specification.name=Java Platform API Specification, java.class.version=49.0, user.country=US, connection.url=jdbc:mysql://localhost/dbtest, java.home=C:\Program Files\Java\jre1.5.0_09, java.vm.info=mixed mode, os.version=5.1, path.separator=;, connection.password=dbtest, java.vm.version=1.5.0_09-b03, hibernate.connection.password=dbtest, user.variant=, java.awt.printerjob=sun.awt.windows.WPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=dbtest, package.definition=sun.,java.,org.apache.catalina.,org.apache.coyote.,org.apache.tomcat.,org.apache.jasper., java.naming.factory.url.pkgs=org.apache.naming, user.home=C:\Documents and Settings\tom, java.specification.vendor=Sun Microsystems Inc., java.library.path=C:\Program Files\Apache Software Foundation\Tomcat 5.5\bin;.;C:\WINDOWS\System32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\system32\WBEM;C:\Program Files\QuickTime\QTSystem\;C:\Program Files\Apache Software Foundation\apache-ant-1.6.5\bin;C:\Program Files\Java\jdk1.5.0_09\bin;C:\Program Files\MySQL\MySQL Server 5.0\bin;C:\Program Files\Pstools;C:\Program Files\GnuWin32\bin, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=com.mysql.jdbc.Driver, connection.username=dbtest, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=org.hibernate.dialect.MySQLDialect, common.loader=${catalina.home}/common/classes,${catalina.home}/common/i18n/*.jar,${catalina.home}/common/endorsed/*.jar,${catalina.home}/common/lib/*.jar, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=C:\Program Files\Apache Software Foundation\Tomcat 5.5\bin\bootstrap.jar, hibernate.bytecode.use_reflection_optimizer=false, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, catalina.home=C:\Program Files\Apache Software Foundation\Tomcat 5.5, sun.cpu.endian=little, hibernate_transaction_factory_class=org.hibernate.transaction.JDBCTransactionFactory, sun.os.patch.level=Service Pack 1, connection.pool_size=2, java.io.tmpdir=C:\Program Files\Apache Software Foundation\Tomcat 5.5\temp, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, server.loader=${catalina.home}/server/classes,${catalina.home}/server/lib/*.jar, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, os.arch=x86, java.ext.dirs=C:\Program Files\Java\jre1.5.0_09\lib\ext, user.dir=C:\Program Files\Apache Software Foundation\Tomcat 5.5, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, file.encoding=Cp1252, java.specification.version=1.5, hibernate.connection.pool_size=2, hibernate.show_sql=true}
>2006-11-20 14:48:32,953 [org.hibernate.persister.entity.AbstractEntityPersister] DEBUG <Static SQL for entity: dbtest.Authority
>2006-11-20 14:48:32,953 [org.hibernate.persister.entity.AbstractEntityPersister] DEBUG < Version select: select id from authorities where id =?
>2006-11-20 14:48:32,953 [org.hibernate.persister.entity.AbstractEntityPersister] DEBUG < Snapshot select: select authority_.id, authority_.role_name as role3_1_, authority_.user_id as user2_1_ from authorities authority_ where authority_.id=?
>2006-11-20 14:48:32,953 [org.hibernate.persister.entity.AbstractEntityPersister] DEBUG < Insert 0: insert into authorities (role_name, user_id, id) values (?, ?, ?)
>2006-11-20 14:48:32,953 [org.hibernate.persister.entity.AbstractEntityPersister] DEBUG < Update 0: update authorities set role_name=?, user_id=? where id=?
>2006-11-20 14:48:32,953 [org.hibernate.persister.entity.AbstractEntityPersister] DEBUG < Delete 0: delete from authorities where id=?
>2006-11-20 14:48:32,968 [org.hibernate.persister.entity.AbstractEntityPersister] DEBUG <Static SQL for entity: dbtest.DBUser
>2006-11-20 14:48:32,968 [org.hibernate.persister.entity.AbstractEntityPersister] DEBUG < Version select: select id from users where id =?
>2006-11-20 14:48:32,968 [org.hibernate.persister.entity.AbstractEntityPersister] DEBUG < Snapshot select: select dbuser_.id, dbuser_.username as username0_, dbuser_.real_name as real3_0_ from users dbuser_ where dbuser_.id=?
>2006-11-20 14:48:32,968 [org.hibernate.persister.entity.AbstractEntityPersister] DEBUG < Insert 0: insert into users (username, real_name, id) values (?, ?, ?)
>2006-11-20 14:48:32,968 [org.hibernate.persister.entity.AbstractEntityPersister] DEBUG < Update 0: update users set username=?, real_name=? where id=?
>2006-11-20 14:48:32,968 [org.hibernate.persister.entity.AbstractEntityPersister] DEBUG < Delete 0: delete from users where id=?
>2006-11-20 14:48:32,984 [org.hibernate.persister.collection.AbstractCollectionPersister] DEBUG <Static SQL for collection: dbtest.DBUser.authorities
>2006-11-20 14:48:32,984 [org.hibernate.persister.collection.AbstractCollectionPersister] DEBUG < Row insert: update authorities set user_id=? where id=?
>2006-11-20 14:48:32,984 [org.hibernate.persister.collection.AbstractCollectionPersister] DEBUG < Row delete: update authorities set user_id=null where user_id=? and id=?
>2006-11-20 14:48:32,984 [org.hibernate.persister.collection.AbstractCollectionPersister] DEBUG < One-shot delete: update authorities set user_id=null where user_id=?
>2006-11-20 14:48:33,031 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for entity dbtest.Authority: select authority0_.id as id1_0_, authority0_.user_id as user2_1_0_, authority0_.role_name as role3_1_0_ from authorities authority0_ where authority0_.id=?
>2006-11-20 14:48:33,031 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for entity dbtest.Authority: select authority0_.id as id1_0_, authority0_.user_id as user2_1_0_, authority0_.role_name as role3_1_0_ from authorities authority0_ where authority0_.id=?
>2006-11-20 14:48:33,031 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for entity dbtest.Authority: select authority0_.id as id1_0_, authority0_.user_id as user2_1_0_, authority0_.role_name as role3_1_0_ from authorities authority0_ where authority0_.id=? for update
>2006-11-20 14:48:33,031 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for entity dbtest.Authority: select authority0_.id as id1_0_, authority0_.user_id as user2_1_0_, authority0_.role_name as role3_1_0_ from authorities authority0_ where authority0_.id=? for update
>2006-11-20 14:48:33,031 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for entity dbtest.Authority: select authority0_.id as id1_0_, authority0_.user_id as user2_1_0_, authority0_.role_name as role3_1_0_ from authorities authority0_ where authority0_.id=? for update
>2006-11-20 14:48:33,046 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for action ACTION_MERGE on entity dbtest.Authority: select authority0_.id as id1_0_, authority0_.user_id as user2_1_0_, authority0_.role_name as role3_1_0_ from authorities authority0_ where authority0_.id=?
>2006-11-20 14:48:33,046 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for action ACTION_REFRESH on entity dbtest.Authority: select authority0_.id as id1_0_, authority0_.user_id as user2_1_0_, authority0_.role_name as role3_1_0_ from authorities authority0_ where authority0_.id=?
>2006-11-20 14:48:33,046 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for entity dbtest.DBUser: select dbuser0_.id as id0_0_, dbuser0_.username as username0_0_, dbuser0_.real_name as real3_0_0_ from users dbuser0_ where dbuser0_.id=?
>2006-11-20 14:48:33,046 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for entity dbtest.DBUser: select dbuser0_.id as id0_0_, dbuser0_.username as username0_0_, dbuser0_.real_name as real3_0_0_ from users dbuser0_ where dbuser0_.id=?
>2006-11-20 14:48:33,046 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for entity dbtest.DBUser: select dbuser0_.id as id0_0_, dbuser0_.username as username0_0_, dbuser0_.real_name as real3_0_0_ from users dbuser0_ where dbuser0_.id=? for update
>2006-11-20 14:48:33,046 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for entity dbtest.DBUser: select dbuser0_.id as id0_0_, dbuser0_.username as username0_0_, dbuser0_.real_name as real3_0_0_ from users dbuser0_ where dbuser0_.id=? for update
>2006-11-20 14:48:33,046 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for entity dbtest.DBUser: select dbuser0_.id as id0_0_, dbuser0_.username as username0_0_, dbuser0_.real_name as real3_0_0_ from users dbuser0_ where dbuser0_.id=? for update
>2006-11-20 14:48:33,062 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for action ACTION_MERGE on entity dbtest.DBUser: select dbuser0_.id as id0_1_, dbuser0_.username as username0_1_, dbuser0_.real_name as real3_0_1_, authoritie1_.user_id as user2_3_, authoritie1_.id as id3_, authoritie1_.id as id1_0_, authoritie1_.user_id as user2_1_0_, authoritie1_.role_name as role3_1_0_ from users dbuser0_ left outer join authorities authoritie1_ on dbuser0_.id=authoritie1_.user_id where dbuser0_.id=?
>2006-11-20 14:48:33,062 [org.hibernate.loader.entity.EntityLoader] DEBUG <Static select for action ACTION_REFRESH on entity dbtest.DBUser: select dbuser0_.id as id0_1_, dbuser0_.username as username0_1_, dbuser0_.real_name as real3_0_1_, authoritie1_.user_id as user2_3_, authoritie1_.id as id3_, authoritie1_.id as id1_0_, authoritie1_.user_id as user2_1_0_, authoritie1_.role_name as role3_1_0_ from users dbuser0_ left outer join authorities authoritie1_ on dbuser0_.id=authoritie1_.user_id where dbuser0_.id=?
>2006-11-20 14:48:33,062 [org.hibernate.loader.collection.OneToManyLoader] DEBUG <Static select for one-to-many dbtest.DBUser.authorities: select authoritie0_.user_id as user2_1_, authoritie0_.id as id1_, authoritie0_.id as id1_0_, authoritie0_.user_id as user2_1_0_, authoritie0_.role_name as role3_1_0_ from authorities authoritie0_ where authoritie0_.user_id=?
>2006-11-20 14:48:33,078 [org.hibernate.impl.SessionFactoryObjectFactory] DEBUG <initializing class SessionFactoryObjectFactory
>2006-11-20 14:48:33,078 [org.hibernate.impl.SessionFactoryObjectFactory] DEBUG <registered: 402881e40f075781010f075783b60000 (unnamed)
>2006-11-20 14:48:33,078 [org.hibernate.impl.SessionFactoryObjectFactory] INFO <Not binding factory to JNDI, no JNDI name configured
>2006-11-20 14:48:33,078 [org.hibernate.impl.SessionFactoryImpl] DEBUG <instantiated session factory
>2006-11-20 14:48:33,093 [org.hibernate.impl.SessionFactoryImpl] DEBUG <Checking 0 named HQL queries
>2006-11-20 14:48:33,093 [org.hibernate.impl.SessionFactoryImpl] DEBUG <Checking 0 named SQL queries
>2006-11-20 14:48:33,171 [org.hibernate.impl.SessionImpl] DEBUG <opened session at timestamp: 11640593131
>2006-11-20 14:48:33,250 [org.hibernate.context.ThreadLocalSessionContext] DEBUG <allowing method [beginTransaction] in non-transacted context
>2006-11-20 14:48:33,250 [org.hibernate.context.ThreadLocalSessionContext] DEBUG <allowing proxied method [beginTransaction] to proceed to real session
>2006-11-20 14:48:33,250 [org.hibernate.transaction.JDBCTransaction] DEBUG <begin
>2006-11-20 14:48:33,250 [org.hibernate.jdbc.ConnectionManager] DEBUG <opening JDBC connection
>2006-11-20 14:48:33,250 [org.hibernate.connection.DriverManagerConnectionProvider] DEBUG <total checked-out connections: 0
>2006-11-20 14:48:33,250 [org.hibernate.connection.DriverManagerConnectionProvider] DEBUG <using pooled JDBC connection, pool size: 0
>2006-11-20 14:48:33,250 [org.hibernate.transaction.JDBCTransaction] DEBUG <current autocommit status: false
>2006-11-20 14:48:33,250 [org.hibernate.jdbc.JDBCContext] DEBUG <after transaction begin
>2006-11-20 14:48:33,250 [dbtest.TestServlet] INFO <users_id: null users_username: ffnvcnng
>2006-11-20 14:48:33,250 [dbtest.TestServlet] INFO <auth_id: nullauth_user_id: null
>2006-11-20 14:48:33,250 [org.hibernate.context.ThreadLocalSessionContext] DEBUG <allowing proxied method [save] to proceed to real session
>2006-11-20 14:48:33,265 [org.hibernate.event.def.DefaultSaveOrUpdateEventListener] DEBUG <saving transient instance
>2006-11-20 14:48:33,265 [org.hibernate.event.def.AbstractSaveEventListener] DEBUG <generated identifier: 402881e40f075781010f075784710001, using strategy: org.hibernate.id.UUIDHexGenerator
>2006-11-20 14:48:33,265 [org.hibernate.event.def.AbstractSaveEventListener] DEBUG <saving [dbtest.DBUser#402881e40f075781010f075784710001]
>2006-11-20 14:48:33,265 [org.hibernate.engine.Cascade] DEBUG <processing cascade ACTION_SAVE_UPDATE for: dbtest.DBUser
>2006-11-20 14:48:33,265 [org.hibernate.engine.Cascade] DEBUG <done processing cascade ACTION_SAVE_UPDATE for: dbtest.DBUser
>2006-11-20 14:48:33,281 [org.hibernate.event.def.WrapVisitor] DEBUG <Wrapped collection in role: dbtest.DBUser.authorities
>2006-11-20 14:48:33,296 [org.hibernate.engine.Cascade] DEBUG <processing cascade ACTION_SAVE_UPDATE for: dbtest.DBUser
>2006-11-20 14:48:33,296 [org.hibernate.engine.Cascade] DEBUG <cascade ACTION_SAVE_UPDATE for collection: dbtest.DBUser.authorities
>2006-11-20 14:48:33,312 [org.hibernate.engine.CascadingAction] DEBUG <cascading to saveOrUpdate: dbtest.Authority
>2006-11-20 14:48:33,312 [org.hibernate.event.def.AbstractSaveEventListener] DEBUG <transient instance of: dbtest.Authority
>2006-11-20 14:48:33,312 [org.hibernate.event.def.DefaultSaveOrUpdateEventListener] DEBUG <saving transient instance
>2006-11-20 14:48:33,312 [org.hibernate.event.def.AbstractSaveEventListener] DEBUG <generated identifier: 402881e40f075781010f075784a00002, using strategy: org.hibernate.id.UUIDHexGenerator
>2006-11-20 14:48:33,312 [org.hibernate.event.def.AbstractSaveEventListener] DEBUG <saving [dbtest.Authority#402881e40f075781010f075784a00002]
>2006-11-20 14:48:33,312 [org.hibernate.engine.Cascade] DEBUG <done cascade ACTION_SAVE_UPDATE for collection: dbtest.DBUser.authorities
>2006-11-20 14:48:33,312 [org.hibernate.engine.Cascade] DEBUG <done processing cascade ACTION_SAVE_UPDATE for: dbtest.DBUser
>2006-11-20 14:48:33,312 [dbtest.TestServlet] INFO <users_id: 402881e40f075781010f075784710001 users_username: ffnvcnng
>2006-11-20 14:48:33,312 [dbtest.TestServlet] INFO <auth_id: nullauth_user_id: null
>2006-11-20 14:48:33,312 [org.hibernate.transaction.JDBCTransaction] DEBUG <commit
>2006-11-20 14:48:33,312 [org.hibernate.impl.SessionImpl] DEBUG <automatically flushing session
>2006-11-20 14:48:33,312 [org.hibernate.event.def.AbstractFlushingEventListener] DEBUG <flushing session
>2006-11-20 14:48:33,312 [org.hibernate.event.def.AbstractFlushingEventListener] DEBUG <processing flush-time cascades
>2006-11-20 14:48:33,312 [org.hibernate.engine.Cascade] DEBUG <processing cascade ACTION_SAVE_UPDATE for: dbtest.DBUser
>2006-11-20 14:48:33,312 [org.hibernate.engine.Cascade] DEBUG <cascade ACTION_SAVE_UPDATE for collection: dbtest.DBUser.authorities
>2006-11-20 14:48:33,312 [org.hibernate.engine.CascadingAction] DEBUG <cascading to saveOrUpdate: dbtest.Authority
>2006-11-20 14:48:33,312 [org.hibernate.event.def.AbstractSaveEventListener] DEBUG <persistent instance of: dbtest.Authority
>2006-11-20 14:48:33,312 [org.hibernate.event.def.DefaultSaveOrUpdateEventListener] DEBUG <ignoring persistent instance
>2006-11-20 14:48:33,312 [org.hibernate.event.def.DefaultSaveOrUpdateEventListener] DEBUG <object already associated with session: [dbtest.Authority#402881e40f075781010f075784a00002]
>2006-11-20 14:48:33,312 [org.hibernate.engine.Cascade] DEBUG <done cascade ACTION_SAVE_UPDATE for collection: dbtest.DBUser.authorities
>2006-11-20 14:48:33,312 [org.hibernate.engine.Cascade] DEBUG <done processing cascade ACTION_SAVE_UPDATE for: dbtest.DBUser
>2006-11-20 14:48:33,312 [org.hibernate.event.def.AbstractFlushingEventListener] DEBUG <dirty checking collections
>2006-11-20 14:48:33,312 [org.hibernate.event.def.AbstractFlushingEventListener] DEBUG <Flushing entities and processing referenced collections
>2006-11-20 14:48:33,328 [org.hibernate.engine.Collections] DEBUG <Collection found: [dbtest.DBUser.authorities#402881e40f075781010f075784710001], was: [<unreferenced>] (initialized)
>2006-11-20 14:48:33,328 [org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/dbtest].[dbtest]] ERROR <Servlet.service() for servlet dbtest threw exception
>org.hibernate.HibernateException: identifier of an instance of dbtest.Authority was altered from 402881e40f075781010f075784a00002 to null
at org.hibernate.event.def.DefaultFlushEntityEventListener.checkId(DefaultFlushEntityEventListener.java:58)
at org.hibernate.event.def.DefaultFlushEntityEventListener.getValues(DefaultFlushEntityEventListener.java:157)
at org.hibernate.event.def.DefaultFlushEntityEventListener.onFlushEntity(DefaultFlushEntityEventListener.java:113)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEntities(AbstractFlushingEventListener.java:196)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:76)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:26)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at dbtest.TestServlet.doGet(TestServlet.java:34)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:747)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:860)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:664)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
at java.lang.Thread.run(Unknown Source)
Problems with Session and transaction handling?
Read this:
http://hibernate.org/42.html