
作者 | 小峯
來源 | 阿裡技術公衆号
前言
線上定位問題時,主要靠監控和日志。一旦超出監控的範圍,則排查思路很重要,按照流程化的思路來定位問題,能夠讓我們在定位問題時從容、淡定,快速的定位到線上的問題。
線上問題定位思維導圖
一 伺服器層面
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.1.3.3 ls
主要是用于顯示指定工作目錄下的内容的資訊。
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
top程序内指令參數:
二 應用層面
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 設定合理的記憶體淘汰政策
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
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 代碼分析
然後根據上述流程日志找到對應的代碼實作,然後進行具體的業務分析。