Page Comparison

...

• 18:00 (Patrick) Recreated 5 CM tables
• 11:30 (Thomas) Finding average cpu_time for queries that run longer than one second

  • No Format
    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
  • AWR 2007-10-09 10:00
• 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)

  • No Format

    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)

  • No Format

    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

...