Transaktionen werden laufend langsamer

Hallo zusammen,

ich habe ein mir nicht erklärliches Phänomen mit postgres, zu dem ich ein paar Tips zur Lösungsfindung gebrauchen könnte:

Das System besteht vereinfacht dargestellt aus einem Prozess, der einmal pro Minute 1000 Objekte in einer Tabelle aktualisiert und 1000 Objekte in einer weiteren Tabelle neu einfügt. Die Tabelle, in die eingefügt wird, wird jeden Tag einmal gewechselt. Nun zeigt sich folgendes Verhalten:

Zu Beginn dauern die Transaktionen 3 Sekunden, nach 10 Stunden Laufzeit sind es 6 Sekunden und nach 24 Stunden sind es schon über 10 Sekunden. Ein Neustart des Prozess nützt nichts, einzig ein Neustart von postgres bringt die Transaktionszeiten wieder auf die initialen 3 Sekunden zurück (und das Spiel beginnt von vorn).

Auch der Einsatz der Version 8.4 hat an diesem Verhalten nichts geändert. Deaktivieren des autovacuum hat auch nichts gebracht. Der Effekt ist reproduzierbar unter Solaris 10 (Sparc) sowie Windows XP SP2 und Windows Server 2003 R2.

Hat jemand eine Idee woran das liegen könnte? Wie kann man über das Statement-Level hinaus herausfinden, womit sich postgres aktuell genau beschäftigt?

Bis dann, Helmut.

Welches OS?


Andreas

Hallo,

ich habe in meinem Beitrag die Betriebssysteme direkt ergänzt.

Bis dann, Helmut.

irgendwelche constraints auf der table? trigger die lookups ausfuehren - evtl. in die immer groesser werdende tablelle? keine geeigneten indizes für diese lookups vorhanden?

offenbar wird der aufwand der aktion ja immer groesser je groesser die tabelle wird … der insert allein ist dafuer eher unwahrscheinlich verantwortlich.

Wann hat sich VACUUM das letzte Mal die Tabelle angeschaut? Wieviele live und dead Tuples gibt es in der Tabelle?

Die Informationen stehen in pg_stat_user_tables.

Ads meint damit die Tabelle, wo die Updates erfolgen. Weitere Fragen von mir:

  • kannst Du rausbekommen, was so lange dauert, das Update oder das Insert?
  • was passiert nach einem Tag, da wechselst Du ja die Insert-Tabelle

Andreas

Hallo zusammen,

Antwort auf die bisherigen Fragen/Anmerkungen:

  • Im “Server-Status” unter “Aktivität” ist praktisch nur das update zu sehen. Kann ich server-seitig genauer ausmessen?

  • Der Wechsel der Tabelle ändert nichts am Zeitverhalten.

  • Beide Tabellen dürften keine dead tuples enthalten, da nicht aus ihnen gelöscht wird. Last vacuum ist leer und n_dead_tup entsprechend 0. n_live_tup in der wachsenden Tabelle aktuell 266420.

  • Auf beiden Tabellen ist jeweils nur ein Primärschlüsselconstraint, es sind keine Trigger auf ihnen definiert.

  • Eine der Tabellen wird nur aktualisiert, die anderen Tabellen repräsentieren jeweils einen Tag, es wird also jeden Tag eine neue Tabelle verwendet. Der Wechsel der Tages-Tabelle verbessert die Situation nicht, nur nach einem Neustart von postgres (bei gleichem Füllstand der Tabellen) sind die Transaktionen zunächst wieder akzeptabel schnell.

Bis dann, Helmut.

Nun, die Tage hatten wir hier schon mal so einen Fall. Darum fangen wir gleich mal in einer anderen Ecke an zu suchen:

Wie groß ist der Hauptspeicher der Maschine? Wieviel Speicher darf PostgreSQL davon nutzen? Wie ist die Einstellung von “shared_buffers”?

Nicht zu löschen ist kein hinreichendes Kriterium. Jedes, in Worten, Jedes Update erzeugt pro aktualisierter Row ein dead tuple. Außnahme: HOT seit 8.3. Erfüllt Dein Update diese Bedingung, also, hast Du 8.3 am Start UND ist es ein HOT-Update?

Okay, grad nochmals gelesen, scheinbar hast Du ein 8.3 am Start. Dennoch bleibt meine Frage bestehen.


Andreas

Hallo zusammen,

entschuldigt bitte die späte Antwort, ich war gestern krank.

Ja, die Bedingungen für ein HOT sind erfüllt. Das Update verändert keine Primärschlüsselspalten oder allgemeiner Spalten, die Teil eines Index sind.

Hier einmal die Statistik zu einer der Tabellen, die immer nur aktualisiert werden:

n_tup_upd: 1823668
n_dead_tup: 774056
n_tup_huot_upd: 546

Wie kann ich sicherstellen, daß auf den fraglichen Tabellen keine dead tuples entstehen, oder daß diese zeitnah wieder aufgeräumt werden? Kann das Aufräumen die Tabelle jeweils längere Zeit blockieren?

Bis dann, Helmut.

Versuch mal, nach jedem Update der Tabelle ein Vacuum für diese Tabelle zu machen.

Andreas

Hoi,

Das ist nicht so einfach, dazu müsste ich die verwendete Bibliothek entsprechend anpassen. Dieses Anwendungsschema ist ja nun nichts besonderes, es muß doch eigentlich automatisch gewährleistet sein oder werden können, daß Änderungen auf Tabellen nicht zu einem stetigen Wachstum führen? Was hat in diesem Zusammenhang folgender Wert zu bedeuten:

n_live_tup: 499268
n_dead_tup: 13552

Ich hatte auf dieser Tabelle eben ein Vacuum durchgeführt, deshalb ist letzterer Wert wieder geringer geworden.

select count(*) auf dieser Tabelle ergibt aber nur 308.

Bis dann, Helmut.

Aua. Mich wundert:

  • Du hast davon gesprochen, in dieser Tabelle 1000 Datensätze zu aktualisieren, nun hat diese nur 308?
  • n_live_tup und count(*) sollten zumindest annähernd gleich sein.

Mach mal ein ‘analyse verbose’ auf diese Tabelle und zeige das dann mal.

Andreas

Das ist nicht “keine” :wink:



oder daß diese zeitnah wieder aufgeräumt werden?

VACUUM



Kann das Aufräumen die Tabelle jeweils längere Zeit blockieren?

Nein, das blockiert gar nicht.

Hoi,

Die “1000” war eine grobe Abschätzung um die Größenordnung zu verdeutlichen. Tatsächlich sind es 308 Datensätze. Es werden allerdings mehrere Tabelle in der skizzierten Art beschrieben, sodaß wir in der Summer dann auch auf mehr als 1000 veränderten/erzeugten Datensätzen pro Minute kommen.

Nach einem erneuten Analyze sind sie das nun auch:

INFO: analysiere »public.dalvekurzinterpolo«INFO: »dalvekurzinterpolo«: 8381 von 8381 Seiten gelesen, enthalten 308 lebende Zeilen und 512820 tote Zeilen; 0 Zeilen in Stichprobe, schätzungsweise 308 Zeilen insgesamtGesamtlaufzeit der Abfrage: 49970 ms.

Weitere Vacuums produzieren immer folgenden Output:


INFO: vacuume »public.dalvekurzinterpolo«INFO: Index »dalvekurzinterpolo_pkey« enthält 514023 Zeilenversionen in 3660 Seiten
DETAIL: 0 Indexzeilenversionen wurde entfernt.
1638 Indexseiten wurden gelöscht, 0 sind gegenwärtig wiederverwendbar.
CPU 0.03s/0.04u sec elapsed 0.09 sec.INFO: »dalvekurzinterpolo«: 0 entfernbare, 514052 nicht entfernbare Zeilenversionen in 3814 von 8381 Seiten gefunden
DETAIL: 513436 tote Zeilenversionen können noch nicht entfernt werden.
Es gibt 4814 unbenutzte Itemzeiger.
0 Seiten sind vollkommen leer.
CPU 0.09s/0.12u sec elapsed 0.25 sec.
INFO: analysiere »public.dalvekurzinterpolo«INFO: »dalvekurzinterpolo«: 8381 von 8381 Seiten gelesen, enthalten 308 lebende Zeilen und 513436 tote Zeilen; 0 Zeilen in Stichprobe, schätzungsweise 308 Zeilen insgesamtGesamtlaufzeit der Abfrage: 625 ms.

Da bleibt immer eine beträchtliche Menge “nicht entfernbarer Zeilenversionen” übrig, wie bekomme ich die nun weg?

Ich gehe jetzt mal alle Tabellen mit einem manuellen Vacuum durch und schaue, ob sich das auf die Performance auswirkt. Das beobachtete Verhalten, daß nach Neustart der Instanz erstmal wieder alles schnell ist wäre damit aber nicht zu erklären, da zwischen den Neustarts ja kein vacuum gemacht wurde.

Bis dann, Helmut.

Das allerdings ist schlecht. Läuft autovacuum?

Was sagt SELECT * FROM pg_stat_user_tables; für diese Tabelle(n)?

Ich hatte ja geschrieben, daß das im Moment probeweise nicht läuft. Das hat aber keine positive Wirkung auf das Problem der immer länger werdenden Laufzeiten gehabt, sprich mit autovacuum wars genauso.

Was ich zum Ausdruck bringen wollte: Zwischen den Neustarts des Servers wird kein vacuum durchgeführt, weil der Server ja zwischen Herunterfahren und Hochfahren schlicht nicht läuft. Nach dem Neustart ist das ansonsten unveränderte System aber auf einmal wieder flott und wird dann wie beschrieben wieder aufend langsamer.

Hier nochmal das Ergebnis des Auto-Vacuum auf einer anderen Tabelle:

INFO: vacuume »public.dalveaktstatusaf59«INFO: Index »dalveaktstatusaf59_pkey« gelesen und 731578 Zeilenversionen entfernt
DETAIL: CPU 0.29s/1.59u sec elapsed 48.19 sec.INFO: »dalveaktstatusaf59«: 731578 Zeilenversionen in 4661 Seiten entfernt
DETAIL: CPU 0.21s/0.25u sec elapsed 85.46 sec.INFO: Index »dalveaktstatusaf59_pkey« enthält 942172 Zeilenversionen in 5476 Seiten
DETAIL: 609289 Indexzeilenversionen wurde entfernt.
1932 Indexseiten wurden gelöscht, 0 sind gegenwärtig wiederverwendbar.
CPU 0.00s/0.00u sec elapsed 0.07 sec.
INFO: »dalveaktstatusaf59«: 0 entfernbare, 942172 nicht entfernbare Zeilenversionen in 10662 von 10662 Seiten gefunden
DETAIL: 941864 tote Zeilenversionen können noch nicht entfernt werden.
Es gibt 230 unbenutzte Itemzeiger.
0 Seiten sind vollkommen leer.
CPU 0.59s/2.07u sec elapsed 158.28 sec.INFO: analysiere »public.dalveaktstatusaf59«INFO: »dalveaktstatusaf59«: 10666 von 10666 Seiten gelesen, enthalten 308 lebende Zeilen und 942480 tote Zeilen; 308 Zeilen in Stichprobe, schätzungsweise 308 Zeilen insgesamtGesamtlaufzeit der Abfrage: 163973 ms.

Danach steht in pg_stat_user_table für diese Tabelle:

n_live_tup: 942172

select count(*) ergibt aber nur 308 Datensätze.

Was hat das zu bedeuten?

Bis dann, Helmut.

nichts gutes …


Andreas

Hoi,

Aha.

Nach einem weiteren Vacuum:

INFO: vacuume »public.dalveaktstatusaf59«INFO: Index »dalveaktstatusaf59_pkey« enthält 951412 Zeilenversionen in 5506 Seiten
DETAIL: 0 Indexzeilenversionen wurde entfernt.
1932 Indexseiten wurden gelöscht, 0 sind gegenwärtig wiederverwendbar.
CPU 0.06s/0.01u sec elapsed 21.87 sec.
INFO: »dalveaktstatusaf59«: 0 entfernbare, 951412 nicht entfernbare Zeilenversionen in 10666 von 10666 Seiten gefunden
DETAIL: 951104 tote Zeilenversionen können noch nicht entfernt werden.
Es gibt 723217 unbenutzte Itemzeiger.
0 Seiten sind vollkommen leer.
CPU 0.23s/0.25u sec elapsed 31.71 sec.INFO: analysiere »public.dalveaktstatusaf59«INFO: »dalveaktstatusaf59«: 10666 von 10666 Seiten gelesen, enthalten 308 lebende Zeilen und 951412 tote Zeilen; 308 Zeilen in Stichprobe, schätzungsweise 308 Zeilen insgesamt

Gesamtlaufzeit der Abfrage: 40390 ms.

Steht in n_dead_tup nun nur noch 1540. Das vacuum scheint man also mehrmals ausführen zu müssen, komisch.

Ansonsten hab ich die eigentliche Ursache für das Problem immer noch nicht verstanden, warum wird der Server mit zunehmender Laufzeit immer langsamer?

Bis dann, Helmut.

Normalerweise nicht.

Ansonsten hab ich die eigentliche Ursache für das Problem immer noch nicht verstanden, warum wird der Server mit zunehmender Laufzeit immer langsamer?

Bis dann, Helmut.

Kann ich Dir auch nicht sagen. Ich tippe in Richtung, daß irgend etwas deinen freien Speicher auffrißt. Das muß nicht wirklich zwingend PG sein. Das die Tabellen so abartig viele dead tuples enthalten und die Statistiken so daneben liegen, ist auch bedenklich. Das sollte bei regelmäßigen Vacuum und Analyse nicht sein.

Ich hab da erst mal keine weitere Idee mehr…


Andreas