psql: FATAL: desculpe, muitos clientes já

16

De repente, estou recebendo esse erro ao tentar acessar o site que usa o banco de dados postgresql ou mesmo ao usar o utilitário psql ou o pgadmin3.

Meu banco de dados está definido para lidar com 150 conexões máximas:

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

Depois de reiniciar o servidor ubuntu em que meu site está (que é realmente a única coisa usando conexões), vejo que a quantidade atual de conexões é 140:

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

Eu não entendo quantas ligações repentinas após a reinicialização do meu servidor. Então eu verifico a atividade do postgresql:

# SELECT * FROM pg_stat_activity;

E vejo mais de 100 colunas com a mesma consulta exata que se parece com isso:

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

Ainda mais importante é que todos eles têm o mesmo endereço de cliente (meu servidor web).

Este servidor da Web está usando ruby ​​on trilhos com um pool de conexões 50. Embora exista um pool de conexões 50, a configuração do processo Passenger / prefork apache é de thread único e, portanto, cada processo não pode gerar 50 threads e 50 conexões com o banco de dados. Além do mais, isso ocorreu após uma reinicialização do sistema, que derrubou todos os usuários do meu servidor web. A probabilidade é que o postgresql no servidor de banco de dados não esteja ciente da reinicialização do servidor da web e ainda esteja tentando executar essas consultas.

Para responder aos comentários de Craig, na coluna de espera, mostra a letra 'f'. Parece que a consulta ainda está em execução e o bloqueio ainda não foi liberado. Como afirmei anteriormente, o que é tão estranho é que, de repente, mais de 100 consultas idênticas entre si em milissegundos de distância apareceram repentinamente nesse estado de execução. Esse é o mistério para mim:

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
postgresql max-connections JohnMerlino
fonte
Dê uma olhada pg_stat_activity.backend_start. Essas conexões foram criadas antes ou depois da reinicialização do servidor da web? Se são todas novas conexões, imagino que isso significa que o problema está no fim do servidor da web.
Nick Barnes
@NickBarnes, todas essas conexões têm a mesma consulta na coluna "current_query" e o tempo de backend_start é praticamente o mesmo para todos eles (milissegundos separados). Isso é o que é tão estranho e acredito que, se a memória me servir corretamente, todos estavam antes da reinicialização. Mas presumi que a reinicialização interromperia a conexão.
31914 JohnMerlino
1
Ok ... Talvez seja necessário verificar topno servidor para ver se esses processos estão ocupados. Se estiverem, acho que as conexões devem desaparecer assim que as consultas terminarem (ou, como alternativa, você pode simplesmente matá-las agora). Se eles estão ociosos, e as conexões são definitivamente morto, então eu não sei o que está acontecendo, ou como evitá-lo da próxima vez ...
Nick Barnes
1
Verifique a waitingbandeira pg_stat_activity, veja se eles estão presos em uma fechadura.
Craig Ringer
1
A saída da qual você colou SELECT * FROM pg_stat_activity;não é crível - não há colunas suficientes. O que diz a coluna de estado? Esse é o campo mais importante para esta pergunta.
Eradman

Respostas:

5

Este parece ser um problema específico da programação do cliente. Você não poderá consertar isso, por exemplo, aumentando o parâmetro "max_connections".

Encontrei um possível problema relacionado: Pool de conexões de banco de dados Ruby

Apesar de você também poder fazer mais depuração no servidor:

Ative "log_connections" e "log_disconnections". Use também "log_line_prefix" com "% m% a% p".

Aplicativos muito úteis para depurar servidores PostgreSQL são powa ou muito mais populares, como: pg_activity

Para depuração de servidor em tempo real, eu prefiro pg_activity - especialmente com seu recurso para exibir bloqueadores e matar sessões.

Josef Hopfgartner
fonte
-4

Esta é a melhor maneira de resolver o problema ... funciona

Efetue login no servidor usando a massa SSH,

sudo /etc/init.d/postgresql stop

isso mata os processos de log morto no banco de dados,

sudo /etc/init.d/postgresql start

Maduka
fonte
5
E então da próxima vez que você parar novamente um servidor de produção? Sua solução remove claramente os processos bloqueados, mas não explica por que eles estão lá, nem é sustentável.
Dezso