Server hat hohen IO-Wait bei geringer Last

D

dev

Registered User
Moin,

folgende Kiste seit November:

1 HE
Intel Quadcore 2.8 GHz
4 GB RAM
2x SATA HD im Soft-RAID1
CentOS 5.5 mit OpenVZ
Click to expand...

Das Ding ist seit einer Woche produktiv mit einigen wenigen Projekten in einer VE und mir fallen relative hohe iowait-Werte auf (siehe Munin-Grafik).

Rein vom Gefühl und aus der Erfahrung sind mir diese zu hoch, ich habe auch mit anderen Maschinen verglichen - da sieht man nix und da ist mehr los.

Heute habe ich mal nach Ursachen geforscht und denke, sie auch gefunden zu haben:

# vmstat 1 10000 said:
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------
0 0 1632 815 158 1623 0 0 0 0 1025 56 0 0 100 0 0
0 2 1632 815 158 1623 0 0 0 4692 1263 92 0 1 95 4 0
0 0 1632 815 158 1623 0 0 0 8 1830 96 0 2 72 25 0
0 0 1632 815 158 1623 0 0 0 8 1113 59 0 1 99 0 0
Click to expand...

IOWait von 25% nach einem Schreibvorgang.


# dstat -M top-io -d -M top-bio --nocolor --disk-util -c said:
----most-expensive---- -dsk/total- ----most-expensive---- sda- sdb- ----total-cpu-usage----
i/o process | read writ| block i/o process |util:util|usr sys idl wai hiq siq
sshd: 93B 128B| 0 0 | | 0: 0| 0 0 100 0 0 0
klogd 95k 144k| 0 10M|php-cgi 0 208k|84.8:20.3| 1 1 76 18 2 1
htop 69k 245B| 0 5800k| | 100:4.40| 0 0 79 17 2 0
mysqld 446k 18k| 0 508k| |13.7:0.90| 1 0 99 0 0 0
htop 69k 260B| 0 608k|kjournald 0 36k|4.10:2.70| 0 0 99 0 0 0
Click to expand...

100% Disk-Utilisation von sda im Gegensatz von 4.4% sdb.


# iostat -d -x 1 1000 said:
Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util
sda 0.00 242.00 0.00 279.00 0.00 4160.00 14.91 144.09 526.64 3.59 100.10
sda1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sda2 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sda3 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sda4 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sda5 0.00 242.00 0.00 279.00 0.00 4160.00 14.91 144.09 526.64 3.59 100.10
sdb 0.00 220.00 0.00 303.00 0.00 4184.00 13.81 0.69 2.28 0.14 4.10
sdb1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sdb2 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sdb3 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sdb4 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
sdb5 0.00 220.00 0.00 303.00 0.00 4184.00 13.81 0.69 2.28 0.14 4.10
md2 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
md3 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
md1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
md0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
Click to expand...

Ein await-Wert von 525 ms im Gegensatz zu 2.28 ms.


Ich gehe davon aus, dass ich mit meinen Analysen richtig liege. Sda ist eine Seagate-Platte, sdb eine Western Digital (sdb habe ich im folgenden Block weggelassen in der smartctl Ausgabe):


# smartctl -a /dev/sda said:
Device Model: ST31000528AS
Serial Number: 9VP83411
Firmware Version: CC38
Click to expand...

Smart sagt, dass alles ok ist mit dem Ding ist, ausserdem ist die neu (105 Tage Laufzeit). Writeback-Cache ist auf beiden Platten aktiviert.

Kann es sein, dass die Platte nicht mit dem Board zurechtkommt(SATA-Controller) oder woran liegt das? Ich selbst verbaue nur noch WD-Platten (nie Probleme gehabt), die paar Seagate die ich hatte, waren immmer höllisch laut und sehr heiss. Hat jemand eine Idee?

Vor allem kann ich das zwar technisch belegen, frage mich aber, wie generell die Hoster mit solchen Problemen umgehen - kaputt ist ja nichts. Wenn ich da noch 2 Container mit Projekten drauflege, ist der Server sicher mit 20-30% iowait Dauerlast weit unter seinen Möglichkeiten.
 

Attachments

  • iowait.png
    iowait.png
    22.3 KB · Views: 261
Last edited by a moderator:
Also wir hatten gestern genau dasselbe ;). Mit einer Platte und haben diese ausgetauscht und siehe da Phänomen weg. Sieht so aus als ob es von einer defekten Platte kam. Kannst du deine sda nicht auch mal austauschen?
 
Last edited by a moderator:
hdparm -tT /dev/sda
hdparm -tT /dev/sdb

damit sollte eine Krücke zu sehen sein von den beiden, wobei es schon die iostat Werte zeigen... :-)
 
Es ist doch offensichtlich, dass es sda ist, wieso sdb?

@DjTom-i: Krücke kann man wohl nicht sagen, sda spackt ja bei nur wenigen Megabytes im Schreibvorgang ab und blockiert. Wären wir im Jahr 1995 würde ich PIO-Modus statt DMA sagen :D

Und beim Lesen fällt nichts weiter auf, sda ist sogar schneller:

/dev/sda:
Timing cached reads: 26288 MB in 2.00 seconds = 13173.21 MB/sec
Timing buffered disk reads: 310 MB in 3.01 seconds = 102.94 MB/sec

/dev/sdb
Timing cached reads: 25600 MB in 2.00 seconds = 12828.58 MB/sec
Timing buffered disk reads: 256 MB in 3.02 seconds = 84.72 MB/sec
Click to expand...

Die Kiste steckt im Rack im RZ und ist gemietet.

Habe gerade mit dem Hoster telefoniert - sda wird morgen früh getauscht.
 
dev said:
@DjTom-i: Krücke kann man wohl nicht sagen, sda spackt ja bei nur wenigen Megabytes im Schreibvorgang ab und blockiert. Wären wir im Jahr 1995 würde ich PIO-Modus statt DMA sagen :D
Click to expand...

Ich bleibe dabei, eine der beiden Platten ist eine Krücke und auszutauschen.
 
@mr_brain: Ich habe die Diagnosen natürlich länger laufen lassen, updatedb war nicht dabei. Es sind ja immer nur ganz kurze Peaks von 25% iowait, die auftreten, wenn z. B. klogd oder mysql schreiben.

Die sieht man in top auch nur, wenn man es so startet: `top -d 0.2`. Ohne den Munin-Graphen hätte ich das gar nicht gemerkt und wenn sdb nicht deutlich andere Werte gehabt hätte auch nicht.

Aber 100:4.40 Prozent und 526.64:2.26 ms sind eine Ansage für die gleiche Datenmenge...
 
So, neue Platte ist drin (ist nun identisch mit sdb) und das RAID wieder synchron. Aber so richtig zufrieden bin ich immer noch nicht, statt 5% iowait sind es nur nur 2%, aber mir erscheint dass immer noch zuviel für die paar MB, die geschrieben werden. Alle meine anderen Server habe weniger iowait.

Beim Writezugriffe auf sda treten immer noch die iowait-Peaks aufs, zwar deutlich niedriger als mit der Seagate, aber immer noch da.
 
Auf den konkreten Prozentwert würde ich nichts geben. Da wird bei jedem Timerinterrupt geschaut, ob die CPU idle ist und gleichzeitig noch ein I/O aussteht. Wenn das in x Prozent der Fälle so ist, dann kommt da eben x% raus. Solaris 10 gibt da generell eine Null aus, weil Sun erkannt hat, das man I/Os nicht auf eine CPU mappen sollte...

Sind die anderen Server denn höher belastet? Weil eben I/O Wait nur gezählt wird, wenn die CPU idle ist.

Für die Plattenperformance sehe ich iostat -x als sinnvolleres Werkzeug an. Was wird da nach dem Umbau ausgegeben?
 
Danke für Deine Antwort! Ich lasse das mal 15 Minuten laufen und hänge das Protokoll hier als Anhang an.
 
Anbei mal 2 typische "Ausreisser", await und %util sind auf sda oft höher als auf sdb. Ich habe nicht einen Datensatz, wo es andersherum ist. Wieso ist da so ein eklatanter Unterschied auf einem mdadm-RAID1?

Und wieso werden auf sda deutlich mehr Sektoren als auf sdb geschrieben?

sdX1, sdX2, sdX3 und sdX5 gehören zu 4 md-Devices, sdX3 bilden das swap-md und sdX4 ist nur die erweiterte Partition, die sdX5 hält.

Code: 
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.50    0.00    1.50    2.99    0.00   95.01

Device:         rrqm/s   wrqm/s   r/s   w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.00   225.00  0.00 331.00     0.00  [B]5288.00 [/B]   15.98    30.63  [B]124.50 [/B]  1.39  [B]46.00[/B]
sda1              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sda2              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sda3              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sda4              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sda5              0.00   225.00  0.00 331.00     0.00  5288.00    15.98    30.63  124.50   1.39  46.00
sdb               0.00   207.00  0.00 211.00     0.00  [B]3344.00[/B]    15.85     0.54    [B]2.55[/B]   0.21   [B]4.40[/B]
sdb1              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sdb2              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sdb3              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sdb4              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sdb5              0.00   207.00  0.00 211.00     0.00  3344.00    15.85     0.54    2.55   0.21   4.40
md2               0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
md3               0.00     0.00  0.00 51.00     0.00   408.00     8.00     0.00    0.00   0.00   0.00
md1               0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
md0               0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00


avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.50    0.00    1.00    1.00    0.00   97.50

Device:         rrqm/s   wrqm/s   r/s   w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.00    59.00  0.00 223.00     0.00  [B]3184.00[/B]    14.28    13.31  [B]113.71[/B]   0.69  [B]15.30[/B]
sda1              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sda2              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sda3              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sda4              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sda5              0.00    59.00  0.00 223.00     0.00  3184.00    14.28    13.31  113.71   0.69  15.30
sdb               0.00    52.00  0.00 94.00     0.00  [B]1168.00[/B]    12.43     0.94   [B]10.02[/B]   0.57   [B]5.40[/B]
sdb1              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sdb2              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sdb3              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sdb4              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sdb5              0.00    52.00  0.00 94.00     0.00  1168.00    12.43     0.94   10.02   0.57   5.40
md2               0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
md3               0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
md1               0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
md0               0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
 
Last edited by a moderator:
Eine echte Erklärung habe ich leider auch nicht.

Wie du schon erkannt hast, gehen auf sda deutlich mehr Schreibvorgänge als auf sdb. Die kommen alle über sdx5. Die sda hat eine längere Queue (avgqu-sz), so dass damit die Antwortzeit für einen I/O auch länger dauert (await). Das könnte ich mir noch erklären, wenn jeder I/O zuerst auf sda durchgeführt wird und erst nach dessen Abschluß auf sdb gestartet wird. Auf sdb würde so gar keine Queue entstehen, weil die I/Os eh schon zeitlich gestreckt ankommen.

Kannst du die I/O-Last reduzieren? 200-300 I/Os pro Sekunde mit 16KB sind für eine einzelne Platte schon heftig. Das da längere Queues entstehen ist kein Wunder. Wäre interessant zu sehen, ob das Ungleichgewicht dann bleibt.
 
Die Caches habe ich auf den HDs kurz deaktiviert, an den Schreibvorgängen an sich hatte sich nichts geändert, sprich die Datenlast viel ebenfalls an, allerdings hatte ich dann auf beiden Platten hohe util Werte.


Danke für Eure Antworten. Ich habe wohl vergessen zu schreiben, dass die Werte weiter oben 2 Dumps aus einer Serie sind, d. h. dazwischen liegen ca. 30 Sekunden. Ich habe nur die gepostet, wo es Ausreisser gab. Die 30 Sekunden passen ja auch zum beschriebenen Verhalten vom pdflush-Daemon, der nach 30 Sekunden schreibt, wenn sein Cache vorher noch nicht vollgelaufen ist.

Nun habe ich auch durch die Zeit neue Erkenntnisse: Die iowait-werte sind deutlich gesunken (siehe wöchentliche Munin-Grafik, die letzte Unterbrechung ist der Plattentausch, danach deutlich niedrigere iowait-Werte im Verlauf).

Auf die ganze Geschichte aufmerksam geworden bin ich nur, da der Rechner trotz 4 GB RAM bei < 500 MB Auslastung immer beim Backup angefangen hat, den Swap vollzuschaufeln. Ich hatte nach einem gzip-Backup von ca. 3 GB 1.7 GB Swap-Belegung!

Anscheinend hat die Seagate-Platte den Kernel so beschäftigt, dass der in seiner Not angefangen hat, den Swap zu nutzen. Das habe ich vor dem Thread und vor dem Plattentausch aber noch nicht unmittelbar in einen Zusammenhang gesetzt (wollte weiteren Thread aufmachen).

Und die Backupzeiten haben sich extrem verbessert:

Seagate vorher:
Overall backup time: 11.80 minute(s).​
WD nachher:
Overall backup time: 4.97 minute(s).​
Click to expand...

Der HD-Tausch hat sich also mehr als gelohnt :o)
 

Attachments

  • iowait-wd.png
    iowait-wd.png
    21.8 KB · Views: 152
You must log in or register to reply here.
Back
Top