Разное время выполнения процедуры с trace и без.

Vox2
Дата: 22.02.2007 19:22:57
Проблема в следующем.
Имеется процедура выполнение которой на рабочем сервере стало занимать очень догое время.
Попытался разобраться в чем дело. Процедура простая - состоит из нескольких селектов. Каждый из них был проверен, выполняются за десятки миллисекунд. Вызов процедуры - от 3х до 5ти минут.
Попытался оттрасировать ситуацию - но с включенным трейсом она работает порядка 50-60 миллисекунд. Поэтому понять проблему не удается.
Ситуация стабильная, повторяется при каждом вызове, только время разное. С блокировками вроде тоже проблемы быть не должно - чистые селекты.
Vox2
Дата: 22.02.2007 19:37:40
Вот трейс вызова. Вот как этом ожет 5 минут выполняться?
Trace file: odb1_ora_3833_uniq.trc
Sort options: default

********************************************************************************
count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing 
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call
********************************************************************************

begin tv; end;


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           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          0          0           1

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

SELECT ID 
FROM
 SYSTEMS WHERE SYSTEM = :B3 AND BRANCH = :B2 AND INSTANCE = :B1 


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

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 104     (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  TABLE ACCESS BY INDEX ROWID SYSTEMS (cr=2 pr=0 pw=0 time=46 us)
      1   INDEX UNIQUE SCAN AK_SYSTEMS (cr=1 pr=0 pw=0 time=19 us)(object id 81728)

********************************************************************************

SELECT WORKMODE 
FROM
 REGISTER WHERE SYSTEMID=:B2 AND DAY = :B1 


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        1      0.00       0.00          0          3          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.00          0          3          0           1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 104     (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  TABLE ACCESS BY INDEX ROWID REGISTER (cr=3 pr=0 pw=0 time=39 us)
      1   INDEX UNIQUE SCAN PK_REGISTER (cr=2 pr=0 pw=0 time=19 us)(object id 81706)

********************************************************************************

SELECT COUNT(*), SUM(AMOUNT) 
FROM
 PAYS WHERE SYSTEMID=:B2 AND DAY = :B1 


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        1      0.00       0.02          3          4          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.02          3          4          0           1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 104     (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SORT AGGREGATE (cr=4 pr=3 pw=0 time=20548 us)
      0   TABLE ACCESS BY INDEX ROWID PAYS (cr=4 pr=3 pw=0 time=20474 us)
      0    INDEX RANGE SCAN IDX_PAYS_DAY_FK4 (cr=4 pr=3 pw=0 time=20436 us)(object id 81700)

********************************************************************************

SELECT COUNT(*), SUM(AMOUNT) 
FROM
 TURNS WHERE SYSTEMID=:B2 AND DAY = :B1 


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        1      0.00       0.00          0          3          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.00          0          3          0           1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 104     (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SORT AGGREGATE (cr=3 pr=0 pw=0 time=66 us)
      0   TABLE ACCESS BY INDEX ROWID TURNS (cr=3 pr=0 pw=0 time=46 us)
      0    INDEX RANGE SCAN IDX_TURNS_DAY_FK7 (cr=3 pr=0 pw=0 time=28 us)(object id 456943)




********************************************************************************

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

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           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          0          0           1

Misses in library cache during parse: 0


OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        4      0.00       0.00          0          0          0           0
Execute      5      0.00       0.00          0          0          0           0
Fetch        4      0.00       0.02          3         12          0           4
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       13      0.00       0.02          3         12          0           4

Misses in library cache during parse: 0

    5  user  SQL statements in session.
    0  internal SQL statements in session.
    5  SQL statements in session.
********************************************************************************
Trace file: odb1_ora_3833_uniq.trc
Trace file compatibility: 10.01.00
Sort options: default

       0  session in tracefile.
       5  user  SQL statements in trace file.
       0  internal SQL statements in trace file.
       5  SQL statements in trace file.
       5  unique SQL statements in trace file.
      50  lines in trace file.
       1  elapsed seconds in trace file.
evostr
Дата: 22.02.2007 22:40:05
Vox2
Дата: 23.02.2007 15:55:36
Читал, но.
Ситуация не совсем такая вроде - все запросы из процедуры выполняются на ура - процедура - не хочет.
Да и собственно последовать совету и сделать alter system flush shared_pool; пока не представляется возможным.