Performance issue on SQL-queries

en@frrom · #1 19th September 2003, 12:34

I encounter the following issue and wonder if anyone has an explanation and / or solution/workaround:

I zoom from a parent display-session to its child display-session, passing on certain values of the current selection in the parent to the child, and displaying the data in the child for that selection.

In the before.program of the child I execute a query using 'group by', for I must select the orders on the index, but have them ordered by a different field. I know that 'group by' and 'order by' take long time [by the way does anyone know what takes longer: group by or order by, or that they are about the same - logically I would say that group by takes even slightly longer, but I'm not sure]; however I noticed that the first time entering the child session with a certain selection, the select in the before.program takes very long. If then I EXIT the child, and then from the parent zoom again to the child with the SAME SELECTION, the the select in the child takes maybe a tenth of the time!!!

For instance:
Let's say the selection is on about 30k records SEARCHED ON INDEX, grouped by one field, which is producing 15 records. Without using group by this selection takes a split second, and the first time with group by it takes around 20 seconds or more(!!!!). Second time zommed without having changed the selection in the parent session, - ALTHOUGHT THE CHILD SESSION HAS BEEN CLOSED COMPLETELY AFTER THE FIRST TIME - it takes maximum 2 seconds!!

- How is this happening (i.e. I had closed the child completely and then re-opened it for the same selection)?
- Is the first time where it takes long 'unusual' and from the second time on the 'usual' or is the first time the normal time it takes, and for some reason afterwards goes faster?
- I need to solve this. I.e. I MUST get this running as fast as the second time, (also) when zooming to the child the first time for the given selection!! How?

Thanks a lot in advance! Any clues would be highly appreciated!!

En.

OmeLuuk · #2 19th September 2003, 12:41

Try to perform some comparing loggings:
use -- -set TT_SQL_TRACE=20240 -dbgsrdduse -dbgtime -keeplog -logfile comparefile in all situations (order by / group by).

Initialization of the first session maybe slow when you use an older portingset. This has to do with file-I/O even though the system logs files as being read from shared memory.

en@frrom · #3 19th September 2003, 13:00

Hi Ome Luuk,

Thanks for your response. I think however you misunderstand me. This has nothing to do with first session start-up. The case is as follows:

On the active bshell, after running already the specific sessions 10 times - that doesn't matter - I start session A, which is a display session.
- The session starts immediately, and gives me my records; no problem.
- In session A I define a selection for display, and get the records immediately - no problem.
- The I zoom - via specific - to session B, the child of session A. This session receives the selection criteria from session A, and display data accordingly.

In the before.program of session B, I run a select based on the selection criteria which were imported from the parent session A, using 'group by'. Here the symptoms happen as descibed in my first post. I.e. first time selecting with specific selection - even if the session has been closed, AND EVEN IF THE PARENT SESSION HAS BEEN CLOSED MEANWHILE (!!) and then open the parent again, select in the parent the same selection as the last time. Now zoom to the child, and the selection will go fast. If the selection criteria were changed in the parent, even while the session is still open, the select in the child will be again very slow the first time, etc.

Hope the symptoms are clear...

Kind regards,

En.

OmeLuuk · #4 19th September 2003, 13:48

Yet, although symptoms are clear.

I think logging would help you understand what it taking so long either way with using group by etc.

Ok, what you say: srdd usage is not the problem, it is query handling. So you will need to see the logfile with TT_SQL_TRACE=20240 and in that case a dbgtime option (added in newer portingset) and dbgfdev (to see creation of sort / query file IO).

Then you may be able to pinpoint the cause of your delay.

What is your portingset version?

NvanBeest · #5 19th September 2003, 13:55

Also, since the second time is much faster, it points to the query being cached by Oracle. The first time, Oracle probably has some difficulty building a query plan, but, once it is cached, the query runs reasonably fast. If you can, you could verify this by executing the sessions, then flush the Oracle cache, and execute again. The second time should now talking as long as the first time!

en@frrom · #6 19th September 2003, 14:24

Hi Ome Luuk, Nico,

Thanks for the replies.

I ran a trace with -dbgfdev, and these are the results:

First time:

------------------------------------------------
Nr Rows Fetched : 24
Fetch Time for 1st Row : 31.281 sec
Max Fetch Time : 31.281 sec
Average Fetch Time : 1.304 sec
Average Fetch Time (except Max) : 0.000 sec
Total Time : 31.297 sec

Second time:

-----------------------------------------------
Nr Rows Fetched : 24
Fetch Time for 1st Row : 1.734 sec
Max Fetch Time : 1.734 sec
Average Fetch Time : 0.072 sec
Average Fetch Time (except Max) : 0.000 sec
Total Time : 1.750 sec
==============================================

When trying with -dbgtime, I received bw-errors, and the bshell didn't connect, so I assume that this is not available for my porting set...?

As you can see the first time takes over 30 seconds in this case, and the second time lesst than 2 seconds! This is also after closing both the parent and the child, and then opening them again with the same selection criteria as before.

Nico, where do I find the Oracle cach? How do I flush the cache?

NPRao · #7 19th September 2003, 20:09

En,

I would not advise you to manually flush the Oracle cache.

From my observation from few sessions in our development group was due to many disable/enable-fields commands used in the sessions, which were executed for all the fields, used in single & multi-occ sessions. I changed the code to use certain enable/disable in single occ mode and the rest in multi-occ mode.
This helped to improve the startup of the session.

More info refer to the link -
refresh

If you post your code it will certainly help others to look at the programming problems.

OmeLuuk · #8 19th September 2003, 22:04

Quote:

en@frrom: ... Fetch Time for 1st Row : 31.281 sec ... Fetch Time for 1st Row : 1.734 sec

Running level 1 driver or level 2? And is there a way to optimize your query with other sequence of fields, using index etc?

Quote:

When trying with -dbgtime, I received bw-errors, and the bshell didn't connect, so I assume that this is not available for my porting set...?

Correct.

en@frrom · #9 22nd September 2003, 10:57

Hi all, thanks for the posts!

Np, I am aware of the performance problem when using too many display() and refresh(). However, this is not the case in my session at all.

Ome Luuk,

I think we have a level 2 db driver. But am not sure how/where to check that... :o

I think my queries are optimized. I played around with it, and tried a few variations. I will post the relevant parts of the code; maybe anyone sees anything...?

In the parent session:

Code:

function extern details.cpcl()
{
	if synch.id then
		synchronize.with.child(synch.id)
	endif
	if not synch.id then
		synch.id = start.synchronized.child ( "tdrom9505se00", 
		"form.curr", "from.form",
		"rel.field.f", "rel.field.f",
		"rel.field.t", "rel.field.t",
		"tdrom991.year.c", "imp.year",
		"incl.free", "incl.free",
		"incl.cost", "incl.cost",
		"perd.f", "perd.f",
		"perd.t", "perd.t" )
	endif
}

In the child:

Code:

	     CASE 3:
		db.retry.point()
		select	tdrom901.cpcl.c, sum(tdrom901.brom.c):sum.brom, sum(tdrom901.disc.c):sum.disc, 
			sum(tdrom901.squa.c):sum.squa, sum(tdrom901.spcs.c):sum.spcs
		from 	tdrom901
		where	tdrom901._index1 inrange {:from.form, :dummy, 0, :dummy, :rel.field.f, 
						     :dummy, :dummy, :imp.year, :perd.f} 
					          and {:from.form, :dummy, 0, :dummy, :rel.field.t, 
						      :dummy, :dummy, :imp.year, :perd.t}
		and	(tdrom901.free.c = tcyesno.no or :incl.free = tcyesno.yes)
		and	((tdrom901.kitm.c = tckitm.purchase or tdrom901.kitm.c = tckitm.manufacture)
			or :incl.cost = tcyesno.yes)
		group by tdrom901.cpcl.c
		selectdo
			| performs some updates...
		endselect
		commit.transaction()
		break

The dummy's are just empty strings, because those fields must be empty.

Regards,

En.

OmeLuuk · #10 22nd September 2003, 11:35

You want to have some sums on certain fields and also perform actions on several of the data selected...
would it not be better to split the query into two queries: first determine the sums and then perform the actions... or would the actions influence the sums? In that case first perform the actions and then calculate the sums...

en@frrom · #11 22nd September 2003, 11:43

Quote:

You want to have some sums on certain fields and also perform actions on several of the data selected...

Ome Luuk, I probably wasn't clear. I select the sum of these (grouped) fields, and update a different table with the sum values.

OmeLuuk · #12 22nd September 2003, 11:48

Is it possible to add an index that starts with the field tdrom901.cpcl.c? Because now you will defenitely need a lot of Full Table Scans (see logfile of TT_SQL_TRACE=20240) to be able to group when selected on index_1.

en@frrom · #13 22nd September 2003, 11:58

Quote:

Is it possible to add an index that starts with the field tdrom901.cpcl.c? Because now you will defenitely need a lot of Full Table Scans (see logfile of TT_SQL_TRACE=20240) to be able to group when selected on index_1.

Will that help?? My select will anyway be for all tdrom901.cpcl.c's. So it would look like this:

Code:

		select	tdrom901.cpcl.c, sum(tdrom901.brom.c):sum.brom, sum(tdrom901.disc.c):sum.disc, 
			sum(tdrom901.squa.c):sum.squa, sum(tdrom901.spcs.c):sum.spcs
		from 	tdrom901
		where	tdrom901._index1 inrange {" ", :from.form, :dummy, 0, :dummy, :rel.field.f, 
						     :dummy, :dummy, :imp.year, :perd.f} 
					          and {"ZZZZZZ", :from.form, :dummy, 0, :dummy, :rel.field.t, 
						      :dummy, :dummy, :imp.year, :perd.t}
		and	(tdrom901.free.c = tcyesno.no or :incl.free = tcyesno.yes)
		and	((tdrom901.kitm.c = tckitm.purchase or tdrom901.kitm.c = tckitm.manufacture)
			or :incl.cost = tcyesno.yes)
		group by tdrom901.cpcl.c

OmeLuuk · #14 22nd September 2003, 12:07

Current code:
Determine condition tdrom901.cpcl.c
Select subset from index1
then for each member determine the condition tdrom901.cpcl.c meets the group-by condition. if not discard, if so, select.

Proposed code: (add extra index)
Select all based upon (ordered) tdrom901.cpcl.c/index1 index:
now all recods may be easlily grouped by the first indexfield because it is ordered with that index. (you should add the order by index X/field tdrom901.cpcl.c to actually use your new index)

en@frrom · #15 22nd September 2003, 12:28

Quote:

- Is the first time where it takes long 'unusual' and from the second time on the 'usual' or is the first time the normal time it takes, and for some reason afterwards goes faster?

Are you saying that the time it should take is the time it takes the first time opening the session with the given selection? Is it normal that 'group by' will take that long??

I'm sorry, but I still don't understand what you are suggesting me to do. Can you please give a little example of what you mean? Tia!