psql: FATAL: sorry, schon zu viele clients

15

Ich erhalte plötzlich diese Fehlermeldung, wenn ich versuche, auf die Website zuzugreifen, die die postgresql-Datenbank verwendet, oder wenn ich das Dienstprogramm psql oder pgadmin3 verwende.

Meine Datenbank kann maximal 150 Verbindungen verwalten:

# SHOW max_connections;
 max_connections 
-----------------
 150
(1 row)

Nach dem Neustart des Ubuntu-Servers, auf dem sich meine Website befindet (was eigentlich das einzige ist, das Verbindungen verwendet), werden derzeit 140 Verbindungen hergestellt:

# select count(*) from pg_stat_activity;
 count 
-------
   140
(1 row)

Ich verstehe nicht, wie plötzlich so viele Verbindungen nach dem Neustart meines Servers. Also überprüfe ich die postgresql Aktivität:

# SELECT * FROM pg_stat_activity;

Und ich sehe über 100 Spalten mit der gleichen genauen Abfrage, die so aussieht:

SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1

Noch wichtiger ist, dass alle dieselbe Client-Adresse haben (mein Webserver).

Dieser Webserver verwendet Ruby on Rails mit einem Verbindungspool von 50. Obwohl es einen Verbindungspool von 50 gibt, ist die Konfiguration von Passenger Process / Prefork Apache Singlethreading und daher kann jeder Prozess nicht 50 Threads und 50 Datenbankverbindungen erzeugen. Dies geschah außerdem nach einem Neustart des Systems, bei dem alle Benutzer von meinem Webserver getrennt wurden. Die Wahrscheinlichkeit ist, dass postgresql auf dem Datenbankserver den Neustart des Webservers nicht kennt und weiterhin versucht, diese Abfragen auszuführen.

Um auf Craigs Kommentare zu antworten, wird in der Wartespalte der Buchstabe 'f' angezeigt. Es scheint, dass die Abfrage noch ausgeführt wird und die Sperre noch nicht aufgehoben wurde. Wie ich bereits sagte, ist es so seltsam, dass in diesem Ausführungszustand plötzlich über 100 Abfragen auftraten, die innerhalb von Millisekunden identisch waren. Das ist mir ein Rätsel:

mydb=# SELECT * FROM pg_stat_activity;

 datid  | datname  | procpid | usesysid | usename |                                                                           current_query                                                                           | waiting |          xact_start           |          query_start          |         backend_start         |  client_addr   | client_port
--------+----------+---------+----------+---------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------+-------------------------------+-------------------------------+-------------------------------+----------------+-------------
 464875 | mydb     |    4992 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:48.437081-04 | 2014-06-28 22:46:48.437081-04 | 2014-06-28 22:46:44.089764-04 | 192.111.11.111 |       37166
 464875 | mydb     |    4993 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:48.497764-04 | 2014-06-28 22:46:48.497764-04 | 2014-06-28 22:46:44.277856-04 | 192.111.11.111 |       37167
 464875 | mydb     |    4994 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:48.504425-04 | 2014-06-28 22:46:48.504425-04 | 2014-06-28 22:46:44.485269-04 | 192.111.11.111 |       37168
 464875 | mydb     |    4996 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:48.482695-04 | 2014-06-28 22:46:48.482695-04 | 2014-06-28 22:46:44.688203-04 | 192.111.11.111 |       37169
 464875 | mydb     |    4998 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:48.432836-04 | 2014-06-28 22:46:48.432836-04 | 2014-06-28 22:46:44.703883-04 | 192.111.11.111 |       37170

-- many more

 464875 | mydb     |    5052 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:59.584386-04 | 2014-06-28 22:46:59.584386-04 | 2014-06-28 22:46:51.85682-04  | 192.111.11.111 |       37360
 464875 | mydb     |    5053 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:59.506483-04 | 2014-06-28 22:46:59.506483-04 | 2014-06-28 22:46:52.083316-04 | 192.111.11.111 |       37367
 464875 | mydb     |    8958 |    16387 | myuser | <IDLE>                                                                                                                                                            | f       |                               | 2014-06-29 00:05:06.735249-04 | 2014-06-27 16:34:39.307312-04 | 192.111.11.111 |       52759
 464875 | mydb     |    5054 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:59.52573-04  | 2014-06-28 22:46:59.52573-04  | 2014-06-28 22:46:52.285867-04 | 192.111.11.111 |       37371
 464875 | mydb     |    5055 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:59.530804-04 | 2014-06-28 22:46:59.530804-04 | 2014-06-28 22:46:52.303562-04 | 192.111.11.111 |       37372
 464875 | mydb     |    5056 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:59.572198-04 | 2014-06-28 22:46:59.572198-04 | 2014-06-28 22:46:52.31447-04  | 192.111.11.111 |       37373
 464875 | mydb     |    5057 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:59.872037-04 | 2014-06-28 22:46:59.872037-04 | 2014-06-28 22:46:52.323721-04 | 192.111.11.111 |       37374
 464875 | mydb     |    5058 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:59.961803-04 | 2014-06-28 22:46:59.961803-04 | 2014-06-28 22:46:52.334238-04 | 192.111.11.111 |       37375
 464875 | mydb     |    5059 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:59.53713-04  | 2014-06-28 22:46:59.53713-04  | 2014-06-28 22:46:52.347227-04 | 192.111.11.111 |       37376
 464875 | mydb     |    5060 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:47:00.208948-04 | 2014-06-28 22:47:00.208948-04 | 2014-06-28 22:46:52.360008-04 | 192.111.11.111 |       37377
 464875 | mydb     |    5061 |    16387 | myuser | SELECT  "reports".* FROM "reports"  WHERE (("reports"."time" < '2014-06-28 13:30:42.000000' AND "reports"."unit_id" = 3192)) ORDER BY "reports"."id" DESC LIMIT 1 | f       | 2014-06-28 22:46:59.938983-04 | 2014-06-28 22:46:59.938983-04 | 2014-06-28 22:46:52.369496-04 | 192.111.11.111 |       37378
JohnMerlino
quelle
Schauen Sie sich an pg_stat_activity.backend_start. Wurden diese Verbindungen vor oder nach dem Neustart des Webservers hergestellt? Wenn sie alle neue Verbindungen sind, würde ich mir vorstellen, dass das Problem am Ende des Webservers liegt.
Nick Barnes
@NickBarnes Diese Verbindungen haben alle die gleiche Abfrage in der Spalte "current_query" und die Backend_start-Zeit ist für alle praktisch dieselbe (im Abstand von Millisekunden). Das ist so seltsam und ich glaube, wenn der Speicher mir richtig dient, waren sie alle vor dem Neustart. Aber ich nahm an, dass der Neustart die Verbindung unterbrechen würde.
JohnMerlino
1
Ok ... Möglicherweise müssen Sie topauf dem Server überprüfen , ob diese Prozesse ausgelastet sind. Wenn dies der Fall ist, sollten die Verbindungen meiner Meinung nach nach nach Abschluss der Abfragen nicht mehr bestehen (oder Sie können sie jetzt einfach beenden). Wenn sie untätig sind und die Verbindungen definitiv tot sind, bin ich mir nicht sicher, was los ist oder wie ich es beim nächsten Mal verhindern kann ...
Nick Barnes
1
Checken Sie die waitingFlagge ein pg_stat_activityund prüfen Sie, ob sie in einem Schloss stecken.
Craig Ringer
1
Die Ausgabe, die Sie eingefügt haben, SELECT * FROM pg_stat_activity;ist nicht glaubwürdig - es sind nicht genügend Spalten vorhanden. Was steht in der Landesspalte? Das ist das wichtigste Feld für diese Frage.
Eradman

Antworten:

5

Dies scheint ein spezifisches Problem der Client-Programmierung zu sein. Sie können dies nicht beheben, indem Sie z. B. den Parameter "max_connections" erhöhen.

Ich habe ein mögliches verwandtes Problem gefunden: Ruby-Datenbankverbindungspooling

Sie könnten aber auch mehr serverseitiges Debuggen durchführen:

Aktivieren Sie "log_connections" und "log_disconnections". Verwenden Sie auch "log_line_prefix" mit "% m% a% p".

Sehr nützliche Anwendungen für das Debuggen von PostgreSQL-Servern sind powa oder viel mehr : pg_activity

Für das Echtzeit-Server-Debugging bevorzuge ich pg_activity - insbesondere mit seiner Funktion zum Anzeigen von Blockern und zum Beenden von Sitzungen.

Josef Hopfgartner
quelle
-4

Dies ist der beste Weg, um das Problem zu lösen ... es funktioniert

Melden Sie sich mit SSH putty beim Server an.

sudo /etc/init.d/postgresql stoppen

Dadurch werden die Dead-Log-Prozesse in der Datenbank abgebrochen.

sudo /etc/init.d/postgresql starten

Maduka
quelle
5
Und dann, wenn Sie das nächste Mal einen Produktionsserver stoppen? Ihre Lösung beseitigt die festgefahrenen Prozesse eindeutig, erklärt jedoch nicht, warum sie vorhanden sind, und ist auch nicht nachhaltig.
Dezso