动态采样造成的故障和分析

动态采样造成的故障和分析

‍‍作者简介：潘仁杰，北京海天起点数据库维护工程师，获有OCP、RHCE证书。多年的运营商、银行数据库运维经验，熟悉Oracle日常运维管理、安装、升级和迁移等擅长并专注于Oracle在unix/linux下的诊断及SQL调优，并且也了解关注MYSQL,大数据和Python等技术。

从事运维工作的朋友会经常掉到”坑”，而产生这些大大小小的”坑”，往往是由于被我们忽视的几个小的、不起眼的因素一起作用下产生的。这些致”坑”因素中有些可能是开发人员导致的、有些可能是DBA疏忽的、有些是客户不当操作导致的。经验丰富的DBA往往可以在系统开发、运维中利用自己经验和知识帮助系统避开这些致”坑”因素。

下面这个案例就是一个多个因素导致的一个故障：

主机环境：

数据库为政府信息中心托管的数据库服务器，数据库上面接入了政府的众多的OA，门户网站，对公系统的数据库。业务发现故障的时候，市法制办在组织全市各区从业人员进行法制考试（各区进行分批考试）。考试现场人员反馈提交答题是提交答案的时候，提供结果缓慢，已经严重影响到考试的正常运行。

登录法制考试所在的数据库节点（节点2）：

在su到oracle用户的时候，系统已经报错了。

#su - oracle

$-bash: fork: Cannot allocate memory

$-bash: xrealloc: cannot allocate 6800 bytes (135168 bytes allocated)

$-bash: fork: Cannot allocate memory

$-bash: xrealloc: cannot allocate 6800 bytes (135168 bytes allocated)

系统在fork子进程的时候报错：Cannot allocatememory（xrealloc是给一个已经分配了地址的指针重新分配空间）。节点2的内存资源被消耗光了，数据库也无法正常登录入节点2 。

此时节点1 性能正常

内存：

TOP:

此时考试还在进行程中，为了保证考试的正常进行。将节点1接管节点2的服务。

[root@hostname]#srvctl stop service –d db_name –s service_name

[root@hostname]#srvctl start service –d db_name –s service_name

结果考试系统还是不能正常提交答案。检查发现：考试系统的JDBC配置（由于安全问题IP已经做过修改）

如下：

jdbc:oracle:thin:@XXX.XXX.XXX.XXX:1621:racdb2

多次和客户强调JDBC应该配置（由于安全问题IP已经做过修改）：

jdbc:oracle:thin:@(description=(address_list= (address=(host=XXX.XXX.XXX.XXX) (protocol=tcp)(port=1621))(address=(host=200.100.50.203)(protocol=tcp) (port=1621)))(connect_data=(service_name= njdx_racdb2)))

修改JDBC的配置，让考试能正常运行。就这么七折腾八折腾，考试预定的时间过去了，考试结束。据信息中心人员反馈，考生和信息中心协商，把考试中受影响的学生安排在下一批考试人员中重考一次。

所以需要尽快查出故障，防止下批次考试中出现问题。故障分析：

检查节点2的alert日志：

对应该故障时间段出现ORA-04030报错:

04030, 00000, "out of process memory when trying to allocate %s bytes (%s,%s)"

// *Cause: Operating system process private memory was exhausted.

// *Action:

……

Thu Jan 12 09:58:32 2017

Errors in file oracle/app/oracle/diag/rdbms/racdb/racdb2/trace/racdb2_ora_64230.trc (incident=1449305):

ORA-04030: ՚Ӣ˔ؖƤ 32832 ؖޚ (pga heap,kgh stack) ʱ޸ԌŚզһأ

Incident details in: oracle/app/oracle/diag/rdbms/racdb/racdb2/incident/incdir_1449305/racdb2_ora_64230_i1449305.trc

Use ADRCI or Support Workbench to package the incident.

……

查看对应trc文件：racdb2_ora_64230.trc，发现生成的TRC文件也受影响了。

中间这个时间的TRC文件都没有了。

检查alert日志上下文，发现有大量的7445报错并且有进程DIE

………………

Thu Jan 12 10:01:20 2017

Exception [type: SIGSEGV, Address not mapped to object] [ADDR:0x7FFFF209C3A8] [PC:0x89C0874, qcplgte_multibyte()+302] [flags: 0x0, count: 1]

Errors in file oracle/app/oracle/diag/rdbms/racdb/racdb2/trace/racdb2_ora_104360.trc (incident=1472817):

ORA-07445: ԶЖӬӣխϳ: ۋфתԢ [qcplgte_multibyte()+302] [SIGSEGV] [ADDR:0x7FFFE6EF37E8] [PC:0x89C0874] [Address not mapped to object] []

进程DIE了

Use ADRCI or Support Workbench to package the incident.

………………

Process J000 died, see its trace file

………………

………………

Process m000 died, see its trace file

………………

Process J000 died, see its trace file

kkjcre1p: unable to spawn jobq slave process

Errors in file oracle/app/oracle/diag/rdbms/racdb/racdb2/trace/racdb2_cjq0_91351.trc:

Process startup failed, error stack:

Errors in file oracle/app/oracle/diag/rdbms/racdb/racdb2/trace/racdb2_psp0_90667.trc:

ORA-27300: OS system dependent operation:fork failed with status: 12

ORA-27301: OS failure message: Cannot allocate memory

ORA-27302: failure occurred at: skgpspawn3

Process J000 died, see its trace file

………………

Process J000 died, see its trace file

………………

………………

Thu Jan 12 10:04:50 2017

Process m000 died, see its trace file

Thu Jan 12 10:04:54 2017

Process startup failed, error stack:

Errors in file oracle/app/oracle/diag/rdbms/racdb/racdb2/trace/racdb2_psp0_90667.trc:

ORA-27300: OS system dependent operation:fork failed with status: 12

ORA-27301: OS failure message: Cannot allocate memory

ORA-27302: failure occurred at: skgpspawn3

Thu Jan 12 10:04:55 2017

………………

可以看到由于内存问题导致了进程DIE，现在需要找出是什么导致了内存消耗。

试图利用节点2 上的AWR去分析故障原因，但是悲剧的发现故障时间段的SNAPSHOT也是缺失的。

故障查找陷入了僵局。

这时候想到其它几批次的考试没有故障（其它几批次考试人数明显比此次人数要少），所以取上场考试时间段内的AWR。Time Model Statistics中发现硬解析达到了令人发指的56.69。这显然是极度异常的。

查询了一下用户的历史SQL：

发现一张出现频率较高的表Z_TEST_ITEM_BAK，在使过的语句上没有绑定变量。似乎可以得出是由于用户的sql没有绑定变量，硬解析过高导致了，进程堆积消耗了所有内存导致的。

但是在SQL ordered by CPU Time和SQLordered by Elapsed Time发现了一条可疑的SQL，从内容上来看，不像是用户写的，但其中一个令人心生警惕的一个表名：Z_TEST_ITEM_BAK。上面查询的SQL内这个表也出现了多次，咨询了一下客户，这个表是考生所有的考试提交结果的备份表。就是所有考生的考试信息全部写入这张表。

这条SQL:

SQL> SELECT * OPT_DYN_SAMP */ *+ ALL_ROWS IGNORE_WHERE_CLAUSE NO_PARALLEL(SAMPLESUB) opt_param('parallel_execution_enabled', 'false') NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */

NVL(SUM(C1), :"SYS_B_00"), NVL(SUM(C2), :"SYS_B_01")

FROM (SELECT *+ IGNORE_WHERE_CLAUSE NO_PARALLEL("T") FULL("T") NO_PARALLEL_INDEX("T") */

:"SYS_B_02" AS C1,

CASE

WHEN "T"."SUBJECTID" = :"SYS_B_03" AND

("T"."SORTNO" = :"SYS_B_04" OR "T"."SORTNO" = :"SYS_B_05") THEN

:"SYS_B_06"

ELSE

:"SYS_B_07"

END AS C2

FROM "FZTEST1601"."Z_TEST_ITEM_BAK" SAMPLE BLOCK(:"SYS_B_08", :"SYS_B_09") SEED(:"SYS_B_10") "T") SAMPLESUB

查询中有一个HITN，/* OPT_DYN_SAMP */是数据库在使用动态采样

动态采样（Dynamic Sampling）技术的最初提出是在Oracle9i R2，在段（表，索引，分区）没有分析的情况下，为了使CBO 优化器得到足够的信息以保证做出正确的执行计划而发明的一种技术，可以把它看做分析手段的一种补充。11.2.0.4之后称为Dynamic Statistic.

检查了一下

SQL> select table_name,NUM_ROWS,BLOCKS,degree,LAST_ANALYZED,PARTITIONED from dba_tables where table_name= 'Z_TEST_ITEM_BAK'and owner ='FZTEST1601';

发现在这个表上果然没有收集统计信息（事后确认，用户每次有新的考试都会重建这张表，但不收集统计信息）。这样导致了SQL执行的时候系统会使用动态采样去收集表的相关统计信息。由动态采样的结果是临时的，每次进行硬解析的时候都要去动态采一次，再加这个表因为是备份总表（数据库比较大）这样SQL执行效率可想而知了，也就难免造成会话的堆积，消耗完所有的内存。

联系用户确认这个考试系统是多年前开发的一个软件，设计容纳少量人员考，现在考试人员远远超出当时的设计容量。

在后面的考试协助用户把表的统计信息都收集了，考试中再也没出现类似的问题了。

分析一下造成加重故障的几个因素：

1．没有收集统计信息

2．应该的SQL没有绑定变量

3．optimizer_dynamic_sampling的设置为使用

4．JDBC的连接串设置为单节点（进行切换的时候）

5．使用用的用户数据达到了一个量级（此系统原来只是供一个小型考试使用，是一个轻量级的小应用）

这些因素，单独存在的时候，都不会成为故障。结果凑到一起的时候，导致这次成坑了。

这次最主要的还是动态采样的问题。

动态采样（Dynamic Sampling）最早出现在Oracle9i R2版本上（11.2.0.4之后称为DynamicStatistic），CBO 优化器需要足够的信息才能做出正确的执行计划，在表、索引、分区缺少统计信息的情况下，就会使用动态采样，是对统计信息采集的一种补充手段。

动态采样的作用

1、CBO 依赖的是充分的统计分析信息，但是并不是每个用户都会非常认真，及时地去对每个表做分析。为了保证执行计划都尽可能地正确，Oracle需要使用动态采样技术来帮助CBO 获取尽可能多的信息。

2、全局临时表。通常来讲，临时表的数据是不做分析的，因为它存放的数据是临时性的，可能很快就释放了，但是当一个查询关联到这样的临时表时，CBO要想获得临时表上的统计信息分析数据，就只能依赖于动态采样了。

3、动态采样除了可以在段对象没有分析时， OLTP系统非常不适宜使用动态采样

动态采样的设置与两个参数有关:

optimizer_dynamic_sampling、optimizer_features_enable；

optimizer_features_enable（类似compatible）影响了,optimizer_dynamic_sampling默认值 ，但是当optimizer_dynamic_sampling设置为11时不受optimizer_features_enable影响。

optimizer_dynamic_sampling

PS: 采样的数据块越多，得到的分析数据就越接近与真实，但同时伴随着资源消耗的也越大。