0

Oracle DBA核心技能:数据库的跟踪和分析方法之SQL_TRACE和DBMS_SYSTEM

eygle 2020-02-04
253
摘要:在我的技术生涯中,对Oracle数据库的接触最多,感受也最深。如果说要将最值得推荐的技能展示给大家,那么我想推荐的就是Oracle跟踪方法。事实上,通过跟踪能够实现的也正是不断了解、接近开发的思路和方法,从而有助于运维中的问题诊断、排查和解决。

在今天的技术领域,DevOps已经成为最热门的话题之一,DevOps是开发和运维一体化的实践趋势,也是运维掌握一定的开发能力,推动和协助开发进行适应高效运维的渐进变革。
image.png
在我的技术生涯中,对Oracle数据库的接触最多,感受也最深。如果说要将最值得推荐的技能展示给大家,那么我想推荐的就是Oracle跟踪方法。事实上,通过跟踪能够实现的也正是不断了解、接近开发的思路和方法,从而有助于运维中的问题诊断、排查和解决。

我在一个活动上分享过一段话,摘录在这里,作为我这一章内容的开始。

“早上我听到一句话印象深刻,叫“隐藏的权利感”,我想把这句话应用到数据库,表达一下我的观点。
Oracle数据库,虽然是一个商用数据库不开源,但是它又是非常开放的一个产品,Oracle几乎所有的内部操作,不管是调优的过程还是数据库的各种内部操作,都是可跟踪解析的。比如Oracle数据库的启动和关闭过程,全程是可跟踪的。它的启动关闭会解析成多少个递归操作,我们全都可以跟踪出来。
所以我们做Oracle DBA的工作时,面对任何事情我们都会非常有信心。Oracle开放了各种接口,方法和手段给我们,只要我们去分析研究,就能够把一个问题的Root Cause找出来,接近Root Cause就离解决问题不远了。
一个数据库只有变得更加开放接口,更加开放DeBug功能的,才能让我们在研究这个数据库的时候也可以找到更多的乐趣。我觉得这里面找到的乐趣就是我讲的,是隐藏的权利感。就是我不动声色,但是我知道我在处理接触这个数据库的时候,我有非常强的把控力,我能撼动和解决几乎所有的问题。我觉得这一点对于技术人员是非常重要的。”

Oracle数据库的这些基本跟踪方法,伴随着我的技术成长和排忧解难的职业历程,以下详细的通过案例进行解析。

1.SQL_TRACE及10046事件
最常用的跟踪方式是通过初始化参数SQL_TRACE或者设置10046事件。首先从文档了解一下SQL_TRACE基本介绍,以使大家能对这个工具有所了解,并熟悉其使用方法。

先来关注一下Oracle 12c官方文档对SQL_TRACE的说明:

参 数 类 型: 布 尔 型
默认值: false
修改方式: ALTER SESSION ,ALTER SYSTEM
PDB修改: Yes
取值范围: true | false

通过设置SQL_TRACE可以启用或禁用SQL 跟踪工具,设置SQL_trace为true可以收集信息用于性能优化或问题诊断;DBMS_SYSTEM包也可以用于实现类似的功能。

以下警告在不同版本的文档中几乎没有任何变化。

警告: 设置初始化参数SQL_TRACE为true会对整个实例产生严重的性能影响,所以在产品环境中如非必要,确保不要设置这个参数。如果只是对特定的session启用跟踪,可以使用ALTER SESSION或DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION来设置。如果必须在数据库级启用SQL_TRACE,你需要保证以下条件以最小化性能影响。
(1)至少保证有25%的CPU idle。
(2)为USER_DUMP_DEST分配足够的空间。
(3)条带化磁盘以减轻IO负担。

在12c中文档中提示:不再支持SQL_TRACE参数,推荐使用DBMS_MONITOR和DBMS_SESSION包来替代其功能,该参数作为向后兼容而保留,其原有功能仍然存在。而事实上,DBA的工作中,SQL_TRACE很少被使用,更多的是10046事件。

自Oracle 10g开始,SQL_TRACE参数才成为动态参数,可以在全局动态启用,在实践中除了研究目的,很少需要如此在全局设置。

SQL> alter system set SQL_trace=true;
System altered.

大多数时候我们使用SQL_trace跟踪当前会话,通过跟踪当前会话可以发现当前操作的后台递归活动(这在研究数据库新特性时尤其有效),研究SQL执行,发现后台错误等。
在session级启用和停止SQL_trace方式如下所示。

SQL> select count(*) from dba_users; --此时的SQL操作将被跟踪
  COUNT(*)
----------
        34
SQL> alter session set SQL_trace=false;  --结束跟踪
SQL> select value from v$diag_info where name='Default Trace File';

在很多时候需要跟踪其他用户的进程,而不是当前用户,这可以通过Oracle提供的系统包DBMS_SYSTEM的SET_SQL_TRACE_IN_SESSION过程来完成,该过程调用提供三个参数。

PROCEDURE SET_SQL_TRACE_IN_SESSION
 Argument Name	            Type             In/Out Default?
 ------------------------------ ----------------------- ------ --------
 SID                        NUMBER        IN
 SERIAL#                   NUMBER        IN
 SQL_TRACE                 BOOLEAN      IN


通过查询v$session可以获得会话的sid、serial#等信息,获得会话信息之后就可以设置跟踪。

SQL> select sid,serial#,username from v$session
  2  where username is not null;
       SID    SERIAL#  USERNAME
---------- ---------- ------------------------------
         8       2041  SYS
         9        437  EYGLE
SQL> exec dbms_system.set_SQL_trace_in_session(9,437,true)
SQL> exec dbms_system.set_SQL_trace_in_session(9,437,false)

DBMS_SYSTEM包功能非常强大,是重要的跟踪手段之一。

SQL_TRACE还可以通过如下方式针对特定的SQL启用跟踪,指定SQL_ID的SQL会被按照指定条件跟踪其执行过程,这在分析特定SQL时非常有效。

ALTER SYSTEM SET EVENTS 'SQL_trace [SQL:&&SQL_id] bind=true, wait=true';

2. DBMS_SYSTEM跟踪案例
以下这个案例是我走上DBA道路第一个帮助朋友解决的问题。这个问题的解决过程,就是利用自己获得的已知知识,通过思考、跟踪去发现问题,并给出解决方案,对我的成长意义非凡。
这个应用是一个后台新闻发布系统,前端展现是一个网站。JAVA开发,通过中间件连接池连接数据库。当时系统症状是访问新闻页极其缓慢,后台发布管理具有同样的问题。通常需要数十秒才能返回。
处理这个问题时,通过前台或者应用代码去分析会变得十分复杂,我想到的第一个办法就是启用跟踪,然后通过分析跟踪文件找出瓶颈所在。诊断时间在晚上,在无集中用户访问的情况下,让用户在前台进行相关页面的访问,同时进行进程跟踪。
首先通过查询v$session视图,获取进程信息。

SQL> select sid,serial#,username from v$session where username is not null;
       SID    SERIAL# USERNAME
---------- ---------- ------------------------------
         7        284 IFLOW
        11        214 IFLOW
        12        164 SYS
        16       1042 IFLOW

然后对相应的应用会话启用SQL_trace跟踪如下。

SQL> exec dbms_system.set_SQL_trace_in_session(7,284,true)
SQL> exec dbms_system.set_SQL_trace_in_session(11,214,true)
SQL> exec dbms_system.set_SQL_trace_in_session(16,1042,true)

应用执行一段时间后,关闭SQL_trace。

SQL> exec dbms_system.set_SQL_trace_in_session(7,284,false)
SQL> exec dbms_system.set_SQL_trace_in_session(11,214,false)
SQL> exec dbms_system.set_SQL_trace_in_session(16,1042,false)

找到跟踪生成的跟踪文件,然后通过Oracle提供的格式化工具——tkprof对trace文件进行格式化处理,筛查其中消耗时间部分。通过检查,发现类似以下语句的是可疑的。

********************************************************************************
select auditstatus,categoryid,auditlevel from
 categoryarticleassign a,category b where b.id=a.categoryid and articleId=
  20030700400141 and auditstatus>0

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.81       0.81          0       3892         0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.81       0.81          0        3892        0           1
********************************************************************************              

这里的查询显然是根据articleId进行新闻读取的。但是注意到逻辑读有3892,这是较高的一个数字,这个内容引起了我的注意。
接下来的类似查询跟踪得到的执行计划显示,全表访问被执行。

select auditstatus,categoryid from
 categoryarticleassign where articleId=20030700400138 and categoryId in ('63',
  '138','139','140','141','142','143','144','168','213','292','341''-1')
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      4.91       4.91          0       2835          7           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      4.91       4.91          0       2835          7           1

Rows     Row Source Operation
-------  ---------------------------------------------------
      1 TABLE ACCESS FULL CATEGORYARTICLEASSIGN

登录数据库,检查相应表结构,看是否存在有效的索引,以下输出中的IDX_ARTICLEID是基于ARTICLEID创建的,但是在以上查询中都没有被用到。

SQL> select index_name,table_name,column_name from user_ind_columns
  2  where table_name=upper('categoryarticleassign');
INDEX_NAME                     TABLE_NAME                     COLUMN_NAME                    
------------------------------ ------------------------------ --------------------           
IDX_ARTICLEID                  CATEGORYARTICLEASSIGN          ARTICLEID
IND_ARTICLEID_CATEG            CATEGORYARTICLEASSIGN          ARTICLEID                     
IND_ARTICLEID_CATEG            CATEGORYARTICLEASSIGN          CATEGORYID                    
IDX_SORTID                     CATEGORYARTICLEASSIGN          SORTID                        
PK_CATEGORYARTICLEASSIGN       CATEGORYARTICLEASSIGN          ARTICLEID                     
PK_CATEGORYARTICLEASSIGN       CATEGORYARTICLEASSIGN          CATEGORYID                    
PK_CATEGORYARTICLEASSIGN       CATEGORYARTICLEASSIGN          ASSIGNTYPE                    

检查下表结构。

SQL> desc categoryarticleassign
 Name                                      Null?    Type
 ----------------------------------------- -------- ----------------------------
 CATEGORYID                                NOT NULL NUMBER
 ARTICLEID                                 NOT NULL VARCHAR2(14)
 ASSIGNTYPE                                NOT NULL VARCHAR2(1)
 AUDITSTATUS                               NOT NULL NUMBER
 SORTID                                    NOT NULL NUMBER
 UNPASS                                             VARCHAR2(255) 

分析表结构发现了问题所在,因为ARTICLEID是个字符型数据,查询中给入的articleId= 20030700400141 是一个数字值,Oracle执行查询时需要将ARTICLEID转换为数字和给定值进行比较,发生潜在的数据类型转换,这就导致了索引不能被采用,产生了全表扫描的执行计划,在客户的系统中大量类似如下的SQL在通过全表扫描产生大量的IO操作。

SQL>  select auditstatus,categoryid
  2   from categoryarticleassign where articleId=20030700400132;
AUDITSTATUS CATEGORYID                                     
----------- ----------                                     
          9         94                                     
          0        383                                     
          0        695                                     
Execution Plan
----------------------------------------------------------                 
   0      SELECT STATEMENT Optimizer=CHOOSE (Cost=110 Card=2 Bytes=38)    
   1    0   TABLE ACCESS (FULL) OF 'CATEGORYARTICLEASSIGN' (Cost=110 Card=2 Bytes=38)   

在这里很有必要解释一下Oracle数据库的数据转换,以下一段内容主要来自官方文档的介绍(依据Oracle 12c版本)。

通常一个表达式不能包含不同的数据类型,例如一个表达式不能计算5x10之后再加上’JAMES’,数字和字符无法进行联合的计算。然而,Oracle支持显示和隐式的数据类型转换,可以将一种数据类型转换为另一种,从而使得某些表达式的运算可以正确执行。显示转换是指通过函数明确指定的数据类型转换,而隐式转换则指未明确指定,依赖Oracle自动进行的数据类型转换。
基于以下几个原因,Oracle推荐使用显示类型转换而不是依赖隐式转换。
(1)使用显示转换使得SQL含义更容易被理解。
(2)隐式数据类型转换会产生负面的性能影响,尤其是当列值被转换成其他常量的数据类型时。
(3)隐式转换的行为依赖每次转换时的环境如数据库参数设置等,其行为可能多变而不确定,例如将datetime值隐式转换为VARCHAR2,这个转换的格式和NLS_DATE_FORMAT 参数有关,可能产生不可预期的结果。
(4)隐式转换的算法会因数据库版本而不同,而显示转换则可以预期。
(5)如果隐式转换发生在索引列,则Oracle可能用不到索引而影响性能。
在现实的开发环境中,绝大多数隐式转换是开发者无意中引入的,但却导致了大量的性能问题。这个案例就处于这样的场景之中。

要知道,在字符和数字进行比对时,Oracle总是将字符转换为数字进行比对。解决本例问题的方法很简单,只须在传入参数两侧各增加一个单引号使其作为字符传入,即可解决这个问题。重新测试类似的查询,可以发现Query模式逻辑读降低为2,占用CPU时间也大大减少。

********************************************************************************
select unpass from
 categoryarticleassign where articleid='20030320000682' and categoryid='113' 

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.00       0.00          0          2          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.00          0          2          0           0

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  TABLE ACCESS BY INDEX ROWID CATEGORYARTICLEASSIGN 
      1   INDEX RANGE SCAN (object id 3080)
********************************************************************************

至此,这个问题得到了完满的解决。但是关于隐式转换的故事还远远没有结束。

在从事数据库工作多年之后,我们发现大多数DBA仍然在面对我们10多年前面对的同样问题,仍然频繁地在解决系统中的隐式转换、索引失效、全表扫描问题。重复的工作就必须找出更高效的、自动化的手段去消解,这也是今天DevOps时代的要义之一

我们的理念就是,从遇到的问题总结规则,聚规则而成规范,由规范衍生工具,通过工具替代人力
如果从以上案例总结规范,至少有以下两条需要开发去注意改进。
(1)使用绑定变量——绑定变量可以减少硬解析,带来性能上的改进,这是最基本的开发实践。
(2)避免隐式转换——隐式转换可能带来索引失效影响性能,也会产生不可预期的程序效果,应当尽量避免。

一个DBA如果能够从实践中不断积累、提炼、上升,那么就能够在企业技术架构中承载更重要的使命和职责。

以上整个问题的改善,事实上就是在运维Ops的过程中,发现开发Dev中存在的问题,如果能够进而通过运维去促进开发,提升运维,这就是DevOps的使命和范畴了。

在现实环境中,我们在很多系统中都看到,大量的性能问题都是由于简单的疏忽导致的,而且由于问题的隐蔽性等,这些问题一旦在线上爆发出来,会给诊断优化带来相当的难度,同时会影响业务的正常运行,所以完善的规范和良好的编码对于一个系统来说是至关重要的。DevOps在Oracle数据库开发中的最佳实践至少可以包括以下两点。
(1)基于运维的开发培训——通过运维中的实践总结,将规则方法推进到开发端,持续改进开发质量。
(2)优化前置的SQL审核——将事后救火变更为事前审核,在开发测试阶段发现和解决问题。

治本永远强于治标。

3 系统递归调用的跟踪
很多时候在进行数据库DDL操作时,Oracle会在后台将这些操作转换为一系列的DML和查询操作。如果其中的某个步骤出现异常,通常其错误提示不容易判定问题所在。这时候跟踪的作用就体现出来。
以下错误是在一次DROP USER中出现的,单从类似这样的提示来看,很多时候是没有丝毫用处的。

ORA-00604: error occurred at recursive SQL level 1 
ORA-00942: table or view does not exist .

关于 recursive SQL 错误,我们有必要做个简单说明。

当我们发出一条简单的DDL命令以后,Oracle数据库要在后台解析这条命令,并转换为Oracle数据库的一系列后台操作。这些后台操作统称为递归SQL。
比如create table这样一条简单的DDL命令,Oracle数据库在后台,实际上要把这个命令转换为对于obj、tab、col$等底层表的插入操作。对于drop table操作,则是在这些系统表中进行反向删除操作。
在面对这样的问题时,通过SQL_trace进行后台跟踪,就可以进一步了解Oracle数据库的后台操作,找出问题点。

SQL> alter session set SQL_trace=true;
SQL> drop user wapcomm;
ORA-00604: error occurred at recursive SQL level 1 
ORA-00942: table or view does not exist .
SQL> alter session set SQL_trace=false;

格式化(使用tkprof)跟踪文件后,我们获得以下输出(摘录部分)。

********************************************************************************
The following statement encountered a error during parse:
DELETE FROM SDO_GEOM_METADATA_TABLE  WHERE SDO_OWNER = 'WAPCOMM' 
Error encountered: ORA-00942
********************************************************************************

drop user wapcomm

********************************************************************************
delete from user_history$ 
where
 user# = :1             -----后台的递归删除操作…

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  DELETE USER_HISTORY$ 
      1   TABLE ACCESS FULL USER_HISTORY$ 

********************************************************************************
declare 
   stmt varchar2(200);
BEGIN
     if dictionary_obj_type = 'USER' THEN
       stmt := 'DELETE FROM SDO_GEOM_METADATA_TABLE ' ||
               ' WHERE SDO_OWNER = ''' || dictionary_obj_name || ''' ';
       EXECUTE IMMEDIATE stmt;
    end if;
end;

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          2           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          0          2           0
********************************************************************************

使用TKPROF格式化以后,Oracle把错误信息首先呈现出来。
ORA-00942错误是由于SDO_GEOM_METADATA_TABLE表/视图不存在所致,问题由此可以定位。对于这一类的错误,定位问题以后解决的方法就要依据具体问题原因而定了。同时可以通过Oracle的官方支持站点MOS(My Oracle Support)去定位是否Bug引起的,是否已经有明确的解决方案。对于本例以关键字SDO_GEOM_METADATA_TABLE检索可以确认这是一个Bug,并且给出了解决方案。

Problem Description 
------------------- 
The Oracle Spatial Option has been installed and you are encountering the following errors while trying to drop a user, who has no spatial tables, connected as SYSTEM: 

ERROR at line 1: 
ORA-00604: error occurred at recursive SQL level 1 
ORA-00942: table or view does not exist 
ORA-06512: at line 7 

A 942 error trace shows the failing SQL statement as: 
DELETE FROM SDO_GEOM_METADATA_TABLE WHERE SDO_OWNER = '<user>' 

Solution Description 
-------------------- 
(1) Create a synonym for SDO_GEOM_METADATA_TABLE under SYSTEM which points to 
MDSYS.SDO_GEOM_METADATA_TABLE. 
(2) Now the user can be dropped connected as SYSTEM. 

对于本例,为MDSYS.SDO_GEOM_METADATA_TABLE创建一个同义词即可解决,是相对简单的情况。这是一个Oracle早期版本的问题,只是这样的分析方法应当被DBA掌握。
跟踪的目标就是,找出根源,解决问题。只要能够找出问题的根源,或者接近根源,那么距离解决问题也就不远了。我推荐的提问方式也是,当遇到问题时,通过跟踪、日志分析更进一步,而不是只依据浅层的表象提出。

「喜欢文章,快来给作者赞赏墨值吧」

评论

0
0
墨值排行
今日本周综合
近期活动
全部
相关课程
全部