New to hibernate, and rather stumped. The problem occurs when querying existing objects via criteria and the referenced collection has more than 0 rows associated. I have read this: http://www.hibernate.org/264.html ans would say I understand why this is happening if it weren't for the fact that it is. Sorry if it is a bit long....

Hibernate version: 3.05

Mapping documents:

<?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="org.usgs.nbii.rcv.model.RCVPortalConfiguration" table="[rcvdb].[dbo].[RCVPortalConfiguration]">

<id name="id" type="int" unsaved-value="0" >
<column name="rcv_portal_conf_id" sql-type="int(4)" not-null="true" />
<generator class="native" />
</id>

<list name="portletConfigs" inverse="true" cascade="delete-orphan">
<key column="rcv_portlet_conf_portal_conf_id"/>
<index column="rcv_portlet_conf_rank" />
<one-to-many class="org.usgs.nbii.rcv.model.RCVPortletConfiguration" />
</list>

<property name="portaluid">
<column name="rcv_portal_conf_portaluid"/>
</property>

<property name="allowRestrictByNode">
<column name="rcv_portal_conf_allowRestrictByNode"/>
</property>

</class>

</hibernate-mapping>

<hibernate-mapping>

<class name="org.usgs.nbii.rcv.model.RCVPortletConfiguration" table="[rcvdb].[dbo].[RCVPortletConfiguration]">
<id name="id" type="int" unsaved-value="0" >
<column name="rcv_portlet_conf_id" sql-type="int(4)" not-null="true" />
<generator class="native" />
</id>

<many-to-one name="portalConfig" column="rcv_portlet_conf_portal_conf_id" class="org.usgs.nbii.rcv.model.RCVPortalConfiguration" not-null="true" cascade="none" />


<property name="title">
<column name="rcv_portlet_conf_title"/>
</property>

<property name="portletId">
<column name="rcv_portlet_conf_portletid"/>
</property>

<property name="allowSearchBox">
<column name="rcv_portlet_conf_searchBox"/>
</property>

<property name="communityId">
<column name="rcv_portlet_conf_community_id"/>
</property>

<property name="rank">
<column name="rcv_portlet_conf_rank"/>
</property>
</class>

</hibernate-mapping>

Code between sessionFactory.openSession() and session.close():

private RCVPortalConfiguration config;

/** Creates a new instance of PortalConfigForm */
public PortalConfigForm() throws Exception{
config = RCVPortalConfiguration.getPortalConfiguration(this.getPortalUid());
this.setAllowRestrictByNode(config.isAllowRestrictByNode());
}


in invoked class....

public static RCVPortalConfiguration getPortalConfiguration(String portaluid) throws Exception{
RCVLogger.log("in RCVPortletConfiguration", RCVLogger.DEBUG);


HibernateUtil.beginTransaction();
Criteria c = HibernateUtil.getSession().createCriteria(RCVPortalConfiguration.class);
c.add(Expression.like("portaluid", portaluid));
List results = c.list();
HibernateUtil.commitTransaction();


RCVPortalConfiguration r = null;
switch(results.size()){
case 0: //we need a new one
r = new RCVPortalConfiguration(portaluid);
break;
case 1: //we found one
r = (RCVPortalConfiguration)results.get(0);
break;
default:

//do some exception stuff, what, we don't know yet.
throw new Exception("More than one object returned from RCVPortalConfiguration w/ portaluid " + portaluid);

}


return r;
}


Using a thread-local described by CaveatEmptor. This is a JSF framework and HibernateUtil.getSession() is called by a phase listener before the restore view phase. HibernateUtil.closeSession() is called by a phase listener after the render response phase. What you see above is all the code that executes before the HibernateExeption is caught.

Getters/Setters/definition for refernece collection:

private List portletConfigs = new ArrayList();

public List getPortletConfigs() {
return (List)portletConfigs;
}

public void setPortletConfigs(List portletConfigs) {
this.portletConfigs.clear();
this.portletConfigs.addAll(portletConfigs);
}


Full stack trace of any exception that occurs:

12:03:22,717 DEBUG util:38 - Don't dereference a collection with cascade="all-delete-orphan": org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs
org.hibernate.HibernateException: Don't dereference a collection with cascade="all-delete-orphan": org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs
at org.hibernate.engine.Collections.processDereferencedCollection(Collections.java:70)
at org.hibernate.engine.Collections.processUnreachableCollection(Collections.java:38)
at org.hibernate.event.def.AbstractFlushingEventListener.flushCollections(AbstractFlushingEventListener.java:211)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:71)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:26)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:730)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:324)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:86)
at org.usgs.nbii.rcv.util.HibernateUtil.commitTransaction(HibernateUtil.java:71)
at org.usgs.nbii.rcv.model.RCVPortalConfiguration.getPortalConfiguration(RCVPortalConfiguration.java:50)
at org.usgs.nbii.rcv.forms.PortalConfigForm.<init>(PortalConfigForm.java:26)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:274)
at java.lang.Class.newInstance0(Class.java:308)
at java.lang.Class.newInstance(Class.java:261)
at java.beans.Beans.instantiate(Beans.java:204)
at java.beans.Beans.instantiate(Beans.java:48)
at com.sun.faces.config.ManagedBeanFactory.newInstance(ManagedBeanFactory.java:203)
at com.sun.faces.application.ApplicationAssociate.createAndMaybeStoreManagedBeans(ApplicationAssociate.java:256)
at com.sun.faces.el.VariableResolverImpl.resolveVariable(VariableResolverImpl.java:78)
at com.sun.faces.el.impl.NamedValue.evaluate(NamedValue.java:125)
at com.sun.faces.el.impl.ComplexValue.evaluate(ComplexValue.java:146)
at com.sun.faces.el.impl.ExpressionEvaluatorImpl.evaluate(ExpressionEvaluatorImpl.java:243)
at com.sun.faces.el.ValueBindingImpl.getValue(ValueBindingImpl.java:173)
at com.sun.faces.el.ValueBindingImpl.getValue(ValueBindingImpl.java:154)
at javax.faces.component.UIOutput.getValue(UIOutput.java:147)
at com.sun.faces.renderkit.html_basic.HtmlBasicInputRenderer.getValue(HtmlBasicInputRenderer.java:82)
at com.sun.faces.renderkit.html_basic.HtmlBasicRenderer.getCurrentValue(HtmlBasicRenderer.java:191)
at com.sun.faces.renderkit.html_basic.HtmlBasicRenderer.encodeEnd(HtmlBasicRenderer.java:169)
at javax.faces.component.UIComponentBase.encodeEnd(UIComponentBase.java:720)
at com.sun.faces.renderkit.html_basic.HtmlBasicRenderer.encodeRecursive(HtmlBasicRenderer.java:443)
at com.sun.faces.renderkit.html_basic.GridRenderer.encodeChildren(GridRenderer.java:233)
at javax.faces.component.UIComponentBase.encodeChildren(UIComponentBase.java:701)
at javax.faces.webapp.UIComponentTag.encodeChildren(UIComponentTag.java:607)
at javax.faces.webapp.UIComponentTag.doEndTag(UIComponentTag.java:544)
at com.sun.faces.taglib.html_basic.PanelGridTag.doEndTag(PanelGridTag.java:460)
at org.apache.jsp.forms.portalConfigForm_jsp._jspx_meth_h_panelGrid_0(portalConfigForm_jsp.java:256)
at org.apache.jsp.forms.portalConfigForm_jsp._jspx_meth_h_form_0(portalConfigForm_jsp.java:209)
at org.apache.jsp.forms.portalConfigForm_jsp._jspx_meth_f_view_0(portalConfigForm_jsp.java:143)
at org.apache.jsp.forms.portalConfigForm_jsp._jspService(portalConfigForm_jsp.java:91)
at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:94)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:324)
at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:292)
at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:236)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at org.netbeans.modules.web.monitor.server.MonitorFilter.doFilter(MonitorFilter.java:362)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:704)
at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:474)
at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:409)
at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:312)
at com.sun.faces.context.ExternalContextImpl.dispatch(ExternalContextImpl.java:322)
at com.sun.faces.application.ViewHandlerImpl.renderView(ViewHandlerImpl.java:130)
at com.sun.faces.lifecycle.RenderResponsePhase.execute(RenderResponsePhase.java:87)
at com.sun.faces.lifecycle.LifecycleImpl.phase(LifecycleImpl.java:200)
at com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:117)
at javax.faces.webapp.FacesServlet.service(FacesServlet.java:198)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at org.netbeans.modules.web.monitor.server.MonitorFilter.doFilter(MonitorFilter.java:362)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:704)
at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:474)
at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:409)
at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:312)
at org.apache.jasper.runtime.PageContextImpl.doForward(PageContextImpl.java:670)
at org.apache.jasper.runtime.PageContextImpl.forward(PageContextImpl.java:637)
at org.apache.jsp.portalConfigIndex_jsp._jspService(portalConfigIndex_jsp.java:50)
at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:94)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:324)
at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:292)
at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:236)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at com.plumtree.remote.filter.ResponseFilter.doFilter(ResponseFilter.java:124)
at com.plumtree.remote.filter.PTPortletFilter.doFilter(PTPortletFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at org.netbeans.modules.web.monitor.server.MonitorFilter.doFilter(MonitorFilter.java:362)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:214)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:198)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:152)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:118)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:929)
at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:160)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:799)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:705)
at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:577)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683)
at java.lang.Thread.run(Thread.java:534)

Name and version of the database you are using:

SQL Server 8


The generated SQL (show_sql=true):

12:03:21,342 DEBUG SQL:324 - select this_.rcv_portal_conf_id as rcv1_0_, this_.rcv_portal_conf_portaluid as rcv2_0_0_, this_.rcv_portal_conf_allowRestrictByNode as rcv3_0_0_ from [rcvdb].[dbo].[RCVPortalConfiguration] this_ where this_.rcv_portal_conf_portaluid like ?
Hibernate: select this_.rcv_portal_conf_id as rcv1_0_, this_.rcv_portal_conf_portaluid as rcv2_0_0_, this_.rcv_portal_conf_allowRestrictByNode as rcv3_0_0_ from [rcvdb].[dbo].[RCVPortalConfiguration] this_ where this_.rcv_portal_conf_portaluid like ?

12:03:22,326 DEBUG SQL:324 - select portletcon0_.rcv_portlet_conf_portal_conf_id as rcv2_1_, portletcon0_.rcv_portlet_conf_id as rcv1_1_, portletcon0_.rcv_portlet_conf_rank as rcv7_1_, portletcon0_.rcv_portlet_conf_id as rcv1_0_, portletcon0_.rcv_portlet_conf_portal_conf_id as rcv2_1_0_, portletcon0_.rcv_portlet_conf_title as rcv3_1_0_, portletcon0_.rcv_portlet_conf_portletid as rcv4_1_0_, portletcon0_.rcv_portlet_conf_searchBox as rcv5_1_0_, portletcon0_.rcv_portlet_conf_community_id as rcv6_1_0_, portletcon0_.rcv_portlet_conf_rank as rcv7_1_0_ from [rcvdb].[dbo].[RCVPortletConfiguration] portletcon0_ where portletcon0_.rcv_portlet_conf_portal_conf_id=?
Hibernate: select portletcon0_.rcv_portlet_conf_portal_conf_id as rcv2_1_, portletcon0_.rcv_portlet_conf_id as rcv1_1_, portletcon0_.rcv_portlet_conf_rank as rcv7_1_, portletcon0_.rcv_portlet_conf_id as rcv1_0_, portletcon0_.rcv_portlet_conf_portal_conf_id as rcv2_1_0_, portletcon0_.rcv_portlet_conf_title as rcv3_1_0_, portletcon0_.rcv_portlet_conf_portletid as rcv4_1_0_, portletcon0_.rcv_portlet_conf_searchBox as rcv5_1_0_, portletcon0_.rcv_portlet_conf_community_id as rcv6_1_0_, portletcon0_.rcv_portlet_conf_rank as rcv7_1_0_ from [rcvdb].[dbo].[RCVPortletConfiguration] portletcon0_ where portletcon0_.rcv_portlet_conf_portal_conf_id=?

Debug level Hibernate log excerpt:

12:03:22,451 DEBUG CollectionLoadContext:112 - reading row
12:03:22,467 DEBUG DefaultLoadEventListener:143 - loading entity: [org.usgs.nbii.rcv.model.RCVPortletConfiguration#18]
12:03:22,467 DEBUG DefaultLoadEventListener:290 - attempting to resolve: [org.usgs.nbii.rcv.model.RCVPortletConfiguration#18]
12:03:22,467 DEBUG DefaultLoadEventListener:299 - resolved object in session cache: [org.usgs.nbii.rcv.model.RCVPortletConfiguration#18]
12:03:22,482 DEBUG Loader:429 - done processing result set (1 rows)
12:03:22,482 DEBUG AbstractBatcher:313 - about to close ResultSet (open ResultSets: 1, globally: 1)
12:03:22,561 DEBUG AbstractBatcher:298 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:03:22,561 DEBUG AbstractBatcher:416 - closing statement
12:03:22,561 DEBUG Loader:528 - total objects hydrated: 1
12:03:22,576 DEBUG TwoPhaseLoad:96 - resolving associations for [org.usgs.nbii.rcv.model.RCVPortletConfiguration#18]
12:03:22,576 DEBUG DefaultLoadEventListener:143 - loading entity: [org.usgs.nbii.rcv.model.RCVPortalConfiguration#13]
12:03:22,576 DEBUG DefaultLoadEventListener:208 - entity found in session cache
12:03:22,576 DEBUG TwoPhaseLoad:167 - done materializing entity [org.usgs.nbii.rcv.model.RCVPortletConfiguration#18]
12:03:22,576 DEBUG CollectionLoadContext:262 - 1 collections were found in result set for role: org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs
12:03:22,576 DEBUG CollectionLoadContext:206 - collection fully initialized: [org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs#13]
12:03:22,576 DEBUG CollectionLoadContext:272 - 1 collections initialized for role: org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs
12:03:22,576 DEBUG Loader:1450 - done loading collection
12:03:22,576 DEBUG DefaultInitializeCollectionEventListener:61 - collection initialized
12:03:22,576 DEBUG TwoPhaseLoad:167 - done materializing entity [org.usgs.nbii.rcv.model.RCVPortalConfiguration#13]
12:03:22,576 DEBUG PersistenceContext:789 - initializing non-lazy collections
12:03:22,576 DEBUG JDBCTransaction:83 - commit
12:03:22,576 DEBUG SessionImpl:323 - automatically flushing session
12:03:22,592 DEBUG AbstractFlushingEventListener:52 - flushing session
12:03:22,592 DEBUG AbstractFlushingEventListener:102 - processing flush-time cascades
12:03:22,592 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: org.usgs.nbii.rcv.model.RCVPortalConfiguration
12:03:22,607 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: org.usgs.nbii.rcv.model.RCVPortalConfiguration
12:03:22,607 DEBUG AbstractFlushingEventListener:150 - dirty checking collections
12:03:22,607 DEBUG AbstractFlushingEventListener:167 - Flushing entities and processing referenced collections
12:03:22,623 DEBUG WrapVisitor:86 - Wrapped collection in role: org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs
12:03:22,623 DEBUG Collections:140 - Collection found: [org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs#13], was: [<unreferenced>] (initialized)
12:03:22,701 DEBUG AbstractFlushingEventListener:203 - Processing unreferenced collections
12:03:22,701 DEBUG Collections:50 - Collection dereferenced: [org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs#13]
12:03:22,701 DEBUG util:38 - caught exception in commitTransaction

O.K. so based on this:

Check getters and setters 02 Aug 2005, 12:40 jsankey

This can also happen if you manage to b0rk either the getter or setter
for the property. For instance, I created a getter in my mapped class
that returned an unmodifiable collection (good practice in most
circumstances). However, this interfered with Hibernate's wrapping of
the collection. It's trivial to correct the getters to behave properly,
but it is momentarily confusing when you get this exception from a
simple test that does not modify the loaded object.

That I read here:

http://www.hibernate.org/264.html


I changed to code to inspect what was coming in for the portletConfig collection like so:

public static RCVPortalConfiguration getPortalConfiguration(String portaluid) throws Exception{

//same as above....<new code>

System.out.println("portletConfig state just prior to transaction commit");
System.out.println(r.getPortletConfigs().size());
for(int i = 0; i < r.getPortletConfigs().size(); i++){
System.out.println("======================\n" + HibernateUtil.getSession().contains(r.getPortletConfigs().get(i)) + "\n==================");
}
System.out.println("COMMITTING TRANSACTION");

//</new code>


HibernateUtil.commitTransaction();
return r;
}


And....

public void setPortletConfigs(List newPortletConfigs) {


System.out.println("comparing size and toStrings of portletConfig and newPortletConfig, respectively");
System.out.println(this.getPortletConfigs().toString() + "=" + this.getPortletConfigs().size());
System.out.println(newPortletConfigs.toString() + "=" +newPortletConfigs.size());


RCVPortletConfiguration temp = null;
System.out.println("++++++++++++++++++++++\nContents of newPortletConfigs\n++++++++++++++++++++\n");
System.out.println("size is: " + newPortletConfigs.size());
for(int i = 0; i < newPortletConfigs.size(); i++){
System.out.println("+++++++++++++++++++++++++");
temp = (RCVPortletConfiguration)newPortletConfigs.get(i);
System.out.println("in hibernate session = " + HibernateUtil.getSession().contains(temp));
if(temp == null)
System.out.println(i + " was null");
else{
System.out.println(i + " was not null");
System.out.println("identifier is " + temp.getId());
System.out.println("title is " + temp.getTitle());

}
System.out.println("++++++++++++++++++++++");
}

System.out.println("+++++++++++++++++++++\n");


this.getPortletConfigs().clear();

System.out.println("size and location of portletConfig and newPortletConfig, respectively, after clear() operation");
System.out.println(this.getPortletConfigs().toString() + "=" + this.getPortletConfigs().size());
System.out.println(newPortletConfigs.toString() + "=" +newPortletConfigs.size());

this.getPortletConfigs().addAll(newPortletConfigs);
System.out.println("size and location of portletConfig after addAll() operation");
System.out.println(this.getPortletConfigs().toString() + "=" + this.getPortletConfigs().size());
}



Output is now this:

09:14:13,023 DEBUG SessionImpl:250 - opened session at timestamp: 4633071013982208
09:14:13,054 DEBUG util:38 - in RCVPortletConfiguration
09:14:13,054 DEBUG JDBCTransaction:46 - begin
09:14:13,054 DEBUG ConnectionManager:296 - opening JDBC connection
09:14:13,070 DEBUG JDBCTransaction:50 - current autocommit status: true
09:14:13,070 DEBUG JDBCTransaction:52 - disabling autocommit
09:14:13,070 DEBUG AbstractBatcher:290 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
09:14:13,070 DEBUG SQL:324 - select this_.rcv_portal_conf_id as rcv1_0_, this_.rcv_portal_conf_portaluid as rcv2_0_0_, this_.rcv_portal_conf_allowRestrictByNode as rcv3_0_0_ from [rcvdb].[dbo].[RCVPortalConfiguration] this_ where this_.rcv_portal_conf_portaluid like ?
Hibernate: select this_.rcv_portal_conf_id as rcv1_0_, this_.rcv_portal_conf_portaluid as rcv2_0_0_, this_.rcv_portal_conf_allowRestrictByNode as rcv3_0_0_ from [rcvdb].[dbo].[RCVPortalConfiguration] this_ where this_.rcv_portal_conf_portaluid like ?
09:14:13,148 DEBUG AbstractBatcher:378 - preparing statement
09:14:13,164 DEBUG AbstractBatcher:306 - about to open ResultSet (open ResultSets: 0, globally: 0)
09:14:13,164 DEBUG Loader:405 - processing result set
09:14:13,164 DEBUG Loader:410 - result set row: 0
09:14:13,164 DEBUG Loader:828 - result row: EntityKey[org.usgs.nbii.rcv.model.RCVPortalConfiguration#13]
09:14:13,179 DEBUG Loader:978 - Initializing object from ResultSet: [org.usgs.nbii.rcv.model.RCVPortalConfiguration#13]
09:14:13,179 DEBUG BasicEntityPersister:1651 - Hydrating entity: [org.usgs.nbii.rcv.model.RCVPortalConfiguration#13]
09:14:13,179 DEBUG Loader:429 - done processing result set (1 rows)
09:14:13,179 DEBUG AbstractBatcher:313 - about to close ResultSet (open ResultSets: 1, globally: 1)
09:14:13,179 DEBUG AbstractBatcher:298 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
09:14:13,179 DEBUG AbstractBatcher:416 - closing statement
09:14:13,179 DEBUG Loader:528 - total objects hydrated: 1
09:14:13,179 DEBUG TwoPhaseLoad:96 - resolving associations for [org.usgs.nbii.rcv.model.RCVPortalConfiguration#13]
09:14:13,179 DEBUG CollectionLoadContext:141 - creating collection wrapper:[org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs#13]
comparing size and toStrings of portletConfig and newPortletConfig, respectively
[]=0
09:14:13,195 DEBUG DefaultInitializeCollectionEventListener:42 - initializing collection [org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs#13]
09:14:13,195 DEBUG DefaultInitializeCollectionEventListener:47 - checking second-level cache
09:14:13,195 DEBUG DefaultInitializeCollectionEventListener:59 - collection not cached
09:14:13,195 DEBUG Loader:1426 - loading collection: [org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs#13]
09:14:13,195 DEBUG AbstractBatcher:290 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
09:14:13,195 DEBUG SQL:324 - select portletcon0_.rcv_portlet_conf_portal_conf_id as rcv2_1_, portletcon0_.rcv_portlet_conf_id as rcv1_1_, portletcon0_.rcv_portlet_conf_rank as rcv7_1_, portletcon0_.rcv_portlet_conf_id as rcv1_0_, portletcon0_.rcv_portlet_conf_portal_conf_id as rcv2_1_0_, portletcon0_.rcv_portlet_conf_title as rcv3_1_0_, portletcon0_.rcv_portlet_conf_portletid as rcv4_1_0_, portletcon0_.rcv_portlet_conf_searchBox as rcv5_1_0_, portletcon0_.rcv_portlet_conf_community_id as rcv6_1_0_, portletcon0_.rcv_portlet_conf_rank as rcv7_1_0_ from [rcvdb].[dbo].[RCVPortletConfiguration] portletcon0_ where portletcon0_.rcv_portlet_conf_portal_conf_id=?
Hibernate: select portletcon0_.rcv_portlet_conf_portal_conf_id as rcv2_1_, portletcon0_.rcv_portlet_conf_id as rcv1_1_, portletcon0_.rcv_portlet_conf_rank as rcv7_1_, portletcon0_.rcv_portlet_conf_id as rcv1_0_, portletcon0_.rcv_portlet_conf_portal_conf_id as rcv2_1_0_, portletcon0_.rcv_portlet_conf_title as rcv3_1_0_, portletcon0_.rcv_portlet_conf_portletid as rcv4_1_0_, portletcon0_.rcv_portlet_conf_searchBox as rcv5_1_0_, portletcon0_.rcv_portlet_conf_community_id as rcv6_1_0_, portletcon0_.rcv_portlet_conf_rank as rcv7_1_0_ from [rcvdb].[dbo].[RCVPortletConfiguration] portletcon0_ where portletcon0_.rcv_portlet_conf_portal_conf_id=?
09:14:13,195 DEBUG AbstractBatcher:378 - preparing statement
09:14:13,226 DEBUG AbstractBatcher:306 - about to open ResultSet (open ResultSets: 0, globally: 0)
09:14:13,226 DEBUG Loader:718 - result set contains (possibly empty) collection: [org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs#13]
09:14:13,226 DEBUG CollectionLoadContext:85 - uninitialized collection: initializing
09:14:13,242 DEBUG Loader:405 - processing result set
09:14:13,242 DEBUG Loader:410 - result set row: 0
09:14:13,242 DEBUG Loader:828 - result row: EntityKey[org.usgs.nbii.rcv.model.RCVPortletConfiguration#18]
09:14:13,336 DEBUG Loader:978 - Initializing object from ResultSet: [org.usgs.nbii.rcv.model.RCVPortletConfiguration#18]
09:14:13,336 DEBUG BasicEntityPersister:1651 - Hydrating entity: [org.usgs.nbii.rcv.model.RCVPortletConfiguration#18]
09:14:13,336 DEBUG Loader:654 - found row of collection: [org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs#13]
09:14:13,336 DEBUG CollectionLoadContext:112 - reading row
09:14:13,336 DEBUG DefaultLoadEventListener:143 - loading entity: [org.usgs.nbii.rcv.model.RCVPortletConfiguration#18]
09:14:13,336 DEBUG DefaultLoadEventListener:290 - attempting to resolve: [org.usgs.nbii.rcv.model.RCVPortletConfiguration#18]
09:14:13,336 DEBUG DefaultLoadEventListener:299 - resolved object in session cache: [org.usgs.nbii.rcv.model.RCVPortletConfiguration#18]
09:14:13,351 DEBUG Loader:429 - done processing result set (1 rows)
09:14:13,351 DEBUG AbstractBatcher:313 - about to close ResultSet (open ResultSets: 1, globally: 1)
09:14:13,351 DEBUG AbstractBatcher:298 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
09:14:13,351 DEBUG AbstractBatcher:416 - closing statement
09:14:13,351 DEBUG Loader:528 - total objects hydrated: 1
09:14:13,351 DEBUG TwoPhaseLoad:96 - resolving associations for [org.usgs.nbii.rcv.model.RCVPortletConfiguration#18]
09:14:13,351 DEBUG DefaultLoadEventListener:143 - loading entity: [org.usgs.nbii.rcv.model.RCVPortalConfiguration#13]
09:14:13,367 DEBUG DefaultLoadEventListener:208 - entity found in session cache
09:14:13,367 DEBUG TwoPhaseLoad:167 - done materializing entity [org.usgs.nbii.rcv.model.RCVPortletConfiguration#18]
09:14:13,367 DEBUG CollectionLoadContext:262 - 1 collections were found in result set for role: org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs
09:14:13,367 DEBUG CollectionLoadContext:206 - collection fully initialized: [org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs#13]
09:14:13,367 DEBUG CollectionLoadContext:272 - 1 collections initialized for role: org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs
09:14:13,367 DEBUG Loader:1450 - done loading collection
09:14:13,367 DEBUG DefaultInitializeCollectionEventListener:61 - collection initialized
[null, org.usgs.nbii.rcv.model.RCVPortletConfiguration@1aa]=2
++++++++++++++++++++++
Contents of newPortletConfigs
++++++++++++++++++++

size is: 2
+++++++++++++++++++++++++
in hibernate session = false
0 was null
++++++++++++++++++++++
+++++++++++++++++++++++++
in hibernate session = true
1 was not null
identifier is 18
title is test
++++++++++++++++++++++
+++++++++++++++++++++

size and location of portletConfig and newPortletConfig, respectively, after clear() operation
[]=0
[null, org.usgs.nbii.rcv.model.RCVPortletConfiguration@1aa]=2
size and location of portletConfig after addAll() operation
[null, org.usgs.nbii.rcv.model.RCVPortletConfiguration@1aa]=2
09:14:13,367 DEBUG TwoPhaseLoad:167 - done materializing entity [org.usgs.nbii.rcv.model.RCVPortalConfiguration#13]
09:14:13,367 DEBUG PersistenceContext:789 - initializing non-lazy collections
portletConfig state just prior to transaction commit
2
======================
false
==================
======================
true
==================
COMMITTING TRANSACTION
09:14:13,367 DEBUG JDBCTransaction:83 - commit
09:14:13,383 DEBUG SessionImpl:323 - automatically flushing session
09:14:13,383 DEBUG AbstractFlushingEventListener:52 - flushing session
09:14:13,383 DEBUG AbstractFlushingEventListener:102 - processing flush-time cascades
09:14:13,383 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: org.usgs.nbii.rcv.model.RCVPortalConfiguration
09:14:13,383 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: org.usgs.nbii.rcv.model.RCVPortalConfiguration
09:14:13,383 DEBUG AbstractFlushingEventListener:150 - dirty checking collections
09:14:13,383 DEBUG AbstractFlushingEventListener:167 - Flushing entities and processing referenced collections
09:14:13,383 DEBUG WrapVisitor:86 - Wrapped collection in role: org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs
comparing size and toStrings of portletConfig and newPortletConfig, respectively
[null, org.usgs.nbii.rcv.model.RCVPortletConfiguration@1aa]=2
[null, org.usgs.nbii.rcv.model.RCVPortletConfiguration@1aa]=2
++++++++++++++++++++++
Contents of newPortletConfigs
++++++++++++++++++++

size is: 2
+++++++++++++++++++++++++
in hibernate session = false
0 was null
++++++++++++++++++++++
+++++++++++++++++++++++++
in hibernate session = true
1 was not null
identifier is 18
title is test
++++++++++++++++++++++
+++++++++++++++++++++

size and location of portletConfig and newPortletConfig, respectively, after clear() operation
[]=0
[]=0
size and location of portletConfig after addAll() operation
[]=0
09:14:13,383 DEBUG Collections:140 - Collection found: [org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs#13], was: [<unreferenced>] (initialized)
09:14:13,383 DEBUG AbstractFlushingEventListener:203 - Processing unreferenced collections
09:14:13,383 DEBUG Collections:50 - Collection dereferenced: [org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs#13]
09:14:13,383 DEBUG util:38 - caught exception in commitTransaction
09:14:13,383 DEBUG util:38 - Don't dereference a collection with cascade="all-delete-orphan": org.usgs.nbii.rcv.model.RCVPortalConfiguration.portletConfigs


Now I am pretty confused....

Hibernate appears to be processing 1 row for the collection, as it should, as there is only one row in the table, however, the collection coming in to
the setter has two elements in it. The first one is null. Where did this come from? Am I dense, do I not understand a list?

Also, it appears the collection being passed to the setter is the same object. So when I clear it, that clears everything. Yet if I don't clear it, then the elements in the list are duped and it just doubles in size. Does this indicate there is a problem w/ my equals() and hashcode() methods?

I could really use some help here, even if it is to just tell me I am dense. At least then I would know to look at myself as the root of the problem. ;)

Also, one more thing......

Changing the setter to just this:

public void setPortletConfigs(List newPortletConfigs) {
this.portletConfigs = newPortletConfigs;


}

Appears to solve the immediate problem. But won't I just run into the dereference problem again if I pass it a newly created List? And if I do, is this just something of which I need to be aware and plan for?