Ken,
On 14. 2. 2015, at 16:04, Ken Anderson <[email protected]> wrote:
> This is certainly odd behavior - something else must be going on.
>
> In your example (a) will always happen - EOF will fault in relationships
> before adding objects to them. But, once that relationship is there, it
> should stay in that EO until some kind of invalidation happens.
Thanks!
> Any chance you could post all the code?
Afraid not; it would mean the complete application, which is pretty big.
Meantime, I've found that
(a) if I batch-add the price orders, the extra SELECT does not happen;
(b) if I out-comment saving EC, the extra SELECT does not happen (even over
many R/R loops);
(c) on the other hand, with a code
===
3.times {
DBPriceOffer o=new DBPriceOffer()
o.price=-1 // just a tag allowing to clean up the mess in the DB
createdBy.editingContext.insertObject(o)
println "WEIRD 17 newo: $o, creator: $createdBy //
EC:${o.editingContext()}
(FTS:${(System.currentTimeMillis()-o.editingContext().fetchTimestamp())/1000}
s)"
o.addObjectToBothSidesOfRelationshipWithKey(createdBy,'user')
println "WEIRD 21"
o.editingContext().saveChanges()
}
System.exit(0) // to keep the mess in DB limited
===
the extra SELECT _does_ happen.
So, at the moment, I am trying to find what happens during a save. I have
commented out my validateForSave and my database context delegate (which logs
out all adaptor ops in databaseContextWillPerformAdaptorOperations), and the
problem still persists.
Far as I can say, (after out-commenting) no code of mine gets called when
saving, but still the log looks like this (removed Begin/Commit internal
transactions, which, I think, can't help, just decrease the legibility, and
removed the list of columns of SELECTs which is long and helps none, I believe):
===
...
WEIRD 17 newo: <DBPriceOffer@823250915 PK:null N /EC:550440296>, creator:
<DBUser@484622050 PK:1000008 Name:'cl' T:'5' /EC:550440296> //
EC:er.extensions.eof.ERXEC@20cf0d68 (FTS:3649.305 s)
16:24:06.586 DEBUG evaluateExpression:
<com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT ...
FROM "T_PRICE_OFFER" t0 WHERE t0."C_CREATOR_ID" = 1000008" withBindings: >
16:24:06.599 DEBUG 185 row(s) processed
WEIRD 21
16:24:06.800 DEBUG evaluateExpression:
<com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "VALUES
(SELECT UNIQUE FROM "T_PRICE_OFFER")" withBindings: >
16:24:06.801 DEBUG fetch canceled
16:24:06.802 DEBUG 1 row(s) processed
16:24:06.845 DEBUG evaluateExpression:
<com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "INSERT INTO
"T_PRICE_OFFER"("C_SHEET_CONFIRMED", "C_UID", "C_AMOUNT", "C_PRICE",
"C_CREATION_DATE", "C_CREATOR_ID", "C_VALID_OFFER") VALUES (NULL, 1000265,
NULL, -1.00, TIMESTAMP '2015-02-14 16:24:06.573', 1000008, false)"
withBindings: >
16:24:06.919 DEBUG evaluateExpression:
<com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT ...
FROM "T_USER" t0 WHERE t0."C_UID" = 1000008" withBindings: >
16:24:06.921 DEBUG 1 row(s) processed
WEIRD 17 newo: <DBPriceOffer@216355583 PK:null N /EC:550440296>, creator:
<DBUser@484622050 PK:1000008 Name:'cl' T:'5' /EC:550440296> //
EC:er.extensions.eof.ERXEC@20cf0d68 (FTS:3649.647 s)
16:24:06.930 DEBUG evaluateExpression:
<com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT ...
FROM "T_PRICE_OFFER" t0 WHERE t0."C_CREATOR_ID" = 1000008" withBindings: >
16:24:06.941 DEBUG 186 row(s) processed
WEIRD 21
16:24:06.972 DEBUG evaluateExpression:
<com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "VALUES
(SELECT UNIQUE FROM "T_PRICE_OFFER")" withBindings: >
16:24:06.974 DEBUG fetch canceled
16:24:06.974 DEBUG 1 row(s) processed
16:24:07.021 DEBUG evaluateExpression:
<com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "INSERT INTO
"T_PRICE_OFFER"("C_SHEET_CONFIRMED", "C_UID", "C_AMOUNT", "C_PRICE",
"C_CREATION_DATE", "C_CREATOR_ID", "C_VALID_OFFER") VALUES (NULL, 1000266,
NULL, -1.00, TIMESTAMP '2015-02-14 16:24:06.916', 1000008, false)"
withBindings: >
16:24:07.090 DEBUG evaluateExpression:
<com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT ...
FROM "T_USER" t0 WHERE t0."C_UID" = 1000008" withBindings: >
16:24:07.092 DEBUG 1 row(s) processed
WEIRD 17 newo: <DBPriceOffer@831641327 PK:null N /EC:550440296>, creator:
<DBUser@484622050 PK:1000008 Name:'cl' T:'5' /EC:550440296> //
EC:er.extensions.eof.ERXEC@20cf0d68 (FTS:3649.819 s)
16:24:07.101 DEBUG evaluateExpression:
<com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT ...
FROM "T_PRICE_OFFER" t0 WHERE t0."C_CREATOR_ID" = 1000008" withBindings: >
16:24:07.111 DEBUG 187 row(s) processed
WEIRD 21
16:24:07.147 DEBUG evaluateExpression:
<com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "VALUES
(SELECT UNIQUE FROM "T_PRICE_OFFER")" withBindings: >
16:24:07.148 DEBUG fetch canceled
16:24:07.148 DEBUG 1 row(s) processed
16:24:07.185 DEBUG evaluateExpression:
<com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "INSERT INTO
"T_PRICE_OFFER"("C_SHEET_CONFIRMED", "C_UID", "C_AMOUNT", "C_PRICE",
"C_CREATION_DATE", "C_CREATOR_ID", "C_VALID_OFFER") VALUES (NULL, 1000267,
NULL, -1.00, TIMESTAMP '2015-02-14 16:24:07.088', 1000008, false)"
withBindings: >
APPLICATION SHUTDOWN SEQUENCE COMPLETE
===
To be frank, with my limited knowledge of SQL I don't quite get the
VALUES (SELECT UNIQUE FROM "T_PRICE_OFFER")
lines; what's that? Of the SELECT FROM T_USER I am not sure whether it really
makes any sense -- why would EOF refetch the user? The rest of lines make sense
-- but for repeating the SELECT FROM T_PRICE_OFFER...
I wonder, what might be the culprit? Note that if the save itself does not
happen (the same code as above without "o.editingContext().saveChanges()"), the
SELECT is not repeated...
Thanks a lot,
OC
> On Feb 14, 2015, at 8:24 AM, OC <[email protected]> wrote:
>
>> Hello there,
>>
>> as Alice said, it gets couriouser and couriouser. I am now logging SQL, and
>> -- at least to me -- it seems my application is SELECTing way too often.
>>
>> The code is still related to the price offers of my previous posts; this
>> time though I am using the default EC and I am not setting fetchTimestamp.
>>
>> I am creating new objects in an entity DBPriceOffer and adding them to 1:N
>> relationship of an entity DBUser -- all of them to the same user.
>>
>> Now, what I would (naïvely?) assume is that
>> (a) the first time this happens, the user's price offers _might be_ fetched
>> (not necessarily, but possibly)
>> (b) nevertheless, when they _are_ once fetched into the EC, they won't be
>> re-fetched anytime soon, for EC caches them and EOF does not make
>> unnecessary roundtrips to the DB.
>>
>> They get re-fetched though -- each sweet time again, with the same EC, no
>> fetchTimestamp. My app never refaults nor refreshes anything. There's about
>> 95 % free heap, so there should be no flushing of soft caches, if WO uses
>> them at all. My current code looks like this:
>>
>> ===
>> DBPriceOffer o=new DBPriceOffer()
>> createdBy.editingContext.insertObject(o)
>> ...
>> println "WEIRD 27 newo: $o, creator: $createdBy // EC:${o.editingContext()}
>> (FTS:${(System.currentTimeMillis()-o.editingContext().fetchTimestamp())/1000}
>> s)"
>> o.addObjectToBothSidesOfRelationshipWithKey(createdBy,'user')
>> //createdBy.addObjectToBothSidesOfRelationshipWithKey(o,'priceOffers') //
>> tried this too, works precisely same way
>> println "WEIRD 31
>> ===
>>
>> and adding price offers through this code _always_ re-fetches the user's
>> relationship into which they are being added:
>>
>> ===
>> WEIRD 27 newo: <DBPriceOffer@1247321477 PK:null N /EC:176991315>, creator:
>> <DBUser@2069151341 PK:1000008 Name:'cl' /EC:176991315> //
>> EC:er.extensions.eof.ERXEC@a8cac53 (FTS:3996.348 s)
>> 14:09:16.912 DEBUG evaluateExpression:
>> <com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT ...
>> FROM "T_PRICE_OFFER" t0 WHERE t0."C_CREATOR_ID" = 1000008" withBindings: >
>> 14:09:16.922 DEBUG 179 row(s) processed
>> WEIRD 31
>> ...
>> WEIRD 27 newo: <DBPriceOffer@81493054 PK:null N /EC:176991315>, creator:
>> <DBUser@2069151341 PK:1000008 Name:'cl' /EC:176991315> //
>> EC:er.extensions.eof.ERXEC@a8cac53 (FTS:4001.53 s)
>> 14:09:22.090 DEBUG evaluateExpression:
>> <com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT ...
>> FROM "T_PRICE_OFFER" t0 WHERE t0."C_CREATOR_ID" = 1000008" withBindings: >
>> 14:09:22.099 DEBUG 180 row(s) processed
>> WEIRD 31
>> ...
>> WEIRD 27 newo: <DBPriceOffer@1879220176 PK:null N /EC:176991315>, creator:
>> <DBUser@2069151341 PK:1000008 Name:'cl /EC:176991315> //
>> EC:er.extensions.eof.ERXEC@a8cac53 (FTS:4006.075 s)
>> 14:09:26.635 DEBUG evaluateExpression:
>> <com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT ...
>> FROM "T_PRICE_OFFER" t0 WHERE t0."C_CREATOR_ID" = 1000008" withBindings: >
>> 14:09:26.643 DEBUG 181 row(s) processed
>> WEIRD 31
>> ...
>> ===
>>
>> and so forth: whenever I add a new price offer into the same user's 1:N
>> relationship, the price offers of that user get re-fetched again.
>>
>> I'm flabbergasted. Is this the normal WebObjects (or, rather, EOF)
>> behaviour? Am I missing something of importance?
>>
>> Thanks,
>> OC
>>
>>
>> _______________________________________________
>> Do not post admin requests to the list. They will be ignored.
>> Webobjects-dev mailing list ([email protected])
>> Help/Unsubscribe/Update your Subscription:
>> https://lists.apple.com/mailman/options/webobjects-dev/kenlists%40anderhome.com
>>
>> This email sent to [email protected]
>
_______________________________________________
Do not post admin requests to the list. They will be ignored.
Webobjects-dev mailing list ([email protected])
Help/Unsubscribe/Update your Subscription:
https://lists.apple.com/mailman/options/webobjects-dev/archive%40mail-archive.com
This email sent to [email protected]
