Exorbitant execution time

Johannes Lebek

Hi there,

lately, I experienced a strange thing on my DB2 V8.1 on Windows: Some
queries took a very long time. A snapshot discovered the following:

Number of executions = 47
Number of compilations = 1
Worst preparation time (ms) = 2
Best preparation time (ms) = 2
Internal rows deleted = 0
Internal rows inserted = 0
Rows read = 192277
Internal rows updated = 0
Rows written = 0
Statement sorts = 47
Buffer pool data logical reads = 76306
Buffer pool data physical reads = 155
Buffer pool temporary data logical reads = 0
Buffer pool temporary data physical reads = 0
Buffer pool index logical reads = 2995
Buffer pool index physical reads = 16
Buffer pool temporary index logical reads = 0
Buffer pool temporary index physical reads = 0
Total execution time (sec.ms) = 123.065931
Total user cpu time (sec.ms) = 0.546875
Total system cpu time (sec.ms) = 0.062500
Statement text = SELECT COL1, COL2, COL3, COL4,
COL5, COL6, COL7, COL8, COL9, COL10, COL11, COL12, COL13 FROM TABLE1
WHERE (COL6 IN (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?)) AND COL12 = 'N'

Total execution time was 123 seconds, although user and system cpu time
had been reasonable values.
There is an index on COL6 and COL12 (in this order; maybe, (COL12, COL6)
is faster).
155 physical reads is not that bad (0.2%). Assumed these are all random
reads, is 120 seconds a reasonable number on a Windows machine? This
equals 775 ms per random read. I learned random reads take about 10 to
20 ms on a z/OS box.
However, I cannot imagine that all physical reads are random reads. If
there are sequential reads, the execution time of random reads must be
even longer.

What are your experiences? Do you think, this execution time is caused
by the physical reads? If not, what are your assumptions?
Thanks for your help,

Johannes

Nov 12 '05 #1

Mark A

"Johannes Lebek" <re****************@domain.com> wrote in message
news:ca**********@sp15en20.hursley.ibm.com...

Hi there,

lately, I experienced a strange thing on my DB2 V8.1 on Windows: Some
queries took a very long time. A snapshot discovered the following:

Number of executions = 47
Number of compilations = 1
Worst preparation time (ms) = 2
Best preparation time (ms) = 2
Internal rows deleted = 0
Internal rows inserted = 0
Rows read = 192277
Internal rows updated = 0
Rows written = 0
Statement sorts = 47
Buffer pool data logical reads = 76306
Buffer pool data physical reads = 155
Buffer pool temporary data logical reads = 0
Buffer pool temporary data physical reads = 0
Buffer pool index logical reads = 2995
Buffer pool index physical reads = 16
Buffer pool temporary index logical reads = 0
Buffer pool temporary index physical reads = 0
Total execution time (sec.ms) = 123.065931
Total user cpu time (sec.ms) = 0.546875
Total system cpu time (sec.ms) = 0.062500
Statement text = SELECT COL1, COL2, COL3, COL4,
COL5, COL6, COL7, COL8, COL9, COL10, COL11, COL12, COL13 FROM TABLE1
WHERE (COL6 IN (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?)) AND COL12 = 'N'

Total execution time was 123 seconds, although user and system cpu time
had been reasonable values.
There is an index on COL6 and COL12 (in this order; maybe, (COL12, COL6)
is faster).
155 physical reads is not that bad (0.2%). Assumed these are all random
reads, is 120 seconds a reasonable number on a Windows machine? This
equals 775 ms per random read. I learned random reads take about 10 to
20 ms on a z/OS box.
However, I cannot imagine that all physical reads are random reads. If
there are sequential reads, the execution time of random reads must be
even longer.

What are your experiences? Do you think, this execution time is caused
by the physical reads? If not, what are your assumptions?
Thanks for your help,

Johannes

First you should do an explain and determine which indexes are being used or
if a tablespace scan is used.

I don't understand what you are saying about the existing indexes. Is their
one composite index on (COL12, COL6) or are their 2 indexes, one on COL12
and one on COL6?

Did you execute runstats with distribution on key columns and indexes all?

How many rows in the table?
What is the cardinality of COL12?
What is the cardinality of the IN values for COL6?

Nov 12 '05 #2

Sean McKeough

Total execution time = time cursor was closed - time cursor was opened

So if your app does a lot of work with the cursor open, that would
explain it.

Johannes Lebek wrote:

Hi there,

lately, I experienced a strange thing on my DB2 V8.1 on Windows: Some
queries took a very long time. A snapshot discovered the following:

Number of executions = 47
Number of compilations = 1
Worst preparation time (ms) = 2
Best preparation time (ms) = 2
Internal rows deleted = 0
Internal rows inserted = 0
Rows read = 192277
Internal rows updated = 0
Rows written = 0
Statement sorts = 47
Buffer pool data logical reads = 76306
Buffer pool data physical reads = 155
Buffer pool temporary data logical reads = 0
Buffer pool temporary data physical reads = 0
Buffer pool index logical reads = 2995
Buffer pool index physical reads = 16
Buffer pool temporary index logical reads = 0
Buffer pool temporary index physical reads = 0
Total execution time (sec.ms) = 123.065931
Total user cpu time (sec.ms) = 0.546875
Total system cpu time (sec.ms) = 0.062500
Statement text = SELECT COL1, COL2, COL3, COL4,
COL5, COL6, COL7, COL8, COL9, COL10, COL11, COL12, COL13 FROM TABLE1
WHERE (COL6 IN (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?)) AND COL12 = 'N'

Total execution time was 123 seconds, although user and system cpu time
had been reasonable values.
There is an index on COL6 and COL12 (in this order; maybe, (COL12, COL6)
is faster).
155 physical reads is not that bad (0.2%). Assumed these are all random
reads, is 120 seconds a reasonable number on a Windows machine? This
equals 775 ms per random read. I learned random reads take about 10 to
20 ms on a z/OS box.
However, I cannot imagine that all physical reads are random reads. If
there are sequential reads, the execution time of random reads must be
even longer.

What are your experiences? Do you think, this execution time is caused
by the physical reads? If not, what are your assumptions?
Thanks for your help,

Johannes

Nov 12 '05 #3

Ian

Johannes Lebek wrote:

Hi there,

lately, I experienced a strange thing on my DB2 V8.1 on Windows: Some
queries took a very long time. A snapshot discovered the following:

Number of executions = 47

Also be aware that the total execution time is cumulative for the number of
executions (47). So, that equates to an average of 2.62 seconds per
execution.

-----= Posted via Newsfeeds.Com, Uncensored Usenet News =-----
http://www.newsfeeds.com - The #1 Newsgroup Service in the World!
-----== Over 100,000 Newsgroups - 19 Different Servers! =-----

Nov 12 '05 #4

PM \(pm3iinc-nospam\) CGO

Hey;
that was my line...

;-)

PM

"Ian" <ia*****@mobileaudio.com> a écrit dans le message de
news:40**********@corp.newsgroups.com...

Johannes Lebek wrote:

Hi there,

lately, I experienced a strange thing on my DB2 V8.1 on Windows: Some
queries took a very long time. A snapshot discovered the following:

Number of executions = 47
Also be aware that the total execution time is cumulative for the number

of executions (47). So, that equates to an average of 2.62 seconds per
execution.

-----= Posted via Newsfeeds.Com, Uncensored Usenet News =-----
http://www.newsfeeds.com - The #1 Newsgroup Service in the World!
-----== Over 100,000 Newsgroups - 19 Different Servers! =-----

Nov 12 '05 #5

Mark Yudkin

> Total execution time (sec.ms) = 123.065931

Total user cpu time (sec.ms) = 0.546875
Total system cpu time (sec.ms) = 0.062500 Means you have something such as
- > 2 minutes in network (e.g. server in Australia, client in Switzerland,
using non-batched reads),
- > 2 minutes in client code (you have a 10MHz AT doing a bubble sort on
each fetch),
- > you are displaying the results to the user (GUI) before closing the
cursor (human thinking time) (==> locking !!!).

"Johannes Lebek" <re****************@domain.com> wrote in message
news:ca**********@sp15en20.hursley.ibm.com... Hi there,

lately, I experienced a strange thing on my DB2 V8.1 on Windows: Some
queries took a very long time. A snapshot discovered the following:

Number of executions = 47
Number of compilations = 1
Worst preparation time (ms) = 2
Best preparation time (ms) = 2
Internal rows deleted = 0
Internal rows inserted = 0
Rows read = 192277
Internal rows updated = 0
Rows written = 0
Statement sorts = 47
Buffer pool data logical reads = 76306
Buffer pool data physical reads = 155
Buffer pool temporary data logical reads = 0
Buffer pool temporary data physical reads = 0
Buffer pool index logical reads = 2995
Buffer pool index physical reads = 16
Buffer pool temporary index logical reads = 0
Buffer pool temporary index physical reads = 0
Total execution time (sec.ms) = 123.065931
Total user cpu time (sec.ms) = 0.546875
Total system cpu time (sec.ms) = 0.062500
Statement text = SELECT COL1, COL2, COL3, COL4,
COL5, COL6, COL7, COL8, COL9, COL10, COL11, COL12, COL13 FROM TABLE1
WHERE (COL6 IN (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?)) AND COL12 = 'N'

Total execution time was 123 seconds, although user and system cpu time
had been reasonable values.
There is an index on COL6 and COL12 (in this order; maybe, (COL12, COL6)
is faster).
155 physical reads is not that bad (0.2%). Assumed these are all random
reads, is 120 seconds a reasonable number on a Windows machine? This
equals 775 ms per random read. I learned random reads take about 10 to
20 ms on a z/OS box.
However, I cannot imagine that all physical reads are random reads. If
there are sequential reads, the execution time of random reads must be
even longer.

What are your experiences? Do you think, this execution time is caused
by the physical reads? If not, what are your assumptions?
Thanks for your help,

Johannes

Nov 12 '05 #6