PUSH SUBQUERY

In the previous article we examined the performance benefit brought by the scalar subquery caching effect when a call to a PL/SQL function is wrapped into a select from dual. Scalar subquery caching, almost always, reduces the number of PL/SQL function recursive calls. In this article I wanted to share with you the observations I have made in the same real-life query when I replaced the call to the PL/SQL function by its content.

The real-life query running under a 12cR1 Exadata machine and using a PL/SQL function in the where clause looks like the following:

SQL> SELECT /*+ gather_plan_statistics */
2     a.xy_etp_dat_deb,
3     a.xy_etp_num,
4     a.xy_bat_id
5  FROM
6     ps_xy_exp_etp_exe a
7  WHERE
8       a.xy_bat_id = f_get_id('BJOBD176')
9   AND a.xy_etp_dat_deb = (select
10                               max(b.xy_etp_dat_deb)
11                           from ps_xy_exp_etp_exe b
12                           where a.xy_bat_id = b.xy_bat_id
13                           )
14   AND a.xy_etp_num     = (select
15                              max(c.xy_etp_num)
16                           from ps_xy_exp_etp_exe c
17                           where c.xy_bat_id    = a.xy_bat_id
18                           and c.xy_etp_dat_deb = a.xy_etp_dat_deb
19                           );

Elapsed: 00:00:01.80

Statistics
---------------------------------------------------------
18605  recursive calls
0  db block gets
297806  consistent gets
0  physical reads
0  redo size
482  bytes sent via SQL*Net to client
372  bytes received via SQL*Net from client
2  SQL*Net roundtrips to/from client
1  sorts (memory)
0  sorts (disk)
1  rows processed

Instead of surrounding the PL/SQL function at line 8 by a “select from dual” as explained in the previous article, I decided to use its content directly into the where clause as shown below at line 8:

SQL> SELECT /*+ gather_plan_statistics */
2     a.xy_etp_dat_deb,
3     a.xy_etp_num,
4     a.xy_bat_id
5  FROM
6     ps_xy_exp_etp_exe a
7  WHERE
8       a.xy_bat_id = (select xy_bat_id from ps_xy_exp_bat where xy_bat_nom = 'BJOBD176')
9  AND a.xy_etp_dat_deb = (select
10                               max(b.xy_etp_dat_deb)
11                           from ps_xy_exp_etp_exe b
12                           where a.xy_bat_id = b.xy_bat_id
13                          )
14   AND a.xy_etp_num     = (select
15                              max(c.xy_etp_num)
16                           from ps_xy_exp_etp_exe c
17                           where c.xy_bat_id    = a.xy_bat_id
18                           and c.xy_etp_dat_deb = a.xy_etp_dat_deb
19                           );
Elapsed: 00:00:00.04

Statistics
-------------------------------------------------------
0  recursive calls
0  db block gets
142  consistent gets
0  physical reads
0  redo size
482  bytes sent via SQL*Net to client
372  bytes received via SQL*Net from client
2  SQL*Net roundtrips to/from client
1  sorts (memory)
0  sorts (disk)
1  rows processed

As you can see, replacing the PL/SQL function call by its content has eliminated the number of recursive calls as we went from 18506 recursive to 0 call and from 2 seconds to 4 milliseconds.

Let’s try to understand what happened so that we got such a performant improvement. First the row source execution plan (for the sake of simplicity I am using the predicate part taken from the explain plan for command):

Plan hash value: 408154845
------------------------------------------------------------------------------------------------
| Id  | Operation                               | Name              | Starts | E-Rows | A-Rows |
------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                        |                   |      1 |        |      1 |
|*  1 |  FILTER                                 |                   |      1 |        |      1 |
|*  2 |   HASH JOIN                             |                   |      1 |      1 |      1 |
|*  3 |    TABLE ACCESS STORAGE FULL            | PS_XY_EXP_ETP_EXE |      1 |     63 |     76 |
|*  4 |     TABLE ACCESS STORAGE FULL FIRST ROWS| PS_XY_EXP_BAT     |      1 |      1 |      1 |
|   5 |    VIEW                                 | VW_SQ_1           |      1 |    296 |    296 |
|   6 |     SORT GROUP BY                       |                   |      1 |    296 |    296 |
|   7 |      TABLE ACCESS STORAGE FULL          | PS_XY_EXP_ETP_EXE |      1 |  18697 |  18605 |
|   8 |   SORT AGGREGATE                        |                   |      1 |      1 |      1 |
|*  9 |    TABLE ACCESS STORAGE FULL            | PS_XY_EXP_ETP_EXE |      1 |      1 |      1 |
------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("A"."XY_ETP_NUM"= (SELECT MAX("C"."XY_ETP_NUM") FROM "PS_XY_EXP_ETP_EXE" "C" WHERE
"C"."XY_ETP_DAT_DEB"=:B1 AND "C"."XY_BAT_ID"=:B2))
2 - access("A"."XY_ETP_DAT_DEB"="MAX(B.XY_ETP_DAT_DEB)" AND "A"."XY_BAT_ID"="ITEM_1")
3 - storage("A"."XY_BAT_ID"= (SELECT "XY_BAT_ID" FROM "PS_XY_EXP_BAT" "PS_XY_EXP_BAT" WHERE
"XY_BAT_NOM"='BJOBD176'))
filter("A"."XY_BAT_ID"= (SELECT "XY_BAT_ID" FROM "PS_XY_EXP_BAT" "PS_XY_EXP_BAT" WHERE
"XY_BAT_NOM"='BJOBD176'))
4 - storage("XY_BAT_NOM"='BJOBD176')
filter("XY_BAT_NOM"='BJOBD176')
9 - filter("C"."XY_ETP_DAT_DEB"=:B1 AND "C"."XY_BAT_ID"=:B2)

That’s a weird non-common execution plan, right?

How could it be differently when we see these two unusual operations at lines Id n°3 and n°4?

Usually, a PARENT-CHILD operation is, for example, an index feeding its parent table with ROWIDS which, then, get filtered by the parent table access by index ROWID. But, here, we have a parent TABLE ACCESS STORAGE FULL of PS_XY_EXP_ETP_EXE at line Id n°3 and an unrelated child operation TABLE ACCESS STORAGE FULL FIRST ROWS of table PS_XY_EXP_BAT at line Id n°4.

What I, very often do, when trying to understand what cunning transformation has been done by Oracle behind the scenes is to check the outline section of the execution plan:

Outline Data
-------------

/*+
BEGIN_OUTLINE_DATA
IGNORE_OPTIM_EMBEDDED_HINTS
OPTIMIZER_FEATURES_ENABLE('12.1.0.2')
DB_VERSION('12.1.0.2')
../..
OUTLINE(@"SEL$3")
OUTLINE(@"SEL$BD9E0841")
OUTLINE(@"SEL$1")
FULL(@"SEL$B9151BA2" "A"@"SEL$1")
NO_ACCESS(@"SEL$B9151BA2" "VW_SQ_1"@"SEL$BD9E0841")
LEADING(@"SEL$B9151BA2" "A"@"SEL$1" "VW_SQ_1"@"SEL$BD9E0841")
USE_HASH(@"SEL$B9151BA2" "VW_SQ_1"@"SEL$BD9E0841")
PUSH_SUBQ(@"SEL$2")                              --> this is where the subuqery is pushed
PQ_FILTER(@"SEL$B9151BA2" SERIAL)
FULL(@"SEL$291F8F59" "B"@"SEL$3")
FULL(@"SEL$4" "C"@"SEL$4")
END_OUTLINE_DATA
*/

Indeed, there is that hint PUSH_SUBQ(@”SEL$2″) which indicates that he scalar subquery against PS_XY_EXP_BAT table has been first evaluated once (Starts =1, Id operation n°4) and then, the result of this evaluation, has been pushed as a predicate against the PS_XY_EXP_ETP_EXE table (Id operation n°3). And this is exactly what made PS_XY_EXP_BAT table a child subordinate action to PS_XY_EXP_ETP_EXE parent table.

If Oracle had not pushed the scalar subquery down the execution plan tree, it would have produced the following execution plan:

explain plan for
SELECT
a.xy_etp_dat_deb,
a.xy_etp_num,
a.xy_bat_id
FROM
ps_xy_exp_etp_exe a
WHERE
a.xy_bat_id = (select /*+ NO_PUSH_SUBQ(@"SEL$2")*/ xy_bat_id from ps_xy_exp_bat where xy_bat_nom = 'BJOBD176')
AND a.xy_etp_dat_deb = (select
max(b.xy_etp_dat_deb)
from ps_xy_exp_etp_exe b
where a.xy_bat_id = b.xy_bat_id)
AND a.xy_etp_num     = (select
max(c.xy_etp_num)
from ps_xy_exp_etp_exe c
where c.xy_bat_id    = a.xy_bat_id
and c.xy_etp_dat_deb = a.xy_etp_dat_deb);

Plan hash value: 1136506203
----------------------------------------------------------------------------------------------
| Id  | Operation                             | Name              | Starts | E-Rows | A-Rows |
----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                      |                   |      1 |        |      1 |
|*  1 |  FILTER                               |                   |      1 |        |      1 |
|*  2 |   HASH JOIN                           |                   |      1 |    296 |    296 |
|*  3 |    HASH JOIN                          |                   |      1 |    296 |    318 |
|   4 |     VIEW                              | VW_SQ_1           |      1 |    296 |    296 |
|   5 |      SORT GROUP BY                    |                   |      1 |    296 |    296 |
|   6 |       TABLE ACCESS STORAGE FULL       | PS_XY_EXP_ETP_EXE |      1 |  18697 |  18605 |--1
|   7 |     TABLE ACCESS STORAGE FULL         | PS_XY_EXP_ETP_EXE |      1 |  18697 |  18605 |
|   8 |    VIEW                               | VW_SQ_2           |      1 |  18697 |  17933 |
|   9 |     SORT GROUP BY                     |                   |      1 |  18697 |  17933 |
|  10 |      TABLE ACCESS STORAGE FULL        | PS_XY_EXP_ETP_EXE |      1 |  18697 |  18605 |
|* 11 |   TABLE ACCESS STORAGE FULL FIRST ROWS| PS_XY_EXP_BAT     |      1 |      1 |      1 |
----------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("A"."XY_BAT_ID"= (SELECT /*+ NO_PUSH_SUBQ */ "XY_BAT_ID" FROM "PS_XY_EXP_BAT"
"PS_XY_EXP_BAT" WHERE "XY_BAT_NOM"='BJOBD176'))
2 - access("A"."XY_ETP_NUM"="MAX(C.XY_ETP_NUM)" AND "ITEM_2"="A"."XY_BAT_ID" AND
"ITEM_3"="A"."XY_ETP_DAT_DEB")
3 - access("A"."XY_ETP_DAT_DEB"="MAX(B.XY_ETP_DAT_DEB)" AND "A"."XY_BAT_ID"="ITEM_1")
11 - storage("XY_BAT_NOM"='BJOBD176')
filter("XY_BAT_NOM"='BJOBD176')

Notice now how the scalar subquery has been left until all the other predicates have been applied to the parent query block (operation Id n°1). This is the case where the subquery is evaluated as a FILTER predicate for every row in the result set. In the PUSH_SUBQ former case, Oracle runs the subquery for each row in PS_XY_EXP_ETP_EXE table and join the 76 survived rows with the rest of the data. This means that when the subquery has been pushed, the first operation in the execution plan tree has eliminated almost all rows and kept only 76. However, in the NO_PUSH_SUBQ case, the first operation(id n°6 in plan with plan hash value 1136506203) in the execution plan produced 18605 rows. Since Oracle started bigger, more data have then to be carried out through the rest of the plan causing, consequently, more work and more time.

Summary

Through two distinct articles, we’ve examined a performance issue of a real-life query using a PL/SQL function in one of its WHERE clause to FILTER rows from the parent query block. In the first article we outlined how we can take benefit from scalar subquery cache effect simply by surrounding the PL/SQL function call with a SELECT FROM DUAL. In the second article (current one) we examined how sometimes it is better to replace the PL/SQL function by its content in the scalar subquery WHERE clause. Proceeding as such, we can offer the Oracle optimizer engine the possibility to push the result of the scalar subquery where clause deeper in the execution plan path; filtering, as such, non-qualified rows much earlier and carrying less data through the rest of the execution plan.

Scalar subquery caching : the select from dual trick

This short note explains why you should think about wrapping your PL/SQL function calls in a SELECT FROM DUAL so that you will get the performance benefit of scalar subquery caching whenever possible.

Recursive calls

Here’s below a real-life query running under a 12cR1 Exadata machine and using a call to a PL/SQL function in line number 8 below:

SQL> SELECT /*+ gather_plan_statistics */
2     a.xy_etp_dat_deb,
3     a.xy_etp_num,
4     a.xy_bat_id
5  FROM
6     sp_xy_exp_etp_exe a
7  WHERE
8       a.xy_bat_id = f_get_id('BJOBD176')
9   AND a.xy_etp_dat_deb = (select
10                               max(b.xy_etp_dat_deb)
11                           from sp_xy_exp_etp_exe b
12                           where a.xy_bat_id = b.xy_bat_id
13                           )
14   AND a.xy_etp_num     = (select
15                              max(c.xy_etp_num)
16                           from sp_xy_exp_etp_exe c
17                           where c.xy_bat_id    = a.xy_bat_id
18                           and c.xy_etp_dat_deb = a.xy_etp_dat_deb
19                           );

Elapsed: 00:00:01.82

Statistics
----------------------------------------------------------
18605  recursive calls
0  db block gets
297806  consistent gets
0  physical reads
0  redo size
482  bytes sent via SQL*Net to client
372  bytes received via SQL*Net from client
2  SQL*Net roundtrips to/from client
1  sorts (memory)
0  sorts (disk)
1  rows processed

I was immediately intrigued by the 18605 recursive calls that were systematically appearing at each execution of the above query. Therefore, I started trying to figure out the root cause of those recursive calls. The corresponding row-source execution plan is:

Plan hash value: 1967369873
--------------------------------------------------------------------------------------
| Id  | Operation                     | Name              | Starts | E-Rows | A-Rows |
--------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |                   |      1 |        |      1 |
|*  1 |  FILTER                       |                   |      1 |        |      1 |
|*  2 |   HASH JOIN                   |                   |      1 |      1 |      1 |
|*  3 |    TABLE ACCESS STORAGE FULL  | SP_XY_EXP_ETP_EXE |      1 |     63 |     76 | --> this
|   4 |    VIEW                       | VW_SQ_1           |      1 |    296 |    296 |
|   5 |     SORT GROUP BY             |                   |      1 |    296 |    296 |
|   6 |      TABLE ACCESS STORAGE FULL| SP_XY_EXP_ETP_EXE |      1 |  18697 |  18605 | --> this
|   7 |   SORT AGGREGATE              |                   |      1 |      1 |      1 |
|*  8 |    TABLE ACCESS STORAGE FULL  | SP_XY_EXP_ETP_EXE |      1 |      1 |      1 |
--------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("A"."XY_ETP_NUM"=)
2 - access("A"."XY_ETP_DAT_DEB"="MAX(B.XY_ETP_DAT_DEB)" AND "A"."XY_BAT_ID"="ITEM_1")
3 - filter("A"."XY_BAT_ID"="F_GET_ID"('BJOBD176'))
8 - filter(("C"."XY_ETP_DAT_DEB"=:B1 AND "C"."XY_BAT_ID"=:B2))

I don’t think that the 18605 A-Rows at operation Id n°6 and the 18605 recursive calls are a result of a mere coincidence. They are inevitably related to each other. Let’s then try to find out this relationship. One way to do that is to look at a 10046-trace of the above query:

SQL> alter session set tracefile_identifier ='QueryRecursiveCalls';

SQL> @46on 12
SQL –- execute query here
SQL> @46off

The TKRPOFED trace file shows the followings:

SELECT /*+ gather_plan_statistics */
a.xy_etp_dat_deb,
a.xy_etp_num,
a.xy_bat_id
FROM
sp_xy_exp_etp_exe a
WHERE
a.xy_bat_id = f_get_id('BJOBD176')
AND a.xy_etp_dat_deb = (select
max(b.xy_etp_dat_deb)
from sp_xy_exp_etp_exe b
where a.xy_bat_id = b.xy_bat_id)
AND a.xy_etp_num     = (select
max(c.xy_etp_num)
from sp_xy_exp_etp_exe c
where c.xy_bat_id    = a.xy_bat_id
and c.xy_etp_dat_deb = a.xy_etp_dat_deb)

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.02       0.02          0         12          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.02       0.02          0         12          0           0

SQL ID: 5gb8jzxq0zcj4 Plan Hash: 1613371837

SELECT XY_BAT_ID
FROM
SP_XY_EXP_BAT WHERE XY_BAT_NOM = :B1

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute  11146      0.93       0.95          0          0          0           0
Fetch    11146      0.83       0.90          0     178336          0       11146
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    22293      1.77       1.85          0     178336          0       11146

As you we can see, there is a recursive SELECT against SP_XY_EXP_BAT table consuming almost all the total time of the query (1.85 seconds). This recursive SELECT, identified by SQL_ID 5gb8jzxq0zcj4, is nothing else than the content of the PL/SQL function used in line number 8 of the original main query and which I am reproducing here below:

WHERE
a.xy_bat_id = f_get_id('BJOBD176');

The capital bind variable :B1 in the TKPROF trace file represents another indication of a SQL embedded in PL/SQL. I can even get the captured value of this bind variable as shown below:

col value_string format a10
col last_captured format a20
select
last_captured
,value_string
from
v$sql_bind_capture
where sql_id = '5gb8jzxq0zcj4';

LAST_CAPTURED        VALUE_STRI
-------------------- ----------
05/08/19             BJOBD176

While the number of executions of the recursive SELECT shown in the TKPROF (11,146) is not exactly the number I was expecting i.e. 18,605, I can, nevertheless, see that the number of executions of the corresponding SQL_ID (5gb8jzxq0zcj4) stored in memory is exactly 18,605

SQL> @gv$sql
Enter value for sql_id: 5gb8jzxq0zcj4

SQL_ID        CHILD_NUMBER PLAN_HASH_VALUE TO_CHAR(P.LAST_ACTI EXECUTIONS
------------- ------------ --------------- ------------------- ----------
5gb8jzxq0zcj4            0      1613371837 05/08/2019 11:27:19      18605

So far, we have identified that the 18605 recursive calls represent simply the 18605 executions of predicate n°3 above which involves the call to the PL/SQL function. But what is, exactly, the relationship between those 18605 recursive calls and the 18605 A-Rows of line 6 in the above execution plan?

The 18605 recursive calls are strongly related to the number of rows present in the SP_XY_EXP_ETP_EXE table.

SQL> select count(1) from SP_XY_EXP_ETP_EXE;

COUNT(1)
----------
18605

Indeed, the PL/SQL function was called as many times as there are rows in this table producing 76 rows as confirmed via the A-Rows column of operation at line n°3 in the above execution plan:

SQL> select count(1) from SP_XY_EXP_ETP_EXE
where xy_bat_id = f_get_id('BJOBD176');

COUNT(1)
----------
76

How to fix the problem while still using the PL/SQL function?

The problem resorts to the multiple executions (18605) of the predicate n°3 on table SP_XY_EXP_ETP_EXE:

3 - filter("A"."XY_BAT_ID"="F_GET_ID"('BJOBD176'))

This happens even though the input to the function, BJOBD176, is constant.

If we surround the call to that function with a SELECT FROM DUAL Oracle will use scalar subquery caching producing, as such, a massive reduction in the number of calls to that function as the following proves:

SELECT /*+ gather_plan_statistics */
a.xy_etp_dat_deb,
a.xy_etp_num,
a.xy_bat_id
FROM
sp_xy_exp_etp_exe a
WHERE
a.xy_bat_id = (select f_get_id('BJOBD176') from dual)
AND a.xy_etp_dat_deb = (select
max(b.xy_etp_dat_deb)
from sp_xy_exp_etp_exe b
where a.xy_bat_id = b.xy_bat_id
)
AND a.xy_etp_num     = (select
max(c.xy_etp_num)
from sp_xy_exp_etp_exe c
where c.xy_bat_id    = a.xy_bat_id
and c.xy_etp_dat_deb = a.xy_etp_dat_deb
);

Elapsed: 00:00:00.02 --> drastic execution time reduction
--------------------------------------------------------------------------------------
| Id  | Operation                     | Name              | Starts | E-Rows | A-Rows |
--------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |                   |      1 |        |      1 |
|*  1 |  FILTER                       |                   |      1 |        |      1 |
|*  2 |   HASH JOIN                   |                   |      1 |      1 |      1 |
|*  3 |    TABLE ACCESS STORAGE FULL  | SP_XY_EXP_ETP_EXE |      1 |     63 |     76 |
|   4 |     FAST DUAL                 |                   |      1 |      1 |      1 |
|   5 |    VIEW                       | VW_SQ_1           |      1 |    296 |    296 |
|   6 |     SORT GROUP BY             |                   |      1 |    296 |    296 |
|   7 |      TABLE ACCESS STORAGE FULL| SP_XY_EXP_ETP_EXE |      1 |  18697 |  18605 |
|   8 |   SORT AGGREGATE              |                   |      1 |      1 |      1 |
|*  9 |    TABLE ACCESS STORAGE FULL  | SP_XY_EXP_ETP_EXE |      1 |      1 |      1 |
--------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("A"."XY_ETP_NUM"=)
2 - access("A"."XY_ETP_DAT_DEB"="MAX(B.XY_ETP_DAT_DEB)" AND"A"."XY_BAT_ID"="ITEM_1")
3 - storage("A"."XY_BAT_ID"=)
filter("A"."XY_BAT_ID"=)
9 - filter(("C"."XY_ETP_DAT_DEB"=:B1 AND "C"."XY_BAT_ID"=:B2))

Statistics
----------------------------------------------------------
1  recursive calls
0  db block gets
142  consistent gets
0  physical reads
0  redo size
482  bytes sent via SQL*Net to client
372  bytes received via SQL*Net from client
2  SQL*Net roundtrips to/from client
1  sorts (memory)
0  sorts (disk)
1  rows processed

Surrounding the call to the function with a select from dual allows Oracle to cache the result of the function for identical results. Therefore, the number of recursive calls drops from 18605 to only a single call and the query completes in about 2 milli-seconds instead of 2 seconds when scalar subquery caching was not possible.

Summary

As explained by Tom Kyte in this excellent article I can confirm that I have, almost always, improved the performance of my queries when I wrapped the PL/SQL function call into a SELECT FROM DUAL. This trick allows us to get the performance benefit of the scalar subquery cache.
In the next article I will show you what happens to the real-life query when I have replaced the PL/SQL function call by its content.

AWR bulk collect

There are many posts out there explaining how to collect a bunch of AWR reports which I could have just referenced and leave it there, but as much for my own documentation as anything else, I decided to write this simple note as an answer to my client request of generating and analyzing 49 one-hour AWR reports.

First, the SQL script to generate a bulk of AWR reports between two dates:

-- +----------------------------------------------------------------------------+
-- | Author : Mohamed Houri                                                     |
-- |----------------------------------------------------------------------------|
-- | DATABASE : 12cR1                                                           |
-- | Name     : AwrBulkcollect.sql                                              |
-- | PURPOSE  : Dynamically create a SQL script to generate a list of AWR       |
-- |            reports between two snapshots dates.                            |
-- | NOTE     : As with any code, ensure to test this script in a development   |
-- |            environment before attempting to run it in production.          |
-- | Remarks : CHR(10) adds a new line                                          |
-- |           SET termout off so that AWR content will not be displayed        |
-- |           For RAC configuration consider the instance number               |       
-- |          Enter input date in this format :'mmddyyyy hh24:mi:ss'            |
-- |                                                                            |
-- ------------------------------------------------------------------------------
set termout off
set head off
set define off
spool collectAWRs.sql

SELECT
    'spool awr_XYZ_inst_1_'
    || t.si
    || '_'
    || t.se
    || '.text '
    || CHR(10)
    || 'SELECT * FROM TABLE(dbms_workload_repository.awr_report_text('
    || t.dbid
    || ','
    || t.instance_number
    || ','
    || t.si
    || ','
    || t.se
    || '));'
    || CHR(10)
    || ' spool off;'
FROM
    (SELECT
            dbid,
            snap_id si,
            snap_id + 1 se,
            instance_number
     FROM
            dba_hist_snapshot
     WHERE
            begin_interval_time >   TO_DATE('27102019 18:00:00', 'ddmmyyyy hh24:mi:ss')
      AND end_interval_time   <=  TO_DATE('27102019 19:30:00', 'ddmmyyyy hh24:mi:ss')
      AND  instance_number = 1
      ) t;
	
spool off;
-- +-------------------------------------+	
  prompt running collectAWRs.sql script |
-- +-------------------------------------+
@collectAWRs.sql

Depending on the number of snapshots found between the two entered dates the output of the script might look like the following:

spool awr_XYZ_inst_1_11923_11924.text                                                                                   
SELECT * FROM TABLE(dbms_workload_repository.awr_report_text(4209020461,1,11923,11924));                                
spool off;                                                                                                             
                                                                                                                        
spool awr_XYZ_inst_1_11922_11923.text                                                                                   
SELECT * FROM TABLE(dbms_workload_repository.awr_report_text(4209020461,1,11922,11923));                                
spool off;     

etc.…

When the script ends you can see such a list of AWR files

Mode                LastWriteTime         Length Name
----                -------------         ------ ----
-a----       10/28/2019   2:45 PM         451751 awr_XYZ_inst_1_11946_11947.text
-a----       10/28/2019   2:46 PM         464089 awr_XYZ_inst_1_11952_11953.text
-a----       10/28/2019   2:47 PM         446377 awr_XYZ_inst_1_11945_11946.text
-a----       10/28/2019   2:48 PM         494261 awr_XYZ_inst_1_11949_11950.text
-a----       10/28/2019   2:49 PM         447109 awr_XYZ_inst_1_11954_11955.text
-a----       10/28/2019   2:50 PM         440269 awr_XYZ_inst_1_11956_11957.text
-a----       10/28/2019   2:51 PM         448697 awr_XYZ_inst_1_11955_11956.text
-a----       10/28/2019   2:52 PM         441979 awr_XYZ_inst_1_11942_11943.text
-a----       10/28/2019   2:53 PM         444789 awr_XYZ_inst_1_11943_11944.text
-a----       10/28/2019   2:54 PM         424755 awr_XYZ_inst_1_11947_11948.text
-a----       10/28/2019   2:55 PM         441857 awr_XYZ_inst_1_11951_11952.text
-a----       10/28/2019   2:55 PM         445155 awr_XYZ_inst_1_11944_11945.text
-a----       10/28/2019   2:56 PM         468731 awr_XYZ_inst_1_11948_11949.text
-a----       10/28/2019   2:57 PM         449185 awr_XYZ_inst_1_11950_11951.text
-a----       10/28/2019   2:58 PM         428541 awr_XYZ_inst_1_11953_11954.text
-a----       10/28/2019   2:59 PM         442711 awr_XYZ_inst_1_11957_11958.text

Top 10 Foreground Events

This list of AWR reports has been requested by the Oracle support so that tuning suggestions can be given to my client. One of the suggestions given by Oracle was that reducing the number of log file sync wait event will help improving the performance of the application. I was curious to know what in the AWR reports list makes Oracle support suggesting this log file sync issue. So, I decided to examine the 45 Top 10 Foreground Events to see how much the log file sync wait event participate to the % of the total DB time.

For that, I used the following simple PowerShell script to generate a single file containing only the Top 10 Foreground Events of the totality of the 45 AWR reports:

$SearchString = 'Top 10 Foreground Events by Total Wait Time'
$AllAwrs=Get-ChildItem -Recurse -Include *.text	
for ($i=0; $i -lt $AllAwrs.Count; $i++)
 {
	$result = Select-String $SearchString $AllAwrs[$i].FullName -Context 0, 14 | % {$_.Context.PostContext} 
    $result |  Out-File Top10ForegroundWaitevents.txt   -Append	
 }     	

And, finally, all what I have to do was to analyze the Top10ForegroundWaitevents.txt file

 Event                                 Waits Time Avg(ms)   time Wait Class 
------------------------------ ------------ ---- ------- ------ ---------- 
DB CPU                                      1820           55.2            
db file scattered read               44,406 1032      23   31.3 User I/O   
db file sequential read           2,346,969 735.       0   22.3 User I/O   
direct path write temp                4,085 50.1      12    1.5 User I/O   
log file sync                         3,688 18.3       5     .6 Commit     --> only 0.6%
direct path read temp                13,173 14.2       1     .4 User I/O   
enq: TX - row lock contention           133    1       7     .0 Applicatio 
control file sequential read         11,846   .6       0     .0 System I/O 
db file parallel read                    13   .6      43     .0 User I/O   
direct path read                      2,556   .5       0     .0 User I/O   
                                                                           
                                            Tota    Wait   % DB            
Event                                 Waits Time Avg(ms)   time Wait Class 
------------------------------ ------------ ---- ------- ------ ---------- 
db file scattered read              212,869 3439      16   94.1 User I/O   
DB CPU                                      422.           11.5            
control file sequential read         11,846   .5       0     .0 System I/O 
OJVM: Generic                           139   .5       3     .0 Other      
db file sequential read               5,270   .3       0     .0 User I/O   
log file sync                            67   .3       4     .0 Commit     --> almost 0.0% 
Disk file operations I/O                373    0       0     .0 User I/O   
direct path read                        108    0       0     .0 User I/O   
SQL*Net message to client             1,706    0       0     .0 Network    
direct path sync                          1    0       2     .0 User I/O   
                                                                           
                                            Tota    Wait   % DB            
Event                                 Waits Time Avg(ms)   time Wait Class 
------------------------------ ------------ ---- ------- ------ ---------- 
DB CPU                                      3918           91.8            
db file scattered read               11,553  235      20    5.5 User I/O   
db file sequential read              28,353 87.4       3    2.0 User I/O   
log file sync                         9,537   78       8    1.8 Commit     --> only 1.8% 
resmgr:become active                      4   10    2512     .2 Scheduler  
enq: TX - row lock contention           344  4.3      13     .1 Applicatio 
direct path read temp                 1,241    1       1     .0 User I/O   
direct path read                      6,324    1       0     .0 User I/O   
direct path write temp                  130   .8       6     .0 User I/O   
control file sequential read         11,871   .7       0     .0 System I/O

Etc.….

Bottom-line

In this very simple note I gave a SQL script to generate multiple AWR reports between two dates. I have also examined, via a PowerShell script, how to loop over the content of those AWR reports and extract only an AWR section into a single file for a better and clean analysis.