线上故障如何快速排查？来看这套技巧大全

作者 | 小峯
来源 | 阿里技术公众号

前言

线上定位问题时，主要靠监控和日志。一旦超出监控的范围，则排查思路很重要，按照流程化的思路来定位问题，能够让我们在定位问题时从容、淡定，快速的定位到线上的问题。

线上问题定位思维导图

一 服务器层面

1.1 磁盘

1.1.1 问题现象

当磁盘容量不足的时候，应用时常会抛出如下的异常信息：

java.io.IOException: 磁盘空间不足

或是类似如下告警信息：

1.1.2 排查思路

1.1.2.1 利用 df 查询磁盘状态

利用以下指令获取磁盘状态：

df -h

结果是：

可知 / 路径下占用量最大。

1.1.2.2 利用 du 查看文件夹大小

利用以下指令获取目录下文件夹大小：

du -sh *

结果是：

可知root文件夹占用空间最大，然后层层递推找到对应的最大的一个或数个文件夹。

1.1.2.3 利用 ls 查看文件大小

利用以下指令获取目录下文件夹大小：

ls -lh

结果是：

可以找到最大的文件是日志文件，然后使用rm指令进行移除以释放磁盘。

1.1.3 相关命令

1.1.3.1 df

主要是用于显示目前在 Linux 系统上的文件系统磁盘使用情况统计。

（1）常用参数

启动参数：

（2）结果参数


1.1.3.2 du

主要是为了显示目录或文件的大小。

（1）常用参数

启动参数：

（2）结果参数

1.1.3.3 ls

主要是用于显示指定工作目录下的内容的信息。

（1）常用参数

启动参数：

（2）结果参数

1.2 CPU过高

1.2.1 问题现象

当CPU过高的时候，接口性能会快速下降，同时监控也会开始报警。

1.2.2 排查思路

1.2.2.1 利用 top 查询CPU使用率最高的进程

利用以下指令获取系统CPU使用率信息：

top

结果是：

从而可以得知pid为14201的进程使用CPU最高。

1.2.3 相关命令

1.2.3.1 top

（1）常用参数

启动参数：

top进程内指令参数：

（2）结果参数

二 应用层面

2.1 Tomcat假死案例分析

2.1.1 发现问题

监控平台发现某个Tomcat节点已经无法采集到数据，连上服务器查看服务器进程还在，netstat -anop|grep 8001端口也有监听，查看日志打印时断时续。

2.2.2 查询日志

查看NG日志，发现有数据进入到当前服务器（有8001和8002两个Tomcat），NG显示8002节点访问正常，8001节点有404错误打印，说明Tomcat已经处于假死状态，这个Tomcat已经不能正常工作了。

过滤Tomcat节点的日志，发现有OOM的异常,但是重启后，有时候Tomcat挂掉后，又不会打印如下OOM的异常：

TopicNewController.getTopicSoftList() error="Java heap space 
From class java.lang.OutOfMemoryError"appstore_apitomcat

2.2.3 获取内存快照

在一次OOM发生后立刻抓取内存快照,需要执行命令的用户与JAVA进程启动用户是同一个，否则会有异常：

/data/program/jdk/bin/jmap -dump:live,format=b,file=/home/www/jmaplogs/jmap-8001-2.bin 18760

ps -ef|grep store.cn.xml|grep -v grep|awk '{print $2}'|xargs /data/program/jdk-1.8.0_11/bin/jmap -dump:live,format=b,file=api.bin

内存dump文件比较大，有1.4G，先压缩，然后拉取到本地用7ZIP解压。

linux压缩dump为.tgz。

在windows下用7zip需要经过2步解压：

.bin.tgz---.bin.tar--.bin

2.2.4 分析内存快照文件

使用Memory Analyzer解析dump文件，发现有很明显的内存泄漏提示。

点击查看详情，发现定位到了代码的具体某行，一目了然：

查看shallow heap与retained heap能发现生成了大量的Object(810325个对象)，后面分析代码发现是上报softItem对象超过300多万个对象，在循环的时候，所有的数据全部保存在某个方法中无法释放，导致内存堆积到1.5G，从而超过了JVM分配的最大数，从而出现OOM。

java.lang.Object[810325] @ 0xb0e971e0

2.2.5 相关知识

2.2.5.1 JVM内存

2.2.5.2 内存分配的流程

如果通过逃逸分析，则会先在TLAB分配，如果不满足条件才在Eden上分配。

2.2.4.3 GC

（1）GC触发的场景

2）GC Roots

GC Roots有4种对象：

• 虚拟机栈(栈桢中的本地变量表)中的引用的对象，就是平时所指的java对象，存放在堆中。

• 方法区中的类静态属性引用的对象，一般指被static修饰引用的对象，加载类的时候就加载到内存中。

• 方法区中的常量引用的对象。

• 本地方法栈中JNI（native方法)引用的对象。

（3）GC算法

• 串行只使用单条GC线程进行处理，而并行则使用多条。

• 多核情况下，并行一般更有执行效率，但是单核情况下，并行未必比串行更有效率。

• STW会暂停所有应用线程的执行，等待GC线程完成后再继续执行应用线程，从而会导致短时间内应用无响应。

• Concurrent会导致GC线程和应用线程并发执行，因此应用线程和GC线程互相抢用CPU，从而会导致出现浮动垃圾，同时GC时间不可控。

（4）新生代使用的GC算法

• 新生代算法都是基于Coping的，速度快。

• Parallel Scavenge：吞吐量优先。
• • 吞吐量=运行用户代码时间 /（运行用户代码时间 + 垃圾收集时间）

（5）老年代使用的GC算法

Parallel Compacting

Concurrent Mark-Sweep(CMS)

（6）垃圾收集器总结

（7）实际场景中算法使用的组合

（8）GC日志格式

（a）监控内存的OOM场景

不要在线上使用jmap手动抓取内存快照，其一系统OOM时手工触发已经来不及，另外在生成dump文件时会占用系统内存资源，导致系统崩溃。只需要在JVM启动参数中提取设置如下参数，一旦OOM触发会自动生成对应的文件，用MAT分析即可。

# 内存OOM时，自动生成dump文件 
-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data/logs/

如果Young GC比较频繁，5S内有打印一条，或者有Old GC的打印，代表内存设置过小或者有内存泄漏，此时需要抓取内存快照进行分享。

（b）Young Gc日志

2020-09-23T01:45:05.487+0800: 126221.918: [GC (Allocation Failure) 2020-09-23T01:45:05.487+0800: 126221.918: [ParNew: 1750755K->2896K(1922432K), 0.0409026 secs] 1867906K->120367K(4019584K), 0.0412358 secs] [Times: user=0.13 sys=0.01, real=0.04 secs]

（c）Old GC日志

2020-10-27T20:27:57.733+0800: 639877.297: [Full GC (Heap Inspection Initiated GC) 2020-10-27T20:27:57.733+0800: 639877.297: [CMS: 165992K->120406K(524288K), 0.7776748 secs] 329034K->120406K(1004928K), [Metaspace: 178787K->178787K(1216512K)], 0.7787158 secs] [Times: user=0.71 sys=0.00, real=0.78 secs]

2.2 应用CPU过高

2.2.1 发现问题

一般情况下会有监控告警进行提示：

2.2.2 查找问题进程

利用top查到占用cpu最高的进程pid为14，结果图如下：

2.2.3 查找问题线程

利用 top -H -p 查看进程内占用cpu最高线程，从下图可知，问题线程主要是activeCpu Thread，其pid为417。

2.2.4 查询线程详细信息

• 首先利用 printf "%x \n" 将tid换为十六进制：xid。

• 再利用 jstack | grep nid=0x -A 10 查询线程信息(若进程无响应，则使用 jstack -f )，信息如下：

2.2.5 分析代码

由上一步可知该问题是由 CpuThread.java 类引发的，故查询项目代码，获得如下信息：

2.2.6 获得结论

根据代码和日志分析，可知是由于限制值max太大，致使线程长时间循环执行，从而导致问题出现。

三 Mysql

3.1 死锁

3.1.1 问题出现

最近线上随着流量变大，突然开始报如下异常，即发生了死锁问题：

Deadlock found when trying to get lock; try restarting transaction ;

3.1.2 问题分析

3.1.2.1 查询事务隔离级别

利用 select @@tx_isolation 命令获取到数据库隔离级别信息：

3.1.2.2 查询数据库死锁日志

利用 show engine innodb status 命令获取到如下死锁信息：


由上可知，是由于两个事物对这条记录同时持有S锁(共享锁)的情况下，再次尝试获取该条记录的X锁(排它锁)，从而导致互相等待引发死锁。

3.1.2.3 分析代码

根据死锁日志的SQL语句，定位获取到如下伪代码逻辑：

@Transactional(rollbackFor = Exception.class)
void saveOrUpdate(MeetingInfo info) {
    // insert ignore into table values (...)
    int result = mapper.insertIgnore(info);
    if (result>0) {
       return;
    }
    // update table set xx=xx where id = xx
    mapper.update(info);
}

3.1.2.4 获得结论

分析获得产生问题的加锁时序如下，然后修改代码实现以解决该问题。

3.2 慢SQL

3.2.1 问题出现

应用TPS下降，并出现SQL执行超时异常或者出现了类似如下的告警信息，则常常意味着出现了慢SQL。

3.2.2 问题分析

分析执行计划：利用explain指令获得该SQL语句的执行计划，根据该执行计划，可能有两种场景。

SQL不走索引或扫描行数过多等致使执行时长过长。

SQL没问题，只是因为事务并发导致等待锁，致使执行时长过长。

3.2.3 场景一

3.2.3.1 优化SQL

通过增加索引，调整SQL语句的方式优化执行时长， 例如下的执行计划：

该SQL的执行计划的type为ALL，同时根据以下type语义，可知无索引的全表查询，故可为其检索列增加索引进而解决。

3.2.4 场景二

3.2.4.1 查询当前事务情况

可以通过查看如下3张表做相应的处理：

-- 当前运行的所有事务
select *  from information_schema.innodb_trx;
-- 当前出现的锁
SELECT * FROM information_schema.INNODB_LOCKS;
-- 锁等待的对应关系
select *  from information_schema.INNODB_LOCK_WAITS;

（1）查看当前的事务有哪些：

（2）查看事务锁类型索引的详细信息：

lock_table字段能看到被锁的索引的表名，lock_mode可以看到锁类型是X锁,lock_type可以看到是行锁record。

3.2.4.2 分析

根据事务情况，得到表信息，和相关的事务时序信息：

DROP TABLE IF EXISTS `emp`;
CREATE TABLE `emp` (
`id` int(11) NOT NULL AUTO_INCREMENT,
`salary` int(10) DEFAULT NULL,
`name` varchar(255) DEFAULT NULL,
PRIMARY KEY (`id`),
KEY `idx_name` (`name`(191)) USING BTREE
) ENGINE=InnoDB AUTO_INCREMENT=6 DEFAULT CHARSET=utf8mb4;

A事物锁住一条记录，不提交，B事物需要更新此条记录，此时会阻塞，如下图是执行顺序：

3.2.4.3 解决方案

（1）修改方案

由前一步的结果,分析事务间加锁时序，例如可以通过tx_query字段得知被阻塞的事务SQL,trx_state得知事务状态等，找到对应代码逻辑，进行优化修改。

（2）临时修改方案

trx_mysql_thread_id是对应的事务sessionId，可以通过以下命令杀死长时间执行的事务，从而避免阻塞其他事务执行。

kill 105853

3.3 连接数过多

3.3.1 问题出现

常出现too many connections异常,数据库连接到达最大连接数。

3.3.2 解决方案

解决方案：

通过set global max_connections=XXX增大最大连接数。

先利用show processlist获取连接信息，然后利用kill杀死过多的连。

常用脚本如下：

排序数据库连接的数目 
mysql -h127.0.0.0.1 -uabc_test -pXXXXX -P3306 -A -e 'show processlist'| awk '{print $4}'|sort|uniq -c|sort -rn|head -10

3.4 相关知识

3.4.1 索引

3.4.1.1 MySql不同的存储引擎

3.4.1.2 InnoDB B+Tree索引实现

主键索引(聚集索引)：

• 叶子节点data域保存了完整的数据的地址。

• 主键与数据全部存储在一颗树上。

• Root节点常驻内存。

• 每个非叶子节点一个innodb_page_size大小,加速磁盘IO。

• 磁盘的I/O要比内存慢几百倍，而磁盘慢的原因在于机械设备寻找磁道慢，因此采用磁盘预读，每次读取一个磁盘页（page:计算机管理存储器的逻辑块-通常为4k）的整倍数。

• 如果没有主键,MySQL默认生成隐含字段作为主键，这个字段长度为6个字节，类型为长整形。

• 辅助索引结构与主索引相同,但叶子节点data域保存的是主键指针。

• InnoDB以表空间Tablespace(idb文件)结构进行组织，每个Tablespace 包含多个Segment段。

• 每个段(分为2种段：叶子节点Segment&非叶子节点Segment)，一个Segment段包含多个Extent。

• 一个Extent占用1M空间包含64个Page（每个Page 16k），InnoDB B-Tree 一个逻辑节点就分配一个物理Page，一个节点一次IO操作。

• 一个Page里包含很多有序数据Row行数据，Row行数据中包含Filed属性数据等信息。

InnoDB存储引擎中页的大小为16KB，一般表的主键类型为INT（占用4个字节）或BIGINT（占用8个字节），指针类型也一般为4或8个字节，也就是说一个页（B+Tree中的一个节点）中大概存储16KB/(8B+8B)=1K个键值（因为是估值，为方便计算，这里的K取值为[10]^3）。

也就是说一个深度为3的B+Tree索引可以维护 10^3 10^3 10^3 = 10亿 条记录。

每个索引的左指针都是比自己小的索引/节点，右指针是大于等于自己的索引/节点。

3.4.2 B+ Tree索引检索

3.4.2.1 主键索引检索

select * from table where id = 1

3.4.2.2 辅助索引检索

select * from table where name = 'a'

3.4.3 事物的隔离级别

3.4.3.1 如何查看数据库的事务隔离级别

使用如下命令可以查看事务的隔离级别：

show variables like 'tx_isolation';

阿里云上的rds的隔离级别是read committed ，而不是原生mysql的“可重复读（repeatable-read）。

• Repeatable read不存在幻读的问题，RR隔离级别保证对读取到的记录加锁 (记录锁)，同时保证对读取的范围加锁，新的满足查询条件的记录不能够插入 (间隙锁)，不存在幻读现象。

• 在MYSQL的事务引擎中，INNODB是使用范围最广的。它默认的事务隔离级别是REPEATABLE READ(可重复读），在标准的事务隔离级别定义下，REPEATABLE READ是不能防止幻读产生的。INNODB使用了next-key locks实现了防止幻读的发生。

• 在默认情况下，mysql的事务隔离级别是可重复读，并且innodb_locks_unsafe_for_binlog参数为OFF，这时默认采用next-key locks。所谓Next-Key Locks，就是Record lock和gap lock的结合，即除了锁住记录本身，还要再锁住索引之间的间隙。可以设置为ON，则RR隔离级别时会出现幻读。

3.4.3.2 多版本并发控制MVCC

MySQL InnoDB存储引擎，实现的是基于多版本的并发控制协议——MVCC (Multi-Version Concurrency Control) (注：与MVCC相对的，是基于锁的并发控制，Lock-Based Concurrency Control)。

MVCC最大的好处，相信也是耳熟能详：读不加锁，读写不冲突。在读多写少的OLTP应用中，读写不冲突是非常重要的，极大的增加了系统的并发性能。

在MVCC并发控制中，读操作可以分成两类：快照读 (snapshot read)与当前读 (current read)。

快照读：简单的select操作，属于快照读，不加锁。(当然，也有例外，下面会分析)。

select * from table where ?;

当前读：特殊的读操作，插入/更新/删除操作，属于当前读，需要加锁。

select * from table where ? lock in share mode;   　加S锁 (共享锁)
-- 下面的都是X锁 (排它锁)
select * from table where ? for update;

insert into table values (…);

update table set ? where ?;

delete from table where ?;

3.4.4.3 场景模拟

修改事务隔离级别的语句：

SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ;  
-- READ UNCOMMITTED/READ COMMITTED/REPEATABLE READ/SERIALIZABLE

（1）脏读场景模拟

DROP TABLE IF EXISTS `employee`;
CREATE TABLE `employee` (
  `id` int(11) NOT NULL,
  `name` varchar(50) NOT NULL,
  `salary` int(11) DEFAULT NULL,
  KEY `IDX_ID` (`id`) USING BTREE
) ENGINE=InnoDB DEFAULT CHARSET=utf8;

-- ----------------------------
-- Records of employee
-- ----------------------------
INSERT INTO `employee` VALUES ('10', '1s', '10');
INSERT INTO `employee` VALUES ('20', '2s', '20');
INSERT INTO `employee` VALUES ('30', '3s', '30');

脏读场景模拟

（2）不可重复读模拟

DROP TABLE IF EXISTS `employee`;
CREATE TABLE `employee` (
  `id` int(11) NOT NULL,
  `name` varchar(50) NOT NULL,
  `salary` int(11) DEFAULT NULL,
  KEY `IDX_ID` (`id`) USING BTREE
) ENGINE=InnoDB DEFAULT CHARSET=utf8;


-- ----------------------------
-- Records of employee
-- ----------------------------
INSERT INTO `employee` VALUES ('10', '1s', '10');
INSERT INTO `employee` VALUES ('20', '2s', '20');
INSERT INTO `employee` VALUES ('30', '3s', '30');

不可重复读的重点是修改: 同样的条件, 你读取过的数据, 再次读取出来发现值不一样了。

（3）幻读场景模拟

表结构与数据如下：id不是主键，也不是唯一索引，只是一个普通索引，事务隔离级别设置的是RR，可以模拟到GAP锁产生的场景。

DROP TABLE IF EXISTS `emp`;
CREATE TABLE `emp` (
  `id` int(11) NOT NULL,
  `salary` int(11) DEFAULT NULL,
  KEY `IDX_ID` (`id`) USING BTREE
) ENGINE=InnoDB DEFAULT CHARSET=utf8;

-- ----------------------------
-- Records of emp
-- ----------------------------
INSERT INTO `emp` VALUES ('10', '10');
INSERT INTO `emp` VALUES ('20', '20');
INSERT INTO `emp` VALUES ('30', '30');

修改id=20的数据后，会在加多个锁：20会被加X锁,[10-20],[20-30]之间会被加GAP锁。

幻读的重点在于新增或者删除 (数据条数变化)。同样的条件, 第1次和第2次读出来的记录数不一样。

在标准的事务隔离级别定义下，REPEATABLE READ是不能防止幻读产生的。INNODB使用了2种技术手段（MVCC AND GAP LOCK)实现了防止幻读的发生。

3.4.4 Innodb的多种锁

3.4.4.1 锁类型

• 表锁的优势：开销小；加锁快；无死锁。

• 表锁的劣势：锁粒度大，发生锁冲突的概率高，并发处理能力低。

• 加锁的方式：自动加锁。查询操作（SELECT），会自动给涉及的所有表加读锁，更新操作（UPDATE、DELETE、INSERT），会自动给涉及的表加写锁。也可以显示加锁。

• 共享读锁：lock table tableName read

• 独占写锁：lock table tableName write

• 批量解锁：unlock tables

3.4.4.2 行锁

只在Repeatable read和Serializable两种事务隔离级别下才会取得上面的锁。

3.4.4.3 意向锁

（1）场景

在mysql中有表锁，LOCK TABLE my_tabl_name READ; 用读锁锁表，会阻塞其他事务修改表数据。LOCK TABLE my_table_name WRITe; 用写锁锁表，会阻塞其他事务读和写。

Innodb引擎又支持行锁，行锁分为共享锁，一个事务对一行的共享只读锁。排它锁，一个事务对一行的排他读写锁。

这两中类型的锁共存的问题考虑这个例子：

事务A锁住了表中的一行，让这一行只能读，不能写。之后，事务B申请整个表的写锁。如果事务B申请成功，那么理论上它就能修改表中的任意一行，这与A持有的行锁是冲突的。

数据库需要避免这种冲突，就是说要让B的申请被阻塞，直到A释放了行锁。

（2）问题

数据库要怎么判断这个冲突呢？

（3）答案

无意向锁的情况下:

step1：判断表是否已被其他事务用表锁锁表

step2：判断表中的每一行是否已被行锁锁住。

有意向锁的情况下:

• step1：不变
• step2：发现表上有意向共享锁，说明表中有些行被共享行锁锁住了，因此，事务B申请表的写锁会被阻塞。

（4）总结

在无意向锁的情况下，step2需要遍历整个表,才能确认是否能拿到表锁。而在意向锁存在的情况下，事务A必须先申请表的意向共享锁，成功后再申请一行的行锁，不需要再遍历整个表，提升了效率。因此意向锁主要是为了实现多粒度锁机制（白话：为了表锁和行锁都能用）。

3.4.4.4 X/S锁

3.4.4.5 一条SQL的加锁分析

-- select操作均不加锁，采用的是快照读，因此在下面的讨论中就忽略了
SQL1：select * from t1 where id = 10;
SQL2：delete from t1 where id = 10;

组合分为如下几种场景：

（1）组合7的GAP锁详解读

Insert操作，如insert [10,aa]，首先会定位到[6,c]与[10,b]间，然后在插入前，会检查这个GAP是否已经被锁上，如果被锁上，则Insert不能插入记录。因此，通过第一遍的当前读，不仅将满足条件的记录锁上 (X锁)，与组合三类似。同时还是增加3把GAP锁，将可能插入满足条件记录的3个GAP给锁上，保证后续的Insert不能插入新的id=10的记录，也就杜绝了同一事务的第二次当前读，出现幻象的情况。

既然防止幻读，需要靠GAP锁的保护，为什么组合五、组合六，也是RR隔离级别，却不需要加GAP锁呢？

GAP锁的目的，是为了防止同一事务的两次当前读，出现幻读的情况。而组合五，id是主键；组合六，id是unique键，都能够保证唯一性。

一个等值查询，最多只能返回一条记录，而且新的相同取值的记录，一定不会在新插入进来，因此也就避免了GAP锁的使用。

（2）结论

• Repeatable Read隔离级别下，id列上有一个非唯一索引，对应SQL：delete from t1 where id = 10; 首先，通过id索引定位到第一条满足查询条件的记录，加记录上的X锁，加GAP上的GAP锁，然后加主键聚簇索引上的记录X锁，然后返回；然后读取下一条，重复进行。直至进行到第一条不满足条件的记录[11,f]，此时，不需要加记录X锁，但是仍旧需要加GAP锁，最后返回结束。

• 什么时候会取得gap lock或nextkey lock 这和隔离级别有关,只在REPEATABLE READ或以上的隔离级别下的特定操作才会取得gap lock或nextkey lock。

3.4.5 线上问题处理

3.4.5.1 观察问题的几个常见库表

首先可以通过下属两个命令来查看mysql的相应的系统变量和状态变量。

# status代表当前系统的运行状态，只能查看，不能修改
show status like '%abc%';
show variables like '%abc%';

MySQL 5.7.6开始后改成了从如下表获取：

performance_schema.global_variables 
performance_schema.session_variables 
performance_schema.variables_by_thread 
performance_schema.global_status 
performance_schema.session_status 
performance_schema.status_by_thread 
performance_schema.status_by_account 
performance_schema.status_by_host 
performance_schema.status_by_user

之前是从如下表获取：

INFORMATION_SCHEMA.GLOBAL_VARIABLES 
INFORMATION_SCHEMA.SESSION_VARIABLES 
INFORMATION_SCHEMA.GLOBAL_STATUS 
INFORMATION_SCHEMA.SESSION_STATUS

比较常用的系统变量和状态变量有：

# 查询慢SQL查询是否开启
show variables like 'slow_query_log';
# 查询慢SQL的时间
show variables like 'long_query_time';
# 查看慢SQL存放路径，一般：/home/mysql/data3016/mysql/slow_query.log
show variables like 'slow_query_log_file';

# 查看数据库的事务隔离级别,RDS:READ-COMMITTED   Mysql:Repeatable read
show variables like 'tx_isolation'; 
 # innodb数据页大小  16384
show variables like 'innodb_page_size'; 

show status  like 'innodb_row_%';

# 查看慢SQL
SHOW SLOW limit 10;
show full slow limit 10;

# 查看autocommit配置
select @@autocommit; 
 # 同上
show variables like 'autocommit'; 
#设置SQL自动提交模式  1:默认,自动提交   0:需要手动触发commit,否则不会生效
set autocommit=1;　　
# 查看默认的搜索引擎
show variables like '%storage_engine%'; 

# 设置事务隔离级别
SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ;

3.5 一些建议

3.5.1 小表驱动大表

• nb_soft_nature：小表
• nb_soft：大表
• package_name：都是索引

MySQL 表关联的算法是Nest Loop Join(嵌套循环连接)，是通过驱动表的结果集作为循环基础数据，然后一条一条地通过该结果集中的数据作为过滤条件到下一个表中查询数据，然后合并结果。

（1）小表驱动大表

nb_soft_nature 中只有24条数据，每条数据的package_name连接到nb_soft表中做查询，由于package_name在nb_soft表中有索引，因此一共只需要24次扫描即可。

（2）大表驱动小表

同上，需要100多万次扫描才能返回结果

3.5.2 使用自增长主键

结合B+Tree的特点，自增主键是连续的，在插入过程中尽量减少页分裂，即使要进行页分裂，也只会分裂很少一部分。并且能减少数据的移动，每次插入都是插入到最后。总之就是减少分裂和移动的频率。

四 Redis

4.1 问题处理思路

4.2 内存告警

时常会出现下述异常提示信息：

OOM command not allowed when used memory

4.2.1 设置合理的内存大小

设置maxmemory和相对应的回收策略算法，设置最好为物理内存的3/4，或者比例更小，因为redis复制数据等其他服务时，也是需要缓存的。以防缓存数据过大致使redis崩溃，造成系统出错不可用。

（1）通过redis.conf 配置文件指定

maxmemory xxxxxx

（2）通过命令修改

config set  maxmemory xxxxx

4.2.2 设置合理的内存淘汰策略

（1）通过redis.conf 配置文件指定

maxmemory-policy allkeys-lru

4.2.3 查看大key

（1）有工具的情况下:

安装工具dbatools redisTools,列出最大的前N个key

/data/program/dbatools-master/redisTools/redis-cli-new -h <ip> -p <port> --bigkeys --bigkey-numb 3

得到如下结果:

Sampled 122114 keys in the keyspace!
Total key length in bytes is 3923725 (avg len 32.13)


Biggest string Key Top   1  found 'xx1' has 36316 bytes
Biggest string Key Top   2  found 'xx2' has 1191 bytes
Biggest string Key Top   3  found 'xx3' has 234 bytes
Biggest   list Key Top   1  found 'x4' has 204480 items
Biggest   list Key Top   2  found 'x5' has 119999 items
Biggest   list Key Top   3  found 'x6' has 60000 items
Biggest    set Key Top   1  found 'x7' has 14205 members
Biggest    set Key Top   2  found 'x8' has 292 members
Biggest    set Key Top   3  found 'x,7' has 21 members
Biggest   hash Key Top   1  found 'x' has 302939 fields
Biggest   hash Key Top   2  found 'xc' has 92029 fields
Biggest   hash Key Top   3  found 'xd' has 39634 fields

原生命令为：

/usr/local/redis-3.0.5/src/redis-cli -c -h <ip> -p <port> --bigkeys

分析rdb文件中的全部key/某种类型的占用量：

rdb -c memory dump.rdb -t list -f dump-formal-list.csv

查看某个key的内存占用量：

[root@iZbp16umm14vm5kssepfdpZ redisTools]# redis-memory-for-key  -s <ip> -p <port> x
Key             x
Bytes               4274388.0
Type                hash
Encoding            hashtable
Number of Elements      39634
Length of Largest Element   29

（2）无工具的情况下可利用以下指令评估key大小：

debug object key

4.3 Redis的慢命令

4.3.1 设置Redis的慢命令的时间阈值(单位：微妙)

（1）通过redis.conf配置文件方式

# 执行时间大于多少微秒(microsecond，1秒 = 1,000,000 微秒)的查询进行记录。
slowlog-log-lower-than 1000

# 最多能保存多少条日志
slowlog-max-len 200

（2）通过命令方式

# 配置查询时间超过1毫秒的， 第一个参数单位是微秒
config set slowlog-log-lower-than 1000

# 保存200条慢查记录
config set slowlog-max-len 200

4.3.2 查看Redis的慢命令

slowlog get

4.4 连接过多

（1）通过redis.conf 配置文件指定最大连接数

maxclients 10000

（2）通过命令修改

config set maxclients xxx

4.5 线上Redis节点挂掉一个之后的处理流程

4.5.1 查看节点状态

执行 cluster nodes 后发现会有一个节点dead：

[rgp@iZ23rjcqbczZ ~]$ /data/program/redis-3.0.3/bin/redis-cli -c -h <ip> -p <port>
ip:port> cluster nodes
9f194f671cee4a76ce3b7ff14d3bda190e0695d5 m1 master - 0 1550322872543 65 connected 10923-16383
a38c6f957f2706f269cf5d9b628586a9372265e9 s1 slave 9f194f671cee4a76ce3b7ff14d3bda190e0695d5 0 1550322872943 65 connected
77ce43ec23f25f77ec68fe71ae3cb799e7300c6d s2 slave 03d72a3a5050c85e280e0bbeb687056b84f10077 0 1550322873543 63 connected
03d72a3a5050c85e280e0bbeb687056b84f10077 m2 master - 0 1550322873343 63 connected 5461-10922
5799070c6a63314296f3661b315b95c6328779f7 :0 slave,fail,noaddr 6147bf416ef216b6a1ef2f100d15de4f439b7352 1550320811474 1550320808793 49 disconnected
6147bf416ef216b6a1ef2f100d15de4f439b7352 m3 myself,master - 0 0 49 connected 0-5460

4.5.2 移除错误节点

（1）一开始执行如下的删除操作失败，需要针对于每一个节点都执行 cluster forget：

ip:port> cluster forget 61c70a61ad91bbac231e33352f5bdb9eb0be6289
CLUSTER FORGET <node_id> 从集群中移除 node_id 指定的节点

（2）删除挂掉的节点：

[rgp@iZ23rjcqbczZ ~]$ /data/program/redis-3.0.3/bin/redis-trib.rb del-node m3 b643d7baa69922b3fdbd1e25ccbe6ed73587b948
>>> Removing node b643d7baa69922b3fdbd1e25ccbe6ed73587b948 from cluster m3
>>> Sending CLUSTER FORGET messages to the cluster...
>>> SHUTDOWN the node.

（3）清理掉节点配置目录下的rdb aof nodes.conf 等文件，否则节点的启动会有如下异常：

[ERR] Node s3 is not empty. Either the node already knows other nodes (check with CLUSTER NODES) or contains some key in database 0.

4.5.3 恢复节点

（1）后台启动Redis某个节点：

/data/program/redis-3.0.3/bin/redis-server /data/program/redis-3.0.3/etc/7001/redis.conf &

（2）将该节点添加进集群：

[root@iZ23rjcqbczZ rgp]# /data/program/redis-3.0.3/bin/redis-trib.rb add-node  --slave --master-id 6147bf416ef216b6a1ef2f100d15de4f439b7352 s3 m3
>>> Adding node s3 to cluster m3
>>> Performing Cluster Check (using node m3)
M: 6147bf416ef216b6a1ef2f100d15de4f439b7352 m3
   slots:0-5460 (5461 slots) master
   0 additional replica(s)
M: 9f194f671cee4a76ce3b7ff14d3bda190e0695d5 m1
   slots:10923-16383 (5461 slots) master
   1 additional replica(s)
S: a38c6f957f2706f269cf5d9b628586a9372265e9 s1
   slots: (0 slots) slave
   replicates 9f194f671cee4a76ce3b7ff14d3bda190e0695d5
S: 77ce43ec23f25f77ec68fe71ae3cb799e7300c6d s2
   slots: (0 slots) slave
   replicates 03d72a3a5050c85e280e0bbeb687056b84f10077
M: 03d72a3a5050c85e280e0bbeb687056b84f10077 m2
   slots:5461-10922 (5462 slots) master
   1 additional replica(s)
[OK] All nodes agree about slots configuration.
>>> Check for open slots...
>>> Check slots coverage...
[OK] All 16384 slots covered.
>>> Send CLUSTER MEET to node s3 to make it join the cluster.
Waiting for the cluster to join..
>>> Configure node as replica of m3.
[OK] New node added correctly.

• s3:本次待添加的从节点ip：port
• m3:主节点的ip：port
• 6147bf416ef216b6a1ef2f100d15de4f439b7352：主节点编号

五 网络

5.1 排查流程

5.1.1 现象出现

在非压测或者高峰期的情况下，突然出现大量的503等错误码，页面无法打开。

5.1.2 查看是否遭受了DOS攻击

当Server上有大量半连接状态且源IP地址是随机的，则可以断定遭到SYN攻击了，使用如下命令可以让之现行。

netstat -n|grep SYN_RECV

5.1.3 查看TCP连接状态

首先利用以下查看tcp总连接数，判断连接数是否正常：

netstat -anoe|grep 8000|wc -l 查看8000

然后利用如下命令判断各个状态的连接数是否正常：

netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'

根据上述信息，如果TIME_WAIT 状态数量过多，可利用如下命令查看连接CLOSE_WAIT最多的IP地址，再结合业务分析问题：

netstat -n|grep TIME_WAIT|awk '{print $5}'|awk -F: '{print $1}'|sort|uniq -c|sort -nr|head -10

5.2 相关知识

5.2.1 TCP连接

TCP三次握手四次挥手

为什么在第3步中客户端还要再进行一次确认呢？这主要是为了防止已经失效的连接请求报文段突然又传回到服务端而产生错误的场景：

所谓"已失效的连接请求报文段"是这样产生的。正常来说，客户端发出连接请求，但因为连接请求报文丢失而未收到确认。于是客户端再次发出一次连接请求，后来收到了确认，建立了连接。数据传输完毕后，释放了连接，客户端一共发送了两个连接请求报文段，其中第一个丢失，第二个到达了服务端，没有"已失效的连接请求报文段"。

现在假定一种异常情况，即客户端发出的第一个连接请求报文段并没有丢失，只是在某些网络节点长时间滞留了，以至于延误到连接释放以后的某个时间点才到达服务端。本来这个连接请求已经失效了，但是服务端收到此失效的连接请求报文段后，就误认为这是客户端又发出了一次新的连接请求。于是服务端又向客户端发出请求报文段，同意建立连接。假定不采用三次握手，那么只要服务端发出确认，连接就建立了。

由于现在客户端并没有发出连接建立的请求，因此不会理会服务端的确认，也不会向服务端发送数据，但是服务端却以为新的传输连接已经建立了，并一直等待客户端发来数据，这样服务端的许多资源就这样白白浪费了。

采用三次握手的办法可以防止上述现象的发生。比如在上述的场景下，客户端不向服务端的发出确认请求，服务端由于收不到确认，就知道客户端并没有要求建立连接。

SYN攻击时一种典型的DDOS攻击，检测SYN攻击的方式非常简单，即当Server上有大量半连接状态且源IP地址是随机的，则可以断定遭到SYN攻击了，使用如下命令可以让之现行：

netstat -nap | grep SYN_RECV

5.2.2 一些常见问题

（1）为什么TCP连接的建立只需要三次握手而TCP连接的释放需要四次握手呢?

因为服务端在LISTEN状态下，收到建立请求的SYN报文后，把ACK和SYN放在一个报文里发送给客户端。而连接关闭时，当收到对方的FIN报文时，仅仅表示对方没有需要发送的数据了，但是还能接收数据，己方未必数据已经全部发送给对方了，所以己方可以立即关闭，也可以将应该发送的数据全部发送完毕后再发送FIN报文给客户端来表示同意现在关闭连接。

从这个角度而言，服务端的ACK和FIN一般都会分开发送。

（2）如果已经建立了连接，但是客户端突然出现故障了怎么办？

TCP还设有一个保活计时器，显然，客户端如果出现故障，服务器不能一直等下去，白白浪费资源。服务器每收到一次客户端的请求后都会重新复位这个计时器，时间通常是设置为2小时，若两小时还没有收到客户端的任何数据，服务器就会发送一个探测报文段，以后每隔75秒钟发送一次。若一连发送10个探测报文仍然没反应，服务器就认为客户端出了故障，接着就关闭连接。

（3）为什么TIME_WAIT状态需要经过2MSL(最大报文段生存时间)才能返回到CLOSE状态？

虽然按道理，四个报文都发送完毕，我们可以直接进入CLOSE状态了，但是我们必须假象网络是不可靠的，有可以最后一个ACK丢失。所以TIME_WAIT状态就是用来重发可能丢失的ACK报文。

在Client发送出最后的ACK回复，但该ACK可能丢失。Server如果没有收到ACK，将不断重复发送FIN片段。所以Client不能立即关闭，它必须确认Server接收到了该ACK。Client会在发送出ACK之后进入到TIME_WAIT状态。Client会设置一个计时器，等待2MSL的时间。如果在该时间内再次收到FIN，那么Client会重发ACK并再次等待2MSL。所谓的2MSL是两倍的MSL(Maximum Segment Lifetime)。

MSL指一个片段在网络中最大的存活时间，2MSL就是一个发送和一个回复所需的最大时间。如果直到2MSL，Client都没有再次收到FIN，那么Client推断ACK已经被成功接收，则结束TCP连接。

六 业务异常日志

6.1 问题出现

主要是通过业务日志监控主动报警或者是查看错误日志被动发现：

6.2 日志分析

6.2.1 确认日志格式

日志格式如下：

<property name="METRICS_LOG_PATTERN"
              value="%d{yyyy-MM-dd HH:mm:ss.SSS}|${APP_NAME}|%X{className}|%X{methodName}|%X{responseStatus}|%X{timeConsume}|%X{traceId}|%X{errorCode}|%msg%n"/>


 <property name="ERROR_LOG_PATTERN"
              value="%d{yyyy-MM-dd HH:mm:ss.SSS}|%-5level|%X{traceId}|${APP_NAME}|%serverIp|%X{tenantId}|%X{accountId}|%thread|%logger{30}|%msg%n"/>


<!--日志格式 时间|级别|链路id|应用名|服务器ip|租户id|用户id|线程名称|logger名称|业务消息 -->
<property name="BIZ_LOG_PATTERN"
              value="%d{yyyy-MM-dd HH:mm:ss.SSS}|%-5level|%X{traceId}|${APP_NAME}|%serverIp|%X{tenantId}|%X{accountId}|%thread|%logger{30}|%msg%n"/>

6.2.2 在日志文件中检索异常

利用如下命令可获得异常的详细信息：

cat error.log|grep -n " java.lang.reflect.InvocationTargetException"

根据日志格式和日志信息，可获得traceId为489d71fe-67db-4f59-a916-33f25d35cab8，然后利用以下指令获取整个流程的日志信息：

cat biz.log |grep -n '489d71fe-67db-4f59-a916-33f25d35cab8'

6.2.3 代码分析

然后根据上述流程日志找到对应的代码实现，然后进行具体的业务分析。