[20211229]再论19c latch free等待事件分析.txt

来源：这里教程网时间：2026-03-03 17:22:33 作者：

[20211229]再论19c latch free等待事件分析.txt --//生产系统昨天例行检查，发现19c再次出现latch free等待事件，再次分析看看。 --//以前的链接http://blog.itpub.net/267265/viewspace-2841664/ =>[20211111]19c latch free等待时间分析.txt 1.环境： xxxx1> @pr ============================== 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.检查： xxxx1> @ashtop event 1=1 &day Total Distinct Distinct Seconds AAS %This EVENT FIRST_SEEN LAST_SEEN Execs Seen Tstamps --------- ------- ------- ------------------------------------------ ------------------- ------------------- ---------- -------- 102094 1.2 80% | 2021-12-28 08:28:15 2021-12-29 08:28:14 62649 74687 14120 .2 11% | Failed Logon Delay 2021-12-28 08:28:16 2021-12-29 08:28:13 1 14087 3535 .0 3% | control file sequential read 2021-12-28 08:28:15 2021-12-29 08:27:36 89 3513 3232 .0 3% | latch free 2021-12-28 08:29:05 2021-12-29 08:27:56 50 2213 831 .0 1% | SQL*Net more data to client 2021-12-28 08:30:32 2021-12-29 08:26:48 45 826 628 .0 0% | log file parallel write 2021-12-28 08:28:50 2021-12-29 08:25:08 1 609 --//Failed Logon Delay 依旧没有解决，无语。 --//我上次临时关闭这个特性，估计服务器数据库发生了重启，检查。 SYS@XXXXX1/ORCLX> alter system set "_enable_spacebg"=false scope=memory; System altered. xxxx1> select INSTANCE_NUMBER,STARTUP_TIME,DATABASE_ROLE from DBA_HIST_DATABASE_INSTANCE where STARTUP_TIME>=sysdate-20; INSTANCE_NUMBER STARTUP_TIME DATABASE_ROLE --------------- ----------------------- ---------------- 1 2021-12-12 16:45:14.000 PRIMARY 2 2021-12-12 16:47:47.000 PRIMARY --//可以发现确实重启过服务器数据库，难道这个问题是bug吗？一天出现latch free 等待事件占3232秒，平均到每小时并不多。 3.分析探究： xxxx1> @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 --//P1对于地址。 xxxx1> @ashtop lower(module),sql_id,p1 "event='latch free'" &day Total Distinct Distinct Seconds AAS %This LOWER(MODULE) SQL_ID P1 FIRST_SEEN LAST_SEEN Execs Seen Tstamps --------- ------- ------- ------------- ------------- ---------- ------------------- ------------------- ---------- -------- 3091 .0 95% | ktsj 1611087616 2021-12-28 08:38:07 2021-12-29 08:36:27 1 2149 145 .0 4% | ktsj f3yfg50ga0r8n 1611087616 2021-12-28 08:44:26 2021-12-29 08:34:50 50 142 2 .0 0% | 1611000448 2021-12-28 23:57:01 2021-12-29 00:46:00 1 2 --//即使是sql语句，也是module=ktsj产生的。 xxxx1> @ wcy &5min "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 ------ ---------- ------- ------ ------------------------------------------------------------------------------------------------ ------------------- ------------------- 20% 2 .0 1 -> 5741,15124,@1=>619,42003,@1=>latch free -> [idle blocker 1,5741,15124 (oracle@oda1 (SMCO))] 2021-12-29 08:34:15 2021-12-29 08:35:51 10% 1 .0 1 -> 5741,15124,@1=>1220,34429,@1=>latch free -> [idle blocker 1,5741,15124 (oracle@oda1 (SMCO))] 2021-12-29 08:38:15 2021-12-29 08:38:15 10% 1 .0 1 -> 5741,15124,@1=>617,46080,@1=>latch free -> [idle blocker 1,5741,15124 (oracle@oda1 (SMCO))] 2021-12-29 08:35:03 2021-12-29 08:35:03 10% 1 .0 1 -> 5741,50215,@2=>1215,13204,@2=>latch free -> [idle blocker 2,5741,50215 (oracle@oda2 (SMCO))] 2021-12-29 08:34:05 2021-12-29 08:34:05 10% 1 .0 1 -> 5741,50215,@2=>912,8474,@2=>latch free -> [idle blocker 2,5741,50215 (oracle@oda2 (SMCO))] 2021-12-29 08:34:50 2021-12-29 08:34:50 10% 1 .0 1 -> 5741,15124,@1=>909,65363,@1=>latch free -> [idle blocker 1,5741,15124 (oracle@oda1 (SMCO))] 2021-12-29 08:35:51 2021-12-29 08:35:51 10% 1 .0 1 -> 5741,15124,@1=>915,29003,@1=>latch free -> [idle blocker 1,5741,15124 (oracle@oda1 (SMCO))] 2021-12-29 08:38:15 2021-12-29 08:38:15 10% 1 .0 1 -> 5741,50215,@2=>909,22979,@2=>latch free -> [idle blocker 2,5741,50215 (oracle@oda2 (SMCO))] 2021-12-29 08:38:03 2021-12-29 08:38:03 10% 1 .0 1 -> 2122,26873,@2=>1215,13204,@2=>latch free -> [idle blocker 2,2122,26873 (oracle@oda2 (W005))] 2021-12-29 08:36:27 2021-12-29 08:36:27 9 rows selected. xxxx1> @bgx w00 PROGRAM MODULE ACTION SID PID SPID ------------------ ------ ----------- ----- ------- ------ oracle@oda1 (W000) KTSJ KTSJ Slave 304 41 22889 oracle@oda1 (W001) KTSJ KTSJ Slave 909 43 22911 oracle@oda1 (W002) KTSJ KTSJ Slave 611 102 46259 oracle@oda1 (W003) KTSJ KTSJ Slave 2121 107 33388 oracle@oda1 (W004) KTSJ KTSJ Slave 2768 189 80228 oracle@oda1 (W005) KTSJ KTSJ Slave 617 222 83251 oracle@oda1 (W006) KTSJ KTSJ Slave 312 221 83363 oracle@oda1 (W007) KTSJ KTSJ Slave 915 223 83429 oracle@oda1 (W008) KTSJ KTSJ Slave 1220 224 83445 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ oracle@oda1 (W009) KTSJ KTSJ Slave 1518 225 83620 oracle@oda1 (W00A) KTSJ KTSJ Slave 1533 425 10988 oracle@oda1 (W00B) KTSJ KTSJ Slave 2127 347 90810 oracle@oda1 (W00C) KTSJ KTSJ Slave 5164 417 91732 oracle@oda1 (W00D) KTSJ KTSJ Slave 2728 229 83938 oracle@oda1 (W00E) KTSJ KTSJ Slave 3029 230 83974 oracle@oda1 (W00F) KTSJ KTSJ Slave 3332 231 97689 oracle@oda1 (W00G) KTSJ KTSJ Slave 3632 232 84006 oracle@oda1 (W00H) KTSJ KTSJ Slave 4236 234 84059 oracle@oda1 (W00I) KTSJ KTSJ Slave 4843 236 31224 oracle@oda1 (W00J) KTSJ KTSJ Slave 2782 429 20932 oracle@oda1 (W00K) KTSJ KTSJ Slave 5144 237 84249 oracle@oda1 (W00L) KTSJ KTSJ Slave 5446 238 84271 oracle@oda1 (W00M) KTSJ KTSJ Slave 10 240 84285 oracle@oda1 (W00N) KTSJ KTSJ Slave 47 360 58385 oracle@oda1 (W00O) KTSJ KTSJ Slave 619 242 84429 oracle@oda1 (W00P) KTSJ KTSJ Slave 917 243 84449 oracle@oda1 (W00Q) KTSJ KTSJ Slave 41 320 64141 oracle@oda1 (W00R) KTSJ KTSJ Slave 4235 194 84620 oracle@oda1 (W00S) KTSJ KTSJ Slave 3075 1090 48190 oracle@oda1 (W00T) KTSJ KTSJ Slave 1825 246 84802 oracle@oda1 (W00U) KTSJ KTSJ Slave 2128 247 84831 oracle@oda1 (W00V) KTSJ KTSJ Slave 3031 250 84867 oracle@oda1 (W00W) KTSJ KTSJ Slave 2730 249 84978 oracle@oda1 (W00X) KTSJ KTSJ Slave 3635 252 85147 oracle@oda1 (W00Y) KTSJ KTSJ Slave 3039 350 4827 oracle@oda1 (W00Z) KTSJ KTSJ Slave 5448 258 85211 36 rows selected. --//我运行在实例1，仔细看sid=619,1220,617,909,915,都是这些W00X的后台进程。我估计遇到了bug。 --//是否是应该这些后台进程启动太多了，我看了exadata 11g仅仅启动1个。 exadate> @bgx w00 PROGRAM MODULE ACTION SID PID SPID ---------------------------------- ------------ ----------- ----- ------- ------ oracle@dm01dbadm01(W000) KTSJ KTSJ Slave 5505 343 23775 xxxx1> @pv 36 Show parameter which have value 36 no rows selected --//依旧无法解决，先临时关闭它： xxxx1> alter system set "_enable_spacebg"=false scope=both; System altered. xxxx1> host sleep 60 xxxx1> @ wcy &1min "event='latch free'" -- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com ) no rows selected xxxx1> @bgx w00 no rows selected xxxx1> @bgx smco no rows selected 4.附上wcy.sql,bgx.sql脚本： xxxx1> define 5min DEFINE 5MIN = "sysdate-5/1440 sysdate" (CHAR) $ cat wcy.sql @ tpt/ash/ash_wait_chains BLOCKING_SESSION||','||BLOCKING_SESSION_SERIAL#||',@'||BLOCKING_INST_ID||'=>'||session_id||','||SESSION_SERIAL#||',@'||inst_id||'=>'||event "&&3" &&1 &&2 $ cat bgx.sql select s.program, s.module, s.action, s.sid, p.pid, p.spid from v$session s, v$process p where s.paddr=p.addr and S.PROGRAM like upper('%&1%') and p.background=1 order by s.program;