[20211111]19c latch free等待时间分析.txt

来源:这里教程网 时间:2026-03-03 17:08:20 作者:

[20211111]19c latch free等待时间分析.txt --//前天遇到的问题,当时的分析有点乱,遇到一些奇怪的问题,自己今天做一些整理. --//检查生产系统,出现latch free等待事件有一些靠前,分析看看。 1.环境: SYS@XXXXX1/ORCLX> @ prxx ============================== PORT_STRING                   : x86_64/Linux 2.4.xx VERSION                       : 19.0.0.0.0 BANNER                        : Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production BANNER_FULL                   : Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production Version 19.9.0.0.0 BANNER_LEGACY                 : Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production CON_ID                        : 0 PL/SQL procedure successfully completed. 2.分析: SYS@XXXXX1/ORCLX> @ ashtop event 1=1 trunc(sysdate) sysdate     Total   Seconds     AAS %This   EVENT                                    FIRST_SEEN          LAST_SEEN --------- ------- ------- ---------------------------------------- ------------------- -------------------     52745      .9   75% |                                          2021-11-09 00:00:02 2021-11-09 16:56:57     10042      .2   14% | Failed Logon Delay                       2021-11-09 00:00:04 2021-11-09 16:56:59      2368      .0    3% | control file sequential read             2021-11-09 00:00:42 2021-11-09 16:56:59      1445      .0    2% | latch free                               2021-11-09 00:01:07 2021-11-09 16:56:50       724      .0    1% | SQL*Net more data to client              2021-11-09 03:11:22 2021-11-09 16:48:59       441      .0    1% | enq: SQ - contention                     2021-11-09 15:53:56 2021-11-09 16:07:01 .. --//其它问题先不管,先前提交的问题都没有解决,无语。主要集中在等待事件latch free上. SYS@XXXXX1/ORCLX> @ ev_name "latch free" EVENT#   EVENT_ID NAME                          PARAMETER1 PARAMETER2 PARAMETER3 WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS DISPLAY_NAME                  CON_ID ------ ---------- ----------------------------- ---------- ---------- ---------- ------------- ----------- ---------- ----------------------------- ------    529 3474287957 latch free                    address    number     why           1893977003           0 Other      latch free                         0    531 2530878290 wait list latch free          address    number                   1893977003           0 Other      wait list latch free               0    646 3765978937 GL: cross instance latch free                                     1893977003           0 Other      GL: cross instance latch free      0 --//latch free 第一个参数p1是latch address。 --//我发现集中在p1=1611087616. SYS@XXXXX1/ORCLX> @ ashtop sql_id,event,p1 p1=1611087616 trunc(sysdate)-1 trunc(sysdate)     Total   Seconds     AAS %This   SQL_ID        EVENT                                            P1 FIRST_SEEN          LAST_SEEN --------- ------- ------- ------------- ---------------------------------------- ---------- ------------------- -------------------      2127      .0   92% |               latch free                               1611087616 2021-11-09 00:01:07 2021-11-09 23:59:46       113      .0    5% |                                                        1611087616 2021-11-09 00:07:26 2021-11-09 23:58:58        61      .0    3% | f3yfg50ga0r8n latch free                               1611087616 2021-11-09 00:23:12 2021-11-09 23:55:51         2      .0    0% | 9x2prazfz86dz                                          1611087616 2021-11-09 15:02:30 2021-11-09 19:12:36         2      .0    0% | f3yfg50ga0r8n                                          1611087616 2021-11-09 00:47:18 2021-11-09 18:24:55 --//1611087616 = 0x60073f00 SYS@XXXXX1/ORCLX> select * from v$latch_children where addr=hextoraw('0000000060073f00'); no rows selected SYS@XXXXX1/ORCLX> select * from v$latch_parent where addr=hextoraw('0000000060073f00')   2  @ prxx ============================== ADDR                          : 0000000060073F00 LATCH#                        : 517 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~=> P2=517 ,对应LATCH#。 LEVEL#                        : 0 NAME                          : space background task latch ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ HASH                          : 1314311971 GETS                          : 1444462 MISSES                        : 798314 SLEEPS                        : 700416 IMMEDIATE_GETS                : 487163 IMMEDIATE_MISSES              : 1603 WAITERS_WOKEN                 : 0 WAITS_HOLDING_LATCH           : 0 SPIN_GETS                     : 98145 SLEEP1                        : 0 SLEEP2                        : 0 SLEEP3                        : 0 SLEEP4                        : 0 SLEEP5                        : 0 SLEEP6                        : 0 SLEEP7                        : 0 SLEEP8                        : 0 SLEEP9                        : 0 SLEEP10                       : 0 SLEEP11                       : 0 WAIT_TIME                     : 199041612 CON_ID                        : 0 PL/SQL procedure successfully completed. SYS@XXXXX1/ORCLX> select * from v$latch where addr=hextoraw('0000000060073f00')   2  @ prxx ============================== ADDR                          : 0000000060073F00 LATCH#                        : 517 LEVEL#                        : 0 NAME                          : space background task latch HASH                          : 1314311971 GETS                          : 1608487 MISSES                        : 888515 SLEEPS                        : 780457 IMMEDIATE_GETS                : 542974 IMMEDIATE_MISSES              : 1860 WAITERS_WOKEN                 : 0 WAITS_HOLDING_LATCH           : 0 SPIN_GETS                     : 108330 SLEEP1                        : 0 SLEEP2                        : 0 SLEEP3                        : 0 SLEEP4                        : 0 SLEEP5                        : 0 SLEEP6                        : 0 SLEEP7                        : 0 SLEEP8                        : 0 SLEEP9                        : 0 SLEEP10                       : 0 SLEEP11                       : 0 WAIT_TIME                     : 218601878 CON_ID                        : 0 PL/SQL procedure successfully completed. --//也就是出现数据文件空间增加的情况。 SYS@XXXXX1/ORCLX> @ tpt/ash/ash_wait_chains BLOCKING_SESSION||','||BLOCKING_SESSION_SERIAL#||',@'||BLOCKING_INST_ID||'=>'||session_id||','||SESSION_SERIAL#||',@'||inst_id||'=>'||event "event='latch free'" sysdate-100 sysdate -- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com ) %This     SECONDS     AAS #Blkrs WAIT_CHAIN                                                                 FIRST_SEEN          LAST_SEEN ------ ---------- ------- ------ -------------------------------------------------------------------------- ------------------- -------------------    9%         414      .0      1 -> 5741,22079,@2=>623,49489,@2=>latch free -> [idle blocker 2,5741,22079]  2021-11-08 00:02:17 2021-11-10 09:48:38    8%         404      .0      1 -> 5741,22079,@2=>620,50618,@2=>latch free -> [idle blocker 2,5741,22079]  2021-11-08 00:03:53 2021-11-10 09:51:02    8%         384      .0      1 -> 5741,22079,@2=>319,21988,@2=>latch free -> [idle blocker 2,5741,22079]  2021-11-08 00:03:05 2021-11-10 09:35:09    7%         352      .0      1 -> 5741,22079,@2=>304,39734,@2=>latch free -> [idle blocker 2,5741,22079]  2021-11-08 00:07:02 2021-11-10 09:35:09    7%         333      .0      1 -> 5741,14347,@1=>617,1119,@1=>latch free -> [idle blocker 1,5741,14347]   2021-11-08 10:43:55 2021-11-10 09:46:59    7%         332      .0      1 -> 5741,14347,@1=>304,33924,@1=>latch free -> [idle blocker 1,5741,14347]  2021-11-08 10:20:52 2021-11-10 09:42:19    6%         296      .0      1 -> 5741,14347,@1=>313,35032,@1=>latch free -> [idle blocker 1,5741,14347]  2021-11-08 10:24:49 2021-11-10 09:35:09    5%         259      .0      1 -> 5741,22079,@2=>922,65278,@2=>latch free -> [idle blocker 2,5741,22079]  2021-11-08 00:04:41 2021-11-10 09:30:23    5%         259      .0      1 -> 5741,22079,@2=>909,59733,@2=>latch free -> [idle blocker 2,5741,22079]  2021-11-08 00:22:08 2021-11-10 09:37:30    5%         238      .0      1 -> 5741,22079,@2=>924,63040,@2=>latch free -> [idle blocker 2,5741,22079]  2021-11-08 00:05:29 2021-11-10 09:47:50    4%         172      .0      1 -> 5741,14347,@1=>920,33701,@1=>latch free -> [idle blocker 1,5741,14347]  2021-11-08 10:19:19 2021-11-10 09:43:56    4%         172      .0      1 -> 5741,14347,@1=>912,57351,@1=>latch free -> [idle blocker 1,5741,14347]  2021-11-08 10:19:19 2021-11-10 09:42:19    3%         166      .0      1 -> 5741,14347,@1=>909,2656,@1=>latch free -> [idle blocker 1,5741,14347]   2021-11-08 10:19:19 2021-11-10 09:41:31    3%         150      .0      1 -> 5741,22079,@2=>1218,46170,@2=>latch free -> [idle blocker 2,5741,22079] 2021-11-08 00:26:54 2021-11-10 09:43:52    1%          72      .0      1 -> 5741,14347,@1=>1220,2757,@1=>latch free -> [idle blocker 1,5741,14347]  2021-11-08 10:33:36 2021-11-10 08:55:27    1%          63      .0      1 -> 5741,14347,@1=>1222,27776,@1=>latch free -> [idle blocker 1,5741,14347] 2021-11-08 10:33:36 2021-11-10 08:18:18    1%          53      .0      1 -> 5741,22079,@2=>1522,52927,@2=>latch free -> [idle blocker 2,5741,22079] 2021-11-08 00:01:32 2021-11-10 09:49:26    1%          51      .0      1 -> 5741,22079,@2=>1517,50587,@2=>latch free -> [idle blocker 2,5741,22079] 2021-11-08 13:04:58 2021-11-10 09:51:02    1%          41      .0      1 -> 5741,22079,@2=>1528,19663,@2=>latch free -> [idle blocker 2,5741,22079] 2021-11-09 13:51:48 2021-11-10 09:04:10    1%          37      .0      1 -> ,,@=>922,65278,@2=>latch free                                           2021-11-08 01:29:40 2021-11-09 12:34:47    1%          34      .0      1 -> ,,@=>924,63040,@2=>latch free                                           2021-11-08 00:50:45 2021-11-09 10:38:05    1%          30      .0      1 -> 5741,14347,@1=>10,58694,@1=>latch free -> [idle blocker 1,5741,14347]   2021-11-08 11:18:04 2021-11-10 09:17:42    1%          30      .0      1 -> 5741,14347,@1=>1522,52719,@1=>latch free -> [idle blocker 1,5741,14347] 2021-11-08 10:24:04 2021-11-10 08:10:20    1%          28      .0      1 -> 5741,14347,@1=>12,25446,@1=>latch free -> [idle blocker 1,5741,14347]   2021-11-08 11:13:18 2021-11-10 08:15:05    0%          22      .0      1 -> 5741,22079,@2=>18,16175,@2=>latch free -> [idle blocker 2,5741,22079]   2021-11-08 05:55:34 2021-11-10 09:50:14    0%          21      .0      1 -> 5741,22079,@2=>16,50299,@2=>latch free -> [idle blocker 2,5741,22079]   2021-11-08 02:30:37 2021-11-10 08:00:41    0%          20      .0      1 -> ,,@=>909,59733,@2=>latch free                                           2021-11-08 00:12:36 2021-11-09 10:42:50    0%          20      .0      1 -> 5741,22079,@2=>1827,39734,@2=>latch free -> [idle blocker 2,5741,22079] 2021-11-09 03:55:36 2021-11-10 09:43:04    0%          17      .0      1 -> 5741,22079,@2=>3638,62933,@2=>latch free -> [idle blocker 2,5741,22079] 2021-11-08 04:01:13 2021-11-10 08:52:14    0%          17      .0      1 -> 5741,22079,@2=>1830,46599,@2=>latch free -> [idle blocker 2,5741,22079] 2021-11-09 03:55:36 2021-11-10 09:00:12 30 rows selected. --//不知道是巧合还是什么原因,两边的阻塞的sid都是=5741. SYS@XXXXX1/ORCLX> @ sid 5741 sid = 5741 SPID       PID        SID    SERIAL# CLIENT_INFO PNAME  TRACEFILE                                                           PROGRAM            TERMINAL SQL_ID        STATUS   C50 ------ ------- ---------- ---------- ----------- ------ ------------------------------------------------------------------- ------------------ -------- ------------- -------- -------------------------------------------------- 17289       39       5741      14347             SMCO   /u01/app/oracle/diag/rdbms/ORCLX/ORCLX1/trace/ORCLX1_smco_17289.trc oracle@oda1 (SMCO) UNKNOWN                ACTIVE   alter system kill session '5741,14347' immediate; SYS@XXXXX1/ORCLX> @ bgx SMCO PROGRAM                                  MODULE       ACTION             SID     PID SPID ---------------------------------------- ------------ ---------------- ----- ------- ------ oracle@oda1 (SMCO)                       KTSJ         KTSJ Coordinator  5741      39 17289 --//应该是smco后台进程,不断检测导致的情况。运维没有做好相应工作,数据文件应该撑开足够的大小。 CREATE TABLESPACE PPPPPP_HHH DATAFILE   '+DATA/ORCLX/DATAFILE/PPPPPP_HHH01' SIZE 12724M AUTOEXTEND ON NEXT 20M MAXSIZE UNLIMITED,   '+DATA/ORCLX/DATAFILE/PPPPPP_HHH02' SIZE 12644M AUTOEXTEND ON NEXT 20M MAXSIZE UNLIMITED LOGGING ONLINE EXTENT MANAGEMENT LOCAL AUTOALLOCATE BLOCKSIZE 8K SEGMENT SPACE MANAGEMENT MANUAL FLASHBACK ON; --//先增加数据文件大小 32G-8K = 32*1024*1024-8 = 33554424 K. --//安全一点是慢慢增加,不是一次到位。过程略. --//明天上班观察看看。上班观察发现,问题依旧: --//2021-11-10 观察到的情况,没解决问题.该扩展的数据文件我已经扩展了,为什么还出现这样的情况呢? SYS@XXXXX1/ORCLX> @ ashtop trunc(sample_time,'HH'),event,p1,p2,p3 "event like '%latch free%'" trunc(sysdate) sysdate     Total   Seconds     AAS %This   TRUNC_SAMPLE_TIME,' EVENT              P1         P2         P3 FIRST_SEEN          LAST_SEEN --------- ------- ------- ------------------- ---------- ---------- ---------- ---------- ------------------- -------------------       116      .0   12% | 2021-11-10 07:00:00 latch free 1611087616        517          0 2021-11-10 07:00:23 2021-11-10 07:59:56       115      .0   12% | 2021-11-10 00:00:00 latch free 1611087616        517          0 2021-11-10 00:01:25 2021-11-10 00:59:22       112      .0   12% | 2021-11-10 02:00:00 latch free 1611087616        517          0 2021-11-10 02:00:32 2021-11-10 02:59:56       111      .0   12% | 2021-11-10 03:00:00 latch free 1611087616        517          0 2021-11-10 03:00:00 2021-11-10 03:59:31       106      .0   11% | 2021-11-10 04:00:00 latch free 1611087616        517          0 2021-11-10 04:00:09 2021-11-10 04:58:54       105      .0   11% | 2021-11-10 05:00:00 latch free 1611087616        517          0 2021-11-10 05:02:04 2021-11-10 05:59:23       104      .0   11% | 2021-11-10 06:00:00 latch free 1611087616        517          0 2021-11-10 06:00:01 2021-11-10 06:59:38        91      .0   10% | 2021-11-10 01:00:00 latch free 1611087616        517          0 2021-11-10 01:00:58 2021-11-10 01:59:38        89      .0    9% | 2021-11-10 08:00:00 latch free 1611087616        517          0 2021-11-10 08:00:41 2021-11-10 08:49:04 9 rows selected. SYS@XXXXX1/ORCLX> @ hide _spacebg NAME                         DESCRIPTION                                           DEFAULT_VALUE SESSION_VALUE SYSTEM_VALUE ISSES ISSYS_MOD ---------------------------- ----------------------------------------------------- ------------- ------------- ------------ ----- --------- _enable_spacebg              enable space management background task               TRUE          TRUE          TRUE         FALSE IMMEDIATE _max_spacebg_msgs_percentage maximum space management interrupt message throttling TRUE          50            50           FALSE IMMEDIATE _max_spacebg_slaves          maximum space management background slaves            TRUE          1024          1024         FALSE IMMEDIATE _max_spacebg_tasks           maximum space management background tasks             TRUE          8192          8192         FALSE FALSE _min_spacebg_slaves          minimum space management background slaves            TRUE          2             2            FALSE IMMEDIATE _minmax_spacebg_slaves       min-max space management background slaves            TRUE          8             8            FALSE IMMEDIATE _spacebg_sync_segblocks      to enable/disable segmon driver                       TRUE          TRUE          TRUE         TRUE  IMMEDIATE 7 rows selected. --//临时关闭这个特性。 SYS@XXXXX1/ORCLX> alter system set "_enable_spacebg"=false scope=memory; System altered. --//关闭后确实消失,但是打开马上出现,有点奇怪. SYS@XXXXX1/ORCLX> alter system set "_enable_spacebg"=true scope=memory; System altered. SYS@XXXXX1/ORCLX> @ ashtop trunc(sample_time,'HH'),event,p1,p2,p3 "event like '%latch free%'" trunc(sysdate) sysdate     Total   Seconds     AAS %This   TRUNCSAMPLE_TIME,' EVENT              P1         P2         P3 FIRST_SEEN          LAST_SEEN --------- ------- ------- ------------------- ---------- ---------- ---------- ---------- ------------------- -------------------       144      .0   13% | 2021-11-11 05:00:00 latch free 1611087616        517          0 2021-11-11 05:00:20 2021-11-11 05:59:53       144      .0   13% | 2021-11-11 06:00:00 latch free 1611087616        517          0 2021-11-11 06:01:04 2021-11-11 06:59:50       129      .0   12% | 2021-11-11 04:00:00 latch free 1611087616        517          0 2021-11-11 04:00:30 2021-11-11 04:59:58       125      .0   12% | 2021-11-11 07:00:00 latch free 1611087616        517          0 2021-11-11 07:00:09 2021-11-11 07:59:42       119      .0   11% | 2021-11-11 02:00:00 latch free 1611087616        517          0 2021-11-11 02:00:45 2021-11-11 02:59:36       118      .0   11% | 2021-11-11 08:00:00 latch free 1611087616        517          0 2021-11-11 08:00:11 2021-11-11 08:51:18       104      .0   10% | 2021-11-11 03:00:00 latch free 1611087616        517          0 2021-11-11 03:00:21 2021-11-11 03:59:58        99      .0    9% | 2021-11-11 01:00:00 latch free 1611087616        517          0 2021-11-11 01:02:02 2021-11-11 01:59:59        95      .0    9% | 2021-11-11 00:00:00 latch free 1611087616        517          0 2021-11-11 00:00:01 2021-11-11 00:59:40 SYS@XXXXX1/ORCLX> @ wcy sysdate-1/24 sysdate "event='latch free'" -- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com ) %This     SECONDS     AAS #Blkrs WAIT_CHAIN                                                                                       FIRST_SEEN          LAST_SEEN ------ ---------- ------- ------ ------------------------------------------------------------------------------------------------ ------------------- -------------------   10%          14      .0      1 -> 53,14066,@2=>636,42912,@2=>latch free -> ,,@=>53,14066,@2=>                                   2021-11-11 07:54:57 2021-11-11 08:46:32    9%          12      .0      1 -> 53,14066,@2=>359,48271,@2=>latch free -> ,,@=>53,14066,@2=>                                   2021-11-11 08:09:14 2021-11-11 08:51:18    8%          11      .0      1 -> 53,14066,@2=>346,23425,@2=>latch free -> ,,@=>53,14066,@2=>                                   2021-11-11 07:53:20 2021-11-11 08:38:37    6%           9      .0      1 -> 3029,60358,@1=>643,2565,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]    2021-11-11 07:53:04 2021-11-11 08:47:46    6%           9      .0      1 -> 53,14066,@2=>335,60360,@2=>latch free -> ,,@=>53,14066,@2=>                                   2021-11-11 07:56:30 2021-11-11 08:49:44    6%           8      .0      1 -> 53,14066,@2=>1218,18526,@2=>latch free -> ,,@=>53,14066,@2=>                                  2021-11-11 08:00:30 2021-11-11 08:50:32    6%           8      .0      1 -> 3029,60358,@1=>633,10877,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]   2021-11-11 07:53:52 2021-11-11 08:46:58    6%           8      .0      1 -> 3029,60358,@1=>340,31327,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]   2021-11-11 07:54:38 2021-11-11 08:49:22    5%           7      .0      1 -> 3029,60358,@1=>334,5066,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]    2021-11-11 08:13:44 2021-11-11 08:44:37    5%           7      .0      1 -> 53,14066,@2=>619,27188,@2=>latch free -> ,,@=>53,14066,@2=>                                   2021-11-11 07:59:42 2021-11-11 08:48:56    5%           7      .0      1 -> 3029,60358,@1=>611,55630,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]   2021-11-11 07:55:26 2021-11-11 08:51:41    4%           6      .0      1 -> 3029,60358,@1=>640,11174,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]   2021-11-11 08:03:24 2021-11-11 08:35:50    4%           5      .0      1 -> 3029,60358,@1=>629,25751,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]   2021-11-11 08:09:43 2021-11-11 08:50:53    4%           5      .0      1 -> 53,14066,@2=>1248,24780,@2=>latch free -> ,,@=>53,14066,@2=>                                  2021-11-11 08:05:16 2021-11-11 08:48:56    3%           4      .0      1 -> 53,14066,@2=>1235,27336,@2=>latch free -> ,,@=>53,14066,@2=>                                  2021-11-11 08:05:16 2021-11-11 08:42:34    2%           3      .0      1 -> 3029,60358,@1=>934,43845,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]   2021-11-11 07:56:14 2021-11-11 08:38:15    2%           3      .0      1 -> 3029,60358,@1=>920,25477,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]   2021-11-11 07:56:14 2021-11-11 08:36:38    2%           3      .0      1 -> 3029,60358,@1=>945,8745,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]    2021-11-11 07:54:38 2021-11-11 08:35:50    1%           1      .0      1 -> ,,@=>1218,18526,@2=>latch free                                                                2021-11-11 08:07:38 2021-11-11 08:07:38    1%           1      .0      1 -> 3029,60358,@1=>2744,30318,@1=>latch free -> ,,@=>3029,60358,@1=>                              2021-11-11 08:22:27 2021-11-11 08:22:27    1%           1      .0      1 -> 3029,60358,@1=>31,26804,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]    2021-11-11 08:39:48 2021-11-11 08:39:48    1%           1      .0      1 -> 53,14066,@2=>3671,18541,@2=>latch free -> [idle blocker 2,53,14066 (oracle@oda2 (SMCO))]      2021-11-11 08:27:29 2021-11-11 08:27:29    1%           1      .0      1 -> 3029,60358,@1=>1539,44405,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]  2021-11-11 08:37:26 2021-11-11 08:37:26    1%           1      .0      1 -> 53,14066,@2=>1850,20064,@2=>latch free -> ,,@=>53,14066,@2=>                                  2021-11-11 08:33:03 2021-11-11 08:33:03    1%           1      .0      1 -> 53,14066,@2=>66,51514,@2=>latch free -> ,,@=>53,14066,@2=>                                    2021-11-11 08:15:36 2021-11-11 08:15:36    1%           1      .0      1 -> 53,14066,@2=>953,27220,@2=>latch free -> ,,@=>53,14066,@2=>                                   2021-11-11 08:50:32 2021-11-11 08:50:32    1%           1      .0      1 -> 934,43845,@1=>611,55630,@1=>latch free -> [idle blocker 1,934,43845 (oracle@oda1 (W00R))]     2021-11-11 08:42:12 2021-11-11 08:42:12    1%           1      .0      1 -> 53,14066,@2=>335,60360,@2=>latch free -> [idle blocker 2,53,14066 (oracle@oda2 (SMCO))]       2021-11-11 08:52:06 2021-11-11 08:52:06 28 rows selected. --//实例1上执行: SYS@XXXXX1/ORCLX> @ bgx SMCO PROGRAM                    MODULE       ACTION             SID     PID SPID -------------------------- ------------ ---------------- ----- ------- ------ oracle@oda1 (SMCO)         KTSJ         KTSJ Coordinator  3029     450 89595 --//实例2上执行: SYS@XXXXX2/ORCLX> @ bgx SMCO PROGRAM                    MODULE       ACTION            SID     PID SPID -------------------------- ------------ ---------------- ---- ------- ------ oracle@oda2 (SMCO)         KTSJ         KTSJ Coordinator   53     740 85315 --//如果你查询阻塞的sid可以发现都是W00开头的后台进程。 --//实例1上执行: SYS@XXXXX1/ORCLX> @ bgx W00 PROGRAM            MODULE       ACTION            SID     PID SPID ------------------ ------------ ---------- ---------- ------- ------ oracle@oda1 (W000) KTSJ         KTSJ Slave       1822     486 89598 oracle@oda1 (W001) KTSJ         KTSJ Slave       1824     586 89602 oracle@oda1 (W002) KTSJ         KTSJ Slave       5454     738 34395 oracle@oda1 (W003) KTSJ         KTSJ Slave       2430     468 89816 oracle@oda1 (W004) KTSJ         KTSJ Slave       5151     677 89842 oracle@oda1 (W005) KTSJ         KTSJ Slave       4566     175 44224 oracle@oda1 (W006) KTSJ         KTSJ Slave       3348     191 66397 oracle@oda1 (W007) KTSJ         KTSJ Slave       3332      91 66407 oracle@oda1 (W008) KTSJ         KTSJ Slave       2742     209 66423 oracle@oda1 (W009) KTSJ         KTSJ Slave        945     203 66439 oracle@oda1 (W00A) KTSJ         KTSJ Slave       5455     258 66454 oracle@oda1 (W00B) KTSJ         KTSJ Slave       5769     219 66470 oracle@oda1 (W00C) KTSJ         KTSJ Slave       2758     349 66588 oracle@oda1 (W00D) KTSJ         KTSJ Slave        643     322 66683 oracle@oda1 (W00E) KTSJ         KTSJ Slave       5154     357 66839 oracle@oda1 (W00F) KTSJ         KTSJ Slave       4546     355 66869 oracle@oda1 (W00G) KTSJ         KTSJ Slave        611     362 66921 oracle@oda1 (W00H) KTSJ         KTSJ Slave        633     182 66933 oracle@oda1 (W00I) KTSJ         KTSJ Slave        334     381 66951 oracle@oda1 (W00J) KTSJ         KTSJ Slave         31     360 67055 oracle@oda1 (W00K) KTSJ         KTSJ Slave       1521     385 67069 oracle@oda1 (W00L) KTSJ         KTSJ Slave        629     382 67144 oracle@oda1 (W00M) KTSJ         KTSJ Slave       1844     386 67168 oracle@oda1 (W00N) KTSJ         KTSJ Slave       4260     394 67282 oracle@oda1 (W00O) KTSJ         KTSJ Slave       5155     397 67334 oracle@oda1 (W00P) KTSJ         KTSJ Slave       1834     206 67439 oracle@oda1 (W00Q) KTSJ         KTSJ Slave        640     402 67456 oracle@oda1 (W00R) KTSJ         KTSJ Slave        934     403 67466 oracle@oda1 (W00S) KTSJ         KTSJ Slave       1232     404 67483 oracle@oda1 (W00T) KTSJ         KTSJ Slave       1539     405 67498 oracle@oda1 (W00U) KTSJ         KTSJ Slave       2132     407 67515 oracle@oda1 (W00V) KTSJ         KTSJ Slave       2453     408 67538 oracle@oda1 (W00W) KTSJ         KTSJ Slave       3050     410 67648 oracle@oda1 (W00X) KTSJ         KTSJ Slave       5444     418 67766 oracle@oda1 (W00Y) KTSJ         KTSJ Slave         24     420 67858 oracle@oda1 (W00Z) KTSJ         KTSJ Slave        340     421 67906 36 rows selected. SYS@XXXXX1/ORCLX> @ wcy sysdate-1/24 sysdate "event='latch free' and inst_id=1" -- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com ) %This     SECONDS        AAS #Blkrs WAIT_CHAIN                                                                                      FIRST_SEEN          LAST_SEEN ------ ---------- ---------- ------ ----------------------------------------------------------------------------------------------- ------------------- -------------------   15%          12          0      1 -> 3029,60358,@1=>643,2565,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]   2021-11-11 08:25:37 2021-11-11 09:13:56     11%           9          0      1 -> 3029,60358,@1=>633,10877,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]  2021-11-11 08:35:02 2021-11-11 09:11:32   10%           8          0      1 -> 3029,60358,@1=>340,31327,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]  2021-11-11 08:47:46 2021-11-11 09:19:33    9%           7          0      1 -> 3029,60358,@1=>334,5066,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]   2021-11-11 08:26:25 2021-11-11 08:52:29    9%           7          0      1 -> 3029,60358,@1=>629,25751,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]  2021-11-11 08:24:48 2021-11-11 09:08:22    9%           7          0      1 -> 3029,60358,@1=>640,11174,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]  2021-11-11 08:21:39 2021-11-11 09:12:20    6%           5          0      1 -> 3029,60358,@1=>920,25477,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]  2021-11-11 08:36:38 2021-11-11 09:10:44    6%           5          0      1 -> 3029,60358,@1=>934,43845,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]  2021-11-11 08:38:15 2021-11-11 09:14:44    5%           4          0      1 -> 3029,60358,@1=>611,55630,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]  2021-11-11 08:27:13 2021-11-11 09:01:12    4%           3          0      1 -> 3029,60358,@1=>945,8745,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]   2021-11-11 08:35:50 2021-11-11 09:12:20    4%           3          0      1 -> 3029,60358,@1=>31,26804,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]   2021-11-11 08:39:48 2021-11-11 09:10:44    4%           3          0      1 -> 3029,60358,@1=>1521,39029,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 08:56:26 2021-11-11 09:04:25    1%           1          0      1 -> 3029,60358,@1=>2744,30318,@1=>latch free -> ,,@=>3029,60358,@1=>                             2021-11-11 08:22:27 2021-11-11 08:22:27    1%           1          0      1 -> 3029,60358,@1=>1818,64479,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 08:58:51 2021-11-11 08:58:51    1%           1          0      1 -> 3029,60358,@1=>1539,44405,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 08:37:26 2021-11-11 08:37:26    1%           1          0      1 -> 3029,60358,@1=>24,6540,@1=>latch free -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))]    2021-11-11 09:11:32 2021-11-11 09:11:32    1%           1          0      1 -> 2453,5139,@1=>1824,53545,@1=>latch free -> [idle blocker 1,2453,5139 (oracle@oda1 (W00V))]   2021-11-11 08:58:03 2021-11-11 08:58:03    1%           1          0      1 -> 934,43845,@1=>611,55630,@1=>latch free -> [idle blocker 1,934,43845 (oracle@oda1 (W00R))]    2021-11-11 08:42:12 2021-11-11 08:42:12    1%           1          0      1 -> ,,@=>1824,53545,@1=>latch free                                                               2021-11-11 08:57:15 2021-11-11 08:57:15 19 rows selected. --//顺便选取其中几个sid看看。 SYS@XXXXX1/ORCLX> @ sid 643,633,340,334,629,640,920,934,611,945 sid = 643,633,340,334,629,640,920,934,611,945 SPID       PID        SID    SERIAL# CLIENT_INFO          PNAME  TRACEFILE                                                           PROGRAM            TERMINAL     SQL_ID        STATUS   C50 ------ ------- ---------- ---------- -------------------- ------ ------------------------------------------------------------------- ------------------ ------------ ------------- -------- -------------------------------------------------- 66933      182        633      10877                      W00H   /u01/app/oracle/diag/rdbms/ORCLX/ORCLX1/trace/ORCLX1_w00h_66933.trc oracle@oda1 (W00H) UNKNOWN                    ACTIVE   alter system kill session '633,10877' immediate; 66439      203        945       8745                      W009   /u01/app/oracle/diag/rdbms/ORCLX/ORCLX1/trace/ORCLX1_w009_66439.trc oracle@oda1 (W009) UNKNOWN                    ACTIVE   alter system kill session '945,8745' immediate; 66683      322        643       2565                      W00D   /u01/app/oracle/diag/rdbms/ORCLX/ORCLX1/trace/ORCLX1_w00d_66683.trc oracle@oda1 (W00D) UNKNOWN                    ACTIVE   alter system kill session '643,2565' immediate; 66921      362        611      55630                      W00G   /u01/app/oracle/diag/rdbms/ORCLX/ORCLX1/trace/ORCLX1_w00g_66921.trc oracle@oda1 (W00G) UNKNOWN                    ACTIVE   alter system kill session '611,55630' immediate; 66951      381        334       5066                      W00I   /u01/app/oracle/diag/rdbms/ORCLX/ORCLX1/trace/ORCLX1_w00i_66951.trc oracle@oda1 (W00I) UNKNOWN                    ACTIVE   alter system kill session '334,5066' immediate; 67144      382        629      25751                      W00L   /u01/app/oracle/diag/rdbms/ORCLX/ORCLX1/trace/ORCLX1_w00l_67144.trc oracle@oda1 (W00L) UNKNOWN                    ACTIVE   alter system kill session '629,25751' immediate; 67456      402        640      11174                      W00Q   /u01/app/oracle/diag/rdbms/ORCLX/ORCLX1/trace/ORCLX1_w00q_67456.trc oracle@oda1 (W00Q) UNKNOWN                    ACTIVE   alter system kill session '640,11174' immediate; 67466      403        934      43845                      W00R   /u01/app/oracle/diag/rdbms/ORCLX/ORCLX1/trace/ORCLX1_w00r_67466.trc oracle@oda1 (W00R) UNKNOWN                    ACTIVE   alter system kill session '934,43845' immediate; 67906      421        340      31327                      W00Z   /u01/app/oracle/diag/rdbms/ORCLX/ORCLX1/trace/ORCLX1_w00z_67906.trc oracle@oda1 (W00Z) UNKNOWN                    ACTIVE   alter system kill session '340,31327' immediate; 67939      423        920      25477                      W010   /u01/app/oracle/diag/rdbms/ORCLX/ORCLX1/trace/ORCLX1_w010_67939.trc oracle@oda1 (W010) UNKNOWN                    ACTIVE   alter system kill session '920,25477' immediate; 10 rows selected. --//可以发现oracle后台进程在相互阻塞,我估计某种条件下激活oracle的bug导致这样的情况。 --//换一个查询方式也可以验证我的判断。 SYS@XXXXX1/ORCLX> @ tpt/ash/ash_wait_chains username||':'||program2||event2 "event='latch free'" trunc(sysdate) sysdate -- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com ) %This     SECONDS        AAS #Blkrs WAIT_CHAIN                                                                    FIRST_SEEN          LAST_SEEN ------ ---------- ---------- ------ ----------------------------------------------------------------------------- ------------------- -------------------   26%         311          0     10 -> SYS:(Wnnn) latch free  -> [idle blocker 2,53,14066 (oracle@oda2 (SMCO))]   2021-11-11 00:00:01 2021-11-11 09:32:30    7%          83          0      1 -> SYS:(WnnU) latch free  -> [idle blocker 2,53,14066 (oracle@oda2 (SMCO))]   2021-11-11 00:00:50 2021-11-11 09:34:06    7%          79          0      4 -> SYS:(Wnnn) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 00:01:46 2021-11-11 09:32:14    6%          72          0      1 -> SYS:(WnnG) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 00:06:32 2021-11-11 09:29:53    6%          66          0      1 -> SYS:(WnnI) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 00:03:22 2021-11-11 09:22:43    5%          63          0      1 -> SYS:(WnnZ) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 00:12:48 2021-11-11 09:33:51    5%          63          0      1 -> SYS:(WnnV) latch free  -> [idle blocker 2,53,14066 (oracle@oda2 (SMCO))]   2021-11-11 00:27:48 2021-11-11 09:26:56    5%          60          0      1 -> SYS:(WnnD) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 00:26:17 2021-11-11 09:13:56    4%          53          0      1 -> SYS:(WnnL) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 00:07:20 2021-11-11 09:27:28    4%          53          0      1 -> SYS:(WnnQ) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 00:05:47 2021-11-11 09:31:26    4%          50          0      1 -> SYS:(WnnH) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 00:21:31 2021-11-11 09:21:55    3%          35          0      1 -> SYS:(WnnO) latch free  -> [idle blocker 2,53,14066 (oracle@oda2 (SMCO))]   2021-11-11 00:55:43 2021-11-11 09:22:10    3%          33          0      1 -> SYS:(WnnR) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 00:22:19 2021-11-11 09:24:19    3%          30          0      1 -> SYS:(WnnM) latch free  -> [idle blocker 2,53,14066 (oracle@oda2 (SMCO))]   2021-11-11 03:28:14 2021-11-11 09:12:39    1%          13          0      8 -> SYS:(Wnnn) latch free                                                      2021-11-11 02:06:19 2021-11-11 08:57:15    1%          12          0      1 -> SYS:(WnnS) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 00:10:33 2021-11-11 07:25:15    1%          10          0      1 -> SYS:(WnnJ) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 00:02:34 2021-11-11 09:10:44    1%          10          0      1 -> SYS:(Wnnn) latch free  -> SYS:(SMCO) ON CPU                                2021-11-11 06:22:32 2021-11-11 08:22:27    1%           6          0      1 -> SYS:(WnnM) latch free                                                      2021-11-11 01:04:27 2021-11-11 09:19:01    0%           5          0      1 -> SYS:(WnnT) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 01:19:32 2021-11-11 08:37:26    0%           5          0      1 -> SYS:(WnnK) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 01:08:24 2021-11-11 09:04:25    0%           5          0      1 -> SYS:(WnnC) latch free  -> [idle blocker 2,53,14066 (oracle@oda2 (SMCO))]   2021-11-11 04:44:29 2021-11-11 06:29:58    0%           5          0      1 -> SYS:(WnnY) latch free  -> [idle blocker 1,3029,60358 (oracle@oda1 (SMCO))] 2021-11-11 00:14:24 2021-11-11 09:11:32    0%           4          0      1 -> SYS:(WnnO) latch free                                                      2021-11-11 01:20:20 2021-11-11 09:33:18    0%           4          0      1 -> SYS:(WnnD) latch free                                                      2021-11-11 03:24:58 2021-11-11 03:54:08    0%           4          0      1 -> SYS:(WnnN) latch free  -> [idle blocker 2,53,14066 (oracle@oda2 (SMCO))]   2021-11-11 04:58:46 2021-11-11 08:33:03    0%           3          0      1 -> SYS:(WnnH) latch free  -> [idle blocker 2,53,14066 (oracle@oda2 (SMCO))]   2021-11-11 01:08:24 2021-11-11 08:27:29    0%           3          0      1 -> SYS:(WnnH) latch free                                                      2021-11-11 00:19:10 2021-11-11 03:29:43    0%           3          0      1 -> SYS:(WnnS) latch free                                                      2021-11-11 00:00:13 2021-11-11 07:29:13    0%           2          0      1 -> SYS:(WnnQ) latch free                                                      2021-11-11 02:50:49 2021-11-11 03:13:50 --//可以发现oracle后台进程在相互阻塞,我估计某种条件下激活oracle的bug导致这样的情况。 --//我个人认为可能与我们应用磁盘空间需求很大存在某种联系。 --//随便看一个awr报表,Segments by DB Blocks Changes靠前都是如下: Segments by DB Blocks Changes     % of Capture shows % of DB Block Changes for each top segment compared     with total DB Block Changes for all segments captured by the Snapshot     When ** MISSING ** occurs, some of the object attributes may not be available Owner       Tablespace Name  Object Name             Subobject Name  Obj. Type  Obj#    Dataobj#  DB Block Changes  % of Capture SYS         SYSAUX           EXP_STAT$                               TABLE      726     726       33,248            23.72 pppppp_HIS  pppppp_HIS       CA_SIGN                                 TABLE      104049  112819    18,608            13.28 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ SYS         SYSTEM           USER$                                   TABLE      22      10        6,576             4.69 SYS@XXXXX1/ORCLX> @@ desc pppppp_his.CA_SIGN            Name                            Null?    Type            ------------------------------- -------- ----------------------------     1      JLXH                            NOT NULL NUMBER(18)     2      TABLENAME                                VARCHAR2(30)     3      TABLEKEYNAME                             VARCHAR2(30)     4      TABLEKEYVALUE                            VARCHAR2(20)     5      STYPE                                    NUMBER(1)     6      CZGH                                     VARCHAR2(10)     7      CZSJ                                     DATE     8      IFTSA                                    NUMBER(1)     9      CERTID                                   VARCHAR2(100)    10      BASE64CERTID                             VARCHAR2(2000)    11      CERTSN                                   VARCHAR2(50)    12      CERTENTITY                               VARCHAR2(50)    13      TSINFO_TIME                              VARCHAR2(30)    14      PLAINTEXT                                BLOB ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~    15      SIGNDATA                                 BLOB    16      TSRESPDATA                               BLOB    17      TSREQDATA                                BLOB --//后面有4个blob字段。 SYS@XXXXX1/ORCLX> select * from V$SEGMENT_STATISTICS where statistic_name='space allocated' order by value desc fetch first 3 rows only; OWNER      OBJECT_NAME                SUBOBJECT_ TABLESPACE_NAME  TS#   OBJ#   DATAOBJ# OBJECT_TYPE        STATISTIC_NAME  STATISTIC#      VALUE CON_ID ---------- -------------------------- ---------- --------------- ---- ------ ---------- ------------------ --------------- ---------- ---------- ------ pppppp_HIS CA_SIGN                               pppppp_HIS         7 104049     112819 TABLE              space allocated         20  335544320      0 pppppp_HIS SYS_LOB0000104049C00014$$             pppppp_HIS         7 104050     112818 LOB                space allocated         20  201326592      0 pppppp_EMR SYS_LOB0000109695C00002$$             pppppp_EMR         8 109696     125167 LOB                space allocated         20   67108864      0 --//可以看出前面2个段space allocated增加很大。SYS_LOB0000104049C00014$$ 说明是表CA_SIGN 的PLAINTEXT blog段。 SYS@XXXXX1/ORCLX> @ sosiz pppppp_his CA_SIGN ********************************** Table Level  参数 schema tablename ********************************** Table                   Number                     Empty  Average    Chain  Average Global User           Sample Name                   of Rows       Blocks       Blocks    Space    Count  Row Len Stats  Stats            Size LAST_ANALYZED --------------- -------------- ------------ ------------ -------- -------- -------- ------ ------ -------------- ------------------- CA_SIGN              2,021,065      908,590           39        0        0    2,929 YES    NO          2,021,065 2021-11-09 22:02:25 ..... --//11月9号才刚刚分析,也就是V$SEGMENT_STATISTICS记录是昨天晚上10点之后的值,单位字节,335544320/1024/1024 = 320M.好像是。 --// 201326592/1024/1024 = 192M.这种情况导致大小是按照前面定义next=20M还是64M,我不是很清楚。总之在这样的情况激活了某种bug。 --//无法重启验证我的判断,先暂时设置"_enable_spacebg"=false。 SYS@XXXXX1/ORCLX> alter system set "_enable_spacebg"=false scope=memory; System altered. --//总之遇到一些细节问题,要仔细探究,不要轻言放弃。

相关推荐