首页 / MYSQL / 运行SQLT出现Latch:cacheBufferChains的一种解决办法

运行SQLT出现Latch:cacheBufferChains的一种解决办法

内容导读

互联网集市收集整理的这篇技术教程文章主要介绍了运行SQLT出现Latch:cacheBufferChains的一种解决办法，小编现在分享给大家，供广大互联网技能从业者学习和参考。文章包含13628字，纯文字阅读大概需要20分钟。

内容图文

这两天在一台10.2.0.4的数据库上面运行SQLT的报告，运行的很缓慢，大概等了1个小时还没出来，查看了一下执行SQLT会话的等待事件，显示latch:cache buffer chains。这里要说下，当SQLT运行的过程中，屏幕会有输出显示。如下所示： To actually diagnose the p

这两天在一台10.2.0.4的数据库上面运行SQLT的报告，运行的很缓慢，大概等了1个小时还没出来，查看了一下执行SQLT会话的等待事件，显示latch:cache buffer chains。这里要说下，当SQLT运行的过程中，屏幕会有输出显示。如下所示：

To actually diagnose the problem behind the disconnect, read ALERT
log and provide referenced traces to Support. After the root cause
of the disconnect is fixed then reset SQLT corresponding parameter.

To monitor progress, login into another session and execute:
SQL> SELECT * FROM SQLTXADMIN.sqlt$_log_v;

… collecting diagnostics details, please wait …

In case of a disconnect review log file in current directory
If running as SYS in 12c make sure to review sqlt_instructions.html first

当时我们就一直卡在这个界面，出不来。这里告诉我们如果要监控SQLT进程，可以查询SELECT * FROM SQLTXADMIN.sqlt$_log_v。我们登陆了另外一个会话，做了如下查询，显示下面的结果。

TIME     LINE
-------- ------------------------------------------------------------------------------------------------------------------------
14:31:19 sqlt$h: -> index_hc_PK_PD_SVC_DICT
14:31:19 sqlt$h: <- index_hc_PK_PD_SVC_DICT
14:31:19 sqlt$h: -> column_hc_PD_SVC_DICT_EFF_DATE
14:31:19 sqlt$h: <- column_hc_PD_SVC_DICT_EFF_DATE
14:31:19 sqlt$h: -> column_hc_PD_SVC_DICT_EXP_DATE
14:31:19 sqlt$h: <- column_hc_PD_SVC_DICT_EXP_DATE
14:31:19 sqlt$h: -> column_hc_PD_SVC_DICT_MASTER_SERV_ID
14:31:19 sqlt$h: <- column_hc_PD_SVC_DICT_MASTER_SERV_ID
14:31:19 sqlt$h: -> column_hc_PD_SVC_DICT_SVC_ID
14:31:19 sqlt$h: <- column_hc_PD_SVC_DICT_SVC_ID
14:31:19 sqlt$h: -> column_hc_PD_SVC_DICT_SVC_TYPE
14:31:19 sqlt$h: <- column_hc_PD_SVC_DICT_SVC_TYPE
14:31:19 sqlt$h: <= health_check
14:31:19 sqlt$m: => main_report
14:31:19 sqlt$m: -> flags
14:31:19 sqlt$m: <- flags
14:31:19 sqlt$m: observations_sec
14:31:19 sqlt$m: sql_text_sec
14:31:20 sqlt$m: sql_identification_sec
14:31:20 sqlt$m: environment_sec
14:31:20 sqlt$m: cbo_environment_sec
14:31:20 sqlt$m: cbo_environment_mod
14:31:20 sqlt$m: cbo_environment_unmod
14:31:20 sqlt$m: bug_fix_control_sec
14:31:20 sqlt$m: bug_fix_control_sec_0
14:31:20 sqlt$m: bug_fix_control_sec_1
14:31:20 sqlt$m: system_stats_sec
14:31:20 sqlt$m: dbms_stats_setup_sec
14:31:21 sqlt$m: init_parameters_sec
14:31:21 sqlt$m: init_parameters_sec_FALSE
14:31:22 sqlt$m: init_parameters_sec_TRUE
14:31:23 sqlt$m: init_parameters_sys_mod
14:31:23 sqlt$m: init_parameters_sys

可以看到我们在做sqlt$m: init_parameters_sys的时候卡住了。但是看到了这个信息，我们也不知道它的意思。于是，我们只能考虑做下10046。 

PARSING IN CURSOR #44 len=632 dep=1 uid=416 oct=3 lid=416 tim=35075498358274 hv=4132104666 ad='121339a8' 
SELECT S.END_INTERVAL_TIME, P.SNAP_ID, P.ISDEFAULT, P.ISMODIFIED, P.PARAMETER_NAME, P.INSTANCE_NUMBER, P.VALUE FROM SQLI$_DBA_HIST_PARAMETER P, SQLT$_DBA_HIS 
T_SNAPSHOT S, (SELECT /*+ NO_MERGE */ DISTINCT SNAP_ID, DBID FROM SQLT$_DBA_HIST_SQLSTAT WHERE STATEMENT_ID = :B1 ) ST WHERE P.STATEMENT_ID = :B1 AND P.STATE 
MENT_ID = S.STATEMENT_ID AND P.SNAP_ID = S.SNAP_ID AND P.DBID = S.DBID AND P.INSTANCE_NUMBER = S.INSTANCE_NUMBER AND (P.ISDEFAULT = 'FALSE' OR P.ISMODIFIED < 
> 'FALSE') AND P.SNAP_ID = ST.SNAP_ID AND P.DBID = ST.DBID ORDER BY S.END_INTERVAL_TIME DESC, P.ISDEFAULT, P.ISMODIFIED DESC, P.PARAMETER_NAME, P.INSTANCE_NU 
MBER 
END OF STMT 
PARSE #44:c=0,e=383,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=35075498358266 
EXEC #44:c=0,e=226,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=35075498358724 
*** 2014-05-08 14:31:45.742 
WAIT #44: nam='db file sequential read' ela= 1088 file#=2001 block#=581279 blocks=1 obj#=535668 tim=35075519750997 
WAIT #44: nam='db file sequential read' ela= 783 file#=2001 block#=586373 blocks=1 obj#=535670 tim=35075520009144 
WAIT #44: nam='db file sequential read' ela= 740 file#=2001 block#=579127 blocks=1 obj#=535670 tim=35075521390313 
WAIT #44: nam='db file sequential read' ela= 1135 file#=2001 block#=579635 blocks=1 obj#=535670 tim=35075522675155 
WAIT #44: nam='db file sequential read' ela= 1105 file#=2001 block#=581144 blocks=1 obj#=535670 tim=35075528124956 
WAIT #44: nam='db file sequential read' ela= 824 file#=2001 block#=577465 blocks=1 obj#=535668 tim=35075528795240 
WAIT #44: nam='db file sequential read' ela= 706 file#=2001 block#=580952 blocks=1 obj#=535668 tim=35075528935134 
*** 2014-05-08 14:31:58.642 
WAIT #44: nam='db file sequential read' ela= 850 file#=2001 block#=575871 blocks=1 obj#=535670 tim=35075532348467 
*** 2014-05-08 14:36:51.985 
WAIT #44: nam='latch: cache buffers chains' ela= 177 address=66109355216 number=122 tries=0 obj#=535670 tim=35075818825412 
*** 2014-05-08 14:41:07.053 
WAIT #44: nam='latch: cache buffers chains' ela= 119 address=66263337712 number=122 tries=0 obj#=535670 tim=35076067923552 
*** 2014-05-08 14:43:21.686 
WAIT #44: nam='latch: cache buffers chains' ela= 15 address=66046764704 number=122 tries=0 obj#=535670 tim=35076199404865 
*** 2014-05-08 15:04:11.215 
WAIT #44: nam='latch: cache buffers chains' ela= 43 address=66336324888 number=122 tries=0 obj#=535670 tim=35077419687444 
*** 2014-05-08 15:06:45.573 
WAIT #44: nam='latch: cache buffers chains' ela= 63 address=65975608120 number=122 tries=0 obj#=535670 tim=35077570432584 
*** 2014-05-08 15:09:39.477 
WAIT #44: nam='latch: cache buffers chains' ela= 223 address=66292257024 number=122 tries=0 obj#=535670 tim=35077740265783 
*** 2014-05-08 15:12:25.390 
WAIT #44: nam='latch: cache buffers chains' ela= 253 address=66066629152 number=122 tries=0 obj#=535670 tim=35077902295960 
*** 2014-05-08 15:24:24.368 
Received ORADEBUG command 'event 10046 trace name context forever,level 12' from process Unix process pid: 6764, image: 
*** 2014-05-08 15:24:42.767 
Received ORADEBUG command 'event 10046 trace name context off' from process Unix process pid: 6764, image: 
Received ORADEBUG command 'tracefile_name' from process Unix process pid: 6764, image:

可以看到10046的等待主要是集中在latch: cache buffers chains上的。看了下运行SQL的执行计划。

PLAN_TABLE_OUTPUT 
------------------------------------------------------------------------------------------------------------------------------------------------------ 
SQL_ID  f2u123bv4pufu, child number 0 
------------------------------------- 
SELECT S.END_INTERVAL_TIME, P.SNAP_ID, P.ISDEFAULT, P.ISMODIFIED, P.PARAMETER_NAME, P.INSTANCE_NUMBER, 
P.VALUE FROM SQLI$_DBA_HIST_PARAMETER P, SQLT$_DBA_HIST_SNAPSHOT S, (SELECT /*+ NO_MERGE */ DISTINCT 
SNAP_ID, DBID FROM SQLT$_DBA_HIST_SQLSTAT WHERE STATEMENT_ID = :B1 ) ST WHERE P.STATEMENT_ID = :B1 AND 
P.STATEMENT_ID = S.STATEMENT_ID AND P.SNAP_ID = S.SNAP_ID AND P.DBID = S.DBID AND P.INSTANCE_NUMBER = 
S.INSTANCE_NUMBER AND (P.ISDEFAULT = 'FALSE' OR P.ISMODIFIED <> 'FALSE') AND P.SNAP_ID = ST.SNAP_ID AND 
P.DBID = ST.DBID ORDER BY S.END_INTERVAL_TIME DESC, P.ISDEFAULT, P.ISMODIFIED DESC, P.PARAMETER_NAME, 
P.INSTANCE_NUMBER 
Plan hash value: 1007730285 
---------------------------------------------------------------------------------------------------------------- 
| Id  | Operation                        | Name                        | Rows  | Bytes | Cost (%CPU)| Time     | 
---------------------------------------------------------------------------------------------------------------- 
|   0 | SELECT STATEMENT                 |                             |       |       |    64 (100)|          | 
|   1 |  SORT ORDER BY                   |                             |    81 | 60426 |    64   (5)| 00:00:01 | 
|*  2 |   HASH JOIN                      |                             |    81 | 60426 |    63   (4)| 00:00:01 | 
|*  3 |    TABLE ACCESS FULL             | SQLT$_DBA_HIST_SNAPSHOT     |  2172 |   137K|     9   (0)| 00:00:01 | 
|   4 |    NESTED LOOPS                  |                             |   303 |   201K|    53   (2)| 00:00:01 | 
|   5 |     VIEW                         |                             |    23 |   598 |     7  (15)| 00:00:01 | 
|   6 |      HASH UNIQUE                 |                             |    23 |   897 |     7  (15)| 00:00:01 | 
|   7 |       TABLE ACCESS BY INDEX ROWID| SQLT$_DBA_HIST_SQLSTAT      |    23 |   897 |     6   (0)| 00:00:01 | 
|*  8 |        INDEX RANGE SCAN          | SQLT$_DBA_HIST_SQLSTAT_N1   |     9 |       |     2   (0)| 00:00:01 | 
|*  9 |     TABLE ACCESS BY INDEX ROWID  | SQLI$_DBA_HIST_PARAMETER    |    13 |  8515 |     2   (0)| 00:00:01 | 
|* 10 |      INDEX RANGE SCAN            | SQLI$_DBA_HIST_PARAMETER_N1 |   202 |       |     1   (0)| 00:00:01 | 
---------------------------------------------------------------------------------------------------------------- 
Predicate Information (identified by operation id): 
--------------------------------------------------- 
   2 - access("P"."STATEMENT_ID"="S"."STATEMENT_ID" AND "P"."SNAP_ID"="S"."SNAP_ID" AND 
              "P"."DBID"="S"."DBID" AND "P"."INSTANCE_NUMBER"="S"."INSTANCE_NUMBER") 
   3 - filter("S"."STATEMENT_ID"=:B1) 
   8 - access("STATEMENT_ID"=:B1) 
   9 - filter((("P"."ISMODIFIED"<>'FALSE' OR "P"."ISDEFAULT"='FALSE') AND "P"."SNAP_ID"="ST"."SNAP_ID")) 
  10 - access("P"."STATEMENT_ID"=:B1 AND "P"."DBID"="ST"."DBID") 
Note 
----- 
   - dynamic sampling used for this statement

按道理来说这个语句应该运行很快才对，怎么会出这种问题了，看到是动态采样的。于是我就想收集了一下这几个表的统计信息。发现统计信息居然还是锁住的。于是强行解锁把这几个表的统计信息收集了。

SQL> exec dbms_stats.UNLOCK_TABLE_STATS(ownname=>'SQLTXPLAIN',TABNAME=>'SQLI$_DBA_HIST_PARAMETER'); 
PL/SQL procedure successfully completed. 
SQL> exec dbms_stats.GATHER_TABLE_STATS(ownname=>'SQLTXPLAIN',TABNAME=>'SQLI$_DBA_HIST_PARAMETER'); 
PL/SQL procedure successfully completed.
SQL> exec dbms_stats.UNLOCK_TABLE_STATS(ownname=>'SQLTXPLAIN',TABNAME=>'SQLT$_DBA_HIST_SQLSTAT'); 
PL/SQL procedure successfully completed. 
SQL>  exec dbms_stats.GATHER_TABLE_STATS(ownname=>'SQLTXPLAIN',TABNAME=>'SQLT$_DBA_HIST_SQLSTAT'); 
PL/SQL procedure successfully completed. 
SQL> exec dbms_stats.UNLOCK_TABLE_STATS(ownname=>'SQLTXPLAIN',TABNAME=>'SQLT$_DBA_HIST_SNAPSHOT'); 
PL/SQL procedure successfully completed. 
SQL> exec dbms_stats.GATHER_TABLE_STATS(ownname=>'SQLTXPLAIN',TABNAME=>'SQLT$_DBA_HIST_SNAPSHOT'); 
PL/SQL procedure successfully completed.

收集完了再次运行，SQLT的结果集就出来了。然后查看了一下新的执行计划。发现确实有改变。SQLT$_DBA_HIST_SQLSTAT从索引范围扫描变成了全表扫描。执行计划由nested loop变成了hash join。

PLAN_TABLE_OUTPUT 
------------------------------------------------------------------------------------------------------------------------------------------------------ 
SQL_ID  f2u123bv4pufu, child number 0 
------------------------------------- 
SELECT S.END_INTERVAL_TIME, P.SNAP_ID, P.ISDEFAULT, P.ISMODIFIED, P.PARAMETER_NAME, 
P.INSTANCE_NUMBER, P.VALUE FROM SQLI$_DBA_HIST_PARAMETER P, SQLT$_DBA_HIST_SNAPSHOT S, (SELECT /*+ 
NO_MERGE */ DISTINCT SNAP_ID, DBID FROM SQLT$_DBA_HIST_SQLSTAT WHERE STATEMENT_ID = :B1 ) ST WHERE 
P.STATEMENT_ID = :B1 AND P.STATEMENT_ID = S.STATEMENT_ID AND P.SNAP_ID = S.SNAP_ID AND P.DBID = 
S.DBID AND P.INSTANCE_NUMBER = S.INSTANCE_NUMBER AND (P.ISDEFAULT = 'FALSE' OR P.ISMODIFIED <> 
'FALSE') AND P.SNAP_ID = ST.SNAP_ID AND P.DBID = ST.DBID ORDER BY S.END_INTERVAL_TIME DESC, 
P.ISDEFAULT, P.ISMODIFIED DESC, P.PARAMETER_NAME, P.INSTANCE_NUMBER 
Plan hash value: 72767641 
-------------------------------------------------------------------------------------------------------------- 
| Id  | Operation                      | Name                        | Rows  | Bytes | Cost (%CPU)| Time     | 
-------------------------------------------------------------------------------------------------------------- 
|   0 | SELECT STATEMENT               |                             |       |       |    72 (100)|          | 
|   1 |  SORT ORDER BY                 |                             |     1 |   698 |    72   (5)| 00:00:01 | 
|*  2 |   HASH JOIN                    |                             |     1 |   698 |    71   (3)| 00:00:01 | 
|*  3 |    HASH JOIN                   |                             |     1 |   667 |    57   (4)| 00:00:01 | 
|*  4 |     TABLE ACCESS BY INDEX ROWID| SQLI$_DBA_HIST_PARAMETER    |     1 |   655 |     0   (0)|          | 
|*  5 |      INDEX RANGE SCAN          | SQLI$_DBA_HIST_PARAMETER_N1 |     1 |       |     0   (0)|          | 
|   6 |     VIEW                       |                             |   707 |  8484 |    56   (2)| 00:00:01 | 
|   7 |      HASH UNIQUE               |                             |   707 | 12019 |    56   (2)| 00:00:01 | 
|*  8 |       TABLE ACCESS FULL        | SQLT$_DBA_HIST_SQLSTAT      |  2078 | 35326 |    55   (0)| 00:00:01 | 
|*  9 |    TABLE ACCESS FULL           | SQLT$_DBA_HIST_SNAPSHOT     |  2174 | 67394 |    14   (0)| 00:00:01 | 
-------------------------------------------------------------------------------------------------------------- 
Predicate Information (identified by operation id): 
--------------------------------------------------- 
   2 - access("P"."STATEMENT_ID"="S"."STATEMENT_ID" AND "P"."SNAP_ID"="S"."SNAP_ID" AND 
              "P"."DBID"="S"."DBID" AND "P"."INSTANCE_NUMBER"="S"."INSTANCE_NUMBER") 
   3 - access("P"."SNAP_ID"="ST"."SNAP_ID" AND "P"."DBID"="ST"."DBID") 
   4 - filter(("P"."ISMODIFIED"<>'FALSE' OR "P"."ISDEFAULT"='FALSE')) 
   5 - access("P"."STATEMENT_ID"=:B1) 
   8 - filter("STATEMENT_ID"=:B1) 
   9 - filter("S"."STATEMENT_ID"=:B1)

原文地址：运行SQLT出现Latch:cache Buffer Chains的一种解决办法, 感谢原作者分享。

内容总结

以上是互联网集市为您收集整理的运行SQLT出现Latch:cacheBufferChains的一种解决办法全部内容，希望文章能够帮你解决运行SQLT出现Latch:cacheBufferChains的一种解决办法所遇到的程序开发问题。 如果觉得互联网集市技术教程内容还不错，欢迎将互联网集市网站推荐给程序员好友。

内容备注

版权声明：本文内容由互联网用户自发贡献，该文观点与技术仅代表作者本人。本站仅提供信息存储空间服务，不拥有所有权，不承担相关法律责任。如发现本站有涉嫌侵权/违法违规的内容， 请发送邮件至 gblab@vip.qq.com 举报，一经查实，本站将立刻删除。

内容手机端

扫描二维码推送至手机访问。

本文链接：https://qyyshop.com/info/555831.html

来源：【匿名】