Hi there,
For some reason, when I store an object whose properties are all null as a composite element in a map within another parent, when I retrieve the parent, while the object's key is still in the map, it returns a null value. I think I am missing something.
I have a "base" class for many objects I hibernate called Item. Item has a property that is a Map called roleAccesses (has appropriate getters and setters) whose values are instances of a class called RoleAccess.
Code:
/**
* Represents the time period a role has access to an item.
*
* @author rudy
*
*/
public class RoleAccess {
private Date activeDate; // the start date of access
private Date expirationDate; // the end date of access
/**
* The start date of access/
* @return the start date.
*/
public Date getActiveDate() {
return activeDate;
}
/**
* Sets the start date of access.
* @param activeDate the date.
*/
public void setActiveDate(Date activeDate) {
this.activeDate = activeDate;
}
/**
* The end date of access.
* @return The date.
*/
public Date getExpirationDate() {
return expirationDate;
}
/**
* Sets the end date of access.
*
* @param expirationDate date
*/
public void setExpirationDate(Date expirationDate) {
this.expirationDate = expirationDate;
}
/**
* Empty constructor for use by hibernate.
*/
public RoleAccess() {
}
/**
* Utility constructor.
* @param activeDate the start date of access.
* @param expirationDate the end date.
*/
public RoleAccess(Date activeDate, Date expirationDate) {
this.activeDate = activeDate;
this.expirationDate = expirationDate;
}
}
Now, the activeDate and expirationDate properties of RoleAccess CAN be null.
I hibernate a subclass of item called Section. As can be seen in the mapping document following, the roleAccesses Map becomes a <map> of composite elements.
Code:
<class name="Section" table="sect_section">
<cache usage="nonstrict-read-write"/>
<id name="id" column="sect_id">
<generator class="uuid.hex"></generator>
</id>
<property name="siteId" column="site_id"/>
<property name="legacyId" column="sect_legacyid"/>
<property name="title" column="sect_title"/>
<property name="shortTitle" column="sect_shorttitle"/>
<property name="description" column="sect_description" />
<property name="publishedDate" column="sect_publisheddate"/>
<property name="lastUpdatedDate" column="sect_lastupdateddate"/>
<property name="language" column="sect_language" />
<property name="displayOrder" column="sect_displayorder"/>
<many-to-one name="parent" class="Section" column="sect_id_parent"/>
<bag name="children" inverse="true" order-by="sect_displayorder">
<cache usage="nonstrict-read-write"/>
<key column="sect_id_parent"/>
<one-to-many class="Section"/>
</bag>
<map name="roleAccesses" cascade="all" table="stra_section_roleaccess">
<cache usage="nonstrict-read-write"/>
<key column="sect_id"/>
<index type="string" column="stra_role"/>
<composite-element class="com.conceptis.pcl.item.RoleAccess">
<property name="activeDate" column="stra_activedate" type="date"/>
<property name="expirationDate" column="stra_expirationdate" type="date"/>
</composite-element>
</map>
</class>
Now here is the following code I execute as part of a unit test (under JUnit)
Code:
final Date publishedDate = new Date(System.currentTimeMillis());
final Date lastUpdatedDate =
new Date(System.currentTimeMillis() + TestConstants.DAY_IN_MILLIS);
session = sessionFactory.openSession();
transaction = session.beginTransaction();
HashMap zRoleAccesses = new HashMap();
RoleAccess userRoleAccess =
new RoleAccess(publishedDate,lastUpdatedDate);
RoleAccess editorRoleAccess =
new RoleAccess(publishedDate,lastUpdatedDate);
// Creating god access with no begin or end date (both null)
RoleAccess godRoleAccess =
new RoleAccess(null,null);
zRoleAccesses.put("user", userRoleAccess);
zRoleAccesses.put("editor", editorRoleAccess);
zRoleAccesses.put("god",godRoleAccess);
z =
new Section(
siteId,
"Z",
publishedDate,
lastUpdatedDate,
"Z",
"Z",
" ",
"en",
zRoleAccesses,
100);
session.save(z);
transaction.commit();
session.close();
session = sessionFactory.openSession();
Section returnedZ = retrieveSection("section.legacyId = 'Z'");
Map returnedRoleAccesses = returnedZ.getRoleAccesses();
assertEquals("Role access count",3,returnedRoleAccesses.size());
assertNotNull("user role access", returnedRoleAccesses.get("user"));
assertNotNull("editor role access", returnedRoleAccesses.get("editor"));
// Interesting bit
assertTrue("god key present",returnedRoleAccesses.containsKey("god"));
assertNotNull("god role access", returnedRoleAccesses.get("god"));
assertNull("no sponsor role access", returnedRoleAccesses.get("sponsor"));
session.close();
Running this unit test, no exceptions are thrown except the assertion that the map returns a non-null value for the key "god" fails. Note this is AFTER the assertion that there is a "god" key in the map. Debugging shows the key exists in the map object, but unlike "user" and "editor" it does not have a RoleAccess instance as a value. This behaviour is not what I expect, obviously; I was expecting to find a RoleAccess under the "god" key whose activeDate and expirationDate are both null! (BTW all other assertions work fine; the "editor" and "user" key assertions all pass),
Now, interestingly if I change the above code so that when I create the "god" RoleAccess I give it either a non-null active date or expiration date, everything works out.
This code is using the 2.1.2 release of hibernate with an Oracle 9i database (9.2 I believe) As I said, no exception is being thrown, it simply fails the unit test at the non-null insertion.
Here is a debug level log from running just this test case.
[code]
17:54:04,144 INFO Environment:462 - Hibernate 2.1.2
17:54:04,144 INFO Environment:491 - hibernate.properties not found
17:54:04,154 INFO Environment:519 - using CGLIB reflection optimizer
17:54:04,154 INFO Configuration:854 - configuring from resource: /hibernate.cfg.xml
17:54:04,165 INFO Configuration:826 - Configuration resource: /hibernate.cfg.xml
17:54:04,205 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibernate-configuration-2.0.dtd in classpath under net/sf/hibernate/
17:54:04,215 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibernate-configuration-2.0.dtd in classpath
17:54:04,265 DEBUG Configuration:812 - dialect=net.sf.hibernate.dialect.Oracle9Dialect
17:54:04,265 DEBUG Configuration:812 - dialect=net.sf.hibernate.dialect.OracleDialect
17:54:04,265 DEBUG Configuration:812 - connection.driver_class=oracle.jdbc.driver.OracleDriver
17:54:04,275 DEBUG Configuration:812 - connection.username=rudy
17:54:04,275 DEBUG Configuration:812 - connection.password=rudy
17:54:04,275 DEBUG Configuration:812 - connection.url=jdbc:oracle:thin:@gandalf.conceptis.com:1521:D1MSW
17:54:04,275 DEBUG Configuration:812 - hibernate.connection.pool_size=5
17:54:04,275 DEBUG Configuration:812 - hibernate.cache.use_query_cache=true
17:54:04,275 DEBUG Configuration:812 - hibernate.transaction.factory_class=net.sf.hibernate.transaction.JDBCTransactionFactory
17:54:04,275 DEBUG Configuration:971 - null<-org.dom4j.tree.DefaultAttribute@1125127 [Attribute: name resource value "com/conceptis/pcl/item/structure/Section.hbm.xml"]
17:54:04,275 INFO Configuration:311 - Mapping resource: com/conceptis/pcl/item/structure/Section.hbm.xml
17:54:04,275 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath under net/sf/hibernate/
17:54:04,285 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath
17:54:04,355 INFO Binder:229 - Mapping class: com.conceptis.pcl.item.structure.Section -> sect_section
17:54:04,365 DEBUG CacheFactory:32 - cache for: com.conceptis.pcl.item.structure.Section usage strategy: nonstrict-read-write
17:54:04,415 DEBUG Binder:462 - Mapped property: id -> sect_id, type: string
17:54:04,425 DEBUG Binder:462 - Mapped property: siteId -> site_id, type: string
17:54:04,425 DEBUG Binder:462 - Mapped property: legacyId -> sect_legacyid, type: string
17:54:04,425 DEBUG Binder:462 - Mapped property: title -> sect_title, type: string
17:54:04,425 DEBUG Binder:462 - Mapped property: shortTitle -> sect_shorttitle, type: string
17:54:04,425 DEBUG Binder:462 - Mapped property: description -> sect_description, type: string
17:54:04,425 DEBUG Binder:462 - Mapped property: publishedDate -> sect_publisheddate, type: timestamp
17:54:04,435 DEBUG Binder:462 - Mapped property: lastUpdatedDate -> sect_lastupdateddate, type: timestamp
17:54:04,435 DEBUG Binder:462 - Mapped property: language -> sect_language, type: string
17:54:04,435 DEBUG Binder:462 - Mapped property: displayOrder -> sect_displayorder, type: integer
17:54:04,435 DEBUG Binder:462 - Mapped property: parent -> sect_id_parent, type: com.conceptis.pcl.item.structure.Section
17:54:04,445 DEBUG Binder:462 - Mapped property: children, type: java.util.Collection
17:54:04,445 INFO Binder:547 - Mapping collection: com.conceptis.pcl.item.structure.Section.roleAccesses -> stra_section_roleaccess
17:54:04,455 DEBUG Binder:462 - Mapped property: roleAccesses, type: java.util.Map
17:54:04,455 DEBUG Configuration:971 - null<-org.dom4j.tree.DefaultAttribute@134a7d8 [Attribute: name resource value "com/conceptis/pcl/item/structure/Topic.hbm.xml"]
17:54:04,455 INFO Configuration:311 - Mapping resource: com/conceptis/pcl/item/structure/Topic.hbm.xml
17:54:04,455 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath under net/sf/hibernate/
17:54:04,455 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath
17:54:04,485 INFO Binder:229 - Mapping class: com.conceptis.pcl.item.structure.Topic -> topc_topic
17:54:04,485 DEBUG CacheFactory:32 - cache for: com.conceptis.pcl.item.structure.Topic usage strategy: nonstrict-read-write
17:54:04,485 DEBUG Binder:462 - Mapped property: id -> topc_id, type: string
17:54:04,495 DEBUG Binder:462 - Mapped property: siteId -> site_id, type: string
17:54:04,495 DEBUG Binder:462 - Mapped property: legacyId -> topc_legacyid, type: string
17:54:04,495 DEBUG Binder:462 - Mapped property: title -> topc_title, type: string
17:54:04,495 DEBUG Binder:462 - Mapped property: shortTitle -> topc_shorttitle, type: string
17:54:04,505 DEBUG Binder:462 - Mapped property: description -> topc_description, type: string
17:54:04,505 DEBUG Binder:462 - Mapped property: publishedDate -> topc_publisheddate, type: timestamp
17:54:04,505 DEBUG Binder:462 - Mapped property: lastUpdatedDate -> topc_lastupdateddate, type: timestamp
17:54:04,505 DEBUG Binder:462 - Mapped property: language -> topc_language, type: string
17:54:04,505 DEBUG Binder:462 - Mapped property: displayOrder -> topc_displayorder, type: integer
17:54:04,505 DEBUG Binder:462 - Mapped property: topicGroup -> tpgr_id, type: com.conceptis.pcl.item.structure.TopicGroup
17:54:04,505 INFO Binder:547 - Mapping collection: com.conceptis.pcl.item.structure.Topic.keywords -> tpkw_topic_keyword
17:54:04,515 DEBUG Binder:462 - Mapped property: keywords, type: java.util.Set
17:54:04,515 INFO Binder:547 - Mapping collection: com.conceptis.pcl.item.structure.Topic.roleAccesses -> tpra_topic_roleaccess
17:54:04,515 DEBUG Binder:462 - Mapped property: roleAccesses, type: java.util.Map
17:54:04,515 DEBUG Configuration:971 - null<-org.dom4j.tree.DefaultAttribute@982589 [Attribute: name resource value "com/conceptis/pcl/item/structure/TopicGroup.hbm.xml"]
17:54:04,515 INFO Configuration:311 - Mapping resource: com/conceptis/pcl/item/structure/TopicGroup.hbm.xml
17:54:04,515 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath under net/sf/hibernate/
17:54:04,525 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath
17:54:04,535 INFO Binder:229 - Mapping class: com.conceptis.pcl.item.structure.TopicGroup -> tpgr_topicgroup
17:54:04,535 DEBUG CacheFactory:32 - cache for: com.conceptis.pcl.item.structure.TopicGroup usage strategy: nonstrict-read-write
17:54:04,535 DEBUG Binder:462 - Mapped property: id -> tpgr_id, type: string
17:54:04,535 DEBUG Binder:462 - Mapped property: siteId -> site_id, type: string
17:54:04,535 DEBUG Binder:462 - Mapped property: legacyId -> tpgr_legacyid, type: string
17:54:04,535 DEBUG Binder:462 - Mapped property: title -> tpgr_title, type: string
17:54:04,535 DEBUG Binder:462 - Mapped property: shortTitle -> tpgr_shorttitle, type: string
17:54:04,535 DEBUG Binder:462 - Mapped property: description -> tpgr_description, type: string
17:54:04,535 DEBUG Binder:462 - Mapped property: publishedDate -> tpgr_publisheddate, type: timestamp
17:54:04,545 DEBUG Binder:462 - Mapped property: lastUpdatedDate -> tpgr_lastupdateddate, type: timestamp
17:54:04,545 DEBUG Binder:462 - Mapped property: language -> tpgr_language, type: string
17:54:04,545 DEBUG Binder:462 - Mapped property: displayOrder -> tpgr_displayorder, type: integer
17:54:04,545 DEBUG Binder:462 - Mapped property: topics, type: java.util.Collection
17:54:04,545 INFO Binder:547 - Mapping collection: com.conceptis.pcl.item.structure.TopicGroup.roleAccesses -> tgra_topicgroup_roleaccess
17:54:04,545 DEBUG Binder:462 - Mapped property: roleAccesses, type: java.util.Map
17:54:04,545 DEBUG Configuration:971 - null<-org.dom4j.tree.DefaultAttribute@1c0e45a [Attribute: name resource value "com/conceptis/pcl/item/SearchContent.hbm.xml"]
17:54:04,545 INFO Configuration:311 - Mapping resource: com/conceptis/pcl/item/SearchContent.hbm.xml
17:54:04,565 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath under net/sf/hibernate/
17:54:04,565 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath
17:54:04,595 INFO Binder:229 - Mapping class: com.conceptis.pcl.item.SearchContent -> srct_searchcontent
17:54:04,595 DEBUG Binder:462 - Mapped property: itemId -> cont_id, type: string
17:54:04,595 DEBUG Binder:462 - Mapped property: siteId -> site_id, type: string
17:54:04,595 DEBUG Binder:462 - Mapped property: xml -> srct_searchxml, type: com.conceptis.pcl.hibernate.type.StringClobType
17:54:04,595 INFO Configuration:1017 - Configured SessionFactory: null
17:54:04,605 DEBUG Configuration:1018 - properties: {hibernate.connection.password=rudy, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, test.pcl.siteid=RUDY, sun.boot.library.path=C:\j2sdk1.4.2_03\jre\bin, java.vm.version=1.4.2_03-b02, hibernate.connection.username=rudy, java.vm.vendor=Sun Microsystems Inc., java.vendor.url=http://java.sun.com/, hibernate.cache.use_query_cache=true, path.separator=;, java.vm.name=Java HotSpot(TM) Client VM, file.encoding.pkg=sun.io, user.country=US, sun.os.patch.level=Service Pack 4, java.vm.specification.name=Java Virtual Machine Specification, user.dir=C:\dev\pcl, java.runtime.version=1.4.2_03-b02, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.endorsed.dirs=C:\j2sdk1.4.2_03\jre\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\rudy\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows 2000, sun.java2d.fontpath=, java.library.path=C:\j2sdk1.4.2_03\bin;.;C:\WINNT\system32;C:\WINNT;C:\j2sdk1.4.2_03\bin;C:\oracle\ora92\bin;C:\Program Files\Oracle\jre\1.3.1\bin;C:\Program Files\Oracle\jre\1.1.8\bin;C:\WINNT\system32;C:\WINNT;C:\WINNT\System32\Wbem;C:\Program Files\ATI Technologies\ATI Control Panel;C:\Program Files\OpenSSH\bin;C:\aspectj1.1\bin;C:\apache-ant-1.5.4\bin, java.specification.name=Java Platform API Specification, java.class.version=48.0, hibernate.connection.pool_size=5, hibernate.transaction.factory_class=net.sf.hibernate.transaction.JDBCTransactionFactory, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, os.version=5.0, connection.password=rudy, user.home=C:\Documents and Settings\rudy, user.timezone=America/New_York, connection.username=rudy, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=Cp1252, java.specification.version=1.4, hibernate.connection.driver_class=oracle.jdbc.driver.OracleDriver, user.name=rudy, java.class.path=C:/Program Files/eclipse/plugins/org.eclipse.jdt.junit_2.1.1/junitsupport.jar;C:\dev\pcl\build\classes;C:\dev\tools\hibernate-2.1\hibernate2.jar;C:\dev\tools\jakarta-struts-1.1\lib\struts.jar;C:\dev\tools\junit3.8.1\junit.jar;C:\dev\tools\hibernate-2.1\lib\odmg.jar;C:\dev\tools\hibernate-2.1\lib\commons-collections.jar;C:\dev\tools\hibernate-2.1\lib\commons-logging.jar;C:\dev\tools\hibernate-2.1\lib\dom4j.jar;C:\dev\tools\hibernate-2.1\lib\ehcache.jar;C:\dev\tools\hibernate-2.1\lib\jdbc2_0-stdext.jar;C:\dev\tools\hibernate-2.1\lib\jta.jar;C:\dev\tools\hibernate-2.1\lib\cglib2.jar;C:\dev\pcl\lib\servlet-2.3.jar;C:\dev\pcl\test\hibernateconfig;C:\dev\tools\mysql-connector-java-3.0.9-stable\mysql-connector-java-3.0.9-stable-bin.jar;C:\dev\cms\cms-client\webapps\WEB-INF\lib\cms-beans-0.1a.jar;C:\dev\pcl\lib\classes12.zip;C:\dev\tools\hibernate-2.1\lib\log4j-1.2.8.jar, java.vm.specification.version=1.0, java.home=C:\j2sdk1.4.2_03\jre, sun.arch.data.model=32, hibernate.connection.url=jdbc:oracle:thin:@gandalf.conceptis.com:1521:D1MSW, hibernate.dialect=net.sf.hibernate.dialect.OracleDialect, user.language=en, java.specification.vendor=Sun Microsystems Inc., awt.toolkit=sun.awt.windows.WToolkit, hibernate.cglib.use_reflection_optimizer=true, java.vm.info=mixed mode, java.version=1.4.2_03, java.ext.dirs=C:\j2sdk1.4.2_03\jre\lib\ext, sun.boot.class.path=C:\j2sdk1.4.2_03\jre\lib\rt.jar;C:\j2sdk1.4.2_03\jre\lib\i18n.jar;C:\j2sdk1.4.2_03\jre\lib\sunrsasign.jar;C:\j2sdk1.4.2_03\jre\lib\jsse.jar;C:\j2sdk1.4.2_03\jre\lib\jce.jar;C:\j2sdk1.4.2_03\jre\lib\charsets.jar;C:\j2sdk1.4.2_03\jre\classes, java.vendor=Sun Microsystems Inc., connection.driver_class=oracle.jdbc.driver.OracleDriver, file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, connection.url=jdbc:oracle:thin:@gandalf.conceptis.com:1521:D1MSW, dialect=net.sf.hibernate.dialect.OracleDialect, sun.cpu.isalist=pentium i486 i386}
17:54:04,605 INFO Configuration:595 - processing one-to-many association mappings
17:54:04,605 DEBUG Binder:1326 - Second pass for collection: com.conceptis.pcl.item.structure.Section.children
17:54:04,605 INFO Binder:1154 - Mapping collection: com.conceptis.pcl.item.structure.Section.children -> sect_section
17:54:04,605 DEBUG CacheFactory:32 - cache for: com.conceptis.pcl.item.structure.Section.children usage strategy: nonstrict-read-write
17:54:04,605 DEBUG Binder:1341 - Mapped collection key: sect_id_parent, one-to-many: com.conceptis.pcl.item.structure.Section
17:54:04,605 DEBUG Binder:1326 - Second pass for collection: com.conceptis.pcl.item.structure.Section.roleAccesses
17:54:04,605 DEBUG CacheFactory:32 - cache for: com.conceptis.pcl.item.structure.Section.roleAccesses usage strategy: nonstrict-read-write
17:54:04,605 DEBUG Binder:462 - Mapped property: activeDate -> stra_activedate, type: timestamp
17:54:04,605 DEBUG Binder:462 - Mapped property: expirationDate -> stra_expirationdate, type: timestamp
17:54:04,745 DEBUG Binder:1341 - Mapped collection key: sect_id, index: stra_role, element: stra_activedate, stra_expirationdate, type: com.conceptis.pcl.item.RoleAccess
17:54:04,745 DEBUG Binder:1326 - Second pass for collection: com.conceptis.pcl.item.structure.Topic.keywords
17:54:04,745 DEBUG CacheFactory:32 - cache for: com.conceptis.pcl.item.structure.Topic.keywords usage strategy: nonstrict-read-write
17:54:04,745 DEBUG Binder:1341 - Mapped collection key: topc_id, element: tpkw_keyword, type: string
17:54:04,745 DEBUG Binder:1326 - Second pass for collection: com.conceptis.pcl.item.structure.Topic.roleAccesses
17:54:04,745 DEBUG CacheFactory:32 - cache for: com.conceptis.pcl.item.structure.Topic.roleAccesses usage strategy: nonstrict-read-write
17:54:04,745 DEBUG Binder:462 - Mapped property: activeDate -> tpra_activedate, type: timestamp
17:54:04,745 DEBUG Binder:462 - Mapped property: expirationDate -> tpra_expirationdate, type: timestamp
17:54:04,745 DEBUG Binder:1341 - Mapped collection key: topc_id, index: tpra_role, element: tpra_activedate, tpra_expirationdate, type: com.conceptis.pcl.item.RoleAccess
17:54:04,745 DEBUG Binder:1326 - Second pass for collection: com.conceptis.pcl.item.structure.TopicGroup.topics
17:54:04,745 INFO Binder:1154 - Mapping collection: com.conceptis.pcl.item.structure.TopicGroup.topics -> topc_topic
17:54:04,745 DEBUG CacheFactory:32 - cache for: com.conceptis.pcl.item.structure.TopicGroup.topics usage strategy: nonstrict-read-write
17:54:04,745 DEBUG Binder:1341 - Mapped collection key: tpgr_id, one-to-many: com.conceptis.pcl.item.structure.Topic
17:54:04,755 DEBUG Binder:1326 - Second pass for collection: com.conceptis.pcl.item.structure.TopicGroup.roleAccesses
17:54:04,755 DEBUG CacheFactory:32 - cache for: com.conceptis.pcl.item.structure.TopicGroup.roleAccesses usage strategy: nonstrict-read-write
17:54:04,755 DEBUG Binder:462 - Mapped property: activeDate -> tgra_activedate, type: timestamp
17:54:04,755 DEBUG Binder:462 - Mapped property: expirationDate -> tgra_expirationdate, type: timestamp
17:54:04,755 DEBUG Binder:1341 - Mapped collection key: tpgr_id, index: tgra_role, element: tgra_activedate, tgra_expirationdate, type: com.conceptis.pcl.item.RoleAccess
17:54:04,755 INFO Configuration:604 - processing one-to-one association property references
17:54:04,755 INFO Configuration:629 - processing foreign key constraints
17:54:04,755 DEBUG Configuration:639 - resolving reference to class: com.conceptis.pcl.item.structure.Topic
17:54:04,755 DEBUG Configuration:639 - resolving reference to class: com.conceptis.pcl.item.structure.Section
17:54:04,755 DEBUG Configuration:639 - resolving reference to class: com.conceptis.pcl.item.structure.Section
17:54:04,755 DEBUG Configuration:639 - resolving reference to class: com.conceptis.pcl.item.structure.Topic
17:54:04,755 DEBUG Configuration:639 - resolving reference to class: com.conceptis.pcl.item.structure.TopicGroup
17:54:04,755 DEBUG Configuration:639 - resolving reference to class: com.conceptis.pcl.item.structure.TopicGroup
17:54:04,785 INFO Dialect:82 - Using dialect: net.sf.hibernate.dialect.OracleDialect
17:54:04,795 INFO SettingsFactory:62 - Use outer join fetching: true
17:54:04,795 INFO DriverManagerConnectionProvider:41 - Using Hibernate built-in connection pool (not for production use!)
17:54:04,795 INFO DriverManagerConnectionProvider:42 - Hibernate connection pool size: 5
17:54:04,856 INFO DriverManagerConnectionProvider:71 - using driver: oracle.jdbc.driver.OracleDriver at URL: jdbc:oracle:thin:@gandalf.conceptis.com:1521:D1MSW
17:54:04,856 INFO DriverManagerConnectionProvider:72 - connection properties: {user=rudy, password=rudy}
17:54:04,856 INFO TransactionFactoryFactory:31 - Transaction strategy: net.sf.hibernate.transaction.JDBCTransactionFactory
17:54:04,856 INFO TransactionManagerLookupFactory:33 - No TransactionManagerLookup configured (in JTA environment, use of process level read-write cache is not recommended)
17:54:04,866 DEBUG DriverManagerConnectionProvider:78 - total checked-out connections: 0
17:54:04,866 DEBUG DriverManagerConnectionProvider:94 - opening new JDBC connection
17:54:05,917 DEBUG DriverManagerConnectionProvider:100 - created connection to: jdbc:oracle:thin:@gandalf.conceptis.com:1521:D1MSW, Isolation Level: 2
17:54:05,937 DEBUG DriverManagerConnectionProvider:114 - returning connection to pool, pool size: 1
17:54:05,937 INFO SettingsFactory:102 - Use scrollable result sets: true
17:54:05,937 INFO SettingsFactory:105 - Use JDBC3 getGeneratedKeys(): false
17:54:05,947 INFO SettingsFactory:108 - Optimize cache for minimal puts: false
17:54:05,947 INFO SettingsFactory:117 - Query language substitutions: {}
17:54:05,947 INFO SettingsFactory:128 - cache provider: net.sf.ehcache.hibernate.Provider
17:54:05,947 INFO Configuration:1080 - instantiating and configuring caches
17:54:05,947 DEBUG Configuration:1091 - instantiating cache com.conceptis.pcl.item.structure.TopicGroup.roleAccesses
17:54:05,947 DEBUG CacheManager:177 - Creating new CacheManager with default config
17:54:05,957 DEBUG CacheManager:151 - Configuring ehcache from classpath.
17:54:05,957 DEBUG Configurator:118 - Configuring ehcache from ehcache.xml found in the classpath: file:/C:/dev/pcl/test/hibernateconfig/ehcache.xml
17:54:05,967 DEBUG Configuration$DiskStore:169 - Disk Store Path: C:\DOCUME~1\rudy\LOCALS~1\Temp\
17:54:05,977 DEBUG MemoryStore:124 - sampleCache2 Cache: Using SpoolingLinkedHashMap implementation
17:54:05,977 DEBUG MemoryStore:104 - initialized MemoryStore for sampleCache2
17:54:05,977 DEBUG MemoryStore:124 - com.conceptis.pcl.item.structure.Section Cache: Using SpoolingLinkedHashMap implementation
17:54:05,977 DEBUG MemoryStore:104 - initialized MemoryStore for com.conceptis.pcl.item.structure.Section
17:54:05,977 DEBUG MemoryStore:124 - com.conceptis.pcl.item.structure.Section.children Cache: Using SpoolingLinkedHashMap implementation
17:54:05,977 DEBUG MemoryStore:104 - initialized MemoryStore for com.conceptis.pcl.item.structure.Section.children
17:54:05,997 DEBUG MemoryStore:124 - sampleCache1 Cache: Using SpoolingLinkedHashMap implementation
17:54:05,997 DEBUG MemoryStore:104 - initialized MemoryStore for sampleCache1
17:54:05,997 DEBUG MemoryStore:124 - com.conceptis.pcl.item.structure.Section.roleAccesses Cache: Using SpoolingLinkedHashMap implementation
17:54:05,997 DEBUG MemoryStore:104 - initialized MemoryStore for com.conceptis.pcl.item.structure.Section.roleAccesses
17:54:05,997 WARN Plugin:95 - Could not find configuration for com.conceptis.pcl.item.structure.TopicGroup.roleAccesses. Configuring using the defaultCache settings.
17:54:05,997 DEBUG MemoryStore:124 - com.conceptis.pcl.item.structure.TopicGroup.roleAccesses Cache: Using SpoolingLinkedHashMap implementation
17:54:05,997 DEBUG MemoryStore:104 - initialized MemoryStore for com.conceptis.pcl.item.structure.TopicGroup.roleAccesses
17:54:05,997 DEBUG Configuration:1091 - instantiating cache com.conceptis.pcl.item.structure.Topic.roleAccesses
17:54:05,997 DEBUG CacheManager:182 - Attempting to create an existing instance. Existing instance returned.
17:54:05,997 WARN Plugin:95 - Could not find configuration for com.conceptis.pcl.item.structure.Topic.roleAccesses. Configuring using the defaultCache settings.
17:54:06,007 DEBUG MemoryStore:124 - com.conceptis.pcl.item.structure.Topic.roleAccesses Cache: Using SpoolingLinkedHashMap implementation
17:54:06,007 DEBUG MemoryStore:104 - initialized MemoryStore for com.conceptis.pcl.item.structure.Topic.roleAccesses
17:54:06,007 DEBUG Configuration:1091 - instantiating cache com.conceptis.pcl.item.structure.TopicGroup
17:54:06,007 DEBUG CacheManager:182 - Attempting to create an existing instance. Existing instance returned.
17:54:06,007 WARN Plugin:95 - Could not find configuration for com.conceptis.pcl.item.structure.TopicGroup. Configuring using the defaultCache settings.
17:54:06,007 DEBUG MemoryStore:124 - com.conceptis.pcl.item.structure.TopicGroup Cache: Using SpoolingLinkedHashMap implementation
17:54:06,007 DEBUG MemoryStore:104 - initialized MemoryStore for com.conceptis.pcl.item.structure.TopicGroup
17:54:06,007 DEBUG Configuration:1091 - instantiating cache com.conceptis.pcl.item.structure.Topic
17:54:06,007 DEBUG CacheManager:182 - Attempting to create an existing instance. Existing instance returned.
17:54:06,007 WARN Plugin:95 - Could not find configuration for com.conceptis.pcl.item.structure.Topic. Configuring using the defaultCache settings.
17:54:06,007 DEBUG MemoryStore:124 - com.conceptis.pcl.item.structure.Topic Cache: Using SpoolingLinkedHashMap implementation
17:54:06,017 DEBUG MemoryStore:104 - initialized MemoryStore for com.conceptis.pcl.item.structure.Topic
17:54:06,017 DEBUG Configuration:1091 - instantiating cache com.conceptis.pcl.item.structure.Topic.keywords
17:54:06,017 DEBUG CacheManager:182 - Attempting to create an existing instance. Existing instance returned.
17:54:06,017 WARN Plugin:95 - Could not find configuration for com.conceptis.pcl.item.structure.Topic.keywords. Configuring using the defaultCache settings.
17:54:06,017 DEBUG MemoryStore:124 - com.conceptis.pcl.item.structure.Topic.keywords Cache: Using SpoolingLinkedHashMap implementation
17:54:06,017 DEBUG MemoryStore:104 - initialized MemoryStore for com.conceptis.pcl.item.structure.Topic.keywords
17:54:06,017 DEBUG Configuration:1091 - instantiating cache com.conceptis.pcl.item.structure.Section
17:54:06,017 DEBUG CacheManager:182 - Attempting to create an existing instance. Existing instance returned.
17:54:06,017 DEBUG Configuration:1091 - instantiating cache com.conceptis.pcl.item.structure.TopicGroup.topics
17:54:06,017 DEBUG CacheManager:182 - Attempting to create an existing instance. Existing instance returned.
17:54:06,017 WARN Plugin:95 - Could not find configuration for com.conceptis.pcl.item.structure.TopicGroup.topics. Configuring using the defaultCache settings.
17:54:06,017 DEBUG MemoryStore:124 - com.conceptis.pcl.item.structure.TopicGroup.topics Cache: Using SpoolingLinkedHashMap implementation
17:54:06,017 DEBUG MemoryStore:104 - initialized MemoryStore for com.conceptis.pcl.item.structure.TopicGroup.topics
17:54:06,027 DEBUG Configuration:1091 - instantiating cache com.conceptis.pcl.item.structure.Section.children
17:54:06,027 DEBUG CacheManager:182 - Attempting to create an existing instance. Existing instance returned.
17:54:06,027 DEBUG Configuration:1091 - instantiating cache com.conceptis.pcl.item.structure.Section.roleAccesses
17:54:06,027 DEBUG CacheManager:182 - Attempting to create an existing instance. Existing instance returned.
17:54:06,047 INFO SessionFactoryImpl:119 - building session factory
17:54:06,047 DEBUG SessionFactoryImpl:125 - instantiating session factory with properties: {hibernate.connection.password=rudy, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, test.pcl.siteid=RUDY, sun.boot.library.path=C:\j2sdk1.4.2_03\jre\bin, java.vm.version=1.4.2_03-b02, hibernate.connection.username=rudy, java.vm.vendor=Sun Microsystems Inc., java.vendor.url=http://java.sun.com/, hibernate.cache.use_query_cache=true, path.separator=;, java.vm.name=Java HotSpot(TM) Client VM, file.encoding.pkg=sun.io, user.country=US, sun.os.patch.level=Service Pack 4, java.vm.specification.name=Java Virtual Machine Specification, user.dir=C:\dev\pcl, java.runtime.version=1.4.2_03-b02, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.endorsed.dirs=C:\j2sdk1.4.2_03\jre\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\rudy\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows 2000, sun.java2d.fontpath=, java.library.path=C:\j2sdk1.4.2_03\bin;.;C:\WINNT\system32;C:\WINNT;C:\j2sdk1.4.2_03\bin;C:\oracle\ora92\bin;C:\Program Files\Oracle\jre\1.3.1\bin;C:\Program Files\Oracle\jre\1.1.8\bin;C:\WINNT\system32;C:\WINNT;C:\WINNT\System32\Wbem;C:\Program Files\ATI Technologies\ATI Control Panel;C:\Program Files\OpenSSH\bin;C:\aspectj1.1\bin;C:\apache-ant-1.5.4\bin, java.specification.name=Java Platform API Specification, java.class.version=48.0, hibernate.connection.pool_size=5, hibernate.transaction.factory_class=net.sf.hibernate.transaction.JDBCTransactionFactory, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, os.version=5.0, connection.password=rudy, user.home=C:\Documents and Settings\rudy, user.timezone=America/New_York, connection.username=rudy, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=Cp1252, java.specification.version=1.4, hibernate.connection.driver_class=oracle.jdbc.driver.OracleDriver, user.name=rudy, java.class.path=C:/Program Files/eclipse/plugins/org.eclipse.jdt.junit_2.1.1/junitsupport.jar;C:\dev\pcl\build\classes;C:\dev\tools\hibernate-2.1\hibernate2.jar;C:\dev\tools\jakarta-struts-1.1\lib\struts.jar;C:\dev\tools\junit3.8.1\junit.jar;C:\dev\tools\hibernate-2.1\lib\odmg.jar;C:\dev\tools\hibernate-2.1\lib\commons-collections.jar;C:\dev\tools\hibernate-2.1\lib\commons-logging.jar;C:\dev\tools\hibernate-2.1\lib\dom4j.jar;C:\dev\tools\hibernate-2.1\lib\ehcache.jar;C:\dev\tools\hibernate-2.1\lib\jdbc2_0-stdext.jar;C:\dev\tools\hibernate-2.1\lib\jta.jar;C:\dev\tools\hibernate-2.1\lib\cglib2.jar;C:\dev\pcl\lib\servlet-2.3.jar;C:\dev\pcl\test\hibernateconfig;C:\dev\tools\mysql-connector-java-3.0.9-stable\mysql-connector-java-3.0.9-stable-bin.jar;C:\dev\cms\cms-client\webapps\WEB-INF\lib\cms-beans-0.1a.jar;C:\dev\pcl\lib\classes12.zip;C:\dev\tools\hibernate-2.1\lib\log4j-1.2.8.jar, java.vm.specification.version=1.0, java.home=C:\j2sdk1.4.2_03\jre, sun.arch.data.model=32, hibernate.connection.url=jdbc:oracle:thin:@gandalf.conceptis.com:1521:D1MSW, hibernate.dialect=net.sf.hibernate.dialect.OracleDialect, user.language=en, java.specification.vendor=Sun Microsystems Inc., awt.toolkit=sun.awt.windows.WToolkit, hibernate.cglib.use_reflection_optimizer=true, java.vm.info=mixed mode, java.version=1.4.2_03, java.ext.dirs=C:\j2sdk1.4.2_03\jre\lib\ext, sun.boot.class.path=C:\j2sdk1.4.2_03\jre\lib\rt.jar;C:\j2sdk1.4.2_03\jre\lib\i18n.jar;C:\j2sdk1.4.2_03\jre\lib\sunrsasign.jar;C:\j2sdk1.4.2_03\jre\lib\jsse.jar;C:\j2sdk1.4.2_03\jre\lib\jce.jar;C:\j2sdk1.4.2_03\jre\lib\charsets.jar;C:\j2sdk1.4.2_03\jre\classes, java.vendor=Sun Microsystems Inc., connection.driver_class=oracle.jdbc.driver.OracleDriver, file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, connection.url=jdbc:oracle:thin:@gandalf.conceptis.com:1521:D1MSW, dialect=net.sf.hibernate.dialect.OracleDialect, sun.cpu.isalist=pentium i486 i386}
17:54:06,318 DEBUG SessionFactoryObjectFactory:39 - initializing class SessionFactoryObjectFactory
17:54:06,328 DEBUG SessionFactoryObjectFactory:76 - registered: 58deee26fac5afa200fac5afa3ee0000 (unnamed)
17:54:06,328 INFO SessionFactoryObjectFactory:82 - no JNDI name configured
17:54:06,328 DEBUG SessionFactoryImpl:196 - instantiated session factory
17:54:06,328 INFO UpdateTimestampsCache:35 - starting update timestamps cache at region: net.sf.hibernate.cache.UpdateTimestampsCache
17:54:06,328 DEBUG CacheManager:182 - Attempting to create an existing instance. Existing instance returned.
17:54:06,328 WARN Plugin:95 - Could not find configuration for net.sf.hibernate.cache.UpdateTimestampsCache. Configuring using the defaultCache settings.
17:54:06,328 DEBUG MemoryStore:124 - net.sf.hibernate.cache.UpdateTimestampsCache Cache: Using SpoolingLinkedHashMap implementation
17:54:06,328 DEBUG MemoryStore:104 - initialized MemoryStore for net.sf.hibernate.cache.UpdateTimestampsCache
17:54:06,328 INFO QueryCache:39 - starting query cache at region: net.sf.hibernate.cache.QueryCache
17:54:06,328 DEBUG CacheManager:182 - Attempting to create an existing instance. Existing instance returned.
17:54:06,328 WARN Plugin:95 - Could not find configuration for net.sf.hibernate.cache.QueryCache. Configuring using the defaultCache settings.
17:54:06,338 DEBUG MemoryStore:124 - net.sf.hibernate.cache.QueryCache Cache: Using SpoolingLinkedHashMap implementation
17:54:06,338 DEBUG MemoryStore:104 - initialized MemoryStore for net.sf.hibernate.cache.QueryCache
17:54:06,398 DEBUG SessionImpl:531 - opened session
17:54:06,408 DEBUG JDBCTransaction:37 - begin
17:54:06,408 DEBUG DriverManagerConnectionProvider:78 - total checked-out connections: 0
17:54:06,408 DEBUG DriverManagerConnectionProvider:84 - using pooled JDBC connection, pool size: 0
17:54:06,408 DEBUG JDBCTransaction:41 - current autocommit status:false
17:54:06,408 DEBUG SessionImpl:760 - generated identifier: 58deee26fac5afa200fac5afa4480001
17:54:06,408 DEBUG SessionImpl:807 - saving [com.conceptis.pcl.item.structure.Section#58deee26fac5afa200fac5afa4480001]
17:54:06,418 DEBUG Cascades:497 - processing cascades for: com.conceptis.pcl.item.structure.Section
17:54:06,418 DEBUG Cascades:506 - done processing cascades for: com.conceptis.pcl.item.structure.Section
17:54:06,418 DEBUG Cascades:497 - processing cascades for: com.conceptis.pcl.item.structure.Section
17:54:06,418 DEBUG Cascades:524 - cascading to collection: com.conceptis.pcl.item.structure.Section.roleAccesses
17:54:06,418 DEBUG Cascades:506 - done processing cascades for: com.conceptis.pcl.item.structure.Section
17:54:06,418 DEBUG JDBCTransaction:59 - commit
17:54:06,428 DEBUG SessionImpl:2210 - flushing session
17:54:06,428 DEBUG Cascades:497 - processing cascades for: com.conceptis.pcl.item.structure.Section
17:54:06,428 DEBUG Cascades:524 - cascading to collection: com.conceptis.pcl.item.structure.Section.roleAccesses
17:54:06,428 DEBUG Cascades:506 - done processing cascades for: com.conceptis.pcl.item.structure.Section
17:54:06,428 DEBUG SessionImpl:2403 - Flushing entities and processing referenced collections
17:54:06,428 DEBUG WrapVisitor:76 - Wrapped collection in role: com.conceptis.pcl.item.structure.Section.roleAccesses
17:54:06,438 DEBUG SessionImpl:2850 - Collection found: [com.conceptis.pcl.item.structure.Section.roleAccesses#58deee26fac5afa200fac5afa4480001], was: [<unreferenced>]
17:54:06,438 DEBUG SessionImpl:2746 - Processing unreferenced collections
17:54:06,438 DEBUG SessionImpl:2760 - Scheduling collection removes/(re)creates/updates
17:54:06,438 DEBUG SessionImpl:2234 - Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
17:54:06,438 DEBUG SessionImpl:2239 - Flushed: 1 (re)creations, 0 updates, 0 removals to 1 collections
17:54:06,438 DEBUG Printer:75 - listing entities:
17:54:06,458 DEBUG Printer:82 - com.conceptis.pcl.item.structure.Section{legacyId=Z, displayOrder=100, title=Z, siteId=RUDY, publishedDate=17 February 2004 17:54:06, lastUpdatedDate=18 February 2004 17:54:06, language=en, id=58deee26fac5afa200fac5afa4480001, roleAccesses=[RoleAccess{activeDate=17 February 2004 17:54:06, expirationDate=18 February 2004 17:54:06}, RoleAccess{activeDate=null, expirationDate=null}, RoleAccess{activeDate=17 February 2004 17:54:06, expirationDate=18 February 2004 17:54:06}], description= , shortTitle=Z, parent=null, children=null}
17:54:06,458 DEBUG SessionImpl:2323 - executing flush
17:54:06,458 DEBUG EntityPersister:453 - Inserting entity: [com.conceptis.pcl.item.structure.Section#58deee26fac5afa200fac5afa4480001]
17:54:06,458 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
17:54:06,458 DEBUG SQL:237 - insert into sect_section (site_id, sect_legacyid, sect_title, sect_shorttitle, sect_description, sect_publisheddate, sect_lastupdateddate, sect_language, sect_displayorder, sect_id_parent, sect_id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
17:54:06,458 DEBUG BatcherImpl:241 - preparing statement
17:54:06,488 DEBUG EntityPersister:388 - Dehydrating entity: [com.conceptis.pcl.item.structure.Section#58deee26fac5afa200fac5afa4480001]
17:54:06,488 DEBUG StringType:46 - binding 'RUDY' to parameter: 1
17:54:06,488 DEBUG StringType:46 - binding 'Z' to parameter: 2
17:54:06,568 DEBUG StringType:46 - binding 'Z' to parameter: 3
17:54:06,568 DEBUG StringType:46 - binding 'Z' to parameter: 4
17:54:06,568 DEBUG StringType:46 - binding ' ' to parameter: 5
17:54:06,578 DEBUG TimestampType:46 - binding '17 February 2004 17:54:06' to parameter: 6
17:54:06,578 DEBUG TimestampType:46 - binding '18 February 2004 17:54:06' to parameter: 7
17:54:06,578 DEBUG StringType:46 - binding 'en' to parameter: 8
17:54:06,578 DEBUG IntegerType:46 - binding '100' to parameter: 9
17:54:06,608 DEBUG StringType:41 - binding null to parameter: 10
17:54:06,608 DEBUG StringType:46 - binding '58deee26fac5afa200fac5afa4480001' to parameter: 11
17:54:06,608 DEBUG BatcherImpl:28 - Adding to batch
17:54:06,618 DEBUG BatcherImpl:50 - Executing batch size: 1
17:54:06,918 DEBUG BatcherImpl:58 - success of batch update unknown: 0
17:54:06,918 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
17:54:06,918 DEBUG BatcherImpl:261 - closing statement
17:54:06,928 DEBUG BasicCollectionPersister:522 - Inserting collection: [com.conceptis.pcl.item.structure.Section.roleAccesses#58deee26fac5afa200fac5afa4480001]
17:54:06,928 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
17:54:06,928 DEBUG SQL:237 - insert into stra_section_roleaccess (sect_id, stra_role, stra_activedate, stra_expirationdate) values (?, ?, ?, ?)
17:54:06,928 DEBUG BatcherImpl:241 - preparing statement
17:54:06,928 DEBUG StringType:46 - binding '58deee26fac5afa200fac5afa4480001' to parameter: 1
17:54:06,939 DEBUG TimestampType:46 - binding '17 February 2004 17:54:06' to parameter: 3
17:54:06,939 DEBUG TimestampType:46 - binding '18 February 2004 17:54:06' to parameter: 4
17:54:06,939 DEBUG StringType:46 - binding 'user' to parameter: 2
17:54:06,939 DEBUG BatcherImpl:28 - Adding to batch
17:54:06,939 DEBUG StringType:46 - binding '58deee26fac5afa200fac5afa4480001' to parameter: 1
17:54:06,939 DEBUG TimestampType:41 - binding null to parameter: 3
17:54:06,939 DEBUG TimestampType:41 - binding null to parameter: 4
17:54:06,939 DEBUG StringType:46 - binding 'god' to parameter: 2
17:54:06,939 DEBUG BatcherImpl:28 - Adding to batch
17:54:06,939 DEBUG StringType:46 - binding '58deee26fac5afa200fac5afa4480001' to parameter: 1
17:54:06,939 DEBUG TimestampType:46 - binding '17 February 2004 17:54:06' to parameter: 3
17:54:06,939 DEBUG TimestampType:46 - binding '18 February 2004 17:54:06' to parameter: 4
17:54:06,949 DEBUG StringType:46 - binding 'editor' to parameter: 2
17:54:06,949 DEBUG BatcherImpl:28 - Adding to batch
17:54:06,949 DEBUG BasicCollectionPersister:544 - done inserting collection: 3 rows inserted
17:54:06,949 DEBUG ReadWriteCache:95 - Invalidating: 58deee26fac5afa200fac5afa4480001
17:54:06,949 DEBUG MemoryStore:194 - com.conceptis.pcl.item.structure.Section.roleAccessesCache: Cannot remove entry as key 58deee26fac5afa200fac5afa4480001 was not found
17:54:06,949 DEBUG BatcherImpl:50 - Executing batch size: 3
17:54:07,129 DEBUG BatcherImpl:58 - success of batch update unknown: 0
17:54:07,129 DEBUG BatcherImpl:58 - success of batch update unknown: 1
17:54:07,129 DEBUG BatcherImpl:58 - success of batch update unknown: 2
17:54:07,129 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
17:54:07,129 DEBUG BatcherImpl:261 - closing statement
17:54:07,159 DEBUG SessionImpl:2790 - post flush
17:54:07,169 DEBUG SessionImpl:561 - transaction completion
17:54:07,169 DEBUG ReadWriteCache:117 - Invalidating (again): 58deee26fac5afa200fac5afa4480001
17:54:07,169 DEBUG MemoryStore:194 - com.conceptis.pcl.item.structure.Section.roleAccessesCache: Cannot remove entry as key 58deee26fac5afa200fac5afa4480001 was not found
17:54:07,169 DEBUG SessionImpl:549 - closing session
17:54:07,169 DEBUG SessionImpl:3294 - disconnecting session
17:54:07,169 DEBUG DriverManagerConnectionProvider:114 - returning connection to pool, pool size: 1
17:54:07,169 DEBUG SessionImpl:561 - transaction completion
17:54:07,169 DEBUG SessionImpl:531 - opened session
17:54:07,179 DEBUG SessionImpl:1497 - find: from com.conceptis.pcl.item.structure.Section as section where section.siteId = 'RUDY' and section.legacyId = 'Z'
17:54:07,179 DEBUG QueryParameters:108 - named parameters: {}
17:54:07,189 DEBUG QueryTranslator:147 - compiling query
17:54:07,209 DEBUG SessionImpl:2210 - flushing session
17:54:07,209 DEBUG SessionImpl:2403 - Flushing entities and processing referenced collections
17:54:07,209 DEBUG SessionImpl:2746 - Processing unreferenced collections
17:54:07,219 DEBUG SessionImpl:2760 - Scheduling collection removes/(re)creates/updates
17:54:07,219 DEBUG SessionImpl:2234 - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
17:54:07,219 DEBUG SessionImpl:2239 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
17:54:07,219 DEBUG SessionImpl:1782 - Dont need to execute flush
17:54:07,219 DEBUG QueryTranslator:199 - HQL: from com.conceptis.pcl.item.structure.Section as section where section.siteId = 'RUDY' and section.legacyId = 'Z'
17:54:07,219 DEBUG QueryTranslator:200 - SQL: select section0_.sect_id as sect_id, section0_.site_id as site_id, section0_.sect_legacyid as sect_leg3_, section0_.sect_title as sect_title, section0_.sect_shorttitle as sect_sho5_, section0_.sect_description as sect_des6_, section0_.sect_publisheddate as sect_pub7_, section0_.sect_lastupdateddate as sect_las8_, section0_.sect_language as sect_lan9_, section0_.sect_displayorder as sect_di10_, section0_.sect_id_parent as sect_id11_ from sect_section section0_ where (section0_.site_id='RUDY' )and(section0_.sect_legacyid='Z' )
17:54:07,219 DEBUG QueryCache:61 - checking cached query results in region: net.sf.hibernate.cache.QueryCache
17:54:07,219 DEBUG Plugin:114 - key: net.sf.hibernate.cache.QueryKey@e0a0c73e
17:54:07,219 DEBUG MemoryStore:179 - net.sf.hibernate.cache.QueryCacheCache: MemoryStore miss for net.sf.hibernate.cache.QueryKey@e0a0c73e
17:54:07,219 DEBUG Cache:234 - net.sf.hibernate.cache.QueryCache cache - Miss
17:54:07,219 DEBUG Plugin:122 - Element for net.sf.hibernate.cache.QueryKey@e0a0c73e is null
17:54:07,219 DEBUG QueryCache:64 - query results were not found in cache
17:54:07,219 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
17:54:07,229 DEBUG DriverManagerConnectionProvider:78 - total checked-out connections: 0
17:54:07,229 DEBUG DriverManagerConnectionProvider:84 - using pooled JDBC connection, pool size: 0
17:54:07,239 DEBUG SQL:237 - select section0_.sect_id as sect_id, section0_.site_id as site_id, section0_.sect_legacyid as sect_leg3_, section0_.sect_title as sect_title, section0_.sect_shorttitle as sect_sho5_, section0_.sect_description as sect_des6_, section0_.sect_publisheddate as sect_pub7_, section0_.sect_lastupdateddate as sect_las8_, section0_.sect_language as sect_lan9_, section0_.sect_displayorder as sect_di10_, section0_.sect_id_parent as sect_id11_ from sect_section section0_ where (section0_.site_id='RUDY' )and(section0_.sect_legacyid='Z' )
17:54:07,239 DEBUG BatcherImpl:241 - preparing statement
17:54:07,249 DEBUG Loader:197 - processing result set
17:54:07,249 DEBUG StringType:68 - returning '58deee26fac5afa200fac5afa4480001' as column: sect_id
17:54:07,249 DEBUG Loader:405 - result row: 58deee26fac5afa200fac5afa4480001
17:54:07,249 DEBUG Loader:536 - Initializing object from ResultSet: 58deee26fac5afa200fac5afa4480001
17:54:07,259 DEBUG Loader:605 - Hydrating entity: com.conceptis.pcl.item.structure.Section#58deee26fac5afa200fac5afa4480001
17:54:07,259 DEBUG StringType:68 - returning 'RUDY' as column: site_id
17:54:07,259 DEBUG StringType:68 - returning 'Z' as column: sect_leg3_
17:54:07,259 DEBUG StringType:68 - returning 'Z' as column: sect_title
17:54:07,259 DEBUG StringType:68 - returning 'Z' as column: sect_sho5_
17:54:07,259 DEBUG StringType:68 - returning ' ' as column: sect_des6_
17:54:07,259 DEBUG TimestampType:68 - returning '17 February 2004 17:54:06' as column: sect_pub7_
17:54:07,259 DEBUG TimestampType:68 - returning '18 February 2004 17:54:06' as column: sect_las8_
17:54:07,259 DEBUG StringType:68 - returning 'en' as column: sect_lan9_
17:54:07,269 DEBUG IntegerType:68 - returning '100' as column: sect_di10_
17:54:07,269 DEBUG StringType:64 - returning null as column: sect_id11_
17:54:07,279 DEBUG Loader:226 - done processing result set (1 rows)
17:54:07,279 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
17:54:07,289 DEBUG BatcherImpl:261 - closing statement
17:54:07,319 DEBUG Loader:239 - total objects hydrated: 1
17:54:07,319 DEBUG SessionImpl:2166 - resolving associations for [com.conceptis.pcl.item.structure.Section#58deee26fac5afa200fac5afa4480001]
17:54:07,329 DEBUG SessionImpl:3891 - creating collection wrapper:[com.conceptis.pcl.item.structure.Section.children#58deee26fac5afa200fac5afa4480001]
17:54:07,329 DEBUG SessionImpl:3891 - creating collection wrapper:[com.conceptis.pcl.item.structure.Section.roleAccesses#58deee26fac5afa200fac5afa4480001]
17:54:07,329 DEBUG SessionImpl:2177 - adding entity to second-level cache [com.conceptis.pcl.item.structure.Section#58deee26fac5afa200fac5afa4480001]
17:54:07,329 DEBUG ReadWriteCache:58 - Caching: 58deee26fac5afa200fac5afa4480001
17:54:07,329 DEBUG SessionImpl:2190 - done materializing entity [com.conceptis.pcl.item.structure.Section#58deee26fac5afa200fac5afa4480001]
17:54:07,329 DEBUG SessionImpl:3082 - initializing non-lazy collections
17:54:07,329 DEBUG SessionImpl:3218 - initializing collection [com.conceptis.pcl.item.structure.Section.roleAccesses#58deee26fac5afa200fac5afa4480001]
17:54:07,329 DEBUG SessionImpl:3219 - checking second-level cache
17:54:07,329 DEBUG ReadWriteCache:37 - Cache lookup: 58deee26fac5afa200fac5afa4480001
17:54:07,329 DEBUG Plugin:114 - key: 58deee26fac5afa200fac5afa4480001
17:54:07,339 DEBUG MemoryStore:179 - com.conceptis.pcl.item.structure.Section.roleAccessesCache: MemoryStore miss for 58deee26fac5afa200fac5afa4480001
17:54:07,339 DEBUG Cache:234 - com.conceptis.pcl.item.structure.Section.roleAccesses cache - Miss
17:54:07,339 DEBUG Plugin:122 - Element for 58deee26fac5afa200fac5afa4480001 is null
17:54:07,339 DEBUG ReadWriteCache:44 - Cache miss
17:54:07,339 DEBUG SessionImpl:3225 - collection not cached
17:54:07,339 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
17:54:07,339 DEBUG SQL:237 - select roleaccess0_.stra_activedate as stra_act2___, roleaccess0_.stra_expirationdate as stra_exp3___, roleaccess0_.sect_id as sect_id__, roleaccess0_.stra_role as stra_role__ from stra_section_roleaccess roleaccess0_ where roleaccess0_.sect_id=?
17:54:07,339 DEBUG BatcherImpl:241 - preparing statement
17:54:07,339 DEBUG StringType:46 - binding '58deee26fac5afa200fac5afa4480001' to parameter: 1
17:54:07,449 DEBUG Loader:327 - result set contains (possibly empty) collection: [com.conceptis.pcl.item.structure.Section.roleAccesses#58deee26fac5afa200fac5afa4480001]
17:54:07,449 DEBUG SessionImpl:2984 - uninitialized collection: initializing
17:54:07,449 DEBUG Loader:197 - processing result set
17:54:07,449 DEBUG Loader:405 - result row:
17:54:07,449 DEBUG StringType:68 - returning '58deee26fac5afa200fac5afa4480001' as column: sect_id__
17:54:07,449 DEBUG Loader:292 - found row of collection: [com.conceptis.pcl.item.structure.Section.roleAccesses#58deee26fac5afa200fac5afa4480001]
17:54:07,449 DEBUG SessionImpl:3007 - reading row
17:54:07,449 DEBUG TimestampType:68 - returning '17 February 2004 17:54:06' as column: stra_act2___
17:54:07,449 DEBUG TimestampType:68 - returning '18 February 2004 17:54:06' as column: stra_exp3___
17:54:07,459 DEBUG StringType:68 - returning 'user' as column: stra_role__
17:54:07,459 DEBUG Loader:405 - result row:
17:54:07,459 DEBUG StringType:68 - returning '58deee26fac5afa200fac5afa4480001' as column: sect_id__
17:54:07,459 DEBUG Loader:292 - found row of collection: [com.conceptis.pcl.item.structure.Section.roleAccesses#58deee26fac5afa200fac5afa4480001]
17:54:07,459 DEBUG SessionImpl:3007 - reading row
17:54:07,459 DEBUG TimestampType:64 - returning null as column: stra_act2___
17:54:07,459 DEBUG TimestampType:64 - returning null as column: stra_exp3___
17:54:07,459 DEBUG StringType:68 - returning 'god' as column: stra_role__
17:54:07,469 DEBUG Loader:405 - result row:
17:54:07,469 DEBUG StringType:68 - returning '58deee26fac5afa200fac5afa4480001' as column: sect_id__
17:54:07,469 DEBUG Loader:292 - found row of collection: [com.conceptis.pcl.item.structure.Section.roleAccesses#58deee26fac5afa200fac5afa4480001]
17:54:07,469 DEBUG SessionImpl:3007 - reading row
17:54:07,469 DEBUG TimestampType:68 - returning '17 February 2004 17:54:06' as column: stra_act2___
17:54:07,469 DEBUG TimestampType:68 - returning '18 February 2004 17:54:06' as column: stra_exp3___
17:54:07,469 DEBUG StringType:68 - returning 'editor' as column: stra_role__
17:54:07,519 DEBUG Loader:226 - done processing result set (3 rows)
17:54:07,519 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
17:54:07,519 DEBUG BatcherImpl:261 - closing statement
17:54:07,529 DEBUG SessionImpl:3043 - 1 collections were found in result set
17:54:07,529 DEBUG SessionImpl:3057 - Caching collection: [com.conceptis.pcl.item.structure.Section.roleAccesses#58deee26fac5afa200fac5afa4480001]
17:54:07,529 DEBUG ReadWriteCache:58 - Caching: 58deee26fac5afa200fac5afa4480001
17:54:07,529 DEBUG SessionImpl:3061 - collection fully initialized: [com.conceptis.pcl.item.structure.Section.roleAccesses#58deee26fac5afa200fac5afa4480001]
17:54:07,529 DEBUG SessionImpl:3064 - 1 collections initialized
17:54:07,529 DEBUG SessionImpl:3227 - collection initialized
17:54:07,529 DEBUG SessionImpl:3218 - initializing collection [com.conceptis.pcl.item.structure.Section.children#58deee26fac5afa200fac5afa4480001]
17:54:07,529 DEBUG SessionImpl:3219 - checking second-level cache
17:54:07,529 DEBUG ReadWriteCache:37 - Cache lookup: 58deee26fac5afa200fac5afa4480001
17:54:07,529 DEBUG Plugin:114 - key: 58deee26fac5afa200fac5afa4480001
17:54:07,529 DEBUG MemoryStore:179 - com.conceptis.pcl.item.structure.Section.childrenCache: MemoryStore miss for 58deee26fac5afa200fac5afa4480001
17:54:07,529 DEBUG Cache:234 - com.conceptis.pcl.item.structure.Section.children cache - Miss
17:54:07,529 DEBUG Plugin:122 - Element for 58deee26fac5afa200fac5afa4480001 is null
17:54:07,529 DEBUG ReadWriteCache:44 - Cache miss
17:54:07,539 DEBUG SessionImpl:3225 - collection not cached
17:54:07,539 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
17:54:07,539 DEBUG SQL:237 - select children0_.sect_id as sect_id__, children0_.sect_id_parent as sect_id11___, children0_.sect_id as sect_id0_, children0_.site_id as site_id0_, children0_.sect_legacyid as sect_leg3_0_, children0_.sect_title as sect_title0_, children0_.sect_shorttitle as sect_sho5_0_, children0_.sect_description as sect_des6_0_, children0_.sect_publisheddate as sect_pub7_0_, children0_.sect_lastupdateddate as sect_las8_0_, children0_.sect_language as sect_lan9_0_, children0_.sect_displayorder as sect_di10_0_, children0_.sect_id_parent as sect_id11_0_ from sect_section children0_ where children0_.sect_id_parent=? order by children0_.sect_displayorder
17:54:07,539 DEBUG BatcherImpl:241 - preparing statement
17:54:07,539 DEBUG StringType:46 - binding '58deee26fac5afa200fac5afa4480001' to parameter: 1
17:54:07,609 DEBUG Loader:327 - result set contains (possibly empty) collection: [com.conceptis.pcl.item.structure.Section.children#58deee26fac5afa200fac5afa4480001]
17:54:07,609 DEBUG SessionImpl:2984 - uninitialized collection: initializing
17:54:07,609 DEBUG Loader:197 - processing result set
17:54:07,609 DEBUG Loader:226 - done processing result set (0 rows)
17:54:07,609 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
17:54:07,609 DEBUG BatcherImpl:261 - closing statement
17:54:07,609 DEBUG Loader:239 - total objects hydrated: 0
17:54:07,609 DEBUG Sessi
Login
FAQ
Search
