Results 1 to 5 of 5
  1. #1
    Join Date
    Aug 2006
    Posts
    5

    Unanswered: Slow query with customer data

    Dear all,

    we have an Oracle 10.2.0.3.0 Database installed on a Solaris 10 operating system. The hardware is a Sun Fire 480R 2x1050MHz US-III+ CPU and 4GB RAM 3x147GB SCSI disks.

    The problem is the following:
    We import customer data via impdp. The table contains ~1.5 million records and the size is ~ 1.2GB. The table is partitioned and after the import only the first partition is used. After the import we have gathered all statistics and rebuild all indexes.

    After that one of our query needs ~40min to execute. However the same query execute ~20sec if we use own data (of course similar amount and characteristic). Besides this it was also fast on the customer machine before the export and import.

    The query is generated by a ProC code and makes a join between 3 tables, but only the main table contains data, the other 2 are empty.

    From the tkprof results (see below) I can see that in the slow case we have a very high disk IO. However I don't know why the big difference between the 2 cases.

    Any ideas, tips how to proceed?

    Thanks in advance!

    The slow query:

    SELECT count(*) /*+ ordered use_nl(TAB1 TAB2 TAB3) index(TAB1 ALARMLOG_IDX_1) index(TAB2 LOG_STATECHANGEDEF_IDX) index(TAB3 LOG_MONITOREDALARM_IDX) */
    FROM alarmLog TAB1, OMCDBSYS.LOG_stateChangeDef TAB2, OMCDBSYS.LOG_monitoredAlarm TAB3
    WHERE tab1.logRecordId = tab2.stateChangeDefLogRecordId(+)
    AND tab1.logRecordId = tab3.monitoredAlarmLogRecordId(+)
    AND (((NOT (perceivedSeverity=:"SYS_B_0") AND managedObjectClass LIKE :"SYS_B_1" ESCAPE(CHR(:"SYS_B_2")) )
    AND (eventTime>=TO_DATE(:"SYS_B_3", :"SYS_B_4")
    AND eventTime<=TO_DATE(:"SYS_B_5", :"SYS_B_6"))))
    ORDER BY eventTime DESC , eventTime DESC

    call count cpu elapsed disk query current rows
    ------- ------ -------- ---------- ---------- ---------- ---------- ----------
    Parse 1 0.00 0.00 0 0 0 0
    Execute 1 0.00 0.00 0 0 0 0
    Fetch 2 94.27 2807.14 385336 1387196 0 1
    ------- ------ -------- ---------- ---------- ---------- ---------- ----------
    total 4 94.27 2807.15 385336 1387196 0 1

    Misses in library cache during parse: 0
    Optimizer mode: ALL_ROWS
    Parsing user id: SYS

    Rows Row Source Operation
    ------- ---------------------------------------------------
    1 SORT AGGREGATE (cr=1387196 pr=385336 pw=0 time=2807150241 us)
    374 FILTER (cr=1387196 pr=385336 pw=0 time=8272413 us)
    374 NESTED LOOPS OUTER (cr=1387196 pr=385336 pw=0 time=8271970 us)
    374 NESTED LOOPS OUTER (cr=1386448 pr=385324 pw=0 time=8262217 us)
    374 NESTED LOOPS (cr=1385700 pr=385312 pw=0 time=8249795 us)
    2 SORT UNIQUE (cr=3 pr=0 pw=0 time=570 us)
    2 TABLE ACCESS FULL PARTITION_TABLE (cr=3 pr=0 pw=0 time=252 us)
    374 PARTITION RANGE ITERATOR PARTITION: KEY KEY (cr=1385697 pr=385312 pw=0 time=8251938 us)
    374 TABLE ACCESS BY LOCAL INDEX ROWID ALARMLOG PARTITION: KEY KEY (cr=1385697 pr=385312 pw=0 time=8251501 us)
    1383458 INDEX RANGE SCAN PK_ALARMLOG PARTITION: KEY KEY (cr=3670 pr=3330 pw=0 time=5537332 us)(object id 13437)
    0 PARTITION RANGE ALL PARTITION: 1 2 (cr=748 pr=12 pw=0 time=81208 us)
    0 INDEX RANGE SCAN LOG_MONITOREDALARM_IDX PARTITION: 1 2 (cr=748 pr=12 pw=0 time=77616 us)(object id 13445)
    0 PARTITION RANGE ALL PARTITION: 1 2 (cr=748 pr=12 pw=0 time=112506 us)
    0 INDEX RANGE SCAN LOG_STATECHANGEDEF_IDX PARTITION: 1 2 (cr=748 pr=12 pw=0 time=109757 us)(object id 13449)
    And the fast one:

    SELECT count(*) /*+ ordered use_nl(TAB1 TAB2 TAB3) index(TAB1 ALARMLOG_IDX_1) index(TAB2 LOG_STATECHANGEDEF_IDX) index(TAB3 LOG_MONITOREDALARM_IDX) */
    FROM alarmLog TAB1, OMCDBSYS.LOG_stateChangeDef TAB2, OMCDBSYS.LOG_monitoredAlarm TAB3
    WHERE tab1.logRecordId = tab2.stateChangeDefLogRecordId(+)
    AND tab1.logRecordId = tab3.monitoredAlarmLogRecordId(+)
    AND (((NOT (perceivedSeverity=:"SYS_B_0") AND managedObjectClass LIKE :"SYS_B_1" ESCAPE(CHR(:"SYS_B_2")) )
    AND (eventTime>=TO_DATE(:"SYS_B_3", :"SYS_B_4")
    AND eventTime<=TO_DATE(:"SYS_B_5", :"SYS_B_6"))))
    ORDER BY eventTime DESC , eventTime DESC

    call count cpu elapsed disk query current rows
    ------- ------ -------- ---------- ---------- ---------- ---------- ----------
    Parse 1 0.00 0.00 0 0 0 0
    Execute 1 0.00 0.00 0 0 0 0
    Fetch 2 5.23 5.14 0 35973 0 1
    ------- ------ -------- ---------- ---------- ---------- ---------- ----------
    total 4 5.23 5.14 0 35973 0 1

    Misses in library cache during parse: 0
    Optimizer mode: ALL_ROWS
    Parsing user id: SYS

    Rows Row Source Operation
    ------- ---------------------------------------------------
    1 SORT AGGREGATE (cr=35973 pr=0 pw=0 time=5140817 us)
    0 FILTER (cr=35973 pr=0 pw=0 time=5140722 us)
    0 HASH JOIN RIGHT SEMI (cr=35973 pr=0 pw=0 time=5140653 us)
    1 TABLE ACCESS FULL PARTITION_TABLE (cr=3 pr=0 pw=0 time=385 us)
    0 NESTED LOOPS OUTER (cr=35970 pr=0 pw=0 time=5138069 us)
    0 NESTED LOOPS OUTER (cr=35970 pr=0 pw=0 time=5138060 us)
    0 PARTITION RANGE SINGLE PARTITION: 1 1 (cr=35970 pr=0 pw=0 time=5138054 us)
    0 TABLE ACCESS BY LOCAL INDEX ROWID ALARMLOG PARTITION: 1 1 (cr=35970 pr=0 pw=0 time=5138028 us)
    1500001 INDEX RANGE SCAN ALARMLOG_IDX_1 PARTITION: 1 1 (cr=7699 pr=0 pw=0 time=1500094 us)(object id 12001)
    0 PARTITION RANGE SINGLE PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us)
    0 INDEX RANGE SCAN LOG_STATECHANGEDEF_IDX PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us)(object id 12009)
    0 PARTITION RANGE SINGLE PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us)
    0 INDEX RANGE SCAN LOG_MONITOREDALARM_IDX PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us)(object id 12005)

  2. #2
    Join Date
    Aug 2004
    Location
    France
    Posts
    754
    So same database version, same data, same indexes, same query...

    - Have statistics been gathered the same way on both databases ? (ANALYZE or DBMS_STATS for example... BTW DBMS_STATS should be used)
    - Have statistics been gathered on ALL tables and indexes concerned by the query ? (not only the main table)
    - Can you check that tables have the exact same indexes AND foreign keys (and that they are activated) ?

    Ah ! You have put a USE_NL hint that tries to force the optimizer to choose NESTED LOOPS for all JOINS between the 3 tables. Though, you can see that the good performing query uses a HASH JOIN as the outer-most join.

    I would first try to delete the USE_NL hint, you can keep the INDEX hints if you wish but you could try a first shot with no hint at all and see what happens.
    ORA-000TK : No bind variable detected... Shared Pool Alert code 5 - Nuclear query ready .

  3. #3
    Join Date
    Aug 2006
    Posts
    5
    Thanks!

    Unfortunately the SQL code is generated by a C program so I can not change it.

    Sometimes the query become fast but if I try to reproduce it (start everything from the beginning with DB install) then it is slow again.

    Here is an execution plan output. The only difference is that the second query was executed 10 hours later then the first on.

    SQL> SELECT count(*) /*+ ordered use_nl(TAB1 TAB2 TAB3) index(TAB1 ALARMLOG_IDX_1) index(TAB2 LOG_STATECHANGEDEF_IDX) index(TAB3 LOG_MONITOREDALARM_IDX) */
    FROM alarmLog TAB1, OMCDBSYS.LOG_stateChangeDef TAB2, OMCDBSYS.LOG_monitoredAlarm TAB3
    WHERE tab1.logRecordId = tab2.stateChangeDefLogRecordId(+)
    AND tab1.logRecordId = tab3.monitoredAlarmLogRecordId(+)
    2 AND (((NOT (perceivedSeverity=5) AND managedObjectClass LIKE '%ES%' ESCAPE(CHR(0)) )
    AND (eventTime>=TO_DATE('20071231220000', 'YYYYMMDDHH24MISS')
    AND eventTime<=TO_DATE('20080824220000', 'YYYYMMDDHH24MISS'))))
    ORDER BY eventTime DESC , eventTime DESC; 3 4 5 6 7 8

    COUNT(*)/*+ORDEREDUSE_NL(TAB1TAB2TAB3)INDEX(TAB1ALARMLOG_ID X_1)INDEX(TAB2LOG_STATECHANGEDEF_IDX)INDEX(TAB3LOG _MONITOREDALARM_IDX)*/
    -----------------------------------------------------------------------------------------------------------------------------------
    374

    Elapsed: 00:52:30.66

    Execution Plan
    ----------------------------------------------------------
    Plan hash value: 2579350973

    -----------------------------------------------------------------------------------------------------------------------
    | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | Pstart| Pstop |
    -----------------------------------------------------------------------------------------------------------------------
    | 0 | SELECT STATEMENT | | 1 | 68 | 10996 (2)| 00:02:12 | | |
    | 1 | SORT AGGREGATE | | 1 | 68 | | | | |
    |* 2 | HASH JOIN RIGHT OUTER | | 41289 | 2741K| 10996 (2)| 00:02:12 | | |
    | 3 | PARTITION RANGE ALL | | 49 | 294 | 1 (0)| 00:00:01 | 1 | 2 |
    | 4 | INDEX FULL SCAN | LOG_MONITOREDALARM_IDX | 49 | 294 | 1 (0)| 00:00:01 | 1 | 2 |
    |* 5 | HASH JOIN RIGHT OUTER | | 41289 | 2499K| 10994 (2)| 00:02:12 | | |
    | 6 | PARTITION RANGE ALL | | 1 | 13 | 1 (0)| 00:00:01 | 1 | 2 |
    | 7 | INDEX FULL SCAN | LOG_STATECHANGEDEF_IDX | 1 | 13 | 1 (0)| 00:00:01 | 1 | 2 |
    | 8 | NESTED LOOPS | | 41289 | 1975K| 10992 (2)| 00:02:12 | | |
    | 9 | SORT UNIQUE | | 1 | 24 | 2 (0)| 00:00:01 | | |
    |* 10 | TABLE ACCESS FULL | PARTITION_TABLE | 1 | 24 | 2 (0)| 00:00:01 | | |
    | 11 | PARTITION RANGE ITERATOR| | 58566 | 1429K| 10989 (2)| 00:02:12 | KEY | KEY |
    |* 12 | TABLE ACCESS FULL | ALARMLOG | 58566 | 1429K| 10989 (2)| 00:02:12 | KEY | KEY |
    -----------------------------------------------------------------------------------------------------------------------

    Predicate Information (identified by operation id):
    ---------------------------------------------------

    2 - access("LOGRECORDID"="TAB3"."MONITOREDALARMLOGRECO RDID"(+))
    5 - access("LOGRECORDID"="TAB2"."STATECHANGEDEFLOGRECO RDID"(+))
    10 - filter(UPPER("LOGRECORDTABLENAME")='ALARMLOG' AND "ACTIVE"=1)
    12 - filter("MANAGEDOBJECTCLASS" LIKE '%ES%' ESCAPE ' ' AND "PERCEIVEDSEVERITY"<>5 AND
    "EVENTTIME">=TO_DATE('2007-12-31 22:00:00', 'yyyy-mm-dd hh24:mi:ss') AND "EVENTTIME"<=TO_DATE('2008-08-24
    22:00:00', 'yyyy-mm-dd hh24:mi:ss') AND "PART_ID"="PARTITIONID")


    Statistics
    ----------------------------------------------------------
    0 recursive calls
    0 db block gets
    1389453 consistent gets
    443118 physical reads
    0 redo size
    639 bytes sent via SQL*Net to client
    488 bytes received via SQL*Net from client
    2 SQL*Net roundtrips to/from client
    1 sorts (memory)
    0 sorts (disk)
    1 rows processed


    SQL>
    SQL> SELECT count(*) /*+ ordered use_nl(TAB1 TAB2 TAB3) index(TAB1 ALARMLOG_IDX_1) index(TAB2 LOG_STATECHANGEDEF_IDX) index(TAB3 LOG_MONITOREDALARM_IDX) */
    FROM alarmLog TAB1, OMCDBSYS.LOG_stateChangeDef TAB2, OMCDBSYS.LOG_monitoredAlarm TAB3
    WHERE tab1.logRecordId = tab2.stateChangeDefLogRecordId(+)
    2 AND tab1.logRecordId = tab3.monitoredAlarmLogRecordId(+)
    3 4 AND (((NOT (perceivedSeverity=5) AND managedObjectClass LIKE '%ES%' ESCAPE(CHR(0)) )
    AND (eventTime>=TO_DATE('20071231220000', 'YYYYMMDDHH24MISS')
    AND eventTime<=TO_DATE('20080824220000', 'YYYYMMDDHH24MISS'))))
    ORDER BY eventTime DESC , eventTime DESC; 5 6 7 8

    COUNT(*)/*+ORDEREDUSE_NL(TAB1TAB2TAB3)INDEX(TAB1ALARMLOG_ID X_1)INDEX(TAB2LOG_STATECHANGEDEF_IDX)INDEX(TAB3LOG _MONITOREDALARM_IDX)*/
    -----------------------------------------------------------------------------------------------------------------------------------
    374

    Elapsed: 00:00:21.03

    Execution Plan
    ----------------------------------------------------------
    Plan hash value: 2579350973

    -----------------------------------------------------------------------------------------------------------------------
    | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | Pstart| Pstop |
    -----------------------------------------------------------------------------------------------------------------------
    | 0 | SELECT STATEMENT | | 1 | 68 | 10996 (2)| 00:02:12 | | |
    | 1 | SORT AGGREGATE | | 1 | 68 | | | | |
    |* 2 | HASH JOIN RIGHT OUTER | | 41289 | 2741K| 10996 (2)| 00:02:12 | | |
    | 3 | PARTITION RANGE ALL | | 49 | 294 | 1 (0)| 00:00:01 | 1 | 2 |
    | 4 | INDEX FULL SCAN | LOG_MONITOREDALARM_IDX | 49 | 294 | 1 (0)| 00:00:01 | 1 | 2 |
    |* 5 | HASH JOIN RIGHT OUTER | | 41289 | 2499K| 10994 (2)| 00:02:12 | | |
    | 6 | PARTITION RANGE ALL | | 1 | 13 | 1 (0)| 00:00:01 | 1 | 2 |
    | 7 | INDEX FULL SCAN | LOG_STATECHANGEDEF_IDX | 1 | 13 | 1 (0)| 00:00:01 | 1 | 2 |
    | 8 | NESTED LOOPS | | 41289 | 1975K| 10992 (2)| 00:02:12 | | |
    | 9 | SORT UNIQUE | | 1 | 24 | 2 (0)| 00:00:01 | | |
    |* 10 | TABLE ACCESS FULL | PARTITION_TABLE | 1 | 24 | 2 (0)| 00:00:01 | | |
    | 11 | PARTITION RANGE ITERATOR| | 58566 | 1429K| 10989 (2)| 00:02:12 | KEY | KEY |
    |* 12 | TABLE ACCESS FULL | ALARMLOG | 58566 | 1429K| 10989 (2)| 00:02:12 | KEY | KEY |
    -----------------------------------------------------------------------------------------------------------------------

    Predicate Information (identified by operation id):
    ---------------------------------------------------

    2 - access("LOGRECORDID"="TAB3"."MONITOREDALARMLOGRECO RDID"(+))
    5 - access("LOGRECORDID"="TAB2"."STATECHANGEDEFLOGRECO RDID"(+))
    10 - filter(UPPER("LOGRECORDTABLENAME")='ALARMLOG' AND "ACTIVE"=1)
    12 - filter("MANAGEDOBJECTCLASS" LIKE '%ES%' ESCAPE ' ' AND "PERCEIVEDSEVERITY"<>5 AND
    "EVENTTIME">=TO_DATE('2007-12-31 22:00:00', 'yyyy-mm-dd hh24:mi:ss') AND "EVENTTIME"<=TO_DATE('2008-08-24
    22:00:00', 'yyyy-mm-dd hh24:mi:ss') AND "PART_ID"="PARTITIONID")


    Statistics
    ----------------------------------------------------------
    15 recursive calls
    0 db block gets
    99358 consistent gets
    69993 physical reads
    0 redo size
    639 bytes sent via SQL*Net to client
    488 bytes received via SQL*Net from client
    2 SQL*Net roundtrips to/from client
    1 sorts (memory)
    0 sorts (disk)
    1 rows processed

    SQL>

  4. #4
    Join Date
    Aug 2004
    Location
    France
    Posts
    754
    Quote Originally Posted by elmu
    Unfortunately the SQL code is generated by a C program so I can not change it.
    So find someone who can

    IMO you won't be able to find a good solution without modifying the SQL.
    ORA-000TK : No bind variable detected... Shared Pool Alert code 5 - Nuclear query ready .

  5. #5
    Join Date
    Jul 2003
    Posts
    2,296
    Please tell me why you need 2 outer joins if you are doing a count(*).
    That makes no sense whatsoever.
    - The_Duck
    you can lead someone to something but they will never learn anything ...

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •