PostgreSQL Transaction Committing für Stunden

11

Ich stoße auf ein Problem, bei dem ich zwei Verbindungen von einem Benutzer zu meinem PostgreSQL-Server habe, die seit ungefähr 4 Stunden ausgeführt werden und sich seit einiger Zeit in einem Commit-Status befinden (mindestens 1 Stunde, in der ich sie beobachtet habe). . Diese Verbindungen blockieren die Ausführung anderer Abfragen, sind jedoch selbst nicht blockiert.

Hier sind die beiden fraglichen Verbindungen.

postgres=# select * from pg_stat_activity where usename = 'xxxxx';
 datid | datname | procpid | usesysid | usename | current_query | waiting |          xact_start           |          query_start          |         backend_start         |  client_addr  | client_port
-------+---------+---------+----------+---------+---------------+---------+-------------------------------+-------------------------------+-------------------------------+---------------+-------------
 20394 | xxxxxx  |   17509 |    94858 | xxxxx   | COMMIT        | f       | 2014-01-30 05:51:11.311363-05 | 2014-01-30 05:51:12.042515-05 | 2014-01-30 05:51:11.294444-05 | xx.xx.xxx.xxx |       63531
 20394 | xxxxxx  |    9593 |    94858 | xxxxx   | COMMIT        | f       | 2014-01-30 06:45:17.032651-05 | 2014-01-30 06:45:17.694533-05 | 2014-01-30 06:45:16.992576-05 | xx.xx.xxx.xxx |       63605

PID 9593 ist die problematischste, die andere Benutzer durch diese blockieren. Soweit der Benutzer zugibt, hat er seine Tabelle abgeschnitten und dann nach jedem Stapel Einsätze in Stapeln von 1.000 festgeschrieben.

Derzeit zeigt diese PID die folgenden Sperren:

postgres=# select * from pg_locks where pid = 9593;
   locktype    | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid  |        mode         | granted
---------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+------+---------------------+---------
 relation      |    20394 | 29173472 |      |       |            |               |         |       |          | 261/0              | 9593 | AccessExclusiveLock | t
 relation      |    20394 | 27794470 |      |       |            |               |         |       |          | 261/0              | 9593 | RowExclusiveLock    | t
 relation      |    20394 | 27794470 |      |       |            |               |         |       |          | 261/0              | 9593 | ShareLock           | t
 relation      |    20394 | 27794470 |      |       |            |               |         |       |          | 261/0              | 9593 | AccessExclusiveLock | t
 virtualxid    |          |          |      |       | 261/503292 |               |         |       |          | 261/0              | 9593 | ExclusiveLock       | t
 transactionid |          |          |      |       |            |     503213304 |         |       |          | 261/0              | 9593 | ExclusiveLock       | t

Ich kann diese PID nicht beenden (nichts passiert, wenn ich den Befehl kill erteile). Ich bin mir nicht sicher, was ich tun soll, um dies weiter zu diagnostizieren und dies offensichtlich zu beheben.

Irgendeine Eingabe jemand?

Ausführen von PostgreSQL 8.4 auf einem Ubuntu Linux-Server.

BEARBEITEN:

Als ich andere Verbindungen in einem ähnlichen Zustand fand, in dem das Commit hängen blieb, suchte ich weiter und fand Folgendes in den Serverprotokollen:

Jan 30 02:29:45 server001 kernel: [3521062.240540] postgres      D 0000000000000000     0 23220   8154 0x00000004
Jan 30 02:29:45 server001 kernel: [3521062.240550]  ffff8800174c9d08 0000000000000082 ffff88041cd24728 0000000000015880
Jan 30 02:29:45 server001 kernel: [3521062.240559]  ffff8806c678b110 0000000000015880 0000000000015880 0000000000015880
Jan 30 02:29:45 server001 kernel: [3521062.240567]  0000000000015880 ffff8806c678b110 0000000000015880 0000000000015880
Jan 30 02:29:45 server001 kernel: [3521062.240575] Call Trace:
Jan 30 02:29:45 server001 kernel: [3521062.240582]  [<ffffffff810da010>] ? sync_page+0x0/0x50
Jan 30 02:29:45 server001 kernel: [3521062.240590]  [<ffffffff81528488>] io_schedule+0x28/0x40
Jan 30 02:29:45 server001 kernel: [3521062.240596]  [<ffffffff810da04d>] sync_page+0x3d/0x50
Jan 30 02:29:45 server001 kernel: [3521062.240603]  [<ffffffff815289a7>] __wait_on_bit+0x57/0x80
Jan 30 02:29:45 server001 kernel: [3521062.240610]  [<ffffffff810da1be>] wait_on_page_bit+0x6e/0x80
Jan 30 02:29:45 server001 kernel: [3521062.240618]  [<ffffffff81078540>] ? wake_bit_function+0x0/0x40
Jan 30 02:29:45 server001 kernel: [3521062.240627]  [<ffffffff810e4480>] ? pagevec_lookup_tag+0x20/0x30
Jan 30 02:29:45 server001 kernel: [3521062.240634]  [<ffffffff810da665>] wait_on_page_writeback_range+0xf5/0x190
Jan 30 02:29:45 server001 kernel: [3521062.240644]  [<ffffffff81053668>] ? try_to_wake_up+0x118/0x340
Jan 30 02:29:45 server001 kernel: [3521062.240651]  [<ffffffff810da727>] filemap_fdatawait+0x27/0x30
Jan 30 02:29:45 server001 kernel: [3521062.240659]  [<ffffffff811431b4>] vfs_fsync+0xa4/0xf0
Jan 30 02:29:45 server001 kernel: [3521062.240667]  [<ffffffff81143239>] do_fsync+0x39/0x60
Jan 30 02:29:45 server001 kernel: [3521062.240674]  [<ffffffff8114328b>] sys_fsync+0xb/0x10
Jan 30 02:29:45 server001 kernel: [3521062.240682]  [<ffffffff81012042>] system_call_fastpath+0x16/0x1b
ETL
quelle
Ich habe ähnliche Einträge nach hoher E / A-Last gesehen. Immer noch nicht sicher, ob Pech oder wirklich eine Verbindung.
Frlan
2
Ich vermute stark einen Festplatten- oder E / A-Subsystemfehler auf dem Server.
Craig Ringer
@CraigRinger - Ich denke du hast recht. Das Seltsame ist, dass ich um 2 Uhr morgens diese Warnungen in der Protokolldatei erhalten habe und seitdem den ganzen Tag keine weiteren Nachrichten in den Protokollen erhalten habe. Die Datenbankverbindungen sind jedoch immer noch hängen geblieben, als ob PostgreSQL diese Fehler nicht behoben hätte. Ich werde heute Abend ein Update des Betriebssystems und dergleichen durchführen (mit einem 4 Jahre alten Kernel).
ETL
@ETL überprüfen dmesgauch - suchen Sie nach E / A-Fehlern, Zeitüberschreitungen, HBA-Fehlern usw. Erstellen Sie eine neue Sicherung und überprüfen Sie Ihre Festplatten, RAID-Subsystem usw.
Craig Ringer
Es muss eine weitere Meldung direkt darüber geben, dass postgres D ... trace printk aufruft, die z. B. CPU-Sperre, Prozess, der länger als 120 Sekunden anhält usw. Dies würde deutlicher darauf hinweisen, wo das Problem liegt, obwohl es sich um die Ablaufverfolgung handelt schon ziemlich klar - das sieht aus wie ein fsync (2). Sieht aus wie das zugrunde liegende Gerät defekt oder zu langsam ist?
Josip Rodin

Antworten:

1

Ich habe seitdem ein Upgrade auf Version 9.4 und einen ganz neuen Server durchgeführt, sodass ich dies nicht weiter debuggen kann. Aber ich glaube, das Problem war mit einer Fahrt. Ich habe ein schlechtes Laufwerk gefunden, das von der Maschine nicht als schlecht gemeldet wurde.

ETL
quelle