Obtaining an Execution Plan – part 2

As short follow-up to obtaining an SQL execution plan, a point regarding DBMS_XPLAN.DISPLAY_CURSOR that I failed to note previously was that with no arguments it returns the plan for the last statement run within the session. I seem to recall that this routine appeared in Oracle 10g.

This is really cool feature as it means your process can capture execution plans themselves for analysis later on. Sure, you can extract the execution plan for a query direct from the SGA or from AWR but if you have concerns about the plan for an SQL statement you can simply log it immediately after its execution with no hassles (or in the case of AWR, no extra licensing fees). This approach might not be suitable for OLTP systems but for those hairy data extract / reporting queries that all too regularly seem to go wrong in the middle of the night this might provide a convenient means of checking execution details. It also provides a convenient way for developers to obtain the execution plan for their queries while doing their development, without having to poke around in the SGA looking up SQL_IDs and PLAN_HASH_VALUEs.

Let’s take a quick look at how you might do this. I’m going to reuse the READINGS table that I created in a previous post along with the query to obtain the latest reading timestamp for a given meter. This routine utilises PKG_LOG to log the execution plan, after having converted to a CLOB.

DECLARE
   
   TYPE t_xplan_table   IS TABLE OF VARCHAR2(300);

   l_meter_id           readings.meter_id%TYPE := 1234;
   l_max_reading_tstamp readings.reading_tstamp%TYPE;
   l_xplan_table        t_xplan_table;

   -- a simple routine that converts t_xplan_table
   -- to a CLOB
   FUNCTION to_clob (p_xplan_table IN t_xplan_table)
   RETURN CLOB
   AS
      c_new_line     CONSTANT VARCHAR2(2) := CHR(10) || CHR(13);
      l_return_value CLOB;
   BEGIN
      dbms_lob.createtemporary (l_return_value, FALSE);
      FOR i IN 1..p_xplan_table.COUNT
      LOOP
         dbms_lob.writeappend (l_return_value
                              ,LENGTH(p_xplan_table(i)||c_new_line) 
                              ,p_xplan_table(i)||c_new_line);
      END LOOP;
      RETURN l_return_value;
   END to_clob;
   
BEGIN

   pkg_app_info.set_module ('Capture SQL plan');
   pkg_log.enable_logging;

   -- run the query whose plan we want to capture   
   SELECT MAX(reading_tstamp)
   INTO   l_max_reading_tstamp
   FROM   readings
   WHERE  meter_id = l_meter_id
   AND    reading_type = 'A';
   
   -- grab the plan of the previously executed query
   SElECT t.plan_table_output
   BULK COLLECT INTO l_xplan_table
   FROM   TABLE(dbms_xplan.display_cursor()) t;
   
   -- write the plan to our LOGS table
   pkg_log.info (p_msg => 'SQL plan capture'
                ,p_msg_detail => to_clob(l_xplan_table));
                
END;
/                   

Once logged we can examine the plan directly from the LOGS table by running something like:

SELECT msg_detail
FROM   logs
WHERE  module = 'Capture SQL plan'
AND    log_timestamp >= SYSTIMESTAMP - INTERVAL '5' MINUTE

One important point to note though, akin to implicit cursor attributes, no other SQL statement can occur between the statements whose plan you want to capture and the call to DBMS_XPLAN. As such, I strongly recommend that the call to DBMS_XPLAN occur immediately after the SQL statement itself. Feel free to create a simple procedure to do this though, perhaps using the PKG_LOG.DEBUG routine so that it’s only enabled when logging is running in “debug mode”:

CREATE OR REPLACE PROCEDURE capture_sql_plan
AS
   
   TYPE t_xplan_table   IS TABLE OF VARCHAR2(300);

   l_xplan_table        t_xplan_table;

   -- a simple routine that converts t_xplan_table
   -- to a CLOB
   FUNCTION to_clob (p_xplan_table IN t_xplan_table)
   RETURN CLOB
   AS
      c_new_line     CONSTANT VARCHAR2(2) := CHR(10) || CHR(13);
      l_return_value CLOB;
   BEGIN
      dbms_lob.createtemporary (l_return_value, FALSE);
      FOR i IN 1..p_xplan_table.COUNT
      LOOP
         dbms_lob.writeappend (l_return_value
                              ,LENGTH(p_xplan_table(i)||c_new_line) 
                              ,p_xplan_table(i)||c_new_line);
      END LOOP;
      RETURN l_return_value;
   END to_clob;
   
BEGIN

   -- grab the plan of the previously executed query
   SElECT t.plan_table_output
   BULK COLLECT INTO l_xplan_table
   FROM   TABLE(dbms_xplan.display_cursor()) t;
   
   -- write the plan to our LOGS table
   pkg_log.debug (p_msg => 'SQL plan capture'
                 ,p_msg_detail => to_clob(l_xplan_table));
                
END capture_sql_plan;