别急着加内存!一次由MySQL锁表引发的OOM连环案,我是这样一步步揪出真凶的

张开发
2026/4/16 23:12:34 15 分钟阅读

分享文章

别急着加内存!一次由MySQL锁表引发的OOM连环案,我是这样一步步揪出真凶的
从OOM到MySQL锁表一场内存泄漏背后的蝴蝶效应凌晨三点报警短信的震动声划破了夜的寂静——生产环境又出现了OOM崩溃。作为团队的技术负责人我揉了揉酸胀的眼睛意识到这绝不是简单的内存不足问题。三周前我们刚给服务器扩容了32GB内存而此刻系统却在低流量时段再次崩溃。这种反直觉的现象暗示着一个更深层次的蝴蝶效应某个看似无关的组件故障正通过系统内部的复杂耦合最终演变成内存灾难。1. 第一现场OOM背后的蛛丝马迹登录服务器后我首先通过dmesg -T查看内核日志发现了那个熟悉的杀手[Fri Jul 15 03:12:47 2022] Memory cgroup out of memory: Kill process 28741 (java) score 998 or sacrifice childLinux的OOM Killer机制就像个冷酷的刽子手当系统内存耗尽时它会根据score选择牺牲品。但我们的Java进程得分高达998通常300以上就危险了这意味着它不仅是内存消耗大户还可能是导致系统不稳定的元凶。进一步检查GC日志发现了更反常的现象# gc.log 2022-07-15T03:12:30.1230800: 34123.456: [Full GC (Ergonomics) 34123.789: [SoftReference, 0.023 secs]34123.812: [WeakReference, 0.001 secs] 34123.813: [FinalReference, 0.003 secs]34123.816: [PhantomReference, 0.002 secs] , 4.231 secs]在崩溃前的五分钟内系统竟然触发了7次Full GC每次耗时都超过4秒。这种GC死亡螺旋GC Death Spiral是典型的内存泄漏征兆——JVM拼命回收却只能释放微不足道的空间。提示当发现Full GC频率超过1次/分钟或单次耗时3秒时就应该立即进入战备状态2. 线索交叉验证非常规的排查路径2.1 Redis连接池的异常信号业务日志中大量出现的错误引起了我的注意redis.clients.jedis.exceptions.JedisConnectionException: Could not get a resource from the pool这个看似普通的连接池耗尽错误结合jstack输出的线程堆栈却揭示了更复杂的情况http-nio-8080-exec-42 #327 daemon prio5 os_prio0 tid0x00007f8a5c01e800 nid0x7a2f waiting on condition [0x00007f8a3d7f7000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for 0x00000006c0c5c1b8 (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) at org.apache.commons.pool2.impl.LinkedBlockingDeque.pollFirst(LinkedBlockingDeque.java:584) at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:442) at redis.clients.util.Pool.getResource(Pool.java:50)关键发现200线程卡在获取Redis连接每个等待线程都持有30-50MB的堆内存连接池配置为100但实际需求峰值可达3002.2 数据库锁的隐藏代价继续深挖线程堆栈发现了更令人震惊的模式quartzScheduler_Worker-7 #178 prio5 os_prio0 tid0x00007f8a6403a000 nid0x6e2f waiting for monitor entry [0x00007f8a4a6f6000] java.lang.Thread.State: BLOCKED (on object monitor) at com.mysql.jdbc.ConnectionImpl.getTransactionIsolation(ConnectionImpl.java:3114) - waiting to lock 0x00000006c1a3b8a0 (a com.mysql.jdbc.JDBC4Connection) at org.apache.ibatis.transaction.jdbc.JdbcTransaction.getTimeout(JdbcTransaction.java:133)数据库监控显示同一时段出现了大量锁等待超时SHOW ENGINE INNODB STATUS; ---TRANSACTION 2A8B9C, ACTIVE 255 sec fetching rows mysql tables in use 1, locked 1 LOCK WAIT 6 lock struct(s), heap size 1136, 3 row lock(s) MySQL thread id 423, OS thread handle 140230, query id 10283 10.0.0.1 app_user SELECT * FROM session_rec WHERE TIMESTAMPDIFF(HOUR, update_time, NOW()) 6这个每小时执行一次的定时任务由于缺少合适的索引导致全表扫描并锁定了数百万行记录。更糟糕的是它与其他关键业务操作产生了死锁链业务线程A先获取Redis锁然后尝试更新session_rec表中的记录定时任务B锁定了整张表业务线程A等待表锁释放持有Redis连接不释放后续请求因Redis连接池耗尽而阻塞3. 根因分析系统性的设计缺陷3.1 索引缺失的连锁反应通过EXPLAIN分析慢查询揭示了问题本质EXPLAIN SELECT * FROM session_rec WHERE TIMESTAMPDIFF(HOUR, update_time, NOW()) 6;idselect_typetabletypepossible_keyskeykey_lenrowsExtra1SIMPLEsession_recALLNULLNULLNULL4832912Using where关键问题对update_time使用了函数计算导致索引失效没有为查询条件创建合适的索引全表扫描导致锁持续时间过长3.2 资源管理的反模式内存分析报告显示系统中存在多种资源泄漏模式// 反模式1不必要的对象创建 public MapString, String parseRequest(HttpServletRequest req) { MapString, String params new HashMap(); // 每次调用新建Map EnumerationString names req.getParameterNames(); while (names.hasMoreElements()) { String name names.nextElement(); params.put(name.trim(), req.getParameter(name).trim()); } return params; } // 反模式2连接未正确释放 public void validateTicket(String ticket) { Jedis jedis pool.getResource(); try { // 业务逻辑 updateSession(ticket); // 如果这里发生锁等待... } finally { // 由于锁等待可能永远执行不到这里 jedis.close(); } }通过jvisualvm分析堆转储文件发现了内存消耗大户对象类型实例数占用内存char[]482,3311.2GBHashMap$Node156,822873MBJedis9745MBMySQL Connection8338MB4. 解决方案从应急止血到架构改造4.1 紧急应对措施索引优化ALTER TABLE session_rec ADD COLUMN expire_flag TINYINT(1) GENERATED ALWAYS AS (IF(TIMESTAMPDIFF(HOUR, update_time, NOW()) 6, 1, NULL)) VIRTUAL, ADD INDEX idx_expire (expire_flag);连接池调整# application.yml spring: redis: pool: max-active: 300 max-wait: 1000ms datasource: hikari: max-lifetime: 600000 leak-detection-threshold: 5000代码热修复// 使用ThreadLocal重用Map对象 private static final ThreadLocalMapString, String REQUEST_MAP ThreadLocal.withInitial(() - new HashMap(16)); public MapString, String parseRequest(HttpServletRequest req) { MapString, String params REQUEST_MAP.get(); params.clear(); // ...填充数据 return params; }4.2 长期架构改进会话存储迁移// 将会话数据迁移到Redis public void updateSession(String sessionId) { String key session: sessionId; try (Jedis jedis pool.getResource()) { jedis.hset(key, lastActive, System.currentTimeMillis()); jedis.expire(key, 6 * 3600); } }定时任务重构// 使用Redis SCAN替代全表查询 public void cleanExpiredSessions() { String pattern session:*; try (Jedis jedis pool.getResource()) { String cursor 0; do { ScanResultString scan jedis.scan(cursor, new ScanParams().match(pattern).count(100)); cursor scan.getCursor(); scan.getResult().forEach(key - { if (jedis.hget(key, lastActive) ! null System.currentTimeMillis() - Long.parseLong(jedis.hget(key, lastActive)) 6 * 3600 * 1000) { jedis.del(key); } }); } while (!cursor.equals(0)); } }内存监控体系# 增加JVM监控参数 JAVA_OPTS$JAVA_OPTS -XX:HeapDumpOnOutOfMemoryError -XX:HeapDumpPath/var/log/heapdump.hprof -XX:NativeMemoryTrackingdetail -XX:UnlockDiagnosticVMOptions -XX:PrintNMTStatistics这场持续三周的排查之旅教会我现代分布式系统的问题从不会乖乖待在它出现的地方。当看到内存报警时真正的凶手可能正在数据库里悠闲地锁着表。关键是要建立全局视角通过日志、监控、代码的三维交叉验证才能揪出那些藏在因果关系链条深处的真凶。

更多文章