[20211111]奇怪的ashtop輸出.txt

lfree發表於2021-11-12

[20211111]奇怪的ashtop輸出.txt

--//看了生產系統ashtop輸出,感覺很奇怪,不知道那裡出了問題,簡單探究看看。

1.環境:
XXXX> @ ver1
PORT_STRING                    VERSION        BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx            11.2.0.4.0     Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production

2.ashtop輸出:
XXXX> @ ashtop event session_type='FOREGROUND'  trunc(sysdate)+9/24 trunc(sysdate)+10/24
    Total
  Seconds     AAS %This   EVENT                                    FIRST_SEEN          LAST_SEEN
--------- ------- ------- ---------------------------------------- ------------------- -------------------
      689      .2   62% |                                          2021-11-11 09:00:20 2021-11-11 09:59:04
      197      .1   18% | direct path read                         2021-11-11 09:00:23 2021-11-11 09:59:43
      113      .0   10% | cell single block physical read          2021-11-11 09:01:14 2021-11-11 09:59:26
       23      .0    2% | control file sequential read             2021-11-11 09:03:02 2021-11-11 09:58:06
       19      .0    2% | direct path write                        2021-11-11 09:04:23 2021-11-11 09:59:05
       18      .0    2% | log file sync                            2021-11-11 09:00:02 2021-11-11 09:59:36
        7      .0    1% | Disk file Mirror Read                    2021-11-11 09:03:05 2021-11-11 09:52:55
        5      .0    0% | SQL*Net break/reset to client            2021-11-11 09:08:36 2021-11-11 09:51:51
        5      .0    0% | SQL*Net more data to client              2021-11-11 09:01:24 2021-11-11 09:59:28
        5      .0    0% | enq: PS - contention                     2021-11-11 09:03:07 2021-11-11 09:36:38
        5      .0    0% | null event                               2021-11-11 09:03:16 2021-11-11 09:39:06
        3      .0    0% | PX Deq: Slave Session Stats              2021-11-11 09:14:08 2021-11-11 09:59:03
        3      .0    0% | gc cr block 2-way                        2021-11-11 09:03:10 2021-11-11 09:39:18
        3      .0    0% | gc current block 2-way                   2021-11-11 09:16:27 2021-11-11 09:39:18
        2      .0    0% | IPC send completion sync                 2021-11-11 09:24:01 2021-11-11 09:54:06
        2      .0    0% | SQL*Net more data from client            2021-11-11 09:02:36 2021-11-11 09:34:49
        2      .0    0% | enq: HW - contention                     2021-11-11 09:11:33 2021-11-11 09:47:37
        1      .0    0% | enq: FB - contention                     2021-11-11 09:11:08 2021-11-11 09:11:08
        1      .0    0% | gc cr request                            2021-11-11 09:03:10 2021-11-11 09:03:10
        1      .0    0% | gc current grant busy                    2021-11-11 09:01:50 2021-11-11 09:01:50
        1      .0    0% | gc current multi block request           2021-11-11 09:42:11 2021-11-11 09:42:11
21 rows selected.
--//我們以前db time最少幾個小時以上的,怎麼突然變得這麼好,問題出在那裡。

XXXX> @ dashtop event session_type='FOREGROUND'  trunc(sysdate)+9/24 trunc(sysdate)+10/24
                                                    Total
%This  EVENT                                      Seconds FIRST_SEEN          LAST_SEEN
------ ---------------------------------------- --------- ------------------- -------------------
  89%                                               42340 2021-11-11 09:00:05 2021-11-11 09:59:56
   6%  cell single block physical read               2660 2021-11-11 09:00:05 2021-11-11 09:59:56
   2%  direct path write temp                         830 2021-11-11 09:00:16 2021-11-11 09:59:56
   1%  log file sync                                  480 2021-11-11 09:00:02 2021-11-11 09:58:14
   1%  SQL*Net more data to client                    360 2021-11-11 09:00:56 2021-11-11 09:59:28
   1%  direct path read                               260 2021-11-11 09:00:23 2021-11-11 09:58:27
   0%  cell list of blocks physical read              170 2021-11-11 09:07:22 2021-11-11 09:59:25
   0%  null event                                     110 2021-11-11 09:00:56 2021-11-11 09:59:15
   0%  SQL*Net break/reset to client                   70 2021-11-11 09:17:10 2021-11-11 09:58:55
   0%  control file sequential read                    40 2021-11-11 09:05:50 2021-11-11 09:50:12
   0%  gc cr multi block request                       40 2021-11-11 09:12:36 2021-11-11 09:43:52
   0%  gc current block 2-way                          40 2021-11-11 09:13:47 2021-11-11 09:40:40
   0%  cell multiblock physical read                   30 2021-11-11 09:19:22 2021-11-11 09:59:45
   0%  direct path write                               30 2021-11-11 09:17:32 2021-11-11 09:55:35
   0%  SQL*Net more data from client                   20 2021-11-11 09:18:51 2021-11-11 09:41:20
   0%  cursor: pin S                                   20 2021-11-11 09:41:41 2021-11-11 09:41:41
   0%  Disk file Mirror Read                           10 2021-11-11 09:35:45 2021-11-11 09:35:45
   0%  Disk file operations I/O                        10 2021-11-11 09:12:06 2021-11-11 09:12:06
   0%  cell smart table scan                           10 2021-11-11 09:21:04 2021-11-11 09:21:04
   0%  cursor: pin S wait on X                         10 2021-11-11 09:52:40 2021-11-11 09:52:40
   0%  gc cr block 2-way                               10 2021-11-11 09:18:03 2021-11-11 09:18:03
   0%  gc current grant busy                           10 2021-11-11 09:42:11 2021-11-11 09:42:11
   0%  read by other session                           10 2021-11-11 09:42:51 2021-11-11 09:42:51
23 rows selected.
--//可以發現dashtop才是比較真實的顯示結果。問題出在那裡呢?
--//42340/3600 = 11.76.

XXXX> SELECT count(*),inst_id FROM gV$ACTIVE_SESSION_HISTORY  WHERE sample_time BETWEEN
                              trunc(sysdate)+9/24 and trunc(sysdate)+10/24 group by inst_id ;
  COUNT(*)    INST_ID
---------- ----------
      1417          2

--//實際上9-10點的資訊在其中一個例項已經不存在gV$ACTIVE_SESSION_HISTORY檢視中,導致出現不對的結果。
--//當前時間:
XXXX> select sysdate from dual ;
SYSDATE
-------------------
2021-11-11 16:39:55
--//實際上 Active Session History buffers 資訊受隱含引數_ash_size控制。
XXXX> @ pd _ash_size
Show all parameters and session values from x$ksppi/x$ksppcv...
      INDX I_HEX NAME                          VALUE    DESCRIPTION
---------- ----- ----------------------------- -------- ----------------------------------------------------------------------
      2647   A57 _olap_dimension_corehash_size 30       OLAP Dimension In-Core Hash Table Maximum Memory Use
      2731   AAB _kffmap_hash_size             1024     size of kffmap_hash table
      2732   AAC _kffmop_hash_size             2048     size of kffmop_hash table
      2840   B18 _ash_size                     1048618  To set the size of the in-memory Active Session History buffers

--//預設1048618 大約1M,如果產生資訊太多,最早產生的資訊將被清除出去。我們生產系統估計一個例項太忙,無法儲存太多ASH資訊。
--//出現ashtop輸出的奇怪現象,以後工作注意。

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/267265/viewspace-2841835/,如需轉載,請註明出處,否則將追究法律責任。

相關文章