ADG备库批量查询失败的原因分析(r8笔记第33天)

目前线上有一套环境是10gR2的,采用了一主两备的架构。在其中一个备库上每天凌晨会开放一个窗口运行一些批量的查询,目前使用dg broker会在指定的时间把备库置为read-only,查询完毕之后修改为online状态。 但是近几天开发的同事突然找到我说,最近几天开始批量查询会频频报错,希望我帮忙查看一下。 语句运行报错,听起来原因应该很简单吧,最大的可能就是备库没有打开,或者是ddl,dml语句之类的。但是看到错误日志,让我着实有些奇怪。 错误日志如下,可以看到是一条查询语句。 [2016.03.06 04:10:02.352]org.springframework.jdbc.UncategorizedSQLException: PreparedStatementCallback; uncategorized SQLException for SQL [select bind_flag from test_billing where cn_master=?]; SQL state [60000]; error code [604]; ORA-00604: error occurred at recursive SQL level 1

[2016.03.06 04:10:02.352]ORA-16000: database open for read-only access

[2016.03.06 04:10:02.352]; nested exception is java.sql.SQLException: ORA-00604: error occurred at recursive SQL level 1

[2016.03.06 04:10:02.352]ORA-16000: database open for read-only access

[2016.03.06 04:10:02.352] 除了这些信息,应用端就没有更多的日志了,而从数据库层面来看,得到的日志如下。

 	Completed: ALTER DATABASE OPEN READ ONLY 
 	Mon Mar 07 03:45:14 CST 2016 
 	Redo Shipping Client Connected as PUBLIC 
 	-- Connected User is Valid 
 	RFS[99]: Assigned to RFS process 28797 
 	RFS[99]: Identified database type as 'physical standby' 
 	RFS[99]: Archived Log: '/U01/app/oracle/admin/acccomdb/arch/1_24776_782846320.dbf' 
 	Mon Mar 07 07:02:59 CST 2016 
 	ORA-1652: unable to extend temp segment by 128 in tablespace                 TEMP2  
 	Mon Mar 07 07:02:59 CST 2016 
 	ORA-1652: unable to extend temp segment by 128 in tablespace                 TEMP2  
 	Mon Mar 07 08:10:03 CST 2016 
 	Stopping background process MMNL 
 	Mon Mar 07 08:10:04 CST 2016 
 	Stopping background process MMON 
 	Mon Mar 07 08:10:05 CST 2016 
 	Active process 10256 user 'oracle' program 'oracle@testdb.cyou.com' 
 	Active process 10258 user 'oracle' program 'oracle@testdb.cyou.com' 
 	Active process 10254 user 'oracle' program 'oracle@testdb.cyou.com' 
 	Active process 10401 user 'oracle' program 'oracle@testdb.cyou.com' 
 	CLOSE: waiting for server sessions to complete. 
 	CLOSE: all sessions shutdown successfully. 

通过上面的日志也分析不出哪里可能有很明显的错误,TEMP的也算是一个引子吧。在排查了各种可能出现的场景后,却始终得不到有效的思路。 我在备库想看看这个问题是否发生。于是根据日志中的语句查询了一下,发现没有任何问题。

 	select bind_flag from test_billing where cn_master=?  语句可以顺利输出结果。

自己也尝试了dml的情况,错误信息也会有所不同。

 	SQL> update test_billing set  bind_flag=0 where cn_master='660078174'; 
 	update test_billing set  bind_flag=0 where cn_master='660078174' 
 	       * 
 	ERROR at line 1: 
 	ORA-01552: cannot use system rollback segment for non-system tablespace 'ACC_DATA' 

这个时候就停下来,开始理一理思路,之前从来没有反馈过这个问题,而问题是在最近发生的。那么应用端是否在最近有什么变化呢,得到的反馈是在1月中下旬有一次变更,但是这都过去好久了,不足以佐证现在的问题。

那数据库端有什么变化吗?唯一的变更就是在最近把这个批量查询从备库2迁到了备库1去做。这个也是近1个月以前完成的事情了,也不足以证明最近的问题。

而从数据库层面,如果存在问题,那看似只有bug的可能性了,但是查了mos一圈,发现了几种可能的场景,但是都和目前的情况不符合,目前查到有两种场景,一种是略微复杂的查询,一种是带有db link的查询。参考链接如下:

 	Dblink on Physical standby - ORA-16000 (Doc ID 1296288.1) 
 	ORA-16000 With A Semantic Query On A Read-only Database (Doc ID 1928638.1) 

目前的情况是这个语句非常简单,实在找不出来可能的原因了。

开发的同事也催的比较紧,但是感觉从数据库层面得到的信息着实有限。无奈之下,开启了手工debug方式。就从alert日志中的那个关于temp的报错开始分析。

还是采用之前的一种分析方式,用两个脚本来分析。

第一个脚本是 check_temp.sh

 	function get_temp_usage 
 	{ 
 	sqlplus -s  / as sysdba <<eof </eof<>
 	set time on 
 	set pages 100 
 	set linesize 200 
 	col sysdate format a10 
 	col username format a15 
 	col sid format 9999 
 	col serial# format 99999 
 	col blocks format 99999999 
 	col sql_text format a70  
 	set feedback off 
 	select systimestamp from dual; 
 	set feedback on 
 	SELECT sysdate,a.username, a.sid, a.serial#, a.osuser, b.blocks, c.sql_text 
 	  FROM v\$session a, v\$sort_usage b, v\$sqlarea c 
 	  WHERE b.tablespace = 'TEMP' 
 	  and a.saddr = b.session_addr 
 	  AND c.address= a.sql_address 
 	  AND c.hash_value = a.sql_hash_value 
 	  AND b.blocks*8192 > 0 
 	  ORDER BY b.tablespace, b.blocks; 
 	EOF 
 	} 
 	get_temp_usage 

第二个脚本 是tmp.sh

 	for i in {1..36000}  
 	do 
 	sh check_temp.sh >> check_temp.log 
 	sleep 10  
 	done
然后在第二天上班的时候就会得到一个比较详细的列表了。

但是今天到公司之后查看详细记录,发现竟然返回都是空行,看来这些语句运行都成了问题。

打开备库又运行了一次查询,sqlplus中运行没有任何问题。

这个时候就有些怀疑是jdbc驱动的问题了,但是这个似乎还是无从考证了。而且查看mos也没有得到确凿的证据。

于是打电话给开发,进一步做了确认,想他们确认连接的IP,端口和用户,然后得到了下面的这个配置信息。 select bind_flag from test_billing where cn_master=? jdbc:oracle:thin:@10.127.1.17:1525:acccomdb TEST_SHINK 看起来也没有什么问题,TEST_SHINK是一个连接用户,会连接到owner用户的表。

和开发进一步进行沟通和协调,想让他们给半个小时左右的时间继续跑一下失败的批量查询,看看我从数据库端能够发现什么。

但是应用运行之后,查看系统级,没有任何的抖动,数据库层面也可以看到应用是连接进来了。

然后开发就提供了最新的日志。 [2016.03.09 11:04:56.274]org.springframework.jdbc.UncategorizedSQLException: PreparedStatementCallback; uncategorized SQLException for SQL [select bind_flag from test_billing where cn_master=?]; SQL state [60000]; error code [604]; ORA-00604: error occurred at recursive SQL level 1 [2016.03.09 11:04:56.274]ORA-16000: database open for read-only access [2016.03.09 11:04:56.274]; nested exception is java.sql.SQLException: ORA-00604: error occurred at recursive SQL level 1 [2016.03.09 11:04:56.274]ORA-16000: database open for read-only access 这个错误和之前的基本是一致的。

看着这个日志就坐在那里发呆,还有什么特别的方式来调试一下这个问题呢。实在不行就只能10046来做一些分析了。但是在做这个之前,我还是耐着性子再看一看。

于是我切换到了这个连接用户, alter session set current_schema= TEST_SHINK; 然后再次运行这个报错的语句,终于得到了期望之中的报错。 SQL> select bind_flag from test_billing where cn_master= '660078174'; select bind_flag from test_billing where cn_master= '660078174' * ERROR at line 1: ORA-00604: error occurred at recursive SQL level 1 ORA-16000: database open for read-only access 有了报错信息,就有了处理问题的方向,于是换了一个方式。采用owenr用户的方式来查看,就没有问题了。 SQL> select bind_flag from acc.test_billing where cn_master= '660078174'; BIND_FLAG ---------- 689537

这个问题是怎么回事呢?

TEST_SHINK下的都是同义词,指向ACC这个owner用户,那么这个同义词有什么特别的呢。进一步查看,发现同义词test_billing是INVALID的。 看起来这个问题总算有了解决的思路,我们可以在主库直接编译运行即可,然后这部分变更会同步到备库。当然同义词为失效的时候,直接查询也会自动编译。所以在主库只需要运行一条select语句即可。在主库中确认,发现TEST_SHINK下的同义词test_billing确实也是INVALID的。

那么在主库运行下面的sql即可。 > select count(*)from TEST_SHINK.TEST_BILLING where cn_master= '660078174'; COUNT(*) ---------- 1

然后再次查看状态,同义词的状态就自动为VALID的了。 然后在备库开启日志应用,然后切换回只读状态,再次验证就没有问题了,然后让应用进一步确认,发现终于正常了。 那么还有一个问题需要解决的就是,根据开发的反馈,应该是从3月4日开始出现了问题,这个test_billing是否在3月3日左右出现了一些变化,导致同义词失效呢。

可以从dba_objects进行论证,当然也是带着一丝侥幸,得到了期望的结果。最新的一次ddl操作是在3月3日的早晨。

> SELECT OWNER,OBJECT_NAME,OBJEcT_TYPE,LAST_DDL_TIME,STATUS FROM DBA_OBJECTS WHERE OBJECT_NAME='TEST_BILLING'; OWNER OBJECT_NAME OBJECT_TYPE LAST_DDL_TIME STATUS -------------------- -------------------- ------------------- ------------------- ---------- ACC TEST_BILLING TABLE 2016-03-03 07:38:28 VALID APP_ACC_USER TEST_BILLING SYNONYM 2016-03-03 07:38:29 VALID TEST_SHINK TEST_BILLING SYNONYM 2016-03-09 11:16:59 VALID 因为这个用户应用只在备库使用,所以就导致了这个看起来奇怪的问题,看来都是事出有因,耐心一些,细致一些还是会有发现。

原文发布于微信公众号 - 杨建荣的学习笔记(jianrong-notes)

原文发表时间:2016-03-09

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

发表于

我来说两句

0 条评论
登录 后参与评论

相关文章

来自专栏微信公众号:Java团长

Spring MVC+Spring+Mybatis实现支付宝支付功能(图文详解)

本教程详细介绍了如何使用ssm框架实现支付宝支付功能。本文章分为两大部分,分别是「支付宝测试环境代码测试」和「将支付宝支付整合到ssm框架」,详细的代码和图文解...

2021
来自专栏好好学java的技术栈

java实现沙箱测试环境支付宝支付和整合微信支付和支付宝支付到ssm(附源码)

下载地址:https://docs.open.alipay.com/270/106291/

4687
来自专栏数据库新发现

【红色警报】近期Oracle数据库遭受比特币勒索攻击原因揭秘和预防

链接:http://www.eygle.com/archives/2016/11/AfterConnect_hacked.html

891
来自专栏JavaEdge

MySQL各种存储引擎介绍与适用场景1.引擎的介绍第三方存储引擎:InfobrightTokuDBXtraDB、PBXT2.常用两种引擎的选择

6996
来自专栏Rgc

项目中记录影响性能的缓慢数据库查询

如果程序性能随着时间推移不断降低,那很有可能是因为数据库查询变慢了,随着数据库规模的增长,这一情况还会变得更糟。优化数据库有时很简单,需要在程序和数据库之间加入...

36411
来自专栏纯洁的微笑

MySQL 大表优化方案

除非单表数据未来会一直不断上涨,否则不要一开始就考虑拆分,拆分会带来逻辑、部署、运维的各种复杂度,一般以整型值为主的表在 千万级以下,字符串为主的表在 五百万以...

1284
来自专栏杨建荣的学习笔记

海量数据迁移之sqlldr和datapump的缺点分析(r4笔记第74天)

在数据迁移中,sql*loader和datapump总是作为一些常用的数据迁移方案,自己在经历了一些项目之后,优点就不说了,说点这些方案的缺点,批评不自由,则赞...

3926
来自专栏数据和云

高危防范:巧用触发器,实现DDL监控

在数据运维过程中,常常因为DBA的疏忽而使数据安全面临威胁,有些威胁来自数据库外部,如rm操作,而有些威胁则来自数据库内部,如Truncate操作.因此对于数据...

2884
来自专栏杨建荣的学习笔记

记一次数据同步需求的改进(二) (r7笔记第5天)

在之前写过记一次数据同步需求的改进(一) (r7笔记第2天)之后,就开始着手对这个需求进行实践。 所谓实践出真知,在实际做的时候才发现可能计划的再好,做的时候还...

3678
来自专栏idba

死锁案例之五

死锁其实是一个很有意思也很有挑战的技术问题,大概每个DBA和部分开发朋友都会在工作过程中遇见。关于死锁我会持续写一个系列的案例分析,希望能够对想了解死锁的朋友...

934

扫码关注云+社区