Shawn_Moore

CA Tuesday Tip: DB Performance Reports - The AWR report - # 2: Top Queries

Discussion created by Shawn_Moore Employee on Jan 25, 2011
Latest reply on Apr 20, 2015 by matej256
CA Clarity Tuesday Tip by Shawn Moore, Sr. Principal Support Engineer for 1/25/2011

This week we are going to look at one of the more common scenarios we see. A custom query (or stored procedure in this case) that heavily impacts performance.

Here's a snippet from the AWR report.

AWR Fragment








(this is a portion of an AWR with a number of edits to generalize the scenario)








I've also attached a spreadsheet snippet of the AWR that should be easier to read. :smile

















SQL ordered by Elapsed Time

















Resources reported for PL/SQL code includes the resources used by all SQL statements called by the code.








% Total DB Time is the Elapsed Time of the SQL statement divided into the Total Database Time multiplied by 100

















[font=Courier New]Elapsed Time (s)
CPU Time (s)
Executions
Elap per Exec (s)
% Total DB Time
SQL Id
SQL Module
SQL Text

10,746
10,183
568
18.92
14.75
2f8796bdsfx9b
JDBC Connect Client
SELECT T.PRPROJECTID AS ID ...

7,101
7,097
1
7101.24
9.75
36ksdqazqpb3y
JDBC Connect Client
call EXP_ADA_MVR…

6,989
6,987
1,002
6.97
9.59
1f5kfqaqbz2yw
JDBC Connect Client
SELECT NVL(MAX(I.TRANSNO), 0) ...[font]





















SQL ordered by Gets

















Resources reported for PL/SQL code includes the resources used by all SQL statements called by the code.








Total Buffer Gets: 789,265,180








Captured SQL account for 95.7% of Total









[font=Courier New]







Buffer Gets
Executions
Gets per Exec
%Total
CPU Time (s)
Elapsed Time (s)
SQL Id
SQL Module
SQL Text
220,582,061
1
220,582,061.00
27.95
7096.77
7101.24
36ksdqazqpb3y
JDBC Connect Client
call EXP_ADA_MVR…
218,187,995
1,002
217,752.49
27.64
6986.52
6988.91
1f5kfqaqbz2yw
JDBC Connect Client
SELECT NVL(MAX(I.TRANSNO), 0) ...
[font]

In the above example we can easily see a few queries than are consuming about 35% of the total CPU time. One of them, however, stands out.

SQL id 36ksdqazqpb3y shows as taking 7101 seconds elapsed time for just 1 execution. We can gather a number of useful items from this AWR report.

1) The elapsed time is close to the CPU time which tells us that this time is straight CPU processing. I wouldn't suspect DB contention or IO at this point. These can be a factor when the Elapsed time is much different from the CPU time.
2) We can clearly see that the 7101 seconds are just for 1 execution, so this is a "big win" item, as addressing the single query will reduce the CPU load.
3) In the SQL ordered by Gets section we can see that the query generates 220.5 million gets. That is a lot of data access. I like to see "bigger" queries under about 25,000-50,000 gets.
4) Eventhough the query didn't show as the top SQL in elapsed time or CPU time, it did show as the highest in its generation of buffer gets, which in this case was 27% of the total on the DB Server.
5) The SQL Text shows us that it is a stored procedure
6) The SQL Module shows us that it was called by a JDBC Connect Client - most of the time this indicates that the query or procedure was called from within Clarity. (Since this was a stored procedure, it was likely called by a background server job)

Next week we will look at one or more other examples from an AWR report.

Shawn Moore
CA Technologies

Attachments

Outcomes