-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 12 posts ] 
Author Message
 Post subject: how to mininize the object graph that gets loaded.
PostPosted: Fri May 07, 2004 9:56 pm 
Regular
Regular

Joined: Sat Feb 21, 2004 8:54 pm
Posts: 60
Location: Lakewood, California
hi, i have this table with some many to one relations (see hbm file below). i have cascade=none and outer-join=false on all of them. all of the parent's have lazy=true or proxy=same class name. i have hibernate.max_fetch_depth=0 in my hibernate.properties file.
but when i do a:
Collection ordered=session.find("select from PoItemOrdered as ordered where ordered.poNew='po3153'");
i get a list of the objects that i want. for each object i see a query that i would expect (see below) , but i also get 4 more (one for each of the parents) that look like he is chasing down the links.

i am a newbie. i must be overlooking something very obvious.

does anyone have any idea how to stop the extra queries?

thanks

for each object in the list i get a:

Hibernate: select poitemorde0_.db_id as db_id, poitemorde0_.po_num as po_num, poitemorde0_.deliver_to_ref as deliver_3_,
...
as po_id, poitemorde0_.asn_id as asn_id from po_item_ordered poitemorde0_ where (poitemorde0_.po_id='po3153' )

which is what i expect.

i also, get four (4) more queries:

Hibernate: select poitem0_.db_id as db_id0_, poitem0_.item_id as item_id0_, poitem0_.item_name as item_name0_,
...
poitem0_.who_modified as who_mod18_0_, poitem0_.when_modified as when_mo19_0_ from po_item poitem0_ where poitem0_.item_id=?

Hibernate: select entity0_.db_id as db_id0_, entity0_.entity_id as entity_id0_, entity0_.entity_type as entity_t3_0_,
...
when_cr23_0_, entity0_.item_ref_ent_id as item_re24_0_ from entity entity0_ where entity0_.entity_id=?

Hibernate: select ponew0_.db_id as db_id0_, ponew0_.po_id as po_id0_, ponew0_.po_num as po_num0_, ponew0_.sub_vendor_id as
...
remarks0_, ponew0_.ordered_by_id as ordered16_0_ from po_new ponew0_ where ponew0_.po_id=?

Hibernate: select asnmessage0_.db_id as db_id0_, asnmessage0_.asn_id as asn_id0_, asnmessage0_.asn_num as asn_num0_,
...
asnmessage0_.who_modified as who_modi8_0_ from asn_message asnmessage0_ where asnmessage0_.asn_id=?

here is the mapping file.

<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
"-//Hibernate/Hibernate Mapping DTD 2.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd" >
<hibernate-mapping>
<!--
Created by the Middlegen Hibernate plugin

http://boss.bekk.no/boss/middlegen/
http://hibernate.sourceforge.net/
-->
<class name='po_db2.hibernate.PoItemOrdered' table='po_item_ordered'>
<id column='db_id' name='dbId' type='int'>
<generator class='assigned' />
</id>
<property column='po_num' length='15' name='poNum' not-null='true' type='java.lang.String' />
<!-- more properties -->
<property column='container_num' length='40' name='containerNum' not-null='true' type='java.lang.String' />
<!-- associations -->
<!-- bi-directional many-to-one association to PoItem -->
<many-to-one cascade='none' class='po_db2.hibernate.PoItem' name='poItem' not-null='false' outer-join='false' property-ref='itemId'>
<column name='item_id' />
</many-to-one>
<!-- bi-directional many-to-one association to Entity -->
<many-to-one cascade='none' class='po_db2.hibernate.Entity' name='entity' not-null='false' outer-join='false' property-ref='entityId'>
<column name='ordered_by_id' />
</many-to-one>
<!-- bi-directional many-to-one association to PoNew -->
<many-to-one cascade='none' class='po_db2.hibernate.PoNew' column='po_id' name='poNew' not-null='true' outer-join='false' property-ref='poId'></many-to-one>
<!-- bi-directional many-to-one association to AsnMessage -->
<many-to-one cascade='none' class='po_db2.hibernate.AsnMessage' name='asnMessage' not-null='false' outer-join='false' property-ref='asnId'>
<column name='asn_id' />
</many-to-one>
</class>
</hibernate-mapping>

_________________
<http://tayek.com/>, co-chair <http://www.ocjug.org/>, actively
seeking telecommuting work. hate spam?
<https://www1.ietf.org/mailman/listinfo/asrg>


Top
 Profile  
 
 Post subject: Same behavior
PostPosted: Fri May 07, 2004 10:47 pm 
Regular
Regular

Joined: Thu Apr 29, 2004 5:08 pm
Posts: 56
Location: Montreal, Quebec, Canada
I'm experiencing the same behavior and asking myself why Hibernate insists at performing selects on linked objects in the object graph. outer-join=false, lazy=true, proxy=class... nothing worked.

I'm using version 2.1.2

Added to watched topic.

_________________
- Frank


Top
 Profile  
 
 Post subject: Re: Same behavior
PostPosted: Sat May 08, 2004 11:44 pm 
Regular
Regular

Joined: Sat Feb 21, 2004 8:54 pm
Posts: 60
Location: Lakewood, California
fdelisle wrote:
I'm experiencing the same behavior and asking myself why Hibernate insists at performing selects on linked objects in the object graph. outer-join=false, lazy=true, proxy=class... nothing worked.

I'm using version 2.1.2.


i am using 2.1.2 also (with mysql 4). there is a thread here: http://forum.hibernate.org/viewtopic.php?t=929664 that sounds similar. i am not doing that as this happens to me on the first read. but you might be doing something like this.

thanks

_________________
<http://tayek.com/>, co-chair <http://www.ocjug.org/>, actively
seeking telecommuting work. hate spam?
<https://www1.ietf.org/mailman/listinfo/asrg>


Top
 Profile  
 
 Post subject: Re: Same behavior
PostPosted: Sun May 09, 2004 6:37 pm 
Regular
Regular

Joined: Sat Feb 21, 2004 8:54 pm
Posts: 60
Location: Lakewood, California
fdelisle wrote:
I'm experiencing the same behavior ... nothing worked.


i truned on tge debugging and added an outer join=false in the properies file just in case and got a lot more stuff to look at. i can see where it's going off to chase down the links (see complete log below).

15:32:08,453 DEBUG Loader:226 - done processing result set (1 rows)
15:32:08,453 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
15:32:08,453 DEBUG BatcherImpl:261 - closing statement
15:32:08,453 DEBUG Loader:239 - total objects hydrated: 1
15:32:08,453 DEBUG SessionImpl:2166 - resolving associations for [po_db2.hibernate.PoItemOrdered#7431]
15:32:08,453 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
Hibernate: select poitem0_.db_id as db_id0_, poitem0_.item_id as item_id0_, poitem0_.item_name as item_name0_, poitem0_.weight_gross_unit as weight_g4_0_, poitem0_.weight_gross as weight_g5_0_, poitem0_.weight_net_unit as weight_n6_0_, poitem0_.weight_net as weight_net0_, poitem0_.volume_unit as volume_u8_0_, poitem0_.volume as volume0_, poitem0_.sku as sku0_, poitem0_.upc as upc0_, poitem0_.quantity_unit as quantit12_0_, poitem0_.quantity as quantity0_, poitem0_.brand as brand0_, poitem0_.description as descrip15_0_, poitem0_.who_created as who_cre16_0_, poitem0_.when_created as when_cr17_0_, poitem0_.who_modified as who_mod18_0_, poitem0_.when_modified as when_mo19_0_ from po_item poitem0_ where poitem0_.item_id=?
15:32:08,453 DEBUG BatcherImpl:241 - preparing statement
...

as you can see, he is trying to resolve the associations for the ordered items. you may want to try this yourself and see if the same thing is happening to you. i will probably look at the class meta data and see if i can see what is set in there.

thanks

log:

started
constructing main for jdbc:mysql://204.1.213.186:3306/po_db2
constructing configuration
15:32:00,781 INFO Environment:462 - Hibernate 2.1.2
15:32:00,812 INFO Environment:496 - loaded properties from resource hibernate.properties: {hibernate.connection.driver_class=org.gjt.mm.mysql.Driver, hibernate.cglib.use_reflection_optimizer=true, hibernate.cache.provider_class=net.sf.hibernate.cache.HashtableCacheProvider, hibernate.cache.use_query_cache=true, hibernate.max_fetch_depth=0, hibernate.dialect=net.sf.hibernate.dialect.MySQLDialect, hibernate.jdbc.use_streams_for_binary=true, hibernate.jdbc.batch_size=0, hibernate.query.substitutions=true 1, false 0, yes 'Y', no 'N', hibernate.use_outer_join=false, hibernate.proxool.pool_alias=pool1, hibernate.connection.username=root, hibernate.show_sql=true, hibernate.connection.password=, hibernate.connection.pool_size=1}
15:32:00,812 INFO Environment:518 - using java.io streams to persist binary types
15:32:00,812 INFO Environment:519 - using CGLIB reflection optimizer
configuring
using: U:\projects\mg2\bin\po_db2\hibernate
15:32:00,859 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\User.hbm.xml
15:32:01,156 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:01,156 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:01,609 INFO Binder:229 - Mapping class: po_db2.hibernate.User -> user
15:32:01,906 DEBUG Binder:462 - Mapped property: dbId -> db_id, type: integer
15:32:01,953 DEBUG Binder:462 - Mapped property: userid -> userid, type: string
15:32:01,968 DEBUG Binder:462 - Mapped property: passwd -> passwd, type: string
15:32:01,968 DEBUG Binder:462 - Mapped property: roleId -> role_id, type: string
15:32:01,968 DEBUG Binder:462 - Mapped property: company -> company, type: string
15:32:01,968 DEBUG Binder:462 - Mapped property: name -> name, type: string
15:32:01,968 DEBUG Binder:462 - Mapped property: languageId -> language_id, type: string
15:32:01,968 DEBUG Binder:462 - Mapped property: active -> active, type: string
15:32:01,968 DEBUG Binder:462 - Mapped property: permissions -> permissions, type: string
15:32:01,968 DEBUG Binder:462 - Mapped property: groups -> groups, type: string
15:32:01,968 DEBUG Binder:462 - Mapped property: idNum -> id_num, type: string
15:32:01,968 DEBUG Binder:462 - Mapped property: agentNum -> agent_num, type: string
15:32:01,968 DEBUG Binder:462 - Mapped property: billtoNum -> billto_num, type: string
15:32:01,968 DEBUG Binder:462 - Mapped property: shpNum -> shp_num, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: csgNum -> csg_num, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: carrierNum -> carrier_num, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: notifypartyNum -> notifyparty_num, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: emailInfo -> email_info, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: eventlist -> eventlist, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: emailError -> email_error, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: queryStr -> query_str, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: agentRefPattern -> agent_ref_pattern, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: billtoRefPattern -> billto_ref_pattern, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: shpRefPattern -> shp_ref_pattern, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: csgRefPattern -> csg_ref_pattern, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: responsibleFor -> responsible_for, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: passwordTxt -> password_txt, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: whoModified -> who_modified, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: whenModified -> when_modified, type: timestamp
15:32:01,984 DEBUG Binder:462 - Mapped property: phone -> phone, type: string
15:32:01,984 DEBUG Binder:462 - Mapped property: fax -> fax, type: string
15:32:02,000 DEBUG Binder:462 - Mapped property: address -> address, type: string
15:32:02,000 DEBUG Binder:462 - Mapped property: address2 -> address2, type: string
15:32:02,000 DEBUG Binder:462 - Mapped property: city -> city, type: string
15:32:02,000 DEBUG Binder:462 - Mapped property: postalCode -> postal_code, type: string
15:32:02,000 DEBUG Binder:462 - Mapped property: orderedById -> ordered_by_id, type: string
15:32:02,000 DEBUG Binder:462 - Mapped property: vendorId -> vendor_id, type: string
15:32:02,000 DEBUG Binder:462 - Mapped property: irsNum -> irs_num, type: string
15:32:02,000 DEBUG Binder:462 - Mapped property: deliverToNum -> deliver_to_num, type: string
15:32:02,000 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\PoItem.hbm.xml
15:32:02,015 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:02,015 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:02,062 INFO Binder:229 - Mapping class: po_db2.hibernate.PoItem -> po_item
15:32:02,062 DEBUG Binder:462 - Mapped property: dbId -> db_id, type: integer
15:32:02,062 DEBUG Binder:462 - Mapped property: itemId -> item_id, type: string
15:32:02,062 DEBUG Binder:462 - Mapped property: itemName -> item_name, type: string
15:32:02,078 DEBUG Binder:462 - Mapped property: weightGrossUnit -> weight_gross_unit, type: string
15:32:02,078 DEBUG Binder:462 - Mapped property: weightGross -> weight_gross, type: big_decimal
15:32:02,078 DEBUG Binder:462 - Mapped property: weightNetUnit -> weight_net_unit, type: string
15:32:02,078 DEBUG Binder:462 - Mapped property: weightNet -> weight_net, type: big_decimal
15:32:02,078 DEBUG Binder:462 - Mapped property: volumeUnit -> volume_unit, type: string
15:32:02,078 DEBUG Binder:462 - Mapped property: volume -> volume, type: big_decimal
15:32:02,093 DEBUG Binder:462 - Mapped property: sku -> sku, type: string
15:32:02,093 DEBUG Binder:462 - Mapped property: upc -> upc, type: string
15:32:02,093 DEBUG Binder:462 - Mapped property: quantityUnit -> quantity_unit, type: string
15:32:02,093 DEBUG Binder:462 - Mapped property: quantity -> quantity, type: big_decimal
15:32:02,093 DEBUG Binder:462 - Mapped property: brand -> brand, type: string
15:32:02,093 DEBUG Binder:462 - Mapped property: description -> description, type: string
15:32:02,093 DEBUG Binder:462 - Mapped property: whoCreated -> who_created, type: string
15:32:02,093 DEBUG Binder:462 - Mapped property: whenCreated -> when_created, type: timestamp
15:32:02,093 DEBUG Binder:462 - Mapped property: whoModified -> who_modified, type: string
15:32:02,109 DEBUG Binder:462 - Mapped property: whenModified -> when_modified, type: timestamp
15:32:02,296 DEBUG Binder:462 - Mapped property: poItemNums, type: java.util.Set
15:32:02,312 DEBUG Binder:462 - Mapped property: poItemOrdereds, type: java.util.Set
15:32:02,312 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\DatabaseHeader.hbm.xml
15:32:02,328 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:02,328 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:02,359 INFO Binder:229 - Mapping class: po_db2.hibernate.DatabaseHeader -> database_header
15:32:02,375 DEBUG Binder:462 - Mapped property: dbId -> db_id, type: integer
15:32:02,375 DEBUG Binder:462 - Mapped property: variable -> variable, type: string
15:32:02,375 DEBUG Binder:462 - Mapped property: language -> language, type: string
15:32:02,375 DEBUG Binder:462 - Mapped property: keyname -> keyname, type: string
15:32:02,375 DEBUG Binder:462 - Mapped property: string -> string, type: string
15:32:02,375 DEBUG Binder:462 - Mapped property: whoModified -> who_modified, type: string
15:32:02,375 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\Entity.hbm.xml
15:32:02,390 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:02,390 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:02,421 INFO Binder:229 - Mapping class: po_db2.hibernate.Entity -> entity
15:32:02,421 DEBUG Binder:462 - Mapped property: dbId -> db_id, type: integer
15:32:02,421 DEBUG Binder:462 - Mapped property: entityId -> entity_id, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: entityType -> entity_type, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: limitOrderedById -> limit_ordered_by_id, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: limitBilltoNum -> limit_billto_num, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: limitCsgNum -> limit_csg_num, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: limitShpNum -> limit_shp_num, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: limitAgentNum -> limit_agent_num, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: entityName -> entity_name, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: contact -> contact, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: add1 -> add1, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: add2 -> add2, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: phone -> phone, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: fax -> fax, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: email -> email, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: city -> city, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: state -> state, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: zip -> zip, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: country -> country, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: whoModified -> who_modified, type: string
15:32:02,421 DEBUG Binder:462 - Mapped property: whenModified -> when_modified, type: timestamp
15:32:02,437 DEBUG Binder:462 - Mapped property: whoCreated -> who_created, type: string
15:32:02,437 DEBUG Binder:462 - Mapped property: whenCreated -> when_created, type: timestamp
15:32:02,437 DEBUG Binder:462 - Mapped property: poItemNums, type: java.util.Set
15:32:02,437 DEBUG Binder:462 - Mapped property: entities, type: java.util.Set
15:32:02,453 DEBUG Binder:462 - Mapped property: entity -> item_ref_ent_id, type: po_db2.hibernate.Entity
15:32:02,593 DEBUG Binder:462 - Mapped property: entityNums, type: java.util.Set
15:32:02,593 DEBUG Binder:462 - Mapped property: poItemOrdereds, type: java.util.Set
15:32:02,593 DEBUG Binder:462 - Mapped property: itemsToBeDelivered, type: java.util.Set
15:32:02,593 DEBUG Binder:462 - Mapped property: orderedPOs, type: java.util.Set
15:32:02,593 DEBUG Binder:462 - Mapped property: sellingPOs, type: java.util.Set
15:32:02,593 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\Report.hbm.xml
15:32:02,609 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:02,609 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:02,718 INFO Binder:229 - Mapping class: po_db2.hibernate.Report -> report
15:32:02,718 DEBUG Binder:462 - Mapped property: dbId -> db_id, type: integer
15:32:02,718 DEBUG Binder:462 - Mapped property: userId -> user_id, type: string
15:32:02,718 DEBUG Binder:462 - Mapped property: reportId -> report_id, type: string
15:32:02,718 DEBUG Binder:462 - Mapped property: title -> title, type: string
15:32:02,718 DEBUG Binder:462 - Mapped property: tablenames -> tablenames, type: string
15:32:02,718 DEBUG Binder:462 - Mapped property: queryDef -> query_def, type: string
15:32:02,718 DEBUG Binder:462 - Mapped property: summaryDef -> summary_def, type: string
15:32:02,718 DEBUG Binder:462 - Mapped property: detailDef -> detail_def, type: string
15:32:02,718 DEBUG Binder:462 - Mapped property: entryDef -> entry_def, type: string
15:32:02,718 DEBUG Binder:462 - Mapped property: sortByDef -> sort_by_def, type: string
15:32:02,718 DEBUG Binder:462 - Mapped property: preEntryDef -> pre_entry_def, type: string
15:32:02,718 DEBUG Binder:462 - Mapped property: preSaveDef -> pre_save_def, type: string
15:32:02,734 DEBUG Binder:462 - Mapped property: dbKey -> db_key, type: string
15:32:02,734 DEBUG Binder:462 - Mapped property: flags -> flags, type: string
15:32:02,734 DEBUG Binder:462 - Mapped property: headerFrequency -> header_frequency, type: integer
15:32:02,734 DEBUG Binder:462 - Mapped property: recordsPerPage -> records_per_page, type: integer
15:32:02,734 DEBUG Binder:462 - Mapped property: sortFieldsNum -> sort_fields_num, type: integer
15:32:02,734 DEBUG Binder:462 - Mapped property: whoModified -> who_modified, type: string
15:32:02,734 DEBUG Binder:462 - Mapped property: whenModified -> when_modified, type: timestamp
15:32:02,734 DEBUG Binder:462 - Mapped property: joinDef -> join_def, type: string
15:32:02,734 DEBUG Binder:462 - Mapped property: preQueryDef -> pre_query_def, type: string
15:32:02,734 DEBUG Binder:462 - Mapped property: sqlDef -> sql_def, type: string
15:32:02,734 DEBUG Binder:462 - Mapped property: downloadDef -> download_def, type: string
15:32:02,734 DEBUG Binder:462 - Mapped property: nextTemplate -> next_template, type: string
15:32:02,734 DEBUG Binder:462 - Mapped property: tabledef -> tabledef, type: string
15:32:02,734 DEBUG Binder:462 - Mapped property: groupByDef -> group_by_def, type: string
15:32:02,750 DEBUG Binder:462 - Mapped property: permission -> permission, type: string
15:32:02,750 DEBUG Binder:462 - Mapped property: module -> module, type: string
15:32:02,750 DEBUG Binder:462 - Mapped property: remark -> remark, type: string
15:32:02,750 DEBUG Binder:462 - Mapped property: postSaveDef -> post_save_def, type: string
15:32:02,750 DEBUG Binder:462 - Mapped property: remarks -> remarks, type: string
15:32:02,750 DEBUG Binder:462 - Mapped property: summaryTemplate -> summary_template, type: string
15:32:02,750 DEBUG Binder:462 - Mapped property: detailTemplate -> detail_template, type: string
15:32:02,750 DEBUG Binder:462 - Mapped property: searchTemplate -> search_template, type: string
15:32:02,750 DEBUG Binder:462 - Mapped property: entryTemplate -> entry_template, type: string
15:32:02,750 DEBUG Binder:462 - Mapped property: downloadTemplate -> download_template, type: string
15:32:02,750 DEBUG Binder:462 - Mapped property: formValidationScripts -> form_validation_scripts, type: string
15:32:02,750 DEBUG Binder:462 - Mapped property: queryDefAdv -> query_def_adv, type: string
15:32:02,765 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\UniqueId.hbm.xml
15:32:02,828 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:02,843 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:02,937 INFO Binder:229 - Mapping class: po_db2.hibernate.UniqueId -> _unique_ids
15:32:02,937 DEBUG Binder:462 - Mapped property: tableName -> table_name, type: string
15:32:02,937 DEBUG Binder:462 - Mapped property: sequenceNum -> sequence_num, type: long
15:32:02,937 DEBUG Binder:462 - Mapped property: prefix -> prefix, type: string
15:32:02,937 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\DatabaseType.hbm.xml
15:32:02,953 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:02,953 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:03,062 INFO Binder:229 - Mapping class: po_db2.hibernate.DatabaseType -> database_type
15:32:03,062 DEBUG Binder:462 - Mapped property: dbId -> db_id, type: integer
15:32:03,062 DEBUG Binder:462 - Mapped property: variable -> variable, type: string
15:32:03,062 DEBUG Binder:462 - Mapped property: keyname -> keyname, type: string
15:32:03,062 DEBUG Binder:462 - Mapped property: string -> string, type: string
15:32:03,062 DEBUG Binder:462 - Mapped property: whoModified -> who_modified, type: string
15:32:03,062 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\Session.hbm.xml
15:32:03,125 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:03,140 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:03,171 INFO Binder:229 - Mapping class: po_db2.hibernate.Session -> session
15:32:03,171 DEBUG Binder:462 - Mapped property: sessionId -> session_id, type: string
15:32:03,171 DEBUG Binder:462 - Mapped property: userid -> userid, type: string
15:32:03,171 DEBUG Binder:462 - Mapped property: remoteIp -> remote_ip, type: string
15:32:03,171 DEBUG Binder:462 - Mapped property: whenModified -> when_modified, type: timestamp
15:32:03,171 DEBUG Binder:462 - Mapped property: login -> login, type: timestamp
15:32:03,171 DEBUG Binder:462 - Mapped property: logout -> logout, type: timestamp
15:32:03,171 DEBUG Binder:462 - Mapped property: requests -> requests, type: integer
15:32:03,171 DEBUG Binder:462 - Mapped property: whenCreated -> when_created, type: timestamp
15:32:03,171 DEBUG Binder:462 - Mapped property: invalidated -> invalidated, type: timestamp
15:32:03,171 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\EntityRole.hbm.xml
15:32:03,234 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:03,250 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:03,281 INFO Binder:229 - Mapping class: po_db2.hibernate.EntityRole -> entity_role
15:32:03,281 DEBUG Binder:462 - Mapped property: roleId -> role_id, type: string
15:32:03,281 DEBUG Binder:462 - Mapped property: roleName -> role_name, type: string
15:32:03,281 DEBUG Binder:462 - Mapped property: description -> description, type: string
15:32:03,296 DEBUG Binder:462 - Mapped property: whoCreated -> who_created, type: string
15:32:03,296 DEBUG Binder:462 - Mapped property: whenCreated -> when_created, type: timestamp
15:32:03,296 DEBUG Binder:462 - Mapped property: whoModified -> who_modified, type: string
15:32:03,296 DEBUG Binder:462 - Mapped property: whenModified -> when_modified, type: timestamp
15:32:03,296 DEBUG Binder:462 - Mapped property: entityNums, type: java.util.Set
15:32:03,296 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\EntityNum.hbm.xml
15:32:03,375 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:03,390 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:03,406 INFO Binder:229 - Mapping class: po_db2.hibernate.EntityNum -> entity_num
15:32:03,406 DEBUG Binder:462 - Mapped property: dbId -> db_id, type: integer
15:32:03,406 DEBUG Binder:462 - Mapped property: PEntNum -> p_ent_num, type: string
15:32:03,406 DEBUG Binder:462 - Mapped property: whoCreated -> who_created, type: string
15:32:03,406 DEBUG Binder:462 - Mapped property: whenCreated -> when_created, type: timestamp
15:32:03,406 DEBUG Binder:462 - Mapped property: whoModified -> who_modified, type: string
15:32:03,406 DEBUG Binder:462 - Mapped property: whenModified -> when_modified, type: timestamp
15:32:03,406 DEBUG Binder:462 - Mapped property: entityRole -> p_ent_role, type: po_db2.hibernate.EntityRole
15:32:03,406 DEBUG Binder:462 - Mapped property: entity -> my_ent_id, type: po_db2.hibernate.Entity
15:32:03,421 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\PoNew.hbm.xml
15:32:03,484 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:03,484 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:03,562 INFO Binder:229 - Mapping class: po_db2.hibernate.PoNew -> po_new
15:32:03,562 DEBUG Binder:462 - Mapped property: dbId -> db_id, type: integer
15:32:03,562 DEBUG Binder:462 - Mapped property: poId -> po_id, type: string
15:32:03,578 DEBUG Binder:462 - Mapped property: poNum -> po_num, type: string
15:32:03,578 DEBUG Binder:462 - Mapped property: subVendorId -> sub_vendor_id, type: string
15:32:03,578 DEBUG Binder:462 - Mapped property: projectId -> project_id, type: string
15:32:03,578 DEBUG Binder:462 - Mapped property: vendorRef -> vendor_ref, type: string
15:32:03,578 DEBUG Binder:462 - Mapped property: closedDate -> closed_date, type: date
15:32:03,578 DEBUG Binder:462 - Mapped property: poSuffix -> po_suffix, type: string
15:32:03,578 DEBUG Binder:462 - Mapped property: whoCreated -> who_created, type: string
15:32:03,578 DEBUG Binder:462 - Mapped property: whenCreated -> when_created, type: timestamp
15:32:03,578 DEBUG Binder:462 - Mapped property: whoModified -> who_modified, type: string
15:32:03,578 DEBUG Binder:462 - Mapped property: whenModified -> when_modified, type: timestamp
15:32:03,578 DEBUG Binder:462 - Mapped property: poDate -> po_date, type: date
15:32:03,578 DEBUG Binder:462 - Mapped property: orderedByRef -> ordered_by_ref, type: string
15:32:03,578 DEBUG Binder:462 - Mapped property: remarks -> remarks, type: string
15:32:03,578 DEBUG Binder:462 - Mapped property: entity -> ordered_by_id, type: po_db2.hibernate.Entity
15:32:03,593 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\AsnMessage.hbm.xml
15:32:03,671 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:03,671 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:03,718 INFO Binder:229 - Mapping class: po_db2.hibernate.AsnMessage -> asn_message
15:32:03,718 DEBUG Binder:462 - Mapped property: dbId -> db_id, type: integer
15:32:03,718 DEBUG Binder:462 - Mapped property: asnId -> asn_id, type: string
15:32:03,718 DEBUG Binder:462 - Mapped property: asnNum -> asn_num, type: string
15:32:03,718 DEBUG Binder:462 - Mapped property: bookingNum -> booking_num, type: string
15:32:03,718 DEBUG Binder:462 - Mapped property: refNum -> ref_num, type: string
15:32:03,718 DEBUG Binder:462 - Mapped property: date -> date, type: date
15:32:03,718 DEBUG Binder:462 - Mapped property: whenModified -> when_modified, type: timestamp
15:32:03,718 DEBUG Binder:462 - Mapped property: whoModified -> who_modified, type: string
15:32:03,718 DEBUG Binder:462 - Mapped property: poItemOrdereds, type: java.util.Set
15:32:03,734 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\ReportRdv.hbm.xml
15:32:03,796 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:03,812 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:03,937 INFO Binder:229 - Mapping class: po_db2.hibernate.ReportRdv -> report_rdv
15:32:03,937 DEBUG Binder:462 - Mapped property: dbId -> db_id, type: integer
15:32:03,937 DEBUG Binder:462 - Mapped property: reportId -> report_id, type: string
15:32:03,937 DEBUG Binder:462 - Mapped property: tableName -> table_name, type: string
15:32:03,937 DEBUG Binder:462 - Mapped property: roleId -> role_id, type: string
15:32:03,937 DEBUG Binder:462 - Mapped property: rule -> rule, type: string
15:32:03,937 DEBUG Binder:462 - Mapped property: whoModified -> who_modified, type: string
15:32:03,937 DEBUG Binder:462 - Mapped property: whenModified -> when_modified, type: timestamp
15:32:03,953 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\PoItemOrdered.hbm.xml
15:32:04,015 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:04,031 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:04,109 INFO Binder:229 - Mapping class: po_db2.hibernate.PoItemOrdered -> po_item_ordered
15:32:04,109 DEBUG Binder:462 - Mapped property: dbId -> db_id, type: integer
15:32:04,109 DEBUG Binder:462 - Mapped property: poNum -> po_num, type: string
15:32:04,109 DEBUG Binder:462 - Mapped property: deliverToRef -> deliver_to_ref, type: string
15:32:04,109 DEBUG Binder:462 - Mapped property: lineNum -> line_num, type: integer
15:32:04,109 DEBUG Binder:462 - Mapped property: poSuffix -> po_suffix, type: string
15:32:04,109 DEBUG Binder:462 - Mapped property: quantityOrdered -> quantity_ordered, type: big_decimal
15:32:04,109 DEBUG Binder:462 - Mapped property: quantityShipped -> quantity_shipped, type: big_decimal
15:32:04,109 DEBUG Binder:462 - Mapped property: shpDt -> shp_dt, type: date
15:32:04,109 DEBUG Binder:462 - Mapped property: hbNum -> hb_num, type: string
15:32:04,109 DEBUG Binder:462 - Mapped property: shipmentId -> shipment_id, type: string
15:32:04,109 DEBUG Binder:462 - Mapped property: deliverBy -> deliver_by, type: date
15:32:04,109 DEBUG Binder:462 - Mapped property: latestShpDt -> latest_shp_dt, type: date
15:32:04,109 DEBUG Binder:462 - Mapped property: earliestShpDt -> earliest_shp_dt, type: date
15:32:04,109 DEBUG Binder:462 - Mapped property: whoCreated -> who_created, type: string
15:32:04,109 DEBUG Binder:462 - Mapped property: whenModified -> when_modified, type: timestamp
15:32:04,109 DEBUG Binder:462 - Mapped property: whoModified -> who_modified, type: string
15:32:04,109 DEBUG Binder:462 - Mapped property: whenCreated -> when_created, type: timestamp
15:32:04,125 DEBUG Binder:462 - Mapped property: unitPrice -> unit_price, type: string
15:32:04,125 DEBUG Binder:462 - Mapped property: unitPriceCurrency -> unit_price_currency, type: string
15:32:04,125 DEBUG Binder:462 - Mapped property: deliverToDepartment -> deliver_to_department, type: string
15:32:04,125 DEBUG Binder:462 - Mapped property: containerNum -> container_num, type: string
15:32:04,156 DEBUG Binder:462 - Mapped property: poItem -> item_id, type: po_db2.hibernate.PoItem
15:32:04,156 DEBUG Binder:462 - Mapped property: entity -> ordered_by_id, type: po_db2.hibernate.Entity
15:32:04,156 DEBUG Binder:462 - Mapped property: poNew -> po_id, type: po_db2.hibernate.PoNew
15:32:04,156 DEBUG Binder:462 - Mapped property: asnMessage -> asn_id, type: po_db2.hibernate.AsnMessage
15:32:04,171 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\PoItemNum.hbm.xml
15:32:04,234 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:04,265 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:04,281 INFO Binder:229 - Mapping class: po_db2.hibernate.PoItemNum -> po_item_num
15:32:04,281 DEBUG Binder:462 - Mapped property: itemNum -> item_num, type: string
15:32:04,281 DEBUG Binder:462 - Mapped property: whoCreated -> who_created, type: string
15:32:04,281 DEBUG Binder:462 - Mapped property: whenCreated -> when_created, type: timestamp
15:32:04,281 DEBUG Binder:462 - Mapped property: whoModified -> who_modified, type: string
15:32:04,281 DEBUG Binder:462 - Mapped property: whenModified -> when_modified, type: timestamp
15:32:04,968 DEBUG Binder:462 - Mapped property: poItem -> item_id, type: po_db2.hibernate.PoItem
15:32:04,968 DEBUG Binder:462 - Mapped property: entity -> item_ref_ent_id, type: po_db2.hibernate.Entity
15:32:04,968 INFO Configuration:185 - Mapping file: U:\projects\mg2\bin\po_db2\hibernate\Permission.hbm.xml
15:32:04,984 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
15:32:04,984 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
15:32:05,015 INFO Binder:229 - Mapping class: po_db2.hibernate.Permission -> permission
15:32:05,015 DEBUG Binder:462 - Mapped property: permissionId -> permission_id, type: string
15:32:05,015 DEBUG Binder:462 - Mapped property: description -> description, type: string
configured, building session factory
15:32:05,015 INFO Configuration:595 - processing one-to-many association mappings
15:32:05,015 DEBUG Binder:1326 - Second pass for collection: po_db2.hibernate.PoItem.poItemNums
15:32:05,015 INFO Binder:1154 - Mapping collection: po_db2.hibernate.PoItem.poItemNums -> po_item_num
15:32:05,015 DEBUG Binder:1341 - Mapped collection key: item_id, one-to-many: po_db2.hibernate.PoItemNum
15:32:05,015 DEBUG Binder:1326 - Second pass for collection: po_db2.hibernate.PoItem.poItemOrdereds
15:32:05,015 INFO Binder:1154 - Mapping collection: po_db2.hibernate.PoItem.poItemOrdereds -> po_item_ordered
15:32:05,015 DEBUG Binder:1341 - Mapped collection key: item_id, one-to-many: po_db2.hibernate.PoItemOrdered
15:32:05,015 DEBUG Binder:1326 - Second pass for collection: po_db2.hibernate.Entity.poItemNums
15:32:05,015 INFO Binder:1154 - Mapping collection: po_db2.hibernate.Entity.poItemNums -> po_item_num
15:32:05,015 DEBUG Binder:1341 - Mapped collection key: item_ref_ent_id, one-to-many: po_db2.hibernate.PoItemNum
15:32:05,015 DEBUG Binder:1326 - Second pass for collection: po_db2.hibernate.Entity.entities
15:32:05,015 INFO Binder:1154 - Mapping collection: po_db2.hibernate.Entity.entities -> entity
15:32:05,031 DEBUG Binder:1341 - Mapped collection key: item_ref_ent_id, one-to-many: po_db2.hibernate.Entity
15:32:05,031 DEBUG Binder:1326 - Second pass for collection: po_db2.hibernate.Entity.entityNums
15:32:05,031 INFO Binder:1154 - Mapping collection: po_db2.hibernate.Entity.entityNums -> entity_num
15:32:05,031 DEBUG Binder:1341 - Mapped collection key: p_ent_id, one-to-many: po_db2.hibernate.EntityNum
15:32:05,031 DEBUG Binder:1326 - Second pass for collection: po_db2.hibernate.Entity.poItemOrdereds
15:32:05,031 INFO Binder:1154 - Mapping collection: po_db2.hibernate.Entity.poItemOrdereds -> po_item_ordered
15:32:05,031 DEBUG Binder:1341 - Mapped collection key: ordered_by_id, one-to-many: po_db2.hibernate.PoItemOrdered
15:32:05,031 DEBUG Binder:1326 - Second pass for collection: po_db2.hibernate.Entity.itemsToBeDelivered
15:32:05,031 INFO Binder:1154 - Mapping collection: po_db2.hibernate.Entity.itemsToBeDelivered -> po_item_ordered
15:32:05,031 DEBUG Binder:1341 - Mapped collection key: deliver_to_id, one-to-many: po_db2.hibernate.PoItemOrdered
15:32:05,031 DEBUG Binder:1326 - Second pass for collection: po_db2.hibernate.Entity.orderedPOs
15:32:05,031 INFO Binder:1154 - Mapping collection: po_db2.hibernate.Entity.orderedPOs -> po_new
15:32:05,031 DEBUG Binder:1341 - Mapped collection key: ordered_by_id, one-to-many: po_db2.hibernate.PoNew
15:32:05,031 DEBUG Binder:1326 - Second pass for collection: po_db2.hibernate.Entity.sellingPOs
15:32:05,031 INFO Binder:1154 - Mapping collection: po_db2.hibernate.Entity.sellingPOs -> po_new
15:32:05,031 DEBUG Binder:1341 - Mapped collection key: vendor_id, one-to-many: po_db2.hibernate.PoNew
15:32:05,031 DEBUG Binder:1326 - Second pass for collection: po_db2.hibernate.EntityRole.entityNums
15:32:05,031 INFO Binder:1154 - Mapping collection: po_db2.hibernate.EntityRole.entityNums -> entity_num
15:32:05,031 DEBUG Binder:1341 - Mapped collection key: p_ent_role, one-to-many: po_db2.hibernate.EntityNum
15:32:05,031 DEBUG Binder:1326 - Second pass for collection: po_db2.hibernate.AsnMessage.poItemOrdereds
15:32:05,031 INFO Binder:1154 - Mapping collection: po_db2.hibernate.AsnMessage.poItemOrdereds -> po_item_ordered
15:32:05,031 DEBUG Binder:1341 - Mapped collection key: asn_id, one-to-many: po_db2.hibernate.PoItemOrdered
15:32:05,031 INFO Configuration:604 - processing one-to-one association property references
15:32:05,046 INFO Configuration:629 - processing foreign key constraints
15:32:05,046 DEBUG Configuration:639 - resolving reference to class: po_db2.hibernate.Entity
15:32:05,046 DEBUG Configuration:639 - resolving reference to class: po_db2.hibernate.PoItem
15:32:05,046 DEBUG Configuration:639 - resolving reference to class: po_db2.hibernate.Entity
15:32:05,046 DEBUG Configuration:639 - resolving reference to class: po_db2.hibernate.Entity
15:32:05,046 DEBUG Configuration:639 - resolving reference to class: po_db2.hibernate.EntityRole
15:32:05,046 DEBUG Configuration:639 - resolving reference to class: po_db2.hibernate.Entity
15:32:05,046 DEBUG Configuration:639 - resolving reference to class: po_db2.hibernate.AsnMessage
15:32:05,125 INFO Dialect:82 - Using dialect: net.sf.hibernate.dialect.MySQLDialect
15:32:05,125 INFO SettingsFactory:58 - Maximim outer join fetch depth: 0
15:32:05,125 INFO SettingsFactory:62 - Use outer join fetching: false
15:32:05,140 INFO DriverManagerConnectionProvider:41 - Using Hibernate built-in connection pool (not for production use!)
15:32:05,140 INFO DriverManagerConnectionProvider:42 - Hibernate connection pool size: 1
15:32:05,234 INFO DriverManagerConnectionProvider:71 - using driver: org.gjt.mm.mysql.Driver at URL: jdbc:mysql://204.1.213.186:3306/po_db2
15:32:05,234 INFO DriverManagerConnectionProvider:72 - connection properties: {user=root, password=}
15:32:05,265 INFO TransactionManagerLookupFactory:33 - No TransactionManagerLookup configured (in JTA environment, use of process level read-write cache is not recommended)
15:32:05,265 DEBUG DriverManagerConnectionProvider:78 - total checked-out connections: 0
15:32:05,265 DEBUG DriverManagerConnectionProvider:94 - opening new JDBC connection
15:32:05,750 DEBUG DriverManagerConnectionProvider:100 - created connection to: jdbc:mysql://204.1.213.186:3306/po_db2, Isolation Level: 4
15:32:05,750 DEBUG DriverManagerConnectionProvider:114 - returning connection to pool, pool size: 1
15:32:05,750 INFO SettingsFactory:102 - Use scrollable result sets: true
15:32:05,750 INFO SettingsFactory:105 - Use JDBC3 getGeneratedKeys(): true
15:32:05,765 INFO SettingsFactory:108 - Optimize cache for minimal puts: false
15:32:05,765 INFO SettingsFactory:114 - echoing all SQL to stdout
15:32:05,765 INFO SettingsFactory:117 - Query language substitutions: {no='N', true=1, yes='Y', false=0}
15:32:05,765 INFO SettingsFactory:128 - cache provider: net.sf.hibernate.cache.HashtableCacheProvider
15:32:05,765 INFO Configuration:1080 - instantiating and configuring caches
15:32:05,859 INFO SessionFactoryImpl:119 - building session factory
15:32:05,859 DEBUG SessionFactoryImpl:125 - instantiating session factory with properties: {java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, hibernate.connection.password=, hibernate.cache.provider_class=net.sf.hibernate.cache.HashtableCacheProvider, sun.boot.library.path=C:\Program Files\Java\j2re1.4.2_03\bin, java.vm.version=1.4.2_03-b02, hibernate.proxool.pool_alias=pool1, hibernate.connection.username=root, java.vm.vendor=Sun Microsystems Inc., java.vendor.url=http://java.sun.com/, path.separator=;, hibernate.cache.use_query_cache=true, java.vm.name=Java HotSpot(TM) Client VM, file.encoding.pkg=sun.io, user.country=US, sun.os.patch.level=Service Pack 1, java.vm.specification.name=Java Virtual Machine Specification, user.dir=U:\projects\mg2, java.runtime.version=1.4.2_03-b02, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.endorsed.dirs=C:\Program Files\Java\j2re1.4.2_03\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\rtayek\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows XP, sun.java2d.fontpath=, java.library.path=C:\Program Files\Java\j2re1.4.2_03\bin;.;C:\WINDOWS\System32;C:\WINDOWS;u:\bin, java.specification.name=Java Platform API Specification, java.class.version=48.0, hibernate.connection.pool_size=1, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, os.version=5.1, user.home=C:\Documents and Settings\rtayek, user.timezone=America/Los_Angeles, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=Cp1252, java.specification.version=1.4, hibernate.connection.driver_class=org.gjt.mm.mysql.Driver, java.class.path=U:\projects\mg2\bin;U:\projects\mg2\lib\hibernate2.jar;U:\projects\mg2\lib\dom4j-1.4.jar;U:\projects\mg2\lib\commons-logging-1.0.3.jar;U:\projects\mg2\lib\commons-collections-2.1.jar;U:\projects\mg2\lib\mysql.jar;U:\projects\mg2\lib\commons-lang-1.0.1.jar;U:\projects\mg2\lib\cglib-2.0-rc2.jar;U:\projects\mg2\lib\jta.jar;U:\projects\mg2\lib\log4j-1.2.8.jar;C:\Program Files\Development\eclipse\plugins\org.junit_3.8.1\junit.jar;U:\projects\mg2\lib\odmg-3.0.jar, user.name=rtayek, hibernate.query.substitutions=true 1, false 0, yes 'Y', no 'N', hibernate.show_sql=true, java.vm.specification.version=1.0, java.home=C:\Program Files\Java\j2re1.4.2_03, sun.arch.data.model=32, hibernate.connection.url=jdbc:mysql://204.1.213.186:3306/po_db2, hibernate.dialect=net.sf.hibernate.dialect.MySQLDialect, 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, hibernate.jdbc.use_streams_for_binary=true, java.version=1.4.2_03, java.ext.dirs=C:\Program Files\Java\j2re1.4.2_03\lib\ext, sun.boot.class.path=C:\Program Files\Java\j2re1.4.2_03\lib\rt.jar;C:\Program Files\Java\j2re1.4.2_03\lib\i18n.jar;C:\Program Files\Java\j2re1.4.2_03\lib\sunrsasign.jar;C:\Program Files\Java\j2re1.4.2_03\lib\jsse.jar;C:\Program Files\Java\j2re1.4.2_03\lib\jce.jar;C:\Program Files\Java\j2re1.4.2_03\lib\charsets.jar;C:\Program Files\Java\j2re1.4.2_03\classes, java.vendor=Sun Microsystems Inc., hibernate.jdbc.batch_size=0, file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, hibernate.use_outer_join=false, hibernate.max_fetch_depth=0, sun.cpu.isalist=pentium i486 i386}
15:32:07,609 DEBUG SessionFactoryObjectFactory:39 - initializing class SessionFactoryObjectFactory
15:32:07,625 DEBUG SessionFactoryObjectFactory:76 - registered: 4c815534fc6be4f500fc6be4fcb90000 (unnamed)
15:32:07,625 INFO SessionFactoryObjectFactory:82 - no JNDI name configured
15:32:07,625 DEBUG SessionFactoryImpl:196 - instantiated session factory
15:32:07,640 INFO UpdateTimestampsCache:35 - starting update timestamps cache at region: net.sf.hibernate.cache.UpdateTimestampsCache
15:32:07,640 INFO QueryCache:39 - starting query cache at region: net.sf.hibernate.cache.QueryCache
session factory constructed
main constructed
start querying db
open session
15:32:07,937 DEBUG SessionImpl:531 - opened session
begin transaction
15:32:07,953 DEBUG JDBCTransaction:37 - begin
15:32:07,953 DEBUG DriverManagerConnectionProvider:78 - total checked-out connections: 0
15:32:07,953 DEBUG DriverManagerConnectionProvider:84 - using pooled JDBC connection, pool size: 0
15:32:07,953 DEBUG JDBCTransaction:41 - current autocommit status:false
got 3 po's
15:32:07,968 DEBUG SessionImpl:1950 - loading [po_db2.hibernate.PoNew#1152]
15:32:07,968 DEBUG SessionImpl:2047 - attempting to resolve [po_db2.hibernate.PoNew#1152]
15:32:07,968 DEBUG SessionImpl:2080 - object not resolved in any cache [po_db2.hibernate.PoNew#1152]
15:32:07,968 DEBUG EntityPersister:416 - Materializing entity: [po_db2.hibernate.PoNew#1152]
15:32:07,984 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
Hibernate: select ponew0_.db_id as db_id0_, ponew0_.po_id as po_id0_, ponew0_.po_num as po_num0_, ponew0_.sub_vendor_id as sub_vend4_0_, ponew0_.project_id as project_id0_, ponew0_.vendor_ref as vendor_ref0_, ponew0_.closed_date as closed_d7_0_, ponew0_.po_suffix as po_suffix0_, ponew0_.who_created as who_crea9_0_, ponew0_.when_created as when_cr10_0_, ponew0_.who_modified as who_mod11_0_, ponew0_.when_modified as when_mo12_0_, ponew0_.po_date as po_date0_, ponew0_.ordered_by_ref as ordered14_0_, ponew0_.remarks as remarks0_, ponew0_.ordered_by_id as ordered16_0_ from po_new ponew0_ where ponew0_.db_id=?
15:32:07,984 DEBUG BatcherImpl:241 - preparing statement
15:32:08,015 DEBUG IntegerType:46 - binding '1152' to parameter: 1
15:32:08,015 DEBUG Loader:197 - processing result set
15:32:08,015 DEBUG Loader:405 - result row: 1152
15:32:08,015 DEBUG Loader:536 - Initializing object from ResultSet: 1152
15:32:08,031 DEBUG Loader:605 - Hydrating entity: po_db2.hibernate.PoNew#1152
15:32:08,046 DEBUG StringType:68 - returning 'po3158' as column: po_id0_
15:32:08,046 DEBUG StringType:68 - returning '520996' as column: po_num0_
15:32:08,046 DEBUG StringType:68 - returning '' as column: sub_vend4_0_
15:32:08,046 DEBUG StringType:68 - returning '' as column: project_id0_
15:32:08,046 DEBUG StringType:68 - returning '' as column: vendor_ref0_
15:32:08,046 DEBUG DateType:64 - returning null as column: closed_d7_0_
15:32:08,046 DEBUG StringType:68 - returning '' as column: po_suffix0_
15:32:08,046 DEBUG StringType:68 - returning 'Remington' as column: who_crea9_0_
15:32:08,093 DEBUG TimestampType:68 - returning '16 October 2003 18:23:26' as column: when_cr10_0_
15:32:08,093 DEBUG StringType:64 - returning null as column: who_mod11_0_
15:32:08,093 DEBUG TimestampType:68 - returning '16 October 2003 18:23:26' as column: when_mo12_0_
15:32:08,093 DEBUG DateType:68 - returning '16 October 2003' as column: po_date0_
15:32:08,093 DEBUG StringType:68 - returning '' as column: ordered14_0_
15:32:08,093 DEBUG StringType:68 - returning '' as column: remarks0_
15:32:08,093 DEBUG IntegerType:68 - returning '1' as column: ordered16_0_
15:32:08,109 DEBUG Loader:226 - done processing result set (1 rows)
15:32:08,109 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
15:32:08,109 DEBUG BatcherImpl:261 - closing statement
15:32:08,109 DEBUG Loader:239 - total objects hydrated: 1
15:32:08,109 DEBUG SessionImpl:2166 - resolving associations for [po_db2.hibernate.PoNew#1152]
15:32:08,109 DEBUG SessionImpl:1950 - loading [po_db2.hibernate.Entity#1]
15:32:08,109 DEBUG SessionImpl:2190 - done materializing entity [po_db2.hibernate.PoNew#1152]
15:32:08,109 DEBUG SessionImpl:3082 - initializing non-lazy collections
found one of mark's
key=1152
po=po_db2.hibernate.PoNew@11946c2[dbId=1152], poid=po3158
finding
15:32:08,281 DEBUG SessionImpl:1497 - find: select from PoItemOrdered as ordered where ordered.poNew='po3158'
15:32:08,312 DEBUG QueryTranslator:147 - compiling query
15:32:08,390 DEBUG SessionImpl:2210 - flushing session
15:32:08,406 DEBUG SessionImpl:2403 - Flushing entities and processing referenced collections
15:32:08,406 DEBUG SessionImpl:2746 - Processing unreferenced collections
15:32:08,406 DEBUG SessionImpl:2760 - Scheduling collection removes/(re)creates/updates
15:32:08,406 DEBUG SessionImpl:2234 - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
15:32:08,406 DEBUG SessionImpl:2239 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
15:32:08,406 DEBUG Printer:75 - listing entities:
15:32:08,421 DEBUG Printer:82 - po_db2.hibernate.PoNew{whenCreated=16 October 2003 18:23:26, remarks=, entity=Entity#1, orderedByRef=, whenModified=16 October 2003 18:23:26, dbId=1152, closedDate=null, whoCreated=Remington, poDate=16 October 2003, projectId=, poSuffix=, poNum=520996, subVendorId=, whoModified=null, poId=po3158, vendorRef=}
15:32:08,421 DEBUG SessionImpl:1782 - Dont need to execute flush
15:32:08,421 DEBUG QueryTranslator:199 - HQL: select from po_db2.hibernate.PoItemOrdered as ordered where ordered.poNew='po3158'
15:32:08,421 DEBUG QueryTranslator:200 - SQL: select poitemorde0_.db_id as db_id, poitemorde0_.po_num as po_num, poitemorde0_.deliver_to_ref as deliver_3_, poitemorde0_.line_num as line_num, poitemorde0_.po_suffix as po_suffix, poitemorde0_.quantity_ordered as quantity6_, poitemorde0_.quantity_shipped as quantity7_, poitemorde0_.shp_dt as shp_dt, poitemorde0_.hb_num as hb_num, poitemorde0_.shipment_id as shipmen10_, poitemorde0_.deliver_by as deliver_by, poitemorde0_.latest_shp_dt as latest_12_, poitemorde0_.earliest_shp_dt as earlies13_, poitemorde0_.who_created as who_cre14_, poitemorde0_.when_modified as when_mo15_, poitemorde0_.who_modified as who_mod16_, poitemorde0_.when_created as when_cr17_, poitemorde0_.unit_price as unit_price, poitemorde0_.unit_price_currency as unit_pr19_, poitemorde0_.deliver_to_department as deliver20_, poitemorde0_.container_num as contain21_, poitemorde0_.item_id as item_id, poitemorde0_.ordered_by_id as ordered23_, poitemorde0_.po_id as po_id, poitemorde0_.asn_id as asn_id from po_item_ordered poitemorde0_ where (poitemorde0_.po_id='po3158' )
15:32:08,421 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
Hibernate: select poitemorde0_.db_id as db_id, poitemorde0_.po_num as po_num, poitemorde0_.deliver_to_ref as deliver_3_, poitemorde0_.line_num as line_num, poitemorde0_.po_suffix as po_suffix, poitemorde0_.quantity_ordered as quantity6_, poitemorde0_.quantity_shipped as quantity7_, poitemorde0_.shp_dt as shp_dt, poitemorde0_.hb_num as hb_num, poitemorde0_.shipment_id as shipmen10_, poitemorde0_.deliver_by as deliver_by, poitemorde0_.latest_shp_dt as latest_12_, poitemorde0_.earliest_shp_dt as earlies13_, poitemorde0_.who_created as who_cre14_, poitemorde0_.when_modified as when_mo15_, poitemorde0_.who_modified as who_mod16_, poitemorde0_.when_created as when_cr17_, poitemorde0_.unit_price as unit_price, poitemorde0_.unit_price_currency as unit_pr19_, poitemorde0_.deliver_to_department as deliver20_, poitemorde0_.container_num as contain21_, poitemorde0_.item_id as item_id, poitemorde0_.ordered_by_id as ordered23_, poitemorde0_.po_id as po_id, poitemorde0_.asn_id as asn_id from po_item_ordered poitemorde0_ where (poitemorde0_.po_id='po3158' )
15:32:08,421 DEBUG BatcherImpl:241 - preparing statement
15:32:08,421 DEBUG Loader:197 - processing result set
15:32:08,421 DEBUG IntegerType:68 - returning '7431' as column: db_id
15:32:08,421 DEBUG Loader:405 - result row: 7431
15:32:08,421 DEBUG Loader:536 - Initializing object from ResultSet: 7431
15:32:08,421 DEBUG Loader:605 - Hydrating entity: po_db2.hibernate.PoItemOrdered#7431
15:32:08,437 DEBUG StringType:68 - returning '521453' as column: po_num
15:32:08,437 DEBUG StringType:68 - returning '' as column: deliver_3_
15:32:08,437 DEBUG IntegerType:68 - returning '1' as column: line_num
15:32:08,437 DEBUG StringType:68 - returning '' as column: po_suffix
15:32:08,437 DEBUG BigDecimalType:68 - returning '5004.0000' as column: quantity6_
15:32:08,437 DEBUG BigDecimalType:68 - returning '0.0000' as column: quantity7_
15:32:08,437 DEBUG DateType:64 - returning null as column: shp_dt
15:32:08,437 DEBUG StringType:68 - returning '' as column: hb_num
15:32:08,437 DEBUG StringType:68 - returning '' as column: shipmen10_
15:32:08,437 DEBUG DateType:68 - returning '15 June 2004' as column: deliver_by
15:32:08,437 DEBUG DateType:64 - returning null as column: latest_12_
15:32:08,437 DEBUG DateType:64 - returning null as column: earlies13_
15:32:08,437 DEBUG StringType:68 - returning 'X12Remingt' as column: who_cre14_
15:32:08,437 DEBUG TimestampType:68 - returning '18 December 2003 00:22:03' as column: when_mo15_
15:32:08,437 DEBUG StringType:64 - returning null as column: who_mod16_
15:32:08,453 DEBUG TimestampType:68 - returning '18 December 2003 00:22:03' as column: when_cr17_
15:32:08,453 DEBUG StringType:68 - returning '' as column: unit_price
15:32:08,453 DEBUG StringType:68 - returning '' as column: unit_pr19_
15:32:08,453 DEBUG StringType:68 - returning '' as column: deliver20_
15:32:08,453 DEBUG StringType:68 - returning '' as column: contain21_
15:32:08,453 DEBUG StringType:68 - returning 'i3527' as column: item_id
15:32:08,453 DEBUG StringType:68 - returning '1.92947' as column: ordered23_
15:32:08,453 DEBUG StringType:68 - returning 'po3158' as column: po_id
15:32:08,453 DEBUG StringType:68 - returning '' as column: asn_id
15:32:08,453 DEBUG Loader:226 - done processing result set (1 rows)
15:32:08,453 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
15:32:08,453 DEBUG BatcherImpl:261 - closing statement
15:32:08,453 DEBUG Loader:239 - total objects hydrated: 1
15:32:08,453 DEBUG SessionImpl:2166 - resolving associations for [po_db2.hibernate.PoItemOrdered#7431]
15:32:08,453 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
Hibernate: select poitem0_.db_id as db_id0_, poitem0_.item_id as item_id0_, poitem0_.item_name as item_name0_, poitem0_.weight_gross_unit as weight_g4_0_, poitem0_.weight_gross as weight_g5_0_, poitem0_.weight_net_unit as weight_n6_0_, poitem0_.weight_net as weight_net0_, poitem0_.volume_unit as volume_u8_0_, poitem0_.volume as volume0_, poitem0_.sku as sku0_, poitem0_.upc as upc0_, poitem0_.quantity_unit as quantit12_0_, poitem0_.quantity as quantity0_, poitem0_.brand as brand0_, poitem0_.description as descrip15_0_, poitem0_.who_created as who_cre16_0_, poitem0_.when_created as when_cr17_0_, poitem0_.who_modified as who_mod18_0_, poitem0_.when_modified as when_mo19_0_ from po_item poitem0_ where poitem0_.item_id=?
15:32:08,453 DEBUG BatcherImpl:241 - preparing statement
15:32:08,468 DEBUG StringType:46 - binding 'i3527' to parameter: 1
15:32:08,484 DEBUG Loader:197 - processing result set
15:32:08,484 DEBUG IntegerType:68 - returning '3552' as column: db_id0_
15:32:08,484 DEBUG Loader:405 - result row: 3552
15:32:08,484 DEBUG Loader:536 - Initializing object from ResultSet: 3552
15:32:08,484 DEBUG Loader:605 - Hydrating entity: po_db2.hibernate.PoItem#3552
15:32:08,484 DEBUG StringType:68 - returning 'i3527' as column: item_id0_
15:32:08,484 DEBUG StringType:68 - returning 'HC-822BP' as column: item_name0_
15:32:08,484 DEBUG StringType:68 - returning '' as column: weight_g4_0_
15:32:08,484 DEBUG BigDecimalType:68 - returning '0.00' as column: weight_g5_0_
15:32:08,484 DEBUG StringType:68 - returning '' as column: weight_n6_0_
15:32:08,484 DEBUG BigDecimalType:68 - returning '0.00' as column: weight_net0_
15:32:08,484 DEBUG StringType:68 - returning '' as column: volume_u8_0_
15:32:08,484 DEBUG BigDecimalType:68 - returning '0.00' as column: volume0_
15:32:08,484 DEBUG StringType:68 - returning '' as column: sku0_
15:32:08,484 DEBUG StringType:64 - returning null as column: upc0_
15:32:08,500 DEBUG StringType:68 - returning 'EA' as column: quantit12_0_
15:32:08,500 DEBUG BigDecimalType:68 - returning '1.00' as column: quantity0_
15:32:08,500 DEBUG StringType:68 - returning '' as column: brand0_
15:32:08,500 DEBUG StringType:68 - returning '' as column: descrip15_0_
15:32:08,500 DEBUG StringType:68 - returning 'X12Remingt' as column: who_cre16_0_
15:32:08,500 DEBUG TimestampType:68 - returning '18 December 2003 00:22:02' as column: when_cr17_0_
15:32:08,500 DEBUG StringType:64 - returning null as column: who_mod18_0_
15:32:08,500 DEBUG TimestampType:68 - returning '18 December 2003 00:22:02' as column: when_mo19_0_
15:32:08,500 DEBUG Loader:226 - done processing result set (1 rows)
15:32:08,500 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
15:32:08,500 DEBUG BatcherImpl:261 - closing statement
15:32:08,500 DEBUG Loader:239 - total objects hydrated: 1
15:32:08,500 DEBUG SessionImpl:2166 - resolving associations for [po_db2.hibernate.PoItem#3552]
15:32:08,515 DEBUG SessionImpl:3891 - creating collection wrapper:[po_db2.hibernate.PoItem.poItemNums#3552]
15:32:08,593 DEBUG SessionImpl:3891 - creating collection wrapper:[po_db2.hibernate.PoItem.poItemOrdereds#3552]
15:32:08,593 DEBUG SessionImpl:2190 - done materializing entity [po_db2.hibernate.PoItem#3552]
15:32:08,593 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
Hibernate: select entity0_.db_id as db_id0_, entity0_.entity_id as entity_id0_, entity0_.entity_type as entity_t3_0_, entity0_.limit_ordered_by_id as limit_or4_0_, entity0_.limit_billto_num as limit_bi5_0_, entity0_.limit_csg_num as limit_cs6_0_, entity0_.limit_shp_num as limit_sh7_0_, entity0_.limit_agent_num as limit_ag8_0_, entity0_.entity_name as entity_n9_0_, entity0_.contact as contact0_, entity0_.add1 as add10_, entity0_.add2 as add20_, entity0_.phone as phone0_, entity0_.fax as fax0_, entity0_.email as email0_, entity0_.city as city0_, entity0_.state as state0_, entity0_.zip as zip0_, entity0_.country as country0_, entity0_.who_modified as who_mod20_0_, entity0_.when_modified as when_mo21_0_, entity0_.who_created as who_cre22_0_, entity0_.when_created as when_cr23_0_, entity0_.item_ref_ent_id as item_re24_0_ from entity entity0_ where entity0_.entity_id=?
15:32:08,593 DEBUG BatcherImpl:241 - preparing statement
15:32:08,593 DEBUG StringType:46 - binding '1.92947' to parameter: 1
15:32:08,609 DEBUG Loader:197 - processing result set
15:32:08,609 DEBUG IntegerType:68 - returning '1' as column: db_id0_
15:32:08,609 DEBUG Loader:405 - result row: 1
15:32:08,609 DEBUG Loader:536 - Initializing object from ResultSet: 1
15:32:08,609 DEBUG Loader:605 - Hydrating entity: po_db2.hibernate.Entity#1
15:32:08,609 DEBUG StringType:68 - returning '1.92947' as column: entity_id0_
15:32:08,609 DEBUG StringType:68 - returning 'buyer' as column: entity_t3_0_
15:32:08,609 DEBUG StringType:68 - returning '' as column: limit_or4_0_
15:32:08,609 DEBUG StringType:68 - returning '' as column: limit_bi5_0_
15:32:08,609 DEBUG StringType:68 - returning '' as column: limit_cs6_0_
15:32:08,609 DEBUG StringType:68 - returning '' as column: limit_sh7_0_
15:32:08,609 DEBUG StringType:68 - returning '' as column: limit_ag8_0_
15:32:08,609 DEBUG StringType:68 - returning 'Remington Products' as column: entity_n9_0_
15:32:08,609 DEBUG StringType:68 - returning '' as column: contact0_
15:32:08,609 DEBUG StringType:68 - returning '' as column: add10_
15:32:08,609 DEBUG StringType:68 - returning '' as column: add20_
15:32:08,625 DEBUG StringType:68 - returning '' as column: phone0_
15:32:08,625 DEBUG StringType:68 - returning '' as column: fax0_
15:32:08,625 DEBUG StringType:68 - returning '' as column: email0_
15:32:08,625 DEBUG StringType:68 - returning '' as column: city0_
15:32:08,625 DEBUG StringType:68 - returning '' as column: state0_
15:32:08,625 DEBUG StringType:68 - returning '' as column: zip0_
15:32:08,625 DEBUG StringType:68 - returning '' as column: country0_
15:32:08,625 DEBUG StringType:68 - returning '' as column: who_mod20_0_
15:32:08,625 DEBUG TimestampType:68 - returning '10 October 2003 13:47:00' as column: when_mo21_0_
15:32:08,625 DEBUG StringType:68 - returning '' as column: who_cre22_0_
15:32:08,625 DEBUG TimestampType:64 - returning null as column: when_cr23_0_
15:32:08,625 DEBUG IntegerType:68 - returning '1' as column: item_re24_0_
15:32:08,640 DEBUG Loader:226 - done processing result set (1 rows)
15:32:08,640 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
15:32:08,640 DEBUG BatcherImpl:261 - closing statement
15:32:08,640 DEBUG Loader:239 - total objects hydrated: 1
15:32:08,640 DEBUG SessionImpl:2166 - resolving associations for [po_db2.hibernate.Entity#1]
15:32:08,640 DEBUG SessionImpl:3891 - creating collection wrapper:[po_db2.hibernate.Entity.poItemNums#1]
15:32:08,640 DEBUG SessionImpl:3891 - creating collection wrapper:[po_db2.hibernate.Entity.entities#1]
15:32:08,640 DEBUG SessionImpl:1950 - loading [po_db2.hibernate.Entity#1]
15:32:08,640 DEBUG SessionImpl:2047 - attempting to resolve [po_db2.hibernate.Entity#1]
15:32:08,640 DEBUG SessionImpl:2063 - resolved object in session cache [po_db2.hibernate.Entity#1]
15:32:08,640 DEBUG SessionImpl:3891 - creating collection wrapper:[po_db2.hibernate.Entity.entityNums#1]
15:32:08,640 DEBUG SessionImpl:3891 - creating collection wrapper:[po_db2.hibernate.Entity.poItemOrdereds#1]
15:32:08,640 DEBUG SessionImpl:3891 - creating collection wrapper:[po_db2.hibernate.Entity.itemsToBeDelivered#1]
15:32:08,640 DEBUG SessionImpl:3891 - creating collection wrapper:[po_db2.hibernate.Entity.orderedPOs#1]
15:32:08,640 DEBUG SessionImpl:3891 - creating collection wrapper:[po_db2.hibernate.Entity.sellingPOs#1]
15:32:08,640 DEBUG SessionImpl:2190 - done materializing entity [po_db2.hibernate.Entity#1]
15:32:08,640 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
Hibernate: select ponew0_.db_id as db_id0_, ponew0_.po_id as po_id0_, ponew0_.po_num as po_num0_, ponew0_.sub_vendor_id as sub_vend4_0_, ponew0_.project_id as project_id0_, ponew0_.vendor_ref as vendor_ref0_, ponew0_.closed_date as closed_d7_0_, ponew0_.po_suffix as po_suffix0_, ponew0_.who_created as who_crea9_0_, ponew0_.when_created as when_cr10_0_, ponew0_.who_modified as who_mod11_0_, ponew0_.when_modified as when_mo12_0_, ponew0_.po_date as po_date0_, ponew0_.ordered_by_ref as ordered14_0_, ponew0_.remarks as remarks0_, ponew0_.ordered_by_id as ordered16_0_ from po_new ponew0_ where ponew0_.po_id=?
15:32:08,640 DEBUG BatcherImpl:241 - preparing statement
15:32:08,640 DEBUG StringType:46 - binding 'po3158' to parameter: 1
15:32:08,656 DEBUG Loader:197 - processing result set
15:32:08,656 DEBUG IntegerType:68 - returning '1152' as column: db_id0_
15:32:08,656 DEBUG Loader:405 - result row: 1152
15:32:08,656 DEBUG Loader:226 - done processing result set (1 rows)
15:32:08,656 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
15:32:08,656 DEBUG BatcherImpl:261 - closing statement
15:32:08,656 DEBUG Loader:239 - total objects hydrated: 0
15:32:08,656 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
Hibernate: select asnmessage0_.db_id as db_id0_, asnmessage0_.asn_id as asn_id0_, asnmessage0_.asn_num as asn_num0_, asnmessage0_.booking_num as booking_4_0_, asnmessage0_.ref_num as ref_num0_, asnmessage0_.date as date0_, asnmessage0_.when_modified as when_mod7_0_, asnmessage0_.who_modified as who_modi8_0_ from asn_message asnmessage0_ where asnmessage0_.asn_id=?
15:32:08,656 DEBUG BatcherImpl:241 - preparing statement
15:32:08,656 DEBUG StringType:46 - binding '' to parameter: 1
15:32:08,656 DEBUG Loader:197 - processing result set
15:32:08,656 DEBUG Loader:226 - done processing result set (0 rows)
15:32:08,656 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
15:32:08,671 DEBUG BatcherImpl:261 - closing statement
15:32:08,671 DEBUG Loader:239 - total objects hydrated: 0
15:32:08,671 DEBUG SessionImpl:2190 - done materializing entity [po_db2.hibernate.PoItemOrdered#7431]
15:32:08,671 DEBUG SessionImpl:3082 - initializing non-lazy collections
end of found one of mark's
15:32:08,671 DEBUG JDBCTransaction:59 - commit
15:32:08,671 DEBUG SessionImpl:2210 - flushing session
15:32:08,671 DEBUG SessionImpl:2403 - Flushing entities and processing referenced collections
15:32:08,703 DEBUG SessionImpl:2850 - Collection found: [po_db2.hibernate.PoItem.poItemNums#3552], was: [po_db2.hibernate.PoItem.poItemNums#3552]
15:32:08,703 DEBUG SessionImpl:2850 - Collection found: [po_db2.hibernate.PoItem.poItemOrdereds#3552], was: [po_db2.hibernate.PoItem.poItemOrdereds#3552]
15:32:08,703 DEBUG SessionImpl:2850 - Collection found: [po_db2.hibernate.Entity.poItemNums#1], was: [po_db2.hibernate.Entity.poItemNums#1]
15:32:08,703 DEBUG SessionImpl:2850 - Collection found: [po_db2.hibernate.Entity.entities#1], was: [po_db2.hibernate.Entity.entities#1]
15:32:08,703 DEBUG SessionImpl:2850 - Collection found: [po_db2.hibernate.Entity.entityNums#1], was: [po_db2.hibernate.Entity.entityNums#1]
15:32:08,703 DEBUG SessionImpl:2850 - Collection found: [po_db2.hibernate.Entity.poItemOrdereds#1], was: [po_db2.hibernate.Entity.poItemOrdereds#1]
15:32:08,703 DEBUG SessionImpl:2850 - Collection found: [po_db2.hibernate.Entity.itemsToBeDelivered#1], was: [po_db2.hibernate.Entity.itemsToBeDelivered#1]
15:32:08,703 DEBUG SessionImpl:2850 - Collection found: [po_db2.hibernate.Entity.orderedPOs#1], was: [po_db2.hibernate.Entity.orderedPOs#1]
15:32:08,703 DEBUG SessionImpl:2850 - Collection found: [po_db2.hibernate.Entity.sellingPOs#1], was: [po_db2.hibernate.Entity.sellingPOs#1]
15:32:08,718 DEBUG SessionImpl:2746 - Processing unreferenced collections
15:32:08,718 DEBUG SessionImpl:2760 - Scheduling collection removes/(re)creates/updates
15:32:08,718 DEBUG SessionImpl:2234 - Flushed: 0 insertions, 0 updates, 0 deletions to 4 objects
15:32:08,718 DEBUG SessionImpl:2239 - Flushed: 0 (re)creations, 0 updates, 0 removals to 9 collections
15:32:08,718 DEBUG Printer:75 - listing entities:
15:32:08,718 DEBUG Printer:82 - po_db2.hibernate.PoNew{whenCreated=16 October 2003 18:23:26, remarks=, entity=Entity#1, orderedByRef=, whenModified=16 October 2003 18:23:26, dbId=1152, closedDate=null, whoCreated=Remington, poDate=16 October 2003, projectId=, poSuffix=, poNum=520996, subVendorId=, whoModified=null, poId=po3158, vendorRef=}
15:32:08,718 DEBUG Printer:82 - po_db2.hibernate.Entity{phone=, add2=, itemsToBeDelivered=uninitialized, fax=, entityNums=uninitialized, limitAgentNum=, add1=, orderedPOs=uninitialized, limitShpNum=, zip=, limitBilltoNum=, whoModified=, entities=uninitialized, city=, poItemOrdereds=uninitialized, whenCreated=null, limitCsgNum=, entity=Entity#1, whenModified=10 October 2003 13:47:00, entityType=buyer, dbId=1, sellingPOs=uninitialized, ent

_________________
<http://tayek.com/>, co-chair <http://www.ocjug.org/>, actively
seeking telecommuting work. hate spam?
<https://www1.ietf.org/mailman/listinfo/asrg>


Top
 Profile  
 
 Post subject: Re: Same behavior
PostPosted: Sun May 09, 2004 7:02 pm 
Regular
Regular

Joined: Sat Feb 21, 2004 8:54 pm
Posts: 60
Location: Lakewood, California
rtayek wrote:
fdelisle wrote:
I'm experiencing the same behavior and ... nothing worked. I'm using version 2.1.2.

i am using 2.1.2 also (with mysql 4). there is a thread here: http://forum.hibernate.org/viewtopic.php?t=929664 that sounds similar...
thanks


tried it with 2.1.3, but got the same sort of thing:

15:57:44,390 DEBUG Loader:239 - total objects hydrated: 1
15:57:44,390 DEBUG SessionImpl:2191 - resolving associations for [po_db2.hibernate.PoItemOrdered#7431]
15:57:44,390 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
Hibernate: select poitem0_.db_id as db_id0_, poitem0_.item_id as item_id0_, poitem0_.item_name as item_name0_, poitem0_.weight_gross_unit as weight_g4_0_, poitem0_.weight_gross as weight_g5_0_, poitem0_.weight_net_unit as weight_n6_0_, poitem0_.weight_net as weight_net0_, poitem0_.volume_unit as volume_u8_0_, poitem0_.volume as volume0_, poitem0_.sku as sku0_, poitem0_.upc as upc0_, poitem0_.quantity_unit as quantit12_0_, poitem0_.quantity as quantity0_, poitem0_.brand as brand0_, poitem0_.description as descrip15_0_, poitem0_.who_created as who_cre16_0_, poitem0_.when_created as when_cr17_0_, poitem0_.who_modified as who_mod18_0_, poitem0_.when_modified as when_mo19_0_ from po_item poitem0_ where poitem0_.item_id=?
15:57:44,390 DEBUG BatcherImpl:241 - preparing statement
15:57:44,406 DEBUG StringType:46 - binding 'i3527' to parameter: 1

thanks

_________________
<http://tayek.com/>, co-chair <http://www.ocjug.org/>, actively
seeking telecommuting work. hate spam?
<https://www1.ietf.org/mailman/listinfo/asrg>


Top
 Profile  
 
 Post subject: Re: Same behavior
PostPosted: Sun May 09, 2004 10:07 pm 
Regular
Regular

Joined: Sat Feb 21, 2004 8:54 pm
Posts: 60
Location: Lakewood, California
rtayek wrote:
fdelisle wrote:
I'm experiencing ...... nothing worked.
I'm using version 2.1.2.

thanks


using 2.1.3, i made every collection lazy and every class have a proxy. and i wrote the code (see blow) to verify this at run time. all of the collections are lazy and all of the classes have proxies and still no joy.

i could not find anything in the simple value stuff that told it whether or not it woul lazy load a reference, so presumable it looks to see if the reference has a proxy.

you might want to run this code on your own stuff and see what it says.

thanks

Code:
   public static java.util.List getPersistentClasses(final Configuration configuration) {
      java.util.List l= new LinkedList();
      for (Iterator i= configuration.getClassMappings(); i.hasNext();) {
         final PersistentClass pc= (PersistentClass)i.next();
         l.add(pc);
      }
      return l;
   }
   public static void info(final java.util.Collection pcs) {
      for (Iterator i= pcs.iterator(); i.hasNext();) {
         final PersistentClass pc= (PersistentClass)i.next();
         logger.info("name=" + pc.getName());
         logger.info("proxy interface=" + pc.getProxyInterface());
         if(pc.getProxyInterface()==null)
            throw new RuntimeException(pc.getName()+" does not have a proxy!");
         logger.info("properties:");
         for (Iterator j= pc.getPropertyIterator(); j.hasNext();) {
            Property p= (Property)j.next();
            logger.info("\t" + p.getName() + "=" + p.getValue());
            if (p.getValue() instanceof net.sf.hibernate.mapping.Collection) {
               logger.info("\t\t is a Collection, isLazy=" + ((net.sf.hibernate.mapping.Collection)p.getValue()).isLazy());
               if(!((net.sf.hibernate.mapping.Collection)p.getValue()).isLazy())
                  throw new RuntimeException(pc.getName()+" is not lazy!");
            } else if (p.getValue() instanceof SimpleValue) {
               logger.info("\t\t is a SimpleValue");
            } else {
               logger.info("\t\t is something else");
            }
         }
         final java.util.Map m= pc.getMetaAttributes();
         logger.info("meta attributes="+m);
         for (Iterator j= m.entrySet().iterator(); j.hasNext();)
            logger.info(j.next());
         logger.info("end of info for: " + pc.getName());
      }
   }

_________________
<http://tayek.com/>, co-chair <http://www.ocjug.org/>, actively
seeking telecommuting work. hate spam?
<https://www1.ietf.org/mailman/listinfo/asrg>


Top
 Profile  
 
 Post subject:
PostPosted: Tue May 18, 2004 12:37 am 
Regular
Regular

Joined: Thu Apr 29, 2004 5:08 pm
Posts: 56
Location: Montreal, Quebec, Canada
Hey,

Finally, I added lazy="true" to the mapping files of the classes that were loaded without my conscenment.

I read this line in the doc:

1 Metadata fetching strategies for single-ended associations
1.1 Lazy fetching for many-to-one and one-to-one associations
---> the associated (target) class must have (automatic) proxying enabled:


Code:
<class name="Item" lazy="true"> ....
or
<class name="Item" proxy="Item"> ....


Now unwanted additional sql queries are gone.

Does this work for you?

_________________
- Frank


Top
 Profile  
 
 Post subject:
PostPosted: Tue May 25, 2004 10:11 pm 
Regular
Regular

Joined: Sat Feb 21, 2004 8:54 pm
Posts: 60
Location: Lakewood, California
fdelisle wrote:
Hey,

Finally, I added lazy="true" to the mapping files ...
Now unwanted additional sql queries are gone.

Does this work for you?


all of mine were lazy or proxied, but no joy. i will try again on a new version of the db.

thanks

_________________
<http://tayek.com/>, co-chair <http://www.ocjug.org/>, actively
seeking telecommuting work. hate spam?
<https://www1.ietf.org/mailman/listinfo/asrg>


Top
 Profile  
 
 Post subject:
PostPosted: Wed May 26, 2004 12:49 am 
Regular
Regular

Joined: Thu Apr 29, 2004 5:08 pm
Posts: 56
Location: Montreal, Quebec, Canada
I don't see how trying it on a new version of the db would help.

Are you sure the extra sql query is for fetching the direct associated object?

Class A... set of Class B
Class B... many-to-one relation to A

If Class A is mapped as lazy="true" (not the collection, but the class itself) or proxied, when loading object(s) of class B, there is no reason associated class A object to be loaded.

Are you sure the extra sql query actually load a Class A Object and not objects associated to it?....

I mean, I can't understand why you're still getting those extra queries....

Please keep me updated on your case,

_________________
- Frank


Top
 Profile  
 
 Post subject:
PostPosted: Wed May 26, 2004 12:52 am 
Regular
Regular

Joined: Thu Apr 29, 2004 5:08 pm
Posts: 56
Location: Montreal, Quebec, Canada
The only thing I see in your mapping that are different from mine are the
"property-ref=..." attributes.

I don't use them.

_________________
- Frank


Top
 Profile  
 
 Post subject:
PostPosted: Fri May 28, 2004 11:06 am 
Regular
Regular

Joined: Sat Feb 21, 2004 8:54 pm
Posts: 60
Location: Lakewood, California
Quote:
The only thing I see in your mapping that are different from mine are the
"property-ref=..." attributes.

I don't use them.


i started over with an empty db and got rid of the property-ref's. the one case that i have looked at so far seemed to work ok. hibernate will say that he loaded the object if debug is on, but he is just loading the proxy i thnk. actuallly referring to the object later seems tol cause a select to be done to actually load the object.

thanks

_________________
<http://tayek.com/>, co-chair <http://www.ocjug.org/>, actively
seeking telecommuting work. hate spam?
<https://www1.ietf.org/mailman/listinfo/asrg>


Top
 Profile  
 
 Post subject:
PostPosted: Fri May 28, 2004 11:51 am 
Regular
Regular

Joined: Thu Apr 29, 2004 5:08 pm
Posts: 56
Location: Montreal, Quebec, Canada
Cool!

Actually, when loading the object, if you see no select from hibernate to load the associated one (many-to-one relation), well it means hibernate doesn't hit the BD. Which is ok.

I think you got it!

About property-ref, from the Hibernate Doc:

Quote:
The property-ref attribute should only be used for mapping legacy data where a foreign key refers to a unique key of the associated table other than the primary key. This is an ugly relational model.


It seems that for some reason, this attribute causes the associated object to be loaded on the way, not respecting its proxied behavior.

I wish you nice coding (mapping) and hope your problem is gone forever.

_________________
- Frank


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 12 posts ] 

All times are UTC - 5 hours [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.