暂无图片
暂无图片
暂无图片
暂无图片
暂无图片
首页 / 故障分享：cursor: pin S wait on X故障

故障分享：cursor: pin S wait on X故障

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



问题描述



数据库侧接到告警短信“数据库等待事件:cursor: pin S wait on X数量: 67,超过告警阈值:60”，同时，接到业务电话反馈：业务系统不可用，执行SQL没动静，初步判断数据库处于Hang死状态。



处理过程



2.1 登录检查数据库运行情况

发现自 18:06:55 开始，第1至第4个实例有大量 “cursor: pin S wait on X” 等待事件和少量 ‘library cache lock’事件。
SAMPLE_TIME CON_ID EVENT count count count count
----------------------- ------ ----------------------- -------- -------- -------- --------
2023-11-23 18:06:55.379 4 cursor: pin S wait on X 19
2023-11-23 18:06:55.379 4 library cache lock                                        1
2023-11-23 18:06:55.491      4 cursor: pin S wait on X 14
2023-11-23 18:06:55.491      4 library cache lock                      1
2023-11-23 18:06:55.555      4 cursor: pin S wait on X 34
2023-11-23 18:06:55.555      4 library cache lock                               2
2023-11-23 18:06:56.017      4 cursor: pin S wait on X 25
2023-11-23 18:06:56.017      4 library cache lock             1
2023-11-23 18:06:56.389      4 cursor: pin S wait on X 32
2023-11-23 18:06:56.389      4 library cache lock                                        1
2023-11-23 18:06:56.498      4 cursor: pin S wait on X 27
2023-11-23 18:06:56.498      4 library cache lock                      1
2023-11-23 18:06:56.563      4 cursor: pin S wait on X 55
2023-11-23 18:06:56.563      4 library cache lock                               2
2023-11-23 18:06:57.027      4 cursor: pin S wait on X 49
2023-11-23 18:06:57.027      4 library cache lock             1
2023-11-23 18:06:57.401      4 cursor: pin S wait on X 43
2023-11-23 18:06:57.401      4 library cache lock                                        1
2023-11-23 18:06:57.508      4 cursor: pin S wait on X 46
2023-11-23 18:06:57.508      4 library cache lock                      1
2023-11-23 18:06:57.572      4 cursor: pin S wait on X 67
2023-11-23 18:06:57.572      4 library cache lock                               2
2023-11-23 18:06:58.034      4 cursor: pin S wait on X 56
2023-11-23 18:06:58.034      4 library cache lock             1
2023-11-23 18:06:58.413      4 cursor: pin S wait on X 46
2023-11-23 18:06:58.413      4 library cache lock                                        1
2023-11-23 18:06:58.516      4 cursor: pin S wait on X 47
2023-11-23 18:06:58.516      4 library cache lock                      1
2023-11-23 18:06:58.582      4 cursor: pin S wait on X 67
2023-11-23 18:06:58.582      4 library cache lock                               2
2023-11-23 18:06:59.044      4 cursor: pin S wait on X 56
2023-11-23 18:06:59.044      4 library cache lock             1
2023-11-23 18:06:59.425      4 cursor: pin S wait on X 46
2023-11-23 18:06:59.425      4 library cache lock                                        1
2023-11-23 18:06:59.526      4 cursor: pin S wait on X 47
2023-11-23 18:06:59.526      4 library cache lock                      1
2023-11-23 18:06:59.589      4 cursor: pin S wait on X 67
2023-11-23 18:06:59.589      4 library cache lock                               2
2023-11-23 18:07:00.053      4 cursor: pin S wait on X 56
2023-11-23 18:07:00.053      4 library cache lock             1
2023-11-23 18:07:00.433      4 cursor: pin S wait on X 46
2023-11-23 18:07:00.433      4 library cache lock                                        1
2023-11-23 18:07:00.533      4 cursor: pin S wait on X 47
2023-11-23 18:07:00.533      4 library cache lock                      1
2023-11-23 18:07:00.598      4 cursor: pin S wait on X 67
2023-11-23 18:07:00.598      4 library cache lock                               2
2023-11-23 18:07:01.063      4 cursor: pin S wait on X 56
2023-11-23 18:07:01.063      4 library cache lock             1
2.2 根据等待事件发生的时间，进一步分析 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
2.3 ‘library cache lock’一般和 SQL 解析有关，继续分析两条 SQL
发现都和对象 XXX.xxx有关，且其中一条为 DDL 操作，据此，基本可以判断是 DDL 操作导致所涉及对象相关的所有游标重新解析，引发 ‘library cache lock’（库缓存争用），下面使用审计日志进一步确认。
-- 8wsunm3bg8tdm
alter table xxx add constraint FK9un3grchexpnpguj72301rt94 foreign key (app_id) references sys_app

-- du56vfn2ar1c9
SELECT m.*
FROM xxx_permission m,
xxx_u_permission um,
xxx_app a,
xxx__info_full u
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)
……
2.4 审计日志显示，18:04:11开始，用户 XX 对多个表执行了多次 DDL 操作（ALTER TABLE） ，其中包括表XX.XXX
至此，问题完全确认由DDL 引发。
另外，根据执行返回的代码 2268，说明创建参考约束并未成功，因为相关表没有主键或唯一索引。




总结及解决方法



3..1 问题总结

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

1）解决方法

临时解决方法：杀掉相关会话，暂停相关 DDL 和 SQL 执行。

2）建议措施

建议业务在执行 DDL 操作时，严格审查对操作对象关联业务可能产生的影响，首先要避开繁忙时段，同时优化DDL操作逻辑，做好前置条件检查，避免重复无效操作加重问题。

END


本文作者：智 源(上海新炬中北团队）

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

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

评论