Db2 CPU Time and Wait Time

99sono · #1 (**permalink**) 03-31-10, 15:05

Hi,

In oracle and microsoft sql server i can easyly monitor the cpu time and wait time spend by query, by monitoring wait event and cpu time statistics before and after the query, and calculating their difference. Normally, these statistics are always made accessible by so called dynamic system views.

In DB2 retrieving a good cpu time and wait time statistics seems hard to do, I'd like your help on that.

Right now, in the session that I use to run query, i also record the following three statistic:
1) current time stamp
2) total_cpu_time
3) total_wait_time

These last two statistics (2 and 3), I fetch them from the "MON_GET_CONNECTION table function", see IBM DB2 9.7 for Linux, UNIX and Windows Information Center.

I don't know if there is any better way to do so.

The problem with this approach, is that when you finish your query, most of time - if not always - you will get an Elapsed Time much larger than the sum of you total_cpu_time with total_wait_time.
This of course makes no sense, and It only seem to happen in DB2.

In a Serial query execution, the Elapsed TIme = CPUTime + WaitTIme.
However, If the database system used parall queries, you would even expect for the sum of the two statistics to easyly surpass your measured elapsed time.
But in either case, you would never expect for the elapsed time to be larger than the sum of CPU Time + wait time.

Does anybody have any Idea how I can effectively monitor these two statistics in a decent enough precision?
And if possible, in a way that I can retrieve them by queries.

You see, The two snapshots that I take before and after the query, are read later by a java application I've made, wich saves the snapshot difference into an excel file. It would be very hard for me to retrieve these statisctics in any other way that did not involve querying the taken snapshots by means of a JDBC connection to db2.

Thanks in advance for any help.
My best regards,
Nuno.

sathyaram_s · #2 (**permalink**) 03-31-10, 16:17

There is an excellent blog post here :

DB2 Diary from Radhesh: Where a DB Request Spends Time in DB2 9.7?

See it this helps

99sono · #3 (**permalink**) 03-31-10, 17:14

Thanks for the helpful post.

But I am unsure as to his metholodgy of monitoring.
From his blog entry, he seems to be pretty confident that with any of those monitor table functions he can monitor where the application spent its time.

He uses the Unit of Work monitor to examplify.
In his Listing 8, he is basically telling:
You elapsed Time is = Total RQST TIme, or close enoguh.

And your elapsed is roughly equal to:
1) Total Wait TIme
2) Total Compile Proc Time
3) Total Section Proc Time
...
8) Total Load Proc Time

If I am not mistaken, all those Proc times should be more or less the Total CPU Time. I may be mistaken in this, but I think i am not.

So he is basically saying that the request time is Total Wait TIme + Total CPU Time.
And that is precisely what is not working out for me.

By the way, something that is not clear for me. He just his monitoring statements after the query but in the same session? Or does he use an alternate session to monitor the statistics of the query?

When I used any statistical view or monitoring table function of DB2, i was under the impression that the statistics gathered were more less specific to only the runing session. When one session terminates, all the statistics are lost. So you can not gather the statistics of connection once it closes. So you either monitor those statistics inside the connection itself, or you have some other connection runing at the same time, monitoring the performance of the first connection that is runing the query.
Is this correct?
How should it be done?
Is my approach of:
1) Open a databse connection
2) Use the session 1st to gather session statistcs before a query
3) Run a query
4) Gather the session statistics after the query
5) With Java connect to databse an query the snapshot difference of (4) -(2), to know the behaviour of the query in (3).

Is this not a proper solution for BD2?

Thanks.

n_i · #4 (**permalink**) 03-31-10, 22:08

Quote:

Originally Posted by 99sono

In oracle and microsoft sql server i can easyly monitor the cpu time and wait time spend by query, by monitoring wait event and cpu time statistics before and after the query, and calculating their difference.

I think vendors put different meanings in these metrics. If you could explain what you are trying to achieve, someone would be able to give you a solution applicable for DB2.

99sono · #5 (**permalink**) 04-01-10, 04:16

Very simple:
What i want is to track the elapsed time, cpu time and wait time of a query; and afterwards to gather this information into java.

The problem is, that unlike in that blog post, when I track the total_cpu_time and total_wait_time of my connection, the cpu time and wait time statistics are nowhere close to meeting the query elapsed time. Therefore, I can not trust the statistics I measure. The values I monitor have to be close enough or surpass the elapsed time; but being inferior is just unaceptable.

sathyaram_s · #6 (**permalink**) 04-01-10, 07:42

Can you provide the example you have done, including the numbers collected.

99sono · #7 (**permalink**) 04-05-10, 03:39

Hi, sorry for the delay...
I've been away.

Bellow is the code I use to snapshot the satistics of my session runing the query:

Code:

connect to face5db@

UPDATE COMMAND OPTIONS USING c OFF@

---------------------------
-- SNAPSHOT BEFORE QUERY:
---------------------------

DROP TABLE MY_OTHER_STATS_START@
CREATE TABLE MY_OTHER_STATS_START ( CTIME timestamp, CPU_TIME_SEC  double, WAIT_TIME_SEC double, CACHE_SIZE_BYTES int, CACHE_HIT_RATIO double) IN USERSPACE1 NOT LOGGED INITIALLY@
INSERT INTO
MY_OTHER_STATS_START
SELECT CURRENT TIMESTAMP as CTIME, CPU_TIME_SEC, WAIT_TIME_SEC, CACHE_SIZE_BYTES, CACHE_HIT_RATIO
FROM
	(SELECT CAST(SUM(TOTAL_CPU_TIME) as double) / 1000000 AS CPU_TIME_SEC, CAST(SUM(TOTAL_WAIT_TIME) as double) / 1000 AS WAIT_TIME_SEC
	FROM TABLE(MON_GET_CONNECTION(null, null)) WHERE APPLICATION_NAME = 'db2bp.exe'  AND CLIENT_APPLNAME LIKE '%.sql'),
	( SELECT NPAGES * PAGESIZE AS CACHE_SIZE_BYTES FROM SYSCAT.BUFFERPOOLS WHERE BPNAME = 'IBMDEFAULTBP' ),
	(SELECT CAST(TOTAL_HIT_RATIO_PERCENT as double) AS CACHE_HIT_RATIO FROM SYSIBMADM.BP_HITRATIO WHERE BP_NAME = 'IBMDEFAULTBP')@
commit@


---------------------------
-- THE QUERY:
---------------------------
CREATE TABLE TB_TARGET (USRID int, FAVF int)
IN OUTPUTSPACE1
NOT LOGGED INITIALLY@

INSERT INTO TB_TARGET
SELECT ID as USRID, FAVF1 as FAVF
FROM PROFILE WHERE FAVF1 IS NOT NULL
UNION ALL
SELECT ID as USRID, FAVF2 AS FAVF FROM PROFILE WHERE FAVF2 IS NOT NULL
UNION ALL
SELECT ID as USRID, FAVF3 AS FAVF FROM PROFILE WHERE FAVF3 IS NOT NULL
UNION ALL
SELECT ID as USRID, FAVF4 AS FAVF FROM PROFILE WHERE FAVF4 IS NOT NULL
UNION ALL
SELECT ID as USRID, FAVF5 AS FAVF FROM PROFILE WHERE FAVF5 IS NOT NULL
@
commit@


---------------------------
-- SNAPSHOT AFTER QUERY:
---------------------------
DROP TABLE MY_OTHER_STATS_END@
CREATE TABLE MY_OTHER_STATS_END ( CTIME timestamp, CPU_TIME_SEC  double, WAIT_TIME_SEC double, CACHE_SIZE_BYTES int, CACHE_HIT_RATIO double) IN USERSPACE1 NOT LOGGED INITIALLY@
INSERT INTO
MY_OTHER_STATS_END
SELECT CURRENT TIMESTAMP as CTIME, CPU_TIME_SEC, WAIT_TIME_SEC, CACHE_SIZE_BYTES, CACHE_HIT_RATIO
FROM
	(SELECT CAST(SUM(TOTAL_CPU_TIME) as double) / 1000000 AS CPU_TIME_SEC, CAST(SUM(TOTAL_WAIT_TIME) as double) / 1000 AS WAIT_TIME_SEC
	FROM TABLE(MON_GET_CONNECTION(null, null)) WHERE APPLICATION_NAME = 'db2bp.exe'  AND CLIENT_APPLNAME LIKE '%.sql'),
	( SELECT NPAGES * PAGESIZE AS CACHE_SIZE_BYTES FROM SYSCAT.BUFFERPOOLS WHERE BPNAME = 'IBMDEFAULTBP' ),
	(SELECT CAST(TOTAL_HIT_RATIO_PERCENT as double) AS CACHE_HIT_RATIO FROM SYSIBMADM.BP_HITRATIO WHERE BP_NAME = 'IBMDEFAULTBP')@
commit@

DROP TABLE MY_DATAFILE_STATS_END@
CREATE TABLE MY_DATAFILE_STATS_END (
	ID int GENERATED ALWAYS AS IDENTITY (START WITH 1, INCREMENT BY 1),TBSP_NAME  VARCHAR(20), TBSP_PAGE_SIZE int, PREADS int, PWRITES int) IN USERSPACE1 NOT LOGGED INITIALLY@


UPDATE COMMAND OPTIONS USING c ON@

terminate@

In this code i just put the statistics for the CPU time and wait time events snapshots, which is the one that is givin me problems. I've cut out the snapshots of the tablespace satistics as there the results seem to be correct.

Once that script finishes executing. Java connects to the database an calculates the snapshot difference of CTIME (current time), cpu time and wait time statistics.

I do NOT calculate any snapshot difference between the cache hit ratio and buffer size statistics, of course.

So that's it.

Now that I am back, I am going to try to something similar but calculating the total cpu time based on all the _PROC statistics that the blog referred. It may improve my results.

99sono · #8 (**permalink**) 04-06-10, 04:44

Well, I doesn't matter any longer.
I finally managed to get coherent CPU times and Wait Time statistics by ignoring the TOTAL_CPU_TIME, and going for the TOTAL_COMMIT_PROC_TIME, and the rest of such statistics.
I followed the scripts used in that blog post you indicated, and those worked fine.

So now I can finally start to benchmark a few queries.

Thanks!

Internet Services

Web Development

Digital Marketing

Consumer Tech