参数一致却导致ORA-01105: mount is incompatible with mounts by other instances

昨日,RAC数据库2节点因私网心跳超时导致CRS重启,异常的是,数据库实例并没有如愿启动,而是在CRS自动带起数据库实例时,NOMOUNT到MOUNT过程中抛出了如下报错:

ORA-01105: mount is incompatible with mounts by other instances 
ORA-19808: recovery destination parameter mismatch

此错误为RAC数据库各实例同一参数生效值存在differ的情况,但是针对本次案例,经过分析与测试,此问题定性为软件Bug,故障现象还原模拟如下:

20200121-1

与生产系统现象一致,3节点RAC中,db_recovery_file_dest 参数为空,db_recovery_file_dest_size为300gb,

20200123-1

我们在节点2上设置db_recovery_file_dest参数,设置为+DG_DATA

20200123-2

我完全还原生产环境中故障的现象,生产环境中,在时间节点1时,集群2节点设置了db_recovery_file_dest参数,并且该参数在1个月后左右,人为将节点1上这个参数设置成了空,并且两次参数范围生效均为scope=both sid=’*’

故障现象出现,节点2宕机,并且无法启动抛出了预期的错误,生成create pfile from memory与create pfile from spfile后进行对比,但是这个参数各个节点均为格式一致的空,理论上不存在参数不一致且冲突的设置。

20200123-3

是否这个参数的设置方式不规范导致了此问题的发生,询问了Oracle业界大神ACED杨廷琨老师,杨老师建议用reset方式再次进行测试,但是测试结果一致,只用alter system reset方式进行参数的重置,仍然会导致此问题的发生。

严谨的杨老师继续给予我第二个测试内容,

(1)是否只是设置为空会引发这个问题,如果修改为其他目录是不是在任意一个节点都可以?

(2)另外,如果置空需要在当时set的节点运行,那么如果当前崩溃尝试启动的恰好是这个节点呢?其他节点的reset都无法使当前节点的实例启动吗?

测试点(1)是否只是设置为空会引发这个问题,如果修改为其他目录是不是在任意一个节点都可以?

20200123-4

这时,模拟2节点宕机并重启后,没有发生ORA-01105与ORA-19808的错误,说明本节点设置值A,另外节点设置非空值B是OK的

测试点(2)如果置空需要在当时set的节点运行,那么如果当前崩溃尝试启动的恰好是这个节点呢?其他节点的reset都无法使当前节点的实例启动吗?

2020012305

20200123-6测试结论:因为这个参数设置导致的“冲突”,从而引发了实例重启的故障,但是,通过上述对生产环境的模拟发现,这个参数各个节点实际上内存生效值与实例SPFILE中的参数数值并不存在差异(包括格式),显然,这是Oracle软件的Bug行为,

1.节点set value,节点set null必须在同一节点上运行,如果不同,则会影响set value 节点重启,解决方案为在set null节点再次执行set null命令,其他节点设置其他VALUE是无影响的(只要别设置为空)

2.如果set null节点已宕机的情况下,之后set value节点也无法启动了,需要其他存活节点上再次执行set null命令后,set value,set null的异常节点均可成功启动

3.如果set null节点存活,则必须在set null节点 再次执行set null命令,若在其他存活节点上执行set null命令,set value节点同样无法启动。

 

RAC节点2遭遇连续驱逐

公司一套核心业务数据库RAC集群数据库2节点实例分别在2019年 11月13日,2020年1月2日,2020年1月11日发生3次被集群驱逐的情况发生,并且故障时,三次重启CRS均夯住,只能通过重启服务器的方式应急解决。

1.集群日志(2019.11.13)

20190112-1112.集群日志(2020.01.02)

20200112-2

3.集群日志(2020.01.11)

20200112-3

通过以上日志得知,三次实例驱逐均是因为集群间私网心跳超时导致,但是依照RAC网络心跳集群的驱逐的原则,2节点被驱逐不见得根因就是出在2节点上,该环境为2节点RAC,因心跳超时导致集群分为2个子集群,保留最小节点号的子集群会留下,所以1节点会有很大几率被保留,2节点会被驱逐。

分析Oswatcher中netstat采集的网络信息:

节点1,故障期间包重组失败统计:

20200112-04

节点1,物理丢包统计:

20200112-07

节点2,故障期间包重组失败统计:

20200112-05

节点2,物理丢包统计:

20200112-06

可以看到,节点1故障期间没有发生物理丢包与包重组失败,然而节点2则物理丢包与包重组失败都存在(数值一值在累计增加),所以基本推定节点2数据库服务器私网网卡存在异常现象。当讨论这个故障期间,有同事提出可以修改linux操作系统内核参数,避免大量包重组失败的问题:

net.ipv4.ipfrag_high_thresh = 16M     --default 4M
net.ipv4.ipfrag_low_thresh = 15M      --default 3M

这种方式是可行的,当无法排查定位出硬件设备问题时,可以尝试利用此方式来继续观察,但是上述现象除了包重组失败还存在物理丢包现象,也就是说很多Packet没有到包重组那步就已经出现ERROR于DROP的现象,物理丢包仍然会导致RAC集群心跳超时从而继续驱逐节点。

通过上述分析后,我们决定不修改内核参数,决定进行本日第二次的私网网卡切换操作,继续观察,硬件同事将eth14切换到eth08后,丢包现象消失,问题暂时解决,继续观察。

Cursor 触发了OPTIMIZER_MISMATCH=Y的Bug?

近日,一个数据服务器CPU基本每日触发报警,Idle已经接近于0,并且存在一定的周期性规律,CPU Idle如下图所示:

20200105-11

定位到具体进程后,发现CPU TIME主要被两个SQL因为创建合适的索引导致大量全表扫描耗尽。经过简单优化后,SQL效率提升,但却发现了一个奇怪的问题:

优化前:

20200105-12

优化后:

20200105-13

使得游标立即失效后,此SQL会立即进行硬解析,但是却硬解析了2个Child Cursor:

20200105-14

20200105-15可以看到,两个Cursor确认是因为客户端NLS_SORT与NLS_COMP参数不一致,导致了Cursor 2无法利用上索引,从而选择了全表扫描的执行计划。但是从V$SQL_SHARED_CURSOR中发现了异常现象,LANGUAGE_MISMATCH很好理解(因为NLS_SORT与NLS_COMP参数不一),但是OPTIMIZER_MISMATCH为何也是’Y’?

20200105-16

利用alter system set events ‘trace[rdbms.SQL_Optimizer.*][sql_id]’ ;查看Trace文件与查询v$sql_optimizer_env确认游标优化器参数时,并没有发现异常现象:

20200105-17

20200105-18如果优化器参数不一,那么cursor执行计划中的Outline Data CBO参数部分会有所区别,但是上图中两个Cursor 执行计划中显示的CBO参数是一致的。虽然Oracle Support中并未发现相关Bug记录,但是猜测很有可能是触发了Bug导致。

Oracle AWR裸数据提取-Tablespace io指标发现的Bug

近日,梳理并确认Oracle数据库历史数据收集SQL有效性与正确性是发现了一个异常的现象,利用如下SQL采集数据库tablespace io相关统计信息时发现,AWR中1-bk Rds/s指标数据却与SQL裸数据提取的Writes数据完全一致。

AWR报告结果

20200105-1

SQL裸数据提取结果:

20200105-2

可以看到,AWR数据中的1-bk Rds/s与Writes数据完全一致,但是1-bk Rds/s的含义应该是每秒发生的读取单个block的次数,然而Writes是通过dba_hist_filestatxs视图中提取PHYWRTS数据指标来实现的,这两个指标含义完全不一致,不可能这么产生如此的巧合。到底是哪里出的问题?并且1-bk Rds/s居然比Av Rds/s(RPS)还要大,这明显是不正常的现象。

继续阅读

应用报错“Io 异常: Connection reset”异常案例

前几日,一套核心业务数据库待投产环境进行投产前测试时应用出现大量“Io 异常: Connection reset”报错,应用无法连接数据库。要来数据库相关信息后,登陆数据库检查状态发现数据库正处于大量’Library Cache Lock与Library Cache Mutex :X等待中,如下图ASH所示:

20191227-1

20191228-5

20191228-6

大量ddl_lock type为79,已经知晓了这种现象的根因,随手做了一个数据库systemstate dump进行验证:

oradebug setmypid
oradebug dump systemstate 266;
oradebug tracefile_name;

探寻 dump Trace文件,我们看到会话正在等待Library Cache Lock,做system dump 的意义在于,要找到持有Library Cache Handle Lock的会话为什么会持有锁,为什么不及时释放锁从而导致后续活动会话get不到Lock资源从而等待,

20191228-1

dump trace文件中已经明确显示了该handle address,继续搜寻后发现证实了我的猜测,

20191228-2我们看到,该Hanlde Lock既有RequestMode=X,同时又存在LockMode=X ,不兼容从而发生的阻塞等待是正常现象,但是发现了该Library Cache Lock 的Namespace=ACCOUNT_STATUS(79),证实了我的猜测,该阻塞等待是因为数据库账户密码错误导致触发Oracle 延迟登录特性,从而产生大量Library Cache Lock。但是为何Io 异常: Connection reset呢?猜测是因为数据库活动会话大量积压,应用服务器连接数被撑满。

既然找到并且证实了根因,针对此问题下一步该如何操作?针对数据库账户密码错误,我们可以执行:

alter system set events '1017 trace name errorstack forever,level 3';

该errorstack会生成trace文件,在trace文件中确认,waitint for library cahce lock中的machine,也就是密码错误触发延迟登录长时间持有Library Cache Lock的应用服务器。

设置完成后,只要利用错误密码登录数据库抛出ORA-01017,则会在数据库Alert中产生一个Trace文件.

20181228-3

20191228-4

随后将报错应用服务器发送至应用方,检查配置的数据库账户密码是否正确。

最后, 为消除之后隐患,在数据库中执行

ALTER SYSTEM SET EVENTS '28401 TRACE NAME CONTEXT FOREVER, LEVEL 1' :

从而使得,今后会话在因密码登录失败后,直接返回报错,不会长时间持有LIBRARY CACHE LOCK 。

alter table drop column(default value not null )导致ORA-12899

近日,同事的测试库中出现一则奇怪的现象邀请我共同探讨,一张数据表在删除一个含有DEFAULT值的非空列时报错,Error Code为ORA-12899,报错详情如下:

20191215-1

12899, 00000, "value too large for column %s (actual: %s, maximum: %s)"
// *Cause: An attempt was made to insert or update a column with a value
// which is too wide for the width of the destination column.
// The name of the column is given, along with the actual width
// of the value, and the maximum allowed width of the column.
// Note that widths are reported in characters if character length
// semantics are in effect for the column, otherwise widths are
// reported in bytes.
// *Action: Examine the SQL statement for correctness. Check source
// and destination column data types.
// Either make the destination column wider, or use a subset
// of the source column (i.e. use substring).

专业的同事,在同样觉得蹊跷的之后,再一次执行此语句并且抓取了相关10046 Trace文件,分析Trace文件后,发现有一条递归update语句导致此错误,导致drop column失败,进入死循环。

2019115-2

继续阅读

针对SCHEMA Rename需求

近日,某测试数据库用户存在更换schema名称的需求,同事准备将数据进行导入导出的同时进行remap schema的工作,其实,从ora11g(11.2.0.2)版本开始,Oracle提供在不动数据的情况下,将schema rename的功能,但是代价是需要将数据库启动restrict模式下,实验如下:

20191208-111

rename之前需要将_enable_rename_user隐含参数改为TRUE(默认为FALSE),此参数意义为enable RENAME-clause using ALTER USER statement。

将数据库启动到restrict模式后,可以利用alter user rename命令进行更改schema name,本案例中为schema独占测试数据库,若生产库将数据库中一般存在多个schema共享一套数据库,启动到 restrict模式会造成应用连接无法连接数据库的情况发生,因本案例为测试系统,生产系统慎用此方式。

20191208-222

Oracle 12c column add default value功能增强

前几日晚,某核心应用负责人准备进行上线操作前打来一个确认电话,咨询了一个Oracle 11g 表添加default值的问题,询问是否有何影响,听完他的描述后,简单跟他描述完原理后,建议他取消此上线操作,否则会造成核心应用严重的性能问题,但是此问题再Oracle 12c新特性中已得到很大改进,对性能的影响已经降到最低。

11g情况下,可以看到,增加一个带有default值的并且没有添加非空约束的列,需要分钟级别(与表数据量有直接关系),完成时间会随着数据量的增加而耗时变长。

20191208-11

会话2,我们在执行alter table时会造成读写阻塞,等待library cache lock

SID=916会话被阻塞

20191208-12

SID=346会话被阻塞:

20191208-14

所以在此期间内产生的应用事务,查询均会被阻塞,如果TABLE量级比较大,会造成更严重的性能问题,因为11g在添加DEFAULT值且没有非空约束时,在更新数据字典的同时仍要更新表中全部已有记录值,我们从segment大小与10046 event trace文件中可以得到论证。

继续阅读

应用端频繁报出java.sql.SQLException: pingDatabase failed, status=-1案例

近日,某航司B2C网站应用人员发来求助排查邮件,告知JBOSS连接数据库经常报出java.sql.SQLException: pingDatabase failed, status=-1的错误,并且经过确认,数据库正处于正常状态下,应用人员提供了相对具体报错时间点,希望尽快帮忙排查一下数据库端有无异常。

20191201-2

登录数据库查看alert与监听日志后发现,数据中确实偶发出现如下链接报错,

20191201-1

继续阅读

RAC数据库日志大量IPC Send timeout报错案例

上周,公司一套核心业务系统数据库出现大量IPC Send timeout的报错信息并伴随出现大量diag进程的dump Trace文件;同时,监控部门同事反馈监控agent已无法连入此库,下图为数据库alert日志截图,抛出的Trace文件均是用作监控需求,查询GV$视图的SQL。

201911127-1

当RAC数据库中出现类似信息时,我们优先考虑RAC数据库节点间出现私网通信不佳,私网丢包,包重组的故障原因,同时与监控查询GV$需要节点间通讯特性比较吻合,我们接下来看一下节点1,2,3的进群日志:

继续阅读