psql: FATAL: désolé, trop de clients déjà

16

Je reçois soudainement cette erreur lorsque j'essaie d'accéder au site Web qui utilise la base de données postgresql, ou même lorsque j'utilise l'utilitaire psql ou pgadmin3.

Ma base de données est configurée pour gérer 150 connexions maximum:

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

Après avoir redémarré le serveur Ubuntu sur lequel se trouve mon site Web (ce qui est vraiment la seule chose qui utilise des connexions), je vois que le nombre actuel de connexions est de 140:

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

Je ne comprends pas comment soudainement autant de connexions après le redémarrage de mon serveur. Je vérifie donc l'activité postgresql:

# SELECT * FROM pg_stat_activity;

Et je vois plus de 100 colonnes avec la même requête exacte qui ressemble à ceci:

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

Plus important encore, ils ont tous la même adresse client (mon serveur Web).

Ce serveur Web utilise Ruby sur rails avec un pool de connexions de 50. Même s'il existe un pool de connexions de 50, la configuration Apache du processus Passager / Prefork est monothread et donc chaque processus ne peut pas générer 50 threads et 50 connexions à la base de données. De plus, cela s'est produit après un redémarrage du système qui a mis tous les utilisateurs hors de mon serveur Web. Il est probable que postgresql sur le serveur de base de données ne soit pas au courant du redémarrage du serveur Web et tente toujours d'exécuter ces requêtes.

Pour répondre aux commentaires de Craig, sous la colonne d'attente, il affiche la lettre «f». Il semble que la requête soit toujours en cours d'exécution et que le verrou n'a pas encore été libéré. Comme je l'ai déjà dit, ce qui est si étrange, c'est que soudainement plus de 100 requêtes identiques les unes aux autres en quelques millisecondes sont soudainement apparues dans cet état d'exécution. Voilà le mystère pour moi:

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
la source
Jetez un oeil à pg_stat_activity.backend_start. Ces connexions ont-elles été créées avant ou après le redémarrage du serveur Web? S'ils sont tous de nouvelles connexions, j'imagine que cela signifie que le problème est du côté du serveur Web.
Nick Barnes
@NickBarnes ces connexions ont toutes la même requête dans la colonne "current_query" et le temps de backend_start est pratiquement le même pour toutes (à quelques millisecondes près). C'est ce qui est si étrange et je crois que si ma mémoire est bonne, ils étaient tous avant le redémarrage. Mais j'ai supposé que le redémarrage romprait la connexion.
JohnMerlino
1
Ok ... Vous devrez peut-être vérifier topsur le serveur pour voir si ces processus sont occupés. Si tel est le cas, je pense que les connexions devraient disparaître une fois les requêtes terminées (ou alternativement, vous pouvez simplement les tuer maintenant). S'ils sont inactifs et que les connexions sont définitivement mortes, alors je ne suis pas sûr de ce qui se passe, ni comment l'empêcher la prochaine fois ...
Nick Barnes
1
Vérifiez le waitingdrapeau pg_stat_activity, voyez s'ils sont coincés sur une serrure.
Craig Ringer
1
La sortie que vous avez collée SELECT * FROM pg_stat_activity;n'est pas crédible - il n'y a pas assez de colonnes. Que dit la colonne d'état? C'est le domaine le plus important pour cette question.
eradman

Réponses:

5

Cela semble être un problème spécifique de programmation client. Vous ne pourrez pas résoudre ce problème en augmentant par exemple le paramètre "max_connections".

J'ai trouvé un problème possible: regroupement de connexions à la base de données Ruby

Bien que vous puissiez également effectuer un débogage côté serveur:

Activez "log_connections" et "log_disconnections". Utilisez également "log_line_prefix" avec "% m% a% p".

Les applications très utiles pour le débogage des serveurs PostgreSQL sont powa ou bien plus comme: pg_activity

Pour le débogage de serveur en temps réel, je préfère pg_activity - en particulier avec sa fonctionnalité pour afficher les bloqueurs et tuer les sessions.

Josef Hopfgartner
la source
-4

C'est la meilleure façon de résoudre le problème ... ça marche

Connectez-vous au serveur à l'aide de SSH putty,

sudo /etc/init.d/postgresql stop

cela tue les processus de journal morts dans la base de données,

sudo /etc/init.d/postgresql start

Maduka
la source
5
Et puis la prochaine fois que vous arrêterez à nouveau un serveur de production? Votre solution supprime clairement les processus bloqués, mais n'explique pas pourquoi ils sont là, ni durable.
dezso