资讯专栏INFORMATION COLUMN

PLSQL JSON类接口优化

IT那活儿 / 321人阅读
PLSQL JSON类接口优化
点击上方“IT那活儿”公众号,关注后了解更多内容,不管IT什么活儿,干就完了!!!

事件背景

数据库版本:12.1.0.2
上午还没到单位,客户就发微信告知赶紧到单位处理一个请求慢的问题,原本十几秒钟就能完成的请求,现在两三天跑不完,第一时间想到的可能就是plsql代码块中SQL执行出现了问题,很有可能是执行计划发生了改变,到单位上手处理之后,发现事件没有自己想的那么简单,plsql代码块中所有的SQL执行速度都很快,1s中之内就能返回结果。但是请求确确实实跑了两三天才完成。
下图所示中标记的为业务通过程序记录的执行调用时间,6000/60/24=4.xx.最慢的时候程序都已经跑了四天多。


分析过程

2.1 plsql代码块中的相关SQL已经进行了排查,并未发现有什么异常SQL,SQL逻辑很简单。
查看PLSQL对应的等待事件,这里发现是db file sequential read(单块读),通过对应的p1.p2发现一直在等待获取file=63 block=1141320这个数据块,并且根据下面查询,发现对于单个block请求时间长达几十秒钟。
2.2 针对对应的等待事件p1.p2,查询对应的block属于那个对象,这里我们发现是CUX_DWMS_CKD_JOB_LOT_IFACE表单块读较慢。

因查询语句太长这里不方便贴出,具体查看语句见如下地址:

https://www.cnblogs.com/hanglinux/p/16302543.html

2.3 分析到这里我怀疑可能是行链接或者是行迁移导致的性能问题,通过@$ORACLE_HOME/rdbms/admin/utlchain.sql以及chain.sql对相关问题表进行了分析,并未发现有行链接或者行迁移的情况,并针对表信息进行了查询以及相关plsql代码快块中的执行计划进行了排查。
###行迁移信息:
SQL> @chine
Enter the schema name to check for Row Chaining (RETURN for All): CUX
Enter the table name to check (RETURN for All tables owned by CUX): CUX_DWMS_CKD_JOB_LOT_IFACE
No Chained Rows found in the CUX owned Tables!
###表列相关信息:
###索引相关信息:
###表历史统计相关信息:
###表段相关信息,这里发现这个表非常的小,仅仅有3M,对于x8一体机而言即便是循环嵌套的全表扫描,也不可能这么慢,更何况是走的索引扫描。
###plsql代码块中表相关查询语句以及执行计划如下,执行计划也是相当的好,到这里问题分析不下去了,整整纠结了一上午。

chain.sql相关脚本地址如下:

https://www.cnblogs.com/hanglinux/p/16302598.html

2.4 通过ash报告获取当前负载信息
##这里发现改存储过程正在慢的点在于apps.json.put
在plsql代码快中,我们发现了如下信息,使用json结构构造数据,通过上层查询的数据,放入json结构代码中,然后进程转存,正常情况下都是使用java、python或者其他的开发工具进行构造,因为逻辑都是存储过程写的,所以对于构造数据业务模块中都统一使用json结构进行了构造,在和开发的沟通中,我们也定位到plsql执行慢的地方在如下代码块。
2.5 通过对plsql代码块进行日志处理,进一步打印每次循环的时间,每次嵌套大概执行的时间是14s。
上述问题表CUX_DWMS_CKD_JOB_LOT_IFACE大概返回2000-3000行数据,也就是说这个嵌套要执行2000-3000次,这里简单的计算就是大概十几个小时,但是实际情况下,随着嵌套循环的进行,后续的嵌套会越来越慢,嵌套的执行时间也会越来越长,最终导致整个请求在2-3天内无法执行完毕。
2.6 定位到慢的代码,进行分析了json结构块
代码中的如下部分,每次内层嵌套完毕之后,都需要put对如下结构代码进行覆盖,结合ash报告中的TOP PL/SQL Procedures中的信息,我们也是发现这里的apps.json.put执行时间较慢。
l_lotline_json := json();
2.7 问题处理解决
通过以上分析,我们建议将l_lotline_json := json();代码结构直接放到下层循环中,每次新建对象,不需要put覆盖之前的数据,和业务人员进行沟通,再次执行,请求已经恢复到十几秒内完成。
因为自己对于开发不熟,对于这个问题,专门询问了开发的同学,开发同学如下解释:按照java的理论新建一个对象消耗的时间更多,如果把l_lotline_json:= json()如下二层嵌套中,每次就需要新建一个对象,不需要put覆盖之前的数据。但在Oracle实际执行过程中确确实实是因为put覆盖对象导致的业务延迟,原来的业务执行的时候也是没有问题的,其他的类似业务也没有问题,单单对于这个plsql程序出现了情况,这里我也不是很懂。修改后的代码如下:
这里是修改后的代码记录执行时间,说明:12号的其他执行时间是前台取消业务记录的时间,并未执行完毕。



回顾总结

  • 业务反馈请求执行较慢,通过分析plsql代码块SQL执行较快;
  • 通过等待事件发现针对与表CUX_DWMS_CKD_JOB_LOT_IFACE单块扫描较慢时间长达几十秒(这里通过结合plsql代码块嵌套执行缓慢问题也进一步解释了为什么单块读要执行几十秒,也说明了在循环嵌套代码块中不仅仅是每次嵌套要14s,而是随着不断的嵌套循环,执行时间会越来越慢。)
  • 通过对应等待事件p1.p2定位问题对象;
  • 分析问题对象有无问题;
  • 通过ash报告定位plsql代码块程序接口问题;
  • 结合开发,通过plsql代码块打印log,进一步确定问题;
  • 通过改写程序代码,业务请求执行时间由原来的2-3天优化至十几秒。


plsql代码块相关分析思路

4.1 统计hash_value那个语句执行的多
select t.SQL_HASH_VALUE,t.SQL_ID,count(1) from v$session t 
where t.STATUS=ACTIVE and t.sql_hash_value<>0 and 
t.program not like oracle@c6ogx6a (W% group by  
t.SQL_HASH_VALUE,t.SQL_ID order by 3 desc;
4.2 通过ash_top_plsq定位正在执行的子程序
set linesize 120
col entry_package for a25
col entry_procedure for a25
col cur_package for a25
col cur_procedure for a25
col calling_code for a70
select
count(*),
sql_id,
procs1.object_name || decode(procs1.procedure_name,,,.)||
procs1.procedure_name || ||
decode(procs2.object_name,procs1.object_name,,
decode(procs2.object_name,,, => ||procs2.object_name))
||
decode(procs2.procedure_name,procs1.procedure_name,,
decode(procs2.procedure_name,,,null,,.)||procs2.procedure_name)
"calling_code"
from v$active_session_history ash,
all_procedures procs1,
all_procedures procs2
where
ash.PLSQL_ENTRY_OBJECT_ID = procs1.object_id (+)
and ash.PLSQL_ENTRY_SUBPROGRAM_ID = procs1.SUBPROGRAM_ID (+)
and ash.PLSQL_OBJECT_ID = procs2.object_id (+)
and ash.PLSQL_SUBPROGRAM_ID = procs2.SUBPROGRAM_ID (+)
and ash.sample_time > sysdate - &minutes/(60*24)
group by procs1.object_name, procs1.procedure_name,
procs2.object_name, procs2.procedure_name,sql_id
order by count(*)
/
4.3 snapper.sql脚本也可以查询相关信息

##脚本调用查询的其实也是v$active_session_history.PLSQL_ENTRY_OBJECT_ID、PLSQL_ENTRY_OBJECT_ID、PLSQL_SUBPROGRAM_ID相关信息,并不能获取正在慢的程序接口类的结构。

https://tanelpoder.com

4.4 通过ash报告中的TOP PL/SQL Procedures定位正在慢的程序接口
##这里我通过10046获取到到相关的内部执行SQL,但是一些变量值我有点拿不准,也就不贴出来了。观察Oracle内部其实调用了一个内部程序包dbms_ash_internal来获取的子程序以及具体的程序结构代码块

##感兴趣的可以看看,记录在如下地址中:

https://www.cnblogs.com/hanglinux/p/16303325.html

4.5 erp相关plsql优化
对于erp系统而言,正常都有一个SQL可以按照请求号,来查询正在调用的sid,以及正在执行的plsql中的sql_id信息,但有时候也是会出现无法查询到plsql代码中具体SQL的尴尬案例。
比如这次分析的案例,通过客户提供的SQL只能检查到正在执行的plsql代码sql_id,内部的SQL执行确确实实找不到,如果发生此类情况,可能就是正在调用某个接口或者子程序吧。


本文作者:李行行(上海新炬王翦团队)

本文来源:“IT那活儿”公众号

文章版权归作者所有,未经允许请勿转载,若此文章存在违规行为,您可以联系管理员删除。

转载请注明本文地址:https://www.ucloud.cn/yun/129318.html

相关文章

  • Java3y文章目录导航

    摘要:前言由于写的文章已经是有点多了,为了自己和大家的检索方便,于是我就做了这么一个博客导航。 前言 由于写的文章已经是有点多了,为了自己和大家的检索方便,于是我就做了这么一个博客导航。 由于更新比较频繁,因此隔一段时间才会更新目录导航哦~想要获取最新原创的技术文章欢迎关注我的公众号:Java3y Java3y文章目录导航 Java基础 泛型就这么简单 注解就这么简单 Druid数据库连接池...

    KevinYan 评论0 收藏0

发表评论

0条评论

IT那活儿

|高级讲师

TA的文章

阅读更多
最新活动
阅读需要支付1元查看
<