Query is taking 4800x longer when run from C++ program than from SQL Plus

Question

We are having a serious problem with a query that defies explanation. In SQL-plus or TOAD it runs in 1/2 sec, but when run from a C++ program via a Distributed Transaction it is taking 41 minutes. Until this week this has run 10,000 of times from the C++ code all under a second.

Nothing has changed in the DB or the code or the W2k servers running the code.

when running from the code it has very high db file sequential read over 1,000,000

when exact same statement is run from SQL plus the db file sequential read is 8

So same statement is doing 100,000x more work when run via code and DT than from sqlplus.

we did the following query to find what blocks are being read SELECT p1 "file#", p2 "block#", p3 "class#" FROM v$session_wait WHERE event = 'db file sequential read'

and they are the tables used in the query. It is reading the tables over and over yet the explain plan indicates only 8 blocks should be read

both tables are ~10 gig in size

here is the statment and the explain plan

SELECT COUNT (*)
  FROM student st, testinstance ti
 WHERE st.dataset_id = :b2
   AND st.student_id = ti.student_id
   AND ti.testinstance_id > :b1
   AND NOT EXISTS (
          SELECT 1
            FROM programscoringexclusion ex
           WHERE ex.program_id = wfgeneral.getprogramid (:b3)
             AND ex.testfamily_id = ti.testfamily_id
             AND NVL (ex.test_level, NVL (ti.test_level, '*')) =
                                                      NVL (ti.test_level, '*')
             AND NVL (ex.battery, NVL (ti.battery, '*')) =
                                                         NVL (ti.battery, '*')
             AND NVL (ex.form, NVL (ti.form, '*')) = NVL (ti.form, '*'))

             Plan
SELECT STATEMENT  CHOOSECost: 2                     
    9 SORT AGGREGATE  Bytes: 43  Cardinality: 1                 
        8 FILTER            
            5 NESTED LOOPS  Cost: 2  Bytes: 43  Cardinality: 1          
                2 TABLE ACCESS BY INDEX ROWID TABLE BBOX.TESTINSTANCE Cost: 1  Bytes: 32  Cardinality: 1    
                    1 INDEX RANGE SCAN INDEX (UNIQUE) BBOX.XXPK0TESTINSTANCE Cost: 1  Cardinality: 1  
                4 TABLE ACCESS BY INDEX ROWID TABLE BBOX.STUDENT Cost: 1  Bytes: 11  Cardinality: 1     
                    3 INDEX UNIQUE SCAN INDEX (UNIQUE) BBOX.XXPK0STUDENT Cost: 1  Cardinality: 1  
            7 TABLE ACCESS BY INDEX ROWID TABLE BBOX.PROGRAMSCORINGEXCLUSION Cost: 1  Bytes: 37  Cardinality: 1         
                6 INDEX RANGE SCAN INDEX BBOX.XXIE1PROGRAMSCORINGEXCLUSION Cost: 1  Cardinality: 1  

how can we see what the actual plan is for a statement when it is actually running? We can tell it is reading the tables aboves. Is it possible that the actual plan is different than the one we are seeing and is in fact doing some kind of Cartesian join or something wierd that takes it 40 mins to resolve? is there a way of determining that?

Answer 1

To find the actual plan used, you can query v$sql_plan with the sql_id. The easiest thing to do, is to put a comment in the query to make it unique, eg

select /* FROM C++ */ ....

and

select /* FROM SQLPLUS */ ....

Then run the query. By querying from v$sql you can find the SQL_ID of the query, eg:

select sql_id, sql_fulltext
from v$sql
where upper(sql_fulltext) like '%FROM C++%';

Then using that SQL_ID, you can query v$sql_plan to get the plan, or better, use the following query:

select * from table(dbms_xplan.diplay_cursor('SQL ID OBTAINED ABOVE'));