CODEWITHSUNDEEP
sqloracle-databasemergesql-execution-plansqlperformance
Alex Bartsmon
Alex Bartsmon

Reputation: 550

Difference between SQL Operations: MERGE STATEMENT and MERGE?

What’s the difference between dba_hist_active_sess_history.sql_plan_operation's MERGE STATEMENT (line Id 0) vs. MERGE (line Id 1)?

For example, consider the following abbreviated execution plan and subset of dba_hist_active_sess_history for a single sql_id that I know was only executed once during the sample_time selected. Both SQL opertaions are waiting for “ON CPU” and “db file sequential read”, but for MERGE STATEMENT no sql_plan_line_id is provided (though I suspect it corresponds to line Id 0) and no valid object information is provided. The majority of the DB Time is spent on these two SQL operations, but what's the difference between them?

Plan hash value: 2410236922

-----------------------------------------------------------------------------------
| Id  | Operation                                   | Name                        |
-----------------------------------------------------------------------------------
|   0 | MERGE STATEMENT                             |                             |
|   1 |  MERGE                                      | [TABLE_NAME]                |
|   2 |   VIEW                                      |                             |
|   3 |    SEQUENCE                                 | [SEQUENCE_NAME]             |
|   4 |     TEMP TABLE TRANSFORMATION               |                             |
...

From dba_hist_active_sess_history:

  SQL_EXEC_ID   SQL_ID          SQL_PLAN_HASH_VALUE   SQL_PLAN_LINE_ID   EVENT                         CURRENT_OBJ#   OBJECT_NAME                     SUBOBJECT_NAME         OBJECT_TYPE          SQL_PLAN_OPERATION   DBTIME
------------- --------------- --------------------- ------------------ ----------------------------- -------------- ------------------------------- ------------------     -------------------- -------------------- --------
                52yu6v2ba5jm5   0                                        ON CPU                        -1                                                                                        MERGE STATEMENT       6070
                52yu6v2ba5jm5   0                                        db file sequential read       -1                                                                                        MERGE STATEMENT       3210
                52yu6v2ba5jm5   0                                        ON CPU                        0                                                                                         MERGE STATEMENT       1970
                52yu6v2ba5jm5   0                                        db file sequential read       0                                                                                         MERGE STATEMENT        440
                52yu6v2ba5jm5   0                                        PGA memory operation          -40004158                                                                                 MERGE STATEMENT         20
                52yu6v2ba5jm5   0                                        latch: cache buffers chains   -1                                                                                        MERGE STATEMENT         10
  16777216      52yu6v2ba5jm5   2410236922            1                  ON CPU                        7253322        [TABLE_NAME]                    [SUBPARTITION_NAME]   TABLE SUBPARTITION   MERGE                  460
  16777216      52yu6v2ba5jm5   2410236922            1                  ON CPU                        7253316        [TABLE_NAME]                    [SUBPARTITION_NAME]   TABLE SUBPARTITION   MERGE                  390
  16777216      52yu6v2ba5jm5   2410236922            1                  ON CPU                        7253342        [INDEX_NAME]                                          INDEX                MERGE                  280
  16777216      52yu6v2ba5jm5   2410236922            1                  db file sequential read       7253343        [INDEX_NAME]                                          INDEX                MERGE                  170
  16777216      52yu6v2ba5jm5   2410236922            1                  db file sequential read       7253357        [INDEX_NAME]                    [PARTITION_NAME]      INDEX PARTITION      MERGE                  140
  16777216      52yu6v2ba5jm5   2410236922            1                  ON CPU                        7253501        [INDEX_NAME]                                          INDEX                MERGE                  140
  16777216      52yu6v2ba5jm5   2410236922            1                  db file sequential read       7253342        [INDEX_NAME]                                          INDEX                MERGE                  120
  16777216      52yu6v2ba5jm5   2410236922            1                  db file sequential read       7253322        [TABLE_NAME]                    [SUBPARTITION_NAME]   TABLE SUBPARTITION   MERGE                  120
  16777216      52yu6v2ba5jm5   2410236922            1                  db file sequential read       7253372        [INDEX_NAME]                    [PARTITION_NAME]      INDEX PARTITION      MERGE                  100
...

Upvotes: 3

Views: 207

Answers (3)

Paul W
Paul W

Reputation: 11603

As others have mentioned, line 0/NULL (MERGE STATEMENT) is a header for the plan as a whole, reported as line 0, whereas line 1 (MERGE) is the actual modification of data blocks using the merge subprogram (this is where actual work gets done). But I also might be able to explain why you might be seeing MERGE STATEMENT or any other %... STATEMENT plan operation in ASH data.

A % STATEMENT value (line 0) in SQL_PLAN_OPERATION always means that at the moment of that sampling the process was in an ongoing database call involving a SQL statement (PARSE, EXEC, FETCH) but not currently executing the logic of the plan subprograms (lines in the plan). This could be because:

  1. There is some statement-level contention (enq: TM, enq: TT, enq: DW, enq: HW, etc.) blocking the plan from being executed. It's ready to start, but cannot until the blocking condition is resolved, and so sits on reporting line 0.
  2. The SQL execution has just begun or just ended and there's a few microseconds in which it hasn't yet or just finished the plan execution (line 1 and below). Think parent envelope code unit just before or just after it calls downstream code, a few microseconds of CPU. While this is usually so miniscule it is rarely captured, if you have a loop and are doing single-row operations at a very high frequency (e.g. 10,000 updates per second), the tiny non-plan overhead in each execution can amount to a sizeable portion of time relative to the plan execution itself and show up in ASH sampling.
  3. There is some recursive SQL/dictionary lookups and what-not happening here and there, where something other than your SQL's own plan is being executed under the covers internally. An example would be TM contention when checking for referential integrity on a child table.
  4. Your SQL invoked a PL/SQL function that itself does its own SQL. Oracle doesn't instrument the operations of the recursive SQL, so its time is accrued to the calling SQL and reported at line 0.
  5. For SELECT statements, after execution completes the client has to request the results by issuing FETCH calls - any time the DB spends on this call (usually very minimal) will show up as line 0 (SELECT STATEMENT) since the plan itself isn't involved. This will almost never be significant unless the client is reading LOBs.
  6. You are in rollback. While rolling back due to an exception thrown during SQL execution. During this rollback, ASH reports line 0. To check this, you'd need to look at v$transaction (join from v$session.taddr) while this is happening (in real-time) to see if used_urecs is going down over time. If it is, that's a rollback. It's doing work, but not the work your plan involves - it's backing everything out. When the rollback finishes (which for a big merge can take a long time) the client receives the exception message. If you can't watch it real-time, you can still query ASH for that one specific session and order the results by sample time - if you see all the MERGE STATEMENT lines together and suddenly start later/after all the other plan lines happening earlier, that's likely a rollback scenario.

One other reason comes to mind rather easily but is misleading - that the SQL may still be in parse. If parse has not yet completed, there is no plan, and so no plan line operation of any kind, not even line 0. It will report NULL, not MERGE STATEMENT. So I don't think that's what's happening here.

I'm sure that in addition to the above there are numerous other scenarios when this happens. Given that your SQL_EXEC_ID is empty, my guess is that it's #6 - rollback. But regardless of the exact cause - the common thread running through all the above is that the plan itself is not being executed in that moment. The merge operation isn't happening, nor any other step in your plan. Some other kind of overhead is going on, which often requires a deeper dive in more than just ASH data to pinpoint.

Upvotes: 2

d r
d r

Reputation: 7846

Explain plan output is a series of dependants (operation indented below) starting with level 0 as a parent (root). The text in Operation column for Id 0 just describes the type of SQL (SELECT, UPDATE, ...., MERGE, ...) STATEMENT and as such - it is not an actual operation. Values depend on its dependants - indented operations below. It is like cascading actions (operations) building values from bottom right upwards to upper left....

EXPLAIN PLAN FOR 
        Select * From EMP Where EMPNO = 7839;

--------------------------------------------------------------------------------------------
| Id  | Operation                   | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |              |     1 |    38 |     1   (0)| 00:00:01 |
|   1 |  TABLE ACCESS BY INDEX ROWID| EMP          |     1 |    38 |     1   (0)| 00:00:01 |
|*  2 |   INDEX UNIQUE SCAN         | SYS_C0022243 |     1 |       |     0   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------


EXPLAIN PLAN FOR 
        Update EMP Set JOB = 'EX-PRESIDENT' Where EMPNO = 7839;

-----------------------------------------------------------------------------------
| Id  | Operation          | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------
|   0 | UPDATE STATEMENT   |              |     1 |    12 |     1   (0)| 00:00:01 |
|   1 |  UPDATE            | EMP          |       |       |            |          |
|*  2 |   INDEX UNIQUE SCAN| SYS_C0022243 |     1 |    12 |     0   (0)| 00:00:01 |
-----------------------------------------------------------------------------------



EXPLAIN PLAN FOR 
        Insert Into EMP (EMPNO, ENAME, JOB, MGR, HIREDATE, SAL, COMM, DEPTNO)
                  VALUES(1111, 'Doe', 'CLARK', 'N', SYSDATE, 700, 0, 10);
                  
---------------------------------------------------------------------------------
| Id  | Operation                | Name | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------
|   0 | INSERT STATEMENT         |      |     1 |    38 |     1   (0)| 00:00:01 |
|   1 |  LOAD TABLE CONVENTIONAL | EMP  |       |       |            |          |
---------------------------------------------------------------------------------


EXPLAIN PLAN FOR 
        MERGE INTO EMP e 
        USING(Select 1111 as EMPNO, 'John' as ENAME From Dual) x ON(e.EMPNO = x.EMPNO)
    WHEN MATCHED THEN
      UPDATE SET e.ENAME = x.ENAME || ' ' || e.ENAME
      
-----------------------------------------------------------------------------------------------
| Id  | Operation                      | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------------
|   0 | MERGE STATEMENT                |              |     1 |    19 |     3   (0)| 00:00:01 |
|   1 |  MERGE                         | EMP          |       |       |            |          |
|   2 |   VIEW                         |              |       |       |            |          |
|   3 |    NESTED LOOPS                |              |     1 |    38 |     3   (0)| 00:00:01 |
|   4 |     TABLE ACCESS BY INDEX ROWID| EMP          |     1 |    38 |     1   (0)| 00:00:01 |
|*  5 |      INDEX UNIQUE SCAN         | SYS_C0022243 |     1 |       |     0   (0)| 00:00:01 |
-----------------------------------------------------------------------------------------------

More detailed explanations here

Regarding the history data, the way I understand it. it is a collection of prety much the same cascading dependancy values having in mind that the history values are the real values taken at the time of sampling while the values from the plan are estimations of resources to be used for the operations planed to be executed.
Though your query was the only one within the session - at the time of sampling - the resources used (at least some of them) are used by some other processes too and are constantly changing. So does the waiting values too and the history values reflect the sampling time resources availability. The history table's event id description here could be taken as a support to the "cascading dependancies" since it implicates waiting values taken are caused by the event itself or by the event last waited (one that actual is depending on). That could explain the ID 0 Operation - which is not an Operation itself but the parent (root) of many real operations indented below.

....
EVENT_ID --->   Identifier of the resource or event for which the session is waiting or for which the session last waited
....

Might be helpfull too - click here

Upvotes: 0

p3consulting
p3consulting

Reputation: 4640

The MERGE STATEMENT as top level 0 is the actual SQL statement executed (MERGE INTO ... USING ... ON ...), the MERGE operation at level 1 is an internal operation chosen by the engine to actually retrieve the data from the database and returns the result. You may find more detailed information in the docs, e.g. https://docs.oracle.com/en/database/oracle/oracle-database/23/tgsql/query-transformations.html, on why the engine choose one way or another.

Upvotes: 0

Related Questions