Добро пожаловать в форум, Guest  >>   Войти | Регистрация | Поиск | Правила | В избранное | Подписаться
Все форумы / Oracle Новый топик    Ответить
 Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
rucrealex
Member

Откуда:
Сообщений: 9
Добрый день.
При переходе на Oracle 11G обнаружен бизнес-процесс время выполнения которого сильно увеличилось.
Снята трасса с Oracle 11G
SELECT * FROM TABLE(DBMS_XPLAN.dISPLAY_CURSOR('1m7fvxcqzdy0q', 0, 'allstats'));

PLAN_TABLE_OUTPUT                                                                                                                                                                                       
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  1m7fvxcqzdy0q, child number 0                                                                                                                                                                   
-------------------------------------                                                                                                                                                                   
SELECT MAX(T_DEPDATE_DOCUMENT) FROM DSBDEPDOC_DBT WHERE T_REFERENC =                                                                                                                                    
:B14 AND T_DEPDATE_DOCUMENT >= :B13 AND T_DEPDATE_DOCUMENT <= :B12 AND                                                                                                                                  
(T_TYPEOPER = :B11 OR T_TYPECOMPLEXOPER = :B11 ) AND T_KINDOP NOT IN                                                                                                                                    
(:B10 , :B9 , :B8 , :B7 , :B6 ) AND T_ACTION != :B5 AND BITAND(T_FLAGS,                                                                                                                                 
:B4 ) = 0 AND T_ACCOUNT NOT IN ('TOP', 'BOT') AND (T_ISSUSPENDED =                                                                                                                                      
CHR(0) OR T_ISSUSPENDED = :B3 ) AND (:B2 = 1 OR T_FLAGSTORN = CHR(0))                                                                                                                                   
AND T_MODE != :B1                                                                                                                                                                                       

Plan hash value: 3682415965                                                                                                                                                                             

-----------------------------------------------------------------------------------------------------------------------                                                                                 
| Id  | Operation                     | Name               | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |                                                                                 
-----------------------------------------------------------------------------------------------------------------------                                                                                 
|   0 | SELECT STATEMENT              |                    |    627 |        |    627 |00:04:43.66 |     227K|  59085 |                                                                                 
|   1 |  SORT AGGREGATE               |                    |    627 |      1 |    627 |00:04:43.66 |     227K|  59085 |                                                                                 
|*  2 |   FILTER                      |                    |    627 |        |      0 |00:04:43.65 |     227K|  59085 |                                                                                 
|*  3 |    TABLE ACCESS BY INDEX ROWID| DSBDEPDOC_DBT      |    627 |      1 |      0 |00:04:43.64 |     227K|  59085 |                                                                                 
|*  4 |     INDEX RANGE SCAN          | DSBDEPDOC_DBT_IDX2 |    627 |     86 |    231K|00:00:12.83 |    3570 |   1615 |                                                                                 
-----------------------------------------------------------------------------------------------------------------------                                                                                 

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

   2 - filter(:B13<=:B12)                                                                                                                                                                               
   3 - filter(("T_ACTION"<>:B5 AND ("T_TYPECOMPLEXOPER"=:B11 OR "T_TYPEOPER"=:B11) AND BITAND("T_FLAGS",:B4)=0                                                                                          
              AND "T_KINDOP"<>:B7 AND "T_MODE"<>:B1 AND ("T_FLAGSTORN"=')                                                                                                                               
   4 - access("T_REFERENC"=:B14 AND "T_DEPDATE_DOCUMENT">=:B13 AND "T_DEPDATE_DOCUMENT"<=:B12)

Время выполнения запроса >280 сек

Этот же запрос на Oracle 10G
PLAN_TABLE_OUTPUT                                                                                                                                                                                       
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  1m7fvxcqzdy0q, child number 0                                                                                                                                                                   
-------------------------------------                                                                                                                                                                   
SELECT MAX(T_DEPDATE_DOCUMENT) FROM DSBDEPDOC_DBT WHERE T_REFERENC = :B14 AND T_DEPDATE_DOCUMENT >= :B13 AND                                                                                            
T_DEPDATE_DOCUMENT <= :B12 AND (T_TYPEOPER = :B11 OR T_TYPECOMPLEXOPER = :B11 ) AND T_KINDOP NOT IN (:B10 ,                                                                                             
:B9 , :B8 , :B7 , :B6 ) AND T_ACTION != :B5 AND BITAND(T_FLAGS, :B4 ) = 0 AND T_ACCOUNT NOT IN ('TOP', 'BOT')                                                                                           
AND (T_ISSUSPENDED = CHR(0) OR T_ISSUSPENDED = :B3 ) AND (:B2 = 1 OR T_FLAGSTORN = CHR(0)) AND T_MODE != :B1                                                                                            

Plan hash value: 3682415965                                                                                                                                                                             

-----------------------------------------------------------------------------------------------------------------------                                                                                 
| Id  | Operation                     | Name               | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |                                                                                 
-----------------------------------------------------------------------------------------------------------------------                                                                                 
|   1 |  SORT AGGREGATE               |                    |      8 |      1 |      8 |00:00:05.49 |    3753 |   2654 |                                                                                 
|*  2 |   FILTER                      |                    |      8 |        |      6 |00:00:04.59 |    3753 |   2654 |                                                                                 
|*  3 |    TABLE ACCESS BY INDEX ROWID| DSBDEPDOC_DBT      |      8 |      1 |      6 |00:00:04.59 |    3753 |   2654 |                                                                                 
|*  4 |     INDEX RANGE SCAN          | DSBDEPDOC_DBT_IDX2 |      8 |      1 |   3798 |00:00:00.09 |      49 |     21 |                                                                                 
-----------------------------------------------------------------------------------------------------------------------                                                                                 

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


PLAN_TABLE_OUTPUT                                                                                                                                                                                       
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
   2 - filter(:B13<=:B12)                                                                                                                                                                               
   3 - filter(("T_MODE"<>:B1 AND ("T_TYPEOPER"=:B11 OR "T_TYPECOMPLEXOPER"=:B11) AND ("T_FLAGSTORN"=')                                                                                                  
   4 - access("T_REFERENC"=:B14 AND "T_DEPDATE_DOCUMENT">=:B13 AND "T_DEPDATE_DOCUMENT"<=:B12)    

План выполнения на 10G такой же, но время выполнения запроса -секунды существенно меньше.
Эксперимент повторялся не единожды, случайности исключаем. перед экспериментами был очищен buffer cashe, shared pool.
Статистика собрана, актуальная. Параметры БД одинаковые.
Базы подняты на одном сервере, дисковый массив - RAID10.
Что может так сильно влиять на время выполнения запроса, если планы одинаковые.
17 июл 13, 09:20    [14576238]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
ORA__SQL
Member

Откуда: Moscow
Сообщений: 1774
rucrealex, а разница A-Rows и Starts вас совсем не смущает?
| Id  | Operation                     | Name               | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |
|*  4 |     INDEX RANGE SCAN          | DSBDEPDOC_DBT_IDX2 |    627 |     86 |    231K|00:00:12.83 |    3570 |   1615 | 

|*  4 |     INDEX RANGE SCAN          | DSBDEPDOC_DBT_IDX2 |      8 |      1 |   3798 |00:00:00.09 |      49 |     21 |
17 июл 13, 09:33    [14576262]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
rucrealex
Member

Откуда:
Сообщений: 9
Ну пока вы не написали вообще не смущало ). Ушел читать доки что сие значит, еще вернусь.
17 июл 13, 10:27    [14576539]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
Gustly
Member

Откуда:
Сообщений: 1426
Тут как раз стоит обратить внимание на A-rows, если не ошибаюсь это actually rows, то бишь сколько оказалось в действительности. И если 3798 строк обработались за 12,83 секунды, то 231к должны обработаться за 231000/3798*12,83=780,34 секунды или 13 минут. Судя по трасе или количество строк различается таки, или по индексу стата разная (в одном случае ждет 231к строк, в другом 3798). Поправьте если ошибаюсь.
17 июл 13, 10:38    [14576623]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
sQud
Member

Откуда: Минск
Сообщений: 100
rucrealex,

Выполните пожалуйста следующий отчет (для 10g и 11g) выполнив следующий скрипт, предварительно подставив свои sql_id и путь после SPOOL

SET LONG 1000000
SET LONGCHUNKSIZE 1000000
SET LINESIZE 1000
SET PAGESIZE 0
SET TRIM ON
SET TRIMSPOOL ON
SET ECHO OFF
SET FEEDBACK OFF

SPOOL /host/report_sql_detail.htm

SELECT DBMS_SQLTUNE.report_sql_detail(
  sql_id       => '526mvccm5nfy4',
  type         => 'ACTIVE',
  report_level => 'ALL') AS report
FROM dual;
SPOOL OFF
17 июл 13, 14:46    [14578385]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
ten
Member

Откуда: Екатеринбург
Сообщений: 1672
Gustly
...Поправьте если ошибаюсь.

Правильно только первое предложение :)
18 июл 13, 09:19    [14581497]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
xtender
Member

Откуда: Мск
Сообщений: 5704
rucrealex
SELECT * FROM TABLE(DBMS_XPLAN.dISPLAY_CURSOR('1m7fvxcqzdy0q', 0, 'allstats'));
зачем берете allstats? это у вас показывает суммарное. в целом, учитывая кол-во выполнений, все приблизительно одинаково в пределах погрешности
18 июл 13, 10:10    [14581861]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
xtender
Member

Откуда: Мск
Сообщений: 5704
ten
Gustly
...Поправьте если ошибаюсь.

Правильно только первое предложение :)
и то, только вторая часть первого предложения, т.к. здесь важнее существенно большее кол-во выполнений :)
18 июл 13, 10:11    [14581867]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
Gustly
Member

Откуда:
Сообщений: 1426
xtender
здесь важнее существенно большее кол-во выполнений :)

А из-за чего оно большее? Из-за реального количества строк? И почему реальное количество строк оказалось больше?
18 июл 13, 10:52    [14582101]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
xtender
Member

Откуда: Мск
Сообщений: 5704
Gustly,

В первом случае статистика за 627 выполнений, а во-втором - за 8
18 июл 13, 11:27    [14582345]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
wurdu
Member

Откуда: Владивосток
Сообщений: 4441
Сними трассировку 10046 бизнес-процесса и станет понятно. Я надеюсь, что statistics_level не стоит all на уровне базы...
18 июл 13, 12:10    [14582737]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
ten
Member

Откуда: Екатеринбург
Сообщений: 1672
rucrealex,
Кстати, что-то странновата секция "Predicate Information".
18 июл 13, 14:31    [14583961]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
xtender
Member

Откуда: Мск
Сообщений: 5704
ten,

из-за chr(0)
18 июл 13, 14:39    [14584036]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
rucrealex
Member

Откуда:
Сообщений: 9
Уважаемый xtender, правильно ли я понял, что снимая статистику так:
SELECT * FROM TABLE(DBMS_XPLAN.dISPLAY_CURSOR('1m7fvxcqzdy0q', 0, 'allstats'));
я вижу что на 11G такой запрос выполнялся 600 раз, а на 10G 6-мь раз. И в первом случае вижу статистику по всем 600-м разам когда он был выполнен. Т.е. сравнивать эти цифры нельзя. Что мне нужно в таком случае писать "allstats last" ? И в этом случае я увижу примерно одинаковый результат. Таким образом, не туда копаю, правильно?
25 июл 13, 10:48    [14614888]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
xtender
Member

Откуда: Мск
Сообщений: 5704
rucrealex,

да
25 июл 13, 11:18    [14615095]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения sql запроса в Oracle 10G и Oracle 11G. Планы одинаковы.  [new]
wurdu
Member

Откуда: Владивосток
Сообщений: 4441
rucrealex
Уважаемый xtender, правильно ли я понял, что снимая статистику так:
SELECT * FROM TABLE(DBMS_XPLAN.dISPLAY_CURSOR('1m7fvxcqzdy0q', 0, 'allstats'));
я вижу что на 11G такой запрос выполнялся 600 раз, а на 10G 6-мь раз. И в первом случае вижу статистику по всем 600-м разам когда он был выполнен. Т.е. сравнивать эти цифры нельзя. Что мне нужно в таком случае писать "allstats last" ? И в этом случае я увижу примерно одинаковый результат. Таким образом, не туда копаю, правильно?
Тебе надо снять trace 10046, обработать его tkprof и проанализировать. Тогда станет понятно на какие запросы надо обращать внимание.
26 июл 13, 04:04    [14619437]     Ответить | Цитировать Сообщить модератору
Все форумы / Oracle Ответить