Re: Timing SQL commands in WebObjects/EOF verses SQLPlus

Hi Gary,

Is this a fetch you've constructed yourself or the result of a fault 
being touched? On our last project (WO 5.1.4) we found that hitting a 
deferred fault on some relationships caused a 200-500ms lag while 
resolving the deferred fault (it should take between 0-1ms to do it). 
We turned off deferred faulting and the speedup was very noticeable. We 
never pursued why only certain relationships caused this problem. Our 
app used raw rows for most fetches and we only turned them into eos 
only during editing so turning off deferred faulting didn't seem to 
have much of an impact.

todd


On Tuesday, January 14, 2003, at 03:43  PM, Gary Pirkola wrote:

> We're trying to get a handle on some database performance issues in a 
> WebObjects/EOF/Oracle application and are seeing some inconsistancies 
> in the times to perform SQL commands depending on from where the 
> queries are issued.
>
> Specifically, we've turned EOAdaptorDebugEnabled on in our application 
> and are seeing logging of SQL commands with associated time stamps as 
> follows:
>
> [2003-01-14 17:19:57 EST] <WorkerThread1>  === Begin Internal 
> Transaction
> [2003-01-14 17:19:57 EST] <WorkerThread1>  evaluateExpression: 
> <com.webobjects.jdbcadaptor.OraclePlugIn$OracleExpression: "SELECT 
> t0.FINISHED, t0.ID_ACTIVE_STAGE, t0.ID_LOCAL_CALL_CHARTCOM, 
> t0.ID_LONG_DISTANCE_CHARTCOM, t0.ID_MRC_CHARTCOM, t0.ID_OCC_CHARTCOM, 
> t0.ID_ORDER, t0.ID_PARENT_TRANSACTION, t0.ID_PREVIOUS_STAGE, 
> t0.ID_SHOPPING_CART, t0.ID_TRANSACTION, t0.MOD_DATE, t0.PARAMETERS, 
> t0.TRANSACTION_TYPE, t0.UNIQNAME FROM OOS_TRANSACTION t0 WHERE 
> t0.ID_SHOPPING_CART = ?" withBindings: 1:4(idShoppingCart)>
> [2003-01-14 17:20:14 EST] <WorkerThread1> 129 row(s) processed
> [2003-01-14 17:20:14 EST] <WorkerThread1>  === Commit Internal 
> Transaction
>
> Since this is one of the queries that is taking longer than we would 
> expect, (17 seconds), we've also run SQLPlus from a terminal command 
> line and submitted the same query directly against the same table in 
> question, (so there's no difference as far as Oracle is concerned we 
> believe)
>
> Using SQLPlus in terminal command mode, this same query:
>
> "SELECT t0.FINISHED, t0.ID_ACTIVE_STAGE, t0.ID_LOCAL_CALL_CHARTCOM, 
> t0.ID_LONG_DISTANCE_CHARTCOM, t0.ID_MRC_CHARTCOM, t0.ID_OCC_CHARTCOM, 
> t0.ID_ORDER, t0.ID_PARENT_TRANSACTION, t0.ID_PREVIOUS_STAGE, 
> t0.ID_SHOPPING_CART, t0.ID_TRANSACTION, t0.MOD_DATE, t0.PARAMETERS, 
> t0.TRANSACTION_TYPE, t0.UNIQNAME FROM OOS_TRANSACTION t0 WHERE 
> t0.ID_SHOPPING_CART = ?" withBindings: 1:4(idShoppingCart)>
>
>  takes about a second ????
>
> Clearly something is happening in WebObjects/EOF  between the "=== 
> Begin Internal Transaction" and the "=== Commit Internal Transaction", 
> that doesn't happen with direct SQLPlus, but we don't have any idea 
> where to start looking to explain the difference (and hopefully to 
> minimize the difference).
>
> Any education/explanation or suggestions about what to look at would 
> be appreciated.
>
> Gary Pirkola and David Snyder (University of Michigan)
>
>
> _______________________________________________
> EOF mailing list
> [email protected]
> http://www.omnigroup.com/mailman/listinfo/eof
>