Zobrazit příspěvky
1
Server / Problém s výkonem disku - kjournald
« kdy: 20. 02. 2013, 15:01:33 »
Zdravím vespolek a měl bych tu jeden zapeklitý problém.
Server :
- IBM X3550 M3 - Xeon E5645@2,4GHz (6 core); 16GB RAM;
dva disky RAID 1
- VMWare ESXi 4.1.0
- Jeden běžící virtuální server
- Centos 5.9 (Final), aktualizovaný + MySQL 5.5.13 (1.el5.remi)
- SCSI controller je LSI Logic SAS ( už nevím proč, historicky?)
- 4 procesory, 5GB RAM
- apache server + mysql s replikací master - master
Problém se projevuje tak, že disk (přesněji paritition) /data (/dev/sdb1) na kterém jsou uložena data mysql je tak vytížený (dle atopU) tak intenzivně, že už se nedostane k lizu zádný jiný proces. Takže jeden proces mysql zamkne nejpoužívanější TB a čeká až bude moci zapsat data. A protože data zapsat nemůže a TB je stále zamknutá, tak všechny ostatní procesy mysql čekají až to ten první proces dokončí a TB zase odemkne.
Podle iotop je disk zcela vytížen procesem kjournald, který zapisuje do souboru /proc/<pid_procesu>/exe.
Když jsem se díval do VMWaru, tak jsem tam nic neobjevil. Dokonce ani když má v linuxu ten disk problém a nestíhá, tak se v grafech VMWaru nezobrazí žádná výkonnostní špička, což mi připadá docela zvláštní.
Disky/partitions:
Nastaveni zápisu na disk:
Filesystem features:
Atop v okamžiku problému:
GENERIC INFO
---------------------
DISK DETAILS
---------------------
MEMORY DETAILS
---------------------
iotop -a v okamžiku problému:
sort IO
---------------------
Zkusil pomocí blktrace dohledat, ktery kjournald kam zapisuje
Výpis lsof seřazený podle IO z iotop, ale ty odkazy na filesystemy moc jisté nejsou.
Takže tak jak tomu nerozumím se mi zdá, že nejvíc je disk vytěžován zápisem metadat.
Má s tím někdo nějakou zkušenost?
Mám to žurnálování vypnout?
Pátrat jiným směrem?
Díky
Server :
- IBM X3550 M3 - Xeon E5645@2,4GHz (6 core); 16GB RAM;
dva disky RAID 1
- VMWare ESXi 4.1.0
- Jeden běžící virtuální server
- Centos 5.9 (Final), aktualizovaný + MySQL 5.5.13 (1.el5.remi)
- SCSI controller je LSI Logic SAS ( už nevím proč, historicky?)
- 4 procesory, 5GB RAM
- apache server + mysql s replikací master - master
Problém se projevuje tak, že disk (přesněji paritition) /data (/dev/sdb1) na kterém jsou uložena data mysql je tak vytížený (dle atopU) tak intenzivně, že už se nedostane k lizu zádný jiný proces. Takže jeden proces mysql zamkne nejpoužívanější TB a čeká až bude moci zapsat data. A protože data zapsat nemůže a TB je stále zamknutá, tak všechny ostatní procesy mysql čekají až to ten první proces dokončí a TB zase odemkne.
Podle iotop je disk zcela vytížen procesem kjournald, který zapisuje do souboru /proc/<pid_procesu>/exe.
Když jsem se díval do VMWaru, tak jsem tam nic neobjevil. Dokonce ani když má v linuxu ten disk problém a nestíhá, tak se v grafech VMWaru nezobrazí žádná výkonnostní špička, což mi připadá docela zvláštní.
Disky/partitions:
Kód: [Vybrat]
sda1 - /boot
sda2 - /
sdb1 - /data ( mysql, php soubory )
sdc1 - /var/log
Nastaveni zápisu na disk:
Kód: [Vybrat]
sda, sdc - cfq
sdb - deadline
Filesystem features:
Kód: [Vybrat]
Parametry jednotlivých partitions:
[code]/dev/sda1 on /boot type ext3 (rw)
- has_journal ext_attr resize_inode dir_index filetype needs_recovery sparse_super
/dev/sda2 on / type ext3 (rw)
- has_journal ext_attr resize_inode dir_index filetype needs_recovery sparse_super large_file
/dev/sdb1 on /data type ext3 (rw,noatime)
- has_journal ext_attr resize_inode dir_index filetype needs_recovery sparse_super large_file
/dev/sdc1 on /var/log type ext2 (rw)
- resize_inode dir_index filetype sparse_super large_file
Atop v okamžiku problému:
GENERIC INFO
---------------------
Kód: [Vybrat]
PRC | sys 0.49s | user 0.61s | #proc 145 | #tslpu 2 | #zombie 0 | #exit 1 |
CPU | sys 16% | user 22% | irq 1% | idle 264% | wait 97% | curscal ?% |
cpu | sys 6% | user 5% | irq 0% | idle 88% | cpu003 w 0% | curscal ?% |
cpu | sys 3% | user 7% | irq 0% | idle 87% | cpu000 w 3% | curscal ?% |
cpu | sys 4% | user 5% | irq 0% | idle 89% | cpu002 w 2% | curscal ?% |
cpu | sys 3% | user 5% | irq 0% | idle 0% | cpu001 w 92% | curscal ?% |
CPL | avg1 3.26 | avg5 3.07 | avg15 2.90 | csw 105766 | intr 4491 | numcpu 4 |
MEM | tot 5.5G | free 2.0G | cache 1.8G | dirty 0.7M | buff 92.8M | slab 151.4M |
SWP | tot 2.0G | free 2.0G | | | vmcom 2.9G | vmlim 4.7G |
DSK | sdb | busy 100% | read 1209 | write 63 | MBw/s 0.11 | avio 2.36 ms |
DSK | sdc | busy 3% | read 0 | write 5 | MBw/s 0.02 | avio 20.2 ms |
DSK | sda | busy 3% | read 0 | write 25 | MBw/s 0.09 | avio 3.64 ms |
NET | transport | tcpi 131 | tcpo 130 | udpi 0 | udpo 0 | tcpao 1 |
NET | network | ipi 131 | ipo 130 | ipfrw 0 | deliv 131 | icmpo 0 |
NET | eth0 ---- | pcki 123 | pcko 122 | si 42 Kbps | so 362 Kbps | erro 0 |
NET | lo ---- | pcki 8 | pcko 8 | si 1 Kbps | so 1 Kbps | erro 0 |
PID RUID THR SYSCPU USRCPU VGROW RGROW RDDSK WRDSK ST EXC S CPUNR CPU CMD 1/1
7891 mysql 46 0.28s 0.31s 0K 0K 8860K 24K -- - S 2 20% mysqld
9817 apache 1 0.15s 0.13s 0K 0K 0K 0K -- - R 2 9% httpd
9909 root 1 0.01s 0.08s 0K 0K 0K 0K -- - S 0 3% iotop
9665 apache 1 0.04s 0.03s 0K 0K 0K 0K -- - S 0 2% httpd
9641 apache 1 0.00s 0.01s 0K 4K 0K 0K -- - S 0 0% httpd
9784 apache 1 0.00s 0.01s 0K 0K 0K 0K -- - S 0 0% httpd
DISK DETAILS
---------------------
Kód: [Vybrat]
PRC | sys 0.34s | user 1.62s | #proc 143 | #tslpu 1 | #zombie 0 | #exit 78 |
CPU | sys 13% | user 55% | irq 1% | idle 246% | wait 86% | curscal ?% |
cpu | sys 4% | user 16% | irq 1% | idle 0% | cpu001 w 79% | curscal ?% |
cpu | sys 3% | user 16% | irq 0% | idle 80% | cpu000 w 1% | curscal ?% |
cpu | sys 3% | user 12% | irq 0% | idle 83% | cpu003 w 2% | curscal ?% |
cpu | sys 2% | user 11% | irq 0% | idle 83% | cpu002 w 4% | curscal ?% |
CPL | avg1 3.29 | avg5 3.08 | avg15 2.91 | csw 21897 | intr 4484 | numcpu 4 |
MEM | tot 5.5G | free 2.0G | cache 1.8G | dirty 2.0M | buff 94.1M | slab 151.2M |
SWP | tot 2.0G | free 2.0G | | | vmcom 2.9G | vmlim 4.7G |
DSK | sdb | busy 99% | read 737 | write 57 | MBw/s 0.25 | avio 3.75 ms |
DSK | sda | busy 3% | read 0 | write 18 | MBw/s 0.08 | avio 5.78 ms |
DSK | sdc | busy 3% | read 0 | write 5 | MBw/s 0.04 | avio 17.4 ms |
NET | transport | tcpi 473 | tcpo 430 | udpi 0 | udpo 0 | tcpao 0 |
NET | network | ipi 473 | ipo 437 | ipfrw 0 | deliv 473 | icmpo 0 |
NET | eth0 ---- | pcki 473 | pcko 437 | si 183 Kbps | so 824 Kbps | erro 0 |
PID RDDSK WRDSK WCANCL DSK CMD 1/2
7891 2996K 80K 8K 67% mysqld
2184 0K 300K 0K 7% kjournald
9996 280K 8K 0K 6% httpd
9810 136K 12K 0K 3% httpd
9641 104K 16K 0K 3% httpd
9794 100K 4K 0K 2% httpd
9675 80K 16K 0K 2% httpd
9665 88K 8K 0K 2% httpd
10006 68K 12K 0K 2% httpd
10204 72K 8K 0K 2% httpd
677 0K 80K 0K 2% kjournald
9697 32K 8K 0K 1% ht
MEMORY DETAILS
---------------------
Kód: [Vybrat]
PRC | sys 0.70s | user 1.89s | #proc 146 | #tslpu 0 | #zombie 0 | #exit 6 |
CPU | sys 23% | user 62% | irq 1% | idle 221% | wait 93% | curscal ?% |
cpu | sys 6% | user 21% | irq 0% | idle 72% | cpu002 w 1% | curscal ?% |
cpu | sys 5% | user 16% | irq 1% | idle 12% | cpu001 w 66% | curscal ?% |
cpu | sys 6% | user 13% | irq 0% | idle 69% | cpu000 w 12% | curscal ?% |
cpu | sys 6% | user 13% | irq 0% | idle 68% | cpu003 w 13% | curscal ?% |
CPL | avg1 2.93 | avg5 3.01 | avg15 2.89 | csw 101582 | intr 4454 | numcpu 4 |
MEM | tot 5.5G | free 1.9G | cache 1.9G | dirty 0.9M | buff 94.8M | slab 151.1M |
SWP | tot 2.0G | free 2.0G | | | vmcom 2.9G | vmlim 4.7G |
DSK | sdb | busy 97% | read 253 | write 211 | MBw/s 0.50 | avio 6.25 ms |
DSK | sda | busy 39% | read 0 | write 195 | MBw/s 0.54 | avio 5.94 ms |
DSK | sdc | busy 5% | read 0 | write 13 | MBw/s 0.02 | avio 11.3 ms |
NET | transport | tcpi 655 | tcpo 570 | udpi 18 | udpo 18 | tcpao 4 |
NET | network | ipi 673 | ipo 588 | ipfrw 0 | deliv 673 | icmpo 0 |
NET | eth0 ---- | pcki 618 | pcko 533 | si 179 Kbps | so 2074 Kbps | erro 0 |
NET | lo ---- | pcki 55 | pcko 55 | si 15 Kbps | so 15 Kbps | erro 0 |
PID MINFLT MAJFLT VSTEXT VSIZE RSIZE VGROW RGROW RUID EUID MEM CMD 1/1
7891 441 0 8564K 2.1G 1.1G 0K 0K mysql mysql 20% mysqld
9641 47 0 310K 425.4M 106.3M 0K 0K apache apache 2% httpd
9702 281 0 310K 333.2M 40212K 0K 0K apache apache 1% httpd
8221 1 0 10K 140.4M 21400K 0K 0K root root 0% mytop
9998 7 0 310K 310.2M 17920K 0K 0K apache apache 0% httpd
9200 4 0 310K 309.4M 17636K 0K 0K apache apache 0% httpd
9994 12 0 310K 309.2M 17624K 0K 0K apache apache 0% httpd
9675 4 0 310K 309.2M 17568K 0K 0K apache apache 0% httpd
9810 398 0 310K 309.4M 17524K 0K 28K apache apache 0% httpd
10006 106 0 310K 309.2M 17464K 0K 12K apache apac
iotop -a v okamžiku problému:
Kód: [Vybrat]
sort DSK WRITE
---------------------
Total DISK READ: 329.61 K/s | Total DISK WRITE: 0.00 B/s
TID PRIO USER DISK READ DISK WRITE> SWAPIN IO COMMAND
677 be/3 root 16.00 K 4.70 M 0.00 % 2.70 % [kjournald]
3521 be/3 mysql 12.18 M 2.07 M 18.86 % 3.97 % mysqld --basedir=/us~lib/mysql/mysql.sock
7924 be/3 mysql 468.00 K 1456.00 K 0.00 % 0.14 % mysqld --basedir=/us~lib/mysql/mysql.sock
2184 be/3 root 28.00 K 1236.00 K 0.00 % 13.59 % [kjournald]
8233 be/3 mysql 4.03 M 700.00 K 0.81 % 1.08 % mysqld --basedir=/us~lib/mysql/mysql.sock
7937 be/3 mysql 844.00 K 612.00 K 0.00 % 0.25 % mysqld --basedir=/us~lib/mysql/mysql.sock
9686 be/3 mysql 3.76 M 484.00 K 0.20 % 1.77 % mysqld --basedir=/us~lib/mysql/mysql.sock
29740 be/3 mysql 5.96 M 464.00 K 1.51 % 2.80 % mysqld --basedir=/us~lib/mysql/mysql.sock
29739 be/3 mysql 1572.00 K 364.00 K 2.52 % 1.16 % mysqld --basedir=/us~lib/mysql/mysql.sock
9723 be/3 mysql 5.82 M 360.00 K 3.55 % 2.25 % mysqld --basedir=/us~lib/mysql/mysql.sock
sort IO
---------------------
Kód: [Vybrat]
TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND
3500 be/3 mysql 71.24 M 312.00 K -7.57 % 17.92 % mysqld --basedir=/us~lib/mysql/mysql.sock
2184 be/3 root 28.00 K 1276.00 K 0.00 % 13.87 % [kjournald]
8360 be/3 mysql 22.30 M 336.00 K 1.02 % 6.16 % mysqld --basedir=/us~lib/mysql/mysql.sock
9641 be/4 apache 412.00 K 108.00 K 1.05 % 4.05 % httpd
3521 be/3 mysql 12.18 M 2.12 M 17.92 % 3.79 % mysqld --basedir=/us~lib/mysql/mysql.sock
29725 be/3 mysql 13.89 M 304.00 K 6.16 % 3.62 % mysqld --basedir=/us~lib/mysql/mysql.sock
9660 be/4 apache 360.00 K 104.00 K -0.26 % 3.22 % httpd
29740 be/3 mysql 5.96 M 512.00 K 1.69 % 2.68 % mysqld --basedir=/us~lib/mysql/mysql.sock
677 be/3 root 20.00 K 4.86 M 0.00 % 2.63 % [kjournald]
9723 be/3 mysql 6.05 M 360.00 K 3.40 % 2.17 % mysqld --basedir=/us~lib/mysql/mysql.sock
Zkusil pomocí blktrace dohledat, ktery kjournald kam zapisuje
Kód: [Vybrat]
/dev/sda - 8,0
/dev/sda1 - 8,1
/dev/sda2 - 8,2
/dev/sdb - 8,16
/dev/sdb1 - 8,17
Výpis lsof seřazený podle IO z iotop, ale ty odkazy na filesystemy moc jisté nejsou.
Kód: [Vybrat]
IO - 12%
kjournald 2184 root rtd DIR 8,2 4096 2 /
kjournald 2184 root txt unknown /proc/2184/exe -> 8,17- /data
IO - 1,3%
kjournald 677 root rtd DIR 8,2 4096 2 /
kjournald 677 root txt unknown /proc/677/exe -> 8,2 - /
IO - 0%
kjournald 2187 root rtd DIR 8,2 4096 2 /
kjournald 2187 root txt unknown /proc/2187/exe -> 8,16- sdb
Takže tak jak tomu nerozumím se mi zdá, že nejvíc je disk vytěžován zápisem metadat.
Má s tím někdo nějakou zkušenost?
Mám to žurnálování vypnout?
Pátrat jiným směrem?
Díky
