Thanks for the question, Rajeshwaran.

Asked: February 22, 2019 - 12:38 pm UTC

Last updated: October 16, 2023 - 1:51 am UTC

Version: 12.2.0.1

Viewed 1000+ times

You Asked

Team,

Was reading about Real time operations monitor in Oracle 12c @ https://docs.oracle.com/en/database/oracle/oracle-database/12.2/tgsql/monitoring-database-operations.html#GUID-DC573FB7-40C5-4D6D-BE81-EF356900B444

and here is a quick demo from local database.

Connected to:
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production

demo@ORA12C> select sid,serial#
  2  from v$session
  3  where username ='SCOTT';

       SID    SERIAL#
---------- ----------
       398      31583

demo@ORA12C> variable x number
demo@ORA12C> exec :x := dbms_sql_monitor.begin_operation(dbop_name=>'MY_DEMO2',session_id=>398,session_serial=>31583);

PL/SQL procedure successfully completed.

demo@ORA12C> print x

         X
----------
         2

Then switched to SCOTT schema and ran these two queries.

select /*+ monitor */ owner,object_type,count(*)
from big_Table
group by owner,object_type
order by 3 desc;

select /*+ monitor */ owner,max(object_id),count(*)
from big_Table
group by owner
order by 3 desc
fetch first 5 rows only ;

Now switched back to the DEMO schema and ended the operation like this.

demo@ORA12C> exec dbms_sql_monitor.end_operation(dbop_name=>'MY_DEMO2',dbop_eid=>:x);

PL/SQL procedure successfully completed.

Post that when tried to generate the SQL Monitor report for the entire database operation id = 2, got only one sql-id reported(typically the last executed sql from scott schema) not both sql's, Kindly advise.

demo@ORA12C> set pagesize 0 echo off timing off linesize 1000 trimspool on trim on long 2000000 longchunksize 2000000 feedback off
demo@ORA12C> select dbms_sql_monitor.report_sql_monitor(dbop_exec_id=>2,type=>'text',report_level=>'ALL') from dual;
SQL Monitoring Report

SQL Text
------------------------------
select /*+ monitor */ owner,max(object_id),count(*) from big_Table group by owner order by 3 desc fetch first 5 rows only

Global Information
------------------------------
 Status              :  DONE (ALL ROWS)
 Instance ID         :  1
 Session             :  SCOTT (398:31583)
 SQL ID              :  0p8wjxam3tns9
 SQL Execution ID    :  16777216
 Execution Started   :  02/04/2019 15:56:23
 First Refresh Time  :  02/04/2019 15:56:23
 Last Refresh Time   :  02/04/2019 15:56:25
 Duration            :  2s
 Service             :  ORA12c
 Program             :  sqlplus.exe
 Fetch Calls         :  2

Global Stats
===========================================================================
| Elapsed |   Cpu   |    IO    |  Other   | Fetch | Buffer | Read | Read  |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Calls |  Gets  | Reqs | Bytes |
===========================================================================
|    1.71 |    0.28 |     1.33 |     0.10 |     2 |  18822 |  599 | 147MB |
===========================================================================

SQL Plan Monitoring Details (Plan Hash Value=1236154803)
=============================================================================================================================================================
| Id |          Operation          |   Name    |  Rows   | Cost |   Time    | Start  | Execs |   Rows   | Read | Read  |  Mem  | Activity | Activity Detail |
|    |                             |           | (Estim) |      | Active(s) | Active |       | (Actual) | Reqs | Bytes | (Max) |   (%)    |   (# samples)   |
=============================================================================================================================================================
|  0 | SELECT STATEMENT            |           |         |      |         1 |     +2 |     1 |        5 |      |       |     . |          |                 |
|  1 |   SORT ORDER BY             |           |       5 | 6474 |         1 |     +2 |     1 |        5 |      |       |  2048 |          |                 |
|  2 |    VIEW                     |           |       5 | 6473 |         1 |     +2 |     1 |        5 |      |       |     . |          |                 |
|  3 |     WINDOW SORT PUSHED RANK |           |    907K | 6473 |         1 |     +2 |     1 |        5 |      |       |  2048 |          |                 |
|  4 |      HASH GROUP BY          |           |    907K | 6473 |         1 |     +2 |     1 |       19 |      |       |   6MB |          |                 |
|  5 |       TABLE ACCESS FULL     | BIG_TABLE |    907K | 4009 |         2 |     +1 |     1 |       1M |  599 | 147MB |     . |          |                 |
=============================================================================================================================================================

demo@ORA12C>

Not sure why there is not response in the previous follow up we did, help us to understand.
https://asktom.oracle.com/pls/apex/asktom.search?tag=how-can-i-track-the-execution-of-plsql-and-sql#9539966000346890225

and Connor said...

I don't think that is the intent, i.e, it is not like SQL trace where we are capturing all the *details*. It is more that we are defining a *composite* operation, and we want execution statistics for *that*.

The reason you are seeing the last operation I think is a short-coming in the parameter validation. Because you are missing a dbop_name, I think it is just dropping through to the default operation (ie, last database operation performed).

For example

SQL> variable exec_id number;
SQL> begin
  2    :exec_id := dbms_sql_monitor.begin_operation ( dbop_name => 'demo' );
  3  end;
  4  /

PL/SQL procedure successfully completed.

SQL> select :exec_id from dual;

  :EXEC_ID
----------
         3

1 row selected.

SQL>
SQL> select /*+ monitor */ max(owner), min(object_id) from t
  2  where object_id > 0
  3  and   log(object_id,2) > 0;

MAX(OWNER)
--------------------------------------------------------------------------------------------------------------------------------
MIN(OBJECT_ID)
--------------
XDB
             2


1 row selected.

SQL>
SQL> select /*+ monitor */ max(x), max(object_id)
  2  from
  3   ( select owner, object_id, stddev(object_id) over ( partition by owner order by created ) as x
  4     from t
  5   );

    MAX(X) MAX(OBJECT_ID)
---------- --------------
32629.3453         102702

1 row selected.

SQL>
SQL> begin
  2    dbms_sql_monitor.end_operation ( dbop_name => 'demo', dbop_eid => :exec_id );
  3  end;
  4  /

PL/SQL procedure successfully completed.

SQL>
SQL> SELECT dbop_name, dbop_exec_id, status
  2  FROM   v$sql_monitor
  3  where  dbop_name = 'demo';

DBOP_NAME                      DBOP_EXEC_ID STATUS
------------------------------ ------------ -------------------
demo                                      3 DONE

1 row selected.

SQL>
SQL> set pagesize 0 echo off timing off linesize 1000 trimspool on trim on long 2000000 longchunksize 2000000 feedback off
SQL> select dbms_sql_monitor.report_sql_monitor(dbop_name => 'demo',dbop_exec_id=>:exec_id ,type=>'text',report_level=>'ALL') from dual;
SQL Monitoring Report

Global Information
------------------------------
 Status              :  DONE
 Instance ID         :  1
 Session             :  MCDONAC (128:42919)
 DBOP Name           :  demo
 DBOP Execution ID   :  3
 First Refresh Time  :  03/11/2019 11:55:53
 Last Refresh Time   :  03/11/2019 11:58:16
 Duration            :  143s
 Module/Action       :  SQL*Plus/-
 Service             :  pdb1
 Program             :  sqlplus.exe

Global Stats
====================================================================================
| Elapsed |   Cpu   |    IO    |  Other   | Buffer | Read  | Read  | Write | Write |
| Time(s) | Time(s) | Waits(s) | Waits(s) |  Gets  | Reqs  | Bytes | Reqs  | Bytes |
====================================================================================
|     142 |     137 |     4.81 |     0.21 |      1 | 11285 |   3GB |  2140 | 386MB |
====================================================================================

SQL> select dbms_sql_monitor.report_sql_monitor_list(dbop_name => 'demo', type=>'text',report_level=>'ALL') from dual;


                                                                                SQL Monitoring List
                                                                               =====================


===================================================================================================================================================================================
| Status | Duration | Inst Id | SQL Id or DBOP Name | Exec Id |        Start        |  User   | Module/Action | Dop | DB Time |  IOs  |               SQL Text                  |
===================================================================================================================================================================================
| DONE   |     143s |    1    |        demo         |    3    | 03/11/2019 11:55:53 | MCDONAC | SQL*Plus/-    |     |    142s | 13425 |                                         |
===================================================================================================================================================================================

SQL>
SQL>

If I now run some other stuff, totally unrelated...

SQL> select /*+ monitor*/ * from scott.emp;
      7369 SMITH      CLERK           7902 17-DEC-80        800                    20
      7499 ALLEN      SALESMAN        7698 20-FEB-81       1600        300         30
      7521 WARD       SALESMAN        7698 22-FEB-81       1250        500         30
      7566 JONES      MANAGER         7839 02-APR-81       2975                    20
      7654 MARTIN     SALESMAN        7698 28-SEP-81       1250       1400         30
      7698 BLAKE      MANAGER         7839 01-MAY-81       2850                    30
      7782 CLARK      MANAGER         7839 09-JUN-81       2450                    10
      7788 SCOTT      ANALYST         7566 09-DEC-82       3000                    20
      7839 KING       PRESIDENT            17-NOV-81       5000                    10
      7844 TURNER     SALESMAN        7698 08-SEP-81       1500                    30
      7876 ADAMS      CLERK           7788 12-JAN-83       1100                    20
      7900 JAMES      CLERK           7698 03-DEC-81        950                    30
      7902 FORD       ANALYST         7566 03-DEC-81       3000                    20
      7934 MILLER     CLERK           7782 23-JAN-82       1300                    10
SQL> select dbms_sql_monitor.report_sql_monitor(dbop_exec_id=>:exec_id ,type=>'text',report_level=>'ALL') from dual;
SQL Monitoring Report

SQL Text
------------------------------
select /*+ monitor*/ * from scott.emp

Global Information
------------------------------
 Status              :  DONE (ALL ROWS)
 Instance ID         :  1
 Session             :  MCDONAC (128:42919)
 SQL ID              :  gwqz99dzxkzdd
 SQL Execution ID    :  16777216
 Execution Started   :  03/11/2019 12:05:31
 First Refresh Time  :  03/11/2019 12:05:31
 Last Refresh Time   :  03/11/2019 12:05:31
 Duration            :  .001259s
 Module/Action       :  SQL*Plus/-
 Service             :  pdb1
 Program             :  sqlplus.exe
 Fetch Calls         :  2

Global Stats
=================================================================
| Elapsed |    IO    |  Other   | Fetch | Buffer | Read | Read  |
| Time(s) | Waits(s) | Waits(s) | Calls |  Gets  | Reqs | Bytes |
=================================================================
|    0.00 |     0.00 |     0.00 |     2 |      7 |    2 | 49152 |
=================================================================

SQL Plan Monitoring Details (Plan Hash Value=3956160932)
========================================================================================================================================
| Id |      Operation      | Name |  Rows   | Cost |   Time    | Start  | Execs |   Rows   | Read | Read  | Activity | Activity Detail |
|    |                     |      | (Estim) |      | Active(s) | Active |       | (Actual) | Reqs | Bytes |   (%)    |   (# samples)   |
========================================================================================================================================
|  0 | SELECT STATEMENT    |      |         |      |           |        |     1 |          |      |       |          |                 |
|  1 |   TABLE ACCESS FULL | EMP  |      14 |    3 |         1 |     +0 |     1 |        0 |    2 | 49152 |          |                 |
========================================================================================================================================

you can see the output is no different to just the a standard report_sql_monitor call, ie, last db operation that took place.

Rating

(2 ratings)

Is this answer out of date? If it is, please let us know via a Comment

Comments

Bind variable value for "Timestamp" data types

Rajeshwaran, Jeyabal, February 26, 2021 - 5:50 am UTC

Team:

we got a sql-monitor report for analysis, with following bind variables.
could you please help us to understand how to interpret the below bind variable value for "Timestamp" into real data?

Binds
=======================================================
| Name | Position |   Type    |  Value                
=======================================================
| :B1  |        1 | NUMBER    | 491150457802610       |
| :B2  |        2 | TIMESTAMP | 7879021912040336E63AD0|
=======================================================

March 02, 2021 - 2:56 am UTC

The string is the hex version of what you would see in a DUMP, eg

SQL> create table t ( x timestamp with time zone );

Table created.

SQL> insert into t values ( systimestamp );

1 row created.

SQL> select x, dump(x) from t;

X
----------------------------------------------------------
DUMP(X)
----------------------------------------------------------
02-MAR-21 10.05.48.557000 AM +08:00
Typ=181 Len=13: 120,121,3,2,3,6,49,33,51,37,64,28,60

Converting the dump bytes to hex, you'd see

78,79,03,02,03,06,31,21,33,25,40,1C,3C

which is what appears in your SQL monitor.

Going back to the decimals, we can break this down into its bytes

- century + 100
- year + 100
- month
- day
- hour + 1
- minute + 1
- second + 1
- nanoseconds (4bytes)
- time zone hour + 20
- time zone minute + 60

so

120, 121 = 2021
3 = march
2 = 2nd
3 = 2am (UTC)
6 = 5mins
49 = 48seconds
33, 51, 37, 64 = 557000000 nanoseconds
28 = 8 hours forward (perth)
60 = 0 mins foward ( perth)

(For the nanoseconds:

33, 51, 37, 64 = 21,33,25,40 in hex, then

SQL> select to_number('21332540','xxxxxxxx') from dual;

TO_NUMBER('21332540','XXXXXXXX')
--------------------------------
                       557000000

I'll leave as an exercise to write a function that does the below:

SQL> select ts_from_monitor('7879021912040336E63AD0') from dual;

TS_FROM_MONITOR('7879021912040336E63AD0')
-------------------------------------------------------------------
25-FEB-21 05.03.02.921058000 PM

or you can wait until it appears on the blog in a few days :-)

Source for Database Time in SQL Monitoring Report

Narendra, October 11, 2023 - 9:57 pm UTC

Hello Connor/Chris,

I am trying to figure out what source data is being used by "Database Time" metric under "Time & Wait" section in a SQL Monitoring (Active) Report.
While for typical SQLs, it provides the breakdown of Database Time and matches with the details in "Activity" column for individual steps in "Plan Statistics" as well as those under "Activity" tab/section.
However, I am trying to understand the details for a test sql that generates a lot of LIOs and runs entirely on CPU on my sandbox environment. For this SQL, the "Database Time" is reporting 6.1 minutes, which is divided into 2.7 minutes of CPU time (44.25%) and 3.4 minutes of Other Wait Time (55.75%). However, all the steps in "Plan Statistics" show only CPU usage. Similarly only CPU is displayed under "Activity" tab. when I query ASH (v$active_session_history), I only see rows with session_state as ON CPU.
So what data is being used to report "Other Waits" in Database Time?

October 16, 2023 - 1:51 am UTC

Can you email the report to asktom_us@oracle.com with the subject line "database-operations-monitor-12c" and we'll take a look

More to Explore

Performance

Get all the information about database performance in the Database Performance guide.

Breadcrumb

Question and Answer

You Asked

and Connor said...

Rating

Comments

Bind variable value for "Timestamp" data types

Source for Database Time in SQL Monitoring Report

More to Explore

Performance

Database operations monitor 12c

Breadcrumb

Question and Answer

You Asked

and Connor said...

Rating

Comments

Bind variable value for "Timestamp" data types

Source for Database Time in SQL Monitoring Report

More to Explore

Performance