Well, after several hours of testing I discovered the following occurs repeateably and predictably:
If I put the first debugging line in which you provided:
Code:
logger.info("barcode count pre-persist [" + colourSize.getBarcodes().size() + "]");
The problem goes away.
If I put the second debuggin line in:
Code:
logger.info("barcode count post-persist [" + colourSize.getBarcodes().size() + "]");
It has no effect on the results (with or without the first line).
Regardless of what level of debugging I have set, the presence or absence of that one debugging line before the call to saveOrUpdate changes the results. I infer from this that it is actually the call to the proxied <bag> Collection.size() which somehow causes things to straighten out and work properly (having said that I want to point out that the collection has already been initialized).
Here is an excert of the trace without the first debugging line, there are some interesting things happening that only happen when that line is absent:
Code:
16:05:11,329 DEBUG SessionImpl:3204 - initializing collection [com.fgl.ina.stylecreation.coloursize.ProductColourAndSize
.barcodes#com.fgl.ina.stylecreation.coloursize.ProductColourAndSize@13799e]
16:05:11,329 DEBUG BatcherImpl:192 - about to open: 0 open PreparedStatements, 0 open ResultSets
16:05:11,329 DEBUG BatcherImpl:226 - prepared statement get: select product_0_.barcode_ID as barcode_ID__, product_0_.in
a_prod_id as ina_prod2___, product_0_.colour_ID as colour_ID__, product_0_.size_ID as size_ID__, barcodet1_.barcode_type
_ID as barcode_type_ID0_, barcodet1_.barcode_type_code as barcode_2_0_, product_0_.barcode_ID as barcode_ID1_, product_0
_.ina_prod_id as ina_prod2_1_, product_0_.colour_ID as colour_ID1_, product_0_.size_ID as size_ID1_, product_0_.barcode_
no as barcode_no1_, product_0_.barcode_type_ID as barcode_6_1_, product_0_.primary_ind as primary_7_1_ from product_barc
ode product_0_ left outer join barcode_type barcodet1_ on product_0_.barcode_type_ID=barcodet1_.barcode_type_ID where pr
oduct_0_.ina_prod_id=? and product_0_.colour_ID=? and product_0_.size_ID=? order by product_0_.barcode_ID
Hibernate: select product_0_.barcode_ID as barcode_ID__, product_0_.ina_prod_id as ina_prod2___, product_0_.colour_ID as
colour_ID__, product_0_.size_ID as size_ID__, barcodet1_.barcode_type_ID as barcode_type_ID0_, barcodet1_.barcode_type_
code as barcode_2_0_, product_0_.barcode_ID as barcode_ID1_, product_0_.ina_prod_id as ina_prod2_1_, product_0_.colour_I
D as colour_ID1_, product_0_.size_ID as size_ID1_, product_0_.barcode_no as barcode_no1_, product_0_.barcode_type_ID as
barcode_6_1_, product_0_.primary_ind as primary_7_1_ from product_barcode product_0_ left outer join barcode_type barcod
et1_ on product_0_.barcode_type_ID=barcodet1_.barcode_type_ID where product_0_.ina_prod_id=? and product_0_.colour_ID=?
and product_0_.size_ID=? order by product_0_.barcode_ID
16:05:11,369 DEBUG BatcherImpl:232 - preparing statement
16:05:11,369 DEBUG IntegerType:45 - binding '303' to parameter: 1
16:05:11,369 DEBUG IntegerType:45 - binding '11' to parameter: 2
16:05:11,379 DEBUG IntegerType:45 - binding '3' to parameter: 3
16:05:11,389 DEBUG Loader:263 - result set contains (possibly empty) collection: [com.fgl.ina.stylecreation.coloursize.ProductColourAndSize.barcodes#com.fgl.ina.stylecreation.coloursize.ProductColourAndSize@13799e]
16:05:11,389 DEBUG SessionImpl:3039 - uninitialized collection: initializing
16:05:11,389 DEBUG Loader:174 - processing result set
...
Up until where the trace excert above starts the two traces (with and without the debugging line) are identical. However, without the call to size(), Hibernate proceeds to reinitialize the collection after having inserted the new child entry. With the call to size() it simply inserts the child and stops, no reinitializing.
The <bag> collection is mapped as lazy but by this point in time has already been initialized (and iterated through...).
I don't know how to do step through debugging in JRun4 so I'm not sure how much farther I can trace it.
Thank-you.
P.S. the FAQ says:
Quote:
I have some other kind of wierd bugs.....
Carefully check the accessor methods for your persistent properties. Broken get/set pairs are a common source of bugs. Remember Hibernate might call a getter method multiple times during a session.
Also, make sure that a call to an accessor method couldn't do anything wierd ... like initialize a lazy collection or proxy.
For some classes it can be worthwhile to provide two get/set pairs for certain properties - one pair for business code and one for Hibernate.
I don't have broken get/set pairs. I don't know that the accessor would/could cause initialization of the lazy collection but trying to use the collection would of course cause initialization if it were not already initialized (which it is).
Thank-you again.