ARTICLE DETAIL

资讯详情

深耕郑州网站建设与运营推广的一线实战洞察。

故障复盘:P95延迟飙升背后的缓存击穿与连接池加固

故障复盘:P95延迟飙升背后的缓存击穿与连接池加固 大半夜被值班电话叫醒屏幕上弹出一条告警核心接口的P95延迟从80ms爬到了500ms。这原本是季度第七个运行维护专项启动后的第一周我们要做的就是对核心交易链路的缓存和数据库层做一次全面加固结果还没等我动手故障倒先找上门了。这就是运行维护这个行当最真实的日常——你永远不知道计划里的哪一项会突然变成一场战役。跟大家交代一下背景。No.7是我们团队本季度的第七个运维专项编号按季度排每个季度从事故记录、容量告警、历史隐患清单里挑出七个重点维护项目第七个通常是那个看起来最不起眼、却最容易在关键时刻掉链子的缓存与数据库链路的隐性风险治理。这篇内容不是讲怎么开发新功能也不是讲架构设计它就是一次完整的运行维护实战记录从告警发现、逐层排查、问题定位、变更修复到事后把经验固化成巡检机制。如果你是运维、SRE、偏后端的开发或者正在为自己的系统稳定性发愁这篇值得从头看到尾。1. 运行维护这个No.7编号背后我们到底在维护什么1.1 季度七个专项为什么单独挑出No.7先说说运行维护这四个字的实际分量。很多人觉得运维就是看看监控、处理告警、重启服务真不是这样。一个系统长期跑在生产环境里会产生大量温水煮青蛙式的隐患磁盘慢慢满了、连接慢慢泄漏了、缓存命中率悄悄掉了、某些配置从上线那天起就没对过。这些事单看都不致命但叠加起来会在某个流量高峰突然爆给你看。No.7专项就是从这些隐患清单里筛选出来的。前六个专项分别处理了磁盘容量规划、日志采集链路改造、定时任务集群隔离、网关限流参数标准化、备份恢复演练、容器基础镜像升级。到第七个所有隐患里只剩下一个高优先级项没有动订单查询链路的缓存与数据库层。这个专项的业务背景很直接每次大促前订单查询接口的延迟都会出现明显抖动但大促过后又恢复正常常规监控里看不到明显异常属于典型的查不出来又确实存在的慢性病。1.2 运行维护的日常存量巡检、容量、备份与预案No.7要覆盖的不只是某个具体技术点。做运行维护核心是把系统维持在可预期的状态里。我给自己拆了四类存量工作巡检每天、每周固定检查关键指标比如Redis内存和命中率、MySQL活跃连接数、磁盘IO延迟、应用线程池活跃度。容量按QPS、数据增长趋势、连接数增长趋势做滚动评估提前判断什么时候需要扩容。备份不只做备份还定期演练恢复确保备份不是摆设。预案把可能发生的故障场景写成操作手册明确每一步谁来做什么、几分钟内必须完成。No.7专项启动时我把这四类工作全部聚焦到订单查询链路目标只有一个让这条链路在任何流量形态下都保持稳定。1.3 动手前的基线把大概还行变成可量化指标专项第一周我没有急着改任何配置先做基线测量。运维工作里最忌讳的是一上来就觉得哪里有问题然后凭感觉调参那样改完你根本不知道是变好了还是变坏了。我拉取了订单查询链路七天的核心指标覆盖平峰和高峰两个时段指标项平峰实测值高峰实测值目标值接口P95延迟80ms120ms高峰120ms接口P99延迟130ms260ms高峰220msRedis命中率99.6%99.1%高峰≥99%MySQL活跃连接数45~6080~120高峰300MySQL Threads_created/小时3002000稳定500磁盘IO await1ms3.2ms高峰5ms这张基线表后来成了整个专项的锚点。七天数据收集完我心里大概有数了平峰一切都好高峰连接数增长异常Redis命中率看似还在99%以上但细看热点key的访问分布已经有集中失效的苗头。没想到的是还没等我完成分析一张更刺眼的告警图就把计划打乱了。2. 凌晨两点半的告警P95冲到500ms慢查询日志却是空的2.1 第一反应是慢SQL但日志打了所有人的脸告警是凌晨2点14分触发的。值班同事发来的截图里订单查询接口的P95延迟从80ms一路飙到500msP99更是到了850ms。奇怪的是错误率并没有上升5xx一条都没有就是单纯的慢。按常规经验接口突然变慢十有八九是数据库出现了慢SQL。我第一反应是打开MySQL慢查询日志结果翻遍了最近一小时的日志一条超过1秒的查询都没有。这就有意思了接口明明慢了五倍数据库却清清爽爽好像什么都没发生过一样。后来复盘时我们意识到这个慢查询日志一片空白本身就是关键线索。慢查询日志的阈值我们设在1秒它只能捕捉单次执行超过1秒的语句但那个晚上根本没有任何一条SQL超过1秒真正的问题是大量执行只需要30毫秒的普通查询在某一瞬间同时涌了进来。单个都不慢加起来却把系统拖垮了这种问题慢查询日志永远看不到。2.2 单次查询都不慢接口为什么卡住为了把问题看清楚我先后做了三件事。第一看应用监控中的调用链数据确认慢在哪个环节第二看系统层面的CPU、内存、IO、上下文切换第三看数据库、缓存的实际连接和线程状态。调用链数据比我想象中更说明问题。SkyWalking显示订单查询接口的耗时分布里数据库查询平均只占35msRedis读取平均占12ms主体服务的业务逻辑本身也只有20ms。每一段单独拿出来都完全正常但这些正常的数据合起来接口的P95就是500ms。这意味着什么意味着耗时并不是某一个环节变慢而是请求在环节之间排队。就像去餐厅吃饭每道菜做菜时间都只要五分钟但厨师一次只能接十个单几十桌客人同时涌进来大家光等位就要半小时。2.3 从链路追踪里读出排队信号排队信号其实在监控里一直都有只是平时没人把它当回事。我看了一组之前总被忽略的指标应用线程池的active线程数、数据库活跃连接数、Redis服务端的连接数。凌晨2点半那一刻应用线程池的活跃线程数瞬间拉满数据库活跃连接数从平时高峰的不到120直接冲到接近400Redis的连接数也翻了倍。到这里基本可以确定不是某个DB节点坏了是整个请求链路在那一分钟遭遇了远超预期的并发量把连接资源打穿了。但新的问题又来了订单查询这个接口平时流量很稳定为什么偏偏在那个时间点出现超大并发缓存明明在前面挡着为什么还有这么多请求直接打到数据库这两个疑问直接把我带进了整个专项里最磨人的排查阶段。3. 剥洋葱式排查连接风暴、缓存击穿和一块变心的RAID卡3.1 线程栈里的等待应用层在等连接凌晨排查的第一步我用Arthas抓了一下应用线程栈。这个动作很关键它能直接告诉你应用层的请求到底卡在哪一行代码上。抓下来的线程栈里大片线程停在同一个位置上Druid连接池获取连接的等待队列。通俗点说请求到了应用层想从连接池借一条数据库连接但池子里已经没有空闲连接了所有线程都在排队等别人还连接。当时连接池配置是初始5个连接、最小空闲5个、最大活跃200。正常情况下订单查询服务的连接需求在50条左右峰值也就120条200的上限绰绰有余。可那晚一瞬间涌入的并发量把活跃连接数推到了将近400的请求需求量连接池直接被打到了上限大量的线程只能干等。这里还要提一个坑连接池打满后应用并不会马上报错而是按配置的maxWait参数等待超时时间。我们当时maxWait配的是60000ms也就是最长等60秒这直接导致许多请求的响应时间被拉长到了几百毫秒甚至更久。这也是为什么错误率是0但P95惨不忍睹。3.2 缓存失效时间太整齐热点数据击穿了保护层应用层的问题清楚了那为什么突然有这么多请求需要数据库连接答案要从Redis缓存说起。订单查询接口有一个缓存设计热门商品信息缓存在Redis里TTL统一设成了一小时也就是3600秒。这天晚上恰好有一批大促商品在0点整批量上架这批商品的数据在凌晨1点整集体过期。缓存过期后的那一瞬间所有针对这些商品的查询全部miss直接穿透到数据库。这个机制叫缓存击穿当某个热点key在过期后的瞬间大量并发请求同时去数据库回源缓存形同虚设。我们监控里Redis命中率从99.6%掉到91%看着好像还行但对被击穿的那一批热点key来说命中率就是0。更狠的是击穿和连接池打满是互相放大的缓存miss导致更多请求要拿数据库连接连接拿不到进一步拖慢响应拖慢的响应又会占用连接更久形成恶性循环。3.3 数据库线程反复创建之外磁盘也在偷偷拖后腿到这里缓存击穿和连接池打满已经能解释大部分问题了。但还有一个小细节始终让我不舒服监控里显示的数据库线程创建数量高得离谱Threads_created一小时内超过两万个而正常情况下这个数字应该只有几百。MySQL的社区版本靠thread_cache_size这个参数缓存线程我们当时的配置是0意味着每一个数据库连接关闭后对应的线程直接被销毁下一次新连接进来又重新创建线程。在高并发下这种创建销毁的开销会被放大到不可忽视。磁盘层面的异常是我最后才发现的。iostat显示数据库服务器的写磁盘等待时间从1ms涨到了25ms提升了一个数量级而且这个异常的时间点和接口变慢高度重合。进一步检查RAID卡状态时我看到了一个让人意外的事实磁盘阵列的写策略不知道什么时候从Write Back变成了Write Through。这两个策略的区别不经解释很难懂。Write Back是数据先写入RAID卡缓存卡上电持久化后立即返回成功应用程序完全感知不到磁盘写压力。Write Through则是每一次写入都要直接落盘任何一次磁盘写入都要等物理磁盘真正写完才返回。一旦变成Write ThroughMySQL的redo log提交和doublewrite缓冲的写入都会直线变慢事务提交延迟自然跟着涨。这相当于在缓存击穿、连接风暴之外数据库底层又把写路径的速度上限砍掉了一大截。3.4 三个隐患为何在同一分钟咬合复盘时我们把整条时间线拉平看一切才真正清晰反常的流量高峰大促期间瞬时并发轻松超过平峰三倍以上。缓存过期过于整齐热度最高的商品key在同一秒集体失效击穿保护层。连接池配置过紧、线程缓存缺失应用和数据库的连接资源在压力下迅速耗尽创建线程的开销加剧整体延迟。RAID写策略异常数据库事务提交在底层被拖慢又反向延长了连接占用时间。这四个因素任何一个单独出现最多就是出现几十秒的轻微抖动监控上甚至都不会触发告警。但它们在同一分钟叠加就像四股绳子同时拉紧直接把P95送到了500ms。我还想强调一点RAID写策略为什么变了直到最后也没有一个明确的答案。可能是一次计划内的控制器重启后参数重置也可能是现场同事排查时误操作没有操作审计日志可以追溯。这次经历也让我养成了一个习惯硬件层的配置状态巡检时必须人工核对不能只看应用层和数据库层的监控因为这类底层配置经常是悄无声息变化的。4. 三层修复落地不扩硬件把配置调回该有的样子4.1 缓存层TTL离散化、本地缓存与互斥重建第一优先级的修复放在缓存层风险最低效果最直接。第一步是给缓存TTL做离散化处理。之前所有key统一3600秒改成基础3600秒加上0到300秒的随机偏移量让过期时间在25分钟到65分钟之间均匀散布。这样即便同一批商品在同一个时刻上架它们的缓存也不会再在同一秒集体过期。这个改动看起来很小却是整个问题链条上成本最低、收益最明显的锚点。第二步是引入进程级本地缓存。在应用里加了一层Caffeine缓存TTL只有2秒。这层缓存的目的是承担超热点数据的短期访问压力它是一种微小的冗余不会产生数据一致性问题却能挡住大量重复请求避免它们穿透到Redis和数据库。第三步是给热点key的重建加互斥锁。当业务代码发现缓存miss不会立即请求数据库而是先用Redis的SETNX尝试获取一把重建锁拿到锁的请求负责查询数据库并回填缓存拿不到锁的请求短暂自旋等待后读取缓存结果。在并发极高的瞬间这个方法能把回源数据库的请求数量从几千压到个位数。这里给出一段简化版的实现示意主要体现逻辑完整代码需要配合业务场景细化public Object getOrderInfo(String orderId) { Object local localCache.getIfPresent(orderId); if (local ! null) return local; Object remote redisTemplate.opsForValue().get(orderId); if (remote ! null) { localCache.put(orderId, remote); return remote; } String lockKey lock: orderId; boolean locked tryLock(lockKey, 3, TimeUnit.SECONDS); try { if (locked) { Object data queryFromDb(orderId); long ttl 3600 ThreadLocalRandom.current().nextInt(300); redisTemplate.opsForValue().set(orderId, data, ttl, TimeUnit.SECONDS); localCache.put(orderId, data); return data; } else { Thread.sleep(50); return getOrderInfo(orderId); } } finally { if (locked) unlock(lockKey); } }这段代码的核心不是某个具体方法而是一个顺序问题本地缓存优先Redis其次两个都没命中才尝试回源回源之前必须加锁。4.2 数据库层连接池不是越大越好线程缓存要配齐接下来处理数据库连接和线程配置。这里我要特别纠正一个常见的想法连接池maxActive是不是设置得越大越好越是高并发场景越不能这么干。连接池太大意味着同时可能有几百个线程各自占着连接执行SQL这对MySQL会形成巨大的线程切换开销和锁竞争压力内存占用也会明显上升。合理的方式是结合高峰期的实际需求留出30%到50%的余量而不是无限调大。我们的订单查询服务实际需求高峰在120条连接左右优化后的连接池配置我放在了100条同时把minIdle从5调到了20这样可以保证突发流量到来时池子里已经有一部分准备好的空闲连接而不是临时再去建。initialSize也调整到10maxWait从60000毫秒降到5000毫秒宁可快速失败走降级也不能让线程在队列里干等60秒。调整后的Druid配置大致如下spring: datasource: druid: initial-size: 10 min-idle: 20 max-active: 100 max-wait: 5000 validation-query: SELECT 1 test-while-idle: true test-on-borrow: falseMySQL侧的thread_cache_size也从0调整到了64让短连接关闭后线程能被缓存复用而不是每次都重新创建。同时开启了缓冲池的预热和转储避免数据库重启后冷启动导致的首次访问延迟thread_cache_size 64 innodb_buffer_pool_size 20G innodb_buffer_pool_dump_at_shutdown ON innodb_buffer_pool_load_at_startup ON把连接池调小很多人会担心不够用但实际上我们后续七天的监控验证了活跃连接稳定在80到90之间池子上限几乎没有触顶过。真正消除连接风暴的其实是缓存层的改动连接池只是让有限的连接资源被更高效地用起来。4.3 硬件层把Write Back找回来并重新确认掉电保护硬件层操作需要谨慎最好在确认业务低峰的窗口执行。我们用存储控制器管理工具查了一下RAID组信息日志里明确显示Write Cache Policy是Write Through直接把它切回了Write Back。这个操作本身不复杂复杂的在于切换背后有个前提RAID卡的缓存可以被用于Write Back前提是它的掉电保护模块状态正常。切换到Write Back之前必须要做一次电池或电容的检测。如果掉电保护模块已经失效RAID卡只能在Write Through模式运行强行切回Write Back遇到意外断电可能导致缓存数据丢失那就是更严重的事故。我们当时检查了BBU状态显示正常才放心切换。切换完成后我让每个业务接口按平时的写量跑了一轮压测观察数据库的写延迟和提交时间。最直观的变化是redo log落盘的等待消失磁盘await从25ms降回1ms多。这里补充一个经验RAID写策略属于运维巡检里最容易漏掉的项目因为应用层没有任何报错监控曲线也只是表现为数据库变慢了不会直接告诉你底层写策略变了。除非你明确知道要去看这个配置否则排查方向很容易被带偏。后来我把RAID写策略状态加进了巡检清单每两周人工核对一次。4.4 灰度顺序和回滚预案安全变更的落地纪律三层改动不是一个晚上全部做掉的顺序很重要。我的执行顺序是先缓存再应用连接池和数据库参数最后动硬件。缓存和连接池都属于可快速回滚的逻辑层变更我通过配置中心动态发布不需要重启业务进程。每组变更发布后观察至少一个完整的业务高峰周期确认指标没有反向恶化再进入下一步。硬件层变更安排在周末凌晨的低峰窗口提前准备好回滚脚本一旦切换后写入延迟没有改善或者出现数据异常能立刻切回原策略。每一步变更前我都记录下当时的指标快照变更后保留一份新的快照。这个过程听起来琐碎但在后续复盘和排查时帮了大忙。没有这些快照你很难分辨指标改善是哪个变更带来的。5. 把一次故障换成一套机制巡检、演练与复盘5.1 巡检表里新增的四项隐性指标No.7专项的核心产出不是那次修复而是修复之后沉淀下来的一整套运行维护机制。我做的第一件事是把这次故障里那个完全没被发现的RAID写策略问题变成一项周期性的显性检查。现在每两周执行一次硬件层的配置核对Cache Policy、电池模块状态、磁盘健康状态全部人工确认并留档。巡检表新增的另外三项指标分别是Redis热点key过期分布、连接池活跃连接趋势、MySQL线程创建速率。它们的共同特点是不看平均值只看分布和趋势。Redis命中率99.6%完全可以掩盖一批热点key集体失效但把所有key的过期时间分布画成直方图一眼就能看出过期是否太集中。MySQL的Threads_created单看某一秒没意义拉出一小时的曲线如果持续高位说明线程复用出了问题。5.2 周度容量评估和最小故障演练以前容量评估是月度做一次而且只关心QPS和CPU使用率这类宏观指标。No.7之后我把连接数的预测纳入了周度评估因为这次故障里连接资源才是真正的瓶颈。规则很简单每周记录一次高峰期MySQL活跃连接数按环比增速线性外推如果预测两周后超过连接池上限的80%立刻触发扩容或优化评审。故障演练也增加了两个最小场景缓存集群整体不可用、连接池被打满。最小场景演练只用一个小流量业务分组来做不惊动全部流量但足以验证降级逻辑是否能按预案生效。第一次演练时缓存被禁用后数据库连接直接冲高真实暴露了预案里没有覆盖到的细节依赖方调用DB的并发控制阈值没有设置。这类细节如果没有演练永远不会在故障前被发现。5.3 复盘会上只追问三个问题最后说复盘。这次修复完成后的复盘会我们不再追求写一份长长的行动清单而是只追问三个问题每一个都逼着大家往深处想第一故障链条上的每个环节为什么当时没有被发现比如RAID写策略变化如果巡检覆盖到位就不会拖到故障爆发缓存key过期集中如果看过分布图就能提前发现。第二哪一步原本可以在五分钟内止血答案是直接把连接池maxWait从60秒调成3秒请求会快速失败而不是全部排队至少能保住接口的可用性而不是让所有请求一起变慢。这个动作现在被写进了应急手册的第一页。第三哪些检查应该从人肉巡检变成自动化我们最终把RAID策略核对和缓存过期分布检查都脚本化了接入了监控告警平台不再是人工两周看一次而是系统每五分钟自动扫一遍。复盘不是为了追责而是为了把每一次故障的经验变成系统自带的防御能力。运行维护做到最后拼的不是谁救火快而是谁能提前把火种灭掉。干这行时间久了你会发现大多数故障都不是某一行的代码写错也不是某台机器坏掉而是几个小问题在时间轴上恰好咬合在一起单看每个都微不足道合在一起就是一场事故。No.7专项留给我的最深体会就是维护的本质是在故障咬合之前提前剪断链条。最后再分享一个小经验每次变更结束后把关键指标截个图存到专项目录里三个月后再回来看你会感谢当初这个不起眼的习惯。
返回列表