hibernate: 2.1.1
jboss: 3.2.1
mysql: 4.0.13
spring: 1.0m4
Hi,
I' m wondering if anyone could tell me where I'm going wrong?
I'm loading in a Company object with two collections - contacts and projects. In this particular use case only the contact collection is needed, but it seems to be initializing the projects collection when I haven't accessed it in the code. Following is the code, metadata and debug output:
public static Map getCompanyMap(ICompany c) {
Map map = new HashMap();
map.put("id", c.getIdAsString());
map.put("name", c.getName());
map.put("alias", c.getAlias());
map.put("street", c.getAddress().getStreet());
map.put("city", c.getAddress().getCity());
map.put("zip", c.getAddress().getZip());
map.put("state", c.getAddress().getState().getName());
map.put("country", c.getAddress().getCountry().getCountry());
map.put("website", c.getWebsite());
map.put("comments", c.getComments());
map.put("abn", c.getAbn());
map.put("acn", c.getAcn());
//map.put("status", c.getStatus().getStatus());
map.put("version", new Integer(c.getVersion()));
for (Iterator i = c.getContacts().iterator(); i.hasNext();) {
Map cMap = new HashMap();
IContact co = (IContact) i.next();
cMap.put("id", co.getIdAsString());
cMap.put("firstname", co.getFirstName());
cMap.put("lastname", co.getLastName());
map.putAll(cMap);
}
return map;
}
Company metadata
<hibernate-mapping>
<class name="com.generator.dom.hibernate.Company" table="companies" discriminator-value="comp" proxy="com.generator.dom.hibernate.Company">
<id name="id" column="companyid" type="long">
<generator class="native"/>
</id>
<version name="version" type="integer"/>
<component name="Address" class="com.generator.dom.hibernate.Address">
<property name="street" type="java.lang.String" length="100" not-null="true"/>
<property name="city" type="java.lang.String" length="100" not-null="true"/>
<property name="zip" type="java.lang.String" length="10" not-null="true"/>
<many-to-one name="state" column="stateid" class="com.generator.dom.hibernate.State" not-null="true"/>
<many-to-one name="country" column="countryid" class="com.generator.dom.hibernate.Country" not-null="true"/>
</component>
<property name="abn" type="java.lang.String" length="50"/>
<property name="acn" type="java.lang.String" length="50"/>
<property name="alias" type="java.lang.String" length="100" not-null="true"/>
<property name="comments" type="java.lang.String">
<column name="comments" sql-type="longtext"/>
</property>
<property name="website" type="java.lang.String" length="100"/>
<property name="name" type="java.lang.String" length="100" not-null="true"/>
<many-to-one name="status" column="statusid" class="com.generator.dom.hibernate.Status" not-null="true"/>
<set name="contacts" inverse="true" lazy="true">
<key column="companyid"/>
<one-to-many class="com.generator.dom.hibernate.Contact"/>
</set>
<set name="projects" inverse="true" lazy="true">
<key column="companyid"/>
<one-to-many class="com.generator.dom.hibernate.Project"/>
</set>
</class>
</hibernate-mapping>
Debug output:
11:42:57,347 DEBUG [SessionImpl] find: from Company as company where company.id = ?
11:42:57,349 DEBUG [QueryParameters] parameters: [1]
11:42:57,350 DEBUG [SessionImpl] flushing session
11:42:57,351 DEBUG [SessionImpl] Flushing entities and processing referenced collections
11:42:57,352 DEBUG [SessionImpl] Processing unreferenced collections
11:42:57,353 DEBUG [SessionImpl] Scheduling collection removes/(re)creates/updates
11:42:57,354 DEBUG [SessionImpl] Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
11:42:57,355 DEBUG [SessionImpl] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
11:42:57,356 DEBUG [SessionImpl] Dont need to execute flush
11:42:57,357 DEBUG [QueryTranslator] HQL: from com.generator.dom.hibernate.Company as company where company.id = ?
11:42:57,358 DEBUG [QueryTranslator] SQL: select company0_.companyid as companyid, company0_.version as version, company0_.street as street, company0_.city as city, company0_.zip as zip, company0_.stateid as stateid, company0_.countryid as countryid, company0_.abn as abn, company0_.acn as acn, company0_.alias as alias, company0_.comments as comments, company0_.website as website, company0_.name as name, company0_.statusid as statusid from companies company0_ where (company0_.companyid=? )
11:42:57,359 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
11:42:57,361 DEBUG [SQL] select company0_.companyid as companyid, company0_.version as version, company0_.street as street, company0_.city as city, company0_.zip as zip, company0_.stateid as stateid, company0_.countryid as countryid, company0_.abn as abn, company0_.acn as acn, company0_.alias as alias, company0_.comments as comments, company0_.website as website, company0_.name as name, company0_.statusid as statusid from companies company0_ where (company0_.companyid=? )
11:42:57,363 DEBUG [BatcherImpl] preparing statement
11:42:57,364 DEBUG [LongType] binding '1' to parameter: 1
11:42:57,391 DEBUG [Loader] processing result set
11:42:57,393 DEBUG [LongType] returning '1' as column: companyid
11:42:57,394 DEBUG [Loader] result row: 1
11:42:57,395 DEBUG [Loader] Initializing object from ResultSet: 1
11:42:57,396 DEBUG [Loader] Hydrating entity: com.generator.dom.hibernate.Company#1
11:42:57,398 DEBUG [IntegerType] returning '30' as column: version
11:42:57,399 DEBUG [StringType] returning '24/43 Bridge Road' as column: street
11:42:57,400 DEBUG [StringType] returning 'Stanmore' as column: city
11:42:57,401 DEBUG [StringType] returning '2048' as column: zip
11:42:57,402 DEBUG [LongType] returning '1' as column: stateid
11:42:57,404 DEBUG [LongType] returning '1' as column: countryid
11:42:57,405 DEBUG [StringType] returning '123456789' as column: abn
11:42:57,406 DEBUG [StringType] returning '000123456789' as column: acn
11:42:57,432 DEBUG [StringType] returning 'geni' as column: alias
11:42:57,434 DEBUG [StringType] returning ' ' as column: comments
11:42:57,435 DEBUG [StringType] returning 'www.geni.com.au' as column: website
11:42:57,436 DEBUG [StringType] returning 'Generator Interactive' as column: name
11:42:57,437 DEBUG [LongType] returning '1' as column: statusid
11:42:57,438 DEBUG [SessionImpl] Version: 30
11:42:57,439 DEBUG [Loader] done processing result set (1 rows)
11:42:57,440 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
11:42:57,441 DEBUG [BatcherImpl] closing statement
11:42:57,442 DEBUG [Loader] total objects hydrated: 1
11:42:57,443 DEBUG [SessionImpl] resolving associations for [com.generator.dom.hibernate.Company#1]
11:42:57,453 DEBUG [SessionImpl] running Session.finalize()
11:42:57,455 DEBUG [SessionImpl] running Session.finalize()
11:42:57,456 DEBUG [SessionImpl] running Session.finalize()
11:42:57,458 DEBUG [SessionImpl] loading [com.generator.dom.hibernate.State#1]
11:42:57,459 DEBUG [SessionImpl] loading [com.generator.dom.hibernate.Country#1]
11:42:57,483 DEBUG [SessionImpl] loading [com.generator.dom.hibernate.Status#1]
11:42:57,484 DEBUG [SessionImpl] collection not cached
11:42:57,486 DEBUG [SessionImpl] collection not cached
11:42:57,487 DEBUG [SessionImpl] done materializing entity [com.generator.dom.hibernate.Company#1]
11:42:57,488 DEBUG [SessionImpl] initializing non-lazy collections
11:42:57,513 DEBUG [SessionImpl] attempting to resolve [com.generator.dom.hibernate.State#1]
11:42:57,515 DEBUG [SessionImpl] object not resolved in any cache [com.generator.dom.hibernate.State#1]
11:42:57,516 DEBUG [EntityPersister] Materializing entity: [com.generator.dom.hibernate.State#1]
11:42:57,518 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
11:42:57,518 DEBUG [SQL] select state0_.stateid as stateid0_, state0_.name as name0_, state0_.fullName as fullName0_ from states state0_ where state0_.stateid=?
11:42:57,519 DEBUG [BatcherImpl] preparing statement
11:42:57,521 DEBUG [LongType] binding '1' to parameter: 1
11:42:57,523 DEBUG [Loader] processing result set
11:42:57,524 DEBUG [Loader] result row: 1
11:42:57,525 DEBUG [Loader] Initializing object from ResultSet: 1
11:42:57,527 DEBUG [Loader] Hydrating entity: com.generator.dom.hibernate.State#1
11:42:57,528 DEBUG [StringType] returning 'NSW' as column: name0_
11:42:57,529 DEBUG [StringType] returning 'New South Wales' as column: fullName0_
11:42:57,530 DEBUG [Loader] done processing result set (1 rows)
11:42:57,531 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
11:42:57,532 DEBUG [BatcherImpl] closing statement
11:42:57,533 DEBUG [Loader] total objects hydrated: 1
11:42:57,534 DEBUG [SessionImpl] resolving associations for [com.generator.dom.hibernate.State#1]
11:42:57,535 DEBUG [SessionImpl] done materializing entity [com.generator.dom.hibernate.State#1]
11:42:57,536 DEBUG [SessionImpl] initializing non-lazy collections
11:42:57,537 DEBUG [SessionImpl] attempting to resolve [com.generator.dom.hibernate.Country#1]
11:42:57,538 DEBUG [SessionImpl] object not resolved in any cache [com.generator.dom.hibernate.Country#1]
11:42:57,540 DEBUG [EntityPersister] Materializing entity: [com.generator.dom.hibernate.Country#1]
11:42:57,541 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
11:42:57,542 DEBUG [SQL] select country0_.countryid as countryid0_, country0_.country as country0_ from countries country0_ where country0_.countryid=?
11:42:57,543 DEBUG [BatcherImpl] preparing statement
11:42:57,544 DEBUG [LongType] binding '1' to parameter: 1
11:42:57,546 DEBUG [Loader] processing result set
11:42:57,548 DEBUG [Loader] result row: 1
11:42:57,549 DEBUG [Loader] Initializing object from ResultSet: 1
11:42:57,561 DEBUG [Loader] Hydrating entity: com.generator.dom.hibernate.Country#1
11:42:57,562 DEBUG [StringType] returning 'Australia' as column: country0_
11:42:57,562 DEBUG [Loader] done processing result set (1 rows)
11:42:57,562 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
11:42:57,563 DEBUG [BatcherImpl] closing statement
11:42:57,563 DEBUG [Loader] total objects hydrated: 1
11:42:57,563 DEBUG [SessionImpl] resolving associations for [com.generator.dom.hibernate.Country#1]
11:42:57,563 DEBUG [SessionImpl] done materializing entity [com.generator.dom.hibernate.Country#1]
11:42:57,563 DEBUG [SessionImpl] initializing non-lazy collections
11:42:57,563 DEBUG [SessionImpl] initializing collection [com.generator.dom.hibernate.Company.contacts#1]
11:42:57,564 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
11:42:57,603 DEBUG [SQL] select contacts0_.contactid as contactid__, contacts0_.companyid as companyid__, contacts0_.contactid as contactid0_, contacts0_.version as version0_, contacts0_.firstName as firstName0_, contacts0_.lastName as lastName0_, contacts0_.phone as phone0_, contacts0_.fax as fax0_, contacts0_.email as email0_, contacts0_.comments as comments0_, contacts0_.position as position0_, contacts0_.mobile as mobile0_, contacts0_.companyid as companyid0_ from contacts contacts0_ where contacts0_.companyid=?
11:42:57,605 DEBUG [BatcherImpl] preparing statement
11:42:57,607 DEBUG [LongType] binding '1' to parameter: 1
11:42:57,610 DEBUG [Loader] result set contains (possibly empty) collection: [com.generator.dom.hibernate.Company.contacts#1]
11:42:57,611 DEBUG [SessionImpl] uninitialized collection: initializing
11:42:57,613 DEBUG [Loader] processing result set
11:42:57,614 DEBUG [Loader] done processing result set (0 rows)
11:42:57,615 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
11:42:57,617 DEBUG [BatcherImpl] closing statement
11:42:57,618 DEBUG [Loader] total objects hydrated: 0
11:42:57,619 DEBUG [SessionImpl] 1 collections were found in result set
11:42:57,619 DEBUG [SessionImpl] collection fully initialized: [com.generator.dom.hibernate.Company.contacts#1]
11:42:57,620 DEBUG [SessionImpl] 1 collections initialized
11:42:57,621 DEBUG [SessionImpl] initializing non-lazy collections
11:42:57,622 DEBUG [HibernateInterceptor] Eagerly flushing Hibernate session
11:42:57,623 DEBUG [SessionImpl] flushing session
11:42:57,624 DEBUG [SessionImpl] Flushing entities and processing referenced collections
11:42:57,626 DEBUG [WrapVisitor] Wrapped collection in role: com.generator.dom.hibernate.Company.contacts
11:42:57,627 DEBUG [WrapVisitor] Wrapped collection in role: com.generator.dom.hibernate.Company.projects
11:42:57,628 DEBUG [AbstractEntityPersister] com.generator.dom.hibernate.Company.contacts is dirty
11:42:57,629 DEBUG [AbstractEntityPersister] com.generator.dom.hibernate.Company.projects is dirty
11:42:57,630 DEBUG [SessionImpl] Updating entity: [com.generator.dom.hibernate.Company#1]
11:42:57,631 DEBUG [Versioning] Incrementing: 30 to 31
11:42:57,632 DEBUG [SessionImpl] Collection found: [com.generator.dom.hibernate.Company.contacts#1], was: [<unreferenced>]
11:42:57,633 DEBUG [SessionImpl] Collection found: [com.generator.dom.hibernate.Company.projects#1], was: [<unreferenced>]
11:42:57,634 DEBUG [SessionImpl] Processing unreferenced collections
11:42:57,635 DEBUG [SessionImpl] Collection dereferenced: [com.generator.dom.hibernate.Company.contacts#1]
11:42:57,636 DEBUG [SessionImpl] Collection dereferenced: [com.generator.dom.hibernate.Company.projects#1]
11:42:57,637 DEBUG [SessionImpl] Scheduling collection removes/(re)creates/updates
11:42:57,639 DEBUG [SessionImpl] Flushed: 0 insertions, 1 updates, 0 deletions to 3 objects
11:42:57,640 DEBUG [SessionImpl] Flushed: 2 (re)creations, 0 updates, 2 removals to 4 collections
11:42:57,640 DEBUG [Printer] listing entities:
11:42:57,641 DEBUG [Printer] com.generator.dom.hibernate.Country{country=Australia, id=1}
11:42:57,642 DEBUG [Printer] com.generator.dom.hibernate.State{fullName=New South Wales, name=NSW, id=1}
11:42:57,644 DEBUG [SessionImpl] initializing collection [com.generator.dom.hibernate.Company.projects#1]
11:42:57,645 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
11:42:57,646 DEBUG [SQL] select projects0_.projectid as projectid__, projects0_.companyid as companyid__, projects0_.projectid as projectid0_, projects0_.version as version0_, projects0_.title as title0_, projects0_.brief as brief0_, projects0_.comments as comments0_, projects0_.quoteNo as quoteNo0_, projects0_.dateRaised as dateRaised0_, projects0_.dateLastModified as dateLast8_0_, projects0_.deadline as deadline0_, projects0_.startDate as startDate0_, projects0_.hours as hours0_, projects0_.companyid as companyid0_, projects0_.manager as manager0_, projects0_.raisedBy as raisedBy0_, projects0_.updatedBy as updatedBy0_, projects0_.statusid as statusid0_ from projects projects0_ where projects0_.companyid=?
11:42:57,648 DEBUG [BatcherImpl] preparing statement
11:42:57,649 DEBUG [LongType] binding '1' to parameter: 1
11:42:57,652 DEBUG [Loader] result set contains (possibly empty) collection: [com.generator.dom.hibernate.Company.projects#1]
11:42:57,653 DEBUG [SessionImpl] uninitialized collection: initializing
11:42:57,654 DEBUG [Loader] processing result set
11:42:57,678 DEBUG [Loader] done processing result set (0 rows)
11:42:57,680 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
11:42:57,681 DEBUG [BatcherImpl] closing statement
11:42:57,682 DEBUG [Loader] total objects hydrated: 0
11:42:57,683 DEBUG [SessionImpl] 1 collections were found in result set
11:42:57,684 DEBUG [SessionImpl] collection fully initialized: [com.generator.dom.hibernate.Company.projects#1]
11:42:57,685 DEBUG [SessionImpl] 1 collections initialized
11:42:57,686 DEBUG [SessionImpl] initializing non-lazy collections
11:42:57,687 DEBUG [Printer] com.generator.dom.hibernate.Company{comments= , contacts=[], abn=123456789, projects=[], Address=Address{country=Country#1, street=24/43 Bridge Road, state=State#1, zip=2048, city=Stanmore}, status=Status#1, name=Generator Interactive, acn=000123456789, website=www.geni.com.au, id=1, alias=geni, version=31}
11:42:57,689 DEBUG [SessionImpl] executing flush
11:42:57,689 DEBUG [EntityPersister] Updating entity: [com.generator.dom.hibernate.Company#1]
11:42:57,689 DEBUG [EntityPersister] Existing version: 30 -> New version: 31
11:42:57,690 DEBUG [BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
11:42:57,690 DEBUG [SQL] update companies set version=?, street=?, city=?, zip=?, stateid=?, countryid=?, abn=?, acn=?, alias=?, comments=?, website=?, name=?, statusid=? where companyid=? and version=?
11:42:57,690 DEBUG [BatcherImpl] preparing statement
11:42:57,690 DEBUG [EntityPersister] Dehydrating entity: [com.generator.dom.hibernate.Company#1]
11:42:57,690 DEBUG [IntegerType] binding '31' to parameter: 1
11:42:57,691 DEBUG [StringType] binding '24/43 Bridge Road' to parameter: 2
11:42:57,691 DEBUG [StringType] binding 'Stanmore' to parameter: 3
11:42:57,691 DEBUG [StringType] binding '2048' to parameter: 4
11:42:57,691 DEBUG [LongType] binding '1' to parameter: 5
11:42:57,691 DEBUG [LongType] binding '1' to parameter: 6
11:42:57,692 DEBUG [StringType] binding '123456789' to parameter: 7
11:42:57,693 DEBUG [StringType] binding '000123456789' to parameter: 8
11:42:57,693 DEBUG [StringType] binding 'geni' to parameter: 9
11:42:57,693 DEBUG [StringType] binding ' ' to parameter: 10
11:42:57,693 DEBUG [StringType] binding 'www.geni.com.au' to parameter: 11
11:42:57,694 DEBUG [StringType] binding 'Generator Interactive' to parameter: 12
11:42:57,694 DEBUG [LongType] binding '1' to parameter: 13
11:42:57,694 DEBUG [LongType] binding '1' to parameter: 14
11:42:57,694 DEBUG [IntegerType] binding '30' to parameter: 15
11:42:57,699 DEBUG [BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
11:42:57,699 DEBUG [BatcherImpl] closing statement
11:42:57,699 DEBUG [SessionImpl] post flush
11:42:57,700 DEBUG [TransactionSynchronizationManager] Removed value [org.springframework.orm.hibernate.SessionHolder@58b6e6] for key [net.sf.hibernate.impl.SessionFactoryImpl@d076a3] from thread [PoolThread-9]
11:42:57,700 DEBUG [SessionFactoryUtils] Closing Hibernate session
11:42:57,700 DEBUG [SessionImpl] closing session
11:42:57,700 DEBUG [SessionImpl] disconnecting session
11:42:57,700 DEBUG [CacheSynchronization] transaction before completion callback
11:42:57,731 DEBUG [CacheSynchronization] transaction after completion callback, status: 3
11:42:57,731 DEBUG [SessionImpl] transaction completion
Hibernate also updates the version number everytime the company info is retrieved. Is this because both of the collections are marked dirty? They are both empty at this point in time.
Thanks in advance for any help
cheers
andy
|