简介: 有哪些常见的线上故障?如何快速定位问题?本文详细总结工作中的经验,从服务器、JAVA应用、数据库、redis、网络和业务六个层面分享线上故障排查的思路和技巧。较长,同学们可收藏后再看。
线上定位问题是,主要靠监控和日志。一旦超出监控的范围,则排查思路很重要,按照流程化的思路来定位问题,能够让我们在定位问题时从容、淡定,快速的定位到线上的问题。
线上问题定位思维导图
当磁盘容量不足的时候,应用时常会抛出如下的异常信息:
java.io.IOException: 磁盘空间不足
或是类似如下告警信息:
利用以下指令获取磁盘状态:
df -h
结果是:
可知 / 路径下占用量最大。
利用以下指令获取目录下文件夹大小:
du -sh *
结果是:
可知root文件夹占用空间最大,然后层层递推找到对应的最大的一个或数个文件夹。
利用以下指令获取目录下文件夹大小:
ls -lh
结果是:
可以找到最大的文件是日志文件,然后使用rm指令进行移除以释放磁盘。
主要是用于显示目前在 linux 系统上的文件系统磁盘使用情况统计。
(1)常用参数
启动参数:
(2)结果参数
1.1.3.2 du
主要是为了显示目录或文件的大小。
(1)常用参数
启动参数:
(2)结果参数
1.1.3.3 ls
主要是用于显示指定工作目录下的内容的信息。
(1)常用参数
启动参数:
(2)结果参数
当CPU过高的时候,接口性能会快速下降,同时监控也会开始报警。
利用以下指令获取系统CPU使用率信息:
top
结果是:
从而可以得知pid为14201的进程使用CPU最高。
(1)常用参数
启动参数:
top进程内指令参数:
(2)结果参数
监控平台发现某个Tomcat节点已经无法采集到数据,连上服务器查看服务器进程还在,netstat -anop|grep 8001端口也有监听,查看日志打印时断时续。
查看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
在一次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
使用Memory Analyzer解析dump文件,发现有很明显的内存泄漏提示。
点击查看详情,发现定位到了代码的具体某行,一目了然:
查看shallow heap与retained heap能发现生成了大量的Object(810325个对象),后面分析代码发现是上报softItem对象超过300多万个对象,在循环的时候,所有的数据全部保存在某个方法中无法释放,导致内存堆积到1.5G,从而超过了JVM分配的最大数,从而出现OOM。
java.lang.Object[810325] @ 0xb0e971e0
2.2.5.2 内存分配的流程
如果通过逃逸分析,则会先在TLAB分配,如果不满足条件才在Eden上分配。
(1)GC触发的场景
2)GC Roots
GC Roots有4种对象:
(3)GC算法
(4)新生代使用的GC算法
(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]
一般情况下会有监控告警进行提示:
利用top查到占用cpu最高的进程pid为14,结果图如下:
利用 top -H -p 查看进程内占用cpu最高线程,从下图可知,问题线程主要是activeCpu Thread,其pid为417。
由上一步可知该问题是由 CpuThread.java 类引发的,故查询项目代码,获得如下信息:
根据代码和日志分析,可知是由于限制值max太大,致使线程长时间循环执行,从而导致问题出现。
最近线上随着流量变大,突然开始报如下异常,即发生了死锁问题:
Deadlock found when trying to get lock; try restarting transaction ;
利用 select @@tx_isolation 命令获取到数据库隔离级别信息:
利用 show engine innodb status 命令获取到如下死锁信息:
由上可知,是由于两个事物对这条记录同时持有S锁(共享锁)的情况下,再次尝试获取该条记录的X锁(排它锁),从而导致互相等待引发死锁。
根据死锁日志的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);
}
分析获得产生问题的加锁时序如下,然后修改代码实现以解决该问题。
应用TPS下降,并出现SQL执行超时异常或者出现了类似如下的告警信息,则常常意味着出现了慢SQL。
分析执行计划:利用explain指令获得该SQL语句的执行计划,根据该执行计划,可能有两种场景。
SQL不走索引或扫描行数过多等致使执行时长过长。
SQL没问题,只是因为事务并发导致等待锁,致使执行时长过长。
通过增加索引,调整SQL语句的方式优化执行时长, 例如下的执行计划:
该SQL的执行计划的type为ALL,同时根据以下type语义,可知无索引的全表查询,故可为其检索列增加索引进而解决。
可以通过查看如下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。
根据事务情况,得到表信息,和相关的事务时序信息:
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事物需要更新此条记录,此时会阻塞,如下图是执行顺序:
(1)修改方案
由前一步的结果,分析事务间加锁时序,例如可以通过tx_query字段得知被阻塞的事务SQL,trx_state得知事务状态等,找到对应代码逻辑,进行优化修改。
(2)临时修改方案
trx_mysql_thread_id是对应的事务sessionId,可以通过以下命令杀死长时间执行的事务,从而避免阻塞其他事务执行。
kill 105853
常出现too many connections异常,数据库连接到达最大连接数。
解决方案:
通过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.1.1 MySql不同的存储引擎
主键索引(聚集索引):
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亿 条记录。
每个索引的左指针都是比自己小的索引/节点,右指针是大于等于自己的索引/节点。
select * from table where id = 1
select * from table where name = 'a'
使用如下命令可以查看事务的隔离级别:
show variables like 'tx_isolation';
阿里云上的rds的隔离级别是read committed ,而不是原生mysql的“可重复读(repeatable-read)。
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 ?;
修改事务隔离级别的语句:
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)实现了防止幻读的发生。
只在Repeatable read和Serializable两种事务隔离级别下才会取得上面的锁。
(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:判断表中的每一行是否已被行锁锁住。
有意向锁的情况下:
(4)总结
在无意向锁的情况下,step2需要遍历整个表,才能确认是否能拿到表锁。而在意向锁存在的情况下,事务A必须先申请表的意向共享锁,成功后再申请一行的行锁,不需要再遍历整个表,提升了效率。因此意向锁主要是为了实现多粒度锁机制(白话:为了表锁和行锁都能用)。
-- 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)结论
首先可以通过下属两个命令来查看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;
MySQL 表关联的算法是Nest Loop Join(嵌套循环连接),是通过驱动表的结果集作为循环基础数据,然后一条一条地通过该结果集中的数据作为过滤条件到下一个表中查询数据,然后合并结果。
(1)小表驱动大表
nb_soft_nature 中只有24条数据,每条数据的package_name连接到nb_soft表中做查询,由于package_name在nb_soft表中有索引,因此一共只需要24次扫描即可。
(2)大表驱动小表
同上,需要100多万次扫描才能返回结果
结合B+Tree的特点,自增主键是连续的,在插入过程中尽量减少页分裂,即使要进行页分裂,也只会分裂很少一部分。并且能减少数据的移动,每次插入都是插入到最后。总之就是减少分裂和移动的频率。
时常会出现下述异常提示信息:
OOM command not allowed when used memory
设置maxmemory和相对应的回收策略算法,设置最好为物理内存的3/4,或者比例更小,因为redis复制数据等其他服务时,也是需要缓存的。以防缓存数据过大致使redis崩溃,造成系统出错不可用。
(1)通过redis.conf 配置文件指定
maxmemory xxxxxx
(2)通过命令修改
config set maxmemory xxxxx
(1)通过redis.conf 配置文件指定
maxmemory-policy allkeys-lru
(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
(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
slowlog get
(1)通过redis.conf 配置文件指定最大连接数
maxclients 10000
(2)通过命令修改
config set maxclients xxx
执行 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
(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.
(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.
在非压测或者高峰期的情况下,突然出现大量的503等错误码,页面无法打开。
当Server上有大量半连接状态且源IP地址是随机的,则可以断定遭到SYN攻击了,使用如下命令可以让之现行。
netstat -n|grep SYN_RECV
首先利用以下查看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
TCP三次握手四次挥手
为什么在第3步中客户端还要再进行一次确认呢?这主要是为了防止已经失效的连接请求报文段突然又传回到服务端而产生错误的场景:
所谓"已失效的连接请求报文段"是这样产生的。正常来说,客户端发出连接请求,但因为连接请求报文丢失而未收到确认。于是客户端再次发出一次连接请求,后来收到了确认,建立了连接。数据传输完毕后,释放了连接,客户端一共发送了两个连接请求报文段,其中第一个丢失,第二个到达了服务端,没有"已失效的连接请求报文段"。
现在假定一种异常情况,即客户端发出的第一个连接请求报文段并没有丢失,只是在某些网络节点长时间滞留了,以至于延误到连接释放以后的某个时间点才到达服务端。本来这个连接请求已经失效了,但是服务端收到此失效的连接请求报文段后,就误认为这是客户端又发出了一次新的连接请求。于是服务端又向客户端发出请求报文段,同意建立连接。假定不采用三次握手,那么只要服务端发出确认,连接就建立了。
由于现在客户端并没有发出连接建立的请求,因此不会理会服务端的确认,也不会向服务端发送数据,但是服务端却以为新的传输连接已经建立了,并一直等待客户端发来数据,这样服务端的许多资源就这样白白浪费了。
采用三次握手的办法可以防止上述现象的发生。比如在上述的场景下,客户端不向服务端的发出确认请求,服务端由于收不到确认,就知道客户端并没有要求建立连接。
SYN攻击是一种典型的DDoS攻击,检测SYN攻击的方式非常简单,即当Server上有大量半连接状态且源IP地址是随机的,则可以断定遭到SYN攻击了,使用如下命令可以让之现行:
netstat -nap | grep SYN_RECV
(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连接。
主要是通过业务日志监控主动报警或者是查看错误日志被动发现:
日志格式如下:
<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"/>
利用如下命令可获得异常的详细信息:
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'
然后根据上述流程日志找到对应的代码实现,然后进行具体的业务分析。
原文:https://developer.aliyun.com/article/778128?spm=a2c6h.12873581.0.0.10ed767dee0C6e&groupCode=othertech