This started as a conversation with a couple of DBA friends when we were playing with MONREPORT.DBSUMMARY. That’s a pretty nifty way to get a quick look at a number of performance parameters, AND to limit the time period covered by the report. But the thing we noticed and were talking about is the difference between activities and requests. In MONREPORT.DBSUMMARY output, there are several sections that note metrics either by activity or by request, or even contrast the two. Here are a couple of examples:
Wait times -------------------------------------------------------------------------------- -- Wait time as a percentage of elapsed time -- % Wait time/Total time --- ---------------------------------- For requests 6 4631/72895 For activities 0 309/58995
…
Application performance database-wide -------------------------------------------------------------------------------- TOTAL_CPU_TIME TOTAL_ TOTAL_APP_ ROWS_READ + per request WAIT_TIME % COMMITS ROWS_MODIFIED ---------------------- ----------- ------------- ---------------------------- 493 6 10480 4791003
I went to some experts at IBM and got some differing answers. If I’m confused, and the experts are confused, that’s a pretty good indication for a great topic for a blog entry. I decided to do some detective work and to write it up. I understand things better when I write about them. A hazard of being a blogger, I suppose.
First, I’ll go through the various metrics I’ll be looking at, then some experiments to see what counts as a activity and what counts in the various categories.
Metrics
When I dug into the data that MONREPORT.DBSUMMARY is based on – MON_GET_WORKLOAD – I found more metrics than just “activities” and “requests”. Below are the monitoring elements (columns in MON_GET_WORKLOAD) that I’ll be looking at, grouped by whether they’re related to activities or requests.
Activities
Activities are described by the IBM DB2 Information Center as being created each time DB2 executes the access plan for an SQL or XQuery Statement or executes the LOAD utility. Note that much of this general description of activities comes from that IBM DB2 Information Center page. Things that count as activities are:
- DML Statements
- DDL Statements
- Call Statements
- LOAD Statements
Activities do not include actions such as connecting to the database, or even compiling the SQL into an access plan.
A SELECT statement is only one activity, even if there are multiple FETCH operations from a cursor. The activity begins with the OPEN and ends with the CLOSE of the statement. This includes statements using WITH HOLD that may span multiple units of work.
A CALL statement is one activity, but it may spawn nested activities. Stored procedures create statements as follows:
Stored Procedure Contains | Nested activities spawned |
No SQL Statements | 0 |
Only one SQL Statement | 1 |
SQL procedures, multiple SQL statements, and looping logic | Multiple activities – one for each statement |
Calls of other stored procedures | Activities for that stored procedure and additional nested activities |
When an SQL statement involves the execution of a user defined function(UDF) or of a trigger, then the activity of that UDF or trigger is included in the activity of the statement – there is no separate activity spawned.
A LOAD will generate several activities – one for the LOAD, and others.
ACT_ABORTED_TOTAL
IBM DB2 Information Center monitor element page: http://www.ibm.com/support/knowledgecenter/SSEPGG_10.1.0/com.ibm.db2.luw.admin.mon.doc/doc/r0054006.html
I want to track failed operations as well as successful ones in this exercise. The info Center indicates that this element can be used to understand if activities on the system are completing successfully, with reasons for failure including cancellation, errors, or threshold violations. I’m not using WLM in this detective work.
ACT_COMPLETED_TOTAL
IBM DB2 Information Center monitor element page: http://www.ibm.com/support/knowledgecenter/SSEPGG_10.1.0/com.ibm.db2.luw.admin.mon.doc/doc/r0054007.html
This element appears to be a simple counter of the number of activities that are completed.
ACT_REJECTED_TOTAL
IBM DB2 Information Center monitor element page: http://www.ibm.com/support/knowledgecenter/SSEPGG_10.1.0/com.ibm.db2.luw.admin.mon.doc/doc/r0054008.html
I’m actually not going to track this one in my examples, but I thought I’d mention it. If you’re using WLM to limit things, then you might have some activities that are rejected due to a threshold being exceeded. I’m not using WLM in this example.
TOTAL_ACT_TIME
IBM DB2 Information Center monitor element page: http://www.ibm.com/support/knowledgecenter/SSEPGG_10.1.0/com.ibm.db2.luw.admin.mon.doc/doc/r0054077.html
As long as I’m tracking this stuff, I thought I’d look at the time spent, as it may give me some additional understanding of what happens where. Note that this is only the time that DB2 spends actively executing the activity – to get the total time, you’d have to add this to the next one – TOTAL_ACT_WAIT_TIME. It seems to me that this one is mis-named. I feel like it should be total_act_exec_time.
TOTAL_ACT_WAIT_TIME
IBM DB2 Information Center monitor element page: http://www.ibm.com/support/knowledgecenter/SSEPGG_10.1.0/com.ibm.db2.luw.admin.mon.doc/doc/r0054078.html
This is the amount of time that the activity spends waiting, when added to TOTAL_ACT_TIME, you can get the total activity time.
APP_ACT_ABORTED_TOTAL
IBM DB2 Information Center monitor element page: http://www.ibm.com/support/knowledgecenter/SSEPGG_10.1.0/com.ibm.db2.luw.admin.dbobj.doc/doc/c0059094.html
This seems to relate to the number of non-nested activities, so this could be interesting to play with.
APP_ACT_COMPLETED_TOTAL
IBM DB2 Information Center monitor element page:http://www.ibm.com/support/knowledgecenter/SSEPGG_10.1.0/com.ibm.db2.luw.admin.mon.doc/doc/r0059566.html
This seems to relate to the number of non-nested activities, so this could be interesting to play with.
Requests
The IBM DB2 Information Center describes requests as including activities – activities are a subset of requests. I think that means that requests include things like PREPARE statements. It will be interesting to see if one request includes multiple activities or if some greater number of requests are generated for a set of activities. Requests also appear to have less representation in event monitors than activities do. I believe the following would count as individual requests, while a single activity starts with OPEN and ends with CLOSE regardless of the number of FETCHes:
- PREPARE
- OPEN
- DESCRIBE
- FETCH
- CLOSE
- COMMIT
Generally, IBM is expecting activities to be more interesting to us than requests.
RQSTS_COMPLETED_TOTAL
IBM DB2 Information Center monitor element page: http://www.ibm.com/support/knowledgecenter/SSEPGG_10.1.0/com.ibm.db2.luw.admin.mon.doc/doc/r0054049.html
The total number of completed requests.
TOTAL_RQST_TIME
IBM DB2 Information Center monitor element page: http://www.ibm.com/support/knowledgecenter/SSEPGG_10.1.0/com.ibm.db2.luw.admin.mon.doc/doc/r0054060.html
Total time spent on requests in milliseconds
APP_RQSTS_COMPLETED_TOTAL
IBM DB2 Information Center monitor element page: http://www.ibm.com/support/knowledgecenter/SSEPGG_10.1.0/com.ibm.db2.luw.admin.mon.doc/doc/r0054011.html
Total number of app requests completed.
Experiments
To understand these, I’m doing simple work against the standard SAMPLE database (because it’s hard to restrict other activity against any other database just for experimental purposes). I’ll deactivate and activate the database between experiments to make sure that the counters are reset.
SQL Used
Here is the SQL I’m using to collect the data discussed above:
select substr(workload_name,1,24) as workload_name , ACT_ABORTED_TOTAL , ACT_COMPLETED_TOTAL , ACT_REJECTED_TOTAL , TOTAL_ACT_TIME , TOTAL_ACT_WAIT_TIME , APP_ACT_ABORTED_TOTAL , APP_ACT_COMPLETED_TOTAL , RQSTS_COMPLETED_TOTAL , TOTAL_RQST_TIME , APP_RQSTS_COMPLETED_TOTAL from table (mon_get_workload(NULL, -2)) as t order by workload_name desc with ur;
To make it look pretty for the blog, I’m pasting the results in as images
Just connecting
Here’s what it looks like simply issuing a connect statement and the SQL to collect the data:
We can see here that my simple connect comprised 1 activity, but 8 requests. My activity time was nothing, but my request time was 922 milliseconds. This connect would have included a database activation, so my guess it that perhaps the requests included some of the overhead with database activation. Results were similar on a repetition of this test.
Simple Query
This test includes the following:
db2 connect to sample db2 "select * from db2inst1.employee"
Results below:
For this one, we see two activities – one for the connect, and one for the query. We see 13 requests. Presumably 8 are for the connect. 5 requests for one query. We would have had to compile it, they must be related to those interim steps.
Effect of Isolation Level
I’m curious as to whether the results would change if I used the uncommitted read isolation level, so for this test, I used:
db2 connect to sample db2 "select * from db2inst1.employee with ur"
Results below:
Still 2 activities and 13 requests – no difference. Not surprising, but I was curious.
Select From System View
Will querying a system view increase the number of requests over a simple query of a single table. So this iteration focuses on:
db2 connect to sample db2 "select * from syscat.bufferpools"
And here are the results:
Same result – 2 activities and 13 requests
So from the last few tests, it looks to me like standard queries including connection will be two requests and 13 activities
Something more complicated
How about turing this thing on itself? Next, I wanted to try seeing the activities/requests of monreport.dbsummary – which is calling a stored procedure and all the actions taken within that procedure.
Actions taken:
db2 connect to sample db2 "call monreport.dbsummary(60)"
Results:
And holy cow, was that more complicated. Notice there are still only 2 “APP_ACT_COMPLETED TOTAL” or parent activities as I’m starting to think of them. But 651 activities, that’s quite a jump. Note that in this case, the number of requests is far lower than activities at just 16. What the heck is that all about?
LOAD
Finally, I was curious how activities and requests looked during a load. So in the SAMPLE database, I did the following:
db2 "export to employee.del of del select * from employee" db2 create table employee_copy like employee
Then I deactivated and reactivated the database to clear out any counters.
I want to compare what it looks like in an import vs. a LOAD. I did the import like this:
$ db2 import from employee.del of del insert into employee_copy SQL3109N The utility is beginning to load data from file "employee.del". SQL3110N The utility has completed processing. "42" rows were read from the input file. SQL3221W ...Begin COMMIT WORK. Input Record Count = "42". SQL3222W ...COMMIT of any database changes was successful. SQL3149N "42" rows were processed from the input file. "42" rows were successfully inserted into the table. "0" rows were rejected. Number of rows read = 42 Number of rows skipped = 0 Number of rows inserted = 42 Number of rows updated = 0 Number of rows rejected = 0 Number of rows committed = 42
And here’s the results for insert:
60 activities. I’m guessing that’s one for each row (42), plus one for the connect. I’m not sure where the other 17 come from.
Now I reset things and did the same thing as a load:
db2 load from employee.del of del insert into employee_copy nonrecoverable SQL3039W The memory available to LOAD for DATA BUFFER prohibits full LOAD parallelism. Load parallelism of "3" will be used SQL3109N The utility is beginning to load data from file "/db2home/db2inst1/employee.del". SQL3500W The utility is beginning the "LOAD" phase at time "01/09/2014 21:32:04.678839". SQL3519W Begin Load Consistency Point. Input record count = "0". SQL3520W Load Consistency Point was successful. SQL3110N The utility has completed processing. "42" rows were read from the input file. SQL3519W Begin Load Consistency Point. Input record count = "42". SQL3520W Load Consistency Point was successful. SQL3515W The utility has finished the "LOAD" phase at time "01/09/2014 21:32:04.927257". Number of rows read = 42 Number of rows skipped = 0 Number of rows loaded = 42 Number of rows rejected = 0 Number of rows deleted = 0 Number of rows committed = 42
I do find it interesting that a LOAD required 10 activities. I’m not sure what the other 9 are, as the Info Center implied that a LOAD is a single activity. One for a connect, but the other 8?
Summary
I hope that this has helped my readers understand the difference between activities and requests. I think the difference becomes more important as I dig into the newer monitoring interfaces, and writing this really helped me understand the difference. I still don’t understand where every activity comes from, much less every request.
Great detail! Thanks so much for this analysis.