Re: Timing SQL commands in WebObjects/EOF verses SQLPlus

Hi Gary,
	A lot is going on in addition to just performing the SQL fetch, namely 
snapshotting the results and creating the EOs. However 127 eos should 
not take 17 seconds. If you have OptimizeIt then you can see what 
objects are being created and where all the time is being sucked up. 
Also what version of WO are you using? 5.2 had a number of performance 
enhancements to the EOF architecture. Another option that you can try 
is to convert the fetch to raw rows at see how that effects 
performance. Another bit to watchout for is LONGs in a table, I have 
seen issues where just by having the long in the table fetch time is 
slowed down by an order of 10 to 20.

Regards,
	Max

On Tuesday, January 14, 2003, at 02: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