Slow Running SQL results in Oracle performance degradation

ChunPei Feng  &  R. Wang 

Environment

Oracle 9iR2 and Unix, production database and standby database

Circumstance

In the morning, routine daily database checking shows that the database has an unusual heavy load. As DBA, definitely, the first checking step is to monitor the top OS processes with command TOP or PRSTAT, which offer an ongoing look at processor activity in real time. In this case, however, a list of the most CPU-intensive processes on the system does not tell us anything special which might particularly cause the database performance degradation.

Next, information fetching about TOP SQL and long-running SQL also fail to figure out the possible reason of this performance problem.

Also, the team of application development confirms that no change has been made at the application level. And, application log doesn¡¯t show exception on heavy jobs and excessive user logon.

According to the information above, it can be concluded that the corrupt database performance is caused by issues relating to the database server.

Steps to diagnose:

1. Check and Compare Historical Statspack Reports

So far, no one is able to tell which job attributes to performance degradation because hundreds of processes, which reside on tens of Unix servers, make DBAs difficult to track process by process. Here, the more feasible action is to recur to Statspack, which provides a great deal of performance information about an Oracle database. By keeping historical Statspack reports, it makes possible to compare current Statspack report to the one in last week. The report, generated at peak period (9:00AM - 10:00AM), is sampled to compare to one of report created in last week at same period.

 Upon comparison, the instant finding is that CPU time is increased by 1,200 (2341 vs. 1175) seconds. Usually, the significant increase on CPU time very likely attribute to the following two scenarios:

• More jobs loaded
• The execution plan of SQLs is changed

  Top 5 Timed Events in Statspack Reports
  ~~~~~~~~~~~~~~~~~~~~~~~~~~~~      

• Current Stataspack Report 

• Statspack Report in Last Week

2. Narrow down by examining SQL Part of Statspack Reports
            
Next, we examine the SQL part of Statspack report and find the following SQL statement (Query 1) is listed at the very beginning of ¡°Buffer Gets part. It tells us that this SQL statement is the consumer of 1161.27 seconds¡¯ CPU Time. In last week¡¯s report, no information about this SQL statement has been reported at the very beginning part.  And, it only took 7.39 seconds to be finished. It¡¯s obvious that this SQL statement must be one of the attributors of performance degradation. 

        SELECT login_id, to_char(gmt_create, 'YYYY-MM-DD HH24:MI:SS')
        from IM_BlackList where black_id = :b1

        Query 1: Query on table IM_BlackList with bind variable

SQL Part of Statspack Report

~~~~~~~~~~~~~~~~~~~~~~~~~~~~      

• Current Stataspack Report 

• Statspack Report in Last Week

Now, our investigation has been significantly narrowed down to single SQL statement. That is

SELECT login_id, to_char(gmt_create, 'YYYY-MM-DD HH24:MI:SS')
from IM_BlackList where black_id = :b1

This is a typical SQL query with binding variable and it should benefit from b-tree index created. But, the statistics show that it seems conduct full table scan rather than using proper index.

The following checking on index of field black_id in table IM_BlackList clearly demonstrates the availability of the index.

SQL> select index_name,column_name from user_ind_columns where table_name = 'IM_BLACKLIST';

IM_BLACKLIST_PK LOGIN_ID
IM_BLACKLIST_PK BLACK_ID
IM_BLACKLIST_LID_IND BLACK_ID

The question now is, how come full table scan replace usage of index for this SQL statement? In order to testify our supposition, we simply execute this SQL statement against production database and it¡¯s clear that full table scan is conducted rather than index access.

3. Go Check Histograms generated by Objects Analyzing

To figure out the problem, we then check histograms on the field of BLACK_ID against standby database. That¡¯s also a comparison practice between production database and standby database. Because the activity of gathering statistics does happen on production database, but not on standby database, we are hoping to find some difference between the histograms on the filed BLACK_ID and then to measure the impact of statistics collecting. We select histograms as criteria because histograms is cost-based optimizer (CBO) feature that allows Oracle to see the possible number of values of a particular column, which is known as data skewing, and histograms can track the number of occurrences of a particular data values when CBO decide on what type of index to use or even whether to use an index.

To gather histograms information against standby database, we run:

SQL> select COLUMN_NAME ,ENDPOINT_NUMBER, ENDPOINT_VALUE ,        from dba_histograms where table_name = 'IM_BLACKLIST' and column_name = 'BLACK_ID';

Query 2:gather histograms information  from dba_hisrograms

Then, we get:

Output 1: Histograms data on standby database

Subsequently, then same command has been executed against production database. The output looks like followings: