暂无图片
暂无图片
暂无图片
暂无图片
暂无图片
首页 / ​DDL 操作引发的性能问题

​DDL 操作引发的性能问题

IT那活儿 2024-04-30
336
点击上方“IT那活儿”公众号--专注于企业全栈运维技术分享，不管IT什么活儿，干就完了！！！    
一

问题描述

[告警内容]:

[一般告警] PDB_XXX 库-10.128.XXX.XX-PDB_XXX3-数据库等待事件:cursor: pin S wait on X数量: 67,超过告警阈值:60,告警时间:XXXX-11-23 18:10:00。

二

分析定位

登录检查数据库运行情况，发现自 18:06:55 开始，第1至第4个实例有大量 “cursor: pin S wait on X” 等待事件和少量 ‘library cache lock’事件。
1 2 3 4 
SAMPLE_TIME CON_ID EVENT count count count count 
----------------------- ------ ----------------------- -------- -------- -------- -------- 
XXXX-11-23 18:06:55.379 4 cursor: pin S wait on X 19
XXXX-11-23 18:06:55.379 4 library cache lock                                        1
XXXX-11-23 18:06:55.491      4 cursor: pin S wait on X 14
XXXX-11-23 18:06:55.491      4 library cache lock                      1
XXXX-11-23 18:06:55.555      4 cursor: pin S wait on X 34
XXXX-11-23 18:06:55.555      4 library cache lock                               2
XXXX-11-23 18:06:56.017      4 cursor: pin S wait on X 25
XXXX-11-23 18:06:56.017      4 library cache lock             1
XXXX-11-23 18:06:56.389      4 cursor: pin S wait on X 32
XXXX-11-23 18:06:56.389      4 library cache lock                                        1
XXXX-11-23 18:06:56.498      4 cursor: pin S wait on X 27
XXXX-11-23 18:06:56.498      4 library cache lock                      1
XXXX-11-23 18:06:56.563      4 cursor: pin S wait on X 55
XXXX-11-23 18:06:56.563      4 library cache lock                               2
XXXX-11-23 18:06:57.027      4 cursor: pin S wait on X 49
XXXX-11-23 18:06:57.027      4 library cache lock             1
XXXX-11-23 18:06:57.401      4 cursor: pin S wait on X 43
XXXX-11-23 18:06:57.401      4 library cache lock                                        1
XXXX-11-23 18:06:57.508      4 cursor: pin S wait on X 46
XXXX-11-23 18:06:57.508      4 library cache lock                      1
XXXX-11-23 18:06:57.572      4 cursor: pin S wait on X 67
XXXX-11-23 18:06:57.572      4 library cache lock                               2
XXXX-11-23 18:06:58.034      4 cursor: pin S wait on X 56
XXXX-11-23 18:06:58.034      4 library cache lock             1
XXXX-11-23 18:06:58.413      4 cursor: pin S wait on X 46
XXXX-11-23 18:06:58.413      4 library cache lock                                        1
XXXX-11-23 18:06:58.516      4 cursor: pin S wait on X 47
XXXX-11-23 18:06:58.516      4 library cache lock                      1
XXXX-11-23 18:06:58.582      4 cursor: pin S wait on X 67
XXXX-11-23 18:06:58.582      4 library cache lock                               2
XXXX-11-23 18:06:59.044      4 cursor: pin S wait on X 56
XXXX-11-23 18:06:59.044      4 library cache lock             1
XXXX-11-23 18:06:59.425      4 cursor: pin S wait on X 46
XXXX-11-23 18:06:59.425      4 library cache lock                                        1
XXXX-11-23 18:06:59.526      4 cursor: pin S wait on X 47
XXXX-11-23 18:06:59.526      4 library cache lock                      1
XXXX-11-23 18:06:59.589      4 cursor: pin S wait on X 67
XXXX-11-23 18:06:59.589      4 library cache lock                               2
XXXX-11-23 18:07:00.053      4 cursor: pin S wait on X 56
XXXX-11-23 18:07:00.053      4 library cache lock             1
XXXX-11-23 18:07:00.433      4 cursor: pin S wait on X 46
XXXX-11-23 18:07:00.433      4 library cache lock                                        1
XXXX-11-23 18:07:00.533      4 cursor: pin S wait on X 47
XXXX-11-23 18:07:00.533      4 library cache lock                      1
XXXX-11-23 18:07:00.598      4 cursor: pin S wait on X 67
XXXX-11-23 18:07:00.598      4 library cache lock                               2
XXXX-11-23 18:07:01.063      4 cursor: pin S wait on X 56
XXXX-11-23 18:07:01.063      4 library cache lock             1
根据等待事件发生的时间，进一步分析 18:00 至 18:10 时段等待事件详细信息，发现 ‘cursor: pin S wait on X’由 ’library cache lock’引发，且和两条 SQL 有关（8wsunm3bg8tdm & du56vfn2ar1c9）。
Pct Samples Path
------- ------- -------------------------------------------------------------------------------------------
   0.02 1 --> 4 * cr5z7mpyksgnv * latch free
   0.02 1 --> 2 * dr98nmg6xnkum * control file sequential read
   0.02 1 --> 1 * 6bqxwxkk8an9s * latch free
   0.02 1 --> 6 * 6bqxwxkk8an9s * latch free
   0.02 1 --> 4 * 6bqxwxkk8an9s * latch free
   0.02 1 --> 8 * 6bqxwxkk8an9s * latch free
   0.02 1 --> 2 * cr5z7mpyksgnv * latch free
   0.05 2 --> 2 * 8wsunm3bg8tdm * row cache lock
   0.05 2 --> 7 * 6bqxwxkk8an9s * latch free
   0.05 2 --> 2 * 8wsunm3bg8tdm * cursor: pin S wait on X --> 2 * 8wsunm3bg8tdm * row cache lock
   0.07 3 --> 1 * 8wsunm3bg8tdm * row cache lock
   0.07 3 --> 4 * 8wsunm3bg8tdm * cursor: pin S wait on X --> 4 * 8wsunm3bg8tdm * row cache lock
   0.07 3 --> 3 * 8wsunm3bg8tdm * row cache lock --> 3 * 8wsunm3bg8tdm * library cache lock
   0.35 14 --> 4 * 8wsunm3bg8tdm * row cache lock
   0.44 18 --> 3 * du56vfn2ar1c9 * library cache lock
   0.44 18 --> 2 * du56vfn2ar1c9 * library cache lock
   0.44 18 --> 1 * du56vfn2ar1c9 * library cache lock
   0.44 18 --> 3 * 8wsunm3bg8tdm * library cache lock
   0.47 19 --> 4 * du56vfn2ar1c9 * library cache lock
  20.90 846 --> 2 * du56vfn2ar1c9 * cursor: pin S wait on X --> 2 * du56vfn2ar1c9 * library cache lock
  21.25 860 --> 4 * du56vfn2ar1c9 * cursor: pin S wait on X --> 4 * du56vfn2ar1c9 * library cache lock
  24.91 1008 --> 1 * du56vfn2ar1c9 * cursor: pin S wait on X --> 1 * du56vfn2ar1c9 * library cache lock
  29.80 1206 --> 3 * du56vfn2ar1c9 * cursor: pin S wait on X --> 3 * du56vfn2ar1c9 * library cache lock
‘library cache lock’一般和 SQL 解析有关，继续分析两条 SQL，发现都和对象 SMUU. s_permiss有关，且其中一条为 DDL 操作，据此，基本可以判断是 DDL 操作导致所涉及对象相关的所有游标重新解析，引发 ‘library cache lock’（库缓存争用），下面使用审计日志进一步确认。
--8wsunm3bg8tdm
alter table s_XXXX add constraint FK9un3grchexpnpguj72301rt94 foreign key (app_id) references sys_app

--du56vfn2ar1c9
SELECT m.*
  FROM s_XXXX m,
       sys_user_XXXX um,
       sys_XXXX a,
       s_XXX
 WHERE m.id = um.permission_id
   AND u.username = um.username
   AND m.app_id = a.id
   AND a.app_code = :1
   AND u.username = :2
   AND m.enabled = 1
   AND um.enabled = 1
   AND a.enabled = 1
   AND u.enabled = 1
   AND u.status = 0
   AND m.removed_time IS NULL
   AND um.removed_time IS NULL
   AND a.removed_time IS NULL
   AND (u.removed_time IS NULL OR u.removed_time >= SYSDATE)
UNION
SELECT m.*
  FROM s_XXXX m,
       s_o_XXX op,
       s_o_info XXXX,
       sys_user_XXXX uo,
       s_XXX u,
       sys_XX a
 WHERE m.id = rm.permission_id
   AND rm.role_id = r.id
   AND r.id = ur.role_id
   AND ur.username = u.username
   AND m.app_id = a.id
   AND a.app_code = :3
   AND u.username = :4
   AND m.enabled = 1
   AND rm.enabled = 1
   AND r.enabled = 1
   AND ur.enabled = 1
   AND u.enabled = 1
   AND u.status = 0
   AND m.removed_time IS NULL
   AND rm.removed_time IS NULL
   AND r.removed_time IS NULL
   AND ur.removed_time IS NULL
   AND (u.removed_time IS NULL OR u.removed_time >= SYSDATE)
   AND a.removed_time IS NULL
UNION
SELECT m.*
  FROM s_XXXX m,
       s_o_XXX op,
       s_o_info XXXX,
       sys_user_XXXX uo,
       s_XXX u,
       sys_XX a
 WHERE m.id = op.permission_id
   AND op.org_code = oif.org_code
   AND oif.org_code = uo.org_code
   AND uo.username = u.username
   AND m.app_id = a.id
   AND a.app_code = :5
   AND u.username = :6
   AND m.enabled = 1
   AND op.enabled = 1
   AND oif.enabled = 1
   AND uo.enabled = 1
   AND u.enabled = 1
   AND a.enabled = 1
   AND oif.status = 0
   AND uo.status = 0
   AND u.status = 0
   AND m.removed_time IS NULL
   AND op.removed_time IS NULL
   AND oif.removed_time IS NULL
   AND uo.removed_time IS NULL
   AND (u.removed_time IS NULL OR u.removed_time >= SYSDATE)
   AND a.removed_time IS NULL
UNION
SELECT m.*
  FROM sys_XXXX a,
       s_XXXX m,
       s_r_XXXX rm,
       sys_XXXX r,
       sys_role_XXXX rp,
       sys_XXXX p,
       sys_user_XXXX uo,
       s_XXXX u
 WHERE a.id = m.app_id
   AND m.id = rm.permission_id
   AND rm.role_id = r.id
   AND r.id = rp.role_id
   AND rp.position_id = p.id
   AND p.id = uo.position_id
   AND uo.username = u.username
   AND u.username = :7
   AND a.app_code = :8
   AND a.enabled = 1
   AND m.enabled = 1
   AND rm.enabled = 1
   AND r.enabled = 1
   AND rp.enabled = 1
   AND p.enabled = 1
   AND uo.enabled = 1
   AND uo.status = 0
   AND u.enabled = 1
   AND u.status = 0
   AND a.removed_time IS NULL
   AND m.removed_time IS NULL
   AND rm.removed_time IS NULL
   AND r.removed_time IS NULL
   AND rp.removed_time IS NULL
   AND p.removed_time IS NULL
   AND uo.removed_time IS NULL
   AND (u.removed_time IS NULL OR u.removed_time >= SYSDATE)
审计日志显示，18:04:11开始，用户 SMUU 对多个表执行了多次 DDL 操作（ALTER TABLE） ，其中包括表SMUU.S_PERMISS，至此，问题完全确认由DDL 引发。
另外，根据执行返回的代码 2268，说明创建参考约束并未成功，因为相关表没有主键或唯一索引。
TIMESTAMP                       SESSIONID IPADDR           OSUSER DBUSER ACTNAME     CODE OBJSCHEMA OBJNAME              
---------------------------- ------------ ---------------- ------ ------ ----------- ---- --------- ----------------------
XXXX-11-23 18:04:11.461593     3836624006 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:04:11.538499     3836624006 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:04:11.867423     3836624006 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:04:11.890558     3836624006 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:04:11.909562     3836624006 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:04:11.962474     3836624006 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      S_PERMISS       
XXXX-11-23 18:06:54.565366     2928990787 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:06:54.592013     2928990787 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:06:54.912145     2928990787 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:06:54.933272     2928990787 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:06:54.956440     2928990787 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:07:43.709180     2513610042 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:07:43.736482     2513610042 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:07:44.045783     2513610042 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:07:44.065035     2513610042 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:07:44.082373     2513610042 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:36.250555     1779278246 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:36.270484     1779278246 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:36.322776     1779278246 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:36.340584     1779278246 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:36.355577     1779278246 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:38.694321     1717505142 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:38.708921       412563072 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:38.719116     1717505142 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:38.732718       412563072 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:39.037852     1717505142 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:39.045539       412563072 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:39.054086     1717505142 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:39.062666       412563072 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:39.067567     1717505142 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:39.076740       412563072 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:40.686031     2091126810 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:40.704945     2091126810 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:40.755695     2091126810 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:40.772659     2091126810 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:40.786337     2091126810 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:42.581350     1596452985 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:42.601656     1596452985 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:42.651729     1596452985 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:42.668539     1596452985 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:42.683111     1596452985 XX.XX.82.163     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:48.225016     2663225304 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:48.247433     2663225304 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:48.299069     2663225304 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:48.316703     2663225304 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:48.333911     2663225304 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:49.956444      321720639 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:49.975976      321720639 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:50.029532      321720639 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:50.047079      321720639 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:50.061844      321720639 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:56.934140     1621373475 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:56.954474     1621373475 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:57.023062     1621373475 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:57.040943     1621373475 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:57.056757     1621373475 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:57.338492     1837626329 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:57.359799     1837626329 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_ENTRY            
XXXX-11-23 18:09:57.410648     1837626329 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:57.428991     1837626329 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY  
XXXX-11-23 18:09:57.443405     1837626329 XX.XX.82.164     oaapp  SMUU   ALTER TABLE 2268 SMUU      ACL_OBJECT_IDENTITY
三

总结及解决方案

3.1 问题总结
由于在非空闲时段对频繁访问的表 XXX.S_XXXX 执行 DDL 操作（添加参考约束），因此所有与此对象相关的游标（例如 du56vfn2ar1c9）需要重新解析，在此期间引发了库缓存争用，导致数据库性能下降。
业务在执行添加约束操作时，未严格检查参考表主键或唯一索引，导致在18:04 至 19:30 期间，所有的 ALTER TABLE 操作均未执行成功（返回 2268），但操作仍然会导致相关游标重新解析，频繁的失败重试进一步加重数据库负担。
3.2 解决方法
杀掉相关会话，暂停相关 DDL 和 SQL 执行。

END


本文作者：任我行(上海新炬中北团队）

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

cursorddl
文章转载自IT那活儿，如果涉嫌侵权，请发送邮件至：contact@modb.pro进行举报，并提供相关证据，一经查实，墨天轮将立刻删除相关内容。

评论