Must-gather information for diagnosing long-running SQL statements on Oracle

Authors: VaughnRokosz
Build basis: None. Applies to DOORS Next 7.x and ETM and EWM 6.x, 7.x

There are two complementary pieces of information to collect from customers when diagnosing long-running SQL statements on Oracle:

• A SQL Monitor report for the long-running statement
• An execution plan (that includes predicate and column projection details)

While there can be overlap between the two, both are required for in-depth analysis. If we have only the monitor output, we may not have information about join predicates (depending on how the monitor output was generated). If we have only the execution plan details, we won't have the actual row counts for the row sources in the execution plan.

Please be aware that there is some time-sensitivity to collecting the data discussed here. You will need to gather the data close to the time that the problem occurs. The detailed information for a SQL statement may not be available in the monitor or in the cursor cache after a few hours. If you try to go back to collect the information days after the problem occurred, you may not be able to find the SQL statement anymore.

There is a more general must gather for performance issues for DOORS Next which should be used in conjunction with this guide.

SQL Monitor reports

Oracle will automatically monitor SQL statements that run in parallel, or that consume more than 5 seconds of CPU or I/O in a single execution. The monitor report provides several valuable bits of information, including:

• The values of bind variables
• A high level execution plan
• Estimates and actuals for each row source in the execution plan
• Memory, CPU, and elapsed time estimates for the steps in the execution plan

Oracle Diagnostics and Tuning pack licenses are required to get monitor reports.

Execution plans

An execution plan shows the detailed steps necessary to execute a SQL statement. The steps are expressed as a set of database operators that produce and consume rows.

The execution plan (generated by

SELECT * FROM TABLE(DBMS_XPLAN.display_cursor('sql_id', NULL, 'all +peeked_binds +outline'));

provides additional context that aids in the interpretation of the monitor output, including:

• The predicates and column projections used by each step in the execution plan
• The values of the bind variables at the time that the statement was hard-parsed
• Details for each child cursor, if there are multiple execution plans available for a statement
• A high-level list of things that influenced the optimizer when generating the plan:
  • Adaptive features
  • SQL plan directives
  • SQL profiles or baselines
  • Dynamic sampling
  • Statistics feedback

Getting SQL Monitor reports

There are several different ways to generate monitor reports. The options vary across the different Oracle versions, but here is a high-level summary:

• Use the Oracle SQL Developer client, and generate monitor reports from the "Real-time SQL Monitor" tool
• Use the SQL Monitor view provided with Oracle Enterprise Manager Cloud Control
• Use the SQL Monitor view provided with Oracle's EM Database Express
• Use sql*plus to generate monitor reports ( DBMS_SQLTUNE.report_sql_monitor_list and DBMS_SQLTUNE.report_sql_monitor)

The best option is to use SQL Developer. You can generate reports from the monitor view in html format and then share them with IBM. The reports generated by SQL Developer are easy for IBM support personnel to interpret, and help us address problems quickly.

If you don't have SQL Developer and can't download it for some reason, then you can use one of the other options. But keep in mind that the reports generated by the other tools are harder for IBM teams to work with, and it can therefore take longer to resolve a problem using these reports.

Monitor reports from SQL Developer

Oracle describes SQL Developer as "a graphical version of SQL*Plus that gives database developers a convenient way to performance basic tasks". You can download SQL Developer from Oracle, and then connect it to your Oracle servers. Use the latest available version (version 19 or later).

Bring up the SQL monitor view by selecting the Tools->RealTime SQL Monitor... menu:

The list of monitored SQL statements appears. This shows the time taken by each SQL statement, the user that executed the statement, as well as other information. If you are having performance problems with a particular application, then look for SQL statements executed by the database user associated with that application. Select the SQL statement of interest to display the execution details:

To generate reports to share with IBM, select the disk icon and then choose the "Save as Report" option. This will capture the information for the statement in HTML format. Upload the HTML file to IBM. Then, choose the "Save as active report" option and save the resulting html file. Then, upload that file to IBM.

Monitor reports from Oracle Enterprise Manager Cloud Control

Oracle's Enterprise Manager Cloud Control is a centralized monitoring solution that can manage all of a customer's Oracle deployments. It has functionality that overlaps other monitoring tools such as New Relic, Logic Monitor and Dynatrace. But it also has monitoring capabilities for Oracle database servers. In fact, it now includes features that were formerly available in the EM Express tool that was part of the Oracle server install. With each release of Oracle, more functionality has been moved from EM Express into Cloud Control.

Access the SQL monitor view by selecting Performance Hub->SQL Monitoring.


Find the slow SQL statement in which you are interested from the list, and click on it.

Then, select Save to save the monitor details to an HTML file. Before uploading the file to IBM, open it in a browser and confirm that the save worked correctly.

Generating monitor output from sql*plus

You can generate monitor reports from sql*plus, using the DBMS_SQLTUNE package. But there are several disadvantages to using that approach, so it is not recommended unless there is no other option.

The output format is much harder to read, and it is therefore harder for the IBM support teams to use. It is harder to get information about one specific statement. You can easily get information about the last execution of a statement, but if that is not also the slow instance, then the output is not helpful to IBM. It takes more time to figure out how to generate a report for any older instances.

If you have the SQL id for a statement of interest, you can generate the monitor output for the last execution of that statement by executing the following PL/SQL script. You would of course change the file name and SQL id to match your own system.

SET LONG 1000000
SET LONGCHUNKSIZE 1000000
SET LINESIZE 1000
SET PAGESIZE 0
SET TRIM ON
SET TRIMSPOOL ON
SET ECHO OFF
SET FEEDBACK OFF

SPOOL /var/tmp/report_sql_monitor_forid.htm
SELECT DBMS_SQLTUNE.report_sql_monitor(
   sql_id       => '1v6xu3zn7uprm',
   type         => 'HTML',
   report_level => 'ALL') AS report
 FROM dual;
 SPOOL OFF

Open the HTML file in a browser to verify that it generated correctly, then upload it to IBM. You should see something similar to this:

This is better than nothing, but it is harder to use than the output from SQL Developer. Note that the execution plan does not include collapsible sections, so it is much harder to navigate than what SQL Developer can generate. You have to rely on indentation, which is difficult for more complex execution plans. So, this is an option of last resort.

The other drawback of this approach is that we may not get data for the instance of the statement that is slow. That might happen in there are some slow instances and some fast instances. In this case, you will need to go through a two-step process to get the monitor output for the slow instance.

The first step is the generate the complete monitor report, showing all of the SQL statements tracked by the monitor. To do that, use:

  SET LONG 1000000
  SET LONGCHUNKSIZE 1000000
  SET LINESIZE 1000
  SET PAGESIZE 0
  SET TRIM ON
  SET TRIMSPOOL ON
  SET ECHO OFF
  SET FEEDBACK OFF

 SPOOL /var/tmp/report_sql_monitor_list.htm
 SELECT DBMS_SQLTUNE.report_sql_monitor_list(
       type         => 'HTML',
       report_level => 'ALL') AS report
 FROM dual;
 SPOOL OFF
  

You should get a report that looks something like this:

Using EM Express

You can also access the Monitor view if you are running EM Express on your Oracle server. The way you get to the UI may vary based on your Oracle release, but in Oracle 19c, you can do that by selecting Performance->Performance hub. Then, select the "Monitored SQL" tab to bring up the list of monitored statements:


You can also use the "Last Hour" view:


Select the SQL statement of interest to bring up the details, then select "Save Report" to save the details to an HTML file. Open the HTML file in a browser to verify that it generated successfully, then upload it to IBM.

Getting execution plans with Oracle Standard edition

The standard edition of Oracle does not include the SQL Monitor. That makes it harder to get execution plans that include row actuals, but it is still possible. The steps involved are:

• Capture the SQL statement of interesting, along with bind parameters
• Create a standalone SQL file that sets the bind parameters and executes the SQL statement of interest
• Add the hint /*+ gather_plan_statistics */ to the statement
• Add the following statement to the SQL file (after the SQL statement)
  • SELECT * FROM table(DBMS_XPLAN.DISPLAY_CURSOR(FORMAT=>'ALLSTATS LAST ALL +OUTLINE'));
• Execute the SQL file (either from SQL Developer or from sql*plus). Capture the output, which will include an explain plan that includes row actuals

Capturing SQL statements and bind parameters

There are two ways to capture a SQL statement (including bind parameters).

First, for DOORS Next Generation, you can check the product log files (rm.log). The view service will log slow SQL automatically if a statement runs for longer than a specified threshold (configurable in rm/admin Advanced Properties). The log file will contain the SQL (with PARAM statements for any bind variable. You can just copy the relevant section of the log into a file and then add the gather_plan_statistics hint.

You can also enable diagnostic logging in DOORS Next Generation by editing conf/rm/log4j2.xml and adding in the following line:

<Logger name="com.ibm.rdm.fronting.server.rrs.views.execution.sql.internal.run.DirectSqlExecutor" level="DEBUG"/>

The DEBUG level logging will log SQL generated by DNG in a format that can be executed by SQL Developer or sql*plsu, so you can just copy the relevant sections out of rm.log and paste them into a file. Then, add in the /*+ gather_plan_statistics */ hint as well as the call to DBMS_XPLAN.DISPLAY_CURSOR.

Note that the logging applies only to SQL generated by DNG. It will not log slow SQL that is generated by Jazz Foundation or other applications. In that case, you'll need to get the bind parameters by using repodebug.

In 702 SR15 and later, repodebug can capture bind parameters when statements are executed. You enable "stat records" to do this. For more details, refer to Collecting DB2 section actuals using repodebug. Once you have the stat record output, you will need to:

• Copy the SQL statement from repodebug into a file
• Add a declaration for each bind parameter to the file. Declare numeric values as NUMBER; declare text and timestamps as VARCHAR(128).
• Set the value for each bind parameter using the execute statement. Get the values from the stat record output.
• Replace "?"s in the SQL text with the names you used when declaration the bind parameters
• Add the following statement at the end of the file: SELECT * FROM table(DBMS_XPLAN.DISPLAY_CURSOR(FORMAT=>'ALLSTATS LAST ALL +OUTLINE')); * Locate the first SELECT in the SQL statement, and add the hint /*+ gather_plan-statistics */ immediately after the SELECT keyword.

An example SQL file is attached.

Once you execute the SQL statement, the output should include an explain plan that includes row actuals (in the A-Rows column).

Getting detailed execution plans

To get a detailed execution plan, execute the following command from sql*plus (or from a SQL Worksheet in SQL Developer). Remember to replace the sql_id parameter with the actual SQL id for the statement that is performing poorly.

        SELECT * FROM TABLE(DBMS_XPLAN.display_cursor('sql_id', NULL, 'all +peeked_binds +outline'));

Save the result to a text file and upload it to IBM. Please do not transform this to a format other than plain text (like PDF or csv). Provide the output in plain text only.

Do not use dbms_xplan.display_awr to generate an execution plan from historical data. These execution plans do not include the predicate and column projection sections, so they are not useful to IBM support personnel.

Here's a simple example of the kind of output we need to have. This includes the tabular form of the execution plan, plus the predicate information section and the column projection information section. The predicate information section tells us what predicates are being applied to each step in the plan, so we can tell what joins or filters are being applied. The column projection information tells us what columns are being produced by each row source in the plan.

Known issues

ORA-00904 error during Explain Plan creation.

We have observed truncated Explain Plans at the point where Oracle optimizations are displayed. The ORA-00904 error is caused by a missing access right on a specific DBA or V$ view of the database of the DB user which created the explain plan. You should be able to create these execution plans with the correct DBA rights without any issues. Contact your Oracle DBA to correct this problem, as IBM are dependent on understanding how Oracle is executing our queries in any problem determination.

References:

• The SQL Monitor
• Explain the explain plan
• Oracle EM Database Express
• SQL Developer download
• What is SQL Developer?
• dbms_xplan

Related topics: Performance sizing guides and datasheets, Disk benchmarking

External links:

• IBM

Additional contributors: PaulEllis