MySQL Undo LogDie wunderbare Welt von Isotopp

Donnerstag, 28. April 2011MySQL Undo Log

"Kris, kannst Du bitte mal gucken?"

Seit heute morgen, 10:00 Uhr, wächst das Undo Log immer weiter an.

Immer wenn InnoDB Daten schreibt wird die alte Version einer Zeile aus der Tabelle in das Undo­Log

verschoben, also physikalisch von der ibd­Datei der Tabelle in die ibdata1 im Datadir von MySQL. In der

Tabelle wird in der veränderten Zeile ein Zeiger von der neuen Version auf die alte Version der Zeile im

Undo­Log installiert, der Roll(back)­Pointer. Die alte Version im Undo­Log zeigt mit ihrem eigenen Roll­

Pointer auf eine noch ältere Version derselben Zeile und so weiter ­ es entsteht für jede Zeile in der

Datenbank eine lineare Liste von Versionen in die Vergangenheit einer Row.

Der InnoDB Purge Thread hat die Aufgabe, das Undo Log zu verkürzen. Wenn er das nicht tut, dann sieht

das so aus wie oben im Graphen gezeigt. Dafür kann es zwei Gründe geben: Purge Lag ­ also mehr

Writes als der Purge Thread wegschaffen kann. Oder lang laufende Transaktionen. Denn der Purge

Thread kann nur dann eine Zeile aus dem Undo Log streichen, wenn es keine aktive Transaktion mehr im

ganzen System gibt, die älter ist als die zu streichende Zeile.

Das ist die weitaus wahrscheinlichere Fehlerquelle. Wie also finden wir den Schuldigen?

mysql> pager grep ACTIVE

mysql> show engine innodb status\G

...

­­­TRANSACTION A90E003AB, ACTIVE 16830 sec, process no 12098, OS thread id

1749563712

...

mysql> pager

mysql> show engine innodb status\G

...

­­­TRANSACTION A90E003AB, ACTIVE 16830 sec, process no 12098, OS thread id

1749563712

3 lock struct(s), heap size 1248, 2 row lock(s), undo log entries 1MySQL thread id 146473882, query id 4156570244 mc02cronapp­01 192.168.1.10 cron_bpTrx read view will not see trx with id >= A90E14DE8, sees < A90E14DE8...

Ein Cronjob hängt also in einer offenen Transaktion seit geraumer Zeit fest? Mehr Informationenbekommen wir aus der Prozeßliste:

mysql> pager grep cronmysql> show processlist;...| 146473882 | cron_bp | mc02cronapp­01:50154 | bp | Sleep | 16434 |...

Ein Login auf der mc02cronapp­01 und ein "lsof ­i ­n ­P | grep 50154" zeigt schnell: Mitnichten ein Cronjob.Ein User hat einen MySQL Kommandozeilenclient gestartet und eine manuelle Verbindung undTransaktion offen gelassen. Ein "KILL 146473882" auf den Thread in MySQL trennt die Verbindung undder Purge Thread kann seine Arbeit fortsetzen, ein Sysadmin mit einem Cluebat kann zu dem Userdispatched werden.

Das Undo­Log ist Teil der ibdata1­Datei. Diese startet mit einer Größe von 10M und wächst per Default inSchritten von 8M im autoextend­Modus. Lang laufende Transaktionen, die den Purge Thread anhalten,führen zu einem Wachstum der ibdata1. InnoDB schrumpft Dateien niemals, und es gibt auch keineMethode, das zu tun ­ zwar wird der Platz in der Datei freigegeben und später wieder genutzt, aber für dasBetriebssystem ist der Platz verloren.

[root@mc01bpmdb­01 ~]# cd /mysql/bp/data[root@mc01bpmdb­01 data]# ls ­lh ibdata*­rw­rw­­­­ 1 mysql mysql 1.3G Apr 28 14:50 ibdata1

Geschrieben von Kristian Köhntopp in MySQL um 12:40 | Kommentare (7) | Trackbacks (0)

TrackbacksTrackback­URL für diesen Eintrag

Keine Trackbacks

KommentareAnsicht der Kommentare: (Linear | Verschachtelt)

Nice one und danke für die Erklärung (mal wieder). Besonders nett auch die Passage mit dem Cluebat :)#1 andy (Link) am 28.04.2011 13:06

Nun stellt sich nur noch die Frage, wie John "user" Doe an das Paßwort für den MySQL­Account für cronjobs gekommen ist. Eventuell eher eine Aufgabe für den Wachdienst als für die Sysadmins.#2 XL am 28.04.2011 18:07

Es war kein John Doe­User, sondern einer mit dem Recht dort zu sein. Das zu erklären ist ein längererVortrag, den ich gerade als Thema für den Froscon 2011 eingereicht habe ("8 rollouts a day keep thedoctor away").#2.1 Kristian Köhntopp (Link) am 29.04.2011 07:49

Mit welcher Software/Framework wurde der Graph erzeugt?

Nach Cacti sieht es jedenfalls nicht aus.

Gruß,Marcel.#3 Der Adminblogger (Link) am 28.04.2011 21:29

Das ist Merlin, äh, MNAS, äh, MEM, also MySQL Enterprise Manager (der in Wahrheit gar nix managed,sondern nur monitored), die Software mit dem wahrscheinlich schlechtesten Graphing der Welt.

Du willst Zabbix mit den kommerziellen Zabbix­Modulen von From Dual.#3.1 Kristian Köhntopp (Link) am 29.04.2011 07:50

Und für die faulen unter uns, gibts nen Setting um ein Rollback nach maximaler Timeoutzeit zu erzwingen?

Und noch ne Sache MSSQL macht das ja auch so. Bei Oracle haben sie sehr lange gebraucht bis man denundo tablespace ohne komische timeouts konfigurieren konnte...#4 Bernd (Link) am 08.05.2011 13:30

Ich verstehe nicht, was genau Du möchtest?

MySQL wird die Verbindung terminieren, wenn sie zu lange Idle ist: Wenn es sich um eine interaktiveShell handelt (beim Connect war das Interactive­Flag durch den Client gesetzt), wird die Verbindung nachinteractive_timeout Sekunden getrennt. Wenn es sich um eine nicht­interaktive Verbindung handelt, wirdnach wait_timeout Sekunden Idle getrennt.

Beide Werte stehen per Default auf 28800 Sekunden (8 Stunden).#4.1 Kristian Köhntopp (Link) am 08.05.2011 13:48

Kommentar schreibenName

E­Mail

Homepage

Antwort zu

Kommentar

Umschließende Sterne heben ein Wort hervor (*wort*), per _wort_ kann ein Wort unterstrichenwerden.

Um maschinelle und automatische Übertragung von Spamkommentaren zu verhindern, bittedie Zeichenfolge im dargestellten Bild in der Eingabemaske eintragen. Nur wenn dieZeichenfolge richtig eingegeben wurde, kann der Kommentar angenommen werden. Bittebeachten Sie, dass Ihr Browser Cookies unterstützen muss, um dieses Verfahrenanzuwenden.

Hier die Zeichenfolge der Spamschutz­Grafik eintragen:

BBCode­Formatierung erlaubt Daten merken?