故障分析 ｜ 是谁偷走了我的 IO.docx

《故障分析 ｜ 是谁偷走了我的 IO.docx》由会员分享，可在线阅读，更多相关《故障分析 ｜ 是谁偷走了我的 IO.docx（15页珍藏版）》请在淘文阁 - 分享文档赚钱的网站上搜索。

1、故障分析I是谁偷走了我的10-IX. 1刖B对于刚接触MySQL数据库不久的小伙伴来说，或多或少会遇到一些 棘手的小问题；比方在数据库磁盘无损坏的情况下，我们经常会遇到数据 库服务器的磁盘10压力很大，但由于服务器上只有MySQL程序，我们第 一想法肯定是某个连接用户在连到数据库后，背着我们在瞎搞着什么；然 而直接通过show processlist命令，看到的结果不一定准确。下面模拟 一个简单场景，让我们确切地定位问题所在。场景模拟，制造10压力# 生成一张大表，用于测iS hoottidbmasteJ# /usr/share/sysbcnch/oltp write only, lua my

2、sq.一 host=10. 186. 61. 36 -mysql-user=sun -mysql-password=，xx 一 mysql-port=3306 mysql-db=testclb tables=l - table size=15000000 -auto inc=off -rcport-intcrval=2 -db- ps-mode=disable -lime=100000 -threads=l prepare sysbench L 0.17 (using system LuaJIT 2. 0.4)Creating table sbtestl.Inserting 15000000

3、records into ，sbtestl，Creating a secondary index on sbtestl对生成的表进行 写操作roottidb-master/usr/share/sysbench/oltp write only, lua -mysql- host=10. 186. 61. 36 -mysql-user=sun -mysql-password=，xx) 一 mysql-port=3306 -mysql-db=testdb -tables=l -table sizc=15000000 auto inc=off -rcport-intcrval=2 -db- ps-mo

4、de=disable -time=100000 -一threads=l run sysbench 1. 0. 17 (using system LuaJIT 2. 0. 4)Running the test with following options: Number of threads: 1Report intermediate results every 2 second(s) Initializing random number generator from current timeQuery0updateINSERT INTO sbtestl (id, k, c, pad) VALU

5、ES (7493994,15041 rootlocalhostNULLQuery0startingshow processlistJ-1111111111111+20 rows in set (0.00 sec)5、通过kill掉14830后，发现磁盘压力果然。ver 了，你这“小阳 人 ” （#一） S。（一皿一/）mysql kill 14830;Query OK, 0 rows affected (0. 00 sec)mysql exitByeSegmentation faultJroottidb-tikvO1iostat -xm 1Linux 3. 10. 0-862. 14. 4.e

6、l7Lx86_64 (tidb-tikvOl) 04/22/2022Ix86_64_(12 CPU)Device:avg2cpu:%user%nice %system %iowait为steal%idleL 210. 000. 440. 180. 1098. 06Device:rrqm/swrqm/s17sw/srMB/s |wMB/s avgrq-sz avgqu-sz %utilawa i tr_awai tw awai tsvetmvda0.01oTiT3. 8324. 55(f090. 27 scdO26. 120. 190. 006. 780005.460. 006. 990. 00

7、0. 691.950. 000. 006. 000. 000.5001500. 000. 500. 00avg-cpu:%usee%nice %system %iowait%steal%idle1.850. 000590. 000. 0097. 56rrqm/swrqm/sr/sw/srMB/swMB/s avgrq-sz avgqu-szawait r_awaitwawaitsvetm%utilvda0.4615. 520. 000.010. 000. 200. 000. 0061.000. 200. 000.181.10scdO0. 000. 000. 000. 000L000. 000.

8、 000. 000. 000. 000. 000. 000. 00avg-cpu:%user%nice %system %iowait先steal%idle3. 360. 000. 840. 080. 0095. 71Device:rrqm/swrqm/s17sw/srMB/swMB/s avgrq-sz %utilavgqu-szawaitr_awaitwawai tsvetmvda0. 00joToo1. 0053. 0007020.48 scdO18.812. 87 01Go0. 220001.000. 000.210. 001. 3177l00L00SOO0. 00ToooTooToo

9、TooToo oToo备注说明：生产环境可不要随随便便kill哦，出问题是要被鞭尸的呦总结对于一些新入门的小可爱来说，以上方法可以循序渐进的帮助你定位 到是哪些连接线程把你的服务器10折腾高的，可以让你更加了解Linux 系统与MySQL之间的联动关系。老鸟嘛，enunni.Initializing worker threads.Threads started!2s thds: 1 tps: 24. 47 qps: 148.33 (r/w/o:0. 00/98. 89/49. 44) lat (ms, 95%): 86. 00 err/s: 0. 00 reconn/s:0. 004s thd

10、s: 1 tps: 53.02 qps: 318. 62 (r/w/o:0. 00/212.58/106.04) lat (ms, 95%) : 48.34 err/s: 0. 00 reconn/s0. 006s thds: 1 tps: 60. 50 qps: 363. 50 (r/w/o:0. 00/242. 50/121l00) (ms, 95%). 43. 39 err/s: 0. 00 reconn/s0. 008s thds: 1 tps: 65.50 qps: 391.02 (r/w/o:0. 00/260. 01/131.01) lat (us, 95%) : 39.65 e

11、rr/s: 0. 00 reconn/s 0.0010s thds: 1 tps: 55.50 qps: 334.51 (r/w/o:CL 00/223.51/111.00) lat (ms, 95%) : 44.98 eb/s: 0. 00 reconn/s 0.0012s thds: 1 tps: 57.00 qps: 340.99 (r/w/o:0二00/227. 00/114.00) lat (ms, 95%) : 38.25 err/s: 0. 00 reconn/s 0? 00问题分析1、通过top命令发现io wait比拟高，咦，What is going on?（假 装不知道我

12、在压测（）top - 17:05:59 up 179 days, 7:05, 2 users, load average: 0. 84, 0. 70, 0. 93Tasks: 181 total, 1 running, 180 sleeping, 0 stopped, 0 zombie%Cpu0 :us,0,sy,0.0ni,952.7wa,0.0hi7 0.0si,oTost%Cpul :6.9us,3.8sy,070ni,-60.TTdT五0wa,0.0hi, 0.00J)st%Cpu2 T2.4us,270sy,0.0ni,90.8id,wa,0 二0htoT6-si,st%Cpu3 :

13、1. 7US,1.3sy,0.0ni,95.3id,1.7va,0.0hi,而si,st%Cpu4 j_ 1.4 us1. 0 sy, 0. 0 ni, 95二6 id, 2. 0 wa, 0. 0hi, 0.0 si, 0.0 st%Cpu5 : 3. 1 us hi, 0.0 si, 0.,1. 4 sy, 0. 0 ni, 81. 4 id, 14. 2 wa, 0. 0D st%Cpu6 3 0. 7 us1. 0 sy, 0. 0 ni, 96二6 jd, L 7 wa0. 0hi, 0.0 si, 0.%Cpu7 _ 1. 0 uD st, 0. 3 sy, 0. 0 ni, 96

14、76 id, 2. 0 wa, 0. 0hlT 0. 0 si, 0.D st%Cpu8 : 0.3 us hi, 0.0 si, 0.,1. 0 sy, 0. 0 ni, 94. 6 id, 4.1 wa, 0. 00 st%Cpu9 : 2.4 us.1.0 sy, 0.0 ni, 91.2 id, 5.4 wa, 0.0hi, 0.0 si, 0.%CpulO 14.7 us0 st,2. 7 sy, 0. 082二6 jd, 0. 0 wa 0. 0hi7 0.0 si, 0.D st%Cpu 11 : 2. 0 us hi, 0. 0 si, 0. i,1. 0 sy, 0. 0 n

15、i, 96. 0 id, 1. 0 wa, 0. 0D stKiB Mem : 12137024 total, 185984 free, 3987936 used,7963104 buff/cacheKiB Swap:0 total,0 free,0 used.7150088 avai1 MemPID USER1PR NI VIRT RES SHR S 用CPU %MEM|TIME+ COMMAND8858 actiont+ : 210:38. 75 mysqld200 72499401. lg 11892 S 30.0 9.326447 tidb:20 0 4000364 1.0g 4740

16、 s 5.3 9.010018:23 TiFlashMain22761 actiont+ 200 2526348 361889756 S 4.0 0J1197:43 ustats29004 root 1802:29 beam. s200 3784084 1036762012 S 2.0 0.92、通过iostat命令进一步分析，我们看到磁盘在频繁的写操作，维 持在26M/s左右（%uitl值比拟大，一般来说，值大于75%是说明磁盘压 力比拟大了）roottidb-tikvO1iostat -xm 1Linux 3. 10. 0-862. 14. 4.el7.x86_64 (tidb-tikvO

17、l) 04/22/2022_x86_64_(12 CPU)avg-cpu: %user %nice %system %iowait %steal %idle1.21Device:rrqm/swrqm/sr/sw/srMB/swMB/s avgrq-szavgqu-szawaitr_awaitwawaitsvctm%utiLvda0.010.183. 5322. 9907080 2525. 840.J9765. 647r400. 711. 88scdO0. 00oToo。叫(kO(L07000. 006. 000. 000. 500. 500. 00o75o oTooavg-cpu:%user%

18、nice %system %iowait先steal%idle2. 220. 001. 198. 280. 0988. 23Device:rrqm/swrqm/sr/sw/srMB/swMB/s avgrq-szavgqu-szawaitr_awai twawai tsvctm%utilvda0. 00oToo328. 00J800. 005. 1226.1F飞olrT27181.49工680.910.4188. 30scdO0. 00oToo0?00soToToo0. 000. 000. 000. 000. 000. 000. 000. 00avg-cpu:%user%nice %syste

19、m %iowait先steal%idle一?630. 001.036. 680. 099075FDevice:rrqm/swrqni/sr/sw/srMB/swMB/s avgrq-szavgqu-szawaitr_awaitwawaitsvctm%utilvda0. 00Too352. 001918. OF5. 5027. 8230. 062. 96313.210. 960. 3783. 60scdO0. 00oToyoToyMo鼠工000. 000. 000. 000. 000. 000. 000. 000. 00avg-cpu:%user%nice %system %iowait%ste

20、al%idle57540. 001.968. 770. 0983. 65Device:rrqm/swrqm/sr/sw/srMB/swMB/s avgrq-szavgqu-szawaitr_awaitwawaitsvctm%utilvda0. 00o.oo300. 001682?0047690. 000. 440. 180. 1098. 0725. 6831.383. 091.553. 681. 170. 45|88. 60scdO0. 000. 000. 000. 000. 00|o. 000. 000. 000. 000. 000. 000. 000. 003、通过iotop命令可以看到与

21、MySQL相关线程1D 22233的10消耗 为52. 59%,读为2.56M/S,同时线程ID 8879的写为27. 31M/s （一般来 说，K）列值越大，说明10压力最有可能与其相关）Total DISK READ :5. 29 M/s | Total DISK WRITE :29. 42 M/sActual DISK READ:5729 M/s Actual DISK WRITE:26. 83 M/sTID PRIO USERDISK READ DISK WRITE SWAPIN I0COMMAND22233 be/4 actionte2. 56 M/s 473.07 K/s 0L00

22、 % 52. 59 %mysqld -defaults-file=/opt/mysql/etc/3306/my. cnf socket=/opt/mysql/data/3306/mysqlcl. sock port=33068879 be/4 actionte 0. 00 B/s27. 31 M/s 0. 00 % 17. 76 %mysqld -defaults-file=/opt/mysql/etc/3306/niy. cnf -d socket=/opt/mysql/data/3306/inysqld. sock port=33068887 be/4 actionte 0. 00 B/s

23、 0. 00 B/s 0. 00 % 10. 10 % mysqld -defaults-file=/opt/mysql/etc/3306/my. cnf socket=/opt/mysql/data/3306/mysqlcl. sock port=33068907 be/4 actionte 116.33 K/s 0. 00 B/s 0. 00 % 6. 27 % mysqld -defaults-file=/opt/mysql/etc/3306/niy. cnf -d socket=/opt/mysql/data/3306/inysqld. sock port=33068930 be/4

24、actionte 7. 76 K/s0. 00 B/s 0. 00 % 3. 45 %mysqld -defaults-file=/opt/mysql/etc/3306/niy. cnf - socket=/opt/mysql/data/3306/mysqld. sock port=33068910 be/4 actionte 1217.57 K/s0700 B/s 0700 % 3.33 % mysqld -defaults-file=/opt/mysql/etc/3306/my. cnf d、 socket=/opt/mysql/data/3306/mysql(l. sock port=3

25、3068911 be/4 actionte 372.25 K/s0700 B/s 0700 % 1. 53 % mysqld -defaults-file=/opt/mysql/etc/3306/my. cnf d、 socket=/opt/ mysq l/data/3306/mysqjxl.ock -port=33062946 be/4 actionte 0. 00 B/s 1985. 34 B/s 0. 00 % 1. 52 % ustats述909 be/4 actionte 418.78 K/s 0L00 B/s 0L00 % 1.08 % mysqld -defaults-file=

26、/opt/mysql/etc/3306/my. cnf -d - socket=/opt/mysql/data/3306/mysqld. sock -port=33064、将上面获取的系统线程ID带入到MySQL中，我们便可以查到连接 用户sun一直在频繁写操作，现在我很怀疑你，但我先保持沉默roottidb-1ikvO 1/opt/mysql/base/8. 0. 21/bin/mysql -S /opt/mysql/data/3306/mysqld. sock -pxx mysql: Warning Using a password on the command 1ine interfac

27、e can be insecure.Welcome to the MySQL monitor. Commands end with ; or g. Your MySQL connection id is 15041Server version: 8.0.21 MySQL Community Server - GPLCopyright (c) 2000, 2020, Oracle and/or its affiliates. All rights reserved.Oracle is a registered trademark of Orac1e Corporation and/or its

28、affiliates. Other names may be trademarks of their respective owners.Type , help;, or h for help. Type c to c1 ear the current input statement.mysql select * from performance schema, threads whereTHREAD_0SD=22233G* . rowTHREAD!)二 14880NAME: thrcad/sql/onc connectionTYPE: FOREGROUNDPROCESSLIST J D 14

29、830# ID 为 148830 连接在疯狂的进行写操作，show proccsslist可以看到正在进行的连接PROCESSLTST_USER: sunPROCESSLIST_HOST: 10. 186.61.16PROCESSLIST,DB: testdbPROCESSLTST_COMMAND: QueryPROCESSLISTJHME： 0PROCESSLIST_STATE: updating【-pROCESSLISTJNFO: UPDATE sbtesll SET k=k+1 WHERE id=7899611PARENT THREAD ID: NULLROLE: NULL INSTRU

30、MENTED: YES# THREAD_OS_ID 为 linux# THREAD_OS_ID 为 linuxHISTORY: YES CONNECTIONJTYPE: TCP/IP THREAD_OSD: 22233 系统中的线程IDRESOURCE_GROUP: USR_default 1 row in set (0. 00 sec)mysql select * from performance_schema. threads whereTHREAD_0S_ID=8879G* . row，广，,、rT*，广 吓、，,、，广，上、，广 吓、，、，广，广，,、，,、，,、，1、,、，.、，|、

31、，广吓、THREAD .1D: 21NAME:thread/innodb/page_f lush_coordinator_thread # MySQL 自身刷 脏数据线程，因为用R的频秦写操作，导装该线程一直进行落盘操作1 row in set (0. 00 sec)TYPE:BACKGROUNDPROCESSLIST_IDNULLprocesslMT USERNULLlROCESSLIST. HOSTNULLPROCESSLIST_DBNULLPROCESSLIST COMMANDNULLPROCESSLIST_TIME264523PROCESSLIST_STATENULLprocesslM

32、T INFONULLPARENT_THREAD_IDNULLROLENULLJNSTRUMENTEDYESHISTORYYESCONNECTION_TYPENULLTHREAD_OS_ID8879RESOURCE GROUPSYS defaulPmysql show processlist;+Id | UserHostdbCommandTimeState| Info 1 + + +5 event_scheduler localhostNULL Daemon264544 Waiting on empty queue| NULLJ8 universe op127.0.0.1:38362NULLSl

33、eep0| NULLI9 universe_op127.0.0.1:38374| NULLSleep0| NULL110 universjopI 127. 0. 0. 1:38376NULL ISleepI0 | NULL111 universe, op127. 0. 0. 1:38380NULLSleep0| NULL12 universe_op:38378| NULLSleep|0I NULL13 universe_op127.0.0.1:38384NULLSleep0TullJ14 universe_op:38382| NULLSleep0I NULL115universe_op110.

34、 186.61.45:50322NULLBinlog Dump GTID 264542 IMaster has sentall binlog toslave; waiting for more, updates | NULL17universe_op1127. 0. 0. 1:38454NULLSleep14 |I NULL1 isuniverse_op1127. 0. 0. 1:38456NULLSleep14 | NULL1J 19universe_op1127. 0. 0. 1:38458I NULL |Sleep14 | NULL 1二0universe op1127. 070?173

35、8460NULLSleep114 |I NULL1121universe_op1127. 0. 0. 1:3846)NULLSleepr14 |I NULL22universe_op1127. 0. 0. 1:38464I NULL |Sleep114 | NULL 123universe op1127. 0. 0.238452I NULL |Sleep114 |I NULL124universe_opr127. 0. 0. 1:38466NULLSleep114 |I NULLI 142universe_op1127. 0. 0. 1:33390I NULLSleep10 |NULL14830 I sun10. 186.61. 16:60730 testdb