Results 1 to 14 of 14
  1. #1
    Join Date
    Dec 2003
    Posts
    1,074

    Unanswered: Interpreting Explain Plan vs Execution Speed

    I've constructed two versions of a SQL statement. I would guess that the second version would be faster, since it would seem reasonable to assume that the first query would have to execute the subselect for every record coming into the main query. However, all of the cost columns favor the first query. The actual runtime, though, is faster for the second query (consistently 16msec vs 45msec).

    I've looked through the documentation on the Optimizer, and I'm not feeling educated enough, so I was hoping someone could supplement (the text would read something like - When the explain plain mentions 'Table Access Full', a full table scan is executed, information which is not that helpful). How should I interpret the following, in the face of the execution times for these queries? Thanks -cf

    SELECT (pts.na_employee.ebd_name) AS empname,
    (SELECT COUNT (*)
    FROM pts.na_employee emp
    WHERE emp.sep_flg IS NULL
    AND emp.division_code = pts.na_employee.division_code) AS emp_cnt
    FROM pts.na_employee

    Operation Object Name Rows Bytes Cost CPU Cost

    SELECT STATEMENT Optimizer Mode=ALL_ROWS 4 K 64
    SORT AGGREGATE 1 5
    TABLE ACCESS FULL PTS.NA_EMPLOYEE 97 485 66 9955420
    TABLE ACCESS FULL PTS.NA_EMPLOYEE 4 K 88 K 64 2588870

    SELECT (pts.na_employee.ebd_name) AS empname,
    (iv.emp_count)
    FROM pts.na_employee,
    (SELECT emp.division_code AS divcode, COUNT(*) AS emp_count
    FROM pts.na_employee emp
    WHERE emp.sep_flg IS NULL
    GROUP BY emp.division_code) iv
    WHERE iv.divcode(+) = pts.na_employee.division_code

    Operation Object Name Rows Bytes Cost CPU Cost

    SELECT STATEMENT Optimizer Mode=ALL_ROWS 5 K 132
    HASH JOIN RIGHT OUTER 5 K 203 K 132 20620648
    VIEW 11 176 67 15194547
    SORT GROUP BY 11 55 67 15194547
    TABLE ACCESS FULL PTS.NA_EMPLOYEE 1 K 5 K 66 9902270
    TABLE ACCESS FULL PTS.NA_EMPLOYEE 4 K 88 K 64 2588870

  2. #2
    Join Date
    Apr 2004
    Posts
    246
    did you confirm the results (not runtime, but actual output)? the two are not doing the same thing. the 1st one is faster because it's not running the subquery for each outside row - it's only running it once. when you join division_code, the "pts.na_employee" does not resolve to the outer query - it resolves to the sub-query. it doesn't care that you've aliased the table as emp, it's still the same table name. you need to alias the outer table, and use that alias in the sub-query:

    SELECT (pts.na_employee.ebd_name) AS empname,
    (SELECT COUNT (*)
    FROM pts.na_employee emp
    WHERE emp.sep_flg IS NULL
    AND emp.division_code = x.division_code) AS emp_cnt
    FROM pts.na_employee x
    Give a man a fish, you feed him for a day. Club him over the head with a fish, he'll leave you alone.

  3. #3
    Join Date
    Dec 2003
    Posts
    1,074
    I ran the queries separately, each achieving a count(*) of 4,302 records, and then I ran a query

    query1
    union
    query2

    and the record count was 4,302. So the output of both queries is identical.

    -Chuck

    I did have to add the NVL() function to the second query to get the UNION to work as it did above:

    SELECT (pts.na_employee.ebd_name) AS empname,
    NVL(iv.emp_count, 0)
    FROM pts.na_employee,
    (SELECT emp.division_code AS divcode, COUNT(*) AS emp_count
    FROM pts.na_employee emp
    WHERE emp.sep_flg IS NULL
    GROUP BY emp.division_code) iv
    WHERE iv.divcode(+) = pts.na_employee.division_code

  4. #4
    Join Date
    Jul 2003
    Posts
    2,296
    Trace both queries and TKPROF it.
    Post the results please.
    - The_Duck
    you can lead someone to something but they will never learn anything ...

  5. #5
    Join Date
    Dec 2003
    Posts
    1,074
    I'm not able to awaken SQL Trace. I followed the documentation as listed in:

    http://download-west.oracle.com/docs...2/sqltrace.htm

    When I check the /udump destination directory, though, there are no files for today. Is there a task that I still need to do to get a trace file?
    -cf

    SQL> alter session set timed_statistics = true;

    Session altered.

    SQL> show parameter MAX_DUMP_FILE_SIZE

    NAME TYPE VALUE
    ------------------------------------ ----------- ------------------------------
    max_dump_file_size string UNLIMITED
    SQL> show parameter USER_DUMP_DEST

    NAME TYPE VALUE
    ------------------------------------ ----------- ------------------------------
    user_dump_dest string /u01/app/oracle/admin/dev/udum
    p
    SQL> ALTER SESSION SET SQL_TRACE = TRUE;

    Session altered.

    SQL> select * from dual;

    D
    -
    X

  6. #6
    Join Date
    May 2004
    Location
    Dominican Republic
    Posts
    721
    how about if you close sql*plus ? ( or alternatively, submit: alter session set sql_trace = false ).

  7. #7
    Join Date
    Dec 2003
    Posts
    1,074
    I able to get this to work (previous explain plan was from TOAD):

    SQL> set autotrace traceonly
    SQL> ed
    Wrote file afiedt.buf

    1 SELECT (pts.na_employee.ebd_name) AS empname,
    2 (SELECT COUNT (*)
    3 FROM pts.na_employee emp
    4 WHERE emp.sep_flg IS NULL AND
    5 emp.division_code = pts.na_employee.division_code) AS emp_cnt
    6* FROM pts.na_employee
    SQL> /

    4302 rows selected.


    Execution Plan
    ----------------------------------------------------------
    0 SELECT STATEMENT Optimizer=ALL_ROWS (Cost=65 Card=4302 Bytes
    =90342)

    1 0 SORT (AGGREGATE)
    2 1 TABLE ACCESS (FULL) OF 'NA_EMPLOYEE' (TABLE) (Cost=66 Ca
    rd=97 Bytes=485)

    3 0 TABLE ACCESS (FULL) OF 'NA_EMPLOYEE' (TABLE) (Cost=65 Card
    =4302 Bytes=90342)





    Statistics
    ----------------------------------------------------------
    1 recursive calls
    0 db block gets
    3571 consistent gets
    0 physical reads
    0 redo size
    117196 bytes sent via SQL*Net to client
    3650 bytes received via SQL*Net from client
    576 SQL*Net roundtrips to/from client
    0 sorts (memory)
    0 sorts (disk)
    4302 rows processed

    SQL> ed
    Wrote file afiedt.buf

    1 SELECT (pts.na_employee.ebd_name) AS empname,
    2 NVL(iv.emp_count, 0) AS emp_count
    3 FROM pts.na_employee,
    4 (SELECT emp.division_code AS divcode, COUNT(*) AS emp_count
    5 FROM pts.na_employee emp
    6 WHERE emp.sep_flg IS NULL
    7 GROUP BY emp.division_code) iv
    8* WHERE iv.divcode(+) = pts.na_employee.division_code
    SQL> /

    4302 rows selected.


    Execution Plan
    ----------------------------------------------------------
    0 SELECT STATEMENT Optimizer=ALL_ROWS (Cost=132 Card=5625 Byte
    s=208125)

    1 0 HASH JOIN (RIGHT OUTER) (Cost=132 Card=5625 Bytes=208125)
    2 1 VIEW (Cost=67 Card=11 Bytes=176)
    3 2 SORT (GROUP BY) (Cost=67 Card=11 Bytes=55)
    4 3 TABLE ACCESS (FULL) OF 'NA_EMPLOYEE' (TABLE) (Cost=6
    6 Card=1063 Bytes=5315)

    5 1 TABLE ACCESS (FULL) OF 'NA_EMPLOYEE' (TABLE) (Cost=65 Ca
    rd=4302 Bytes=90342)





    Statistics
    ----------------------------------------------------------
    1 recursive calls
    0 db block gets
    821 consistent gets
    0 physical reads
    0 redo size
    117198 bytes sent via SQL*Net to client
    3650 bytes received via SQL*Net from client
    576 SQL*Net roundtrips to/from client
    1 sorts (memory)
    0 sorts (disk)
    4302 rows processed

  8. #8
    Join Date
    Dec 2003
    Posts
    1,074
    Set SQL_TRACE = FALSE? Could you please explain. Duck was asking that I trace the session, and then use TKPROF to produce output. The instructions I was following mention that SQL_TRACE =TRUE.
    -cf

  9. #9
    Join Date
    May 2004
    Location
    Dominican Republic
    Posts
    721
    Quote Originally Posted by chuck_forbes
    Set SQL_TRACE = FALSE? Could you please explain. Duck was asking that I trace the session, and then use TKPROF to produce output. The instructions I was following mention that SQL_TRACE =TRUE.
    -cf
    If you close sql*plus ( which implicit close your session ) or submit an alter session set sql_trace = false, you will see the trace file generated under your dump destination folder.

  10. #10
    Join Date
    Jul 2003
    Posts
    2,296
    come on now. dbas should know how to create a trace file and TKPROF it.
    PHP Code:
    show parameter user_dump_dest
    show parameter timed_statistics

    alter session set timed_statistics 
    true;

    alter session set events 
      
    '10046 trace name context forever, level 12';

    /* run both queries */

    /* on Unix, run this to find the trace-file name */
    select rtrim(c.value,'/') || '/' || d.instance_name || 
           
    '_ora_' || ltrim(to_char(a.spid)) || '.trc'
      
    from v$process av$session bv$parameter cv$instance d
     where a
    .addr b.paddr
       
    and b.audsid sys_context'userenv''sessionid')
       and 
    c.name 'user_dump_dest'
    /

    /* now CLOSE the sqlplus session in order to generate that trace file */
    /* goto the db server and tkprof that filename you just got from the query */
    /* example: tkprof /apps/oracle/sid/udump/sid_ora_25999.trc tkprof_output.prf */
    /* now open that file you just created: cat tkprof_output.prf */
    /* post the results here */ 
    - The_Duck
    you can lead someone to something but they will never learn anything ...

  11. #11
    Join Date
    Dec 2003
    Posts
    1,074
    Believe me, I wish I didn't have to press you on this information, as it sounds like a technique that most of you know already. I promise you that I won't have to ask again once I get this working.

    Duck, I tried your instructions as follows, but no trace file is being created. I tried it a second time adding ALTER SESSION SET SQL_TRACE=TRUE, but I still received no trace file:



    [oracle@ora4 udump]$ sqlplus "forbesc@dev"

    SQL*Plus: Release 10.1.0.3.0 - Production on Wed Nov 24 08:12:12 2004

    Copyright (c) 1982, 2004, Oracle. All rights reserved.

    Enter password:

    Connected to:
    Oracle Database 10g Enterprise Edition Release 10.1.0.3.0 - Production
    With the Partitioning, OLAP and Data Mining options

    SQL> show parameter user_dump_dest

    NAME TYPE VALUE
    ------------------------------------ ----------- ------------------------------
    user_dump_dest string /u01/app/oracle/admin/dev/udum
    p
    SQL> show parameter timed_statistics

    NAME TYPE VALUE
    ------------------------------------ ----------- ------------------------------
    timed_statistics boolean TRUE
    SQL> alter session set events
    2 '10046 trace name context forever, level 12';

    Session altered.

    SQL> SELECT (pts.na_employee.ebd_name) AS empname,
    (SELECT COUNT (*)
    FROM pts.na_employee emp
    WHERE emp.sep_flg IS NULL AND
    emp.division_code = pts.na_employee.division_code) AS emp_cnt
    FROM pts.na_employee; 2 3 4 5 6

    ...data...
    EMPNAME EMP_CNT
    ---------------------- ----------
    POWELL, LOU 206

    4302 rows selected.

    SQL> SELECT (pts.na_employee.ebd_name) AS empname,
    nvl(iv.emp_count, 0)
    FROM pts.na_employee,
    (SELECT emp.division_code AS divcode, COUNT(*) AS emp_count
    FROM pts.na_employee emp
    WHERE emp.sep_flg IS NULL
    GROUP BY emp.division_code) iv
    WHERE iv.divcode(+) = pts.na_employee.division_code;

    ...data...
    EMPNAME NVL(IV.EMP_COUNT,0)
    ---------------------- -------------------
    POWELL, LOUIS 206

    4302 rows selected.

    SQL> select rtrim(c.value,'/') || '/' || d.instance_name ||
    '_ora_' || ltrim(to_char(a.spid)) || '.trc'
    from v$process a, v$session b, v$parameter c, v$instance d
    where a.addr = b.paddr
    and b.audsid = sys_context( 'userenv', 'sessionid')
    and c.name = 'user_dump_dest';

    RTRIM(C.VALUE,'/')||'/'||D.INSTANCE_NAME||'_ORA_'||LTRIM(TO_CHAR(A.SPID) )||'.TRC
    --------------------------------------------------------------------------------
    /u01/app/oracle/admin/dev/udump/dev_ora_21386.trc

    SQL> exit
    Disconnected from Oracle Database 10g Enterprise Edition Release 10.1.0.3.0 - Production
    With the Partitioning, OLAP and Data Mining options
    [oracle@ora4 udump]$ more /u01/app/oracle/admin/dev/udump/dev_ora_21386.trc
    /u01/app/oracle/admin/dev/udump/dev_ora_21386.trc: No such file or directory
    [oracle@ora4 udump]$ ls -ltr /u01/app/oracle/admin/dev/udump
    ...
    -rw-r----- 1 oracle oinstall 2623 Nov 19 19:13 dev_ora_11440.trc
    -rw-r----- 1 oracle oinstall 1633 Nov 20 19:05 dev_ora_32289.trc
    -rw-r----- 1 oracle oinstall 1633 Nov 21 19:05 dev_ora_26761.trc
    -rw-r----- 1 oracle oinstall 1633 Nov 22 19:06 dev_ora_14892.trc
    -rw-r----- 1 oracle oinstall 1631 Nov 23 19:06 dev_ora_3812.trc

  12. #12
    Join Date
    Jul 2003
    Posts
    2,296
    are you running MTS? (multi threaded server)

    check and see if the file is in your bdump directory.
    - The_Duck
    you can lead someone to something but they will never learn anything ...

  13. #13
    Join Date
    Mar 2002
    Location
    Reading, UK
    Posts
    1,137
    A couple of points

    1) If you have found the second query is faster why not just use it. Also 16ms vs 45ms is not a significant difference unless this query is being run thousands of times.

    2) An execution plan is oracle's best guess as to how to execute the query. If Oracle always picked the optimal execution plan lots of DBAs would be out of a job

    3) Dont forget the optimizer is affected by the configation parameters, A large pga_aggregate_target or hash_area_size will favour hash joins in your second query. Also other parameters like optimizer* and db_file_multiblock_read_count.

    4) Are your tables/indexes analyzed? and also what level of analysis have you done, a more comprehensive analyze such for all columns size <n> may cause the second query to be more favourable. Also gathering system stats (dbms_stats) may also help you.

    Alan

  14. #14
    Join Date
    Dec 2003
    Posts
    1,074
    We are running in a Shared Server environment, using 10g. I checked the /bdump directory, and most of the trc files there were from the shared servers and dispatchers, and the rest were from October.

    I did pull my mind together and try to search for the file output from the following query:

    SQL> select rtrim(c.value,'/') || '/' || d.instance_name ||
    '_ora_' || ltrim(to_char(a.spid)) || '.trc'
    from v$process a, v$session b, v$parameter c, v$instance d
    where a.addr = b.paddr
    and b.audsid = sys_context( 'userenv', 'sessionid')
    and c.name = 'user_dump_dest';

    RTRIM(C.VALUE,'/')||'/'||D.INSTANCE_NAME||'_ORA_'||LTRIM(TO_CHAR(A.SPID) )||'.TRC
    --------------------------------------------------------------------------------
    /u01/app/oracle/admin/dev/udump/dev_ora_21386.trc


    [oracle@ora4 bdump]$ find / -name 'dev_ora_21386.trc'


    but I came up empty.

    AlanP,

    I agree that for this query, this sort of intensive investigation is not going to pay off. I thought this would be quick. Now, I am hoping to use the skills I learn here against more troublesome queries in the future.

    -Chuck

Posting Permissions

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