SmartSite Production Database Performance Troubleshooting

Owned by devtools@ucdavis.edu
Last updated: Oct 14, 2007 by AnonymousVersion comment

Proposed Solutions

  • As we learned from today's Oracle Tuning class, disabling Automatic Storage Management (ASM) could potentially fix our index problems
  • Change Oracle's statistics gathering function to run between 03:00 - 04:00 instead at 22:00
    • Oracle assumes to be the only active user during stats gathering
    • All the tables, indexes, views need to be created in the same order via scripts
  • Switch to RBO (Rule Based Optimizer) for certain views
    • Eventual deterministic/stable performance after queries have been tuned
    • Need to be careful that we're not joining these non-analyzed tables to analyzed ones
    • We may need to switch our OPTIMIZER_MODE setting over to CHOOSE?
  • Keep in mind after rebuilding the CM tables there are only 2 tables and 2 queries that run into trouble regularly.  We should be careful not to implement DB wide strategies to attack these 2 problems.   We need to understand why they differ and see if they can be tuned. (KA)

Activity Log

Sunday 10-14-2007

Satruday 10-13-2007

  • 19:30 (Drew) I remember I mentioned the parameter OPTIMIZER_INDEX_COST_ADJ and you answered that you have tried to lower the parameter to as
    low as 20 and it did not work. I did some my own tests today with tables that have 168K rows and a query that has similar structure as the CM
    query we discussed, i.e, all rows in the select statement comes from one table and none from the other table. The purpose of my tests was to
    see if adjust the OPTIMIZER_INDEX_COST_ADJ can change the execution plan. I adjust that parameter using "alter session"|| so that other session
    will not be affected. The parameter can also be adjusted on system level, which will affect all the sessions in the database. The index on
    PROVIDER_ID is not a unique index. The following are my test results.
    The first two tests were when the parameter set to 100. Those two tests show when rows are selected from one table, that table will be full
    table scanned. Then I start to adjust the OPTIMIZER_INDEX_COST_ADJ. Just as what you have said, as low as 20 will not change the execution
    plan. In my case, even as low as 5 still does not use the index. So, I adjust that parameter to 1, the lowest possible value. The execution
    plan finally pick up the index and no more full table scan. The detail tests steps are shown below.
    I am not suggesting anythings here to you and I just want to share my test results, in case you are interested in doing similar tests on your
    query. Since I don't know if the modification of the parameter will change other queries' behavior, I think more tests have to be done to
    determine if it's good or bad. In my case, it only needs about 10 minutes to do all the tests.

Friday 10-12-2007

  • 15:57 (Patrick) The way things are currently configured on caje, the 5 tables will be switched at 6am and 6pm each
    day. The autostats window is now set for 5am Monday-Friday. That means the tables will have stats on them for at
    most one hour.

Thursday 10-11-2007

  • 06:07 (Patrick) Recreated 5 CM tables

Wednesday 10-10-2007

  • 23:18 (Prabhu) 
    • I think, we need to verify colums widths/datatypes of underlying tables, view, mviews. 
In case of a join same columns of different tables should have same datatype and column length to make CBO work correctly.
On RAC and TEST i set the hidden parameter "_keep_remote_column_size" to TRUE, which will allow mviews to maintain the column size same as its source(banner). 
We did not have this parameter set to true in production. When we had a problem with mview refresh, we fixed it by
altering the column widths of following as below. This was a quick fix from oracle support. I feel, it is worth trying to set this paramter and recreate these two mviews.
Thanks,
Prabhu
alter table BANNER_ENROLLMENTSET modify CATEGORY varchar2(25);
alter table BANNER_ENROLLMENTSET modify CREATEDBY varchar2(25);
alter table BANNER_ENROLLMENTSET modify LASTMODIFIEDBY varchar2(25);
alter table BANNER_ENROLLMENT modify CREATEDBY varchar2(25);
alter table BANNER_ENROLLMENT modify LASTMODIFIEDBY varchar2(25);
alter table BANNER_CM_SECTION modify CREATEDBY varchar2(25);
alter table BANNER_CM_SECTION modify LASTMODIFIEDBY varchar2(25);
  • 22:19 (Prabhu) Removed Stats from COURSEMANAGEMENT_INSTRUCT_TA, COURSEMANAGEMENT_SECTION_TA and all associated Indexes
  • 18:07 (Prabhu) Recreated 5 CM tables
  • 06:07 (Prabhu) Recreated 5 CM tables

Tuesday 10-09 2007

  • 22:04 (Kirk) Seeing full table scans. (Thomas) Running FullTableAccess.grooy shows: 
    • TIMESTAMP: 10-09-2007 22:04:46
OPERATION: TABLE ACCESS
OPTIONS: FULL
OBJECT_OWNER: SAKAI_EXTERNAL
OBJECT_TYPE: TABLE
TIME: 77
COST: 6366
CARDINALITY: 457617
BYTES: 198605778
CPU_COST: 375633528
IO_COST: 6339
SQL_FULLTEXT: /* Formatted on 2007/10/06 22:27 (Formatter Plus v4.8.6) */SELECT sectioncmi0_.eid AS eid248_, sectioncmi0_.CATEGORY AS category248_,
sectioncmi0_.title AS title248_,       sectioncmi0_.description AS descript4_248_,       sectioncmi0_.createdby AS createdby248_,       sectioncmi0_.createddate AS createdd6_248_,       sectioncmi0_.lastmodifiedby AS lastmodi7_248_,       sectioncmi0_.lastmodifieddate AS lastmodi8_248_,       sectioncmi0_.courseoffering_eid AS courseof9_248_,       sectioncmi0_.enrollmentset_eid AS enrollm10_248_,       sectioncmi0_.PARENT AS parent248_, sectioncmi0_.MAXSIZE AS maxsize248_  FROM coursemanagement_section sectioncmi0_,       coursemanagement_instructors instructor1_ WHERE instructor1_.section_eid = sectioncmi0_.eid   AND instructor1_.person_eid = '00125158'

TIMESTAMP: 10-09-2007 22:04:46
OPERATION: TABLE ACCESS
OPTIONS: FULL
OBJECT_OWNER: SAKAI_EXTERNAL
OBJECT_TYPE: TABLE
TIME: 77
COST: 6366
CARDINALITY: 457617
BYTES: 198605778
CPU_COST: 375633528
IO_COST: 6339
SQL_FULLTEXT: /* Formatted on 2007/10/06 22:27 (Formatter Plus v4.8.6) */SELECT sectioncmi0_.eid AS eid248_, sectioncmi0_.CATEGORY AS category248_,
sectioncmi0_.title AS title248_,       sectioncmi0_.description AS descript4_248_,       sectioncmi0_.createdby AS createdby248_,
sectioncmi0_.createddate AS createdd6_248_,       sectioncmi0_.lastmodifiedby AS lastmodi7_248_,       sectioncmi0_.lastmodifieddate AS lastmodi8_248_,      sectioncmi0_.courseoffering_eid AS courseof9_248_,       sectioncmi0_.enrollmentset_eid AS enrollm10_248_,       sectioncmi0_.PARENT AS parent248_, sectioncmi0_.MAXSIZE AS maxsize248_  FROM coursemanagement_section sectioncmi0_,       coursemanagement_instructors instructor1_ WHERE
instructor1_.section_eid = sectioncmi0_.eid   AND instructor1_.person_eid = '00125158'

  • 18:00 (Patrick) Recreated 5 CM tables
  • 11:30 (Thomas) Finding average cpu_time for queries that run longer than one second 
    • select cpu_time / 1000000 / executions as average_cpu_time, executions, first_load_time, last_load_time, last_active_time, sql_text
from v$sql
where parsing_schema_name = 'SAKAI_EXTERNAL'
and cpu_time / 1000000 / executions > 1
and sql_text like 'select %'
order by cpu_time desc;

  • 10:00 (Prabhu) AWR Report
  • 08:52 (Kirk)
    • Drew, What else could the statistics run be doing to slow down our queries? To recover should we
      have also deleted the stats on the indexes for the tables involved? All we know for sure is
      that the queries run find when the tables have been built from scratch and no stats have been run.
      Prabhu, I see you get better output from your sqlplus when you do the autotrace traceonly.
      Is this based on your version of sqlplus or is there something else I need to do to get
      the display of the %CPU cost that I see in your traces?
  • 06:47 (Drew) 
    • I don't think I am convinced the delete stats is working according your results.  Yes, the query uses indexes
after deleting the stats. However, from the stats and the Elapsed time I know the query performance is not
improving.  Even though the query is using the index, it's performance may not improving.  The Elapsed time 1s
still 19 seconds.  Also, the consistent gets and physical read are too high and the query is still slow.
You second AWR did not covered long enough and would not catch the query.  In the first AWR report, it covered
47 minutes and the slow query (looks like a different one based on the sql_id) was executed only 2 times.  The
second report's 2.7 minutes may not catch the slow query at all.  You need a longer period between the
snapshots for the report.
Go back to the trace, the one I said Yes, you will see the difference.  Please don't just see if the index is
used, you need to see how fast you can get the data. I copy the one I say worked fine here to save your time
going back.  You can comparing the two and see the difference.

Thanks,
Drew

Look at the difference:
13 rows selected.
Elapsed: 00:00:00.01

58  consistent gets
0  physical reads

<good one>
I ran the trace for this query now and seems indexex are being used. I also attached a awr between 8:00 am and 9:00 am, which is after rebuilding the tables. I am also planing to take awr before and after 10:00 pm and see show these plans are changing. if it not in relation with stats, we can focus on HWM and think of segment shrinking.

select sectioncmi0_.EID as EID248_, sectioncmi0_.CATEGORY as
2  CATEGORY248_, sectioncmi0_.TITLE as TITLE248_, sectioncmi0_.DESCRIPTION
3  as DESCRIPT4_248_, sectioncmi0_.CREATEDBY as CREATEDBY248_,
4  sectioncmi0_.CREATEDDATE as CREATEDD6_248_, sectioncmi0_.LASTMODIFIEDBY
5  as LASTMODI7_248_, sectioncmi0_.LASTMODIFIEDDATE as LASTMODI8_248_,
6  sectioncmi0_.COURSEOFFERING_EID as
7  COURSEOF9_248_,sectioncmi0_.ENROLLMENTSET_EID as ENROLLM10_248_,
8  sectioncmi0_.PARENT as PARENT248_, sectioncmi0_.MAXSIZE as MAXSIZE248_
9  from sakai_external.COURSEMANAGEMENT_SECTION sectioncmi0_, sakai_external.COURSEMANAGEMENT_INSTRUCTORS
10  instructor1_
11  where instructor1_.SECTION_EID=sectioncmi0_.EID and
12  instructor1_.PERSON_EID='00125158';
13 rows selected.
Elapsed: 00:00:00.01
Execution Plan
----------------------------------------------------------
Plan hash value: 616479917
--------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name                         | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |                              |    23 | 56051 |    66   (0)| 00:00:01 |
|   1 |  TABLE ACCESS BY INDEX ROWID  | COURSEMANAGEMENT_SECTION_TB  |     2 |  4758 |     4   (0)| 00:00:01 |
|   2 |   NESTED LOOPS                |                              |    23 | 56051 |    66   (0)| 00:00:01 |
|   3 |    TABLE ACCESS BY INDEX ROWID| COURSEMANAGEMENT_INSTRUCT_TB |    13 |   754 |    14   (0)| 00:00:01 |
|*  4 |     INDEX RANGE SCAN          | CM_INST_TB_PERSON_IDX        |    13 |       |     3   (0)| 00:00:01 |
|*  5 |    INDEX RANGE SCAN           | CM_SECTION_TB_EID_IDX        |     2 |       |     2   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
4 - access("INSTRUCTOR1_"."PERSON_EID"='00125158')
5 - access("INSTRUCTOR1_"."SECTION_EID"="SECTIONCMI0_"."EID")
Note
-----
- dynamic sampling used for this statement

Statistics
----------------------------------------------------------
0  recursive calls
0  db block gets
58  consistent gets
0  physical reads
0  redo size
11946  bytes sent via SQL*Net to client
400  bytes received via SQL*Net from client
2  SQL*Net roundtrips to/from client
0  sorts (memory)
0  sorts (disk)
13  rows processed
------------------------------------------------------------------------
</good one>

  • 06:00 (Patrick) Recreated 5 CM tables
  • 00:18 (Kirk) 
    • Verified that only the 2 tables have lost their stats:

SQL Statement which produced this data:
select table_name, to_char(last_analyzed,'mm/dd/yyyy hh24:mi:ss')
from user_tables where lower(table_name) like 'coursemanagement_%'

TABLE_NAME                     TO_CHAR(LAST_ANALYZED,'MM/DD/YYYYHH24:MI:SS')
COURSEMANAGEMENT_ENROLLMENT_TA 10/08/2007 22:01:33                          COURSEMANAGEMENT_ENROLLMENT_TB 10/08/2007 22:01:47                          COURSEMANAGEMENT_INSTRUCT_TA   NULL                                         COURSEMANAGEMENT_INSTRUCT_TB   10/08/2007 22:01:10                          COURSEMANAGEMENT_MEMBERSHIP_TA 10/08/2007 22:00:39                          COURSEMANAGEMENT_MEMBERSHIP_TB 10/08/2007 22:00:18                          COURSEMANAGEMENT_OFFERING_TA   10/08/2007 22:00:11                          COURSEMANAGEMENT_OFFERING_TB   10/08/2007 22:00:08                          COURSEMANAGEMENT_SECTION_TA    NULL                                         COURSEMANAGEMENT_SECTION_TB    10/08/2007 22:02:05
and none of the indexes lost theirs:

SQL Statement which produced this data:
select index_name, to_char(last_analyzed,'mm/dd/yyyy hh24:mi:ss')
from user_indexes where lower(index_name) like '%cm_enroll_t%'

INDEX_NAME                     TO_CHAR(LAST_ANALYZED,'MM/DD/YYYYHH24:MI:SS')
CM_ENROLL_TA_EID_IDX           10/08/2007 22:01:33                          CM_ENROLL_TA_ES_IDX            10/08/2007 22:01:34                          CM_ENROLL_TA_PERSON_IDX        10/08/2007 22:01:37                          CM_ENROLL_TB_EID_IDX           10/08/2007 22:01:50                          CM_ENROLL_TB_ES_IDX            10/08/2007 22:01:51                          CM_ENROLL_TB_PERSON_IDX        10/08/2007 22:01:55

Monday 10-08-2007

  • 23:42 (Prabhu) 
    • Here is what I have done.
1. ran our problem query(section) at 10:30pm after stats. Noticed full scans.
2. took AWR
3. dropped stats for the two tables involved in the query.
4. ran the query again. Noticed idexes being used.
5. took AWR
6. reran the query to make sure indexes are in place
PS: cron job will be switching tables from "A" to "B" tomorrow at 06:00 hrs.

    • AWR 2007-10-08 22:00
    • AWR 2007-10-08 23:19
  • 22:39 (Thomas) Detected Full Table Access 
    • TIMESTAMP: 10-08-2007 22:39:25
OPERATION: TABLE ACCESS
OPTIONS: FULL
OBJECT_OWNER: SAKAI_EXTERNAL
OBJECT_TYPE: TABLE
TIME: 79
COST: 6506
CARDINALITY: 456438
BYTES: 199463406
CPU_COST: 379747898
IO_COST: 6479
SQL_FULLTEXT: SELECT sectioncmi0_.eid AS eid248_, sectioncmi0_.CATEGORY AS category248_,sectioncmi0_.title AS
title248_,sectioncmi0_.description AS descript4_248_,sectioncmi0_.createdby AS createdby248_,sectioncmi0_.createddate
 AS createdd6_248_,sectioncmi0_.lastmodifiedby AS lastmodi7_248_,sectioncmi0_.lastmodifieddate AS
lastmodi8_248_,sectioncmi0_.courseoffering_eid AS courseof9_248_,sectioncmi0_.enrollmentset_eid AS
enrollm10_248_,sectioncmi0_.PARENT AS parent248_, sectioncmi0_.MAXSIZE ASmaxsize248_FROM
sakai_external.coursemanagement_section sectioncmi0_,sakai_external.coursemanagement_instructors instructor1_WHERE
instructor1_.section_eid = sectioncmi0_.eidAND instructor1_.person_eid = '00125158'

  • 22:23 (Thomas) Detected Full Table Access 
    • TIMESTAMP: 10-08-2007 22:23:00
OPERATION: TABLE ACCESS
OPTIONS: FULL
OBJECT_OWNER: SAKAI_EXTERNAL
OBJECT_TYPE: TABLE
TIME: 79
COST: 6506
CARDINALITY: 456438
BYTES: 199463406
CPU_COST: 379747898
IO_COST: 6479
SQL_FULLTEXT: /* Formatted on 2007/10/08 22:22 (Formatter Plus v4.8.6) */SELECT sectioncmi0_.eid AS eid248_,
sectioncmi0_.CATEGORY AS category248_,       sectioncmi0_.title AS title248_,       sectioncmi0_.description AS
descript4_248_,       sectioncmi0_.createdby AS createdby248_,       sectioncmi0_.createddate AS createdd6_248_,
sectioncmi0_.lastmodifiedby AS lastmodi7_248_,       sectioncmi0_.lastmodifieddate AS lastmodi8_248_,
sectioncmi0_.courseoffering_eid AS courseof9_248_,       sectioncmi0_.enrollmentset_eid AS enrollm10_248_,
sectioncmi0_.PARENT AS parent248_, sectioncmi0_.MAXSIZE AS maxsize248_  FROM coursemanagement_section sectioncmi0_,
coursemanagement_instructors instructor1_ WHERE instructor1_.section_eid = sectioncmi0_.eid   AND instructor1_.person_eid = :1

  • 08:57 (Drew) 
    • After reading how the tables are created and the synonyms are used in the database, I start to think the execution plan
mess could be caused by the use of synonyms (just think).  Please read the following two articles/email regarding the
synonym and performance.
http://expertanswercenter.techtarget.com/eac/knowledgebaseAnswer/0,295199,sid63_gci977691,00.html
http://www.freelists.org/archives/oracle-l/11-2004/msg00075.html
In the first article, it says "The use of private synonyms can cause multiple versions of the same SQL text to be
maintained in the library cache, thus reducing the sharing of SQL".  I would think this is even true when we have
different table definitions.
I am thinking if you can test a procedure without using synonyms like the following: One set of script will cover all
the reload.  The "alter table rename" is as fast as you create the synonym.

<>
--The table coursemanagement_section_new and all it's indexes have been created.
--Two set of the tables are used.  Only one reload script is needed.

INSERT INTO coursemanagement_section_new SELECT * FROM coursemanagement_section_v;
commit;

alter table coursemanagement_section rename to coursemanagement_section_old;
alter table coursemanagement_section_new rename to coursemanagement_section;
analyze table coursemanagement_section compute statistics;
alter table coursemanagement_section_old rename to coursemanagement_section_new;
truncate table coursemanagement_section_new;

--repeat the above in each relaod.
--That will get rid of the synonym.
</>
This is just some thoughts based on the articles on synonyms and I don't know if this can resolve the problem. I think
it worth of trying if other options cannot resolve the problem. In case you don't have access to the first website
listed above, I copy the text and attach it at the end of this note (see below).

  • 05:05 (Patrick) At of 5:05 am, Monday, 10/8, the "B" set of external tables are current and in production.

Sunday 10-07-2007

  • 14:11 (Prabhu) Created AWR report:
  • 14:09 (Drew) 
    • If you are sure without stats will help the performance (as Prabhu as shown the table has not been analyzed), after
 the auto stats collection, run the following as a DBA, will delete the table stats:

EXEC DBMS_STATS.delete_table_stats('SAKAI_EXTERNAL', 'COURSEMANAGEMENT_SECTION_TA');
or
EXEC DBMS_STATS.delete_table_stats('SAKAI_EXTERNAL', 'COURSEMANAGEMENT_SECTION_TB');

This will remove the stats for that table and put the table into a status as of now, which makes the query perform better.
Can you run a AWR report and an autotrace and make sure the non-stats table performs better (as of now)?
Be careful if you remove the stats of a table because it may affect other queries.



  • 13:05 (Drew) 
    • I forgot to mention this parameter can be adjusted on line without affecting end users.  When you see the full table
scan (with all the stats), you adjust this parameter (as sys) and then run the plan and stats (set autotrace traceonly)
in the application owner account and see if you can see the plan change.  This parameter is easy to adjust without
shutting down the database.  When I worked at at Ford Motor company, we adjusted that parameter to achieve better
performance.



  • 12:51 (Drew) 
    • Without the stats, the query will use rule-based optimizer (RBO) and will pick up all of the indexes it can find because
it's one of the rules.  Generally, if the tables are created correctly, the stats would certainly help.  The query is a
simple one and should not be difficult for CBO to find the best way.  Here I think the drop and recreate table is not a
good practice in that case.  The two tables  (before dropped and the recreated one) are different objects in the database
with different object id. Oracle will gather stats for that table for sure.

If you run:
select table_name, to_char(last_analyzed,'mm/dd/yyyy hh24:mi:ss') from user_tables where lower(table_name)='coursemanagement_section_ta';

You will find when it's last analyzed.
Have you tried to adjust this parameter, optimizer_index_cost_adj ?
If not, please try to read through the following and see if that can help.  To start with, you can let this parameter equals 50.
http://www.dba-oracle.com/oracle_tips_cost_adj.htm



  • 12:20 (Prabhu) I disable monitor when tables dropped and enable when new ones created as below. 
    • ---Enable monitoring
SQL> alter index sakai_external.CM_INST_TA_PERSON_IDX monitoring usage;
Index altered.
SQL> alter index sakai_external.CM_SECTION_TA_EID_IDX monitoring usage;
Index altered.
SQL> select index_name, table_name, monitoring, used, end_monitoring from v$object_usage;
no rows selected

---Disable monitoring
alter index sakai_external.CM_INST_TB_PERSON_IDX nomonitoring usage;
alter index sakai_external.CM_SECTION_TB_EID_IDX nomonitoring usage;



  • 07:00 (Patrick) I've rebuilt the TA tables with current data and the synonyms now point there. The job completed at 7am.

Saturday 10-06-2007

  • 24:00 (Oracle) run stats
  • 06:58 (Patrick) I switched to the recreated TB tables. The job started at 6:58am and completed at 7:06.
    • I checked the problem query on both the TA and TB tables and it looks like the indexes are still being used.
    • I noticed that there are 151 pairs of duplicate EID's in the SECTION table. Have we considered changing the view to weed those out?

Friday 10-05-2007

  • 22:00 (Oracle) run stats
  • 14:49 (Patrick) 
    • Thanks, Brian. I created the indexes and added these statements to the
script that recreates the tables for the synonym switch. There are
currently no outstanding queries in the poor performance category.



  • 11:43 (Brian) 
    • Oh, I see, I didn't put an index on it because it was all null.  Okay,
here are indexes for the courseset_eid and courseoffering_eid columns,
both of which are all null.

CREATE INDEX CM_MEMBERSHIP_TA_CS_IDX ON COURSEMANAGEMENT_MEMBERSHIP_TA
(COURSESET_EID) STORAGE(INITIAL 50M NEXT 10M);
CREATE INDEX CM_MEMBERSHIP_TB_CS_IDX ON COURSEMANAGEMENT_MEMBERSHIP_TB
(COURSESET_EID) STORAGE(INITIAL 50M NEXT 10M);

CREATE INDEX CM_MEMBERSHIP_TA_CO_IDX ON COURSEMANAGEMENT_MEMBERSHIP_TA
(COURSEOFFERING_EID) STORAGE(INITIAL 50M NEXT 10M);
CREATE INDEX CM_MEMBERSHIP_TB_CO_IDX ON COURSEMANAGEMENT_MEMBERSHIP_TB
(COURSEOFFERING_EID) STORAGE(INITIAL 50M NEXT 10M);

That will create the indexes on both tables.



  • 11:18 (Patrick) 
    • sar -q
Linux 2.6.9-55.0.6.ELsmp (caje)         10/05/2007

12:00:01 AM   runq-sz  plist-sz   ldavg-1   ldavg-5  ldavg-15
12:10:01 AM         1      1211      0.72      0.91      0.98
02:10:01 AM         0      1211      0.12      0.18      0.47
02:20:02 AM         0      1215      1.32      1.28      0.89
02:30:01 AM         0      1209      0.09      0.36      0.61
02:40:01 AM         0      1211      0.05      0.14      0.37
02:50:01 AM         0      1215      0.95      0.49      0.38
03:00:09 AM         1      1212      0.05      0.39      0.45
03:10:01 AM         0      1211      0.23      0.20      0.31
03:20:01 AM         0      1214      0.21      0.20      0.24
03:30:01 AM         1      1208      1.15      0.91      0.57
03:40:01 AM         0      1210      0.06      0.45      0.54
03:50:02 AM         0      1217      0.52      0.28      0.37
04:00:01 AM         1      1214      1.21      1.36      0.93
04:10:02 AM         0      1225      1.55      1.86      1.45
04:20:02 AM         0      1226      1.24      1.54      1.42
04:30:02 AM         0      1220      1.36      1.19      1.26
04:40:02 AM         0      1220      1.14      1.45      1.41
04:50:07 AM         0      1224      1.34      1.28      1.28
05:00:06 AM         1      1220      1.32      1.36      1.34
06:00:01 AM         0      1215      0.65      0.33      0.51
06:40:02 AM         0      1212      1.16      0.75      0.66
07:20:01 AM         0      1222      1.57      2.18      1.83
07:40:01 AM         1      1213      0.63      1.14      1.64
08:00:01 AM         5      1216      4.51      3.28      2.21
08:40:04 AM        13      1227     17.44     17.31     12.78
08:50:13 AM        14      1254     20.77     19.95     16.40
09:10:19 AM         9      1235     21.66     23.12     20.19
09:30:01 AM         0      1237      1.48      3.77     10.36
09:40:01 AM         0      1236      0.57      1.29      5.91
10:00:06 AM         2      1235      1.67      1.40      2.42
Average:            2      1220      2.89      3.01      3.01

It's really frustrating that, even at 7:40am, the system is breezing
along.

Prabhu and I will work to schedule a rebuild of the tables at 7:00 am
each morning.
That job runs about 20 minutes. We will then switch the synonyms by
7:30am.

We are also opening a service request with Oracle.



  • 11:17 (Drew) 
    • If execution plan stability is an issue for you after modifying the Oracle default window, you can consider the Plan Stability specified in this Oracle document:
http://download.oracle.com/docs/cd/B19306_01/server.102/b14211/outlines.htm#sthref1787



  • 09:07 (Patrick) 
    • This query is active for a number of sessions (around 10)  today:

select sectioncmi0_.EID as EID248_, sectioncmi0_.CATEGORY as
CATEGORY248_, sectioncmi0_.TITLE as TITLE248_, sectioncmi0_.DESCRIPTION
as DESCRIPT4_248_, sectioncmi0_.CREATEDBY as CREATEDBY248_,
sectioncmi0_.CREATEDDATE as CREATEDD6_248_, sectioncmi0_.LASTMODIFIEDBY
as LASTMODI7_248_, sectioncmi0_.LASTMODIFIEDDATE as LASTMODI8_248_,
sectioncmi0_.COURSEOFFERING_EID as
COURSEOF9_248_,sectioncmi0_.ENROLLMENTSET_EID as ENROLLM10_248_,
sectioncmi0_.PARENT as PARENT248_, sectioncmi0_.MAXSIZE as MAXSIZE248_
from COURSEMANAGEMENT_SECTION sectioncmi0_, COURSEMANAGEMENT_INSTRUCTORS
instructor1_ where instructor1_.SECTION_EID=sectioncmi0_.EID and
instructor1_.PERSON_EID=:1

Here is the explain plan:

SELECT STATEMENT ()
TABLE ACCESS (BY INDEX ROWID)
COURSEMANAGEMENT_INSTRUCT_TA
NESTED LOOPS ()
TABLE ACCESS (FULL)
COURSEMANAGEMENT_SECTION_TA
INDEX (RANGE SCAN)
CM_INST_TA_PERSON_IDX



  • 08:47 (Patrick) (error) Building a set of new tables after DB performance degraded

Thursday 10-04-2007

  • 15:20 (Patrick) Run coursemanagement_merge_procs.sql
    • coursemanagement_merge_procs.sql
    • Script run fine for:
      • coursemanagement_section
      • coursemanagement_offering
    • coursemanagement_enrollment
    • Script hung during the delete records process for:
      • coursemanagement_instructors
      • coursemanagement_membership
  • 11:35 (Patrick) (error) Recreated the 5 CM tables after DB load increased over 20

Wednesday 10-03-2007

  • ... ?

Tuesday 10-02-2007

  • 2.4.x Head prod 001 Installed

Monday 10-01-2007

  • ... ?

Sunday 09-30-2007

  • ... ?

Saturday 09-29-2007

  • ... ?