Oracle mechanics

30.05.2016

Топ I/O ожиданий/блоков/операций по записям ASH

Filed under: Oracle,Scripts — Игорь Усольцев @ 00:34
Tags: ,

AWR классифицирует запросы в части I/O по след.метрикам:

  • SQL ordered by User I/O Wait Time — соответственно по User I/O Time, кол-ву ожиданий и потраченному DB Time, что соответствует распределению строк в ASH
  • SQL ordered by Reads, отсортированному по Physical Reads (in blocks)
  • SQL ordered by Physical Reads (UnOptimized), упорядоченному по кол-ву Physical Read Requsts ( с выденением UnOptimized), что крайне полезно при разборе проблем в части ввода/вывода

Набросал запрос для тех же метрик на основе записей ASH, добавив для полноты картины системные/Background Processes и возможности сортировки по WAITS (соответствует User I/O Wait Time в AWR), REQS (Physical Read Requsts) и BLOCKS (Physical Reads) с учётом отличия db file blocksize и log file blocksize, без учёта возможных различий blocksize разных db files

На примере одной OLTP бд, сортируя ASH по считанным/записанным блокам (в пересчёте на db file blocksize), можно видеть активную писательскую деятельность дочерних LG00:

12.1.0.2.@ SQL> @ash_io_waits blocks 20 ""
 
INST SQL_PROCESS   SUM(WAIT_COUNT)     waits% SUM(REQUESTS)      reqs% SUM(BLOCKS)    blocks% event(waits:requests:blocks)
---- ------------- --------------- ---------- ------------- ---------- ----------- ---------- ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
   2 (LG00)                   2861       3,93          8774       2,99      369839      10,65 log file parallel write(2861:8774:369839)
   2 1mbx3m11g17vn            7956      10,94          8609       2,94      367678      10,59 db file sequential read(5413:5413:5413); direct path read(1611:1611:327470); direct path write temp(354:354:19870); direct path read temp(273:273:12527); db file scattered read(230:230:1670); db file parallel read(41:694:694); local write wait(33:33:33); read by other session(1:1:1)
   1 1mbx3m11g17vn            5478       7,53          5482       1,87      331056       9,53 db file sequential read(3268:3268:3268); direct path read(1551:1551:304082); direct path write temp(313:313:14583); direct path read temp(245:245:8667); db file scattered read(99:99:450); db file parallel read(2:6:6)
   2 f37q3y43djfp4            1183       1,63          1183        0,4      302044        8,7 direct path read(1180:1180:301914); db file sequential read(2:2:2); db file scattered read(1:1:128)
   2 7c7m5p2d6hgrv            1191       1,64          1191       0,41      301836       8,69 direct path read(1179:1179:301690); db file sequential read(10:10:10); db file scattered read(2:2:136)
   1 (LG00)                   3705       5,09         11268       3,84      241952       6,97 log file parallel write(3705:11268:241952)
   1 8nvw9g88s3u3p            1313       1,81          1430       0,49      183591       5,29 db file scattered read(927:927:114035); direct path read(343:343:69145); read by other session(20:20:20); db file sequential read(17:17:17); direct path write temp(3:3:130); direct path read temp(2:2:126); db file parallel read(1:118:118)
   1 8r5cuxzdqy9zm             690       0,95           690       0,24      176366       5,08 direct path read(690:690:176366)
   1 6pjyzur87q35n            3709        5,1        137753      46,97      137753       3,97 db file parallel read(2087:136131:136131); db file sequential read(1609:1609:1609); read by other session(12:12:12); Disk file operations I/O(1:1:1)
   1 7zcz3z8kvghva            1956       2,69          5138       1,75       94147       2,71 db file sequential read(1578:1578:1578); direct path read(350:350:89359); db file parallel read(28:3210:3210)
   1 (ARC4)                    349       0,48           349       0,12       73087       2,11 log file sequential read(285:285:72960); control file sequential read(32:32:95); Log archive I/O(27:27:27); Disk file Mirror Read(5:5:5)
   2 (ARC2)                    672       0,92           672       0,23       64930       1,87 control file sequential read(258:258:258); log file sequential read(254:254:64512); Log archive I/O(95:95:95); Disk file Mirror Read(65:65:65)
   2 7zcz3z8kvghva            1278       1,76          3152       1,07       56200       1,62 db file sequential read(1021:1021:1021); direct path read(205:205:52479); db file parallel read(21:1895:1895); db file scattered read(17:17:47); direct path read temp(6:6:378); direct path write temp(6:6:378); read by other session(2:2:2)
   2 (LG01)                    553       0,76          1634       0,56       54429       1,57 log file parallel write(553:1634:54429)
   2 d266j9sy9qfc2             296       0,41           336       0,11       43180       1,24 direct path read(184:184:38570); direct path write temp(62:62:3842); db file sequential read(22:22:22); db file scattered read(19:19:515); direct path read temp(5:5:187); db file parallel read(4:44:44)
   1 1kmbdxzuxy443             336       0,46           336       0,11       42976       1,24 db file scattered read(336:336:42976)
   1 (LG01)                    512        0,7          1506       0,51       36475       1,05 log file parallel write(512:1506:36475)
...

, на порядок превышающую активность LG01, что, возможно, демонстрирует реализацию LGnn (Log Writer Worker) processes are not used when there is a SYNC standby destination, или просто является следствием невысокой интенсивности генерации redo,…

В другой OLTP бд по кол-ву ожиданий (SUM(WAIT_COUNT)) топ занимают DBRW процессы:

SQL> @ash_io_waits waits 10 "where sample_time > sysdate - 2/24"
 
INST SQL_PROCESS   SUM(WAIT_COUNT)     waits% SUM(REQUESTS)      reqs% SUM(BLOCKS)    blocks% event(waits:requests:blocks)
---- ------------- --------------- ---------- ------------- ---------- ----------- ---------- -------------------------------------------------------------------------------------------------------------
   1 (DBW1)                   4054       6,71          4054       4,04        4054       0,64 db file parallel write(4054:4054:4054)
   1 (DBW0)                   3920       6,49          3920        3,9        3920       0,62 db file parallel write(3920:3920:3920)
   1 (DBW2)                   3666       6,07          3666       3,65        3666       0,58 db file parallel write(3666:3666:3666)
   1 (DBW4)                   3486       5,77          3486       3,47        3486       0,55 db file parallel write(3486:3486:3486)
   1 (DBW3)                   3485       5,77          3485       3,47        3485       0,55 db file parallel write(3485:3485:3485)
   1 (DBW5)                   3426       5,67          3426       3,41        3426       0,54 db file parallel write(3426:3426:3426)
   1 15gjqxuh22a2a            3401       5,63          3415        3,4      214711       33,9 db file scattered read(3390:3390:214686); db file sequential read(9:9:9); db file parallel read(2:16:16)
   1 d4n18h9zr8pbv            2537        4,2          2537       2,53        2537        0,4 db file sequential read(2537:2537:2537)
   1 (ARC3)                   1574       2,61          1574       1,57       11465       1,81 Log archive I/O(1409:1409:1409); log file sequential read(157:157:10048); control file sequential read(8:8:8)
   1 8m20zfsv98dkb            1567        2,6          1567       1,56        1567       0,25 db file sequential read(1079:1079:1079); read by other session(488:488:488)
 
10 rows selected

, а по кол-ву системных запросов на I/O (SUM(REQUESTS)) проявляются запросы, активно использующие ожидание db file parallel read:

SQL> @ash_io_waits reqs 10 "where sample_time > sysdate - 1/24"
 
INST SQL_PROCESS   SUM(WAIT_COUNT)     waits% SUM(REQUESTS)      reqs% SUM(BLOCKS)    blocks% event(waits:requests:blocks)
---- ------------- --------------- ---------- ------------- ---------- ----------- ---------- ---------------------------------------------------------------------------------------------------------------------------------------------
   1 9q83f8ku3dcjf            1807       4,34         50926      38,22       50930      14,58 db file sequential read(1340:1340:1340); db file parallel read(466:49585:49585); db file scattered read(1:1:5)
   1 9bs9djg83hd5g             141       0,34         13431      10,08       13431       3,85 db file parallel read(114:13404:13404); db file sequential read(23:23:23); read by other session(4:4:4)
   1 6323dus0q91ad             239       0,57         11732       8,81       11732       3,36 db file parallel read(160:11653:11653); db file sequential read(79:79:79)
   1 cq58t7r803pf0              87       0,21          5750       4,32        5750       1,65 db file parallel read(48:5711:5711); db file sequential read(27:27:27); read by other session(12:12:12)
   1 6qr7ktqcg0g5r             113       0,27          5617       4,22        5617       1,61 db file sequential read(68:68:68); db file parallel read(45:5549:5549)
   1 8t18yxs8gff0j            3076       7,39          3091       2,32        3096       0,89 db file sequential read(1611:1611:1611); read by other session(1455:1455:1455); db file parallel read(7:22:22); db file scattered read(3:3:8)
   1 (DBW1)                   2463       5,92          2463       1,85        2463       0,71 db file parallel write(2463:2463:2463)
   1 (DBW0)                   2410       5,79          2410       1,81        2410       0,69 db file parallel write(2410:2410:2410)
   1 caf1q5yd565xq            2300       5,53          2300       1,73        2300       0,66 db file sequential read(2300:2300:2300)
   1 (DBW4)                   2278       5,47          2278       1,71        2278       0,65 db file parallel write(2278:2278:2278)
 
10 rows selected

— подробно с трейсами описанное в The Oracle ‘db file parallel read’ wait event

В третьей бд (ERP типа) по топу обработанных блоков можно оценить красоту FULL SCAN-ов (и, стало быть HASH JOIN-ов, перестроение MVIEW, etc…):)

SQL> @ash_io_waits blocks 10 "where sample_time > sysdate - 1/24/2"
 
INST SQL_PROCESS   SUM(WAIT_COUNT)     waits% SUM(REQUESTS)      reqs% SUM(BLOCKS)    blocks% event(waits:requests:blocks)
---- ------------- --------------- ---------- ------------- ---------- ----------- ---------- ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
   2 5ts81uw6t5juu             288      11,37           288       9,54       33916      42,27 direct path read(268:268:33896); db file sequential read(20:20:20)
   2 6j8csg1rbwv3y             199       7,85           199       6,59       23915       29,8 direct path read(199:199:23915)
   2 ck8r731jj3vfj             118       4,66           118       3,91       14562      18,15 direct path read(118:118:14562)
   2 03fcwns9kqtsj             207       8,17           207       6,86        1189       1,48 direct path read temp(207:207:1189)
   1 FOREGROUND                 16       0,63            16       0,53         712       0,89 control file sequential read(11:11:704); Disk file operations I/O(2:2:2); direct path write temp(2:2:2); direct path read(1:1:4)
   1 7w5f28c52uqn1              92       3,63            92       3,05         675       0,84 db file sequential read(53:53:53); direct path read(39:39:622)
   1 18sysu7va59rz             531      20,96           531      17,59         573       0,71 db file sequential read(524:524:524); db file scattered read(7:7:49)
   2 FOREGROUND                 15       0,59            15        0,5         522       0,65 control file sequential read(8:8:512); Disk file operations I/O(4:4:4); direct path write temp(2:2:2); direct path read(1:1:4)
   1 3nkb2k9zhyu9v              89       3,51           481      15,94         481        0,6 db file parallel read(48:440:440); db file sequential read(41:41:41)
   1 (ARC7)                      8       0,32             8       0,27         452       0,56 control file sequential read(5:5:68); log file sequential read(3:3:384)
 
10 rows selected

В части статистики отдельных запросов точные данные, конечно же, в V$SQLSTATS/DBA_HIST_SQLSTAT, а скрипт может быть полезен для оценки общей картины на произвольных отрезках времени

P.S. Текст запроса:

--
-- ASH I/O waits
-- Usage: SQL> @ash_io_waits [waits|reqs|blocks] [10]         "where sample_time > sysdate - 1/24"
--                            ^sort order         ^top N rows  ^ash filter
-- by Igor Usoltsev
--

set echo off feedback off heading on timi off pages 1000 lines 500 VERIFY OFF

col SQL_PROCESS for a13
col "event(waits:requests:blocks)" for a300
col "waits%" for 99.00
col "reqs%" for 99.00
col "blocks%" for 99.00
col inst_id for 9999 hea #i
col PROGRAMS for a60 HEADING 'PROGRAMS BY TYPES                                           '
col t0 for 999

with ash as (select * from gv$active_session_history &3)
, log_block as (select value / (select max(blocksize) from v$log) as ratio from v$parameter where name = 'db_block_size')
select * from (
    select inst_id,
           SQL_PROCESS,
           SUM(WAIT_COUNT),
           round(RATIO_TO_REPORT(SUM(WAIT_COUNT)) OVER() * 100, 2) AS "waits%",
           SUM(REQUESTS),
           round(RATIO_TO_REPORT(SUM(REQUESTS)) OVER() * 100, 2)   AS "reqs%",
           SUM(BLOCKS),
           round(RATIO_TO_REPORT(SUM(BLOCKS)) OVER() * 100, 2)     AS "blocks%",
           decode(nvl(upper('&&1'), 'BLOCKS')
                                 , 'WAITS' , rtrim(xmlagg(xmlelement(s, EVENT || '(' || WAIT_COUNT||':'|| REQUESTS ||':'|| BLOCKS, '); ').extract('//text()') order by WAIT_COUNT desc), '; ')
                                 , 'REQS'  , rtrim(xmlagg(xmlelement(s, EVENT || '(' || WAIT_COUNT||':'|| REQUESTS ||':'|| BLOCKS, '); ').extract('//text()') order by REQUESTS desc), '; ')
                                 , 'BLOCKS', rtrim(xmlagg(xmlelement(s, EVENT || '(' || WAIT_COUNT||':'|| REQUESTS ||':'|| BLOCKS, '); ').extract('//text()') order by BLOCKS desc), '; ')
                                           , rtrim(xmlagg(xmlelement(s, EVENT || '(' || WAIT_COUNT||':'|| REQUESTS ||':'|| BLOCKS, '); ').extract('//text()') order by BLOCKS desc), '; '))
--           rtrim(xmlagg(xmlelement(s, EVENT || '(' || WAIT_COUNT||':'|| REQUESTS ||':'|| BLOCKS, '); ').extract('//text()') order by WAIT_COUNT desc), '; ')
            as "event(waits:requests:blocks)"
      from (select inst_id,
                   SQL_PROCESS,
                   event,
                   sum(WAIT_COUNT)                   as WAIT_COUNT,
                   sum(WAIT_COUNT * REQS_PER_WAIT)   as REQUESTS,
                   round(sum(WAIT_COUNT * BLOCKS_PER_WAIT) / decode(substr(event, 1, 8), 'log file', log_block.ratio, 1)) as BLOCKS
              from (select count(*) as WAIT_COUNT,
                           nvl(sql_id,decode(session_type,'BACKGROUND',REGEXP_SUBSTR(program, '\([^\)]+\)'), nvl2(qc_session_id, 'PX', 'FOREGROUND'))) as SQL_PROCESS,
                           event,
                           case when  p2text = 'blocks' then p2 when p3text in ('blocks','block cnt') then p3 else 1 end as BLOCKS_PER_WAIT,
                           decode(p3text,'requests',p3,1)                                           as REQS_PER_WAIT,
                           inst_id
                      from ash
                     where 
                        wait_class in ('User I/O','System I/O') and
                        session_state = 'WAITING'
                     group by nvl(sql_id,decode(session_type,'BACKGROUND',REGEXP_SUBSTR(program, '\([^\)]+\)'), nvl2(qc_session_id, 'PX', 'FOREGROUND'))),
                              event,
                              case when  p2text = 'blocks' then p2 when p3text in ('blocks','block cnt') then p3 else 1 end,
                              decode(p3text,'requests',p3,1),
                              inst_id)
                 , log_block
             group by inst_id,
                      SQL_PROCESS,
                      event,
                      log_block.ratio)
     group by inst_id, SQL_PROCESS
     order by decode(nvl(upper('&&1'),'BLOCKS'), 'WAITS', SUM(WAIT_COUNT), 'REQS', SUM(REQUESTS), 'BLOCKS', SUM(BLOCKS), SUM(BLOCKS)) desc
) where rownum <= nvl('&2', 10)
/
set feedback on echo off VERIFY ON

, в числе прочих можно скачать одним zip-ом

Добавить комментарий »

Комментариев нет.

RSS feed for comments on this post. TrackBack URI

Добавить комментарий

Заполните поля или щелкните по значку, чтобы оставить свой комментарий:

Логотип WordPress.com

Для комментария используется ваша учётная запись WordPress.com. Выход / Изменить )

Фотография Twitter

Для комментария используется ваша учётная запись Twitter. Выход / Изменить )

Фотография Facebook

Для комментария используется ваша учётная запись Facebook. Выход / Изменить )

Google+ photo

Для комментария используется ваша учётная запись Google+. Выход / Изменить )

Connecting to %s

Блог на WordPress.com.

%d такие блоггеры, как: